{"thread":{"id":"40365","subject":"git rebase -i failing due to phantom index.lock","startedAt":"2015-09-16T20:08:27Z","lastAt":"2015-09-21T16:48:32Z","messageCount":3,"participants":["Giuseppe Bilotta","Duy Nguyen"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"270154","messageId":"CAOxFTcwTOJjRnA=7gR4GP2u0bsDCRv+j8PEw0c8Nv-nVVrynTQ@mail.gmail.com","threadId":"40365","inReplyTo":null,"subject":"git rebase -i failing due to phantom index.lock","fromName":"Giuseppe Bilotta","fromEmail":"giuseppe.bilotta@gmail.com","sentAt":"2015-09-16T20:08:27Z","receivedAt":"2015-09-16T20:08:27Z","isPatch":false,"sender":{"key":"giuseppe.bilotta@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1464?v=4"},"body":"Hello all,\n\nI've recently started to note an issue with git rebase -i failing with\nalarming frequency, especially on one of my repositories, claiming\nthat index.lock could not be created because it exists, even though it\ndoesn't and nothing else seems to be locking the index. The rebase\nbombs more usually during the initial checkout than during any other\nof the steps.\n\nThe problem is somewhat randomly reproducible, as it doesn't happen\n100% of the time. It also seems to happen more consistently with more\nrecent git versions, or at least with my custom built git than with\nthe distro-shipped one.\n\nA somewhat problematic git bisect has allowed me to identify commit\n03b86647722f11ccc321cd7279aa49b811d17cc2 as the first bad commit.\n\nThe problem has all signs of a timing issue, which I'm having problems\nisolating, although simply providing a timeout on the index lock calls\nseems to fix it. Making git stall instead of die on error allowed me\nto obtain this backtrace which I suspect will not be particularly\nuseful:\n\n#0 0x00000000004c4666 in unable_to_lock_message\n(path=path@entry=0x1bad940 \".git/index\", err=,\nbuf=buf@entry=0x7ffd3b990900) at lockfile.c:158\n#1 0x00000000004c46c6 in unable_to_lock_die (path=path@entry=0x1bad940\n\".git/index\", err=) at lockfile.c:167\n#2 0x00000000004c480b in hold_lock_file_for_update_timeout\n(lk=lk@entry=0x1bd7be0, path=0x1bad940 \".git/index\", flags=, timeout_ms=timeout_ms@entry=0) at lockfile.c:177\n#3 0x00000000004e6e2a in hold_lock_file_for_update (flags=1,\npath=, lk=0x1bd7be0) at lockfile.h:165\n#4 hold_locked_index (lk=lk@entry=0x1bd7be0,\ndie_on_error=die_on_error@entry=1) at read-cache.c:1411\n#5 0x0000000000420cb0 in merge_working_tree (old=0x7ffd3b990a20,\nold=0x7ffd3b990a20, new=0x7ffd3b990a00, new=0x7ffd3b990a00,\nwriteout_error=0x7ffd3b9909c0, opts=0x7ffd3b992a31)\nat builtin/checkout.c:471\n#6 switch_branches (new=0x7ffd3b990a00, opts=0x7ffd3b992a31) at\nbuiltin/checkout.c:826\n#7 checkout_branch (new=0x7ffd3b990a00, opts=0x7ffd3b992a31) at\nbuiltin/checkout.c:1123\n#8 cmd_checkout (argc=, argv=,\nprefix=) at builtin/checkout.c:1273\n#9 0x0000000000405e7e in run_builtin (argv=0x7ffd3b992480, argc=2,\np=0x7acab0 ) at git.c:350\n#10 handle_builtin (argc=2, argv=0x7ffd3b992480) at git.c:535\n#11 0x0000000000405021 in run_argv (argv=0x7ffd3b9922d8,\nargcp=0x7ffd3b9922bc) at git.c:581\n#12 main (argc=2, av=) at git.c:689\n\nAdditional information: I have the bash git prompt enabled, I do not\nhave anything else accessing that repository at the same time, and the\nrepository is “spread out” across multiple workdirs created with git\nnew-workdir, each with a different branch checked out. It is also\nusually accessed under a symlink (cd ~/shortcut/repo/branch rather\nthan ~/full/path/to/repo/branch). Running Debian unstable with Linux\n4.1.0 on an SSD-backed ext4 partition mounted with data=ordered. I\ncan't thnk of any other detail that might be even just remotely\ninvolved in this odd issue. Any suggestions on how to debug it are\nwelcome.\n\nBest regards,\n\n-- \nGiuseppe \"Oblomov\" Bilotta\n"},{"id":"270207","messageId":"CACsJy8CnxGSJT62FRsZP4cD7Az36XGDjJwr+Szddhz42P_hJDg@mail.gmail.com","threadId":"40365","inReplyTo":"CAOxFTcwTOJjRnA=7gR4GP2u0bsDCRv+j8PEw0c8Nv-nVVrynTQ@mail.gmail.com","subject":"Re: git rebase -i failing due to phantom index.lock","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2015-09-17T12:57:59Z","receivedAt":"2015-09-17T12:57:59Z","isPatch":false,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Thu, Sep 17, 2015 at 3:08 AM, Giuseppe Bilotta\n wrote:\n> Hello all,\n>\n> I've recently started to note an issue with git rebase -i failing with\n> alarming frequency, especially on one of my repositories, claiming\n> that index.lock could not be created because it exists, even though it\n> doesn't and nothing else seems to be locking the index. The rebase\n> bombs more usually during the initial checkout than during any other\n> of the steps.\n>\n> The problem is somewhat randomly reproducible, as it doesn't happen\n> 100% of the time. It also seems to happen more consistently with more\n> recent git versions, or at least with my custom built git than with\n> the distro-shipped one.\n>\n> A somewhat problematic git bisect has allowed me to identify commit\n> 03b86647722f11ccc321cd7279aa49b811d17cc2 as the first bad commit.\n\nThat commit is mostly refactoring, but there's one extra lock added in\nthese hunks. Maybe you can revert it and see if it improves anything.\n\ndiff --git a/builtin/apply.c b/builtin/apply.c\nindex 87439fa..5e13444 100644\n--- a/builtin/apply.c\n+++ b/builtin/apply.c\n@@ -3644,7 +3644,7 @@ static void build_fake_ancestor(struct patch\n*list, const char *filename)\n {\n struct patch *patch;\n struct index_state result = { NULL };\n- int fd;\n+ static struct lock_file lock;\n\n /* Once we start supporting the reverse patch, it may be\n * worth showing the new sha1 prefix, but until then...\n@@ -3682,8 +3682,8 @@ static void build_fake_ancestor(struct patch\n*list, const char *filename)\n die (\"Could not add %s to temporary index\", name);\n }\n\n- fd = open(filename, O_WRONLY | O_CREAT, 0666);\n- if (fd < 0 || write_index(&result, fd) || close(fd))\n+ hold_lock_file_for_update(&lock, filename, LOCK_DIE_ON_ERROR);\n+ if (write_locked_index(&result, &lock, COMMIT_LOCK))\n die (\"Could not write temporary index to %s\", filename);\n\n discard_index(&result);\n\n> The problem has all signs of a timing issue, which I'm having problems\n> isolating, although simply providing a timeout on the index lock calls\n> seems to fix it.\n\nlockfile has received some updates lately. This commit caught my eyes,\n044b6a9 (lockfile: allow file locking to be retried with a timeout -\n2015-05-11), but this is just a shot in the dark..\n\n> Making git stall instead of die on error allowed me\n> to obtain this backtrace which I suspect will not be particularly\n> useful:\n>\n> #0 0x00000000004c4666 in unable_to_lock_message\n> (path=path@entry=0x1bad940 \".git/index\", err=,\n> buf=buf@entry=0x7ffd3b990900) at lockfile.c:158\n> #1 0x00000000004c46c6 in unable_to_lock_die (path=path@entry=0x1bad940\n> \".git/index\", err=) at lockfile.c:167\n> #2 0x00000000004c480b in hold_lock_file_for_update_timeout\n> (lk=lk@entry=0x1bd7be0, path=0x1bad940 \".git/index\", flags= out>, timeout_ms=timeout_ms@entry=0) at lockfile.c:177\n> #3 0x00000000004e6e2a in hold_lock_file_for_update (flags=1,\n> path=, lk=0x1bd7be0) at lockfile.h:165\n> #4 hold_locked_index (lk=lk@entry=0x1bd7be0,\n> die_on_error=die_on_error@entry=1) at read-cache.c:1411\n> #5 0x0000000000420cb0 in merge_working_tree (old=0x7ffd3b990a20,\n> old=0x7ffd3b990a20, new=0x7ffd3b990a00, new=0x7ffd3b990a00,\n> writeout_error=0x7ffd3b9909c0, opts=0x7ffd3b992a31)\n> at builtin/checkout.c:471\n\nSo it fails at \"git checkout\". That'll give me something to look in\ngit-rebase*.sh. Thanks.\n-- \nDuy\n"},{"id":"270401","messageId":"CAOxFTcx4SsCSbnZ=mv2s7GyDX29gBrZa+uijtbrUTMWjVXXCKg@mail.gmail.com","threadId":"40365","inReplyTo":"CACsJy8CnxGSJT62FRsZP4cD7Az36XGDjJwr+Szddhz42P_hJDg@mail.gmail.com","subject":"Re: git rebase -i failing due to phantom index.lock","fromName":"Giuseppe Bilotta","fromEmail":"giuseppe.bilotta@gmail.com","sentAt":"2015-09-21T16:48:32Z","receivedAt":"2015-09-21T16:48:32Z","isPatch":false,"sender":{"key":"giuseppe.bilotta@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1464?v=4"},"body":"Hello,\n\nOn Thu, Sep 17, 2015 at 2:57 PM, Duy Nguyen wrote:\n> On Thu, Sep 17, 2015 at 3:08 AM, Giuseppe Bilotta\n> wrote:\n>\n>> A somewhat problematic git bisect has allowed me to identify commit\n>> 03b86647722f11ccc321cd7279aa49b811d17cc2 as the first bad commit.\n>\n> That commit is mostly refactoring, but there's one extra lock added in\n> these hunks. Maybe you can revert it and see if it improves anything.\n>\n> diff --git a/builtin/apply.c b/builtin/apply.c\n> index 87439fa..5e13444 100644\n> --- a/builtin/apply.c\n> +++ b/builtin/apply.c\n> @@ -3644,7 +3644,7 @@ static void build_fake_ancestor(struct patch\n> *list, const char *filename)\n> {\n> struct patch *patch;\n> struct index_state result = { NULL };\n> - int fd;\n> + static struct lock_file lock;\n>\n> /* Once we start supporting the reverse patch, it may be\n> * worth showing the new sha1 prefix, but until then...\n> @@ -3682,8 +3682,8 @@ static void build_fake_ancestor(struct patch\n> *list, const char *filename)\n> die (\"Could not add %s to temporary index\", name);\n> }\n>\n> - fd = open(filename, O_WRONLY | O_CREAT, 0666);\n> - if (fd < 0 || write_index(&result, fd) || close(fd))\n> + hold_lock_file_for_update(&lock, filename, LOCK_DIE_ON_ERROR);\n> + if (write_locked_index(&result, &lock, COMMIT_LOCK))\n> die (\"Could not write temporary index to %s\", filename);\n>\n> discard_index(&result);\n\nThis is not trivial to revert because write_index isn't available\nanymore. I'm not sure what I should replace it with.\n\n>> The problem has all signs of a timing issue, which I'm having problems\n>> isolating, although simply providing a timeout on the index lock calls\n>> seems to fix it.\n>\n> lockfile has received some updates lately. This commit caught my eyes,\n> 044b6a9 (lockfile: allow file locking to be retried with a timeout -\n> 2015-05-11), but this is just a shot in the dark..\n\nThe point is that, if I add a timeout to the checkout lock, it works.\nIt works as if something locks it earlier, and the unlock doesn't\nregister quickly enough, so waiting a few tens of milliseconds makes\nit work.\n\n> So it fails at \"git checkout\". That'll give me something to look in\n> git-rebase*.sh. Thanks.\n\n\nFor what it's worth, the problem seems easier to replicate with a very\nlong list of commits than with a short one.\n\nBest regards,\n\n\n-- \nGiuseppe \"Oblomov\" Bilotta\n"}]}