{"thread":{"id":"43000","subject":"[PATCH 2/7] trace: stop using write_or_whine_pipe()","startedAt":"2016-08-03T22:59:17Z","lastAt":"2016-08-05T18:42:04Z","messageCount":20,"participants":["Jeff King","Junio C Hamano","Christian Couder"],"isPatch":true,"patchVersion":1,"patchTotal":7},"messages":[{"id":"293034","messageId":"20160803225800.mwwznno7tiujycgt@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"[PATCH 2/7] trace: stop using write_or_whine_pipe()","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T22:58:00Z","receivedAt":"2016-08-03T22:59:17Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"The write_or_whine_pipe function does two things:\n\n 1. it checks for EPIPE and converts it into a signal death\n\n 2. it prints a message to stderr on error\n\nThe first thing does not help us, and actively hurts.\nGenerally we would simply die from SIGPIPE in this case,\nunless somebody has taken the time to ignore SIGPIPE for the\nwhole process. And if they _did_ do that, it seems rather\nsilly for the trace code, which otherwise takes pains to\ncontinue even in the face of errors (e.g., by not using\nwrite_or_die!), to take down the whole process for one\nspecific type of error.\n\nNor does the second thing help us; it just makes it harder\nto write our error message, because we have to feed bits of\nit as an argument to write_or_whine_pipe(). Translators\nnever get to see the full message, and it's hard for us to\ncustomize it.\n\nLet's switch to just using write_in_full() and writing our\nown error string. For now, the error is identical to what\nwrite_or_whine_pipe() would say, but now that it's more\nunder our control, we can improve it in future patches.\n\nSigned-off-by: Jeff King \n---\n trace.c | 11 ++++++++---\n 1 file changed, 8 insertions(+), 3 deletions(-)\n\ndiff --git a/trace.c b/trace.c\nindex f204a7d..bdbe149 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -132,18 +132,23 @@ static int prepare_trace_line(const char *file, int line,\n \treturn 1;\n }\n \n+static void trace_write(struct trace_key *key, const void *buf, unsigned len)\n+{\n+\tif (write_in_full(get_trace_fd(key), buf, len) < 0)\n+\t\tfprintf(stderr, \"%s: write error (%s)\\n\", err_msg, strerror(errno));\n+}\n+\n void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)\n {\n \tif (!trace_want(key))\n \t\treturn;\n-\twrite_or_whine_pipe(get_trace_fd(key), buf, len, err_msg);\n+\ttrace_write(key, buf, len);\n }\n \n static void print_trace_line(struct trace_key *key, struct strbuf *buf)\n {\n \tstrbuf_complete_line(buf);\n-\n-\twrite_or_whine_pipe(get_trace_fd(key), buf->buf, buf->len, err_msg);\n+\ttrace_write(key, buf->buf, buf->len);\n \tstrbuf_release(buf);\n }\n \n-- \n2.9.2.670.g42e63de\n\n"},{"id":"293035","messageId":"20160803225826.hlr273h4cy2hcfyk@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"[PATCH 3/7] trace: use warning() for printing trace errors","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T22:58:26Z","receivedAt":"2016-08-03T22:59:55Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"Right now we just fprintf() straight to stderr, which can\nmake the output hard to distinguish. It would be helpful to\ngive it one of our usual prefixes like \"error:\", \"warning:\",\netc.\n\nIt doesn't make sense to use error() here, as the trace code\nis \"optional\" debugging code. If something goes wrong, we\nshould warn the user, but saying \"error\" implies the actual\ngit operation had a problem. So warning() is the only sane\nchoice.\n\nNote that this does end up calling warn_routine() to do the\nformatting. So in theory, somebody who tries to trace from\ntheir warn_routine() could cause a loop. But nobody does\nthis, and in fact nobody in the history of git has ever\nreplaced the default warn_builtin (there isn't even a\nset_warn_routine function!).\n\nSigned-off-by: Jeff King \n---\n trace.c | 11 +++++------\n 1 file changed, 5 insertions(+), 6 deletions(-)\n\ndiff --git a/trace.c b/trace.c\nindex bdbe149..6a77e4d 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -61,9 +61,8 @@ static int get_trace_fd(struct trace_key *key)\n \telse if (is_absolute_path(trace)) {\n \t\tint fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666);\n \t\tif (fd == -1) {\n-\t\t\tfprintf(stderr,\n-\t\t\t\t\"Could not open '%s' for tracing: %s\\n\"\n-\t\t\t\t\"Defaulting to tracing on stderr...\\n\",\n+\t\t\twarning(\"Could not open '%s' for tracing: %s\\n\"\n+\t\t\t\t\"Defaulting to tracing on stderr...\",\n \t\t\t\ttrace, strerror(errno));\n \t\t\tkey->fd = STDERR_FILENO;\n \t\t} else {\n@@ -71,10 +70,10 @@ static int get_trace_fd(struct trace_key *key)\n \t\t\tkey->need_close = 1;\n \t\t}\n \t} else {\n-\t\tfprintf(stderr, \"What does '%s' for %s mean?\\n\"\n+\t\twarning(\"What does '%s' for %s mean?\\n\"\n \t\t\t\"If you want to trace into a file, then please set \"\n \t\t\t\"%s to an absolute pathname (starting with /).\\n\"\n-\t\t\t\"Defaulting to tracing on stderr...\\n\",\n+\t\t\t\"Defaulting to tracing on stderr...\",\n \t\t\ttrace, key->key, key->key);\n \t\tkey->fd = STDERR_FILENO;\n \t}\n@@ -135,7 +134,7 @@ static int prepare_trace_line(const char *file, int line,\n static void trace_write(struct trace_key *key, const void *buf, unsigned len)\n {\n \tif (write_in_full(get_trace_fd(key), buf, len) < 0)\n-\t\tfprintf(stderr, \"%s: write error (%s)\\n\", err_msg, strerror(errno));\n+\t\twarning(\"%s: write error (%s)\", err_msg, strerror(errno));\n }\n \n void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)\n-- \n2.9.2.670.g42e63de\n\n"},{"id":"293036","messageId":"20160803230103.daexq233ufrttnmn@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"[PATCH 6/7] trace: disable key after write error","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T23:01:04Z","receivedAt":"2016-08-03T23:02:59Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"If we get a write error writing to a trace descriptor, the\nerror isn't likely to go away if we keep writing. Instead,\nyou'll just get the same error over and over. E.g., try:\n\n GIT_TRACE_PACKET=42 git ls-remote >/dev/null\n\nYou don't really need to see:\n\n warning: unable to write trace for GIT_TRACE_PACKET: Bad file descriptor\n\nhundreds of times. We could fallback to tracing to stderr,\nas we do in the error code-path for open(), but there's not\nmuch point. If the user fed us a bogus descriptor, they're\nprobably better off fixing their invocation. And if they\ndidn't, and we saw a transient error (e.g., ENOSPC writing\nto a file), it probably doesn't help anybody to have half of\nthe trace in a file, and half on stderr.\n\nSigned-off-by: Jeff King \n---\n trace.c | 1 +\n 1 file changed, 1 insertion(+)\n\ndiff --git a/trace.c b/trace.c\nindex 4efb256..083eb98 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -134,6 +134,7 @@ static void trace_write(struct trace_key *key, const void *buf, unsigned len)\n \t\tnormalize_trace_key(&key);\n \t\twarning(\"unable to write trace for %s: %s\",\n \t\t\tkey->key, strerror(errno));\n+\t\ttrace_disable(key);\n \t}\n }\n \n-- \n2.9.2.670.g42e63de\n\n"},{"id":"293037","messageId":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803213920.jg3eshy57bsldqjh@sigill.intra.peff.net","subject":"[PATCH 0/7] minor trace fixes and cosmetic improvements","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T22:56:00Z","receivedAt":"2016-08-03T23:03:03Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Aug 03, 2016 at 05:39:20PM -0400, Jeff King wrote:\n\n> Thinking about (2), I'd go so far as to say that the trace actually\n> should just be using:\n> \n> if (write_in_full(...) < 0)\n> \twarning(\"unable to write trace to ...: %s\", strerror(errno));\n> \n> and we should get rid of write_or_whine_pipe entirely.\n\nI started to write a patch to do that, but it turns out the trace code\nis full of bugs (and opportunities for cosmetic improvements).\n\nHere's what I came up with.\n\n [1/7]: trace: handle NULL argument in trace_disable()\n [2/7]: trace: stop using write_or_whine_pipe()\n [3/7]: trace: use warning() for printing trace errors\n [4/7]: trace: cosmetic fixes for error messages\n [5/7]: trace: correct variable name in write() error message\n [6/7]: trace: disable key after write error\n [7/7]: write_or_die: drop write_or_whine_pipe()\n\n-Peff\n"},{"id":"293038","messageId":"20160803230141.fujy7umrihw2utpu@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"[PATCH 7/7] write_or_die: drop write_or_whine_pipe()","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T23:01:42Z","receivedAt":"2016-08-03T23:03:16Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"This function has no callers, and is not likely to gain any\nbecause it's confusing to use.\n\nIt unconditionally complains to stderr, but _doesn't_ die.\nYet any caller which wants a \"gentle\" write would generally\nwant to suppress the error message, because presumably\nthey're going to write a better one, and/or try the\noperation again.\n\nAnd the check_pipe() call leads to confusing behaviors. It\nmeans we die for EPIPE, but not for other errors, which is\nconfusing and pointless.\n\nOn top of all that, it has unusual error return semantics,\nwhich makes it easy for callers to get it wrong.\n\nLet's drop the function, and if somebody ever needs to\nresurrect something like it, they can fix these warts.\n\nSigned-off-by: Jeff King \n---\n cache.h | 1 -\n write_or_die.c | 12 ------------\n 2 files changed, 13 deletions(-)\n\ndiff --git a/cache.h b/cache.h\nindex b5f76a4..3885911 100644\n--- a/cache.h\n+++ b/cache.h\n@@ -1740,7 +1740,6 @@ extern int copy_file(const char *dst, const char *src, int mode);\n extern int copy_file_with_time(const char *dst, const char *src, int mode);\n \n extern void write_or_die(int fd, const void *buf, size_t count);\n-extern int write_or_whine_pipe(int fd, const void *buf, size_t count, const char *msg);\n extern void fsync_or_die(int fd, const char *);\n \n extern ssize_t read_in_full(int fd, void *buf, size_t count);\ndiff --git a/write_or_die.c b/write_or_die.c\nindex 9816879..0734432 100644\n--- a/write_or_die.c\n+++ b/write_or_die.c\n@@ -82,15 +82,3 @@ void write_or_die(int fd, const void *buf, size_t count)\n \t\tdie_errno(\"write error\");\n \t}\n }\n-\n-int write_or_whine_pipe(int fd, const void *buf, size_t count, const char *msg)\n-{\n-\tif (write_in_full(fd, buf, count) < 0) {\n-\t\tcheck_pipe(errno);\n-\t\tfprintf(stderr, \"%s: write error (%s)\\n\",\n-\t\t\tmsg, strerror(errno));\n-\t\treturn 0;\n-\t}\n-\n-\treturn 1;\n-}\n-- \n2.9.2.670.g42e63de\n"},{"id":"293039","messageId":"20160803225657.vdjih5mzvdmilx4d@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"[PATCH 1/7] trace: handle NULL argument in trace_disable()","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T22:56:57Z","receivedAt":"2016-08-03T23:03:44Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"All of the trace functions treat a NULL key as a synonym for\nthe default GIT_TRACE key. Except for trace_disable(), which\nwill segfault.\n\nFortunately, this can't cause any bugs, as the function has\nno callers. But rather than drop it, let's fix the bug, as I\nplan to add a caller.\n\nSigned-off-by: Jeff King \n---\n trace.c | 20 ++++++++++++++++----\n 1 file changed, 16 insertions(+), 4 deletions(-)\n\ndiff --git a/trace.c b/trace.c\nindex 4aeea60..f204a7d 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -25,15 +25,25 @@\n #include \"cache.h\"\n #include \"quote.h\"\n \n+/*\n+ * \"Normalize\" a key argument by converting NULL to our trace_default,\n+ * and otherwise passing through the value. All caller-facing functions\n+ * should normalize their inputs in this way, though most get it\n+ * for free by calling get_trace_fd() (directly or indirectly).\n+ */\n+static void normalize_trace_key(struct trace_key **key)\n+{\n+\tstatic struct trace_key trace_default = { \"GIT_TRACE\" };\n+\tif (!*key)\n+\t\t*key = &trace_default;\n+}\n+\n /* Get a trace file descriptor from \"key\" env variable. */\n static int get_trace_fd(struct trace_key *key)\n {\n-\tstatic struct trace_key trace_default = { \"GIT_TRACE\" };\n \tconst char *trace;\n \n-\t/* use default \"GIT_TRACE\" if NULL */\n-\tif (!key)\n-\t\tkey = &trace_default;\n+\tnormalize_trace_key(&key);\n \n \t/* don't open twice */\n \tif (key->initialized)\n@@ -75,6 +85,8 @@ static int get_trace_fd(struct trace_key *key)\n \n void trace_disable(struct trace_key *key)\n {\n+\tnormalize_trace_key(&key);\n+\n \tif (key->need_close)\n \t\tclose(key->fd);\n \tkey->fd = 0;\n-- \n2.9.2.670.g42e63de\n\n"},{"id":"293040","messageId":"20160803230422.vec7mhjo6jfzbpap@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"Re: [PATCH 0/7] minor trace fixes and cosmetic improvements","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T23:04:23Z","receivedAt":"2016-08-03T23:04:29Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Aug 03, 2016 at 06:56:00PM -0400, Jeff King wrote:\n\n> On Wed, Aug 03, 2016 at 05:39:20PM -0400, Jeff King wrote:\n> \n> > Thinking about (2), I'd go so far as to say that the trace actually\n> > should just be using:\n> > \n> > if (write_in_full(...) < 0)\n> > \twarning(\"unable to write trace to ...: %s\", strerror(errno));\n> > \n> > and we should get rid of write_or_whine_pipe entirely.\n> \n> I started to write a patch to do that, but it turns out the trace code\n> is full of bugs (and opportunities for cosmetic improvements).\n> \n> Here's what I came up with.\n> \n> [1/7]: trace: handle NULL argument in trace_disable()\n> [2/7]: trace: stop using write_or_whine_pipe()\n> [3/7]: trace: use warning() for printing trace errors\n> [4/7]: trace: cosmetic fixes for error messages\n> [5/7]: trace: correct variable name in write() error message\n> [6/7]: trace: disable key after write error\n> [7/7]: write_or_die: drop write_or_whine_pipe()\n\nOops, I meant to detach this from the parent thread, but apparently I am\nincompetent at editing email headers.\n\nThis really is totally orthogonal to your series (except that you should\nobviously not use write_or_whine_pipe(), but that is the case whether I\nrip it out or not :) ).\n\n-Peff\n"},{"id":"293042","messageId":"20160803230022.drw4kcwgheeqn3xr@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"[PATCH 4/7] trace: cosmetic fixes for error messages","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T23:00:23Z","receivedAt":"2016-08-03T23:08:08Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"The error messages for the trace code are often multi-line;\nthe first line gets a nice \"warning:\", but the rest are\nleft-aligned. Let's give them an indentation to make sure\nthey stand out as a unit.\n\nWhile we're here, let's also downcase the first letter of\neach error (our usual style), and break up a long line of\nadvice (since we're already using multiple lines, one more\ndoesn't hurt).\n\nWe also replace \"What does 'foo' for GIT_TRACE mean?\". While\ncute, it's probably a good idea to give more context, and\nfollow our usual styles. So it's now \"unknown trace value\nfor 'GIT_TRACE': foo\".\n\nSigned-off-by: Jeff King \n---\nI went with an indent the size of \"warning: \", because that string does\nnot actually get translated (it seems like it probably should, though).\n\nI think it would be nicer to still to print:\n\n warning: first line\n warning: second line\n\netc. We do that for \"advice:\", but not the rest of the vreportf\nfunctions. It might be nice to do that, but we'd have to go back to\nprinting into a buffer (since we can't break up the incoming format\nstring that we feed to fprintf).\n\n trace.c | 16 ++++++++--------\n 1 file changed, 8 insertions(+), 8 deletions(-)\n\ndiff --git a/trace.c b/trace.c\nindex 6a77e4d..4d68eb5 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -61,8 +61,8 @@ static int get_trace_fd(struct trace_key *key)\n \telse if (is_absolute_path(trace)) {\n \t\tint fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666);\n \t\tif (fd == -1) {\n-\t\t\twarning(\"Could not open '%s' for tracing: %s\\n\"\n-\t\t\t\t\"Defaulting to tracing on stderr...\",\n+\t\t\twarning(\"could not open '%s' for tracing: %s\\n\"\n+\t\t\t\t\" Defaulting to tracing on stderr...\",\n \t\t\t\ttrace, strerror(errno));\n \t\t\tkey->fd = STDERR_FILENO;\n \t\t} else {\n@@ -70,11 +70,11 @@ static int get_trace_fd(struct trace_key *key)\n \t\t\tkey->need_close = 1;\n \t\t}\n \t} else {\n-\t\twarning(\"What does '%s' for %s mean?\\n\"\n-\t\t\t\"If you want to trace into a file, then please set \"\n-\t\t\t\"%s to an absolute pathname (starting with /).\\n\"\n-\t\t\t\"Defaulting to tracing on stderr...\",\n-\t\t\ttrace, key->key, key->key);\n+\t\twarning(\"unknown trace value for '%s': %s\\n\"\n+\t\t\t\" If you want to trace into a file, then please set %s\\n\"\n+\t\t\t\" to an absolute pathname (starting with /)\\n\"\n+\t\t\t\" Defaulting to tracing on stderr...\",\n+\t\t\tkey->key, trace, key->key);\n \t\tkey->fd = STDERR_FILENO;\n \t}\n \n@@ -93,7 +93,7 @@ void trace_disable(struct trace_key *key)\n \tkey->need_close = 0;\n }\n \n-static const char err_msg[] = \"Could not trace into fd given by \"\n+static const char err_msg[] = \"could not trace into fd given by \"\n \t\"GIT_TRACE environment variable\";\n \n static int prepare_trace_line(const char *file, int line,\n-- \n2.9.2.670.g42e63de\n\n"},{"id":"293043","messageId":"20160803230032.hgbq4kdd6jiwcxb7@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160803225600.fgm23bdacunmrw44@sigill.intra.peff.net","subject":"[PATCH 5/7] trace: correct variable name in write() error message","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-03T23:00:32Z","receivedAt":"2016-08-03T23:08:11Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"Our error message for write() always mentions GIT_TRACE,\neven though we may be writing for a different variable\nentirely. It's also not quite accurate to say \"fd given by\nGIT_TRACE environment variable\", as we may hit this error\nbased on a filename the user put in the variable (we do\ncomplain and switch to stderr if the file cannot be opened,\nbut it's still possible to hit a write() error on the\ndescriptor later).\n\nSo let's fix those things, and switch to our more usual\n\"unable to do X: Y\" format for the error.\n\nSigned-off-by: Jeff King \n---\n trace.c | 10 +++++-----\n 1 file changed, 5 insertions(+), 5 deletions(-)\n\ndiff --git a/trace.c b/trace.c\nindex 4d68eb5..4efb256 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -93,9 +93,6 @@ void trace_disable(struct trace_key *key)\n \tkey->need_close = 0;\n }\n \n-static const char err_msg[] = \"could not trace into fd given by \"\n-\t\"GIT_TRACE environment variable\";\n-\n static int prepare_trace_line(const char *file, int line,\n \t\t\t struct trace_key *key, struct strbuf *buf)\n {\n@@ -133,8 +130,11 @@ static int prepare_trace_line(const char *file, int line,\n \n static void trace_write(struct trace_key *key, const void *buf, unsigned len)\n {\n-\tif (write_in_full(get_trace_fd(key), buf, len) < 0)\n-\t\twarning(\"%s: write error (%s)\", err_msg, strerror(errno));\n+\tif (write_in_full(get_trace_fd(key), buf, len) < 0) {\n+\t\tnormalize_trace_key(&key);\n+\t\twarning(\"unable to write trace for %s: %s\",\n+\t\t\tkey->key, strerror(errno));\n+\t}\n }\n \n void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)\n-- \n2.9.2.670.g42e63de\n\n"},{"id":"293136","messageId":"xmqqk2fw1d41.fsf@gitster.mtv.corp.google.com","threadId":"43000","inReplyTo":"20160803225826.hlr273h4cy2hcfyk@sigill.intra.peff.net","subject":"Re: [PATCH 3/7] trace: use warning() for printing trace errors","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2016-08-04T20:41:02Z","receivedAt":"2016-08-04T20:41:11Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> Right now we just fprintf() straight to stderr, which can\n> make the output hard to distinguish. It would be helpful to\n> give it one of our usual prefixes like \"error:\", \"warning:\",\n> etc.\n>\n> It doesn't make sense to use error() here, as the trace code\n> is \"optional\" debugging code. If something goes wrong, we\n> should warn the user, but saying \"error\" implies the actual\n> git operation had a problem. So warning() is the only sane\n> choice.\n>\n> Note that this does end up calling warn_routine() to do the\n> formatting. So in theory, somebody who tries to trace from\n> their warn_routine() could cause a loop. But nobody does\n> this, and in fact nobody in the history of git has ever\n> replaced the default warn_builtin (there isn't even a\n> set_warn_routine function!).\n\nI think the last bit is about to change; cf. 545f13c0 (usage: add\nset_warn_routine(), 2016-07-30) on cc/apply-am topic.\n"},{"id":"293137","messageId":"xmqqfuqk1d23.fsf@gitster.mtv.corp.google.com","threadId":"43000","inReplyTo":"20160803230022.drw4kcwgheeqn3xr@sigill.intra.peff.net","subject":"Re: [PATCH 4/7] trace: cosmetic fixes for error messages","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2016-08-04T20:42:12Z","receivedAt":"2016-08-04T20:42:26Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> I think it would be nicer to still to print:\n>\n> warning: first line\n> warning: second line\n>\n> etc. We do that for \"advice:\", but not the rest of the vreportf\n> functions. It might be nice to do that, but we'd have to go back to\n> printing into a buffer (since we can't break up the incoming format\n> string that we feed to fprintf).\n\nYes, yes.\n"},{"id":"293138","messageId":"xmqq8twc1cx4.fsf@gitster.mtv.corp.google.com","threadId":"43000","inReplyTo":"20160803230103.daexq233ufrttnmn@sigill.intra.peff.net","subject":"Re: [PATCH 6/7] trace: disable key after write error","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2016-08-04T20:45:11Z","receivedAt":"2016-08-04T20:50:32Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> If we get a write error writing to a trace descriptor, the\n> error isn't likely to go away if we keep writing. Instead,\n> you'll just get the same error over and over. E.g., try:\n>\n> GIT_TRACE_PACKET=42 git ls-remote >/dev/null\n>\n> You don't really need to see:\n>\n> warning: unable to write trace for GIT_TRACE_PACKET: Bad file descriptor\n>\n> hundreds of times. We could fallback to tracing to stderr,\n> as we do in the error code-path for open(), but there's not\n> much point. If the user fed us a bogus descriptor, they're\n> probably better off fixing their invocation. And if they\n> didn't, and we saw a transient error (e.g., ENOSPC writing\n> to a file), it probably doesn't help anybody to have half of\n> the trace in a file, and half on stderr.\n\nYes, I think I like this better than \"we cannot open the named file,\nso let's trace into standard error stream\" that is done in the code\nin the context of [3/7]. We should do the same over there.\n"},{"id":"293141","messageId":"20160804212157.cn7ecyxcbyf4okd7@sigill.intra.peff.net","threadId":"43000","inReplyTo":"xmqqk2fw1d41.fsf@gitster.mtv.corp.google.com","subject":"Re: [PATCH 3/7] trace: use warning() for printing trace errors","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-04T21:21:57Z","receivedAt":"2016-08-04T21:22:26Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Aug 04, 2016 at 01:41:02PM -0700, Junio C Hamano wrote:\n\n> Jeff King writes:\n> \n> > Right now we just fprintf() straight to stderr, which can\n> > make the output hard to distinguish. It would be helpful to\n> > give it one of our usual prefixes like \"error:\", \"warning:\",\n> > etc.\n> >\n> > It doesn't make sense to use error() here, as the trace code\n> > is \"optional\" debugging code. If something goes wrong, we\n> > should warn the user, but saying \"error\" implies the actual\n> > git operation had a problem. So warning() is the only sane\n> > choice.\n> >\n> > Note that this does end up calling warn_routine() to do the\n> > formatting. So in theory, somebody who tries to trace from\n> > their warn_routine() could cause a loop. But nobody does\n> > this, and in fact nobody in the history of git has ever\n> > replaced the default warn_builtin (there isn't even a\n> > set_warn_routine function!).\n> \n> I think the last bit is about to change; cf. 545f13c0 (usage: add\n> set_warn_routine(), 2016-07-30) on cc/apply-am topic.\n\nThanks, I meant to check this series against \"pu\" to make sure there are\nno new callers for write_or_whine_pipe(), but forgot to.\n\nIt looks like that same topic does add one new caller, and switches the\n\"fprintf\" inside it to use warning().\n\nIMHO the call added by 19a73ac (builtin/apply: make try_create_file()\nreturn -1 on error, 2016-07-30) should just be a regular:\n\n if (write_in_full(...) < 0)\n error(...);\n\nWe don't care about the weird pipe handling there (we know we're writing\nto a file we just created), and the way the error message is passed in\njust makes things weird. Plus it seems more like an error() than a\nwarning (e.g., we call error() immediately below when close() fails!).\nBut 8fab3c6 (write_or_die: use warning() instead of fprintf(stderr,\n...), 2016-07-30) makes it an unconditional warning (that commit, btw,\nhas a bug in that it retains the trailing newline of the message, even\nthough warning() will add one itself).\n\nSo I'd suggest that series drop the call write_or_whine_pipe() and drop\n8fab3c6 entirely.\n\nI wondered if that would then let us drop set_warn_routine(), but it\nlooks like there are other warning() calls it cares about. So that would\ninvalidate the last paragraph here, though I still think converting the\ntrace errors to warning() is a reasonable thing to do.\n\n-Peff\n"},{"id":"293142","messageId":"20160804212244.cilov7i2uelg7lnh@sigill.intra.peff.net","threadId":"43000","inReplyTo":"xmqq8twc1cx4.fsf@gitster.mtv.corp.google.com","subject":"Re: [PATCH 6/7] trace: disable key after write error","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-04T21:22:44Z","receivedAt":"2016-08-04T21:22:52Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Aug 04, 2016 at 01:45:11PM -0700, Junio C Hamano wrote:\n\n> Jeff King writes:\n> \n> > If we get a write error writing to a trace descriptor, the\n> > error isn't likely to go away if we keep writing. Instead,\n> > you'll just get the same error over and over. E.g., try:\n> >\n> > GIT_TRACE_PACKET=42 git ls-remote >/dev/null\n> >\n> > You don't really need to see:\n> >\n> > warning: unable to write trace for GIT_TRACE_PACKET: Bad file descriptor\n> >\n> > hundreds of times. We could fallback to tracing to stderr,\n> > as we do in the error code-path for open(), but there's not\n> > much point. If the user fed us a bogus descriptor, they're\n> > probably better off fixing their invocation. And if they\n> > didn't, and we saw a transient error (e.g., ENOSPC writing\n> > to a file), it probably doesn't help anybody to have half of\n> > the trace in a file, and half on stderr.\n> \n> Yes, I think I like this better than \"we cannot open the named file,\n> so let's trace into standard error stream\" that is done in the code\n> in the context of [3/7]. We should do the same over there.\n\nYeah, I was tempted to strip that out, too. I'll look into preparing a\npatch on top.\n\n-Peff\n"},{"id":"293143","messageId":"xmqqy44cz0k6.fsf@gitster.mtv.corp.google.com","threadId":"43000","inReplyTo":"20160804212157.cn7ecyxcbyf4okd7@sigill.intra.peff.net","subject":"Re: [PATCH 3/7] trace: use warning() for printing trace errors","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2016-08-04T21:28:09Z","receivedAt":"2016-08-04T21:28:17Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> I wondered if that would then let us drop set_warn_routine(), but it\n> looks like there are other warning() calls it cares about. So that would\n> invalidate the last paragraph here, though I still think converting the\n> trace errors to warning() is a reasonable thing to do.\n\nYes. That is why tonight's pushout will have this series in 'jch'\n(that is a point on a linear history between 'master' and 'pu') and\ntentatively ejects cc/apply-am topic out of 'pu', expecting it to be\nrerolled.\n\nThanks.\n\n"},{"id":"293165","messageId":"20160805075838.zkwoyorvdc4ljn6l@sigill.intra.peff.net","threadId":"43000","inReplyTo":"20160804212244.cilov7i2uelg7lnh@sigill.intra.peff.net","subject":"Re: [PATCH 6/7] trace: disable key after write error","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-05T07:58:38Z","receivedAt":"2016-08-05T07:59:22Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Aug 04, 2016 at 05:22:44PM -0400, Jeff King wrote:\n\n> On Thu, Aug 04, 2016 at 01:45:11PM -0700, Junio C Hamano wrote:\n> \n> > Jeff King writes:\n> > \n> > > If we get a write error writing to a trace descriptor, the\n> > > error isn't likely to go away if we keep writing. Instead,\n> > > you'll just get the same error over and over. E.g., try:\n> > >\n> > > GIT_TRACE_PACKET=42 git ls-remote >/dev/null\n> > >\n> > > You don't really need to see:\n> > >\n> > > warning: unable to write trace for GIT_TRACE_PACKET: Bad file descriptor\n> > >\n> > > hundreds of times. We could fallback to tracing to stderr,\n> > > as we do in the error code-path for open(), but there's not\n> > > much point. If the user fed us a bogus descriptor, they're\n> > > probably better off fixing their invocation. And if they\n> > > didn't, and we saw a transient error (e.g., ENOSPC writing\n> > > to a file), it probably doesn't help anybody to have half of\n> > > the trace in a file, and half on stderr.\n> > \n> > Yes, I think I like this better than \"we cannot open the named file,\n> > so let's trace into standard error stream\" that is done in the code\n> > in the context of [3/7]. We should do the same over there.\n> \n> Yeah, I was tempted to strip that out, too. I'll look into preparing a\n> patch on top.\n\nHere's a patch that can go on the tip of jk/trace-fixup.\n\n-- >8 --\nSubject: [PATCH] trace: do not fall back to stderr\n\nIf the trace code cannot open a specified file, or does not\nunderstand the contents of the GIT_TRACE variable, it falls\nback to printing trace output to stderr.\n\nThis is an attempt to be helpful, but in practice it just\nends up annoying. The user was trying to get the output to\ngo somewhere else, so spewing it to stderr does not really\naccomplish that. And as it's intended for debugging, they\ncan presumably re-run the command with their error\ncorrected.\n\nSo instead of falling back, this patch disables bogus trace\nkeys for the rest of the program, just as we do for write\nerrors. We can drop the \"Defaulting to...\" part of the error\nmessage entirely; after seeing \"cannot open '/foo'\", the\nuser can assume that tracing is skipped.\n\nSigned-off-by: Jeff King \n---\n trace.c | 10 ++++------\n 1 file changed, 4 insertions(+), 6 deletions(-)\n\ndiff --git a/trace.c b/trace.c\nindex 083eb98..7508aea 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -61,10 +61,9 @@ static int get_trace_fd(struct trace_key *key)\n \telse if (is_absolute_path(trace)) {\n \t\tint fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666);\n \t\tif (fd == -1) {\n-\t\t\twarning(\"could not open '%s' for tracing: %s\\n\"\n-\t\t\t\t\" Defaulting to tracing on stderr...\",\n+\t\t\twarning(\"could not open '%s' for tracing: %s\",\n \t\t\t\ttrace, strerror(errno));\n-\t\t\tkey->fd = STDERR_FILENO;\n+\t\t\ttrace_disable(key);\n \t\t} else {\n \t\t\tkey->fd = fd;\n \t\t\tkey->need_close = 1;\n@@ -72,10 +71,9 @@ static int get_trace_fd(struct trace_key *key)\n \t} else {\n \t\twarning(\"unknown trace value for '%s': %s\\n\"\n \t\t\t\" If you want to trace into a file, then please set %s\\n\"\n-\t\t\t\" to an absolute pathname (starting with /)\\n\"\n-\t\t\t\" Defaulting to tracing on stderr...\",\n+\t\t\t\" to an absolute pathname (starting with /)\",\n \t\t\tkey->key, trace, key->key);\n-\t\tkey->fd = STDERR_FILENO;\n+\t\ttrace_disable(key);\n \t}\n \n \tkey->initialized = 1;\n-- \n2.9.2.707.g48ee8b7\n\n"},{"id":"293166","messageId":"20160805075600.dzt4hfvcdgruo2ef@sigill.intra.peff.net","threadId":"43000","inReplyTo":"xmqqy44cz0k6.fsf@gitster.mtv.corp.google.com","subject":"Re: [PATCH 3/7] trace: use warning() for printing trace errors","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-05T07:56:00Z","receivedAt":"2016-08-05T07:59:35Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Aug 04, 2016 at 02:28:09PM -0700, Junio C Hamano wrote:\n\n> Jeff King writes:\n> \n> > I wondered if that would then let us drop set_warn_routine(), but it\n> > looks like there are other warning() calls it cares about. So that would\n> > invalidate the last paragraph here, though I still think converting the\n> > trace errors to warning() is a reasonable thing to do.\n> \n> Yes. That is why tonight's pushout will have this series in 'jch'\n> (that is a point on a linear history between 'master' and 'pu') and\n> tentatively ejects cc/apply-am topic out of 'pu', expecting it to be\n> rerolled.\n\nHere's a replacement patch 3. Same code, but it clarifies the\nwarn_routine situation in the commit message.\n\n-- >8 --\nSubject: [PATCH] trace: use warning() for printing trace errors\n\nRight now we just fprintf() straight to stderr, which can\nmake the output hard to distinguish. It would be helpful to\ngive it one of our usual prefixes like \"error:\", \"warning:\",\netc.\n\nIt doesn't make sense to use error() here, as the trace code\nis \"optional\" debugging code. If something goes wrong, we\nshould warn the user, but saying \"error\" implies the actual\ngit operation had a problem. So warning() is the only sane\nchoice.\n\nNote that this does end up calling warn_routine() to do the\nformatting. This is probably a good thing, since they are\nclearly trying to hook messages before they make it to\nstderr. However, it also means that in theory somebody who\ntries to trace from their warn_routine() could cause a loop.\nThis seems rather unlikely in practice (we've never even\noverridden the default warn_builtin routine before, and\nrecent discussions to do so would just install a noop\nroutine).\n\nSigned-off-by: Jeff King \n---\n trace.c | 11 +++++------\n 1 file changed, 5 insertions(+), 6 deletions(-)\n\ndiff --git a/trace.c b/trace.c\nindex bdbe149..6a77e4d 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -61,9 +61,8 @@ static int get_trace_fd(struct trace_key *key)\n \telse if (is_absolute_path(trace)) {\n \t\tint fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666);\n \t\tif (fd == -1) {\n-\t\t\tfprintf(stderr,\n-\t\t\t\t\"Could not open '%s' for tracing: %s\\n\"\n-\t\t\t\t\"Defaulting to tracing on stderr...\\n\",\n+\t\t\twarning(\"Could not open '%s' for tracing: %s\\n\"\n+\t\t\t\t\"Defaulting to tracing on stderr...\",\n \t\t\t\ttrace, strerror(errno));\n \t\t\tkey->fd = STDERR_FILENO;\n \t\t} else {\n@@ -71,10 +70,10 @@ static int get_trace_fd(struct trace_key *key)\n \t\t\tkey->need_close = 1;\n \t\t}\n \t} else {\n-\t\tfprintf(stderr, \"What does '%s' for %s mean?\\n\"\n+\t\twarning(\"What does '%s' for %s mean?\\n\"\n \t\t\t\"If you want to trace into a file, then please set \"\n \t\t\t\"%s to an absolute pathname (starting with /).\\n\"\n-\t\t\t\"Defaulting to tracing on stderr...\\n\",\n+\t\t\t\"Defaulting to tracing on stderr...\",\n \t\t\ttrace, key->key, key->key);\n \t\tkey->fd = STDERR_FILENO;\n \t}\n@@ -135,7 +134,7 @@ static int prepare_trace_line(const char *file, int line,\n static void trace_write(struct trace_key *key, const void *buf, unsigned len)\n {\n \tif (write_in_full(get_trace_fd(key), buf, len) < 0)\n-\t\tfprintf(stderr, \"%s: write error (%s)\\n\", err_msg, strerror(errno));\n+\t\twarning(\"%s: write error (%s)\", err_msg, strerror(errno));\n }\n \n void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)\n-- \n2.9.2.707.g48ee8b7\n\n"},{"id":"293167","messageId":"20160805080016.tne7lvvvaw3viot2@sigill.intra.peff.net","threadId":"43000","inReplyTo":"xmqqfuqk1d23.fsf@gitster.mtv.corp.google.com","subject":"Re: [PATCH 4/7] trace: cosmetic fixes for error messages","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-08-05T08:00:17Z","receivedAt":"2016-08-05T08:01:17Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Aug 04, 2016 at 01:42:12PM -0700, Junio C Hamano wrote:\n\n> Jeff King writes:\n> \n> > I think it would be nicer to still to print:\n> >\n> > warning: first line\n> > warning: second line\n> >\n> > etc. We do that for \"advice:\", but not the rest of the vreportf\n> > functions. It might be nice to do that, but we'd have to go back to\n> > printing into a buffer (since we can't break up the incoming format\n> > string that we feed to fprintf).\n> \n> Yes, yes.\n\nActually, I guess in this case we could easily do:\n\n warning(\"something\");\n warning(\"something else\");\n\netc (the lines are fairly stand-alone, so I don't think it runs afoul of\nthe usual translator-lego problem; not to mention that these aren't\nactually translated). I don't really care that much between that and the\nindented output, but if there's a preference, I'm happy to re-roll with\nthat.\n\n-Peff\n"},{"id":"293168","messageId":"CAP8UFD3hvrrwmnyF0PLreAos62hN_1W4bwYV9toMQ-vQQ6rgog@mail.gmail.com","threadId":"43000","inReplyTo":"xmqqy44cz0k6.fsf@gitster.mtv.corp.google.com","subject":"Re: [PATCH 3/7] trace: use warning() for printing trace errors","fromName":"Christian Couder","fromEmail":"christian.couder@gmail.com","sentAt":"2016-08-05T07:59:22Z","receivedAt":"2016-08-05T08:01:21Z","isPatch":true,"sender":{"key":"christian.couder@gmail.com","avatar":"https://avatars.githubusercontent.com/u/208954?v=4"},"body":"On Thu, Aug 4, 2016 at 11:28 PM, Junio C Hamano wrote:\n> Jeff King writes:\n>\n>> I wondered if that would then let us drop set_warn_routine(), but it\n>> looks like there are other warning() calls it cares about. So that would\n>> invalidate the last paragraph here, though I still think converting the\n>> trace errors to warning() is a reasonable thing to do.\n>\n> Yes. That is why tonight's pushout will have this series in 'jch'\n> (that is a point on a linear history between 'master' and 'pu') and\n> tentatively ejects cc/apply-am topic out of 'pu', expecting it to be\n> rerolled.\n\nOk, I will reroll soon with Peff's suggested changes.\n"},{"id":"293218","messageId":"xmqqwpjvvz0x.fsf@gitster.mtv.corp.google.com","threadId":"43000","inReplyTo":"CAP8UFD3hvrrwmnyF0PLreAos62hN_1W4bwYV9toMQ-vQQ6rgog@mail.gmail.com","subject":"Re: [PATCH 3/7] trace: use warning() for printing trace errors","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2016-08-05T18:41:50Z","receivedAt":"2016-08-05T18:42:04Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Christian Couder writes:\n\n> On Thu, Aug 4, 2016 at 11:28 PM, Junio C Hamano wrote:\n>> Jeff King writes:\n>>\n>>> I wondered if that would then let us drop set_warn_routine(), but it\n>>> looks like there are other warning() calls it cares about. So that would\n>>> invalidate the last paragraph here, though I still think converting the\n>>> trace errors to warning() is a reasonable thing to do.\n>>\n>> Yes. That is why tonight's pushout will have this series in 'jch'\n>> (that is a point on a linear history between 'master' and 'pu') and\n>> tentatively ejects cc/apply-am topic out of 'pu', expecting it to be\n>> rerolled.\n>\n> Ok, I will reroll soon with Peff's suggested changes.\n\nThanks.\n"}]}