{"thread":{"id":"58111","subject":"t0301-credential-cache test failure on cygwin","startedAt":"2022-07-07T01:50:32Z","lastAt":"2022-07-13T20:35:11Z","messageCount":15,"participants":["Ramsay Jones","Junio C Hamano","Jeff King","Adam Dinwoodie"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"458548","messageId":"9dc3e85f-a532-6cff-de11-1dfb2e4bc6b6@ramsayjones.plus.com","threadId":"58111","inReplyTo":null,"subject":"t0301-credential-cache test failure on cygwin","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsayjones.plus.com","sentAt":"2022-07-07T01:50:21Z","receivedAt":"2022-07-07T01:50:32Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"\nDuring the v2.34.0 development cycle, between -rc1 and -rc2, as a result of an\nupdate to cygwin, test t0301-credential-cache started failing on cygwin (it had\nnever failed before then). This was noted in [1] and later Adam (cygwin git\nmaintainer) confirmed this was due to a change in cygwin (there had been many\nchanges to the 'pipe' code).\n\nGiven that 'ssh-agent' provides all of my 'password' keeping needs, I have to\nadmit that, at the time, I was not overly concerned about the failure. :(\n(Also, it was a cygwin failure, so no need to fix git).\n\nHowever, I had some time to kill tonight, so I decided to take a _quick_ look\nto see if there was something that could be done ... (famous last words).\n\n  $ cd t\n  $ ./t0301-credential-cache.sh -i -v -x\n\n  ...\n\n  expecting success of 0301.13 'socket defaults to ~/.cache/git/credential/socket':\n          test_when_finished \"\n                  git credential-cache exit &&\n                  rmdir -p .cache/git/credential/\n          \" &&\n          test_path_is_missing \"$HOME/.git-credential-cache\" &&\n          test_path_is_socket \"$HOME/.cache/git/credential/socket\"\n  \n  ++ test_when_finished '\n                  git credential-cache exit &&\n                  rmdir -p .cache/git/credential/\n          '\n  ++ test 0 = 0\n  ++ test_cleanup='{\n                  git credential-cache exit &&\n                  rmdir -p .cache/git/credential/\n  \n                  } && (exit \"$eval_ret\"); eval_ret=$?; :'\n  ++ test_path_is_missing '/home/ramsay/git/t/trash directory.t0301-credential-cache/.git-credential-cache'\n  ++ test 1 -ne 1\n  ++ test -e '/home/ramsay/git/t/trash directory.t0301-credential-cache/.git-credential-cache'\n  ++ test_path_is_socket '/home/ramsay/git/t/trash directory.t0301-credential-cache/.cache/git/credential/socket'\n  ++ test -S '/home/ramsay/git/t/trash directory.t0301-credential-cache/.cache/git/credential/socket'\n  ++ git credential-cache exit\n  fatal: read error from cache daemon: Software caused connection abort\n  ++ eval_ret=128\n  ++ :\n  not ok 13 - socket defaults to ~/.cache/git/credential/socket\n  #\n  #               test_when_finished \"\n  #                       git credential-cache exit &&\n  #                       rmdir -p .cache/git/credential/\n  #               \" &&\n  #               test_path_is_missing \"$HOME/.git-credential-cache\" &&\n  #               test_path_is_socket \"$HOME/.cache/git/credential/socket\"\n  #\n  1..13\n  ++ git credential-cache exit\n  ++ exit 128\n  ++ eval_ret=128\n  ++ :\n  $\n\nAround the time of v2.34.0-rc2, problems with the cygwin 'unix-stream-socket'\nemulation caused some t0052-simple-ipc tests to fail (indeed the mailing-list\nthread containing [1] was actually related to that failure). These problems\nwere fixed in commit 974ef7ced2 (simple-ipc: work around issues with Cygwin's\nUnix socket emulation, 2021-11-10).\n\nSo, I was half expecting the failure to be noted at the 'test_path_is_socket'\nline in the test. As you can see, it actually fails in the 'test_when_finished'\nblock with the 'git credential-cache exit', and the failure given as:\n\n  fatal: read error from cache daemon: Software caused connection abort\n\nlooking at builtin/credential-cache.c, lines 40-66, we see:\n\n    40\tstatic int send_request(const char *socket, const struct strbuf *out)\n    41\t{\n    42\t\tint got_data = 0;\n    43\t\tint fd = unix_stream_connect(socket, 0);\n    44\t\n    45\t\tif (fd < 0)\n    46\t\t\treturn -1;\n    47\t\n    48\t\tif (write_in_full(fd, out->buf, out->len) < 0)\n    49\t\t\tdie_errno(\"unable to write to cache daemon\");\n    50\t\tshutdown(fd, SHUT_WR);\n    51\t\n    52\t\twhile (1) {\n    53\t\t\tchar in[1024];\n    54\t\t\tint r;\n    55\t\n    56\t\t\tr = read_in_full(fd, in, sizeof(in));\n    57\t\t\tif (r == 0 || (r < 0 && connection_closed(errno)))\n    58\t\t\t\tbreak;\n    59\t\t\tif (r < 0)\n    60\t\t\t\tdie_errno(\"read error from cache daemon\");\n    61\t\t\twrite_or_die(1, in, r);\n    62\t\t\tgot_data = 1;\n    63\t\t}\n    64\t\tclose(fd);\n    65\t\treturn got_data;\n    66\t}\n\nSo, the read_in_full() call is returning an error, the error code is not\none that connection_closed() recognised and die_errno() is called at\nline #60 (with errno=113).\n\nLooking in the <errno.h> header file, we see:\n\n  #define ECONNABORTED 113        /* Software caused connection abort */\n\nNow, I find this a little odd, since most descriptions of ECONNABORTED\nindicate that it is an error caused by the client but returned to the\nserver from the accept() call. This is definitely not what is happening\nhere. :)\n\nAnyway, the somewhat loose meanings assigned to error codes aside, one\nsimple solution would be:\n\n  diff --git a/builtin/credential-cache.c b/builtin/credential-cache.c\n  index 78c02ad531..84fd513c62 100644\n  --- a/builtin/credential-cache.c\n  +++ b/builtin/credential-cache.c\n  @@ -27,7 +27,7 @@ static int connection_fatally_broken(int error)\n   \n   static int connection_closed(int error)\n   {\n  -\treturn (error == ECONNRESET);\n  +\treturn (error == ECONNRESET) || (error == ECONNABORTED);\n   }\n   \n   static int connection_fatally_broken(int error)\n  --\n\n.. which does, indeed, 'fix' the problem. (Well, it side-steps the problem,\nreally).\n\nHaving deleted the above patch, I now had a look at the server side. Tracing\nout the server execution showed no surprises - everything progressed as one\nwould expect and it 'exit(0)'-ed correctly! The relevant part of the code to\nprocess a client request (in the serve_one_client() function, lines 132-142\nin builtin/credential-cache--daemon.c) looks like:\n\n\telse if (!strcmp(action.buf, \"exit\")) {\n\t\t/*\n\t\t * It's important that we clean up our socket first, and then\n\t\t * signal the client only once we have finished the cleanup.\n\t\t * Calling exit() directly does this, because we clean up in\n\t\t * our atexit() handler, and then signal the client when our\n\t\t * process actually ends, which closes the socket and gives\n\t\t * them EOF.\n\t\t */\n\t\texit(0);\n\t}\n\nNow, the comment doesn't make clear to me why \"it's important that we clean\nup our socket first\" and, indeed, whether 'socket' refers to the socket\ndescriptor or the socket file. In the past, all of my unix-stream-socket\nservers have closed the socket descriptor and then unlink()-ed the socket\nfile before exit(), with no 'atexit' calls in sight (lightly cribbed from a\n30+ years old Unix Network programming book by Stevens - or was it the Comer\nbook - or maybe the Comer and Stevens book - I forget!).\n\nThe C standard (see C11 7.22.4.4) says that the 'exit' function first calls\nall functions registered by 'atexit', then all open streams with unwritten\nbuffered data are flushed, all open streams are closed, and all files created\nby the 'tmpfile' function are removed.\n\nThe C standard can only refer to 'FILE *' streams, but POSIX says practically\nthe same, but in addition (see 'Consequences of Process Termination'), that\n\"All of the file descriptors, directory streams, conversion descriptors,\nand message catalog descriptors open in the calling process shall be closed.\"\n\nNote that the above descriptions do not nail down the _exact_ ordering of\ncertain cleanup operations. (eg do the file descriptors get closed in a\nlow->high, high->low or random order)? So, if the cleanup operations can\nfail, depending on the order of operations, then the results could be\nundefined.\n\nAnyway, I started playing around with flushing/closing of 'FILE *' streams\nbefore the 'exit' call, to change the order, relative to the socket-file\ndeletion in the 'atexit' function (or the closing of the listen-socket\ndescriptor, come to that). In particular, I found that if I were to close\nthe 'in'put stream, then the client would receive an EOF and exit normally\n(ie no error return from read_in_full() above).\n\n[fclose(in); fclose(out) also works, but fclose(out) on its own does not.\nfflush() in various combinations did not work at all].\n\nSo, the following patch also provides a 'fix' for this issue (although it\nwould require a change to the comment for a _real_ patch):\n\n  diff --git a/builtin/credential-cache--daemon.c b/builtin/credential-cache--daemon.c\n  index 4c6c89ab0d..556393498f 100644\n  --- a/builtin/credential-cache--daemon.c\n  +++ b/builtin/credential-cache--daemon.c\n  @@ -138,6 +138,7 @@ static void serve_one_client(FILE *in, FILE *out)\n   \t\t * process actually ends, which closes the socket and gives\n   \t\t * them EOF.\n   \t\t */\n  +\t\tfclose(in);\n   \t\texit(0);\n   \t}\n   \telse if (!strcmp(action.buf, \"erase\"))\n  --\n\nHaving noticed that the 'timeout' test was not failing, I decided to try\nmaking the 'action=exit' code-path behave more like the timeout code, as\nfar as exiting the server is concerned. Indeed, you might ask why the\ntimeout code doesn't just 'exit(0)' as well ...\n\nAnyway, the following patch does that, and it also provides a 'fix' for this\nissue!\n\n  diff --git a/builtin/credential-cache--daemon.c b/builtin/credential-cache--daemon.c\n  index 4c6c89ab0d..fb9b1e04a6 100644\n  --- a/builtin/credential-cache--daemon.c\n  +++ b/builtin/credential-cache--daemon.c\n  @@ -114,11 +114,12 @@ static int read_request(FILE *fh, struct credential *c,\n   \treturn 0;\n   }\n   \n  -static void serve_one_client(FILE *in, FILE *out)\n  +static int serve_one_client(FILE *in, FILE *out)\n   {\n   \tstruct credential c = CREDENTIAL_INIT;\n   \tstruct strbuf action = STRBUF_INIT;\n   \tint timeout = -1;\n  +\tint serve = 1; /* ie continue to serve clients */\n   \n   \tif (read_request(in, &c, &action, &timeout) < 0)\n   \t\t/* ignore error */ ;\n  @@ -130,15 +131,8 @@ static void serve_one_client(FILE *in, FILE *out)\n   \t\t}\n   \t}\n   \telse if (!strcmp(action.buf, \"exit\")) {\n  -\t\t/*\n  -\t\t * It's important that we clean up our socket first, and then\n  -\t\t * signal the client only once we have finished the cleanup.\n  -\t\t * Calling exit() directly does this, because we clean up in\n  -\t\t * our atexit() handler, and then signal the client when our\n  -\t\t * process actually ends, which closes the socket and gives\n  -\t\t * them EOF.\n  -\t\t */\n  -\t\texit(0);\n  +\t\t/* stop serving clients */\n  +\t\tserve = 0;\n   \t}\n   \telse if (!strcmp(action.buf, \"erase\"))\n   \t\tremove_credential(&c);\n  @@ -157,6 +151,7 @@ static void serve_one_client(FILE *in, FILE *out)\n   \n   \tcredential_clear(&c);\n   \tstrbuf_release(&action);\n  +\treturn serve;\n   }\n   \n   static int serve_cache_loop(int fd)\n  @@ -179,6 +174,7 @@ static int serve_cache_loop(int fd)\n   \tif (pfd.revents & POLLIN) {\n   \t\tint client, client2;\n   \t\tFILE *in, *out;\n  +\t\tint serve;\n   \n   \t\tclient = accept(fd, NULL, NULL);\n   \t\tif (client < 0) {\n  @@ -194,9 +190,10 @@ static int serve_cache_loop(int fd)\n   \n   \t\tin = xfdopen(client, \"r\");\n   \t\tout = xfdopen(client2, \"w\");\n  -\t\tserve_one_client(in, out);\n  +\t\tserve = serve_one_client(in, out);\n   \t\tfclose(in);\n   \t\tfclose(out);\n  +\t\treturn serve;\n   \t}\n   \treturn 1;\n   }\n  -- \n\n[Note the 'serve' variable was the least objectionable name I could come up\nwith, but it could probably be improved!]\n\nSo, we now have three patches which 'fix' the issue. What does this tell us?\nWell, not an awful lot! ;-)\n\nI repeat, until I updated to v3.3.2 of cygwin, none of these patches were\nrequired, since the test did not fail. In order to progress, someone needs\nto bisect the commits in the cygwin git repository to find the commit which\nchanged the behaviour of the unix stream socket emulation.\n\nI had a look at the cygwin gitweb site [2], and started reading the commit\nmessages from 'cygwin-3_3_2-release' tag, but nothing stood out. Also, I did\nnot note (in [1]) which version of cygwin I updated _from_, so I don't know\nwhere to stop! (Sometimes I update often, sometimes not for 6-9 months!\nI have a vague feeling that I was in a reasonably often update tempo, so\nthere may be no need to go too far back).\n\n[Also, I spent loads of time reading the code [3] to the 'fhandler_socket_unix'\nclass, only to notice that it is conditional on the '__WITH_AF_UNIX'\npre-processor variable. I can't find any code which #defines it, so ...]\n\n[Also, in [1] I noted that the v3.3.2 update added an hour to the runtime\nof the testsuite. If I run the test something like:\n\n  $ export GIT_TEST_CHAIN_LINT=0\n  $ export TEST_NO_MALLOC_CHECK=yes\n  $ make test >test-out-2-37-rel 2>&1\n\n.. then I can get back about 45min of that hour!\n\n(I also have DEFAULT_TEST_TARGET=prove and GIT_PROVE_OPTS='--timer' in my\nconfig.mak)]\n\nUnfortunately, I can't be the one to investigate the change to cygwin, so I\nwill have to leave that to someone with the necessary knowledge/skill with\nthe cygwin codebase. (The last time I built/debugged the cygwin .dll, the\nrepo was in cvs! Yes, many, many years ago. If I remember correctly, building\nthe .dll wasn't really the problem - it was the testing that was the *huge*\nPITA, especially if you have services running).\n\nIt seems unlikely, but it is possible (despite what I said earlier), that the\nfault lies with git - it could be relying on implementation behaviour. Until\nwe know how cygwin changed, we will not be able to determine a suitable fix.\n\nHmm, I will send the three RFC patches to the list, just to make it slightly\neasier for someone to try them out, if they wish.\n\nSorry for not looking at this earlier and for not finding a suitable fix.\n\nIt's getting late ...\n\n\nATB,\nRamsay Jones\n\n[1] https://lore.kernel.org/git/02b6cfa8-bd0a-275d-fce0-a3a9f316ded3@ramsayjones.plus.com/\n[2] https://cygwin.com/git/newlib-cygwin.git\n[3] https://cygwin.com/git/?p=newlib-cygwin.git;a=blob;f=winsup/cygwin/fhandler_socket_unix.cc;h=8abb581b999e79ad71ddd19a1557e2be0fd9d757;hb=5cc4b92c25af1af9250e4498e60943fcc82b7487\n\n\n"},{"id":"458555","messageId":"xmqqtu7t30uv.fsf@gitster.g","threadId":"58111","inReplyTo":"9dc3e85f-a532-6cff-de11-1dfb2e4bc6b6@ramsayjones.plus.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2022-07-07T06:15:04Z","receivedAt":"2022-07-07T06:15:13Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Ramsay Jones <ramsay@ramsayjones.plus.com> writes:\n\n> However, I had some time to kill tonight, so I decided to take a _quick_ look\n> to see if there was something that could be done ... (famous last words).\n> ...\n>   diff --git a/builtin/credential-cache.c b/builtin/credential-cache.c\n>   index 78c02ad531..84fd513c62 100644\n>   --- a/builtin/credential-cache.c\n>   +++ b/builtin/credential-cache.c\n>   @@ -27,7 +27,7 @@ static int connection_fatally_broken(int error)\n>    \n>    static int connection_closed(int error)\n>    {\n>   -\treturn (error == ECONNRESET);\n>   +\treturn (error == ECONNRESET) || (error == ECONNABORTED);\n>    }\n\nThis feels like papering over the problem.\n\n> Having noticed that the 'timeout' test was not failing, I decided to try\n> making the 'action=exit' code-path behave more like the timeout code, as\n> far as exiting the server is concerned. Indeed, you might ask why the\n> timeout code doesn't just 'exit(0)' as well ...\n>\n> Anyway, the following patch does that, and it also provides a 'fix' for this\n> issue!\n\nIf this codepath was written like this (i.e. [PATCH 1C]) from the\nbeginning, I would have found it very sensible (i.e. instead of\ncaling exit() in the middle of the infinite client serving loop,\nexiting the loop cleanly is easier to follow and maintain), even if\nwe didn't know the issue on Cygwin you investigated.\n\n"},{"id":"458566","messageId":"4529b11a-e514-6676-f427-ffaec484e8f1@ramsayjones.plus.com","threadId":"58111","inReplyTo":"xmqqtu7t30uv.fsf@gitster.g","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsayjones.plus.com","sentAt":"2022-07-07T15:17:08Z","receivedAt":"2022-07-07T15:17:22Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"\n[\nJeff: sorry for not CC:-ing you on the original email - I had intended\nto do just that, but forgot! :(\n\nSee: https://lore.kernel.org/git/9dc3e85f-a532-6cff-de11-1dfb2e4bc6b6@ramsayjones.plus.com/\n]\n\nOn 07/07/2022 07:15, Junio C Hamano wrote:\n> Ramsay Jones <ramsay@ramsayjones.plus.com> writes:\n> \n>> However, I had some time to kill tonight, so I decided to take a _quick_ look\n>> to see if there was something that could be done ... (famous last words).\n>> ...\n>>   diff --git a/builtin/credential-cache.c b/builtin/credential-cache.c\n>>   index 78c02ad531..84fd513c62 100644\n>>   --- a/builtin/credential-cache.c\n>>   +++ b/builtin/credential-cache.c\n>>   @@ -27,7 +27,7 @@ static int connection_fatally_broken(int error)\n>>    \n>>    static int connection_closed(int error)\n>>    {\n>>   -\treturn (error == ECONNRESET);\n>>   +\treturn (error == ECONNRESET) || (error == ECONNABORTED);\n>>    }\n> \n> This feels like papering over the problem.\n\nAgreed, ... which is what I really meant by \"(Well, it side-steps the\nproblem, really).\"\n\n>> Having noticed that the 'timeout' test was not failing, I decided to try\n>> making the 'action=exit' code-path behave more like the timeout code, as\n>> far as exiting the server is concerned. Indeed, you might ask why the\n>> timeout code doesn't just 'exit(0)' as well ...\n>>\n>> Anyway, the following patch does that, and it also provides a 'fix' for this\n>> issue!\n> \n> If this codepath was written like this (i.e. [PATCH 1C]) from the\n> beginning, I would have found it very sensible (i.e. instead of\n> caling exit() in the middle of the infinite client serving loop,\n> exiting the loop cleanly is easier to follow and maintain), even if\n> we didn't know the issue on Cygwin you investigated.\n\nYep, apart from the variable name, I quite like the approach taken by\nthe 1C patch.\n\nAll three of these patches were really just \"showing my working\" and\nallowing anyone to \"follow along\" without the hassle of trying to\nscrape the diffs from the email.\n\nAs I said, I don't think we can determine a suitable fix without first\nfinding the cygwin commit which caused this test failure. But if we\ncan't determine this, for whatever reason, then I would favour a patch\nto git based on the 1C patch. (Writing the commit message to justify the\nchange, without mentioning this cygwin issue, may be more challenging! :)\n\nAlso, I would like to understand why the code is written as it is\ncurrently. I'm sure there must be a good reason - I just don't know\nwhat it is! I suspect (ie I'm guessing), it has something to do with\noperating in a high contention context [TOCTOU on socket?] ... dunno. ;-)\n\nATB,\nRamsay Jones\n\n\n"},{"id":"458586","messageId":"YsciDznU2TqzCXP4@coredump.intra.peff.net","threadId":"58111","inReplyTo":"9dc3e85f-a532-6cff-de11-1dfb2e4bc6b6@ramsayjones.plus.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2022-07-07T18:12:31Z","receivedAt":"2022-07-07T18:12:37Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Jul 07, 2022 at 02:50:21AM +0100, Ramsay Jones wrote:\n\n> Having deleted the above patch, I now had a look at the server side. Tracing\n> out the server execution showed no surprises - everything progressed as one\n> would expect and it 'exit(0)'-ed correctly! The relevant part of the code to\n> process a client request (in the serve_one_client() function, lines 132-142\n> in builtin/credential-cache--daemon.c) looks like:\n> \n> \telse if (!strcmp(action.buf, \"exit\")) {\n> \t\t/*\n> \t\t * It's important that we clean up our socket first, and then\n> \t\t * signal the client only once we have finished the cleanup.\n> \t\t * Calling exit() directly does this, because we clean up in\n> \t\t * our atexit() handler, and then signal the client when our\n> \t\t * process actually ends, which closes the socket and gives\n> \t\t * them EOF.\n> \t\t */\n> \t\texit(0);\n> \t}\n> \n> Now, the comment doesn't make clear to me why \"it's important that we clean\n> up our socket first\" and, indeed, whether 'socket' refers to the socket\n> descriptor or the socket file. In the past, all of my unix-stream-socket\n> servers have closed the socket descriptor and then unlink()-ed the socket\n> file before exit(), with no 'atexit' calls in sight (lightly cribbed from a\n> 30+ years old Unix Network programming book by Stevens - or was it the Comer\n> book - or maybe the Comer and Stevens book - I forget!).\n\nThat comment refers to the socket file. If we close the handle to the\nclient before we clean up the socket file, then the client may finish\nwhile the socket file is still there. So anybody expecting that:\n\n  git credential-cache exit\n\nis a sequencing operation will be fooled. One obvious thing is:\n\n  git credential-cache exit\n  git credential-cache store <some-cred\n\nwhich is now racy; the second command may try to contact the socket for\nthe exiting daemon. It might actually handle that gracefully (because\nthe server wouldn't actually accept()) but I didn't check. But another\nexample, and the one that motivated that comment is:\n\n  git credential-cache exit\n  test_path_is_missing $HOME/.git-credential-cache/socket\n\nwhich is exactly what our tests do. ;) See the discussion around here:\n\n  https://lore.kernel.org/git/20160318061201.GA28102@sigill.intra.peff.net/\n\nA few messages up we even discuss adding an fclose(). :)\n\n> The C standard (see C11 7.22.4.4) says that the 'exit' function first calls\n> all functions registered by 'atexit', then all open streams with unwritten\n> buffered data are flushed, all open streams are closed, and all files created\n> by the 'tmpfile' function are removed.\n\nRight. That's exactly the order we're relying on: our atexit cleans up\nthe socket and _then_ the descriptor to the client is closed.\n\nI think we could actually just call delete_tempfile() explicitly. Back\nwhen the code was originally written, that would require making sure our\natexit() handler didn't do a double-cleanup, but these days it uses the\ntempfile code, which I believe does the right thing.\n\nI think that still wouldn't solve your cygwin problem, though; from the\nclient perspective the behavior would be the same.\n\n> Anyway, I started playing around with flushing/closing of 'FILE *' streams\n> before the 'exit' call, to change the order, relative to the socket-file\n> deletion in the 'atexit' function (or the closing of the listen-socket\n> descriptor, come to that). In particular, I found that if I were to close\n> the 'in'put stream, then the client would receive an EOF and exit normally\n> (ie no error return from read_in_full() above).\n\nRight, but now you've introduced the race discussed above.\n\n> Having noticed that the 'timeout' test was not failing, I decided to try\n> making the 'action=exit' code-path behave more like the timeout code, as\n> far as exiting the server is concerned.\n\nI think this introduces a similar race.\n\n> Indeed, you might ask why the timeout code doesn't just 'exit(0)' as well ...\n\nIt doesn't matter there, because there's no client expecting us to exit.\nSo the sequence of cleaning up our socket vs hanging up on the client\ndoesn't matter. And indeed, it's unlikely to even _have_ a client here,\nas they'd have to connect and do their business right as our final\ncredential was hitting its expiration.\n\n> So, we now have three patches which 'fix' the issue. What does this tell us?\n> Well, not an awful lot! ;-)\n\nOf the three, I actually like the client-side one to check errno the\nbest. The client is mostly \"best effort\". If it can't talk to the daemon\nfor whatever reason, then it becomes a noop (there is nothing it can\nretrieve from the cache, and if it's trying to write, then oh well, the\ncached value was immediately expired!).\n\nSo one could argue that _every_ read error should be silently ignored.\nCalling die_errno() is mostly a nicety for debugging a broken setup, but\nin normal use, the outcome is the same either way (and Git will\ncertainly ignore the exit code credential-cache anyway). I prefer the\n\"ignore known harmless errors\" approach, possibly because I am often the\none debugging. ;) If ECONNABORTED is a harmless error we see in\npractice, I don't mind adding it to the list (under the same rationale\nas the current ECONNRESET that is there).\n\n-Peff\n"},{"id":"458588","messageId":"YscjxOWqf7GUvnps@coredump.intra.peff.net","threadId":"58111","inReplyTo":"4529b11a-e514-6676-f427-ffaec484e8f1@ramsayjones.plus.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2022-07-07T18:19:48Z","receivedAt":"2022-07-07T18:19:52Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Jul 07, 2022 at 04:17:08PM +0100, Ramsay Jones wrote:\n\n> > If this codepath was written like this (i.e. [PATCH 1C]) from the\n> > beginning, I would have found it very sensible (i.e. instead of\n> > caling exit() in the middle of the infinite client serving loop,\n> > exiting the loop cleanly is easier to follow and maintain), even if\n> > we didn't know the issue on Cygwin you investigated.\n> \n> Yep, apart from the variable name, I quite like the approach taken by\n> the 1C patch.\n> [...]\n> Also, I would like to understand why the code is written as it is\n> currently. I'm sure there must be a good reason - I just don't know\n> what it is! I suspect (ie I'm guessing), it has something to do with\n> operating in a high contention context [TOCTOU on socket?] ... dunno. ;-)\n\nI wrote a longer reply in the thread, but just to be clear here: your 1C\nwill indeed introduce a race.\n\nIMHO it is not worth switching away from the current code which calls\nexit() to return up the stock. But if you wanted to do so without\nintroducing a race, I think you could call delete_tempfile() before\nclosing any streams, like this (on top of your 1C):\n\ndiff --git a/builtin/credential-cache--daemon.c b/builtin/credential-cache--daemon.c\nindex fb9b1e04a6..9b9cc1b70e 100644\n--- a/builtin/credential-cache--daemon.c\n+++ b/builtin/credential-cache--daemon.c\n@@ -131,6 +131,7 @@ static int serve_one_client(FILE *in, FILE *out)\n \t\t}\n \t}\n \telse if (!strcmp(action.buf, \"exit\")) {\n+\t\tdelete_tempfile(&socket_file);\n \t\t/* stop serving clients */\n \t\tserve = 0;\n \t}\n\nbut you'd have to make the socket_file struct globally available. And of\ncourse it does not fix your cygwin problem, which I believe is mutually\nexclusive with keeping the race-free ordering. ;)\n\n-Peff\n"},{"id":"458589","messageId":"xmqqsfnczslt.fsf@gitster.g","threadId":"58111","inReplyTo":"YsciDznU2TqzCXP4@coredump.intra.peff.net","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2022-07-07T18:26:54Z","receivedAt":"2022-07-07T18:27:00Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King <peff@peff.net> writes:\n\n> Of the three, I actually like the client-side one to check errno the\n> best. The client is mostly \"best effort\". If it can't talk to the daemon\n> for whatever reason, then it becomes a noop (there is nothing it can\n> retrieve from the cache, and if it's trying to write, then oh well, the\n> cached value was immediately expired!).\n>\n> So one could argue that _every_ read error should be silently ignored.\n> Calling die_errno() is mostly a nicety for debugging a broken setup, but\n> in normal use, the outcome is the same either way (and Git will\n> certainly ignore the exit code credential-cache anyway). I prefer the\n> \"ignore known harmless errors\" approach, possibly because I am often the\n> one debugging. ;) If ECONNABORTED is a harmless error we see in\n> practice, I don't mind adding it to the list (under the same rationale\n> as the current ECONNRESET that is there).\n\nWith the issue of race clearly explained, I agree that this would be\nthe best solution for this issue.\n\nThanks.\n"},{"id":"458591","messageId":"Yscl/Jx4g74RwkCK@coredump.intra.peff.net","threadId":"58111","inReplyTo":"4529b11a-e514-6676-f427-ffaec484e8f1@ramsayjones.plus.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2022-07-07T18:29:16Z","receivedAt":"2022-07-07T18:32:22Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Jul 07, 2022 at 04:17:08PM +0100, Ramsay Jones wrote:\n\n> Also, I would like to understand why the code is written as it is\n> currently. I'm sure there must be a good reason - I just don't know\n> what it is! I suspect (ie I'm guessing), it has something to do with\n> operating in a high contention context [TOCTOU on socket?] ... dunno. ;-)\n\nBy the way, I was slightly surprised you did not find the explanation in\nthe commit history. A blame[1] of credential-cache--daemon.c shows that\nthe comment was added by 7d5e9c9849 (credential-cache--daemon: clarify\n\"exit\" action semantics, 2016-03-18) which mentions the race in the\ntests. And then searching for that commit message in the list yields the\nthread I linked earlier with more context[2].\n\nI mention this not as a criticism, because your digging for backstory\nwas otherwise quite thorough. It's only _because_ it was so thorough\nthat I was surprised you didn't find that commit. ;) So I offer it only\nas a suggestion for future digging.\n\n-Peff\n\n[1] Likewise this works:\n\n       git log --follow -S'important that we clean up' builtin/credential-cache--daemon.c\n\n    but the --follow is necessary because of the rename when it became a\n    builtin. It's cool that \"blame\" handles this seamlessly. :)\n\n[2] Finding the original patch on the list is my go-to trick when a\n    commit message hasn't sufficiently explained things. I know Junio\n    was for a while (is still?) kept a git-notes mapping of commits to\n    emails. In practice, I usually just do a manual search for a few\n    unique-looking phrases from the commit message. That should be\n    pretty easy with lore these days, though I do it with a local\n    archive indexed by notmuch.\n\n-Peff\n"},{"id":"458598","messageId":"fa951e27-7b7b-848c-01c8-f706f97d87e7@ramsayjones.plus.com","threadId":"58111","inReplyTo":"Yscl/Jx4g74RwkCK@coredump.intra.peff.net","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsayjones.plus.com","sentAt":"2022-07-07T19:14:31Z","receivedAt":"2022-07-07T19:17:41Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"\n\nOn 07/07/2022 19:29, Jeff King wrote:\n> On Thu, Jul 07, 2022 at 04:17:08PM +0100, Ramsay Jones wrote:\n> \n>> Also, I would like to understand why the code is written as it is\n>> currently. I'm sure there must be a good reason - I just don't know\n>> what it is! I suspect (ie I'm guessing), it has something to do with\n>> operating in a high contention context [TOCTOU on socket?] ... dunno. ;-)\n> \n> By the way, I was slightly surprised you did not find the explanation in\n> the commit history. A blame[1] of credential-cache--daemon.c shows that\n> the comment was added by 7d5e9c9849 (credential-cache--daemon: clarify\n> \"exit\" action semantics, 2016-03-18) which mentions the race in the\n> tests. And then searching for that commit message in the list yields the\n> thread I linked earlier with more context[2].\n\nHeh, just 10min before I read your previous email (er, actually your\nprevious, previous email) I found commit 7d5e9c9849 (credential-cache--daemon:\nclarify \"exit\" action semantics, 2016-03-18). I hadn't had time to dig\nany further yet (as usual I'm trying to do 3 things at the same time).\n\nWhat can I say? It was nearly 3am and I wanted to go bed. It took nearly\n50min just to write the email. This was just a _quick_ look remember! ;-)\n\nSorry!\n\nATB,\nRamsay Jones\n\n\n"},{"id":"458600","messageId":"ee1aa051-1c01-f525-e925-a21e63682531@ramsayjones.plus.com","threadId":"58111","inReplyTo":"YsciDznU2TqzCXP4@coredump.intra.peff.net","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsayjones.plus.com","sentAt":"2022-07-07T19:59:17Z","receivedAt":"2022-07-07T19:59:26Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"\n\nOn 07/07/2022 19:12, Jeff King wrote:\n> On Thu, Jul 07, 2022 at 02:50:21AM +0100, Ramsay Jones wrote:\n> \n>> Having deleted the above patch, I now had a look at the server side. Tracing\n>> out the server execution showed no surprises - everything progressed as one\n>> would expect and it 'exit(0)'-ed correctly! The relevant part of the code to\n>> process a client request (in the serve_one_client() function, lines 132-142\n>> in builtin/credential-cache--daemon.c) looks like:\n>>\n>> \telse if (!strcmp(action.buf, \"exit\")) {\n>> \t\t/*\n>> \t\t * It's important that we clean up our socket first, and then\n>> \t\t * signal the client only once we have finished the cleanup.\n>> \t\t * Calling exit() directly does this, because we clean up in\n>> \t\t * our atexit() handler, and then signal the client when our\n>> \t\t * process actually ends, which closes the socket and gives\n>> \t\t * them EOF.\n>> \t\t */\n>> \t\texit(0);\n>> \t}\n>>\n>> Now, the comment doesn't make clear to me why \"it's important that we clean\n>> up our socket first\" and, indeed, whether 'socket' refers to the socket\n>> descriptor or the socket file. In the past, all of my unix-stream-socket\n>> servers have closed the socket descriptor and then unlink()-ed the socket\n>> file before exit(), with no 'atexit' calls in sight (lightly cribbed from a\n>> 30+ years old Unix Network programming book by Stevens - or was it the Comer\n>> book - or maybe the Comer and Stevens book - I forget!).\n> \n> That comment refers to the socket file. If we close the handle to the\n> client before we clean up the socket file, then the client may finish\n> while the socket file is still there. So anybody expecting that:\n> \n>   git credential-cache exit\n> \n> is a sequencing operation will be fooled. One obvious thing is:\n> \n>   git credential-cache exit\n>   git credential-cache store <some-cred\n> \n> which is now racy; the second command may try to contact the socket for\n> the exiting daemon. It might actually handle that gracefully (because\n> the server wouldn't actually accept()) but I didn't check. But another\n> example, and the one that motivated that comment is:\n> \n>   git credential-cache exit\n>   test_path_is_missing $HOME/.git-credential-cache/socket\n> \n> which is exactly what our tests do. ;) See the discussion around here:\n> \n>   https://lore.kernel.org/git/20160318061201.GA28102@sigill.intra.peff.net/\n\nI have now read (much) of that thread and it makes sense now. (Yes, I probably\nshould have postponed sending the email until after researching some more today;\nlesson learned).\n\n[snip]\n>> So, we now have three patches which 'fix' the issue. What does this tell us?\n>> Well, not an awful lot! ;-)\n> \n> Of the three, I actually like the client-side one to check errno the\n> best. The client is mostly \"best effort\". If it can't talk to the daemon\n> for whatever reason, then it becomes a noop (there is nothing it can\n> retrieve from the cache, and if it's trying to write, then oh well, the\n> cached value was immediately expired!).\n> \n> So one could argue that _every_ read error should be silently ignored.\n> Calling die_errno() is mostly a nicety for debugging a broken setup, but\n> in normal use, the outcome is the same either way (and Git will\n> certainly ignore the exit code credential-cache anyway). I prefer the\n> \"ignore known harmless errors\" approach, possibly because I am often the\n> one debugging. ;) If ECONNABORTED is a harmless error we see in\n> practice, I don't mind adding it to the list (under the same rationale\n> as the current ECONNRESET that is there).\n\nYes, I was going to ask about ECONNRESET ... heh, no I'm kidding! :)\n\nYeah, if we can't determine the reason for cygwin changing behaviour\nhere (and fix it in cygwin), then this is probably the simplest solution.\n\nATB,\nRamsay Jones\n\n\n"},{"id":"458754","messageId":"CA+kUOakjnOxs_FGojdZXaiaY4+68pvyBHsbue+AQHp7PLXqNJw@mail.gmail.com","threadId":"58111","inReplyTo":"4529b11a-e514-6676-f427-ffaec484e8f1@ramsayjones.plus.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Adam Dinwoodie","fromEmail":"adam@dinwoodie.org","sentAt":"2022-07-11T07:49:55Z","receivedAt":"2022-07-11T07:50:04Z","isPatch":false,"sender":{"key":"adam@dinwoodie.org","avatar":"https://avatars.githubusercontent.com/u/1397507?v=4"},"body":"On Thu, 7 Jul 2022 at 16:17, Ramsay Jones <ramsay@ramsayjones.plus.com> wrote:\n> [\n> Jeff: sorry for not CC:-ing you on the original email - I had intended\n> to do just that, but forgot! :(\n>\n> See: https://lore.kernel.org/git/9dc3e85f-a532-6cff-de11-1dfb2e4bc6b6@ramsayjones.plus.com/\n> ]\n>\n> On 07/07/2022 07:15, Junio C Hamano wrote:\n> > Ramsay Jones <ramsay@ramsayjones.plus.com> writes:\n> >\n> >> However, I had some time to kill tonight, so I decided to take a _quick_ look\n> >> to see if there was something that could be done ... (famous last words).\n> >> ...\n> >>   diff --git a/builtin/credential-cache.c b/builtin/credential-cache.c\n> >>   index 78c02ad531..84fd513c62 100644\n> >>   --- a/builtin/credential-cache.c\n> >>   +++ b/builtin/credential-cache.c\n> >>   @@ -27,7 +27,7 @@ static int connection_fatally_broken(int error)\n> >>  \n> >>    static int connection_closed(int error)\n> >>    {\n> >>   -  return (error == ECONNRESET);\n> >>   +  return (error == ECONNRESET) || (error == ECONNABORTED);\n> >>    }\n> >\n> > This feels like papering over the problem.\n>\n> Agreed, ... which is what I really meant by \"(Well, it side-steps the\n> problem, really).\"\n>\n> >> Having noticed that the 'timeout' test was not failing, I decided to try\n> >> making the 'action=exit' code-path behave more like the timeout code, as\n> >> far as exiting the server is concerned. Indeed, you might ask why the\n> >> timeout code doesn't just 'exit(0)' as well ...\n> >>\n> >> Anyway, the following patch does that, and it also provides a 'fix' for this\n> >> issue!\n> >\n> > If this codepath was written like this (i.e. [PATCH 1C]) from the\n> > beginning, I would have found it very sensible (i.e. instead of\n> > caling exit() in the middle of the infinite client serving loop,\n> > exiting the loop cleanly is easier to follow and maintain), even if\n> > we didn't know the issue on Cygwin you investigated.\n>\n> Yep, apart from the variable name, I quite like the approach taken by\n> the 1C patch.\n>\n> All three of these patches were really just \"showing my working\" and\n> allowing anyone to \"follow along\" without the hassle of trying to\n> scrape the diffs from the email.\n>\n> As I said, I don't think we can determine a suitable fix without first\n> finding the cygwin commit which caused this test failure. But if we\n> can't determine this, for whatever reason, then I would favour a patch\n> to git based on the 1C patch. (Writing the commit message to justify the\n> change, without mentioning this cygwin issue, may be more challenging! :)\n\nI've been trying to dig into this; I've essentially never played with\nthe code for Cygwin itself until now, but I suspect I'm probably one of\nthe best-placed folks to actually do that investigation.\n\nUnfortunately, I've gone as far back as 18 December 2020 in the code for\nthe Cygwin DLL itself, and I'm still seeing t0301 failing in exactly the\nsame way.  There's a few possible explanations for that, but my guess is\neither (a) the issue isn't in the Cygwin DLL itself but in some other\nlibrary that was updated around the same time, or (b) I'm not managing\nas clean a build as I'm aiming for, and my builds of the old Cygwin\ncommits are being polluted by something in my current environment.\n\nEither way I think I can make progress: my next step is to (temporarily)\ngive up on bisecting by commit in the repository that tracks the Cygwin\nDLL, and instead bisect by time using the Cygwin Time Machine, which\nshould let me get an entire Cygwin environment as it would have been at\nsome point in the past.\n\n> Also, I would like to understand why the code is written as it is\n> currently. I'm sure there must be a good reason - I just don't know\n> what it is! I suspect (ie I'm guessing), it has something to do with\n> operating in a high contention context [TOCTOU on socket?] ... dunno. ;-)\n>\n> ATB,\n> Ramsay Jones\n"},{"id":"458788","messageId":"CA+kUOak29RkU-ooMgOz8yCg9-q6vb1VfdP8_VLay_V650ttwjA@mail.gmail.com","threadId":"58111","inReplyTo":"CA+kUOakjnOxs_FGojdZXaiaY4+68pvyBHsbue+AQHp7PLXqNJw@mail.gmail.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Adam Dinwoodie","fromEmail":"adam@dinwoodie.org","sentAt":"2022-07-11T13:39:00Z","receivedAt":"2022-07-11T13:39:13Z","isPatch":false,"sender":{"key":"adam@dinwoodie.org","avatar":"https://avatars.githubusercontent.com/u/1397507?v=4"},"body":"On Mon, 11 Jul 2022 at 08:50, Adam Dinwoodie <adam@dinwoodie.org> wrote:\n>\n> On Thu, 7 Jul 2022 at 16:17, Ramsay Jones <ramsay@ramsayjones.plus.com> wrote:\n> > [\n> > Jeff: sorry for not CC:-ing you on the original email - I had intended\n> > to do just that, but forgot! :(\n> >\n> > See: https://lore.kernel.org/git/9dc3e85f-a532-6cff-de11-1dfb2e4bc6b6@ramsayjones.plus.com/\n> > ]\n> >\n> > On 07/07/2022 07:15, Junio C Hamano wrote:\n> > > Ramsay Jones <ramsay@ramsayjones.plus.com> writes:\n> > >\n> > >> However, I had some time to kill tonight, so I decided to take a _quick_ look\n> > >> to see if there was something that could be done ... (famous last words).\n> > >> ...\n> > >>   diff --git a/builtin/credential-cache.c b/builtin/credential-cache.c\n> > >>   index 78c02ad531..84fd513c62 100644\n> > >>   --- a/builtin/credential-cache.c\n> > >>   +++ b/builtin/credential-cache.c\n> > >>   @@ -27,7 +27,7 @@ static int connection_fatally_broken(int error)\n> > >>\n> > >>    static int connection_closed(int error)\n> > >>    {\n> > >>   -  return (error == ECONNRESET);\n> > >>   +  return (error == ECONNRESET) || (error == ECONNABORTED);\n> > >>    }\n> > >\n> > > This feels like papering over the problem.\n> >\n> > Agreed, ... which is what I really meant by \"(Well, it side-steps the\n> > problem, really).\"\n> >\n> > >> Having noticed that the 'timeout' test was not failing, I decided to try\n> > >> making the 'action=exit' code-path behave more like the timeout code, as\n> > >> far as exiting the server is concerned. Indeed, you might ask why the\n> > >> timeout code doesn't just 'exit(0)' as well ...\n> > >>\n> > >> Anyway, the following patch does that, and it also provides a 'fix' for this\n> > >> issue!\n> > >\n> > > If this codepath was written like this (i.e. [PATCH 1C]) from the\n> > > beginning, I would have found it very sensible (i.e. instead of\n> > > caling exit() in the middle of the infinite client serving loop,\n> > > exiting the loop cleanly is easier to follow and maintain), even if\n> > > we didn't know the issue on Cygwin you investigated.\n> >\n> > Yep, apart from the variable name, I quite like the approach taken by\n> > the 1C patch.\n> >\n> > All three of these patches were really just \"showing my working\" and\n> > allowing anyone to \"follow along\" without the hassle of trying to\n> > scrape the diffs from the email.\n> >\n> > As I said, I don't think we can determine a suitable fix without first\n> > finding the cygwin commit which caused this test failure. But if we\n> > can't determine this, for whatever reason, then I would favour a patch\n> > to git based on the 1C patch. (Writing the commit message to justify the\n> > change, without mentioning this cygwin issue, may be more challenging! :)\n>\n> I've been trying to dig into this; I've essentially never played with\n> the code for Cygwin itself until now, but I suspect I'm probably one of\n> the best-placed folks to actually do that investigation.\n>\n> Unfortunately, I've gone as far back as 18 December 2020 in the code for\n> the Cygwin DLL itself, and I'm still seeing t0301 failing in exactly the\n> same way.  There's a few possible explanations for that, but my guess is\n> either (a) the issue isn't in the Cygwin DLL itself but in some other\n> library that was updated around the same time, or (b) I'm not managing\n> as clean a build as I'm aiming for, and my builds of the old Cygwin\n> commits are being polluted by something in my current environment.\n>\n> Either way I think I can make progress: my next step is to (temporarily)\n> give up on bisecting by commit in the repository that tracks the Cygwin\n> DLL, and instead bisect by time using the Cygwin Time Machine, which\n> should let me get an entire Cygwin environment as it would have been at\n> some point in the past.\n\nMinor progress update: I've now confirmed the failure was introduced by\na change in the Cygwin library between the binaries for Cygwin versions\n3.2.0-1 and 3.3.1-1. Specifically, the test passes with Cygwin from the\n27 October 2021 package archive[0], and fails with Cygwin from the 28\nOctober 2021 archive[1], and the only difference between the two that\nhas any chance of being relevant is that bump in the Cygwin release.\n\nHaving confirmed that, I'll go back to trying to get the Cygwin builds\nto work for me, so I can bisect the commit history between those\nreleases.\n\n[0]: http://ctm.crouchingtigerhiddenfruitbat.org/pub/cygwin/circa/64bit/2021/10/27/155642/index.html\n[1]: http://ctm.crouchingtigerhiddenfruitbat.org/pub/cygwin/circa/64bit/2021/10/28/174906/index.html\n"},{"id":"458795","messageId":"51972253-c1a1-8be7-39f5-3093ac83ffb1@ramsayjones.plus.com","threadId":"58111","inReplyTo":"CA+kUOak29RkU-ooMgOz8yCg9-q6vb1VfdP8_VLay_V650ttwjA@mail.gmail.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsayjones.plus.com","sentAt":"2022-07-11T14:56:19Z","receivedAt":"2022-07-11T14:56:26Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"\n\nOn 11/07/2022 14:39, Adam Dinwoodie wrote:\n[snip]\n\n> \n> Minor progress update: I've now confirmed the failure was introduced by\n> a change in the Cygwin library between the binaries for Cygwin versions\n> 3.2.0-1 and 3.3.1-1. Specifically, the test passes with Cygwin from the\n> 27 October 2021 package archive[0], and fails with Cygwin from the 28\n> October 2021 archive[1], and the only difference between the two that\n> has any chance of being relevant is that bump in the Cygwin release.\n\nHeh, I was just about to email you with similar news! I had a look at\nmy setup.log to see what I actually updated (and from what) and the\nonly thing that seemed to make sense was an update of the cygwin .dll\nfrom v3.2.0-1 to v3.3.2-1 (I will add below an extract from my setup.log\nfor that day, in case you see anything else of interest).\n\n[The previous entry was for 25th October 2021 and had some more interesting\nentries, like binutils, libcurl, etc., but I don't think it is relevant]\n\nSorry I didn't think to look sooner.\n\nHappy Hunting!\n\nATB,\nRamsay Jones\n\n--- >8 ---\n\n[snip]\n2021/11/09 02:52:01 Augmented Transaction List:\n2021/11/09 02:52:01    0 install cygwin               3.3.2-1  \n2021/11/09 02:52:01    1   erase cygwin               3.2.0-1  \n2021/11/09 02:52:01    2 install cygwin-debuginfo     3.3.2-1  \n2021/11/09 02:52:01    3   erase cygwin-debuginfo     3.2.0-1  \n2021/11/09 02:52:01    4 install cygwin-devel         3.3.2-1  \n2021/11/09 02:52:01    5   erase cygwin-devel         3.2.0-1  \n2021/11/09 02:52:01    6 install cygwin-doc           3.3.2-1  \n2021/11/09 02:52:01    7   erase cygwin-doc           3.2.0-1  \n2021/11/09 02:52:01    8 install perl-DateTime-Locale 1.33-1   \n2021/11/09 02:52:01    9   erase perl-DateTime-Locale 1.32-1   \n2021/11/09 02:52:01   10 install perl-URI             5.10-1   \n2021/11/09 02:52:01   11   erase perl-URI             5.09-1   \n2021/11/09 02:52:01   12 install libpcre2_8_0         10.39-1  \n2021/11/09 02:52:01   13   erase libpcre2_8_0         10.38-1  \n2021/11/09 02:52:01   14 install libpcre2_16_0        10.39-1  \n2021/11/09 02:52:01   15   erase libpcre2_16_0        10.38-1  \n2021/11/09 02:52:01   16 install libopenldap2_5_0     2.5.9-1  \n2021/11/09 02:52:01   17   erase libopenldap2_5_0     2.5.8-1  \n2021/11/09 02:52:01   18 install libidn12             1.38-1   \n2021/11/09 02:52:01   19 install libarchive13         3.5.2-2  \n2021/11/09 02:52:01   20   erase libarchive13         3.5.2-1  \n2021/11/09 02:52:01   21 install git                  2.33.1-1 \n2021/11/09 02:52:01   22   erase git                  2.33.0-1 \n2021/11/09 02:52:01   23 install gawk                 5.1.1-1  \n2021/11/09 02:52:01   24   erase gawk                 5.1.0-1  \n2021/11/09 02:52:01   25 install perl-libwww-perl     6.58-1   \n2021/11/09 02:52:01   26   erase perl-libwww-perl     6.57-1   \n2021/11/09 02:52:01   27 install libpcre2-posix3      10.39-1  \n2021/11/09 02:52:01   28   erase libpcre2-posix3      10.38-1  \n2021/11/09 02:52:01   29 install lynx                 2.8.9-13 \n2021/11/09 02:52:01   30   erase lynx                 2.8.7-2  \n2021/11/09 02:52:01   31 install gitk                 2.33.1-1 \n2021/11/09 02:52:01   32   erase gitk                 2.33.0-1 \n2021/11/09 02:52:01   33 install git-email            2.33.1-1 \n2021/11/09 02:52:01   34   erase git-email            2.33.0-1 \n2021/11/09 02:52:01   35 install git-gui              2.33.1-1 \n2021/11/09 02:52:01   36   erase git-gui              2.33.0-1 \n[snip]\n2021/11/09 02:52:19 Uninstalling cygwin\n2021/11/09 02:52:19 Uninstalling cygwin-debuginfo\n2021/11/09 02:52:20 Uninstalling cygwin-devel\n2021/11/09 02:52:20 Uninstalling cygwin-doc\n2021/11/09 02:52:26 Uninstalling perl-DateTime-Locale\n2021/11/09 02:52:28 Uninstalling perl-URI\n2021/11/09 02:52:29 Uninstalling libpcre2_8_0\n2021/11/09 02:52:29 Uninstalling libpcre2_16_0\n2021/11/09 02:52:29 Uninstalling libopenldap2_5_0\n2021/11/09 02:52:29 Uninstalling libarchive13\n2021/11/09 02:52:29 Uninstalling git\n2021/11/09 02:52:30 Uninstalling gawk\n2021/11/09 02:52:30 Uninstalling perl-libwww-perl\n2021/11/09 02:52:31 Uninstalling libpcre2-posix3\n2021/11/09 02:52:31 Uninstalling lynx\n2021/11/09 02:52:31 Uninstalling gitk\n2021/11/09 02:52:31 Uninstalling git-email\n2021/11/09 02:52:31 Uninstalling git-gui\n[snip]\n2021/11/09 02:55:50 Changing gid to Administrators\n2021/11/09 02:55:54 note: In-use files have been replaced. You need to reboot as soon as possible to activate the new versions. Cygwin may operate incorrectly until you reboot.\n2021/11/09 02:55:54 Ending cygwin install\n"},{"id":"458984","messageId":"CA+kUOam-_3qR7YguPyUmyC2dWi2M1cy6Hg4Pveak+f40qtYBvA@mail.gmail.com","threadId":"58111","inReplyTo":"51972253-c1a1-8be7-39f5-3093ac83ffb1@ramsayjones.plus.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Adam Dinwoodie","fromEmail":"adam@dinwoodie.org","sentAt":"2022-07-13T14:42:38Z","receivedAt":"2022-07-13T14:42:56Z","isPatch":false,"sender":{"key":"adam@dinwoodie.org","avatar":"https://avatars.githubusercontent.com/u/1397507?v=4"},"body":"On Mon, 11 Jul 2022 at 15:56, Ramsay Jones <ramsay@ramsayjones.plus.com> wrote:\n> On 11/07/2022 14:39, Adam Dinwoodie wrote:\n> [snip]\n>\n> >\n> > Minor progress update: I've now confirmed the failure was introduced by\n> > a change in the Cygwin library between the binaries for Cygwin versions\n> > 3.2.0-1 and 3.3.1-1. Specifically, the test passes with Cygwin from the\n> > 27 October 2021 package archive[0], and fails with Cygwin from the 28\n> > October 2021 archive[1], and the only difference between the two that\n> > has any chance of being relevant is that bump in the Cygwin release.\n>\n> Heh, I was just about to email you with similar news! I had a look at\n> my setup.log to see what I actually updated (and from what) and the\n> only thing that seemed to make sense was an update of the cygwin .dll\n> from v3.2.0-1 to v3.3.2-1 (I will add below an extract from my setup.log\n> for that day, in case you see anything else of interest).\n\nHaving now spent far more time than I'd like wrangling the Cygwin build\ninfrastructure, I've found the change in the Cygwin code that introduced\nthe break. But I'm afraid progressing beyond this -- and in particular\nmaking any sort of judgement about appropriate next steps -- is beyond\nwhat I'm going to have time for in the foreseeable future.\n\n(On the plus side, this has given me the kick to actually work out how\nto do this sort of investigation, so if and when I get to investigating\nthe other test failures that also seem to be caused by changes in the\nCygwin environment, I now have a much better idea what I'm doing!)\n\nRelevant commit is below:\n\nhttps://cygwin.com/git/?p=newlib-cygwin.git;a=commitdiff;h=ef95c03522f65d5956a8dc82d869c6bc378ef3f9\n\ncommit ef95c03522f65d5956a8dc82d869c6bc378ef3f9 (HEAD, refs/bisect/bad)\nAuthor: Corinna Vinschen <corinna@vinschen.de>\nDate:   Tue Apr 6 21:35:43 2021 +0200\n\n    Cygwin: select: Fix FD_CLOSE handling\n    \n    An FD_CLOSE event sets a socket descriptor ready for writing.\n    This is incorrect if the FD_CLOSE is a result of shutdown(SHUT_RD).\n    Only set the socket descriptor ready for writing if the FD_CLOSE\n    is indicating an connection abort or reset error condition.\n    \n    This requires to tweak fhandler_socket_wsock::evaluate_events.\n    FD_CLOSE in conjunction with FD_ACCEPT/FD_CONNECT special cases\n    a shutdown condition by setting an error code.  This is correct\n    for accept/connect, but not for select.  In this case, make sure\n    to return with an error code only if FD_CLOSE indicates a\n    connection error.\n    \n    Signed-off-by: Corinna Vinschen <corinna@vinschen.de>\n\ndiff --git a/winsup/cygwin/fhandler_socket_inet.cc b/winsup/cygwin/fhandler_socket_inet.cc\nindex bc08d3cf1..4ecb31a27 100644\n--- a/winsup/cygwin/fhandler_socket_inet.cc\n+++ b/winsup/cygwin/fhandler_socket_inet.cc\n@@ -361,20 +361,30 @@ fhandler_socket_wsock::evaluate_events (const long event_mask, long &events,\n \t  wsock_events->events |= FD_WRITE;\n \t  wsock_events->connect_errorcode = 0;\n \t}\n-      /* This test makes accept/connect behave as on Linux when accept/connect\n-         is called on a socket for which shutdown has been called.  The second\n-\t half of this code is in the shutdown method. */\n       if (events & FD_CLOSE)\n \t{\n-\t  if ((event_mask & FD_ACCEPT) && saw_shutdown_read ())\n+\t  if (evts.iErrorCode[FD_CLOSE_BIT])\n \t    {\n-\t      WSASetLastError (WSAEINVAL);\n+\t      WSASetLastError (evts.iErrorCode[FD_CLOSE_BIT]);\n \t      ret = SOCKET_ERROR;\n \t    }\n-\t  if (event_mask & FD_CONNECT)\n+\t  /* This test makes accept/connect behave as on Linux when accept/\n+\t     connect is called on a socket for which shutdown has been called.\n+\t     The second half of this code is in the shutdown method.  Note that\n+\t     we only do this when called from accept/connect, not from select.\n+\t     In this case erase == false, just as with read (MSG_PEEK). */\n+\t  if (erase)\n \t    {\n-\t      WSASetLastError (WSAECONNRESET);\n-\t      ret = SOCKET_ERROR;\n+\t      if ((event_mask & FD_ACCEPT) && saw_shutdown_read ())\n+\t\t{\n+\t\t  WSASetLastError (WSAEINVAL);\n+\t\t  ret = SOCKET_ERROR;\n+\t\t}\n+\t      if (event_mask & FD_CONNECT)\n+\t\t{\n+\t\t  WSASetLastError (WSAECONNRESET);\n+\t\t  ret = SOCKET_ERROR;\n+\t\t}\n \t    }\n \t}\n       if (erase)\ndiff --git a/winsup/cygwin/select.cc b/winsup/cygwin/select.cc\nindex 956cd9bc1..b493ccc11 100644\n--- a/winsup/cygwin/select.cc\n+++ b/winsup/cygwin/select.cc\n@@ -1709,15 +1709,18 @@ peek_socket (select_record *me, bool)\n   fhandler_socket_wsock *fh = (fhandler_socket_wsock *) me->fh;\n   long events;\n   /* Don't play with the settings again, unless having taken a deep look into\n-     Richard W. Stevens Network Programming book.  Thank you. */\n+     Richard W. Stevens Network Programming book and how these flags are\n+     defined in Winsock.  Thank you. */\n   long evt_mask = (me->read_selected ? (FD_READ | FD_ACCEPT | FD_CLOSE) : 0)\n \t\t| (me->write_selected ? (FD_WRITE | FD_CONNECT | FD_CLOSE) : 0)\n \t\t| (me->except_selected ? FD_OOB : 0);\n   int ret = fh->evaluate_events (evt_mask, events, false);\n   if (me->read_selected)\n     me->read_ready |= ret || !!(events & (FD_READ | FD_ACCEPT | FD_CLOSE));\n   if (me->write_selected)\n-    me->write_ready |= ret || !!(events & (FD_WRITE | FD_CONNECT | FD_CLOSE));\n+    /* Don't check for FD_CLOSE here.  Only an error case (ret == -1)\n+       will set ready for writing. */\n+    me->write_ready |= ret || !!(events & (FD_WRITE | FD_CONNECT));\n   if (me->except_selected)\n     me->except_ready |= !!(events & FD_OOB);\n \n"},{"id":"459003","messageId":"Ys8aJ1HSLnWFT5qB@coredump.intra.peff.net","threadId":"58111","inReplyTo":"CA+kUOam-_3qR7YguPyUmyC2dWi2M1cy6Hg4Pveak+f40qtYBvA@mail.gmail.com","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2022-07-13T19:16:55Z","receivedAt":"2022-07-13T19:17:00Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Jul 13, 2022 at 03:42:38PM +0100, Adam Dinwoodie wrote:\n\n> Having now spent far more time than I'd like wrangling the Cygwin build\n> infrastructure, I've found the change in the Cygwin code that introduced\n> the break. But I'm afraid progressing beyond this -- and in particular\n> making any sort of judgement about appropriate next steps -- is beyond\n> what I'm going to have time for in the foreseeable future.\n\nHmm. So I had assumed that the problem was unlink()ing the socket path\nwhile the client was still trying to read(). If that's the case, then I\n_think_ the minimal reproduction below should also trigger the problem.\nThat might give you something more useful to show to Cygwin folks.\n\nBut...\n\n> commit ef95c03522f65d5956a8dc82d869c6bc378ef3f9 (HEAD, refs/bisect/bad)\n> Author: Corinna Vinschen <corinna@vinschen.de>\n> Date:   Tue Apr 6 21:35:43 2021 +0200\n> \n>     Cygwin: select: Fix FD_CLOSE handling\n>     \n>     An FD_CLOSE event sets a socket descriptor ready for writing.\n>     This is incorrect if the FD_CLOSE is a result of shutdown(SHUT_RD).\n>     Only set the socket descriptor ready for writing if the FD_CLOSE\n>     is indicating an connection abort or reset error condition.\n>     \n>     This requires to tweak fhandler_socket_wsock::evaluate_events.\n>     FD_CLOSE in conjunction with FD_ACCEPT/FD_CONNECT special cases\n>     a shutdown condition by setting an error code.  This is correct\n>     for accept/connect, but not for select.  In this case, make sure\n>     to return with an error code only if FD_CLOSE indicates a\n>     connection error.\n\n...this is about select outcomes. Which makes me think two things\n(though these are really pretty blind guesses, as I'm not at all\nfamiliar with Cygwin's socket code):\n\n  - it may be that this situation was always ECONNABORTED (it's not on\n    Linux, but perhaps due to details of the underlying socket code on\n    Windows, it's different there). And this patch is just surfacing\n    that state to the caller better.\n\n  - it could be unrelated to the unlink() entirely. The socket code in\n    Git dups the client descriptor and opens two FILE* handles, one for\n    reading and one for writing. Could it be that it's important to\n    fclose() one before the other (and the implicit closing done by\n    exit() does the wrong order)? It seems like a stretch, but this\n    commit message is talking about a shutdown(SHUT_RD), which is kind\n    of what you get by fclose-ing one side (though again, not on Linux,\n    because the \"FILE*\" are aware that they are read/write, but the\n    underlying descriptors aren't).\n\nOr maybe those are just totally off track. I know you said you don't\nhave time to dig further, and that's fine. But if you or anybody has a\nchance to try the program below, it might be interesting to see the\nresult (it would confirm whether it's the unlink() that's the problem).\n\n-- >8 --\n#include <stdio.h>\n#include <stdlib.h>\n\n#include <unistd.h>\n#include <sys/socket.h>\n#include <sys/un.h>\n\n#define SOCKET_PATH \"mysocket\"\n\nstatic void diesys(const char *syscall)\n{\n\tperror(syscall);\n\texit(1);\n}\n\nstatic int create_server(void)\n{\n\tint fd;\n\tstruct sockaddr_un sa = {\n\t\t.sun_family = AF_UNIX,\n\t\t.sun_path = SOCKET_PATH,\n\t};\n\n\tfd = socket(AF_UNIX, SOCK_STREAM, 0);\n\tif (fd < 0)\n\t\tdiesys(\"socket\");\n\tif (bind(fd, (struct sockaddr *)&sa, sizeof(sa)) < 0)\n\t\tdiesys(\"bind\");\n\tif (listen(fd, 5) < 0)\n\t\tdiesys(\"listen\");\n\n\treturn fd;\n}\n\nstatic void do_server(int listen_fd)\n{\n\tint client_fd = accept(listen_fd, NULL, NULL);\n\tif (client_fd < 0)\n\t\tdiesys(\"accept\");\n\tif (unlink(SOCKET_PATH) < 0)\n\t\tdiesys(\"unlink\");\n\tif (close(client_fd) < 0)\n\t\tdiesys(\"close(client)\");\n\tclose(listen_fd);\n}\n\nstatic void do_client(void)\n{\n\tint fd;\n\tchar buf[64];\n\tstruct sockaddr_un sa = {\n\t\t.sun_family = AF_UNIX,\n\t\t.sun_path = SOCKET_PATH,\n\t};\n\n\tfd = socket(AF_UNIX, SOCK_STREAM, 0);\n\tif (fd < 0)\n\t\tdiesys(\"socket\");\n\tif (connect(fd, (struct sockaddr *)&sa, sizeof(sa)) < 0)\n\t\tdiesys(\"connect\");\n\tif (read(fd, buf, sizeof(buf)) < 0)\n\t\tdiesys(\"read\");\n\tclose(fd);\n}\n\nint main(void)\n{\n\tint fd = create_server();\n\n\tif (fork()) {\n\t\tdo_server(fd);\n\t} else {\n\t\tclose(fd);\n\t\tdo_client();\n\t}\n\treturn 0;\n}\n"},{"id":"459012","messageId":"6e9b21ff-a716-b202-e8c8-f83116b9a171@ramsayjones.plus.com","threadId":"58111","inReplyTo":"Ys8aJ1HSLnWFT5qB@coredump.intra.peff.net","subject":"Re: t0301-credential-cache test failure on cygwin","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsayjones.plus.com","sentAt":"2022-07-13T20:35:03Z","receivedAt":"2022-07-13T20:35:11Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"\n\nOn 13/07/2022 20:16, Jeff King wrote:\n> On Wed, Jul 13, 2022 at 03:42:38PM +0100, Adam Dinwoodie wrote:\n> \n> Hmm. So I had assumed that the problem was unlink()ing the socket path\n> while the client was still trying to read(). If that's the case, then I\n> _think_ the minimal reproduction below should also trigger the problem.\n> That might give you something more useful to show to Cygwin folks.\n\nHmm, good find - I looked at this commit while searching the gitweb pages the\nother night, but didn't think it was relevant! :( Oh, well ...\n\nI don't have too much time tonight, but I gave your program a quick try:\n\n  $ gcc -o test-unix-sock test-unix-sock.c\n  $ ./test-unix-sock\n  $ ls -l my*\n  ls: cannot access 'my*': No such file or directory\n  $ ./test-unix-sock\n  $ echo $?\n  0\n  $ \n\nHTH.\n\nATB,\nRamsay Jones\n\n\n"}]}