[PATCH v6 05/11] trace: add infrastructure to augment trace output with additional info

2014-06-20 Thread Karsten Blees
To be able to add a common prefix or suffix to all trace output (e.g.
a timestamp or file:line of the caller), factor out common setup and
cleanup tasks of the trace* functions.

Some unit-tests use trace output to verify internal state, and variable
output such as timestamps and line numbers are not useful there. Disable
additional trace output if GIT_TRACE_BARE is set.

When adding a common prefix, it makes sense that the output of each trace
call starts on a new line. Add '\n' in case the caller forgot.

Note that this explicitly limits trace output to line-by-line, it is no
longer possible to trace-print just part of a line. Until now, this was
just an implicit assumption (trace-printing part of a line worked, but
messed up the trace file if multiple threads or processes were involved).

Thread-safety / inter-process-safety is also the reason why we need to do
the prefixing and suffixing in memory rather than issuing multiple write()
calls. Write_or_whine_pipe() / xwrite() is atomic unless the size exceeds
MAX_IO_SIZE (8MB, see wrapper.c). In case of trace_strbuf, this costs an
additional string copy (which should be irrelevant for performance in light
of actual file IO).

While we're at it, rename trace_strbuf's 'buf' argument, which suggests
that the function is modifying the buffer. Trace_strbuf() currently is the
only trace API that can print arbitrary binary data (without barfing on
'%' or stopping at '\0'), so 'data' seems more appropriate.

Signed-off-by: Karsten Blees bl...@dcon.de
---
 t/t1510-repo-setup.sh |  2 +-
 t/t5503-tagfollow.sh  |  8 
 trace.c   | 53 ---
 trace.h   |  2 +-
 4 files changed, 48 insertions(+), 17 deletions(-)

diff --git a/t/t1510-repo-setup.sh b/t/t1510-repo-setup.sh
index e1b2a99..8db8d68 100755
--- a/t/t1510-repo-setup.sh
+++ b/t/t1510-repo-setup.sh
@@ -57,7 +57,7 @@ test_repo () {
export GIT_WORK_TREE
fi 
rm -f trace 
-   GIT_TRACE_SETUP=$(pwd)/trace git symbolic-ref HEAD /dev/null 

+   GIT_TRACE_BARE=1 GIT_TRACE_SETUP=$(pwd)/trace git 
symbolic-ref HEAD /dev/null 
grep '^setup: ' trace result 
test_cmp expected result
)
diff --git a/t/t5503-tagfollow.sh b/t/t5503-tagfollow.sh
index f30c038..dc10143 100755
--- a/t/t5503-tagfollow.sh
+++ b/t/t5503-tagfollow.sh
@@ -56,7 +56,7 @@ test_expect_success 'fetch A (new commit : 1 connection)' '
rm -f $U 
(
cd cloned 
-   GIT_TRACE_PACKET=$UPATH git fetch 
+   GIT_TRACE_BARE=1 GIT_TRACE_PACKET=$UPATH git fetch 
test $A = $(git rev-parse --verify origin/master)
) 
get_needs $U actual 
@@ -86,7 +86,7 @@ test_expect_success 'fetch C, T (new branch, tag : 1 
connection)' '
rm -f $U 
(
cd cloned 
-   GIT_TRACE_PACKET=$UPATH git fetch 
+   GIT_TRACE_BARE=1 GIT_TRACE_PACKET=$UPATH git fetch 
test $C = $(git rev-parse --verify origin/cat) 
test $T = $(git rev-parse --verify tag1) 
test $A = $(git rev-parse --verify tag1^0)
@@ -122,7 +122,7 @@ test_expect_success 'fetch B, S (commit and tag : 1 
connection)' '
rm -f $U 
(
cd cloned 
-   GIT_TRACE_PACKET=$UPATH git fetch 
+   GIT_TRACE_BARE=1 GIT_TRACE_PACKET=$UPATH git fetch 
test $B = $(git rev-parse --verify origin/master) 
test $B = $(git rev-parse --verify tag2^0) 
test $S = $(git rev-parse --verify tag2)
@@ -146,7 +146,7 @@ test_expect_success 'new clone fetch master and tags' '
cd clone2 
git init 
git remote add origin .. 
-   GIT_TRACE_PACKET=$UPATH git fetch 
+   GIT_TRACE_BARE=1 GIT_TRACE_PACKET=$UPATH git fetch 
test $B = $(git rev-parse --verify origin/master) 
test $S = $(git rev-parse --verify tag2) 
test $B = $(git rev-parse --verify tag2^0) 
diff --git a/trace.c b/trace.c
index b7ca51b..9fa406e 100644
--- a/trace.c
+++ b/trace.c
@@ -77,17 +77,45 @@ static void do_trace_print(const char *key, const struct 
strbuf *buf)
close(fd);
 }
 
+static int trace_bare = -1;
+
+static int prepare_trace_line(const char *key, struct strbuf *buf)
+{
+   if (!trace_want(key))
+   return 0;
+
+   set_try_to_free_routine(NULL);  /* is never reset */
+
+   /* unit tests may want to disable additional trace output */
+   if (trace_bare  0)
+   trace_bare = trace_want(GIT_TRACE_BARE);
+   if (trace_bare)
+   return 1;
+
+   /* add line prefix here */
+
+   return 1;
+}
+
+static void print_trace_line(const char *key, struct strbuf *buf)
+{
+   /* append newline if missing */
+   if (buf-len  

Re: [PATCH v6 05/11] trace: add infrastructure to augment trace output with additional info

2014-06-20 Thread Junio C Hamano
Karsten Blees karsten.bl...@gmail.com writes:

 To be able to add a common prefix or suffix to all trace output (e.g.
 a timestamp or file:line of the caller), factor out common setup and
 cleanup tasks of the trace* functions.

 Some unit-tests use trace output to verify internal state, and variable
 output such as timestamps and line numbers are not useful there. Disable
 additional trace output if GIT_TRACE_BARE is set.

Hmph, this makes me wonder if we are better off making these
additional trace output optional, i.e. not disabling with
GIT_TRACE_BARE like this, but show the new output only when
explicitly asked for by setting GIT_TRACE_PERF or something.

--
To unsubscribe from this list: send the line unsubscribe git in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [PATCH v6 05/11] trace: add infrastructure to augment trace output with additional info

2014-06-20 Thread Karsten Blees
Am 21.06.2014 00:33, schrieb Junio C Hamano:
 Karsten Blees karsten.bl...@gmail.com writes:
 
 To be able to add a common prefix or suffix to all trace output (e.g.
 a timestamp or file:line of the caller), factor out common setup and
 cleanup tasks of the trace* functions.

 Some unit-tests use trace output to verify internal state, and variable
 output such as timestamps and line numbers are not useful there. Disable
 additional trace output if GIT_TRACE_BARE is set.
 
 Hmph, this makes me wonder if we are better off making these
 additional trace output optional, i.e. not disabling with
 GIT_TRACE_BARE like this, but show the new output only when
 explicitly asked for by setting GIT_TRACE_PERF or something.
 

GIT_TRACE_VERBOSE perhaps? It affects all trace output, not just
GIT_TRACE_PERFORMANCE. The tests would still have to disable it
explicitly, though, in case someone sets it in their profile.

However, IIRC conclusion of v4 discussion was that this would be
useful for all trace output [1], so I think it should be the default.

[1] https://groups.google.com/forum/#!topic/msysgit/UMKTvmZX5aI

--
To unsubscribe from this list: send the line unsubscribe git in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [PATCH v6 05/11] trace: add infrastructure to augment trace output with additional info

2014-06-20 Thread Junio C Hamano
On Fri, Jun 20, 2014 at 4:32 PM, Karsten Blees karsten.bl...@gmail.com wrote:
 Am 21.06.2014 00:33, schrieb Junio C Hamano:
 Karsten Blees karsten.bl...@gmail.com writes:

 GIT_TRACE_VERBOSE perhaps? It affects all trace output, not just
 GIT_TRACE_PERFORMANCE. The tests would still have to disable it
 explicitly, though, in case someone sets it in their profile.

 However, IIRC conclusion of v4 discussion was that this would be
 useful for all trace output [1], so I think it should be the default.

 [1] https://groups.google.com/forum/#!topic/msysgit/UMKTvmZX5aI

Hmph, after re-reading of that thread, I recall that I thought Peff's

 Would it make
 sense to just tie this to regular trace_* calls, and if
 GIT_TRACE_PERFORMANCE is set, add a timestamp to each line?

was the conclusion (i.e. by default no change, ask with GIT_TRACE_PERFORMANCE),
and that I found that reasonable back then.

As to the need to disable in the tests, yes, you are right. Just like
we give predictiable
environment to tests by setting EDITOR, HOME, etc. in test-lib.sh, we
should do the
same for these new settings there.

Thanks.
--
To unsubscribe from this list: send the line unsubscribe git in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html