{"thread":{"id":"52140","subject":"[PATCH 0/1] Fix t5516 flakiness in Visual Studio builds","startedAt":"2019-10-28T15:01:04Z","lastAt":"2019-11-02T04:06:01Z","messageCount":34,"participants":["Johannes Schindelin via GitGitGadget","Junio C Hamano","SZEDER Gábor","Johannes Schindelin","Jeff King","Alexandr Miloslavskiy"],"isPatch":true,"patchVersion":1,"patchTotal":1},"messages":[{"id":"384999","messageId":"pull.428.git.1572274859.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":null,"subject":"[PATCH 0/1] Fix t5516 flakiness in Visual Studio builds","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-28T15:00:58Z","receivedAt":"2019-10-28T15:01:04Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Among the flaky tests, it seems that the Azure Pipeline suffers relatively\nfrequently from t5516 failing with the Visual Studio builds. Essentially, we\ngrep for an error message, but that error message is produced twice, once by\na fetch and once by the upload-pack spawned from it, and those error\nmessages are usually interleaved because of MSVC runtime fprintf() \nidiosyncracies. \n\nThe commit message of this patch is based, in part, on \nhttps://github.com/gitgitgadget/git/pull/407. The patch itself is a much\nmore minimal alternative (using xwrite() instead of fprintf()) to the code\nof https://github.com/gitgitgadget/git/pull/407, avoiding the complexity of\nthe part of the code that allows for unlimited messages.\n\nWhile it would seem theoretically more elegant to allow for unlimited\nmessages, in practice too-long messages cause more problems than they solve,\nand therefore we already clip them, and this patch does not change that\nbehavior.\n\nThis fixes https://github.com/gitgitgadget/git/issues/240.\n\nJohannes Schindelin (1):\n vreportf(): avoid buffered write in favor of unbuffered one\n\n usage.c | 12 +++++++++---\n 1 file changed, 9 insertions(+), 3 deletions(-)\n\n\nbase-commit: 566a1439f6f56c2171b8853ddbca0ad3f5098770\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-428%2Fdscho%2Ffix-t5516-flakiness-v1\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-428/dscho/fix-t5516-flakiness-v1\nPull-Request: https://github.com/gitgitgadget/git/pull/428\n-- \ngitgitgadget\n"},{"id":"385000","messageId":"455026ce3ef2b2d7cfecfc4b4bf5b588eebddcfe.1572274859.git.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":"pull.428.git.1572274859.gitgitgadget@gmail.com","subject":"[PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-28T15:00:59Z","receivedAt":"2019-10-28T15:01:05Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"From: Johannes Schindelin \n\nThe MSVC runtime behavior differs from glibc's with respect to\n`fprintf(stderr, ...)` in that the former writes out the message\ncharacter by character.\n\nIn t5516, this leads to a funny problem where a `git fetch` process as\nwell as the `git upload-pack` process spawned by it _both_ call `die()`\nat the same time. The output can look like this:\n\n\tfatal: git uploadfata-lp: raemcokte :error: upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n\t8e86a771eda009872d6ab2886\n\nLet's avoid this predicament altogether by rendering the entire message,\nincluding the prefix and the trailing newline, into the buffer we\nalready have (and which is still fixed size) and then write it out via\n`write_in_full()`.\n\nThe history of `vreportf()` with regard to this issue includes the\nfollowing commits:\n\nd048a96e (2007-11-09) - 'char msg[256]' is introduced to avoid interleaving\n389d1767 (2009-03-25) - Buffer size increased to 1024 to avoid truncation\n625a860c (2009-11-22) - Buffer size increased to 4096 to avoid truncation\nf4c3edc0 (2015-08-11) - Buffer removed to avoid truncation\nb5a9e435 (2017-01-11) - Reverts f4c3edc0 to be able to replace control\n chars before sending to stderr\n9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n This is seemingly related to d048a96e.\n137a0d0e (2007-11-19) - Addresses out-of-order for display()\n34df8aba (2009-03-10) - Switches xwrite() to fprintf() in recv_sideband()\n to support UTF-8 emulation\neac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\n so it's safe to use xwrite() again\n5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n\nNote that we need to be careful to handle the return value of\n`vsnprintf()` that indicates the _desired_ byte count.\n\nAlso please note that we `fflush(stderr)` here to help when running in a\nGit Bash on Windows: in this case, `stderr` is not actually truly\nunbuffered, and needs the extra help.\n\nCo-authored-by: Alexandr Miloslavskiy \nSigned-off-by: Johannes Schindelin \n---\n usage.c | 12 +++++++++---\n 1 file changed, 9 insertions(+), 3 deletions(-)\n\ndiff --git a/usage.c b/usage.c\nindex 2fdb20086b..4328894dce 100644\n--- a/usage.c\n+++ b/usage.c\n@@ -10,13 +10,19 @@ void vreportf(const char *prefix, const char *err, va_list params)\n {\n \tchar msg[4096];\n \tchar *p;\n-\n-\tvsnprintf(msg, sizeof(msg), err, params);\n+\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n+\tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n \tfor (p = msg; *p; p++) {\n \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n \t\t\t*p = '?';\n \t}\n-\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n+\tif (ret > 0) {\n+\t\tif (off + ret > sizeof(msg) - 1)\n+\t\t\tret = sizeof(msg) - 1 - off;\n+\t\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n+\t\tfflush(stderr);\n+\t\txwrite(2, msg, off + ret + 1);\n+\t}\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n-- \ngitgitgadget\n"},{"id":"385042","messageId":"xmqqeeyw6xyr.fsf@gitster-ct.c.googlers.com","threadId":"52140","inReplyTo":"455026ce3ef2b2d7cfecfc4b4bf5b588eebddcfe.1572274859.git.gitgitgadget@gmail.com","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-10-29T03:18:36Z","receivedAt":"2019-10-29T03:18:48Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"\"Johannes Schindelin via GitGitGadget\" \nwrites:\n\n> Also please note that we `fflush(stderr)` here to help when running in a\n> Git Bash on Windows: in this case, `stderr` is not actually truly\n> unbuffered, and needs the extra help.\n\nYuck. So on all systems, vreportf() now totally bypasses stdio?\n\nAlso, this is only to help output from us that goes via vreportf()\nand other codepaths in us that use stdio to write to the standard\nerror stream can still get mixed on Windows (I think the answer is\nyes, because we wouldn't need fflush() in this patch if we are\ncovering all writes to the standard error stream)?\n\nBy the way, I'd retitle the patch to highlight that we are still\ndoing buffered write, if I were doing this topic. We are just\navoiding some implementations of stdio that do not give us buffering\nand doing the buffering ourselves.\n\n Subject: vreportf(): don't rely on stdio buffering\n\nor something like that.\n\n> Co-authored-by: Alexandr Miloslavskiy \n> Signed-off-by: Johannes Schindelin \n> ---\n> usage.c | 12 +++++++++---\n> 1 file changed, 9 insertions(+), 3 deletions(-)\n>\n> diff --git a/usage.c b/usage.c\n> index 2fdb20086b..4328894dce 100644\n> --- a/usage.c\n> +++ b/usage.c\n> @@ -10,13 +10,19 @@ void vreportf(const char *prefix, const char *err, va_list params)\n> {\n> \tchar msg[4096];\n> \tchar *p;\n> -\n> -\tvsnprintf(msg, sizeof(msg), err, params);\n> +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n\nLike snprintf(3) the strlcpy() and strlcat() functions return the\ntotal length of the string they tried to create. For strlcpy() that\nmeans the length of src.\n\nSo \"off\" would be strlen(prefix), which could be longer than\nsizeof(msg)? Then what happens to this vsnprintf() we see below?\n\n> +\tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n> \tfor (p = msg; *p; p++) {\n> \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> \t\t\t*p = '?';\n> \t}\n> -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n\nStrictly speaking this is a breaking change in that control\nsequences in prefix are now clobbered. Does any caller call this\nfunction with prefix like \"^M\\033[K\" to overwrite the\nlast output line with the new message? If not, then probably we do\nnot have to worry about it (and reusing msg[] does feel attractive).\n\n> +\tif (ret > 0) {\n> +\t\tif (off + ret > sizeof(msg) - 1)\n> +\t\t\tret = sizeof(msg) - 1 - off;\n> +\t\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n> +\t\tfflush(stderr);\n> +\t\txwrite(2, msg, off + ret + 1);\n> +\t}\n> }\n> \n> static NORETURN void usage_builtin(const char *err, va_list params)\n"},{"id":"385066","messageId":"20191029103842.GV4348@szeder.dev","threadId":"52140","inReplyTo":"455026ce3ef2b2d7cfecfc4b4bf5b588eebddcfe.1572274859.git.gitgitgadget@gmail.com","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-10-29T10:38:42Z","receivedAt":"2019-10-29T10:38:49Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"On Mon, Oct 28, 2019 at 03:00:59PM +0000, Johannes Schindelin via GitGitGadget wrote:\n> From: Johannes Schindelin \n> \n> The MSVC runtime behavior differs from glibc's with respect to\n> `fprintf(stderr, ...)` in that the former writes out the message\n> character by character.\n> \n> In t5516, this leads to a funny problem where a `git fetch` process as\n> well as the `git upload-pack` process spawned by it _both_ call `die()`\n> at the same time. The output can look like this:\n> \n> \tfatal: git uploadfata-lp: raemcokte :error: upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n> \t8e86a771eda009872d6ab2886\n\nHeh.\n\n> Let's avoid this predicament altogether by rendering the entire message,\n> including the prefix and the trailing newline, into the buffer we\n> already have (and which is still fixed size) and then write it out via\n> `write_in_full()`.\n\ns/write_in_full/xwrite/ perhaps? Both the cover letter and the patch\nbelow use xwrite().\n\n> The history of `vreportf()` with regard to this issue includes the\n> following commits:\n> \n> d048a96e (2007-11-09) - 'char msg[256]' is introduced to avoid interleaving\n> 389d1767 (2009-03-25) - Buffer size increased to 1024 to avoid truncation\n> 625a860c (2009-11-22) - Buffer size increased to 4096 to avoid truncation\n> f4c3edc0 (2015-08-11) - Buffer removed to avoid truncation\n> b5a9e435 (2017-01-11) - Reverts f4c3edc0 to be able to replace control\n> chars before sending to stderr\n> 9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n> This is seemingly related to d048a96e.\n> 137a0d0e (2007-11-19) - Addresses out-of-order for display()\n> 34df8aba (2009-03-10) - Switches xwrite() to fprintf() in recv_sideband()\n> to support UTF-8 emulation\n> eac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\n> so it's safe to use xwrite() again\n> 5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n> \n> Note that we need to be careful to handle the return value of\n> `vsnprintf()` that indicates the _desired_ byte count.\n> \n> Also please note that we `fflush(stderr)` here to help when running in a\n> Git Bash on Windows: in this case, `stderr` is not actually truly\n> unbuffered, and needs the extra help.\n> \n> Co-authored-by: Alexandr Miloslavskiy \n> Signed-off-by: Johannes Schindelin \n> ---\n> usage.c | 12 +++++++++---\n> 1 file changed, 9 insertions(+), 3 deletions(-)\n> \n> diff --git a/usage.c b/usage.c\n> index 2fdb20086b..4328894dce 100644\n> --- a/usage.c\n> +++ b/usage.c\n> @@ -10,13 +10,19 @@ void vreportf(const char *prefix, const char *err, va_list params)\n> {\n> \tchar msg[4096];\n> \tchar *p;\n> -\n> -\tvsnprintf(msg, sizeof(msg), err, params);\n> +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> +\tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n> \tfor (p = msg; *p; p++) {\n> \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> \t\t\t*p = '?';\n> \t}\n> -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n> +\tif (ret > 0) {\n> +\t\tif (off + ret > sizeof(msg) - 1)\n> +\t\t\tret = sizeof(msg) - 1 - off;\n> +\t\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n> +\t\tfflush(stderr);\n> +\t\txwrite(2, msg, off + ret + 1);\n> +\t}\n> }\n> \n> static NORETURN void usage_builtin(const char *err, va_list params)\n> -- \n> gitgitgadget\n"},{"id":"385071","messageId":"nycvar.QRO.7.76.6.1910291222500.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"xmqqeeyw6xyr.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-29T12:30:51Z","receivedAt":"2019-10-29T12:31:24Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Junio,\n\nOn Tue, 29 Oct 2019, Junio C Hamano wrote:\n\n> \"Johannes Schindelin via GitGitGadget\" \n> writes:\n>\n> > Also please note that we `fflush(stderr)` here to help when running in a\n> > Git Bash on Windows: in this case, `stderr` is not actually truly\n> > unbuffered, and needs the extra help.\n>\n> Yuck. So on all systems, vreportf() now totally bypasses stdio?\n\nYep ;-)\n\n> Also, this is only to help output from us that goes via vreportf() and\n> other codepaths in us that use stdio to write to the standard error\n> stream can still get mixed on Windows (I think the answer is yes,\n> because we wouldn't need fflush() in this patch if we are covering all\n> writes to the standard error stream)?\n\nYes, `write()` can get interrupted, so there is still a slight chance of\ninterleaving.\n\nHowever, with `fprintf()`, apparently the MSVC runtime essentially\nwrites and flushes one character at a time, which will make it _much_\nmore likely that two competing processes write interleaved messages to\n`stderr`.\n\n> By the way, I'd retitle the patch to highlight that we are still doing\n> buffered write, if I were doing this topic. We are just avoiding some\n> implementations of stdio that do not give us buffering and doing the\n> buffering ourselves.\n>\n> Subject: vreportf(): don't rely on stdio buffering\n>\n> or something like that.\n\nGood idea.\n\n> > Co-authored-by: Alexandr Miloslavskiy \n> > Signed-off-by: Johannes Schindelin \n> > ---\n> > usage.c | 12 +++++++++---\n> > 1 file changed, 9 insertions(+), 3 deletions(-)\n> >\n> > diff --git a/usage.c b/usage.c\n> > index 2fdb20086b..4328894dce 100644\n> > --- a/usage.c\n> > +++ b/usage.c\n> > @@ -10,13 +10,19 @@ void vreportf(const char *prefix, const char *err, va_list params)\n> > {\n> > \tchar msg[4096];\n> > \tchar *p;\n> > -\n> > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n>\n> Like snprintf(3) the strlcpy() and strlcat() functions return the\n> total length of the string they tried to create. For strlcpy() that\n> means the length of src.\n\nTrue (I misread `compat/strlcpy.c` and forgot to consult the\ndocumentation). This length can be longer than `msg`, of course.\n\n> So \"off\" would be strlen(prefix), which could be longer than\n> sizeof(msg)? Then what happens to this vsnprintf() we see below?\n\nA problem.\n\nI `git grep`ed and saw that only very short `prefix`es are hard-coded.\nSo that is a hypothetical concern.\n\nHowever, Alex also indicated his discomfort with this, so I will change\nthe code to account for a `prefix` that is too long (the entire error\nmessage will be clipped away in that case, which is unfortunate, but to\nbe expected).\n\n> > +\tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n> > \tfor (p = msg; *p; p++) {\n> > \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> > \t\t\t*p = '?';\n> > \t}\n> > -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n>\n> Strictly speaking this is a breaking change in that control\n> sequences in prefix are now clobbered. Does any caller call this\n> function with prefix like \"^M\\033[K\" to overwrite the\n> last output line with the new message? If not, then probably we do\n> not have to worry about it (and reusing msg[] does feel attractive).\n\nSuch a sequence would not exactly be a prefix, but okay, I changed the\ncode to replace only characters in the non-prefix part. For good\nmeasure, I also detect `NUL`s in that part and shorten `ret` in that\ncase (think `die(\"This was an\\0unintentional NUL\")`).\n\nThanks for the review!\nDscho\n\n> > +\tif (ret > 0) {\n> > +\t\tif (off + ret > sizeof(msg) - 1)\n> > +\t\t\tret = sizeof(msg) - 1 - off;\n> > +\t\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n> > +\t\tfflush(stderr);\n> > +\t\txwrite(2, msg, off + ret + 1);\n> > +\t}\n> > }\n> >\n> > static NORETURN void usage_builtin(const char *err, va_list params)\n>\n"},{"id":"385072","messageId":"nycvar.QRO.7.76.6.1910291334210.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"20191029103842.GV4348@szeder.dev","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-29T12:38:49Z","receivedAt":"2019-10-29T12:39:17Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Gábor,\n\nOn Tue, 29 Oct 2019, SZEDER Gábor wrote:\n\n> On Mon, Oct 28, 2019 at 03:00:59PM +0000, Johannes Schindelin via GitGitGadget wrote:\n> > From: Johannes Schindelin \n> >\n> > The MSVC runtime behavior differs from glibc's with respect to\n> > `fprintf(stderr, ...)` in that the former writes out the message\n> > character by character.\n> >\n> > In t5516, this leads to a funny problem where a `git fetch` process as\n> > well as the `git upload-pack` process spawned by it _both_ call `die()`\n> > at the same time. The output can look like this:\n> >\n> > \tfatal: git uploadfata-lp: raemcokte :error: upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n> > \t8e86a771eda009872d6ab2886\n>\n> Heh.\n\nYes ;-)\n\n> > Let's avoid this predicament altogether by rendering the entire message,\n> > including the prefix and the trailing newline, into the buffer we\n> > already have (and which is still fixed size) and then write it out via\n> > `write_in_full()`.\n>\n> s/write_in_full/xwrite/ perhaps? Both the cover letter and the patch\n> below use xwrite().\n\nExcellent eyes! I had originally used `write_in_full()` before realizing\nthat `xwrite()` would be more appropriate.\n\nFixed.\n\nThank you for helping me improve the patch!\nDscho\n\n> > The history of `vreportf()` with regard to this issue includes the\n> > following commits:\n> >\n> > d048a96e (2007-11-09) - 'char msg[256]' is introduced to avoid interleaving\n> > 389d1767 (2009-03-25) - Buffer size increased to 1024 to avoid truncation\n> > 625a860c (2009-11-22) - Buffer size increased to 4096 to avoid truncation\n> > f4c3edc0 (2015-08-11) - Buffer removed to avoid truncation\n> > b5a9e435 (2017-01-11) - Reverts f4c3edc0 to be able to replace control\n> > chars before sending to stderr\n> > 9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n> > This is seemingly related to d048a96e.\n> > 137a0d0e (2007-11-19) - Addresses out-of-order for display()\n> > 34df8aba (2009-03-10) - Switches xwrite() to fprintf() in recv_sideband()\n> > to support UTF-8 emulation\n> > eac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\n> > so it's safe to use xwrite() again\n> > 5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n> >\n> > Note that we need to be careful to handle the return value of\n> > `vsnprintf()` that indicates the _desired_ byte count.\n> >\n> > Also please note that we `fflush(stderr)` here to help when running in a\n> > Git Bash on Windows: in this case, `stderr` is not actually truly\n> > unbuffered, and needs the extra help.\n> >\n> > Co-authored-by: Alexandr Miloslavskiy \n> > Signed-off-by: Johannes Schindelin \n> > ---\n> > usage.c | 12 +++++++++---\n> > 1 file changed, 9 insertions(+), 3 deletions(-)\n> >\n> > diff --git a/usage.c b/usage.c\n> > index 2fdb20086b..4328894dce 100644\n> > --- a/usage.c\n> > +++ b/usage.c\n> > @@ -10,13 +10,19 @@ void vreportf(const char *prefix, const char *err, va_list params)\n> > {\n> > \tchar msg[4096];\n> > \tchar *p;\n> > -\n> > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> > +\tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n> > \tfor (p = msg; *p; p++) {\n> > \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> > \t\t\t*p = '?';\n> > \t}\n> > -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n> > +\tif (ret > 0) {\n> > +\t\tif (off + ret > sizeof(msg) - 1)\n> > +\t\t\tret = sizeof(msg) - 1 - off;\n> > +\t\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n> > +\t\tfflush(stderr);\n> > +\t\txwrite(2, msg, off + ret + 1);\n> > +\t}\n> > }\n> >\n> > static NORETURN void usage_builtin(const char *err, va_list params)\n> > --\n> > gitgitgadget\n>\n"},{"id":"385078","messageId":"e426627e1494e31e548fe044c1c1806ff59340cf.1572356272.git.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":"pull.428.v2.git.1572356272.gitgitgadget@gmail.com","subject":"[PATCH v2 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-29T13:37:52Z","receivedAt":"2019-10-29T13:37:59Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"From: Johannes Schindelin \n\nThe MSVC runtime behavior differs from glibc's with respect to\n`fprintf(stderr, ...)` in that the former writes out the message\ncharacter by character.\n\nIn t5516, this leads to a funny problem where a `git fetch` process as\nwell as the `git upload-pack` process spawned by it _both_ call `die()`\nat the same time. The output can look like this:\n\n\tfatal: git uploadfata-lp: raemcokte :error: upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n\t8e86a771eda009872d6ab2886\n\nLet's avoid this predicament altogether by rendering the entire message,\nincluding the prefix and the trailing newline, into the buffer we\nalready have (and which is still fixed size) and then write it out via\n`xwrite()`.\n\nWe still clip the message to at most 4095 characters.\n\nThe history of `vreportf()` with regard to this issue includes the\nfollowing commits:\n\nd048a96e (2007-11-09) - 'char msg[256]' is introduced to avoid interleaving\n389d1767 (2009-03-25) - Buffer size increased to 1024 to avoid truncation\n625a860c (2009-11-22) - Buffer size increased to 4096 to avoid truncation\nf4c3edc0 (2015-08-11) - Buffer removed to avoid truncation\nb5a9e435 (2017-01-11) - Reverts f4c3edc0 to be able to replace control\n chars before sending to stderr\n9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n This is seemingly related to d048a96e.\n137a0d0e (2007-11-19) - Addresses out-of-order for display()\n34df8aba (2009-03-10) - Switches xwrite() to fprintf() in recv_sideband()\n to support UTF-8 emulation\neac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\n so it's safe to use xwrite() again\n5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n\nNote that we print nothing if the `vsnprintf()` call failed to render\nthe error message; There is little we can do in that case, and it should\nnot happen anyway.\n\nAlso please note that we `fflush(stderr)` here to help when running in a\nGit Bash on Windows: in this case, `stderr` is not actually truly\nunbuffered, and needs the extra help.\n\nHelped-by: Alexandr Miloslavskiy \nHelped-by: SZEDER Gábor \nHelped-by: Junio C Hamano \nSigned-off-by: Johannes Schindelin \n---\n usage.c | 15 +++++++++++----\n 1 file changed, 11 insertions(+), 4 deletions(-)\n\ndiff --git a/usage.c b/usage.c\nindex 2fdb20086b..5dfd38acb8 100644\n--- a/usage.c\n+++ b/usage.c\n@@ -9,14 +9,21 @@\n void vreportf(const char *prefix, const char *err, va_list params)\n {\n \tchar msg[4096];\n-\tchar *p;\n+\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n+\tchar *p, *pend = msg + sizeof(msg);\n \n-\tvsnprintf(msg, sizeof(msg), err, params);\n-\tfor (p = msg; *p; p++) {\n+\tp = msg + off < pend ? msg + off : pend - 1;\n+\tif (vsnprintf(p, pend - p, err, params) < 0)\n+\t\treturn; /* vsnprintf() failed, there is nothing we can do */\n+\n+\tfor (; p != pend - 1 && *p; p++) {\n \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n \t\t\t*p = '?';\n \t}\n-\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n+\n+\t*(p++) = '\\n'; /* we no longer need a NUL */\n+\tfflush(stderr);\n+\txwrite(2, msg, p - msg);\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n-- \ngitgitgadget\n"},{"id":"385079","messageId":"pull.428.v2.git.1572356272.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":"pull.428.git.1572274859.gitgitgadget@gmail.com","subject":"[PATCH v2 0/1] Fix t5516 flakiness in Visual Studio builds","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-29T13:37:51Z","receivedAt":"2019-10-29T13:37:59Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Among the flaky tests, it seems that the Azure Pipeline suffers relatively\nfrequently from t5516 failing with the Visual Studio builds. Essentially, we\ngrep for an error message, but that error message is produced twice, once by\na fetch and once by the upload-pack spawned from it, and those error\nmessages are usually interleaved because of MSVC runtime fprintf() \nidiosyncracies. \n\nThe commit message of this patch is based, in part, on \nhttps://github.com/gitgitgadget/git/pull/407. The patch itself is a much\nmore minimal alternative (using xwrite() instead of fprintf()) to the code\nof https://github.com/gitgitgadget/git/pull/407, avoiding the complexity of\nthe part of the code that allows for unlimited messages.\n\nWhile it would seem theoretically more elegant to allow for unlimited\nmessages, in practice too-long messages cause more problems than they solve,\nand therefore we already clip them, and this patch does not change that\nbehavior.\n\nThis fixes https://github.com/gitgitgadget/git/issues/240.\n\nChanges since v1:\n\n * Changed the oneline to be more accurate (thanks Junio).\n * Improved the commit message (e.g. talking about the xwrite() function\n this patch uses, rather than the write_in_full() function used by an\n earlier iteration, thanks Gábor).\n * Revamped the actual code to account for insanely long prefixes (thanks\n for the advice, Junio).\n\nJohannes Schindelin (1):\n vreportf(): avoid relying on stdio buffering\n\n usage.c | 15 +++++++++++----\n 1 file changed, 11 insertions(+), 4 deletions(-)\n\n\nbase-commit: 566a1439f6f56c2171b8853ddbca0ad3f5098770\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-428%2Fdscho%2Ffix-t5516-flakiness-v2\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-428/dscho/fix-t5516-flakiness-v2\nPull-Request: https://github.com/gitgitgadget/git/pull/428\n\nRange-diff vs v1:\n\n 1: 455026ce3e ! 1: e426627e14 vreportf(): avoid buffered write in favor of unbuffered one\n @@ -1,6 +1,6 @@\n Author: Johannes Schindelin \n \n - vreportf(): avoid buffered write in favor of unbuffered one\n + vreportf(): avoid relying on stdio buffering\n \n The MSVC runtime behavior differs from glibc's with respect to\n `fprintf(stderr, ...)` in that the former writes out the message\n @@ -16,7 +16,9 @@\n Let's avoid this predicament altogether by rendering the entire message,\n including the prefix and the trailing newline, into the buffer we\n already have (and which is still fixed size) and then write it out via\n - `write_in_full()`.\n + `xwrite()`.\n +\n + We still clip the message to at most 4095 characters.\n \n The history of `vreportf()` with regard to this issue includes the\n following commits:\n @@ -36,39 +38,45 @@\n so it's safe to use xwrite() again\n 5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n \n - Note that we need to be careful to handle the return value of\n - `vsnprintf()` that indicates the _desired_ byte count.\n + Note that we print nothing if the `vsnprintf()` call failed to render\n + the error message; There is little we can do in that case, and it should\n + not happen anyway.\n \n Also please note that we `fflush(stderr)` here to help when running in a\n Git Bash on Windows: in this case, `stderr` is not actually truly\n unbuffered, and needs the extra help.\n \n - Co-authored-by: Alexandr Miloslavskiy \n + Helped-by: Alexandr Miloslavskiy \n + Helped-by: SZEDER Gábor \n + Helped-by: Junio C Hamano \n Signed-off-by: Johannes Schindelin \n \n diff --git a/usage.c b/usage.c\n --- a/usage.c\n +++ b/usage.c\n @@\n + void vreportf(const char *prefix, const char *err, va_list params)\n {\n \tchar msg[4096];\n - \tchar *p;\n --\n --\tvsnprintf(msg, sizeof(msg), err, params);\n +-\tchar *p;\n +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n -+\tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n - \tfor (p = msg; *p; p++) {\n ++\tchar *p, *pend = msg + sizeof(msg);\n + \n +-\tvsnprintf(msg, sizeof(msg), err, params);\n +-\tfor (p = msg; *p; p++) {\n ++\tp = msg + off < pend ? msg + off : pend - 1;\n ++\tif (vsnprintf(p, pend - p, err, params) < 0)\n ++\t\treturn; /* vsnprintf() failed, there is nothing we can do */\n ++\n ++\tfor (; p != pend - 1 && *p; p++) {\n \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n \t\t\t*p = '?';\n \t}\n -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n -+\tif (ret > 0) {\n -+\t\tif (off + ret > sizeof(msg) - 1)\n -+\t\t\tret = sizeof(msg) - 1 - off;\n -+\t\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n -+\t\tfflush(stderr);\n -+\t\txwrite(2, msg, off + ret + 1);\n -+\t}\n ++\n ++\t*(p++) = '\\n'; /* we no longer need a NUL */\n ++\tfflush(stderr);\n ++\txwrite(2, msg, p - msg);\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n\n-- \ngitgitgadget\n"},{"id":"385080","messageId":"20191029134932.GA2843@sigill.intra.peff.net","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910291222500.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-29T13:49:32Z","receivedAt":"2019-10-29T13:49:34Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Oct 29, 2019 at 01:30:51PM +0100, Johannes Schindelin wrote:\n\n> > Also, this is only to help output from us that goes via vreportf() and\n> > other codepaths in us that use stdio to write to the standard error\n> > stream can still get mixed on Windows (I think the answer is yes,\n> > because we wouldn't need fflush() in this patch if we are covering all\n> > writes to the standard error stream)?\n> \n> Yes, `write()` can get interrupted, so there is still a slight chance of\n> interleaving.\n> \n> However, with `fprintf()`, apparently the MSVC runtime essentially\n> writes and flushes one character at a time, which will make it _much_\n> more likely that two competing processes write interleaved messages to\n> `stderr`.\n\nWow, they have truly taken \"unbuffered\" to a whole new level.\n\nI don't mind seeing this for all platforms, though. I can't think of any\ndownside, and having one less moving part to contend with in our\nerror-reporting code seems like a good thing.\n\n> > > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > > +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> >\n> > Like snprintf(3) the strlcpy() and strlcat() functions return the\n> > total length of the string they tried to create. For strlcpy() that\n> > means the length of src.\n> \n> True (I misread `compat/strlcpy.c` and forgot to consult the\n> documentation). This length can be longer than `msg`, of course.\n\nI'd recommend xsnprintf() here. If we have a prefix longer than our\nvreportf() buffer, I think a BUG() is the right outcome.\n\n> I `git grep`ed and saw that only very short `prefix`es are hard-coded.\n> So that is a hypothetical concern.\n> \n> However, Alex also indicated his discomfort with this, so I will change\n> the code to account for a `prefix` that is too long (the entire error\n> message will be clipped away in that case, which is unfortunate, but to\n> be expected).\n\nI'd disagree here. Any caller sending an arbitrarily-large prefix is\nholding it wrong, and we'd probably want to know as soon as possible\n(and a BUG() is our best bet there).\n\n-Peff\n"},{"id":"385081","messageId":"20191029135221.GB2843@sigill.intra.peff.net","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910291334210.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-29T13:52:21Z","receivedAt":"2019-10-29T13:52:23Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Oct 29, 2019 at 01:38:49PM +0100, Johannes Schindelin wrote:\n\n> > > Let's avoid this predicament altogether by rendering the entire message,\n> > > including the prefix and the trailing newline, into the buffer we\n> > > already have (and which is still fixed size) and then write it out via\n> > > `write_in_full()`.\n> >\n> > s/write_in_full/xwrite/ perhaps? Both the cover letter and the patch\n> > below use xwrite().\n> \n> Excellent eyes! I had originally used `write_in_full()` before realizing\n> that `xwrite()` would be more appropriate.\n\nWhat's your reasoning there? We wouldn't expect xwrite() to ever return\nwith a partial write. But if it did for whatever reason, surely we'd\nprefer to keep trying to print the rest of the error rather than leave\nit truncated? We might see an error on the subsequent write(), but it's\nworth calling it to find out, I'd think.\n\n-Peff\n"},{"id":"385084","messageId":"nycvar.QRO.7.76.6.1910291510330.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"20191029134932.GA2843@sigill.intra.peff.net","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-29T14:13:39Z","receivedAt":"2019-10-29T14:13:50Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Tue, 29 Oct 2019, Jeff King wrote:\n\n> On Tue, Oct 29, 2019 at 01:30:51PM +0100, Johannes Schindelin wrote:\n>\n> > > Also, this is only to help output from us that goes via vreportf() and\n> > > other codepaths in us that use stdio to write to the standard error\n> > > stream can still get mixed on Windows (I think the answer is yes,\n> > > because we wouldn't need fflush() in this patch if we are covering all\n> > > writes to the standard error stream)?\n> >\n> > Yes, `write()` can get interrupted, so there is still a slight chance of\n> > interleaving.\n> >\n> > However, with `fprintf()`, apparently the MSVC runtime essentially\n> > writes and flushes one character at a time, which will make it _much_\n> > more likely that two competing processes write interleaved messages to\n> > `stderr`.\n>\n> Wow, they have truly taken \"unbuffered\" to a whole new level.\n>\n> I don't mind seeing this for all platforms, though. I can't think of any\n> downside, and having one less moving part to contend with in our\n> error-reporting code seems like a good thing.\n>\n> > > > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > > > +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> > >\n> > > Like snprintf(3) the strlcpy() and strlcat() functions return the\n> > > total length of the string they tried to create. For strlcpy() that\n> > > means the length of src.\n> >\n> > True (I misread `compat/strlcpy.c` and forgot to consult the\n> > documentation). This length can be longer than `msg`, of course.\n>\n> I'd recommend xsnprintf() here. If we have a prefix longer than our\n> vreportf() buffer, I think a BUG() is the right outcome.\n\nBut BUG_fl() calls vreportf(). I am worried about an infinite\nrecursion...\n\n>\n> > I `git grep`ed and saw that only very short `prefix`es are hard-coded.\n> > So that is a hypothetical concern.\n> >\n> > However, Alex also indicated his discomfort with this, so I will change\n> > the code to account for a `prefix` that is too long (the entire error\n> > message will be clipped away in that case, which is unfortunate, but to\n> > be expected).\n>\n> I'd disagree here. Any caller sending an arbitrarily-large prefix is\n> holding it wrong, and we'd probably want to know as soon as possible\n> (and a BUG() is our best bet there).\n\nHow about truncating already inside the prefix, then? It would miss the\nentire error message... but at least it would print _something_...\n\nCiao,\nDscho\n"},{"id":"385085","messageId":"nycvar.QRO.7.76.6.1910291514090.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"20191029135221.GB2843@sigill.intra.peff.net","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-29T14:18:29Z","receivedAt":"2019-10-29T14:18:44Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Tue, 29 Oct 2019, Jeff King wrote:\n\n> On Tue, Oct 29, 2019 at 01:38:49PM +0100, Johannes Schindelin wrote:\n>\n> > > > Let's avoid this predicament altogether by rendering the entire message,\n> > > > including the prefix and the trailing newline, into the buffer we\n> > > > already have (and which is still fixed size) and then write it out via\n> > > > `write_in_full()`.\n> > >\n> > > s/write_in_full/xwrite/ perhaps? Both the cover letter and the patch\n> > > below use xwrite().\n> >\n> > Excellent eyes! I had originally used `write_in_full()` before realizing\n> > that `xwrite()` would be more appropriate.\n>\n> What's your reasoning there? We wouldn't expect xwrite() to ever return\n> with a partial write. But if it did for whatever reason, surely we'd\n> prefer to keep trying to print the rest of the error rather than leave\n> it truncated? We might see an error on the subsequent write(), but it's\n> worth calling it to find out, I'd think.\n\nOh, `xwrite()` does not write in full, eh? But at least it continues on\n`EINTR`...\n\nWill fix.\nDscho\n"},{"id":"385086","messageId":"1a6119b4-b44f-0edd-da18-46b7d31a274f@syntevo.com","threadId":"52140","inReplyTo":"e426627e1494e31e548fe044c1c1806ff59340cf.1572356272.git.gitgitgadget@gmail.com","subject":"Re: [PATCH v2 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Alexandr Miloslavskiy","fromEmail":"alexandr.miloslavskiy@syntevo.com","sentAt":"2019-10-29T14:21:37Z","receivedAt":"2019-10-29T14:21:43Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"On 29.10.2019 14:37, Johannes Schindelin via GitGitGadget wrote:\n\n > -\tvsnprintf(msg, sizeof(msg), err, params);\n > -\tfor (p = msg; *p; p++) {\n > +\tp = msg + off < pend ? msg + off : pend - 1;\n\nAccording to my understanding, this is undefined behavior:\n\nhttp://www.open-std.org/jtc1/sc22/wg21/docs/papers/2011/n3242.pdf\n... Unless both pointers point to elements of the same array object, or \none past the last element of the array object, the behavior is undefined.\n\n > The MSVC runtime behavior differs from glibc's with respect to\n > `fprintf(stderr, ...)` in that the former writes out the message\n > character by character.\n\nCan you please preserve the research text about fprintf() behavior on \ndifferent platforms that I provided before? Change formatting to what \nyou think fits best.\n\nfprintf() has problems with any buffering settings\n--------------------------------------------------\n1) If `stderr` is fully buffered:\n the ordering of `stdout` and `stderr` messages could be wrong,\n because `stderr` output waits for the buffer to become full.\n2) If `stderr` has any type of buffering:\n buffer has fixed size, which could lead to interleaved buffer blocks\n when two threads/processes write at the same time.\n3) If `stderr` is not buffered:\n Some implementations, such as VC++ and MinGW, literally disable\n buffering and `fprintf()` will output char-by-char, which leads to\n unreadable char-interleaved writes if two processes write to\n `stderr` at the same time (threads are OK because `fprintf()`\n usually locks `FILE*` in current process).\n4) If stderr is line buffered: MinGW/VC++ will enable full buffering\n instead. See MSDN for `setvbuf()`.\n\nfprintf() behavior in git, per platform\n---------------------------------------\n1) libc - large outputs can be block-interleaved\n fprintf() enables temporary stream buffering.\n Code references:\n buffered_vfprintf()\n2) VC++ - char-interleaved\n fprintf() enables temporary stream buffering, but only if stream was\n not set to no buffering. This has no effect, because stderr is not\n buffered by default, and git takes an extra step to ensure that in\n `swap_osfhnd()`.\n Code references:\n _iob[_IOB_ENTRIES]\n __acrt_stdio_temporary_buffering_guard\n has_any_buffer()\n3) MinGW - char-interleaved (console), full buffering (file)\n `fprintf()` obeys `stderr` buffering. But it uses old MSVCRT.DLL,\n which eventually calls `_flsbuf()`, which enables buffering unless\n `isatty(stderr)` or buffering is disabled. Buffering is not disabled\n by default for `stderr`. Therefore, buffering is enabled only for\n file-redirected `stderr`.\n Code references:\n __mingw_vfprintf()\n __pformat_wcputs()\n _fputc_nolock()\n _flsbuf()\n _iob[_IOB_ENTRIES]\n\n"},{"id":"385088","messageId":"20191029143246.GA3683@sigill.intra.peff.net","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910291510330.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-29T14:32:46Z","receivedAt":"2019-10-29T14:32:48Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Oct 29, 2019 at 03:13:39PM +0100, Johannes Schindelin wrote:\n\n> > I'd recommend xsnprintf() here. If we have a prefix longer than our\n> > vreportf() buffer, I think a BUG() is the right outcome.\n> \n> But BUG_fl() calls vreportf(). I am worried about an infinite\n> recursion...\n\nGood point. I think it would be OK in practice (BUG() gives its own\nlength-limited prefix), but it's probably a good idea to err on the side\nof caution inside vreportf.\n\n> > I'd disagree here. Any caller sending an arbitrarily-large prefix is\n> > holding it wrong, and we'd probably want to know as soon as possible\n> > (and a BUG() is our best bet there).\n> \n> How about truncating already inside the prefix, then? It would miss the\n> entire error message... but at least it would print _something_...\n\nYeah, that might be OK. Hopefully missing the whole rest of the error\nmessage would cause some tests to fail.\n\nYou could also abort() after having written if we want to be more\nBUG()-like.\n\n-Peff\n"},{"id":"385091","messageId":"xmqqtv7r5wn3.fsf@gitster-ct.c.googlers.com","threadId":"52140","inReplyTo":"20191029134932.GA2843@sigill.intra.peff.net","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-10-29T16:44:48Z","receivedAt":"2019-10-29T16:44:51Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> Wow, they have truly taken \"unbuffered\" to a whole new level.\n>\n> I don't mind seeing this for all platforms, though. I can't think of any\n> downside, and having one less moving part to contend with in our\n> error-reporting code seems like a good thing.\n\nFWIW, it was my mistake to sound as if I was unhappy to see this\ndone on all platforms. As long as the end result is to reasonably\nbuffer, I do not mind us (as opposed to the system library we\nsometimes cannot trust) being the one who implements the buffering.\n\nI very much prefer to see the same code run everywhere than #ifdef\nin this case.\n\n> I'd recommend xsnprintf() here. If we have a prefix longer than our\n> vreportf() buffer, I think a BUG() is the right outcome.\n> ...\n> I'd disagree here. Any caller sending an arbitrarily-large prefix is\n> holding it wrong, and we'd probably want to know as soon as possible\n> (and a BUG() is our best bet there).\n\nYes. We are not using an unvetted input as the prefix here, if\nsomebody needs to use a larger prefix somewhere, that patch needs to\nargue the pros-and-cons between making the buffer larger or\nshortening that larger prefix.\n\n\n"},{"id":"385096","messageId":"nycvar.QRO.7.76.6.1910292049530.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"1a6119b4-b44f-0edd-da18-46b7d31a274f@syntevo.com","subject":"Re: [PATCH v2 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-29T19:57:33Z","receivedAt":"2019-10-29T19:58:03Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Alex,\n\nOn Tue, 29 Oct 2019, Alexandr Miloslavskiy wrote:\n\n> On 29.10.2019 14:37, Johannes Schindelin via GitGitGadget wrote:\n>\n> > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > -\tfor (p = msg; *p; p++) {\n> > +\tp = msg + off < pend ? msg + off : pend - 1;\n>\n> According to my understanding, this is undefined behavior:\n\nIt is not entirely obvious to me what exactly you mean by \"this\",\nassuming that you refer to comparing two pointers via `<`, I agree that\nthis is not the best idea, I changed it to `off < pend - msg`. If my\nassumption is correct, however, we are still talking about C, so I\nwonder how this C++ document you linked could bear any relevance:\n\n> http://www.open-std.org/jtc1/sc22/wg21/docs/papers/2011/n3242.pdf\n> ... Unless both pointers point to elements of the same array object, or one\n> past the last element of the array object, the behavior is undefined.\n>\n> > The MSVC runtime behavior differs from glibc's with respect to\n> > `fprintf(stderr, ...)` in that the former writes out the message\n> > character by character.\n>\n> Can you please preserve the research text about fprintf() behavior on\n> different platforms that I provided before? Change formatting to what you\n> think fits best.\n\nQuite honestly, I purposefully refrained from copying that information.\nWhile even the following paragraphs are incomplete by necessity (there\nare many more standard C libraries we try to work against, e.g. musl and\nnewlibc, and it would be insanity to try to cover them all in an\nanalysis of stdio buffering), the only finding that is relevant to the\npatch under discussion is that MSVC's runtime outputs to `stderr` byte\nby byte (or more correctly, character by character, I guess), and I did\nmention this in the commit message (in the part you quoted).\n\nThanks,\nDscho\n\n>\n> fprintf() has problems with any buffering settings\n> --------------------------------------------------\n> 1) If `stderr` is fully buffered:\n> the ordering of `stdout` and `stderr` messages could be wrong,\n> because `stderr` output waits for the buffer to become full.\n> 2) If `stderr` has any type of buffering:\n> buffer has fixed size, which could lead to interleaved buffer blocks\n> when two threads/processes write at the same time.\n> 3) If `stderr` is not buffered:\n> Some implementations, such as VC++ and MinGW, literally disable\n> buffering and `fprintf()` will output char-by-char, which leads to\n> unreadable char-interleaved writes if two processes write to\n> `stderr` at the same time (threads are OK because `fprintf()`\n> usually locks `FILE*` in current process).\n> 4) If stderr is line buffered: MinGW/VC++ will enable full buffering\n> instead. See MSDN for `setvbuf()`.\n>\n> fprintf() behavior in git, per platform\n> ---------------------------------------\n> 1) libc - large outputs can be block-interleaved\n> fprintf() enables temporary stream buffering.\n> Code references:\n> buffered_vfprintf()\n> 2) VC++ - char-interleaved\n> fprintf() enables temporary stream buffering, but only if stream was\n> not set to no buffering. This has no effect, because stderr is not\n> buffered by default, and git takes an extra step to ensure that in\n> `swap_osfhnd()`.\n> Code references:\n> _iob[_IOB_ENTRIES]\n> __acrt_stdio_temporary_buffering_guard\n> has_any_buffer()\n> 3) MinGW - char-interleaved (console), full buffering (file)\n> `fprintf()` obeys `stderr` buffering. But it uses old MSVCRT.DLL,\n> which eventually calls `_flsbuf()`, which enables buffering unless\n> `isatty(stderr)` or buffering is disabled. Buffering is not disabled\n> by default for `stderr`. Therefore, buffering is enabled only for\n> file-redirected `stderr`.\n> Code references:\n> __mingw_vfprintf()\n> __pformat_wcputs()\n> _fputc_nolock()\n> _flsbuf()\n> _iob[_IOB_ENTRIES]\n>\n>\n"},{"id":"385097","messageId":"fce0894ee46f737322551b51edf5cd2a53413a50.1572379280.git.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":"pull.428.v3.git.1572379280.gitgitgadget@gmail.com","subject":"[PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-29T20:01:20Z","receivedAt":"2019-10-29T20:01:26Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"From: Johannes Schindelin \n\nThe MSVC runtime behavior differs from glibc's with respect to\n`fprintf(stderr, ...)` in that the former writes out the message\ncharacter by character.\n\nIn t5516, this leads to a funny problem where a `git fetch` process as\nwell as the `git upload-pack` process spawned by it _both_ call `die()`\nat the same time. The output can look like this:\n\n\tfatal: git uploadfata-lp: raemcokte :error: upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n\t8e86a771eda009872d6ab2886\n\nLet's avoid this predicament altogether by rendering the entire message,\nincluding the prefix and the trailing newline, into the buffer we\nalready have (and which is still fixed size) and then write it out via\n`write_in_full()`.\n\nWe still clip the message to at most 4095 characters.\n\nThe history of `vreportf()` with regard to this issue includes the\nfollowing commits:\n\nd048a96e (2007-11-09) - 'char msg[256]' is introduced to avoid interleaving\n389d1767 (2009-03-25) - Buffer size increased to 1024 to avoid truncation\n625a860c (2009-11-22) - Buffer size increased to 4096 to avoid truncation\nf4c3edc0 (2015-08-11) - Buffer removed to avoid truncation\nb5a9e435 (2017-01-11) - Reverts f4c3edc0 to be able to replace control\n chars before sending to stderr\n9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n This is seemingly related to d048a96e.\n137a0d0e (2007-11-19) - Addresses out-of-order for display()\n34df8aba (2009-03-10) - Switches xwrite() to fprintf() in recv_sideband()\n to support UTF-8 emulation\neac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\n so it's safe to use xwrite() again\n5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n\nNote that we print nothing if the `vsnprintf()` call failed to render\nthe error message; There is little we can do in that case, and it should\nnot happen anyway.\n\nAlso please note that we `fflush(stderr)` here to help when running in a\nGit Bash on Windows: in this case, `stderr` is not actually truly\nunbuffered, and needs the extra help.\n\nHelped-by: Jeff King \nHelped-by: Alexandr Miloslavskiy \nHelped-by: SZEDER Gábor \nHelped-by: Junio C Hamano \nSigned-off-by: Johannes Schindelin \n---\n usage.c | 15 +++++++++++----\n 1 file changed, 11 insertions(+), 4 deletions(-)\n\ndiff --git a/usage.c b/usage.c\nindex 2fdb20086b..471efb2de9 100644\n--- a/usage.c\n+++ b/usage.c\n@@ -9,14 +9,21 @@\n void vreportf(const char *prefix, const char *err, va_list params)\n {\n \tchar msg[4096];\n-\tchar *p;\n+\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n+\tchar *p, *pend = msg + sizeof(msg);\n \n-\tvsnprintf(msg, sizeof(msg), err, params);\n-\tfor (p = msg; *p; p++) {\n+\tp = off < pend - msg ? msg + off : pend - 1;\n+\tif (vsnprintf(p, pend - p, err, params) < 0)\n+\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n+\n+\tfor (; p != pend - 1 && *p; p++) {\n \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n \t\t\t*p = '?';\n \t}\n-\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n+\n+\t*(p++) = '\\n'; /* we no longer need a NUL */\n+\tfflush(stderr);\n+\twrite_in_full(2, msg, p - msg);\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n-- \ngitgitgadget\n"},{"id":"385098","messageId":"pull.428.v3.git.1572379280.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":"pull.428.v2.git.1572356272.gitgitgadget@gmail.com","subject":"[PATCH v3 0/1] Fix t5516 flakiness in Visual Studio builds","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-29T20:01:19Z","receivedAt":"2019-10-29T20:01:26Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Among the flaky tests, it seems that the Azure Pipeline suffers relatively\nfrequently from t5516 failing with the Visual Studio builds. Essentially, we\ngrep for an error message, but that error message is produced twice, once by\na fetch and once by the upload-pack spawned from it, and those error\nmessages are usually interleaved because of MSVC runtime fprintf() \nidiosyncracies.\n\nAs a consequence, I have to re-run about half a dozen failed builds a day,\nwhich I would like to avoid. My plan is therefore to merge this patch into\nGit for Windows v2.24.0-rc2.\n\nThe commit message of this patch is based, in part, on \nhttps://github.com/gitgitgadget/git/pull/407. \n\nThis fixes https://github.com/gitgitgadget/git/issues/240.\n\nChanges since v2:\n\n * Using write_in_full() instead of xwrite() again (to make sure that the\n entire message is printed).\n * When vsnprintf() fails, now we at least print the prefix.\n * The code to check whether prefix was too long no longer tests an\n inequality between pointers, but between sizes.\n\nChanges since v1:\n\n * Changed the oneline to be more accurate (thanks Junio).\n * Improved the commit message (e.g. talking about the xwrite() function\n this patch uses, rather than the write_in_full() function used by an\n earlier iteration, thanks Gábor).\n * Revamped the actual code to account for insanely long prefixes (thanks\n for the advice, Junio).\n\nJohannes Schindelin (1):\n vreportf(): avoid relying on stdio buffering\n\n usage.c | 15 +++++++++++----\n 1 file changed, 11 insertions(+), 4 deletions(-)\n\n\nbase-commit: 566a1439f6f56c2171b8853ddbca0ad3f5098770\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-428%2Fdscho%2Ffix-t5516-flakiness-v3\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-428/dscho/fix-t5516-flakiness-v3\nPull-Request: https://github.com/gitgitgadget/git/pull/428\n\nRange-diff vs v2:\n\n 1: e426627e14 ! 1: fce0894ee4 vreportf(): avoid relying on stdio buffering\n @@ -16,7 +16,7 @@\n Let's avoid this predicament altogether by rendering the entire message,\n including the prefix and the trailing newline, into the buffer we\n already have (and which is still fixed size) and then write it out via\n - `xwrite()`.\n + `write_in_full()`.\n \n We still clip the message to at most 4095 characters.\n \n @@ -46,6 +46,7 @@\n Git Bash on Windows: in this case, `stderr` is not actually truly\n unbuffered, and needs the extra help.\n \n + Helped-by: Jeff King \n Helped-by: Alexandr Miloslavskiy \n Helped-by: SZEDER Gábor \n Helped-by: Junio C Hamano \n @@ -64,9 +65,9 @@\n \n -\tvsnprintf(msg, sizeof(msg), err, params);\n -\tfor (p = msg; *p; p++) {\n -+\tp = msg + off < pend ? msg + off : pend - 1;\n ++\tp = off < pend - msg ? msg + off : pend - 1;\n +\tif (vsnprintf(p, pend - p, err, params) < 0)\n -+\t\treturn; /* vsnprintf() failed, there is nothing we can do */\n ++\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n +\n +\tfor (; p != pend - 1 && *p; p++) {\n \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n @@ -76,7 +77,7 @@\n +\n +\t*(p++) = '\\n'; /* we no longer need a NUL */\n +\tfflush(stderr);\n -+\txwrite(2, msg, p - msg);\n ++\twrite_in_full(2, msg, p - msg);\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n\n-- \ngitgitgadget\n"},{"id":"385100","messageId":"20191029200936.GA12337@sigill.intra.peff.net","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910292049530.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-29T20:09:36Z","receivedAt":"2019-10-29T20:09:38Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Oct 29, 2019 at 08:57:33PM +0100, Johannes Schindelin wrote:\n\n> > On 29.10.2019 14:37, Johannes Schindelin via GitGitGadget wrote:\n> >\n> > > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > > -\tfor (p = msg; *p; p++) {\n> > > +\tp = msg + off < pend ? msg + off : pend - 1;\n> >\n> > According to my understanding, this is undefined behavior:\n> \n> It is not entirely obvious to me what exactly you mean by \"this\",\n> assuming that you refer to comparing two pointers via `<`, I agree that\n> this is not the best idea, I changed it to `off < pend - msg`. If my\n> assumption is correct, however, we are still talking about C, so I\n> wonder how this C++ document you linked could bear any relevance:\n\nI think the issue is not the comparison, but rather that forming the\npointer \"msg + off\" is undefined, since its point outside of any object\n(including the \"one past\" rule). And this is illegal in both C and C++,\nthough of course it works fine in practice most of the time.\n\nDoing \"off < pend - msg\" is legal. Or note that \"pend\" is just\n\"msg + sizeof(msg)\", subtract out the common term and end up with\n\"off < sizeof(msg)\". :)\n\n> > Can you please preserve the research text about fprintf() behavior on\n> > different platforms that I provided before? Change formatting to what you\n> > think fits best.\n> \n> Quite honestly, I purposefully refrained from copying that information.\n> While even the following paragraphs are incomplete by necessity (there\n> are many more standard C libraries we try to work against, e.g. musl and\n> newlibc, and it would be insanity to try to cover them all in an\n> analysis of stdio buffering), the only finding that is relevant to the\n> patch under discussion is that MSVC's runtime outputs to `stderr` byte\n> by byte (or more correctly, character by character, I guess), and I did\n> mention this in the commit message (in the part you quoted).\n\nOne other case is impacted, which is:\n\n> > 1) If `stderr` is fully buffered:\n> > the ordering of `stdout` and `stderr` messages could be wrong,\n> > because `stderr` output waits for the buffer to become full.\n\nWe'll now output the stderr message closer to its time-of-printing,\nwhich is a good thing (it may still be in a weird place with respect to\na buffered stdout, but getting the error message out ASAP is the best we\ncan do there).\n\nI agree that the rest of the research is not especially relevant to the\ncode change (though I'm glad it is available in the list archive).\n\n-Peff\n"},{"id":"385101","messageId":"nycvar.QRO.7.76.6.1910292101300.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"20191029143246.GA3683@sigill.intra.peff.net","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-29T20:09:14Z","receivedAt":"2019-10-29T20:09:39Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Tue, 29 Oct 2019, Jeff King wrote:\n\n> On Tue, Oct 29, 2019 at 03:13:39PM +0100, Johannes Schindelin wrote:\n> >\n> > > I'd disagree here. Any caller sending an arbitrarily-large prefix\n> > > is holding it wrong, and we'd probably want to know as soon as\n> > > possible (and a BUG() is our best bet there).\n> >\n> > How about truncating already inside the prefix, then? It would miss\n> > the entire error message... but at least it would print\n> > _something_...\n>\n> Yeah, that might be OK. Hopefully missing the whole rest of the error\n> message would cause some tests to fail.\n\nI am not really worried about that. So far, we only have prefixes like\n`\"fatal: \"` or `\"error: \"`. The longest prefix is in `BUG_fl()` itself,\nwhen we have access to the file name and the line number of the\ntriggering line, in which case it is `\"BUG: :: \"`. So as\nlong as nobody builds a custom version of Git that includes a file whose\npath is insanely long, they should be fine. I am certain that Junio will\nnever accept such a file into git.git.\n\nOh, and even if anybody would introduce insanely long paths into their\nfork of git.git, they would _still_ be safe because `BUG_fl()` limits\nthe prefix to 256 bytes, including `NUL`.\n\n> You could also abort() after having written if we want to be more\n> BUG()-like.\n\nAs I said, this is really a part of the patch I am not at all concerned\nabout. The prefixes are well under control, and I only addressed that\npotential future breakage (that I believe falls squarely into YAGNI\nterritory) only because two reviewers seemed to be concerned.\n\nI really believe that the care I put into the patch to safeguard against\noverly long prefixes is seriously overkill.\n\nCiao,\nDscho\n"},{"id":"385102","messageId":"97291857-42a2-4865-b265-d55fcf131ba5@syntevo.com","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910292049530.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Alexandr Miloslavskiy","fromEmail":"alexandr.miloslavskiy@syntevo.com","sentAt":"2019-10-29T20:11:29Z","receivedAt":"2019-10-29T20:11:33Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"On 29.10.2019 20:57, Johannes Schindelin wrote:\n\n> It is not entirely obvious to me what exactly you mean by \"this\",\n> assuming that you refer to comparing two pointers via `<`, I agree that\n> this is not the best idea, I changed it to `off < pend - msg`. If my\n> assumption is correct, however, we are still talking about C, so I\n> wonder how this C++ document you linked could bear any relevance:\n\nThe linked portion of text speaks about adding to pointer. The paragraph \nis a bit long and my quote was indeed hard to grasp. And yes, sorry, C++ \nhabits. However, the same thing applies to C, let's have this link instead:\n\nhttps://web.archive.org/web/20181230041359if_/http://www.open-std.org/jtc1/sc22/wg14/www/abq/c17_updated_proposed_fdis.pdf\n\nHopefully a better quote this time (c/c++ standard are hard to read for \nmortals like me):\n\nWhen an expression that has integer type is added to or subtracted from \na pointer <...> If both the pointer operand and the result point\nto elements of the same array object, or one past the last element of \nthe array object, <...> otherwise, the behavior is undefined.\n\n> Quite honestly, I purposefully refrained from copying that information.\n\nThat's a pity, I've put quite an effort into researching all that.\n"},{"id":"385105","messageId":"56f1bb8c-c4dc-4537-b42b-e728d2f2df19@syntevo.com","threadId":"52140","inReplyTo":"20191029200936.GA12337@sigill.intra.peff.net","subject":"Re: [PATCH v2 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Alexandr Miloslavskiy","fromEmail":"alexandr.miloslavskiy@syntevo.com","sentAt":"2019-10-29T20:24:54Z","receivedAt":"2019-10-29T20:24:55Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"On 29.10.2019 21:09, Jeff King wrote:\n\n> I think the issue is not the comparison, but rather that forming the\n> pointer \"msg + off\" is undefined, since its point outside of any object\n> (including the \"one past\" rule). And this is illegal in both C and C++,\n\nYes, thanks for clarifying.\n\n > + p = msg + off < pend ? msg + off : pend - 1;\n\n > though of course it works fine in practice most of the time.\n\nThe easiest thing that an optimizer can do (and that's actually quite \nlikely in my understanding) is to conclude that 'msg + off' is the only \nnon-UB branch here, therefore 'msg + off < pend' can be taken as always \ntrue, and then discard 'pend - 1' branch. Afterall, UB serve the biggest \nrole in optimizations.\n\nThat's even more true now that all parts of equation are local and easy \nto grasp for static analysis.\n"},{"id":"385108","messageId":"20191029203259.GB12337@sigill.intra.peff.net","threadId":"52140","inReplyTo":"fce0894ee46f737322551b51edf5cd2a53413a50.1572379280.git.gitgitgadget@gmail.com","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-29T20:32:59Z","receivedAt":"2019-10-29T20:33:02Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Oct 29, 2019 at 08:01:20PM +0000, Johannes Schindelin via GitGitGadget wrote:\n\n> diff --git a/usage.c b/usage.c\n> index 2fdb20086b..471efb2de9 100644\n> --- a/usage.c\n> +++ b/usage.c\n> @@ -9,14 +9,21 @@\n> void vreportf(const char *prefix, const char *err, va_list params)\n> {\n> \tchar msg[4096];\n> -\tchar *p;\n> +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> +\tchar *p, *pend = msg + sizeof(msg);\n> \n> -\tvsnprintf(msg, sizeof(msg), err, params);\n> -\tfor (p = msg; *p; p++) {\n> +\tp = off < pend - msg ? msg + off : pend - 1;\n> +\tif (vsnprintf(p, pend - p, err, params) < 0)\n> +\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n> +\n> +\tfor (; p != pend - 1 && *p; p++) {\n> \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> \t\t\t*p = '?';\n> \t}\n\nThis version looks OK to me. Some bikeshedding:\n\n - I suspect it may be more readable to just stick to offsets instead\n of pointers, since that's what strlcpy() and vsnprintf() give us.\n\n - I don't think \"p == pend - 1\" can ever trigger, since either\n vsnprintf() or we will have just written a NUL.\n\n - Do we need to contend with vsnprintf() return a negative value in\n general in our codebase? We already BUG() on it elsewhere. Yes, that\n BUG() would try to write via this code path, but it implies to me\n that we've already dealt with any such broken vsnprintf()\n implementations (via compat/snprintf.c).\n\nIf you're sick of bikeshedding, though, I can live without any of those\nbeing addressed.\n\n> +\t*(p++) = '\\n'; /* we no longer need a NUL */\n> +\tfflush(stderr);\n> +\twrite_in_full(2, msg, p - msg);\n\nOne non-bikeshed question: would fprintf() on some platforms have sent\n\"\\r\\n\", which is no longer happening with our write()? Do we need to\ncare about that?\n\n-Peff\n"},{"id":"385127","messageId":"xmqqsgnb3t5l.fsf@gitster-ct.c.googlers.com","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910292101300.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH 1/1] vreportf(): avoid buffered write in favor of unbuffered one","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-10-30T01:43:02Z","receivedAt":"2019-10-30T01:43:11Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Johannes Schindelin writes:\n\n> I really believe that the care I put into the patch to safeguard against\n> overly long prefixes is seriously overkill.\n\nIf it was buggy, the care given to it probably was insufficient, not\noverkill ;-)\n\nAs long as we know there won't be an overflow, and our compilers\nwon't complain about possible overflow, simpler code that is easier\nto reason about is better. I tend to think that Peff's\n\"consistently count based on offsets, instead of pointer arithmetic\nthat you can easily get wrong\" would give us an easier-to-read\nresult in this case.\n\nThanks for simplifying the original \"overkill\" version. Except for\nthe bug resulting from misunderstanding of strlcpy() return value,\nthe version I saw was a quite pleasant read.\n\n\n"},{"id":"385129","messageId":"xmqqo8xz3sa2.fsf@gitster-ct.c.googlers.com","threadId":"52140","inReplyTo":"fce0894ee46f737322551b51edf5cd2a53413a50.1572379280.git.gitgitgadget@gmail.com","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-10-30T02:01:57Z","receivedAt":"2019-10-30T02:02:02Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"\"Johannes Schindelin via GitGitGadget\" \nwrites:\n\n> Subject: Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering\n\nperfect ;-)\n\n> Let's avoid this predicament altogether by rendering the entire message,\n> including the prefix and the trailing newline, into the buffer we\n> already have (and which is still fixed size) and then write it out via\n> `write_in_full()`.\n>\n> We still clip the message to at most 4095 characters.\n\nGood.\n\n> Also please note that we `fflush(stderr)` here to help when running in a\n> Git Bash on Windows: in this case, `stderr` is not actually truly\n> unbuffered, and needs the extra help.\n\nI do not think you have to single out Windows in this case; if we\nare writing directly to file descriptor #2, as long as there have\nbeen something written by the process to the standard error stream\nbefore our caller called us, we must flush it to make sure what\nwe are going to write out will come after, no matter what platform\nwe are on.\n\n The process may have written to the standard error stream and\n there may be something left in the buffer kept in the stdio\n layer. Call fflush(stderr) before writing the message we\n prepare in this function.\n\nor something along that line would be sufficient.\n\n> diff --git a/usage.c b/usage.c\n> index 2fdb20086b..471efb2de9 100644\n> --- a/usage.c\n> +++ b/usage.c\n> @@ -9,14 +9,21 @@\n> void vreportf(const char *prefix, const char *err, va_list params)\n> {\n> \tchar msg[4096];\n> -\tchar *p;\n> +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> +\tchar *p, *pend = msg + sizeof(msg);\n> \n> -\tvsnprintf(msg, sizeof(msg), err, params);\n> -\tfor (p = msg; *p; p++) {\n> +\tp = off < pend - msg ? msg + off : pend - 1;\n> +\tif (vsnprintf(p, pend - p, err, params) < 0)\n> +\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n> +\n> +\tfor (; p != pend - 1 && *p; p++) {\n\nIt may make the result much simpler to start with something like:\n\n\tsize_t prefix_len = strlen(prefix);\n\n\tif (sizeof(msg) <= prefix_len) {\n \t\tfprintf(stderr, \"BUG!!! too long a prefix '%s'\\n\", prefix);\n\t\tabort();\n\t}\n\tmemcpy(msg, prefix, prefix_len);\n\tp = msg + prefix_len;\n\nas we agreed that we won't have prefix that will fill or overflow\nmsg[] based on your earlier reading of the callers like BUG-fl.\nThat way, we probably may be able to even lose the pend pointer and\narithmetic around it.\n\n> \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> \t\t\t*p = '?';\n> \t}\n\nThanks. With this flow it is crystal clear that the prefix is shown\nas-is, while the payload is sanitized.\n\n> -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n> +\n> +\t*(p++) = '\\n'; /* we no longer need a NUL */\n> +\tfflush(stderr);\n> +\twrite_in_full(2, msg, p - msg);\n> }\n> \n> static NORETURN void usage_builtin(const char *err, va_list params)\n"},{"id":"385147","messageId":"nycvar.QRO.7.76.6.1910300947410.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"20191029203259.GB12337@sigill.intra.peff.net","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-30T08:54:52Z","receivedAt":"2019-10-30T08:55:25Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Tue, 29 Oct 2019, Jeff King wrote:\n\n> On Tue, Oct 29, 2019 at 08:01:20PM +0000, Johannes Schindelin via GitGitGadget wrote:\n>\n> > diff --git a/usage.c b/usage.c\n> > index 2fdb20086b..471efb2de9 100644\n> > --- a/usage.c\n> > +++ b/usage.c\n> > @@ -9,14 +9,21 @@\n> > void vreportf(const char *prefix, const char *err, va_list params)\n> > {\n> > \tchar msg[4096];\n> > -\tchar *p;\n> > +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> > +\tchar *p, *pend = msg + sizeof(msg);\n> >\n> > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > -\tfor (p = msg; *p; p++) {\n> > +\tp = off < pend - msg ? msg + off : pend - 1;\n> > +\tif (vsnprintf(p, pend - p, err, params) < 0)\n> > +\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n> > +\n> > +\tfor (; p != pend - 1 && *p; p++) {\n> > \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> > \t\t\t*p = '?';\n> > \t}\n>\n> This version looks OK to me. Some bikeshedding:\n>\n> - I suspect it may be more readable to just stick to offsets instead\n> of pointers, since that's what strlcpy() and vsnprintf() give us.\n\nAn earlier (unsent) iteration did exactly that, but it was quite a bit\nmore unreadable because of the required arithmetics with `sizeof(msg)`.\n\n> - I don't think \"p == pend - 1\" can ever trigger, since either\n> vsnprintf() or we will have just written a NUL.\n\nYou are right, but I wanted to make extra sure that this code is robust\neven (or: especially) in the presence of buggy libc functions.\n\nIt's not even expensive, I don't think.\n\n> - Do we need to contend with vsnprintf() return a negative value in\n> general in our codebase? We already BUG() on it elsewhere. Yes, that\n> BUG() would try to write via this code path, but it implies to me\n> that we've already dealt with any such broken vsnprintf()\n> implementations (via compat/snprintf.c).\n\nIt is true that the test suite bails out with a `BUG()` when\n`vsnprintf()` is broken. But I figured that we want to be safe rather\nthan sorry. Besides, I have no full picture about what potential reasons\ncould make `vsnprintf()` return a negative value: for what I know, an\ninvalid format string could trigger that. And I _really_ want this code\npath to be as robust as I can make it.\n\n> If you're sick of bikeshedding, though, I can live without any of those\n> being addressed.\n\nOh, that's okay, and I would not even call it bikeshedding, I think you\nraised valid concerns.\n\n> > +\t*(p++) = '\\n'; /* we no longer need a NUL */\n> > +\tfflush(stderr);\n> > +\twrite_in_full(2, msg, p - msg);\n>\n> One non-bikeshed question: would fprintf() on some platforms have sent\n> \"\\r\\n\", which is no longer happening with our write()? Do we need to\n> care about that?\n\nI am not aware of any platform where `fprintf()` would automatically\ntransform `\\n` to `\\r\\n`. Not unless the `FILE *` in question has been\nopened with the `t` flag. And I am rather certain that `stderr` is not\nopened with that flag. And if it was, I would force it off in Git for\nWindows.\n\nThanks,\nDscho\n"},{"id":"385149","messageId":"nycvar.QRO.7.76.6.1910300957370.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"xmqqo8xz3sa2.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-30T09:13:26Z","receivedAt":"2019-10-30T09:13:53Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Junio,\n\nOn Wed, 30 Oct 2019, Junio C Hamano wrote:\n\n> \"Johannes Schindelin via GitGitGadget\" \n> writes:\n>\n> > Also please note that we `fflush(stderr)` here to help when running in a\n> > Git Bash on Windows: in this case, `stderr` is not actually truly\n> > unbuffered, and needs the extra help.\n>\n> I do not think you have to single out Windows in this case; if we\n> are writing directly to file descriptor #2, as long as there have\n> been something written by the process to the standard error stream\n> before our caller called us, we must flush it to make sure what\n> we are going to write out will come after, no matter what platform\n> we are on.\n>\n> The process may have written to the standard error stream and\n> there may be something left in the buffer kept in the stdio\n> layer. Call fflush(stderr) before writing the message we\n> prepare in this function.\n>\n> or something along that line would be sufficient.\n\nI replaced the paragraph with a slightly edited version of this. Thanks.\n\n> > diff --git a/usage.c b/usage.c\n> > index 2fdb20086b..471efb2de9 100644\n> > --- a/usage.c\n> > +++ b/usage.c\n> > @@ -9,14 +9,21 @@\n> > void vreportf(const char *prefix, const char *err, va_list params)\n> > {\n> > \tchar msg[4096];\n> > -\tchar *p;\n> > +\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> > +\tchar *p, *pend = msg + sizeof(msg);\n> >\n> > -\tvsnprintf(msg, sizeof(msg), err, params);\n> > -\tfor (p = msg; *p; p++) {\n> > +\tp = off < pend - msg ? msg + off : pend - 1;\n> > +\tif (vsnprintf(p, pend - p, err, params) < 0)\n> > +\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n> > +\n> > +\tfor (; p != pend - 1 && *p; p++) {\n>\n> It may make the result much simpler to start with something like:\n>\n> \tsize_t prefix_len = strlen(prefix);\n>\n> \tif (sizeof(msg) <= prefix_len) {\n> \t\tfprintf(stderr, \"BUG!!! too long a prefix '%s'\\n\", prefix);\n> \t\tabort();\n> \t}\n> \tmemcpy(msg, prefix, prefix_len);\n> \tp = msg + prefix_len;\n>\n> as we agreed that we won't have prefix that will fill or overflow\n> msg[] based on your earlier reading of the callers like BUG-fl.\n\nMakes sense. I was a bit blinded by my endeavor to keep the diffstat\nsmall.\n\n> That way, we probably may be able to even lose the pend pointer and\n> arithmetic around it.\n\nI tried this, and it still looks more obvious to me with `pend`.\n\n> > \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> > \t\t\t*p = '?';\n> > \t}\n>\n> Thanks. With this flow it is crystal clear that the prefix is shown\n> as-is, while the payload is sanitized.\n\nYes ;-)\n\nThanks,\nDscho\n\n> > -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n> > +\n> > +\t*(p++) = '\\n'; /* we no longer need a NUL */\n> > +\tfflush(stderr);\n> > +\twrite_in_full(2, msg, p - msg);\n> > }\n> >\n> > static NORETURN void usage_builtin(const char *err, va_list params)\n>\n>\n"},{"id":"385154","messageId":"pull.428.v4.git.1572432276.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":"pull.428.v3.git.1572379280.gitgitgadget@gmail.com","subject":"[PATCH v4 0/1] Fix t5516 flakiness in Visual Studio builds","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-30T10:44:35Z","receivedAt":"2019-10-30T10:44:41Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Among the flaky tests, it seems that the Azure Pipeline suffers relatively\nfrequently from t5516 failing with the Visual Studio builds. Essentially, we\ngrep for an error message, but that error message is produced twice, once by\na fetch and once by the upload-pack spawned from it, and those error\nmessages are usually interleaved because of MSVC runtime fprintf() \nidiosyncracies.\n\nAs a consequence, I have to re-run about half a dozen failed builds a day,\nwhich I would like to avoid. My plan is therefore to merge this patch into\nGit for Windows v2.24.0-rc2.\n\nThe commit message of this patch is based, in part, on \nhttps://github.com/gitgitgadget/git/pull/407. \n\nThis fixes https://github.com/gitgitgadget/git/issues/240.\n\nChanges since v3:\n\n * Reworded the part of the commit message that talks about the need for \n fflush(stderr); for accuracy, as suggested by Junio.\n * Simplified the flow of the prefix handling as well as providing a proper \n BUG message and abort()ing when the prefix is too long. Thanks Junio!\n\nChanges since v2:\n\n * Using write_in_full() instead of xwrite() again (to make sure that the\n entire message is printed).\n * When vsnprintf() fails, now we at least print the prefix.\n * The code to check whether prefix was too long no longer tests an\n inequality between pointers, but between sizes.\n\nChanges since v1:\n\n * Changed the oneline to be more accurate (thanks Junio).\n * Improved the commit message (e.g. talking about the xwrite() function\n this patch uses, rather than the write_in_full() function used by an\n earlier iteration, thanks Gábor).\n * Revamped the actual code to account for insanely long prefixes (thanks\n for the advice, Junio).\n\nJohannes Schindelin (1):\n vreportf(): avoid relying on stdio buffering\n\n usage.c | 20 ++++++++++++++++----\n 1 file changed, 16 insertions(+), 4 deletions(-)\n\n\nbase-commit: 566a1439f6f56c2171b8853ddbca0ad3f5098770\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-428%2Fdscho%2Ffix-t5516-flakiness-v4\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-428/dscho/fix-t5516-flakiness-v4\nPull-Request: https://github.com/gitgitgadget/git/pull/428\n\nRange-diff vs v3:\n\n 1: fce0894ee4 ! 1: f6d6c8122a vreportf(): avoid relying on stdio buffering\n @@ -42,9 +42,9 @@\n the error message; There is little we can do in that case, and it should\n not happen anyway.\n \n - Also please note that we `fflush(stderr)` here to help when running in a\n - Git Bash on Windows: in this case, `stderr` is not actually truly\n - unbuffered, and needs the extra help.\n + The process may have written to `stderr` and there may be something left\n + in the buffer kept in the stdio layer. Call `fflush(stderr)` before\n + writing the message we prepare in this function.\n \n Helped-by: Jeff King \n Helped-by: Alexandr Miloslavskiy \n @@ -60,12 +60,17 @@\n {\n \tchar msg[4096];\n -\tchar *p;\n -+\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n +\tchar *p, *pend = msg + sizeof(msg);\n ++\tsize_t prefix_len = strlen(prefix);\n \n -\tvsnprintf(msg, sizeof(msg), err, params);\n -\tfor (p = msg; *p; p++) {\n -+\tp = off < pend - msg ? msg + off : pend - 1;\n ++\tif (sizeof(msg) <= prefix_len) {\n ++\t\tfprintf(stderr, \"BUG!!! too long a prefix '%s'\\n\", prefix);\n ++\t\tabort();\n ++\t}\n ++\tmemcpy(msg, prefix, prefix_len);\n ++\tp = msg + prefix_len;\n +\tif (vsnprintf(p, pend - p, err, params) < 0)\n +\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n +\n\n-- \ngitgitgadget\n"},{"id":"385155","messageId":"f6d6c8122abbd6339cf83309ac3761bbdac44023.1572432276.git.gitgitgadget@gmail.com","threadId":"52140","inReplyTo":"pull.428.v4.git.1572432276.gitgitgadget@gmail.com","subject":"[PATCH v4 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-30T10:44:36Z","receivedAt":"2019-10-30T10:44:43Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"From: Johannes Schindelin \n\nThe MSVC runtime behavior differs from glibc's with respect to\n`fprintf(stderr, ...)` in that the former writes out the message\ncharacter by character.\n\nIn t5516, this leads to a funny problem where a `git fetch` process as\nwell as the `git upload-pack` process spawned by it _both_ call `die()`\nat the same time. The output can look like this:\n\n\tfatal: git uploadfata-lp: raemcokte :error: upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n\t8e86a771eda009872d6ab2886\n\nLet's avoid this predicament altogether by rendering the entire message,\nincluding the prefix and the trailing newline, into the buffer we\nalready have (and which is still fixed size) and then write it out via\n`write_in_full()`.\n\nWe still clip the message to at most 4095 characters.\n\nThe history of `vreportf()` with regard to this issue includes the\nfollowing commits:\n\nd048a96e (2007-11-09) - 'char msg[256]' is introduced to avoid interleaving\n389d1767 (2009-03-25) - Buffer size increased to 1024 to avoid truncation\n625a860c (2009-11-22) - Buffer size increased to 4096 to avoid truncation\nf4c3edc0 (2015-08-11) - Buffer removed to avoid truncation\nb5a9e435 (2017-01-11) - Reverts f4c3edc0 to be able to replace control\n chars before sending to stderr\n9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n This is seemingly related to d048a96e.\n137a0d0e (2007-11-19) - Addresses out-of-order for display()\n34df8aba (2009-03-10) - Switches xwrite() to fprintf() in recv_sideband()\n to support UTF-8 emulation\neac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\n so it's safe to use xwrite() again\n5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n\nNote that we print nothing if the `vsnprintf()` call failed to render\nthe error message; There is little we can do in that case, and it should\nnot happen anyway.\n\nThe process may have written to `stderr` and there may be something left\nin the buffer kept in the stdio layer. Call `fflush(stderr)` before\nwriting the message we prepare in this function.\n\nHelped-by: Jeff King \nHelped-by: Alexandr Miloslavskiy \nHelped-by: SZEDER Gábor \nHelped-by: Junio C Hamano \nSigned-off-by: Johannes Schindelin \n---\n usage.c | 20 ++++++++++++++++----\n 1 file changed, 16 insertions(+), 4 deletions(-)\n\ndiff --git a/usage.c b/usage.c\nindex 2fdb20086b..58fb5fff5f 100644\n--- a/usage.c\n+++ b/usage.c\n@@ -9,14 +9,26 @@\n void vreportf(const char *prefix, const char *err, va_list params)\n {\n \tchar msg[4096];\n-\tchar *p;\n+\tchar *p, *pend = msg + sizeof(msg);\n+\tsize_t prefix_len = strlen(prefix);\n \n-\tvsnprintf(msg, sizeof(msg), err, params);\n-\tfor (p = msg; *p; p++) {\n+\tif (sizeof(msg) <= prefix_len) {\n+\t\tfprintf(stderr, \"BUG!!! too long a prefix '%s'\\n\", prefix);\n+\t\tabort();\n+\t}\n+\tmemcpy(msg, prefix, prefix_len);\n+\tp = msg + prefix_len;\n+\tif (vsnprintf(p, pend - p, err, params) < 0)\n+\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n+\n+\tfor (; p != pend - 1 && *p; p++) {\n \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n \t\t\t*p = '?';\n \t}\n-\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n+\n+\t*(p++) = '\\n'; /* we no longer need a NUL */\n+\tfflush(stderr);\n+\twrite_in_full(2, msg, p - msg);\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n-- \ngitgitgadget\n"},{"id":"385201","messageId":"20191031062454.GB20830@sigill.intra.peff.net","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910300947410.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-31T06:24:54Z","receivedAt":"2019-10-31T06:24:56Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Oct 30, 2019 at 09:54:52AM +0100, Johannes Schindelin wrote:\n\n> > One non-bikeshed question: would fprintf() on some platforms have sent\n> > \"\\r\\n\", which is no longer happening with our write()? Do we need to\n> > care about that?\n> \n> I am not aware of any platform where `fprintf()` would automatically\n> transform `\\n` to `\\r\\n`. Not unless the `FILE *` in question has been\n> opened with the `t` flag. And I am rather certain that `stderr` is not\n> opened with that flag. And if it was, I would force it off in Git for\n> Windows.\n\nOK, thanks. You guessed the platform I was thinking of. :)\n\nAnother more far-fetched one: IIRC our stdio wrappers on Windows do some\nmagic to convert ANSI color codes into actual terminal codes. Could that\nbe a problem here? I think we'd kill off any color codes in the actual\nmessage due to the control-code replacement. In theory the prefix could\nhave them. I don't think any code does now, but the PUSH_COLOR_ERROR\nstuff in builtin/push.c is getting close. I wouldn't be surprised for\nthat to eventually get folded into error().\n\n-Peff\n"},{"id":"385212","messageId":"nycvar.QRO.7.76.6.1910311123010.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"20191031062454.GB20830@sigill.intra.peff.net","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-31T10:26:30Z","receivedAt":"2019-10-31T10:26:54Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Thu, 31 Oct 2019, Jeff King wrote:\n\n> On Wed, Oct 30, 2019 at 09:54:52AM +0100, Johannes Schindelin wrote:\n>\n> > > One non-bikeshed question: would fprintf() on some platforms have sent\n> > > \"\\r\\n\", which is no longer happening with our write()? Do we need to\n> > > care about that?\n> >\n> > I am not aware of any platform where `fprintf()` would automatically\n> > transform `\\n` to `\\r\\n`. Not unless the `FILE *` in question has been\n> > opened with the `t` flag. And I am rather certain that `stderr` is not\n> > opened with that flag. And if it was, I would force it off in Git for\n> > Windows.\n>\n> OK, thanks. You guessed the platform I was thinking of. :)\n>\n> Another more far-fetched one: IIRC our stdio wrappers on Windows do some\n> magic to convert ANSI color codes into actual terminal codes. Could that\n> be a problem here? I think we'd kill off any color codes in the actual\n> message due to the control-code replacement. In theory the prefix could\n> have them. I don't think any code does now, but the PUSH_COLOR_ERROR\n> stuff in builtin/push.c is getting close. I wouldn't be surprised for\n> that to eventually get folded into error().\n\nA valid concern!\n\nAs per eac14f8909d (Win32: Thread-safe windows console output,\n2012-01-14), `write()` _implicitly_ gets the ANSI emulation of\n`winansi.c`.\n\nSo I think we're good.\n\nThanks for thinking of all kinds of angles,\nDscho\n"},{"id":"385223","messageId":"20191031154837.GB30187@sigill.intra.peff.net","threadId":"52140","inReplyTo":"nycvar.QRO.7.76.6.1910311123010.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-31T15:48:37Z","receivedAt":"2019-10-31T15:48:40Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 31, 2019 at 11:26:30AM +0100, Johannes Schindelin wrote:\n\n> > Another more far-fetched one: IIRC our stdio wrappers on Windows do some\n> > magic to convert ANSI color codes into actual terminal codes. Could that\n> > be a problem here? I think we'd kill off any color codes in the actual\n> > message due to the control-code replacement. In theory the prefix could\n> > have them. I don't think any code does now, but the PUSH_COLOR_ERROR\n> > stuff in builtin/push.c is getting close. I wouldn't be surprised for\n> > that to eventually get folded into error().\n> \n> A valid concern!\n> \n> As per eac14f8909d (Win32: Thread-safe windows console output,\n> 2012-01-14), `write()` _implicitly_ gets the ANSI emulation of\n> `winansi.c`.\n> \n> So I think we're good.\n> \n> Thanks for thinking of all kinds of angles,\n\nGood. Thanks for humoring my wild speculation. :)\n\nI remember being confused by this not too long ago, so I did a quick dig\nin the archive. And indeed, there was a confusing comment which caught\nme in 2016, and which you removed back then (via 3d0a83382f26). I even\nreviewed the patch. Maybe this time I will remember the outcome!\n\n-Peff\n"},{"id":"385272","messageId":"nycvar.QRO.7.76.6.1911011940590.46@tvgsbejvaqbjf.bet","threadId":"52140","inReplyTo":"20191031154837.GB30187@sigill.intra.peff.net","subject":"Re: [PATCH v3 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-11-01T18:41:40Z","receivedAt":"2019-11-01T18:42:15Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi,\n\nOn Thu, 31 Oct 2019, Jeff King wrote:\n\n> On Thu, Oct 31, 2019 at 11:26:30AM +0100, Johannes Schindelin wrote:\n>\n> > > Another more far-fetched one: IIRC our stdio wrappers on Windows do some\n> > > magic to convert ANSI color codes into actual terminal codes. Could that\n> > > be a problem here? I think we'd kill off any color codes in the actual\n> > > message due to the control-code replacement. In theory the prefix could\n> > > have them. I don't think any code does now, but the PUSH_COLOR_ERROR\n> > > stuff in builtin/push.c is getting close. I wouldn't be surprised for\n> > > that to eventually get folded into error().\n> >\n> > A valid concern!\n> >\n> > As per eac14f8909d (Win32: Thread-safe windows console output,\n> > 2012-01-14), `write()` _implicitly_ gets the ANSI emulation of\n> > `winansi.c`.\n> >\n> > So I think we're good.\n> >\n> > Thanks for thinking of all kinds of angles,\n>\n> Good. Thanks for humoring my wild speculation. :)\n\nOf course!\n\n> I remember being confused by this not too long ago, so I did a quick dig\n> in the archive. And indeed, there was a confusing comment which caught\n> me in 2016, and which you removed back then (via 3d0a83382f26). I even\n> reviewed the patch. Maybe this time I will remember the outcome!\n\nHeh, I won't fault you because I totally forgot about it myself.\n\nCiao,\nDscho\n"},{"id":"385292","messageId":"xmqqd0ea6hy8.fsf@gitster-ct.c.googlers.com","threadId":"52140","inReplyTo":"f6d6c8122abbd6339cf83309ac3761bbdac44023.1572432276.git.gitgitgadget@gmail.com","subject":"Re: [PATCH v4 1/1] vreportf(): avoid relying on stdio buffering","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-11-02T04:05:51Z","receivedAt":"2019-11-02T04:06:01Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"\"Johannes Schindelin via GitGitGadget\" \nwrites:\n\n> From: Johannes Schindelin \n>\n> The MSVC runtime behavior differs from glibc's with respect to\n> `fprintf(stderr, ...)` in that the former writes out the message\n> character by character.\n> ...\n> Let's avoid this predicament altogether by rendering the entire message,\n> including the prefix and the trailing newline, into the buffer we\n> already have (and which is still fixed size) and then write it out via\n> `write_in_full()`.\n> ...\n> The process may have written to `stderr` and there may be something left\n> in the buffer kept in the stdio layer. Call `fflush(stderr)` before\n> writing the message we prepare in this function.\n\nThanks.\n\nThis is for future reference and not a comment for you alone, but we\nprobably do not want to single out glibc like this proposed log\nmessage does in its first paragraph, as if in the author's mind, the\nworld has only two systems. It invites questions like \"what about\nvarious BSD variants? how does musl behave?\" that may lead to a\nsuggestion to further update it to \"differs from most everybody\nelse\", or we may end up saying \"MSVC, X and Y share this problem\nunlike all others\". Either way, at that point, the original\nsingling out of glibc becomes meaningless.\n\n\"Platform X has this issue and here is a way to avoid that on\neverybody\" is a good description of the motivation, and the mention\nof the behaviour of MSVC runtime is what we want to see there.\n\n The MSVC runtime writes out the message character by\n character given `fprintf(stderr, ...)`.\n\nIt is not necessary to add \"There may be other platforms that share\nthe same issue, but MSVC alone is already important enough so we do\nnot list them here\". It is trivially true and obvious ;-)\n\nAs I said, the above is for future reference for everybody; it's\ncutting close to the final, so let's queue this (and the other one)\nas-is.\n\nThanks for working on this fix.\n\n> Helped-by: Jeff King \n> Helped-by: Alexandr Miloslavskiy \n> Helped-by: SZEDER Gábor \n> Helped-by: Junio C Hamano \n> Signed-off-by: Johannes Schindelin \n> ---\n> usage.c | 20 ++++++++++++++++----\n> 1 file changed, 16 insertions(+), 4 deletions(-)\n>\n> diff --git a/usage.c b/usage.c\n> index 2fdb20086b..58fb5fff5f 100644\n> --- a/usage.c\n> +++ b/usage.c\n> @@ -9,14 +9,26 @@\n> void vreportf(const char *prefix, const char *err, va_list params)\n> {\n> \tchar msg[4096];\n> -\tchar *p;\n> +\tchar *p, *pend = msg + sizeof(msg);\n> +\tsize_t prefix_len = strlen(prefix);\n> \n> -\tvsnprintf(msg, sizeof(msg), err, params);\n> -\tfor (p = msg; *p; p++) {\n> +\tif (sizeof(msg) <= prefix_len) {\n> +\t\tfprintf(stderr, \"BUG!!! too long a prefix '%s'\\n\", prefix);\n> +\t\tabort();\n> +\t}\n> +\tmemcpy(msg, prefix, prefix_len);\n> +\tp = msg + prefix_len;\n> +\tif (vsnprintf(p, pend - p, err, params) < 0)\n> +\t\t*p = '\\0'; /* vsnprintf() failed, clip at prefix */\n> +\n> +\tfor (; p != pend - 1 && *p; p++) {\n> \t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n> \t\t\t*p = '?';\n> \t}\n> -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n> +\n> +\t*(p++) = '\\n'; /* we no longer need a NUL */\n> +\tfflush(stderr);\n> +\twrite_in_full(2, msg, p - msg);\n> }\n> \n> static NORETURN void usage_builtin(const char *err, va_list params)\n"}]}