{"thread":{"id":"52091","subject":"[PATCH 0/1] vreportf: Fix interleaving issues, remove 4096 limitation","startedAt":"2019-10-22T14:39:11Z","lastAt":"2019-10-28T16:06:09Z","messageCount":16,"participants":["Alexandr Miloslavskiy via GitGitGadget","Johannes Schindelin","Alexandr Miloslavskiy","Jeff King"],"isPatch":true,"patchVersion":1,"patchTotal":1},"messages":[{"id":"384605","messageId":"pull.407.git.1571755147.gitgitgadget@gmail.com","threadId":"52091","inReplyTo":null,"subject":"[PATCH 0/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Alexandr Miloslavskiy via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-22T14:39:06Z","receivedAt":"2019-10-22T14:39:11Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"This fixes t5516 on Windows. For detailed explanation please refer to code\ncomments in this commit.\n\nThere was a lot of back-and-forth already in vreportf(): d048a96e\n(2007-11-09) - 'char msg[256]' is introduced to avoid interleaving 389d1767\n(2009-03-25) - Buffer size increased to 1024 to avoid truncation 625a860c\n(2009-11-22) - Buffer size increased to 4096 to avoid truncation f4c3edc0\n(2015-08-11) - Buffer removed to avoid truncation b5a9e435 (2017-01-11) -\nReverts f4c3edc0 to be able to replace control chars before sending to\nstderr\n\nThis fix attempts to solve all issues:\n\n1) avoid multiple fprintf() interleaving 2) avoid truncation 3) avoid char\ninterleaving in fprintf() on some platforms 4) avoid buffer block\ninterleaving when output is large 5) avoid Out-of-order messages 6) replace\ncontrol characters in output\n\nOther commits worthy of notice: 9ac13ec9 (2006-10-11) - Another attempt to\nsolve interleaving. This is seemingly related to d048a96e. 137a0d0e\n(2007-11-19) - Addresses out-of-order for display() 34df8aba (2009-03-10) -\nSwitches xwrite() to fprintf() in recv_sideband() to support UTF-8 emulation\neac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\nso it's safe to use xwrite() again 5e5be9e2 (2016-06-28) - recv_sideband()\nuses xwrite() again\n\nSigned-off-by: Alexandr Miloslavskiy alexandr.miloslavskiy@syntevo.com\n[alexandr.miloslavskiy@syntevo.com]\n\nAlexandr Miloslavskiy (1):\n  vreportf: Fix interleaving issues, remove 4096 limitation\n\n usage.c | 154 +++++++++++++++++++++++++++++++++++++++++++++++++++++---\n 1 file changed, 148 insertions(+), 6 deletions(-)\n\n\nbase-commit: d966095db01190a2196e31195ea6fa0c722aa732\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-407%2FSyntevoAlex%2F%230194_t5516_fixes-v1\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-407/SyntevoAlex/#0194_t5516_fixes-v1\nPull-Request: https://github.com/gitgitgadget/git/pull/407\n-- \ngitgitgadget\n"},{"id":"384606","messageId":"5fd06fa881da6d0058b9c78525502a6126f68d71.1571755147.git.gitgitgadget@gmail.com","threadId":"52091","inReplyTo":"pull.407.git.1571755147.gitgitgadget@gmail.com","subject":"[PATCH 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Alexandr Miloslavskiy via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-22T14:39:07Z","receivedAt":"2019-10-22T14:39:13Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"From: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>\n\nThis also fixes t5516 on Windows VS build.\nFor detailed explanation please refer to code comments in this commit.\n\nThere was a lot of back-and-forth already in vreportf():\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\n\nThis fix attempts to solve all issues:\n1) avoid multiple fprintf() interleaving\n2) avoid truncation\n3) avoid char interleaving in fprintf() on some platforms\n4) avoid buffer block interleaving when output is large\n5) avoid out-of-order messages\n6) replace control characters in output\n\nOther commits worthy of notice:\n9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n\t\t\t\t\t\tThis 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\t\t\t\t\t\tto support UTF-8 emulation\neac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\n\t\t\t\t\t\tso it's safe to use xwrite() again\n5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n\nSigned-off-by: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>\n---\n usage.c | 154 +++++++++++++++++++++++++++++++++++++++++++++++++++++---\n 1 file changed, 148 insertions(+), 6 deletions(-)\n\ndiff --git a/usage.c b/usage.c\nindex 2fdb20086b..ccdd91a7b9 100644\n--- a/usage.c\n+++ b/usage.c\n@@ -6,17 +6,159 @@\n #include \"git-compat-util.h\"\n #include \"cache.h\"\n \n+static void replace_control_chars(char* str, size_t size, char replacement)\n+{\n+\tsize_t i;\n+\n+\tfor (i = 0; i < size; i++) {\n+    \t\tif (iscntrl(str[i]) && str[i] != '\\t' && str[i] != '\\n')\n+\t\t\tstr[i] = replacement;\n+\t}\n+}\n+\n+/*\n+ * Atomically report (prefix + vsnprintf(err, params) + '\\n') to stderr.\n+ * Always returns desired buffer size.\n+ * Doesn't write to stderr if content didn't fit.\n+ *\n+ * This function composes everything into a single buffer before\n+ * sending to stderr. This is to defeat various non-atomic issues:\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\n+ *    blocks when two threads/processes write at the same time.\n+ * 3) If stderr is not buffered:\n+ *    There are two problems, one with atomic fprintf() and another\n+ *    for non-atomic fprintf(), and both occur depending on platform\n+ *    (see details below). If atomic, this function still writes 3\n+ *    parts, which could get interleaved with multiple threads. If\n+ *    not atomic, then fprintf() will basically write char-by-char,\n+ *    which leads to unreadable char-interleaved writes if two\n+ *    processes write to stderr at the same time (threads are OK\n+ *    because fprintf() usually locks file in current process). This\n+ *    for example happens in t5516 where 'git-upload-pack' detects\n+ *    an error, reports it to parent 'git fetch' and both die() at the\n+ *    same time.\n+ *\n+ *    Behaviors, at the moment of writing:\n+ *    a) libc - fprintf()-interleaved\n+ *       fprintf() enables temporary stream buffering.\n+ *       See: buffered_vfprintf()\n+ *    b) VC++ - char-interleaved\n+ *       fprintf() enables temporary stream buffering, but only if\n+ *       stream was not set to no buffering. This has no effect,\n+ *       because stderr is not buffered by default, and git takes\n+ *       an extra step to ensure that in swap_osfhnd().\n+ *       See: _iob[_IOB_ENTRIES],\n+ *            __acrt_stdio_temporary_buffering_guard,\n+ *            has_any_buffer()\n+ *    c) 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 for\n+ *       file-redirected stderr.\n+ *       See: __mingw_vfprintf(),\n+ *            __pformat_wcputs(),\n+ *            _fputc_nolock(),\n+ *            _flsbuf(),\n+ *            _iob[_IOB_ENTRIES]\n+ * 4) If stderr is line buffered: MinGW/VC++ will enable full\n+ *    buffering instead. See MSDN setvbuf().\n+ */\n+static size_t vreportf_buf(char *buf, size_t buf_size, const char *prefix, const char *err, va_list params)\n+{\n+\tint printf_ret = 0;\n+\tsize_t prefix_size = 0;\n+\tsize_t total_size = 0;\n+\n+\t/*\n+\t * NOTE: Can't use strbuf functions here, because it can be called when\n+\t * malloc() is no longer possible, and strbuf will recurse die().\n+\t */\n+\n+\t/* Prefix */\n+\tprefix_size = strlen(prefix);\n+\tif (total_size + prefix_size <= buf_size)\n+\t\tmemcpy(buf + total_size, prefix, prefix_size);\n+\t\n+\ttotal_size += prefix_size;\n+\n+\t/* Formatted message */\n+\tif (total_size <= buf_size)\n+\t\tprintf_ret = vsnprintf(buf + total_size, buf_size - total_size, err, params);\n+\telse\n+\t\tprintf_ret = vsnprintf(NULL, 0, err, params);\n+\n+\tif (printf_ret < 0)\n+\t\tBUG(\"your vsnprintf is broken (returned %d)\", printf_ret);\n+\n+\t/*\n+\t * vsnprintf() returns _desired_ size (without terminating null).\n+\t * If vsnprintf() was truncated that will be seen when appending '\\n'.\n+\t */\n+\ttotal_size += printf_ret;\n+\n+\t/* Trailing \\n */\n+\tif (total_size + 1 <= buf_size)\n+\t\tbuf[total_size] = '\\n';\n+\n+\ttotal_size += 1;\n+\n+\t/* Send the buffer, if content fits */\n+\tif (total_size <= buf_size) {\n+\t    replace_control_chars(buf, total_size, '?');\n+\t    fwrite(buf, total_size, 1, stderr);\n+\t}\n+\n+\treturn total_size;\n+}\n+\n void vreportf(const char *prefix, const char *err, va_list params)\n {\n+\tsize_t res = 0;\n+\tchar *buf = NULL;\n+\tsize_t buf_size = 0;\n+\n+\t/*\n+\t * NOTE: This can be called from failed xmalloc(). Any malloc() can\n+\t * fail now. Let's try to report with a fixed size stack based buffer.\n+\t * Also, most messages should fit, and this path is faster.\n+\t */\n \tchar msg[4096];\n-\tchar *p;\n+\tres = vreportf_buf(msg, sizeof(msg), prefix, err, params);\n+\tif (res <= sizeof(msg)) {\n+\t\t/* Success */\n+\t\treturn;\n+\t}\n \n-\tvsnprintf(msg, sizeof(msg), 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+\t * Try to allocate a suitable sized malloc(), if possible.\n+\t * NOTE: Do not use xmalloc(), because on failure it will call\n+\t * die() or warning() and lead to recursion.\n+\t */\n+\tbuf_size = res;\n+\tbuf = malloc(buf_size);\n+\tif (buf) {\n+\t\tres = vreportf_buf(buf, buf_size, prefix, err, params);\n+\t\tFREE_AND_NULL(buf);\n+\n+\t\tif (res <= buf_size) {\n+\t\t\t/* Success */\n+\t\t\treturn;\n+\t\t}\n \t}\n-\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n+\n+\t/* \n+\t * When everything fails, report in parts.\n+\t * This can have all problems prevented by vreportf_buf().\n+\t */\n+\tfprintf(stderr, \"vreportf: not enough memory (tried to allocate %lu bytes)\\n\", (unsigned long)buf_size);\n+\tfputs(prefix, stderr);\n+\tvfprintf(stderr, err, params);\n+\tfputc('\\n', stderr);\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n-- \ngitgitgadget\n"},{"id":"384607","messageId":"pull.407.v2.git.1571755538.gitgitgadget@gmail.com","threadId":"52091","inReplyTo":"pull.407.git.1571755147.gitgitgadget@gmail.com","subject":"[PATCH v2 0/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Alexandr Miloslavskiy via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-22T14:45:36Z","receivedAt":"2019-10-22T14:45:42Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"This fixes t5516 on Windows. For detailed explanation please refer to code\ncomments in this commit.\n\nThere was a lot of back-and-forth already in vreportf(): d048a96e\n(2007-11-09) - 'char msg[256]' is introduced to avoid interleaving 389d1767\n(2009-03-25) - Buffer size increased to 1024 to avoid truncation 625a860c\n(2009-11-22) - Buffer size increased to 4096 to avoid truncation f4c3edc0\n(2015-08-11) - Buffer removed to avoid truncation b5a9e435 (2017-01-11) -\nReverts f4c3edc0 to be able to replace control chars before sending to\nstderr\n\nThis fix attempts to solve all issues:\n\n1) avoid multiple fprintf() interleaving 2) avoid truncation 3) avoid char\ninterleaving in fprintf() on some platforms 4) avoid buffer block\ninterleaving when output is large 5) avoid Out-of-order messages 6) replace\ncontrol characters in output\n\nOther commits worthy of notice: 9ac13ec9 (2006-10-11) - Another attempt to\nsolve interleaving. This is seemingly related to d048a96e. 137a0d0e\n(2007-11-19) - Addresses out-of-order for display() 34df8aba (2009-03-10) -\nSwitches xwrite() to fprintf() in recv_sideband() to support UTF-8 emulation\neac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,\nso it's safe to use xwrite() again 5e5be9e2 (2016-06-28) - recv_sideband()\nuses xwrite() again\n\nSigned-off-by: Alexandr Miloslavskiy alexandr.miloslavskiy@syntevo.com\n[alexandr.miloslavskiy@syntevo.com]\n\nAlexandr Miloslavskiy (1):\n  vreportf: Fix interleaving issues, remove 4096 limitation\n\n usage.c | 154 +++++++++++++++++++++++++++++++++++++++++++++++++++++---\n 1 file changed, 148 insertions(+), 6 deletions(-)\n\n\nbase-commit: d966095db01190a2196e31195ea6fa0c722aa732\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-407%2FSyntevoAlex%2F%230194_t5516_fixes-v2\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-407/SyntevoAlex/#0194_t5516_fixes-v2\nPull-Request: https://github.com/gitgitgadget/git/pull/407\n\nRange-diff vs v1:\n\n 1:  5fd06fa881 ! 1:  54f0d6f6b5 vreportf: Fix interleaving issues, remove 4096 limitation\n     @@ -23,12 +23,12 @@\n      \n          Other commits worthy of notice:\n          9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.\n     -                                                    This is seemingly related to d048a96e.\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     +                            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     +                            so it's safe to use xwrite() again\n          5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again\n      \n          Signed-off-by: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>\n\n-- \ngitgitgadget\n"},{"id":"384608","messageId":"54f0d6f6b53dd4fdd6e4129c942de8002459fd88.1571755538.git.gitgitgadget@gmail.com","threadId":"52091","inReplyTo":"pull.407.v2.git.1571755538.gitgitgadget@gmail.com","subject":"[PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Alexandr Miloslavskiy via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-10-22T14:45:37Z","receivedAt":"2019-10-22T14:45:44Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"From: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>\n\nThis also fixes t5516 on Windows VS build.\nFor detailed explanation please refer to code comments in this commit.\n\nThere was a lot of back-and-forth already in vreportf():\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\n\nThis fix attempts to solve all issues:\n1) avoid multiple fprintf() interleaving\n2) avoid truncation\n3) avoid char interleaving in fprintf() on some platforms\n4) avoid buffer block interleaving when output is large\n5) avoid out-of-order messages\n6) replace control characters in output\n\nOther commits worthy of notice:\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\nSigned-off-by: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>\n---\n usage.c | 154 +++++++++++++++++++++++++++++++++++++++++++++++++++++---\n 1 file changed, 148 insertions(+), 6 deletions(-)\n\ndiff --git a/usage.c b/usage.c\nindex 2fdb20086b..ccdd91a7b9 100644\n--- a/usage.c\n+++ b/usage.c\n@@ -6,17 +6,159 @@\n #include \"git-compat-util.h\"\n #include \"cache.h\"\n \n+static void replace_control_chars(char* str, size_t size, char replacement)\n+{\n+\tsize_t i;\n+\n+\tfor (i = 0; i < size; i++) {\n+    \t\tif (iscntrl(str[i]) && str[i] != '\\t' && str[i] != '\\n')\n+\t\t\tstr[i] = replacement;\n+\t}\n+}\n+\n+/*\n+ * Atomically report (prefix + vsnprintf(err, params) + '\\n') to stderr.\n+ * Always returns desired buffer size.\n+ * Doesn't write to stderr if content didn't fit.\n+ *\n+ * This function composes everything into a single buffer before\n+ * sending to stderr. This is to defeat various non-atomic issues:\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\n+ *    blocks when two threads/processes write at the same time.\n+ * 3) If stderr is not buffered:\n+ *    There are two problems, one with atomic fprintf() and another\n+ *    for non-atomic fprintf(), and both occur depending on platform\n+ *    (see details below). If atomic, this function still writes 3\n+ *    parts, which could get interleaved with multiple threads. If\n+ *    not atomic, then fprintf() will basically write char-by-char,\n+ *    which leads to unreadable char-interleaved writes if two\n+ *    processes write to stderr at the same time (threads are OK\n+ *    because fprintf() usually locks file in current process). This\n+ *    for example happens in t5516 where 'git-upload-pack' detects\n+ *    an error, reports it to parent 'git fetch' and both die() at the\n+ *    same time.\n+ *\n+ *    Behaviors, at the moment of writing:\n+ *    a) libc - fprintf()-interleaved\n+ *       fprintf() enables temporary stream buffering.\n+ *       See: buffered_vfprintf()\n+ *    b) VC++ - char-interleaved\n+ *       fprintf() enables temporary stream buffering, but only if\n+ *       stream was not set to no buffering. This has no effect,\n+ *       because stderr is not buffered by default, and git takes\n+ *       an extra step to ensure that in swap_osfhnd().\n+ *       See: _iob[_IOB_ENTRIES],\n+ *            __acrt_stdio_temporary_buffering_guard,\n+ *            has_any_buffer()\n+ *    c) 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 for\n+ *       file-redirected stderr.\n+ *       See: __mingw_vfprintf(),\n+ *            __pformat_wcputs(),\n+ *            _fputc_nolock(),\n+ *            _flsbuf(),\n+ *            _iob[_IOB_ENTRIES]\n+ * 4) If stderr is line buffered: MinGW/VC++ will enable full\n+ *    buffering instead. See MSDN setvbuf().\n+ */\n+static size_t vreportf_buf(char *buf, size_t buf_size, const char *prefix, const char *err, va_list params)\n+{\n+\tint printf_ret = 0;\n+\tsize_t prefix_size = 0;\n+\tsize_t total_size = 0;\n+\n+\t/*\n+\t * NOTE: Can't use strbuf functions here, because it can be called when\n+\t * malloc() is no longer possible, and strbuf will recurse die().\n+\t */\n+\n+\t/* Prefix */\n+\tprefix_size = strlen(prefix);\n+\tif (total_size + prefix_size <= buf_size)\n+\t\tmemcpy(buf + total_size, prefix, prefix_size);\n+\t\n+\ttotal_size += prefix_size;\n+\n+\t/* Formatted message */\n+\tif (total_size <= buf_size)\n+\t\tprintf_ret = vsnprintf(buf + total_size, buf_size - total_size, err, params);\n+\telse\n+\t\tprintf_ret = vsnprintf(NULL, 0, err, params);\n+\n+\tif (printf_ret < 0)\n+\t\tBUG(\"your vsnprintf is broken (returned %d)\", printf_ret);\n+\n+\t/*\n+\t * vsnprintf() returns _desired_ size (without terminating null).\n+\t * If vsnprintf() was truncated that will be seen when appending '\\n'.\n+\t */\n+\ttotal_size += printf_ret;\n+\n+\t/* Trailing \\n */\n+\tif (total_size + 1 <= buf_size)\n+\t\tbuf[total_size] = '\\n';\n+\n+\ttotal_size += 1;\n+\n+\t/* Send the buffer, if content fits */\n+\tif (total_size <= buf_size) {\n+\t    replace_control_chars(buf, total_size, '?');\n+\t    fwrite(buf, total_size, 1, stderr);\n+\t}\n+\n+\treturn total_size;\n+}\n+\n void vreportf(const char *prefix, const char *err, va_list params)\n {\n+\tsize_t res = 0;\n+\tchar *buf = NULL;\n+\tsize_t buf_size = 0;\n+\n+\t/*\n+\t * NOTE: This can be called from failed xmalloc(). Any malloc() can\n+\t * fail now. Let's try to report with a fixed size stack based buffer.\n+\t * Also, most messages should fit, and this path is faster.\n+\t */\n \tchar msg[4096];\n-\tchar *p;\n+\tres = vreportf_buf(msg, sizeof(msg), prefix, err, params);\n+\tif (res <= sizeof(msg)) {\n+\t\t/* Success */\n+\t\treturn;\n+\t}\n \n-\tvsnprintf(msg, sizeof(msg), 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+\t * Try to allocate a suitable sized malloc(), if possible.\n+\t * NOTE: Do not use xmalloc(), because on failure it will call\n+\t * die() or warning() and lead to recursion.\n+\t */\n+\tbuf_size = res;\n+\tbuf = malloc(buf_size);\n+\tif (buf) {\n+\t\tres = vreportf_buf(buf, buf_size, prefix, err, params);\n+\t\tFREE_AND_NULL(buf);\n+\n+\t\tif (res <= buf_size) {\n+\t\t\t/* Success */\n+\t\t\treturn;\n+\t\t}\n \t}\n-\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n+\n+\t/* \n+\t * When everything fails, report in parts.\n+\t * This can have all problems prevented by vreportf_buf().\n+\t */\n+\tfprintf(stderr, \"vreportf: not enough memory (tried to allocate %lu bytes)\\n\", (unsigned long)buf_size);\n+\tfputs(prefix, stderr);\n+\tvfprintf(stderr, err, params);\n+\tfputc('\\n', stderr);\n }\n \n static NORETURN void usage_builtin(const char *err, va_list params)\n-- \ngitgitgadget\n"},{"id":"384854","messageId":"nycvar.QRO.7.76.6.1910251034110.46@tvgsbejvaqbjf.bet","threadId":"52091","inReplyTo":"54f0d6f6b53dd4fdd6e4129c942de8002459fd88.1571755538.git.gitgitgadget@gmail.com","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-25T11:37:33Z","receivedAt":"2019-10-25T11:38:01Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Alex,\n\n\nOn Tue, 22 Oct 2019, Alexandr Miloslavskiy via GitGitGadget wrote:\n\n> From: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>\n>\n> This also fixes t5516 on Windows VS build.\n\nMaybe this could do with an example? I could imagine that we might want\nto use the log of\nhttps://dev.azure.com/git/git/_build/results?buildId=1264&view=ms.vss-test-web.build-test-results-tab&runId=1016906&resultId=101011&paneView=attachments:\n\n-- snip --\n[...]\n++ eval '\n\twant_trace && set -x\n\nmkdir -p \"$TRASH_DIRECTORY/prereq-test-dir\" &&\n(\n\tcd \"$TRASH_DIRECTORY/prereq-test-dir\" &&\n\t! git env--helper --type=bool --default=0 --exit-code GIT_TEST_GETTEXT_POISON\n\n)'\n+++ want_trace\n+++ test t = t\n+++ test '' = t\n+++ test t = t\n+++ set -x\n+++ mkdir -p '/d/a/1/s/t/trash directory.t5516-fetch-push/prereq-test-dir'\n+++ cd '/d/a/1/s/t/trash directory.t5516-fetch-push/prereq-test-dir'\n+++ git env--helper --type=bool --default=0 --exit-code GIT_TEST_GETTEXT_POISON\nprerequisite C_LOCALE_OUTPUT ok\nerror: 'grep remote error:.*not our ref.*64ea4c133d59fa98e86a771eda009872d6ab2886$ err' didn't find a match in:\nfatal: git upload-pack: not our ref 64ea4c133d59fa98e86afatal: 771eda009872d6abremote error: upload-pack2: not our re886\nf 64ea4c133d59fa98e86a771eda009872d6ab2886\nerror: last command exited with $?=1\n-- snap --\n\nIt is quite obvious that this `fatal:` line is garbled ;-)\n\n> For detailed explanation please refer to code comments in this commit.\n>\n> There was a lot of back-and-forth already in vreportf():\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>\n> This fix attempts to solve all issues:\n> 1) avoid multiple fprintf() interleaving\n> 2) avoid truncation\n> 3) avoid char interleaving in fprintf() on some platforms\n> 4) avoid buffer block interleaving when output is large\n> 5) avoid out-of-order messages\n> 6) replace control characters in output\n>\n> Other commits worthy of notice:\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\nSo far, it makes a lot of sense, and is well-researched. Thank you for\nbeing very diligent.\n\n>\n> Signed-off-by: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>\n> ---\n>  usage.c | 154 +++++++++++++++++++++++++++++++++++++++++++++++++++++---\n>  1 file changed, 148 insertions(+), 6 deletions(-)\n>\n> diff --git a/usage.c b/usage.c\n> index 2fdb20086b..ccdd91a7b9 100644\n> --- a/usage.c\n> +++ b/usage.c\n> @@ -6,17 +6,159 @@\n>  #include \"git-compat-util.h\"\n>  #include \"cache.h\"\n>\n> +static void replace_control_chars(char* str, size_t size, char replacement)\n> +{\n> +\tsize_t i;\n> +\n> +\tfor (i = 0; i < size; i++) {\n> +    \t\tif (iscntrl(str[i]) && str[i] != '\\t' && str[i] != '\\n')\n> +\t\t\tstr[i] = replacement;\n> +\t}\n> +}\n\nSo this is just factored out from `vreportf()`, right?\n\n> +\n> +/*\n> + * Atomically report (prefix + vsnprintf(err, params) + '\\n') to stderr.\n> + * Always returns desired buffer size.\n> + * Doesn't write to stderr if content didn't fit.\n> + *\n> + * This function composes everything into a single buffer before\n> + * sending to stderr. This is to defeat various non-atomic issues:\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\n> + *    blocks when two threads/processes write at the same time.\n> + * 3) If stderr is not buffered:\n> + *    There are two problems, one with atomic fprintf() and another\n> + *    for non-atomic fprintf(), and both occur depending on platform\n> + *    (see details below). If atomic, this function still writes 3\n> + *    parts, which could get interleaved with multiple threads. If\n> + *    not atomic, then fprintf() will basically write char-by-char,\n> + *    which leads to unreadable char-interleaved writes if two\n> + *    processes write to stderr at the same time (threads are OK\n> + *    because fprintf() usually locks file in current process). This\n> + *    for example happens in t5516 where 'git-upload-pack' detects\n> + *    an error, reports it to parent 'git fetch' and both die() at the\n> + *    same time.\n> + *\n> + *    Behaviors, at the moment of writing:\n> + *    a) libc - fprintf()-interleaved\n> + *       fprintf() enables temporary stream buffering.\n> + *       See: buffered_vfprintf()\n> + *    b) VC++ - char-interleaved\n> + *       fprintf() enables temporary stream buffering, but only if\n> + *       stream was not set to no buffering. This has no effect,\n> + *       because stderr is not buffered by default, and git takes\n> + *       an extra step to ensure that in swap_osfhnd().\n> + *       See: _iob[_IOB_ENTRIES],\n> + *            __acrt_stdio_temporary_buffering_guard,\n> + *            has_any_buffer()\n> + *    c) 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 for\n> + *       file-redirected stderr.\n> + *       See: __mingw_vfprintf(),\n> + *            __pformat_wcputs(),\n> + *            _fputc_nolock(),\n> + *            _flsbuf(),\n> + *            _iob[_IOB_ENTRIES]\n> + * 4) If stderr is line buffered: MinGW/VC++ will enable full\n> + *    buffering instead. See MSDN setvbuf().\n> + */\n> +static size_t vreportf_buf(char *buf, size_t buf_size, const char *prefix, const char *err, va_list params)\n> +{\n> +\tint printf_ret = 0;\n> +\tsize_t prefix_size = 0;\n> +\tsize_t total_size = 0;\n> +\n> +\t/*\n> +\t * NOTE: Can't use strbuf functions here, because it can be called when\n> +\t * malloc() is no longer possible, and strbuf will recurse die().\n> +\t */\n> +\n> +\t/* Prefix */\n> +\tprefix_size = strlen(prefix);\n> +\tif (total_size + prefix_size <= buf_size)\n> +\t\tmemcpy(buf + total_size, prefix, prefix_size);\n> +\n> +\ttotal_size += prefix_size;\n> +\n> +\t/* Formatted message */\n> +\tif (total_size <= buf_size)\n> +\t\tprintf_ret = vsnprintf(buf + total_size, buf_size - total_size, err, params);\n> +\telse\n> +\t\tprintf_ret = vsnprintf(NULL, 0, err, params);\n> +\n> +\tif (printf_ret < 0)\n> +\t\tBUG(\"your vsnprintf is broken (returned %d)\", printf_ret);\n> +\n> +\t/*\n> +\t * vsnprintf() returns _desired_ size (without terminating null).\n> +\t * If vsnprintf() was truncated that will be seen when appending '\\n'.\n> +\t */\n> +\ttotal_size += printf_ret;\n> +\n> +\t/* Trailing \\n */\n> +\tif (total_size + 1 <= buf_size)\n> +\t\tbuf[total_size] = '\\n';\n> +\n> +\ttotal_size += 1;\n> +\n> +\t/* Send the buffer, if content fits */\n> +\tif (total_size <= buf_size) {\n> +\t    replace_control_chars(buf, total_size, '?');\n> +\t    fwrite(buf, total_size, 1, stderr);\n> +\t}\n> +\n> +\treturn total_size;\n> +}\n> +\n>  void vreportf(const char *prefix, const char *err, va_list params)\n>  {\n> +\tsize_t res = 0;\n> +\tchar *buf = NULL;\n> +\tsize_t buf_size = 0;\n> +\n> +\t/*\n> +\t * NOTE: This can be called from failed xmalloc(). Any malloc() can\n> +\t * fail now. Let's try to report with a fixed size stack based buffer.\n> +\t * Also, most messages should fit, and this path is faster.\n> +\t */\n>  \tchar msg[4096];\n> -\tchar *p;\n> +\tres = vreportf_buf(msg, sizeof(msg), prefix, err, params);\n> +\tif (res <= sizeof(msg)) {\n> +\t\t/* Success */\n> +\t\treturn;\n> +\t}\n>\n> -\tvsnprintf(msg, sizeof(msg), 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> +\t * Try to allocate a suitable sized malloc(), if possible.\n> +\t * NOTE: Do not use xmalloc(), because on failure it will call\n> +\t * die() or warning() and lead to recursion.\n> +\t */\n> +\tbuf_size = res;\n> +\tbuf = malloc(buf_size);\n\nWhy not `alloca()`?\n\nAnd to take a step back, I think that previous rounds of patches trying\nto essentially address the same problem made the case that it is okay to\ncut off insanely-long messages, so I am not sure we would want to open\nthat can of worms again...\n\n> +\tif (buf) {\n> +\t\tres = vreportf_buf(buf, buf_size, prefix, err, params);\n> +\t\tFREE_AND_NULL(buf);\n> +\n> +\t\tif (res <= buf_size) {\n> +\t\t\t/* Success */\n> +\t\t\treturn;\n> +\t\t}\n>  \t}\n> -\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n> +\n> +\t/*\n> +\t * When everything fails, report in parts.\n> +\t * This can have all problems prevented by vreportf_buf().\n> +\t */\n> +\tfprintf(stderr, \"vreportf: not enough memory (tried to allocate %lu bytes)\\n\", (unsigned long)buf_size);\n> +\tfputs(prefix, stderr);\n> +\tvfprintf(stderr, err, params);\n> +\tfputc('\\n', stderr);\n\nQuite honestly, I would love to avoid that amount of complexity,\ncertainly in a part of the code that we would like to have rock solid\nbecause it is usually exercised when things go very, very wrong and we\nneed to provide the user who is bitten by it enough information to take\nto the Git contributors to figure out the root cause(s).\n\nSo let's take another step back and look at the original `vreportf()`:\n\n\tvoid vreportf(const char *prefix, const char *err, va_list params)\n\t{\n\t\tchar msg[4096];\n\t\tchar *p;\n\n\t\tvsnprintf(msg, sizeof(msg), err, params);\n\t\tfor (p = msg; *p; p++) {\n\t\t\tif (iscntrl(*p) && *p != '\\t' && *p != '\\n')\n\t\t\t\t*p = '?';\n\t\t}\n\t\tfprintf(stderr, \"%s%s\\n\", prefix, msg);\n\t}\n\nIs the problem that causes those failures with VS the fact that\n`fprintf(stderr, ...)` might be interleaved with the output of another\nprocess that _also_ wants to write to `stderr`? I assume that this _is_\nthe problem.\n\nFurther, I guess that the problem is compounded by the fact that we\nusually run the tests in a Git Bash on Windows, i.e. in a MinTTY that\nemulates a console (there _is_ work under way to support the newly\nintroduces ptys, but that work is far from done), so the standard error\nfile handle might behave in unexpected ways in that scenario.\n\nBut I do wonder whether replacing that `fprintf()` by a `write()` would\nwork better. After all, we could write the `prefix` into the `msg`\nalready:\n\n\t\tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n\t\tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n\t\t[...]\n\t\tif (ret > 0)\n\t\t\twrite(2, msg, off + ret);\n\nWould that also work around the problem?\n\nCiao,\nDscho\n\n>  }\n>\n>  static NORETURN void usage_builtin(const char *err, va_list params)\n> --\n> gitgitgadget\n>\n"},{"id":"384858","messageId":"e7002f76-65d3-607f-3b5a-e242938374f7@syntevo.com","threadId":"52091","inReplyTo":"nycvar.QRO.7.76.6.1910251034110.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Alexandr Miloslavskiy","fromEmail":"alexandr.miloslavskiy@syntevo.com","sentAt":"2019-10-25T12:38:43Z","receivedAt":"2019-10-25T12:47:38Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"> Maybe this could do with an example?\n\nI myself observed results like this when running t5516:\n------\nfatal: git fatal: remote errouploar: upload-pack: not our ref \n64ea4c133d59fa98e86a771eda009872d6ab2886d-pack: not o\nur ref 64ea4c133d59fa98e86a771eda009872d6ab2886\n------\n\nDo you want me to add this garbled string to commit message?\n\n>> +static void replace_control_chars(char* str, size_t size, char replacement)\n\n> So this is just factored out from `vreportf()`, right?\n\nYes.\n\n>> +\tbuf = malloc(buf_size);\n\n> Why not `alloca()`?\n\nAllocating large chunks on stack is usually not recommended. There is a \nfunny test \"init allows insanely long --template\" in t0001 which \ndemonstrates that sometimes vreportf() can attempt to print very long \nstrings. Crashing due to stack overflow doesn't sound like a good thing.\n\n> And to take a step back, I think that previous rounds of patches trying\n> to essentially address the same problem made the case that it is okay to\n> cut off insanely-long messages, so I am not sure we would want to open\n> that can of worms again...\n\nI draw a different conclusion here. Each author thought that \"1024 must \ndefinitely be enough!\" but then discovered that it's not enough again, \nfor example due to long \"usage\" output. At some point, f4c3edc0 even \ntried to remove all limits after a chain of limits that were too small. \nSo I would say that this is still a problem.\n\n> Quite honestly, I would love to avoid that amount of complexity,\n> certainly in a part of the code that we would like to have rock solid\n> because it is usually exercised when things go very, very wrong and we\n> need to provide the user who is bitten by it enough information to take\n> to the Git contributors to figure out the root cause(s).\n\nIt's a choice between simpler code and trying to account for everything \nthat could happen. I think we'd rather have more complex code that \nhandles more cases, exactly to try and deliver output to user no matter \nwhat.\n\n> Is the problem that causes those failures with VS the fact that\n> `fprintf(stderr, ...)` might be interleaved with the output of another\n> process that _also_ wants to write to `stderr`? I assume that this _is_\n> the problem.\n\nThis is where I started. But if you look at comment in vreportf_buf, \nthere are more problems, such as interleaving blocks of larger messages, \nwhich could happen on any platform. I tried to make it work in most \ncases possible.\n\n> Further, I guess that the problem is compounded by the fact that we\n> usually run the tests in a Git Bash on Windows, i.e. in a MinTTY that\n> emulates a console (there _is_ work under way to support the newly\n> introduces ptys, but that work is far from done), so the standard error\n> file handle might behave in unexpected ways in that scenario.\n\nTo my knowledge, this is not related. t5516 failures are because git \nexplicitly wants stderr to be unbuffered. VC++ and MinGW runtimes take \nthat literally. fprintf() outputs char-by-char, and all of that results \nin char-interleaving.\n\n> But I do wonder whether replacing that `fprintf()` by a `write()` would\n> work better. After all, we could write the `prefix` into the `msg`\n> already:\n> \n> \tsize_t off = strlcpy(msg, prefix, sizeof(msg));\n> \tint ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n> \t[...]\n> \tif (ret > 0)\n> \t\twrite(2, msg, off + ret);\n> \n> Would that also work around the problem?\n\nYou forgot to add '\\'n. But yes, that would solve many problems, except \ntruncation to 4096. Then I would expect a patch to increase buffer size \nto 8192 in the next couple years. And if you also try to solve \ntruncation, it will get you very close to my code.\n"},{"id":"384863","messageId":"nycvar.QRO.7.76.6.1910251548560.46@tvgsbejvaqbjf.bet","threadId":"52091","inReplyTo":"e7002f76-65d3-607f-3b5a-e242938374f7@syntevo.com","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-25T14:02:36Z","receivedAt":"2019-10-25T14:03:04Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Alex,\n\nOn Fri, 25 Oct 2019, Alexandr Miloslavskiy wrote:\n\n> > Maybe this could do with an example?\n>\n> I myself observed results like this when running t5516:\n> ------\n> fatal: git fatal: remote errouploar: upload-pack: not our ref\n> 64ea4c133d59fa98e86a771eda009872d6ab2886d-pack: not o\n> ur ref 64ea4c133d59fa98e86a771eda009872d6ab2886\n> ------\n>\n> Do you want me to add this garbled string to commit message?\n\nI think that would make things a lot more relatable ;-)\n\nMy example is even worse (read: more convincing), though:\n\nfatal: git uploadfata-lp: raemcokte :error:  upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n8e86a771eda009872d6ab2886\n\nSo maybe you want to use that?\n\n> > > +\tbuf = malloc(buf_size);\n>\n> > Why not `alloca()`?\n>\n> Allocating large chunks on stack is usually not recommended. There is a funny\n> test \"init allows insanely long --template\" in t0001 which demonstrates that\n> sometimes vreportf() can attempt to print very long strings. Crashing due to\n> stack overflow doesn't sound like a good thing.\n\nIndeed. A clipped message will be a lot more helpful in such a scenario.\n\n> > And to take a step back, I think that previous rounds of patches trying\n> > to essentially address the same problem made the case that it is okay to\n> > cut off insanely-long messages, so I am not sure we would want to open\n> > that can of worms again...\n>\n> I draw a different conclusion here. Each author thought that \"1024 must\n> definitely be enough!\" but then discovered that it's not enough again, for\n> example due to long \"usage\" output. At some point, f4c3edc0 even tried to\n> remove all limits after a chain of limits that were too small. So I would say\n> that this is still a problem.\n\nThe most important aspect of `vreportf()` is, at least as far as I am\nconcerned, to \"get the message out\".\n\nAs such, no, I don't want it to fail, neither due to `alloca()` nor due\nto `malloc()`. I'd rather have it produce a cut-off message that at\nleast shows the first 4095 bytes of the message.\n\n> > Quite honestly, I would love to avoid that amount of complexity,\n> > certainly in a part of the code that we would like to have rock\n> > solid because it is usually exercised when things go very, very\n> > wrong and we need to provide the user who is bitten by it enough\n> > information to take to the Git contributors to figure out the root\n> > cause(s).\n>\n> It's a choice between simpler code and trying to account for\n> everything that could happen. I think we'd rather have more complex\n> code that handles more cases, exactly to try and deliver output to\n> user no matter what.\n\nComplex code usually has more bugs than simple code. I don't want\n`vreportf()` to have potential bugs that we don't know about.\n\n> > Is the problem that causes those failures with VS the fact that\n> > `fprintf(stderr, ...)` might be interleaved with the output of\n> > another process that _also_ wants to write to `stderr`? I assume\n> > that this _is_ the problem.\n>\n> This is where I started. But if you look at comment in vreportf_buf,\n> there are more problems, such as interleaving blocks of larger\n> messages, which could happen on any platform. I tried to make it work\n> in most cases possible.\n\nAgain, I don't think that it is wise to try to make this work for\narbitrary sizes of error messages.\n\nAt some stage, the scrollback of the console won't be large enough to\nfix that message!\n\nSo I think it is very sane to say that at some point, enough is enough.\n\nFour thousand bytes seems a really long message, anyway.\n\n> > Further, I guess that the problem is compounded by the fact that we\n> > usually run the tests in a Git Bash on Windows, i.e. in a MinTTY\n> > that emulates a console (there _is_ work under way to support the\n> > newly introduces ptys, but that work is far from done), so the\n> > standard error file handle might behave in unexpected ways in that\n> > scenario.\n>\n> To my knowledge, this is not related. t5516 failures are because git\n> explicitly wants stderr to be unbuffered. VC++ and MinGW runtimes take\n> that literally. fprintf() outputs char-by-char, and all of that\n> results in char-interleaving.\n\nYes, as my example above demonstrates. (Ugh!)\n\n> > But I do wonder whether replacing that `fprintf()` by a `write()` would\n> > work better. After all, we could write the `prefix` into the `msg`\n> > already:\n> >\n> >  size_t off = strlcpy(msg, prefix, sizeof(msg));\n> >  int ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);\n> >  [...]\n> >  if (ret > 0)\n> >   write(2, msg, off + ret);\n> >\n> > Would that also work around the problem?\n>\n> You forgot to add '\\'n. But yes, that would solve many problems,\n\n\n... and indeed, I verified that this patch fixes the problem:\n\n-- snip --\ndiff --git a/usage.c b/usage.c\nindex 2fdb20086bd..7f5bdfb0f40 100644\n--- a/usage.c\n+++ b/usage.c\n@@ -10,13 +10,16 @@ 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\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n+\t\twrite_in_full(2, msg, off + ret + 1);\n+\t}\n }\n\n static NORETURN void usage_builtin(const char *err, va_list params)\n-- snap --\n\n> except truncation to 4096. Then I would expect a patch to increase\n> buffer size to 8192 in the next couple years. And if you also try to\n> solve truncation, it will get you very close to my code.\n\nMy point is: I don't want to \"fix\" truncation. I actually think of it as\na feature. An error message that is longer than the average news article\nI read is too long, period.\n\nBTW I have a couple more tidbits to add to the commit message, if you\nwould be so kind as to pick them up: I know _which_ two processes battle\nfor `stderr`. I instrumented the code slightly, and this is what I got:\n\n-- snip --\n$ GIT_TRACE=1 GIT_TEST_PROTOCOL_VERSION= ../git.exe --exec-path=$PWD/..  -C trash\\ directory.t5516-fetch-push/shallow2/  fetch ../testrepo/.git 64ea4c133d59fa98e86a771eda009872d6ab2886\n14:55:55.360382 exec-cmd.c:238          trace: resolved executable dir: C:/git-sdk-64/usr/src/vs2017-test\n14:55:55.362379 exec-cmd.c:54           RUNTIME_PREFIX requested, but prefix computation failed.  Using static fallback '/mingw64'.\n14:55:55.387189 git.c:444               trace: built-in (pid=21620): git fetch ../testrepo/.git 64ea4c133d59fa98e86a771eda009872d6ab2886\n14:55:55.392644 run-command.c:663       trace: run_command: unset GIT_PREFIX; 'git-upload-pack '\\''../testrepo/.git'\\'''\n14:55:55.659992 exec-cmd.c:238          trace: resolved executable dir: C:/git-sdk-64/usr/src/vs2017-test\n14:55:55.661762 exec-cmd.c:54           RUNTIME_PREFIX requested, but prefix computation failed.  Using static fallback '/mingw64'.\n14:55:55.662759 git.c:444               trace: built-in (pid=27452): git upload-pack ../testrepo/.git\n14:55:55.681188 run-command.c:663       trace: run_command: git rev-list --stdin\nfatal: git upload-pack: not our ref 64ea4c133d59fa98e86a771eda009872d6ab2886\nfatal: remote error (pid=21620): upload-pack: not our ref 64ea4c133d59fa98e86a771eda009872d6ab2886\n-- snap --\n\nAs you can see, the two error messages stem from the `git fetch` process\n(with the prefix \"remote error:\") and the process it spawned, `git upload-pack`.\n\nBTW if you pick up the indicated patch and the tidbits for the commit\nmessage and then send out a new iteration via GitGitGadget, I would not\nmind being co-author at all ;-)\n\nCiao,\nDscho\n"},{"id":"384866","messageId":"4bd58e13-4e6e-5122-6127-4399d34fde43@syntevo.com","threadId":"52091","inReplyTo":"nycvar.QRO.7.76.6.1910251548560.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Alexandr Miloslavskiy","fromEmail":"alexandr.miloslavskiy@syntevo.com","sentAt":"2019-10-25T14:15:37Z","receivedAt":"2019-10-25T14:15:41Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"On 25.10.2019 16:02, Johannes Schindelin wrote:\n> My example is even worse (read: more convincing), though:\n> \n> fatal: git uploadfata-lp: raemcokte :error:  upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n> 8e86a771eda009872d6ab2886\n> \n> So maybe you want to use that?\n\nOK.\n\n> Again, I don't think that it is wise to try to make this work for\n> arbitrary sizes of error messages.\n\n > My point is: I don't want to \"fix\" truncation. I actually think of it\n > as a feature\n\nIt would be helpful to hear opinions from someone else, before the patch \nis reworked significantly.\n\n> I know _which_ two processes battle for `stderr`.\n\nI think I said the same in code comment, bullet 3, near t5516?\n"},{"id":"384887","messageId":"nycvar.QRO.7.76.6.1910252323490.46@tvgsbejvaqbjf.bet","threadId":"52091","inReplyTo":"4bd58e13-4e6e-5122-6127-4399d34fde43@syntevo.com","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-25T21:28:53Z","receivedAt":"2019-10-25T21:29:17Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Alex,\n\nOn Fri, 25 Oct 2019, Alexandr Miloslavskiy wrote:\n\n> On 25.10.2019 16:02, Johannes Schindelin wrote:\n> > My example is even worse (read: more convincing), though:\n> >\n> > fatal: git uploadfata-lp: raemcokte :error:  upload-pnot our arcef k6: n4ot\n> > our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9\n> > 8e86a771eda009872d6ab2886\n> >\n> > So maybe you want to use that?\n>\n> OK.\n>\n> > Again, I don't think that it is wise to try to make this work for\n> > arbitrary sizes of error messages.\n>\n> > My point is: I don't want to \"fix\" truncation. I actually think of it\n> > as a feature\n>\n> It would be helpful to hear opinions from someone else, before the patch is\n> reworked significantly.\n\nIf you must wait, well, then you must.\n\nThe commits you found seem to suggest already that there is support for\nclipping the message, but hey, what do I know, maybe the mood changed\nover the years.\n\nSince I have to re-run CI/PR builds regularly that failed due to t5516,\nI will be very tempted _not_ to wait, though.\n\n> > I know _which_ two processes battle for `stderr`.\n>\n> I think I said the same in code comment, bullet 3, near t5516?\n\nProbably.\n\nA code comment about a test case that is not in the very vicinity of\nsaid comment is _prone_ to get stale.\n\nIn other words: this information does not belong into a code comment. It\nbelongs into the commit message.\n\nIf you needed any indication that this is true: I would not have missed\nthis important piece if it had been in the commit message (instead of\nthe code with whose added complexity I disagree).\n\nCiao,\nDscho\n"},{"id":"384890","messageId":"20191025221118.GA29213@sigill.intra.peff.net","threadId":"52091","inReplyTo":"nycvar.QRO.7.76.6.1910251548560.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-25T22:11:19Z","receivedAt":"2019-10-25T22:11:21Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Oct 25, 2019 at 04:02:36PM +0200, Johannes Schindelin wrote:\n\n> ... and indeed, I verified that this patch fixes the problem:\n> \n> -- snip --\n> diff --git a/usage.c b/usage.c\n> index 2fdb20086bd..7f5bdfb0f40 100644\n> --- a/usage.c\n> +++ b/usage.c\n> @@ -10,13 +10,16 @@ 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\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n> +\t\twrite_in_full(2, msg, off + ret + 1);\n> +\t}\n>  }\n\nHeh. This is quite similar to what I posted in:\n\n  https://public-inbox.org/git/20190828145412.GB14432@sigill.intra.peff.net/\n\nthough I missed the cleverness with \"we no longer need a NUL\" to get an\nextra byte. ;)\n\n> > except truncation to 4096. Then I would expect a patch to increase\n> > buffer size to 8192 in the next couple years. And if you also try to\n> > solve truncation, it will get you very close to my code.\n> \n> My point is: I don't want to \"fix\" truncation. I actually think of it as\n> a feature. An error message that is longer than the average news article\n> I read is too long, period.\n\nYeah. As the person responsible for many of the \"avoid truncation\" works\nreferenced in the original patch, I have come to the conclusion that it\nis not worth the complexity. Even when we do manage to produce a\ngigantic error message correctly, it's generally not very readable.\n\nThat's basically what I came here to say, and I was pleased to find that\nyou had already argued for it quite well. So I'll just add my support\nfor the direction you've taken the conversation.\n\nI _do_ wish we could do the truncation more intelligently. I'd much\nrather see:\n\n  error: unable to open 'absurdly-long-file-name...': permission denied\n\nthan:\n\n  error: unable to open 'absurdly-long-file-name-that-goes-on-forever-and-ev\n\nBut I don't think it's possible without reimplementing snprintf\nourselves.\n\n-Peff\n"},{"id":"384907","messageId":"da6420c7-205e-c73c-8397-ab5d4b1a6663@syntevo.com","threadId":"52091","inReplyTo":"20191025221118.GA29213@sigill.intra.peff.net","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Alexandr Miloslavskiy","fromEmail":"alexandr.miloslavskiy@syntevo.com","sentAt":"2019-10-26T08:02:00Z","receivedAt":"2019-10-26T08:02:05Z","isPatch":true,"sender":{"key":"alexandr.miloslavskiy@syntevo.com","avatar":null},"body":"On 26.10.2019 0:11, Jeff King wrote:\n> Yeah. As the person responsible for many of the \"avoid truncation\" works\n> referenced in the original patch, I have come to the conclusion that it\n> is not worth the complexity. Even when we do manage to produce a\n> gigantic error message correctly, it's generally not very readable.\n> \n> That's basically what I came here to say, and I was pleased to find that\n> you had already argued for it quite well. So I'll just add my support\n> for the direction you've taken the conversation.\n\n\nThanks! Truncation, then :)\n"},{"id":"384919","messageId":"nycvar.QRO.7.76.6.1910262040360.46@tvgsbejvaqbjf.bet","threadId":"52091","inReplyTo":"20191025221118.GA29213@sigill.intra.peff.net","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-26T20:56:45Z","receivedAt":"2019-10-26T20:57:29Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Fri, 25 Oct 2019, Jeff King wrote:\n\n> On Fri, Oct 25, 2019 at 04:02:36PM +0200, Johannes Schindelin wrote:\n>\n> > ... and indeed, I verified that this patch fixes the problem:\n> >\n> > -- snip --\n> > diff --git a/usage.c b/usage.c\n> > index 2fdb20086bd..7f5bdfb0f40 100644\n> > --- a/usage.c\n> > +++ b/usage.c\n> > @@ -10,13 +10,16 @@ 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\tmsg[off + ret] = '\\n'; /* we no longer need a NUL */\n> > +\t\twrite_in_full(2, msg, off + ret + 1);\n> > +\t}\n> >  }\n>\n> Heh. This is quite similar to what I posted in:\n>\n>   https://public-inbox.org/git/20190828145412.GB14432@sigill.intra.peff.net/\n>\n> though I missed the cleverness with \"we no longer need a NUL\" to get an\n> extra byte. ;)\n\n:-)\n\nI also use `xwrite()` instead of `write()`...\n\n> > > except truncation to 4096. Then I would expect a patch to increase\n> > > buffer size to 8192 in the next couple years. And if you also try to\n> > > solve truncation, it will get you very close to my code.\n> >\n> > My point is: I don't want to \"fix\" truncation. I actually think of it as\n> > a feature. An error message that is longer than the average news article\n> > I read is too long, period.\n>\n> Yeah. As the person responsible for many of the \"avoid truncation\" works\n> referenced in the original patch, I have come to the conclusion that it\n> is not worth the complexity. Even when we do manage to produce a\n> gigantic error message correctly, it's generally not very readable.\n>\n> That's basically what I came here to say, and I was pleased to find that\n> you had already argued for it quite well. So I'll just add my support\n> for the direction you've taken the conversation.\n\nThank you for affirming. I have to admit that I would have loved for my\nargument to work on its own, and not require the additional force of a\nsecond opinion. In my mind, there is little opinion required here.\n\n> I _do_ wish we could do the truncation more intelligently. I'd much\n> rather see:\n>\n>   error: unable to open 'absurdly-long-file-name...': permission denied\n>\n> than:\n>\n>   error: unable to open 'absurdly-long-file-name-that-goes-on-forever-and-ev\n>\n> But I don't think it's possible without reimplementing snprintf\n> ourselves.\n\nIndeed. I _did_ start to implement `strbuf_vaddf()` from scratch, over\nten years ago:\n\nhttps://public-inbox.org/git/alpine.LSU.1.00.0803061727120.3941@racer.site/\n\nI am not sure whether we want to resurrect it, it would need to grow\nsupport _at least_ for `%PRIuMAX` and `%PRIdMAX`, but that should not be\nhard.\n\nBack to the issue at hand: I did open a GitGitGadget PR with my proposed\nchange, in the hopes that I could somehow fast-track this fix into the\nCI/PR builds over at https://github.com/gitgitgadget/git, but there are\nproblems: it seems that now there is an at least occasional broken pipe\nin the same test when run on macOS.\n\nThere _also_ seems to be something spooky going on in t3510.12 and .13,\nwhere the expected output differs from the actual output only by a\nre-ordering of the lines:\n\n-- snip --\n[...]\n+++ diff -u expect advice\n--- expect\t2019-10-25 22:17:44.982884700 +0000\n+++ advice\t2019-10-25 22:17:45.278884500 +0000\n@@ -1,3 +1,3 @@\n error: cherry-pick is already in progress\n-hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n fatal: cherry-pick failed\n+hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n-- snap --\n\nFor details, see:\nhttps://dev.azure.com/gitgitgadget/git/_build/results?buildId=19336&view=ms.vss-test-web.build-test-results-tab\nand\nhttps://dev.azure.com/Git-for-Windows/git/_build/results?buildId=44549&view=ms.vss-test-web.build-test-results-tab\n(You need to click on a test case title to open the logs, then inspect\nthe Attachments to get to the full trace)\n\nSo much as I would love to see the flakiness of t5516 be fixed as soon\nas possible, I fear we will have to look at the underlying issue a bit\ncloser: there are two processes writing to `stderr` concurrently. I\ndon't know whether there would be a good way for the `stderr` of the\n`upload-pack` process to be consumed by the `fetch` process, and to be\nprinted by the latter.\n\nCiao,\nDscho\n"},{"id":"384920","messageId":"20191026213648.GA7331@sigill.intra.peff.net","threadId":"52091","inReplyTo":"nycvar.QRO.7.76.6.1910262040360.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-10-26T21:36:48Z","receivedAt":"2019-10-26T21:36:52Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Sat, Oct 26, 2019 at 10:56:45PM +0200, Johannes Schindelin wrote:\n\n> Back to the issue at hand: I did open a GitGitGadget PR with my proposed\n> change, in the hopes that I could somehow fast-track this fix into the\n> CI/PR builds over at https://github.com/gitgitgadget/git, but there are\n> problems: it seems that now there is an at least occasional broken pipe\n> in the same test when run on macOS.\n\nYes, I think that's another issue in the same test. There's more\ndiscussion further down in the thread I linked earlier, starting here:\n\n  https://public-inbox.org/git/20190829143805.GB1746@sigill.intra.peff.net/\n\nand I think Gábor's solution here:\n\n  https://public-inbox.org/git/20190830121005.GI8571@szeder.dev/\n\nis the right direction (and note that this _isn't_ just a test artifact,\nbut a bug that occasionally hits real-world cases, too).\n\n> There _also_ seems to be something spooky going on in t3510.12 and .13,\n> where the expected output differs from the actual output only by a\n> re-ordering of the lines:\n> \n> -- snip --\n> [...]\n> +++ diff -u expect advice\n> --- expect\t2019-10-25 22:17:44.982884700 +0000\n> +++ advice\t2019-10-25 22:17:45.278884500 +0000\n> @@ -1,3 +1,3 @@\n>  error: cherry-pick is already in progress\n> -hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n>  fatal: cherry-pick failed\n> +hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n> -- snap --\n\nHrm. I'd have thought those are both coming from the same process. Which\nimplies that we're not fflushing stderr before calling write(2). But\nyour patch seems to do so...\n\n<scratches head> Aha. I think you force-pushed up as I am typing this.\n:) So I think that is indeed the solution.\n\n> So much as I would love to see the flakiness of t5516 be fixed as soon\n> as possible, I fear we will have to look at the underlying issue a bit\n> closer: there are two processes writing to `stderr` concurrently. I\n> don't know whether there would be a good way for the `stderr` of the\n> `upload-pack` process to be consumed by the `fetch` process, and to be\n> printed by the latter.\n\nThe worst part is that this message already _is_ consumed by fetch: we\nsend it twice, once over the sideband, and once directly to stderr. In\nmost cases the stderr version is lost, but some server providers might\nbe collecting it. I wouldn't mind seeing the direct-to-stderr one\ndropped. There's some more discussion in (from the same thread linked\nearlier):\n\n  https://public-inbox.org/git/20190828145412.GB14432@sigill.intra.peff.net/\n\n-Peff\n"},{"id":"384921","messageId":"nycvar.QRO.7.76.6.1910262351340.46@tvgsbejvaqbjf.bet","threadId":"52091","inReplyTo":"nycvar.QRO.7.76.6.1910262040360.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-26T21:56:21Z","receivedAt":"2019-10-26T21:57:08Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Sat, 26 Oct 2019, Johannes Schindelin wrote:\n\n> [...] I did open a GitGitGadget PR with my proposed change,\n\nI should have mentioned the URL:\n\n\thttps://github.com/gitgitgadget/git/pull/428\n\nFWIW, in the meantime I managed to address below-mentioned breakages\n(apart from the broken pipe problem that is discussed over here:\nhttps://public-inbox.org/git/20190828161552.GE8571@szeder.dev/) and the\nbuild is green.\n\nAlex asked to be given time to brush his patch up on Monday, so I am\nholding off sending my version (for now...).\n\nCiao,\nDscho\n\n> in the hopes that I could somehow fast-track this fix into the\n> CI/PR builds over at https://github.com/gitgitgadget/git, but there are\n> problems: it seems that now there is an at least occasional broken pipe\n> in the same test when run on macOS.\n>\n> There _also_ seems to be something spooky going on in t3510.12 and .13,\n> where the expected output differs from the actual output only by a\n> re-ordering of the lines:\n>\n> -- snip --\n> [...]\n> +++ diff -u expect advice\n> --- expect\t2019-10-25 22:17:44.982884700 +0000\n> +++ advice\t2019-10-25 22:17:45.278884500 +0000\n> @@ -1,3 +1,3 @@\n>  error: cherry-pick is already in progress\n> -hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n>  fatal: cherry-pick failed\n> +hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n> -- snap --\n>\n> For details, see:\n> https://dev.azure.com/gitgitgadget/git/_build/results?buildId=19336&view=ms.vss-test-web.build-test-results-tab\n> and\n> https://dev.azure.com/Git-for-Windows/git/_build/results?buildId=44549&view=ms.vss-test-web.build-test-results-tab\n> (You need to click on a test case title to open the logs, then inspect\n> the Attachments to get to the full trace)\n>\n> So much as I would love to see the flakiness of t5516 be fixed as soon\n> as possible, I fear we will have to look at the underlying issue a bit\n> closer: there are two processes writing to `stderr` concurrently. I\n> don't know whether there would be a good way for the `stderr` of the\n> `upload-pack` process to be consumed by the `fetch` process, and to be\n> printed by the latter.\n>\n> Ciao,\n> Dscho\n>\n"},{"id":"384924","messageId":"nycvar.QRO.7.76.6.1910270002570.46@tvgsbejvaqbjf.bet","threadId":"52091","inReplyTo":"nycvar.QRO.7.76.6.1910262351340.46@tvgsbejvaqbjf.bet","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-26T22:05:10Z","receivedAt":"2019-10-26T22:07:42Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Sorry, me again,\n\nOn Sat, 26 Oct 2019, Johannes Schindelin wrote:\n\n> On Sat, 26 Oct 2019, Johannes Schindelin wrote:\n>\n> > [...] I did open a GitGitGadget PR with my proposed change,\n>\n> I should have mentioned the URL:\n>\n> \thttps://github.com/gitgitgadget/git/pull/428\n\nI should have mentioned that I also opened\nhttps://github.com/git-for-windows/git/pull/2373 with the same branch,\nwhich exercizes the Visual Studio build, too, so it is a bit more\ninformative than the GitGitGadget PR (which only runs the regular GCC\nbuild on Windows which, as per Alex' analysis, is not affected by this\nproblem).\n\nCiao,\nDscho\n\n> FWIW, in the meantime I managed to address below-mentioned breakages\n> (apart from the broken pipe problem that is discussed over here:\n> https://public-inbox.org/git/20190828161552.GE8571@szeder.dev/) and the\n> build is green.\n>\n> Alex asked to be given time to brush his patch up on Monday, so I am\n> holding off sending my version (for now...).\n>\n> Ciao,\n> Dscho\n>\n> > in the hopes that I could somehow fast-track this fix into the\n> > CI/PR builds over at https://github.com/gitgitgadget/git, but there are\n> > problems: it seems that now there is an at least occasional broken pipe\n> > in the same test when run on macOS.\n> >\n> > There _also_ seems to be something spooky going on in t3510.12 and .13,\n> > where the expected output differs from the actual output only by a\n> > re-ordering of the lines:\n> >\n> > -- snip --\n> > [...]\n> > +++ diff -u expect advice\n> > --- expect\t2019-10-25 22:17:44.982884700 +0000\n> > +++ advice\t2019-10-25 22:17:45.278884500 +0000\n> > @@ -1,3 +1,3 @@\n> >  error: cherry-pick is already in progress\n> > -hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n> >  fatal: cherry-pick failed\n> > +hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n> > -- snap --\n> >\n> > For details, see:\n> > https://dev.azure.com/gitgitgadget/git/_build/results?buildId=19336&view=ms.vss-test-web.build-test-results-tab\n> > and\n> > https://dev.azure.com/Git-for-Windows/git/_build/results?buildId=44549&view=ms.vss-test-web.build-test-results-tab\n> > (You need to click on a test case title to open the logs, then inspect\n> > the Attachments to get to the full trace)\n> >\n> > So much as I would love to see the flakiness of t5516 be fixed as soon\n> > as possible, I fear we will have to look at the underlying issue a bit\n> > closer: there are two processes writing to `stderr` concurrently. I\n> > don't know whether there would be a good way for the `stderr` of the\n> > `upload-pack` process to be consumed by the `fetch` process, and to be\n> > printed by the latter.\n> >\n> > Ciao,\n> > Dscho\n> >\n>\n"},{"id":"385006","messageId":"nycvar.QRO.7.76.6.1910281701430.46@tvgsbejvaqbjf.bet","threadId":"52091","inReplyTo":"20191026213648.GA7331@sigill.intra.peff.net","subject":"Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-10-28T16:05:39Z","receivedAt":"2019-10-28T16:06:09Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Peff,\n\nOn Sat, 26 Oct 2019, Jeff King wrote:\n\n> On Sat, Oct 26, 2019 at 10:56:45PM +0200, Johannes Schindelin wrote:\n>\n> > Back to the issue at hand: I did open a GitGitGadget PR with my proposed\n> > change, in the hopes that I could somehow fast-track this fix into the\n> > CI/PR builds over at https://github.com/gitgitgadget/git, but there are\n> > problems: it seems that now there is an at least occasional broken pipe\n> > in the same test when run on macOS.\n>\n> Yes, I think that's another issue in the same test. There's more\n> discussion further down in the thread I linked earlier, starting here:\n>\n>   https://public-inbox.org/git/20190829143805.GB1746@sigill.intra.peff.net/\n>\n> and I think Gábor's solution here:\n>\n>   https://public-inbox.org/git/20190830121005.GI8571@szeder.dev/\n>\n> is the right direction (and note that this _isn't_ just a test artifact,\n> but a bug that occasionally hits real-world cases, too).\n\nThat sounds good! I guess I should continue _that_ thread.\n\n> > There _also_ seems to be something spooky going on in t3510.12 and .13,\n> > where the expected output differs from the actual output only by a\n> > re-ordering of the lines:\n> >\n> > -- snip --\n> > [...]\n> > +++ diff -u expect advice\n> > --- expect\t2019-10-25 22:17:44.982884700 +0000\n> > +++ advice\t2019-10-25 22:17:45.278884500 +0000\n> > @@ -1,3 +1,3 @@\n> >  error: cherry-pick is already in progress\n> > -hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n> >  fatal: cherry-pick failed\n> > +hint: try \"git cherry-pick (--continue | --skip | --abort | --quit)\"\n> > -- snap --\n>\n> Hrm. I'd have thought those are both coming from the same process. Which\n> implies that we're not fflushing stderr before calling write(2). But\n> your patch seems to do so...\n>\n> <scratches head> Aha. I think you force-pushed up as I am typing this.\n> :) So I think that is indeed the solution.\n\nYes, sorry, I had this idea and it worked locally, and I wanted to know\nwhether it would turn the PR build green.\n\n> > So much as I would love to see the flakiness of t5516 be fixed as soon\n> > as possible, I fear we will have to look at the underlying issue a bit\n> > closer: there are two processes writing to `stderr` concurrently. I\n> > don't know whether there would be a good way for the `stderr` of the\n> > `upload-pack` process to be consumed by the `fetch` process, and to be\n> > printed by the latter.\n>\n> The worst part is that this message already _is_ consumed by fetch: we\n> send it twice, once over the sideband, and once directly to stderr. In\n> most cases the stderr version is lost, but some server providers might\n> be collecting it. I wouldn't mind seeing the direct-to-stderr one\n> dropped. There's some more discussion in (from the same thread linked\n> earlier):\n>\n>   https://public-inbox.org/git/20190828145412.GB14432@sigill.intra.peff.net/\n\nIt is tricky all right.\n\nFull disclosure: I am mainly interested in having lots less failing\nbuilds (which I all re-run manually when I see that a known-flaky test\nfailed).\n\nCiao,\nDscho\n"}]}