From c81539b5f6f608ec48358ca6a35f7323e96432e1 Mon Sep 17 00:00:00 2001 From: Jeff King Date: Wed, 3 Aug 2016 18:56:57 -0400 Subject: [PATCH 1/8] trace: handle NULL argument in trace_disable() All of the trace functions treat a NULL key as a synonym for the default GIT_TRACE key. Except for trace_disable(), which will segfault. Fortunately, this can't cause any bugs, as the function has no callers. But rather than drop it, let's fix the bug, as I plan to add a caller. Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- trace.c | 20 ++++++++++++++++---- 1 file changed, 16 insertions(+), 4 deletions(-) diff --git a/trace.c b/trace.c index 4aeea60973..f204a7d88a 100644 --- a/trace.c +++ b/trace.c @@ -25,15 +25,25 @@ #include "cache.h" #include "quote.h" +/* + * "Normalize" a key argument by converting NULL to our trace_default, + * and otherwise passing through the value. All caller-facing functions + * should normalize their inputs in this way, though most get it + * for free by calling get_trace_fd() (directly or indirectly). + */ +static void normalize_trace_key(struct trace_key **key) +{ + static struct trace_key trace_default = { "GIT_TRACE" }; + if (!*key) + *key = &trace_default; +} + /* Get a trace file descriptor from "key" env variable. */ static int get_trace_fd(struct trace_key *key) { - static struct trace_key trace_default = { "GIT_TRACE" }; const char *trace; - /* use default "GIT_TRACE" if NULL */ - if (!key) - key = &trace_default; + normalize_trace_key(&key); /* don't open twice */ if (key->initialized) @@ -75,6 +85,8 @@ static int get_trace_fd(struct trace_key *key) void trace_disable(struct trace_key *key) { + normalize_trace_key(&key); + if (key->need_close) close(key->fd); key->fd = 0; From c0222e762ef57c59fa793862618cfcdfef1cf3f8 Mon Sep 17 00:00:00 2001 From: Jeff King Date: Wed, 3 Aug 2016 18:58:00 -0400 Subject: [PATCH 2/8] trace: stop using write_or_whine_pipe() The write_or_whine_pipe function does two things: 1. it checks for EPIPE and converts it into a signal death 2. it prints a message to stderr on error The first thing does not help us, and actively hurts. Generally we would simply die from SIGPIPE in this case, unless somebody has taken the time to ignore SIGPIPE for the whole process. And if they _did_ do that, it seems rather silly for the trace code, which otherwise takes pains to continue even in the face of errors (e.g., by not using write_or_die!), to take down the whole process for one specific type of error. Nor does the second thing help us; it just makes it harder to write our error message, because we have to feed bits of it as an argument to write_or_whine_pipe(). Translators never get to see the full message, and it's hard for us to customize it. Let's switch to just using write_in_full() and writing our own error string. For now, the error is identical to what write_or_whine_pipe() would say, but now that it's more under our control, we can improve it in future patches. Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- trace.c | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/trace.c b/trace.c index f204a7d88a..bdbe149396 100644 --- a/trace.c +++ b/trace.c @@ -132,18 +132,23 @@ static int prepare_trace_line(const char *file, int line, return 1; } +static void trace_write(struct trace_key *key, const void *buf, unsigned len) +{ + if (write_in_full(get_trace_fd(key), buf, len) < 0) + fprintf(stderr, "%s: write error (%s)\n", err_msg, strerror(errno)); +} + void trace_verbatim(struct trace_key *key, const void *buf, unsigned len) { if (!trace_want(key)) return; - write_or_whine_pipe(get_trace_fd(key), buf, len, err_msg); + trace_write(key, buf, len); } static void print_trace_line(struct trace_key *key, struct strbuf *buf) { strbuf_complete_line(buf); - - write_or_whine_pipe(get_trace_fd(key), buf->buf, buf->len, err_msg); + trace_write(key, buf->buf, buf->len); strbuf_release(buf); } From 38f460caa26e5dd06c3e874e30ea0ec5beb49b56 Mon Sep 17 00:00:00 2001 From: Jeff King Date: Fri, 5 Aug 2016 03:56:00 -0400 Subject: [PATCH 3/8] trace: use warning() for printing trace errors Right now we just fprintf() straight to stderr, which can make the output hard to distinguish. It would be helpful to give it one of our usual prefixes like "error:", "warning:", etc. It doesn't make sense to use error() here, as the trace code is "optional" debugging code. If something goes wrong, we should warn the user, but saying "error" implies the actual git operation had a problem. So warning() is the only sane choice. Note that this does end up calling warn_routine() to do the formatting. This is probably a good thing, since they are clearly trying to hook messages before they make it to stderr. However, it also means that in theory somebody who tries to trace from their warn_routine() could cause a loop. This seems rather unlikely in practice (we've never even overridden the default warn_builtin routine before, and recent discussions to do so would just install a noop routine). Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- trace.c | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/trace.c b/trace.c index bdbe149396..6a77e4df03 100644 --- a/trace.c +++ b/trace.c @@ -61,9 +61,8 @@ static int get_trace_fd(struct trace_key *key) else if (is_absolute_path(trace)) { int fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666); if (fd == -1) { - fprintf(stderr, - "Could not open '%s' for tracing: %s\n" - "Defaulting to tracing on stderr...\n", + warning("Could not open '%s' for tracing: %s\n" + "Defaulting to tracing on stderr...", trace, strerror(errno)); key->fd = STDERR_FILENO; } else { @@ -71,10 +70,10 @@ static int get_trace_fd(struct trace_key *key) key->need_close = 1; } } else { - fprintf(stderr, "What does '%s' for %s mean?\n" + warning("What does '%s' for %s mean?\n" "If you want to trace into a file, then please set " "%s to an absolute pathname (starting with /).\n" - "Defaulting to tracing on stderr...\n", + "Defaulting to tracing on stderr...", trace, key->key, key->key); key->fd = STDERR_FILENO; } @@ -135,7 +134,7 @@ static int prepare_trace_line(const char *file, int line, static void trace_write(struct trace_key *key, const void *buf, unsigned len) { if (write_in_full(get_trace_fd(key), buf, len) < 0) - fprintf(stderr, "%s: write error (%s)\n", err_msg, strerror(errno)); + warning("%s: write error (%s)", err_msg, strerror(errno)); } void trace_verbatim(struct trace_key *key, const void *buf, unsigned len) From b3a1c5da0242c936bfc007722aa0011494629b32 Mon Sep 17 00:00:00 2001 From: Jeff King Date: Wed, 3 Aug 2016 19:00:23 -0400 Subject: [PATCH 4/8] trace: cosmetic fixes for error messages The error messages for the trace code are often multi-line; the first line gets a nice "warning:", but the rest are left-aligned. Let's give them an indentation to make sure they stand out as a unit. While we're here, let's also downcase the first letter of each error (our usual style), and break up a long line of advice (since we're already using multiple lines, one more doesn't hurt). We also replace "What does 'foo' for GIT_TRACE mean?". While cute, it's probably a good idea to give more context, and follow our usual styles. So it's now "unknown trace value for 'GIT_TRACE': foo". Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- trace.c | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/trace.c b/trace.c index 6a77e4df03..4d68eb522f 100644 --- a/trace.c +++ b/trace.c @@ -61,8 +61,8 @@ static int get_trace_fd(struct trace_key *key) else if (is_absolute_path(trace)) { int fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666); if (fd == -1) { - warning("Could not open '%s' for tracing: %s\n" - "Defaulting to tracing on stderr...", + warning("could not open '%s' for tracing: %s\n" + " Defaulting to tracing on stderr...", trace, strerror(errno)); key->fd = STDERR_FILENO; } else { @@ -70,11 +70,11 @@ static int get_trace_fd(struct trace_key *key) key->need_close = 1; } } else { - warning("What does '%s' for %s mean?\n" - "If you want to trace into a file, then please set " - "%s to an absolute pathname (starting with /).\n" - "Defaulting to tracing on stderr...", - trace, key->key, key->key); + warning("unknown trace value for '%s': %s\n" + " If you want to trace into a file, then please set %s\n" + " to an absolute pathname (starting with /)\n" + " Defaulting to tracing on stderr...", + key->key, trace, key->key); key->fd = STDERR_FILENO; } @@ -93,7 +93,7 @@ void trace_disable(struct trace_key *key) key->need_close = 0; } -static const char err_msg[] = "Could not trace into fd given by " +static const char err_msg[] = "could not trace into fd given by " "GIT_TRACE environment variable"; static int prepare_trace_line(const char *file, int line, From 3b0c3ab777d7d1fc2fbfaba9ec8ce4d845428d99 Mon Sep 17 00:00:00 2001 From: Jeff King Date: Wed, 3 Aug 2016 19:00:32 -0400 Subject: [PATCH 5/8] trace: correct variable name in write() error message Our error message for write() always mentions GIT_TRACE, even though we may be writing for a different variable entirely. It's also not quite accurate to say "fd given by GIT_TRACE environment variable", as we may hit this error based on a filename the user put in the variable (we do complain and switch to stderr if the file cannot be opened, but it's still possible to hit a write() error on the descriptor later). So let's fix those things, and switch to our more usual "unable to do X: Y" format for the error. Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- trace.c | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/trace.c b/trace.c index 4d68eb522f..4efb256fa2 100644 --- a/trace.c +++ b/trace.c @@ -93,9 +93,6 @@ void trace_disable(struct trace_key *key) key->need_close = 0; } -static const char err_msg[] = "could not trace into fd given by " - "GIT_TRACE environment variable"; - static int prepare_trace_line(const char *file, int line, struct trace_key *key, struct strbuf *buf) { @@ -133,8 +130,11 @@ static int prepare_trace_line(const char *file, int line, static void trace_write(struct trace_key *key, const void *buf, unsigned len) { - if (write_in_full(get_trace_fd(key), buf, len) < 0) - warning("%s: write error (%s)", err_msg, strerror(errno)); + if (write_in_full(get_trace_fd(key), buf, len) < 0) { + normalize_trace_key(&key); + warning("unable to write trace for %s: %s", + key->key, strerror(errno)); + } } void trace_verbatim(struct trace_key *key, const void *buf, unsigned len) From 46ac74b71681f1d2ff29615236193e651dcdd9fe Mon Sep 17 00:00:00 2001 From: Jeff King Date: Wed, 3 Aug 2016 19:01:04 -0400 Subject: [PATCH 6/8] trace: disable key after write error If we get a write error writing to a trace descriptor, the error isn't likely to go away if we keep writing. Instead, you'll just get the same error over and over. E.g., try: GIT_TRACE_PACKET=42 git ls-remote >/dev/null You don't really need to see: warning: unable to write trace for GIT_TRACE_PACKET: Bad file descriptor hundreds of times. We could fallback to tracing to stderr, as we do in the error code-path for open(), but there's not much point. If the user fed us a bogus descriptor, they're probably better off fixing their invocation. And if they didn't, and we saw a transient error (e.g., ENOSPC writing to a file), it probably doesn't help anybody to have half of the trace in a file, and half on stderr. Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- trace.c | 1 + 1 file changed, 1 insertion(+) diff --git a/trace.c b/trace.c index 4efb256fa2..083eb984e1 100644 --- a/trace.c +++ b/trace.c @@ -134,6 +134,7 @@ static void trace_write(struct trace_key *key, const void *buf, unsigned len) normalize_trace_key(&key); warning("unable to write trace for %s: %s", key->key, strerror(errno)); + trace_disable(key); } } From ca5c701ca50c24807793294c5ed22230858ac5e6 Mon Sep 17 00:00:00 2001 From: Jeff King Date: Wed, 3 Aug 2016 19:01:42 -0400 Subject: [PATCH 7/8] write_or_die: drop write_or_whine_pipe() This function has no callers, and is not likely to gain any because it's confusing to use. It unconditionally complains to stderr, but _doesn't_ die. Yet any caller which wants a "gentle" write would generally want to suppress the error message, because presumably they're going to write a better one, and/or try the operation again. And the check_pipe() call leads to confusing behaviors. It means we die for EPIPE, but not for other errors, which is confusing and pointless. On top of all that, it has unusual error return semantics, which makes it easy for callers to get it wrong. Let's drop the function, and if somebody ever needs to resurrect something like it, they can fix these warts. Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- cache.h | 1 - write_or_die.c | 12 ------------ 2 files changed, 13 deletions(-) diff --git a/cache.h b/cache.h index b5f76a4cf4..388591157c 100644 --- a/cache.h +++ b/cache.h @@ -1740,7 +1740,6 @@ extern int copy_file(const char *dst, const char *src, int mode); extern int copy_file_with_time(const char *dst, const char *src, int mode); extern void write_or_die(int fd, const void *buf, size_t count); -extern int write_or_whine_pipe(int fd, const void *buf, size_t count, const char *msg); extern void fsync_or_die(int fd, const char *); extern ssize_t read_in_full(int fd, void *buf, size_t count); diff --git a/write_or_die.c b/write_or_die.c index 981687945a..073443247a 100644 --- a/write_or_die.c +++ b/write_or_die.c @@ -82,15 +82,3 @@ void write_or_die(int fd, const void *buf, size_t count) die_errno("write error"); } } - -int write_or_whine_pipe(int fd, const void *buf, size_t count, const char *msg) -{ - if (write_in_full(fd, buf, count) < 0) { - check_pipe(errno); - fprintf(stderr, "%s: write error (%s)\n", - msg, strerror(errno)); - return 0; - } - - return 1; -} From 6f25305799f0bbddbac1d678293e8c5cf404deb3 Mon Sep 17 00:00:00 2001 From: Jeff King Date: Fri, 5 Aug 2016 03:58:38 -0400 Subject: [PATCH 8/8] trace: do not fall back to stderr If the trace code cannot open a specified file, or does not understand the contents of the GIT_TRACE variable, it falls back to printing trace output to stderr. This is an attempt to be helpful, but in practice it just ends up annoying. The user was trying to get the output to go somewhere else, so spewing it to stderr does not really accomplish that. And as it's intended for debugging, they can presumably re-run the command with their error corrected. So instead of falling back, this patch disables bogus trace keys for the rest of the program, just as we do for write errors. We can drop the "Defaulting to..." part of the error message entirely; after seeing "cannot open '/foo'", the user can assume that tracing is skipped. Signed-off-by: Jeff King Signed-off-by: Junio C Hamano --- trace.c | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/trace.c b/trace.c index 083eb984e1..7508aea028 100644 --- a/trace.c +++ b/trace.c @@ -61,10 +61,9 @@ static int get_trace_fd(struct trace_key *key) else if (is_absolute_path(trace)) { int fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666); if (fd == -1) { - warning("could not open '%s' for tracing: %s\n" - " Defaulting to tracing on stderr...", + warning("could not open '%s' for tracing: %s", trace, strerror(errno)); - key->fd = STDERR_FILENO; + trace_disable(key); } else { key->fd = fd; key->need_close = 1; @@ -72,10 +71,9 @@ static int get_trace_fd(struct trace_key *key) } else { warning("unknown trace value for '%s': %s\n" " If you want to trace into a file, then please set %s\n" - " to an absolute pathname (starting with /)\n" - " Defaulting to tracing on stderr...", + " to an absolute pathname (starting with /)", key->key, trace, key->key); - key->fd = STDERR_FILENO; + trace_disable(key); } key->initialized = 1;