{"thread":{"id":"50737","subject":"[PATCH 0/2] Randomize / timestamp trace2 targets","startedAt":"2019-03-13T23:33:35Z","lastAt":"2019-03-25T16:29:36Z","messageCount":34,"participants":["Josh Steadmon","Ævar Arnfjörð Bjarmason","Jeff King","Junio C Hamano","Johannes Schindelin","Jeff Hostetler"],"isPatch":true,"patchVersion":1,"patchTotal":2},"messages":[{"id":"371417","messageId":"cover.1552519463.git.steadmon@google.com","threadId":"50737","inReplyTo":null,"subject":"[PATCH 0/2] Randomize / timestamp trace2 targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-13T23:33:27Z","receivedAt":"2019-03-13T23:33:35Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"Persistently enabling trace2 output is difficult because it requires\nspecifying a full filename. This series teaches tr2_dst_get_trace_fd()\nto randomize filenames when a directory or filename prefix are given as\ntargets in the GIT_TR2_* envvars. It also allows expansion of a\ntimestamp template string into the current UTC timestamp.\n\nJosh Steadmon (2):\n  date: make get_time() public\n  trace2: randomize/timestamp trace2 targets\n\n Documentation/technical/api-trace2.txt | 10 +++\n cache.h                                |  1 +\n date.c                                 |  2 +-\n t/t0210-trace2-normal.sh               | 93 ++++++++++++++++++++++++++\n trace2/tr2_dst.c                       | 86 +++++++++++++++++++++++-\n 5 files changed, 189 insertions(+), 3 deletions(-)\n\n-- \n2.21.0.360.g471c308f928-goog\n\n"},{"id":"371418","messageId":"e6b01ad4bfe48cbf09c120756d0e7cac198ea6f0.1552519463.git.steadmon@google.com","threadId":"50737","inReplyTo":"cover.1552519463.git.steadmon@google.com","subject":"[PATCH 1/2] date: make get_time() public","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-13T23:33:28Z","receivedAt":"2019-03-13T23:33:37Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"get_time() is the standard way to get the current time while also\nrespecting frozen timestamps for tests. Expose this for use in other\nfiles.\n\nSigned-off-by: Josh Steadmon <steadmon@google.com>\n---\n cache.h | 1 +\n date.c  | 2 +-\n 2 files changed, 2 insertions(+), 1 deletion(-)\n\ndiff --git a/cache.h b/cache.h\nindex abd518a9a2..0a2c436d0a 100644\n--- a/cache.h\n+++ b/cache.h\n@@ -1489,6 +1489,7 @@ struct date_mode {\n #define DATE_MODE(t) date_mode_from_type(DATE_##t)\n struct date_mode *date_mode_from_type(enum date_mode_type type);\n \n+void get_time(struct timeval *now);\n const char *show_date(timestamp_t time, int timezone, const struct date_mode *mode);\n void show_date_relative(timestamp_t time, const struct timeval *now,\n \t\t\tstruct strbuf *timebuf);\ndiff --git a/date.c b/date.c\nindex 8126146c50..33576d2deb 100644\n--- a/date.c\n+++ b/date.c\n@@ -115,7 +115,7 @@ static int local_tzoffset(timestamp_t time)\n \treturn local_time_tzoffset((time_t)time, &tm);\n }\n \n-static void get_time(struct timeval *now)\n+void get_time(struct timeval *now)\n {\n \tconst char *x;\n \n-- \n2.21.0.360.g471c308f928-goog\n\n"},{"id":"371419","messageId":"17ec237ba7498251a3ff64eec259d6f61c8f5ccc.1552519463.git.steadmon@google.com","threadId":"50737","inReplyTo":"cover.1552519463.git.steadmon@google.com","subject":"[PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-13T23:33:29Z","receivedAt":"2019-03-13T23:33:40Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"When the value of a trace2 environment variable contains instances of\nthe string \"%ISO8601%\", expand them into the current UTC timestamp in\nISO 8601 format.\n\nWhen the value of a trace2 environment variable is an absolute path\nreferring to an existing directory, write output to randomly-named\nfiles under the given directory. If the value is an absolute path\nreferring to a non-existent file and ends with a dash, use the value as\na prefix for randomly named files.\n\nThe random filenames will consist of the value of the environment\nvariable (after potential timestamp expansion), followed by a 6\ncharacter random string such as would be produced by mkstemp(3).\n\nThis makes it more convenient to collect traces for every git\ninvocation by unconditionally setting the relevant trace2 envvar to a\nconstant directory name.\n\nSigned-off-by: Josh Steadmon <steadmon@google.com>\n---\n Documentation/technical/api-trace2.txt | 10 +++\n t/t0210-trace2-normal.sh               | 93 ++++++++++++++++++++++++++\n trace2/tr2_dst.c                       | 86 +++++++++++++++++++++++-\n 3 files changed, 187 insertions(+), 2 deletions(-)\n\ndiff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt\nindex 2de565fa3d..1362bf7d0b 100644\n--- a/Documentation/technical/api-trace2.txt\n+++ b/Documentation/technical/api-trace2.txt\n@@ -109,6 +109,16 @@ values are recognized.\n \n \tEnables the target, opens and writes to the file in append mode.\n \n+\tIf the path includes any instances of the string \"%ISO8601%\", they will\n+\tbe replaced with the current UTC timestamp in ISO 8601 format with\n+\tdashes and colons removed, e.g., \"20190315T143059Z\".\n+\n+\tIf (after potential timestamp expansion) the path already exists and is\n+\ta directory, the traces will write to randomly-named files (one per\n+\tprocess) under the given directory. If the pathname does not already\n+\texist and ends with a dash, it will be used as a prefix for\n+\trandomly-named files (one per process).\n+\n `af_unix:[<socket_type>:]<absolute-pathname>`::\n \n \tEnables the target, opens and writes to a Unix Domain Socket\ndiff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh\nindex 03a0aedb1d..1b992c3e61 100755\n--- a/t/t0210-trace2-normal.sh\n+++ b/t/t0210-trace2-normal.sh\n@@ -80,6 +80,99 @@ test_expect_success 'normal stream, return code 1' '\n \ttest_cmp expect actual\n '\n \n+test_expect_success 'randomized filename' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir traces &&\n+\tGIT_TR2=\"$(pwd)/traces\" test-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <\"$(ls traces/??????)\" >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+\n+test_expect_success 'randomized filename with prefix' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir traces &&\n+\tGIT_TR2=\"$(pwd)/traces/trace-\" test-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <\"$(ls traces/trace-??????)\" >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+\n+test_expect_success 'timestamped filename' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir traces &&\n+\tGIT_TEST_DATE_NOW=1552658399 GIT_TR2=\"$(pwd)/traces/trace.%ISO8601%\" \\\n+\t\ttest-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <traces/trace.20190315T135959Z >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+\n+test_expect_success 'multiple timestamps' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir -p traces/20190315T135959Z &&\n+\tGIT_TEST_DATE_NOW=1552658399 GIT_TR2=\"$(pwd)/traces/%ISO8601%/trace.%ISO8601%\" \\\n+\t\ttest-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <traces/20190315T135959Z/trace.20190315T135959Z >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+\n+test_expect_success 'timestamp plus randomization' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir traces &&\n+\tGIT_TEST_DATE_NOW=1552658399 GIT_TR2=\"$(pwd)/traces/trace-%ISO8601%-\" test-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <\"$(ls traces/trace-20190315T135959Z-??????)\" >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+test_expect_success 'no randomization if target exists' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir traces &&\n+\ttouch traces/trace- &&\n+\tGIT_TR2=\"$(pwd)/traces/trace-\" test-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <traces/trace- >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+\n+\n # Verb 002exit\n #\n # Explicit exit(code) from within cmd_<verb> propagates <code>.\ndiff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c\nindex fd490a43ad..27405a92b4 100644\n--- a/trace2/tr2_dst.c\n+++ b/trace2/tr2_dst.c\n@@ -12,6 +12,11 @@\n  */\n #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n \n+/* Constant string used for timestamp replacement in output destination\n+ * filenames. See tr2_replace_timestamp_templates() below.\n+ */\n+static const char *iso_timestamp_tmpl = \"%ISO8601%\";\n+\n static int tr2_dst_want_warning(void)\n {\n \tstatic int tr2env_dst_debug = -1;\n@@ -55,6 +60,64 @@ static int tr2_dst_try_path(struct tr2_dst *dst, const char *tgt_value)\n \treturn dst->fd;\n }\n \n+static void tr2_replace_timestamp_templates(const char *path,\n+\t\t\t\t\t    struct strbuf *modified_path)\n+{\n+\tchar *iso_ptr;\n+\n+\tstrbuf_addstr(modified_path, path);\n+\n+\tiso_ptr = strstr(modified_path->buf, iso_timestamp_tmpl);\n+\tif (iso_ptr) {\n+\t\tstruct timeval tv;\n+\t\tstruct tm tm;\n+\t\tsize_t iso_len = strlen(iso_timestamp_tmpl);\n+\t\tstruct strbuf timestamp = STRBUF_INIT;\n+\n+\t\tget_time(&tv);\n+\t\tgmtime_r(&tv.tv_sec, &tm);\n+\t\tstrbuf_addftime(&timestamp, \"%Y%m%dT%H%M%SZ\", &tm, 0, 0);\n+\n+\t\twhile (iso_ptr) {\n+\t\t\tstrbuf_splice(modified_path,\n+\t\t\t\t      iso_ptr - modified_path->buf, iso_len,\n+\t\t\t\t      timestamp.buf, timestamp.len);\n+\n+\t\t\tiso_ptr = strstr(modified_path->buf,\n+\t\t\t\t\t iso_timestamp_tmpl);\n+\t\t}\n+\n+\t\tstrbuf_release(&timestamp);\n+\t}\n+}\n+\n+static int tr2_dst_try_random_path(struct tr2_dst *dst, struct strbuf *path)\n+{\n+\tint fd;\n+\tchar last_path_char;\n+\n+\tlast_path_char = path->buf[path->len - 1];\n+\tif (!is_dir_sep(last_path_char) && last_path_char != '-')\n+\t\tstrbuf_addch(path, '/');\n+\n+\tstrbuf_addstr(path, \"XXXXXX\");\n+\n+\tfd = mkstemp(path->buf);\n+\tif (fd == -1) {\n+\t\tif (tr2_dst_want_warning())\n+\t\t\twarning(\"trace2: could not open '%s' for '%s' tracing: %s\",\n+\t\t\t\tpath->buf, dst->env_var_name, strerror(errno));\n+\t\ttr2_dst_trace_disable(dst);\n+\t\treturn 0;\n+\t}\n+\n+\tdst->fd = fd;\n+\tdst->need_close = 1;\n+\tdst->initialized = 1;\n+\n+\treturn dst->fd;\n+}\n+\n #ifndef NO_UNIX_SOCKETS\n #define PREFIX_AF_UNIX \"af_unix:\"\n #define PREFIX_AF_UNIX_STREAM \"af_unix:stream:\"\n@@ -177,6 +240,7 @@ static void tr2_dst_malformed_warning(struct tr2_dst *dst,\n int tr2_dst_get_trace_fd(struct tr2_dst *dst)\n {\n \tconst char *tgt_value;\n+\tstruct stat st;\n \n \t/* don't open twice */\n \tif (dst->initialized)\n@@ -202,8 +266,26 @@ int tr2_dst_get_trace_fd(struct tr2_dst *dst)\n \t\treturn dst->fd;\n \t}\n \n-\tif (is_absolute_path(tgt_value))\n-\t\treturn tr2_dst_try_path(dst, tgt_value);\n+\tif (is_absolute_path(tgt_value)) {\n+\t\tint fd;\n+\t\tstruct strbuf modified_path = STRBUF_INIT;\n+\n+\t\ttr2_replace_timestamp_templates(tgt_value, &modified_path);\n+\n+\t\t/*\n+\t\t * Randomize the path if it is an existing directory, or if the\n+\t\t * path does not exist and ends with '-'.\n+\t\t */\n+\t\tif (is_directory(modified_path.buf) ||\n+\t\t    (stat(modified_path.buf, &st) == -1 && errno == ENOENT &&\n+\t\t     modified_path.buf[modified_path.len - 1] == '-'))\n+\t\t\tfd = tr2_dst_try_random_path(dst, &modified_path);\n+\t\telse\n+\t\t\tfd = tr2_dst_try_path(dst, modified_path.buf);\n+\n+\t\tstrbuf_release(&modified_path);\n+\t\treturn fd;\n+\t}\n \n #ifndef NO_UNIX_SOCKETS\n \tif (starts_with(tgt_value, PREFIX_AF_UNIX))\n-- \n2.21.0.360.g471c308f928-goog\n\n"},{"id":"371421","messageId":"87h8c6baif.fsf@evledraar.gmail.com","threadId":"50737","inReplyTo":"17ec237ba7498251a3ff64eec259d6f61c8f5ccc.1552519463.git.steadmon@google.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2019-03-13T23:49:28Z","receivedAt":"2019-03-13T23:49:34Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"\nOn Thu, Mar 14 2019, Josh Steadmon wrote:\n\n> When the value of a trace2 environment variable contains instances of\n> the string \"%ISO8601%\", expand them into the current UTC timestamp in\n> ISO 8601 format.\n\nAny reason not to just support feeding the path to strbuf_addftime(), to\ne.g. support a daily/hourly log?\n\n> When the value of a trace2 environment variable is an absolute path\n> referring to an existing directory, write output to randomly-named\n> files under the given directory. If the value is an absolute path\n> referring to a non-existent file and ends with a dash, use the value as\n> a prefix for randomly named files.\n>\n> The random filenames will consist of the value of the environment\n> variable (after potential timestamp expansion), followed by a 6\n> character random string such as would be produced by mkstemp(3).\n>\n> This makes it more convenient to collect traces for every git\n> invocation by unconditionally setting the relevant trace2 envvar to a\n> constant directory name.\n\nHrm, api-trace2.txt already specifies that the \"sid\" is going to be\nunique, couldn't we just have some mode where we use that?\n\nBut then of course when we have nested processes will contain slashes,\nso we'd either run into deep nesting or need to munge the slashes, in\nwhich case we might bump against a file length limit (although I haven't\nseen process trees deeper than 3-4).\n\nJust to pry about the use-case since I'm doing similar collecting, why\nare you finding this easier to process?\n\nWith the current O_APPEND semantics you're (unless I've missed\nsomething) guaranteed to get a single process tree in nested order,\nwhereas with this they'll all end up in separate files and you'll need\nto slurp them up, sort the whole thing and stitch it together yourself\nwithout the benefit of stream-parsing it where you can cheat a bit\nknowing that e.g. a \"reflog expire\" entry is always coming after the\ncorresponding \"gc\" that invoked it.\n"},{"id":"371430","messageId":"20190314001600.GC31968@sigill.intra.peff.net","threadId":"50737","inReplyTo":"17ec237ba7498251a3ff64eec259d6f61c8f5ccc.1552519463.git.steadmon@google.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-03-14T00:16:01Z","receivedAt":"2019-03-14T00:17:19Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Mar 13, 2019 at 04:33:29PM -0700, Josh Steadmon wrote:\n\n> When the value of a trace2 environment variable contains instances of\n> the string \"%ISO8601%\", expand them into the current UTC timestamp in\n> ISO 8601 format.\n\nThis definitely seems useful. Could we drop the final \"%\" and make it\neither a single-character \"%t\" or \"%(iso8601)\" to match our other\nformatting strings? There's no _technical_ reason to do that, but it\njust seems like there's not much point in being unnecessarily\ninconsistent.\n\n> When the value of a trace2 environment variable is an absolute path\n> referring to an existing directory, write output to randomly-named\n> files under the given directory. If the value is an absolute path\n> referring to a non-existent file and ends with a dash, use the value as\n> a prefix for randomly named files.\n> \n> The random filenames will consist of the value of the environment\n> variable (after potential timestamp expansion), followed by a 6\n> character random string such as would be produced by mkstemp(3).\n\nDoing this automatically for directories feels kind of magical. I'd have\nexpected it to be just another placeholder. And in fact, I'd think using\nthe process id as a placeholder would be pretty common. Between\ntimestamp and pid, that's generally unique (though I'm not opposed to\nthe random placeholder if somebody really wants to be thorough).\n\nThat leaves the door open for being able to append to or overwrite\nexisting trace files later, if we want to make that a possibility.\n\n-Peff\n"},{"id":"371465","messageId":"xmqqwol27zv4.fsf@gitster-ct.c.googlers.com","threadId":"50737","inReplyTo":"20190314001600.GC31968@sigill.intra.peff.net","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-03-14T06:07:43Z","receivedAt":"2019-03-14T06:07:48Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King <peff@peff.net> writes:\n\n> This definitely seems useful. Could we drop the final \"%\" and make it\n> either a single-character \"%t\" or \"%(iso8601)\" to match our other\n> formatting strings? There's no _technical_ reason to do that, but it\n> just seems like there's not much point in being unnecessarily\n> inconsistent.\n\nI do agree that %TOKEN% is not among the patterns we've used before,\nand I fully anticipated that it would attract paintbrushes when the\nproposal hits the public list ;-)\n\nA big question is what we want to be consisten with, though.  From\nthe readability point-of-view, for-each-ref language %(token) is\neasier to read and extend.  A secondary question is that there\nlikely are things other than the timestamp of the time process\nstarted that may want to be interpolated, so we may want to pick\nsome useful vocabulary upfront.  If we can declare interpolation\nwill be done ONLY for timestamps, as Ævar suggests, taking strftime\npattern directly from the caller may be sufficiently simple to\nexplain and useful, but I am not sure \"only for timestamps\" is a\nlimitation we would want to adopt this early in the design process.\n\n> Doing this automatically for directories feels kind of magical. I'd have\n> expected it to be just another placeholder. And in fact, I'd think using\n> the process id as a placeholder would be pretty common. Between\n> timestamp and pid, that's generally unique (though I'm not opposed to\n> the random placeholder if somebody really wants to be thorough).\n>\n> That leaves the door open for being able to append to or overwrite\n> existing trace files later, if we want to make that a possibility.\n\nThanks.\n"},{"id":"371502","messageId":"nycvar.QRO.7.76.6.1903141531160.41@tvgsbejvaqbjf.bet","threadId":"50737","inReplyTo":"cover.1552519463.git.steadmon@google.com","subject":"Re: [PATCH 0/2] Randomize / timestamp trace2 targets","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2019-03-14T14:34:22Z","receivedAt":"2019-03-14T14:34:44Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Josh,\n\nOn Wed, 13 Mar 2019, Josh Steadmon wrote:\n\n> Persistently enabling trace2 output is difficult because it requires\n> specifying a full filename. This series teaches tr2_dst_get_trace_fd()\n> to randomize filenames when a directory or filename prefix are given as\n> targets in the GIT_TR2_* envvars. It also allows expansion of a\n> timestamp template string into the current UTC timestamp.\n\nGiven the problem you try to solve, would it not make more sense to use\n`getnanotime()` than some randomized file name or an ISO date format?\n\nCiao,\nJohannes\n"},{"id":"371617","messageId":"1431dc76-1b1c-c581-6355-b796591e99a8@jeffhostetler.com","threadId":"50737","inReplyTo":"87h8c6baif.fsf@evledraar.gmail.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-15T18:39:47Z","receivedAt":"2019-03-15T18:39:51Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/13/2019 7:49 PM, Ævar Arnfjörð Bjarmason wrote:\n> \n> On Thu, Mar 14 2019, Josh Steadmon wrote:\n> \n>> When the value of a trace2 environment variable contains instances of\n>> the string \"%ISO8601%\", expand them into the current UTC timestamp in\n>> ISO 8601 format.\n> \n> Any reason not to just support feeding the path to strbuf_addftime(), to\n> e.g. support a daily/hourly log?\n> \n>> When the value of a trace2 environment variable is an absolute path\n>> referring to an existing directory, write output to randomly-named\n>> files under the given directory. If the value is an absolute path\n>> referring to a non-existent file and ends with a dash, use the value as\n>> a prefix for randomly named files.\n>>\n>> The random filenames will consist of the value of the environment\n>> variable (after potential timestamp expansion), followed by a 6\n>> character random string such as would be produced by mkstemp(3).\n>>\n>> This makes it more convenient to collect traces for every git\n>> invocation by unconditionally setting the relevant trace2 envvar to a\n>> constant directory name.\n> \n> Hrm, api-trace2.txt already specifies that the \"sid\" is going to be\n> unique, couldn't we just have some mode where we use that?\n> \n> But then of course when we have nested processes will contain slashes,\n> so we'd either run into deep nesting or need to munge the slashes, in\n> which case we might bump against a file length limit (although I haven't\n> seen process trees deeper than 3-4).\n\nUsing the \"sid\" would be a good place to start.  Just take the final\ncomponent in the string (after the last slash or the whole sid if there\nare no slashes).  That will give you a filename with microseconds since\nepoch of the command's start time and the PID.\n\nThat should be unique, should not require random strings, and not go\ndeep in the filesystem.  And it will let you correlate files between\nchild and parent commands, if you need to.\n\nSo maybe if GIT_TR2_* is set to a directory, we append the final portion\nof the \"sid\" and create a file inside that directory.\n\n> \n> Just to pry about the use-case since I'm doing similar collecting, why\n> are you finding this easier to process?\n> \n> With the current O_APPEND semantics you're (unless I've missed\n> something) guaranteed to get a single process tree in nested order,\n> whereas with this they'll all end up in separate files and you'll need\n> to slurp them up, sort the whole thing and stitch it together yourself\n> without the benefit of stream-parsing it where you can cheat a bit\n> knowing that e.g. a \"reflog expire\" entry is always coming after the\n> corresponding \"gc\" that invoked it.\n> \n\nYes, with O_APPEND, you should get a series of events as they happen\non the system all properly interleaved.  And see concurrent activity.\nThis file should let you grep to see individual processes if you want\nto.\n\nRouting each command to a different file is fine if you want, but\nthat opens you up to having to manage and delete them.\n\nWhether to have 1 file (with occasional rotation) or 1 file-per-command\ndepends, I guess, on how you want to process them.\n\nI'm routing the Trace2 data to a named-pipe/socket and have a daemon\ncollecting and filtering, so I have a single pathname for output and\nyet get the per-file stream handling that I think Josh is looking for.\n\nThanks,\nJeff\n"},{"id":"371622","messageId":"366839dd-7470-bda0-d84e-4169842c7852@jeffhostetler.com","threadId":"50737","inReplyTo":"cover.1552519463.git.steadmon@google.com","subject":"Re: [PATCH 0/2] Randomize / timestamp trace2 targets","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-15T19:18:11Z","receivedAt":"2019-03-15T19:18:14Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/13/2019 7:33 PM, Josh Steadmon wrote:\n> Persistently enabling trace2 output is difficult because it requires\n> specifying a full filename. This series teaches tr2_dst_get_trace_fd()\n> to randomize filenames when a directory or filename prefix are given as\n> targets in the GIT_TR2_* envvars. It also allows expansion of a\n> timestamp template string into the current UTC timestamp.\n\n\nDoes the use of envvar cause issues?  Or is it just the fixed absolute\npathname?  When I started this, I was trying to keep the GIT_TRACE\nmodel.\n\nAs was briefly discussed in [1] I was thinking of adding a way to\nhave a personal and/or system setting, but not a git config variable,\nthat would let you setup tracing without relying on environment\nvariables.\n\nIt's something that I've been wanting to do, it just got buried by\n$DAYJOB stuff.  I can try to bump it up if there's interest.\n\nThanks\nJeff\n\n[1] \nhttps://public-inbox.org/git/pull.108.v4.git.gitgitgadget@gmail.com/T/#mcce3b088aabc42e9867f8a9e09dd7dea5f9a773a\n"},{"id":"371624","messageId":"87sgvo9bwt.fsf@evledraar.gmail.com","threadId":"50737","inReplyTo":"1431dc76-1b1c-c581-6355-b796591e99a8@jeffhostetler.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2019-03-15T19:26:42Z","receivedAt":"2019-03-15T19:26:48Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"\nOn Fri, Mar 15 2019, Jeff Hostetler wrote:\n\n> On 3/13/2019 7:49 PM, Ævar Arnfjörð Bjarmason wrote:\n>>\n>> On Thu, Mar 14 2019, Josh Steadmon wrote:\n>>\n>>> When the value of a trace2 environment variable contains instances of\n>>> the string \"%ISO8601%\", expand them into the current UTC timestamp in\n>>> ISO 8601 format.\n>>\n>> Any reason not to just support feeding the path to strbuf_addftime(), to\n>> e.g. support a daily/hourly log?\n>>\n>>> When the value of a trace2 environment variable is an absolute path\n>>> referring to an existing directory, write output to randomly-named\n>>> files under the given directory. If the value is an absolute path\n>>> referring to a non-existent file and ends with a dash, use the value as\n>>> a prefix for randomly named files.\n>>>\n>>> The random filenames will consist of the value of the environment\n>>> variable (after potential timestamp expansion), followed by a 6\n>>> character random string such as would be produced by mkstemp(3).\n>>>\n>>> This makes it more convenient to collect traces for every git\n>>> invocation by unconditionally setting the relevant trace2 envvar to a\n>>> constant directory name.\n>>\n>> Hrm, api-trace2.txt already specifies that the \"sid\" is going to be\n>> unique, couldn't we just have some mode where we use that?\n>>\n>> But then of course when we have nested processes will contain slashes,\n>> so we'd either run into deep nesting or need to munge the slashes, in\n>> which case we might bump against a file length limit (although I haven't\n>> seen process trees deeper than 3-4).\n>\n> Using the \"sid\" would be a good place to start.  Just take the final\n> component in the string (after the last slash or the whole sid if there\n> are no slashes).  That will give you a filename with microseconds since\n> epoch of the command's start time and the PID.\n>\n> That should be unique, should not require random strings, and not go\n> deep in the filesystem.  And it will let you correlate files between\n> child and parent commands, if you need to.\n>\n> So maybe if GIT_TR2_* is set to a directory, we append the final portion\n> of the \"sid\" and create a file inside that directory.\n>\n>>\n>> Just to pry about the use-case since I'm doing similar collecting, why\n>> are you finding this easier to process?\n>>\n>> With the current O_APPEND semantics you're (unless I've missed\n>> something) guaranteed to get a single process tree in nested order,\n>> whereas with this they'll all end up in separate files and you'll need\n>> to slurp them up, sort the whole thing and stitch it together yourself\n>> without the benefit of stream-parsing it where you can cheat a bit\n>> knowing that e.g. a \"reflog expire\" entry is always coming after the\n>> corresponding \"gc\" that invoked it.\n>>\n>\n> Yes, with O_APPEND, you should get a series of events as they happen\n> on the system all properly interleaved.  And see concurrent activity.\n> This file should let you grep to see individual processes if you want\n> to.\n>\n> Routing each command to a different file is fine if you want, but\n> that opens you up to having to manage and delete them.\n>\n> Whether to have 1 file (with occasional rotation) or 1 file-per-command\n> depends, I guess, on how you want to process them.\n>\n> I'm routing the Trace2 data to a named-pipe/socket and have a daemon\n> collecting and filtering, so I have a single pathname for output and\n> yet get the per-file stream handling that I think Josh is looking for.\n\nIs the collecting code something you can share & general enough that it\nmight be useful for others?\n"},{"id":"371625","messageId":"6dc8e2db-4ae4-4be4-ab4f-bba12e3429d0@jeffhostetler.com","threadId":"50737","inReplyTo":"87sgvo9bwt.fsf@evledraar.gmail.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-15T20:14:24Z","receivedAt":"2019-03-15T20:14:27Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/15/2019 3:26 PM, Ævar Arnfjörð Bjarmason wrote:\n> \n> On Fri, Mar 15 2019, Jeff Hostetler wrote:\n> \n[...]\n>>\n>> I'm routing the Trace2 data to a named-pipe/socket and have a daemon\n>> collecting and filtering, so I have a single pathname for output and\n>> yet get the per-file stream handling that I think Josh is looking for.\n> \n> Is the collecting code something you can share & general enough that it\n> might be useful for others?\n> \n\nYes, we're currently talking about releasing the source for that too.\nIt probably won't happen this month, maybe early next quarter.\n\nJeff\n"},{"id":"371626","messageId":"20190315203704.GC47591@google.com","threadId":"50737","inReplyTo":"nycvar.QRO.7.76.6.1903141531160.41@tvgsbejvaqbjf.bet","subject":"Re: [PATCH 0/2] Randomize / timestamp trace2 targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-15T20:37:04Z","receivedAt":"2019-03-15T20:37:16Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"On 2019.03.14 15:34, Johannes Schindelin wrote:\n> Hi Josh,\n> \n> On Wed, 13 Mar 2019, Josh Steadmon wrote:\n> \n> > Persistently enabling trace2 output is difficult because it requires\n> > specifying a full filename. This series teaches tr2_dst_get_trace_fd()\n> > to randomize filenames when a directory or filename prefix are given as\n> > targets in the GIT_TR2_* envvars. It also allows expansion of a\n> > timestamp template string into the current UTC timestamp.\n> \n> Given the problem you try to solve, would it not make more sense to use\n> `getnanotime()` than some randomized file name or an ISO date format?\n\nFor my specific use case, getnanotime() would probably be sufficient.\nHowever, others requested the timestamp feature before I sent this to\nthe list. I don't know whether they had a specific use case in mind.\n"},{"id":"371627","messageId":"20190315203836.GD47591@google.com","threadId":"50737","inReplyTo":"366839dd-7470-bda0-d84e-4169842c7852@jeffhostetler.com","subject":"Re: [PATCH 0/2] Randomize / timestamp trace2 targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-15T20:38:36Z","receivedAt":"2019-03-15T20:38:44Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"On 2019.03.15 15:18, Jeff Hostetler wrote:\n> \n> \n> On 3/13/2019 7:33 PM, Josh Steadmon wrote:\n> > Persistently enabling trace2 output is difficult because it requires\n> > specifying a full filename. This series teaches tr2_dst_get_trace_fd()\n> > to randomize filenames when a directory or filename prefix are given as\n> > targets in the GIT_TR2_* envvars. It also allows expansion of a\n> > timestamp template string into the current UTC timestamp.\n> \n> \n> Does the use of envvar cause issues?  Or is it just the fixed absolute\n> pathname?  When I started this, I was trying to keep the GIT_TRACE\n> model.\n> \n> As was briefly discussed in [1] I was thinking of adding a way to\n> have a personal and/or system setting, but not a git config variable,\n> that would let you setup tracing without relying on environment\n> variables.\n> \n> It's something that I've been wanting to do, it just got buried by\n> $DAYJOB stuff.  I can try to bump it up if there's interest.\n> \n> Thanks\n> Jeff\n> \n> [1] https://public-inbox.org/git/pull.108.v4.git.gitgitgadget@gmail.com/T/#mcce3b088aabc42e9867f8a9e09dd7dea5f9a773a\n\nYeah in our case it's the fixed filename that's the issue. It's more\nconvenient for us to have lots of small files that are \"finished\"\nrelatively quickly, rather than one that is constantly appended to.\n"},{"id":"371628","messageId":"20190315204327.GE47591@google.com","threadId":"50737","inReplyTo":"87h8c6baif.fsf@evledraar.gmail.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-15T20:43:27Z","receivedAt":"2019-03-15T20:43:36Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"On 2019.03.14 00:49, Ævar Arnfjörð Bjarmason wrote:\n> \n> On Thu, Mar 14 2019, Josh Steadmon wrote:\n> \n> > When the value of a trace2 environment variable contains instances of\n> > the string \"%ISO8601%\", expand them into the current UTC timestamp in\n> > ISO 8601 format.\n> \n> Any reason not to just support feeding the path to strbuf_addftime(), to\n> e.g. support a daily/hourly log?\n\nNo reason not to. Seems reasonable to me.\n\n> > When the value of a trace2 environment variable is an absolute path\n> > referring to an existing directory, write output to randomly-named\n> > files under the given directory. If the value is an absolute path\n> > referring to a non-existent file and ends with a dash, use the value as\n> > a prefix for randomly named files.\n> >\n> > The random filenames will consist of the value of the environment\n> > variable (after potential timestamp expansion), followed by a 6\n> > character random string such as would be produced by mkstemp(3).\n> >\n> > This makes it more convenient to collect traces for every git\n> > invocation by unconditionally setting the relevant trace2 envvar to a\n> > constant directory name.\n> \n> Hrm, api-trace2.txt already specifies that the \"sid\" is going to be\n> unique, couldn't we just have some mode where we use that?\n> \n> But then of course when we have nested processes will contain slashes,\n> so we'd either run into deep nesting or need to munge the slashes, in\n> which case we might bump against a file length limit (although I haven't\n> seen process trees deeper than 3-4).\n> \n> Just to pry about the use-case since I'm doing similar collecting, why\n> are you finding this easier to process?\n\nBasically, our collection setup prefers smaller files that are\n\"finished\" earlier, rather than long-lived files that are constantly\nappended to.\n\n> With the current O_APPEND semantics you're (unless I've missed\n> something) guaranteed to get a single process tree in nested order,\n> whereas with this they'll all end up in separate files and you'll need\n> to slurp them up, sort the whole thing and stitch it together yourself\n> without the benefit of stream-parsing it where you can cheat a bit\n> knowing that e.g. a \"reflog expire\" entry is always coming after the\n> corresponding \"gc\" that invoked it.\n\nYeah, that is not an issue for us, although I can see why others would\nprefer single file. I suppose we can just modify the envvar to point to\nour newly-generated file before we spawn any child processes?\n"},{"id":"371629","messageId":"20190315204919.GF47591@google.com","threadId":"50737","inReplyTo":"20190315204327.GE47591@google.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-15T20:49:19Z","receivedAt":"2019-03-15T20:49:30Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"On 2019.03.15 13:43, Josh Steadmon wrote:\n> On 2019.03.14 00:49, Ævar Arnfjörð Bjarmason wrote:\n> > \n> > On Thu, Mar 14 2019, Josh Steadmon wrote:\n> > \n> > > When the value of a trace2 environment variable contains instances of\n> > > the string \"%ISO8601%\", expand them into the current UTC timestamp in\n> > > ISO 8601 format.\n> > \n> > Any reason not to just support feeding the path to strbuf_addftime(), to\n> > e.g. support a daily/hourly log?\n> \n> No reason not to. Seems reasonable to me.\n\nAlthough as Junio says elsewhere in this thread, it's possible that we\nmay want to support fields other than timestamps.\n"},{"id":"371757","messageId":"xmqq1s357yfj.fsf@gitster-ct.c.googlers.com","threadId":"50737","inReplyTo":"20190315204919.GF47591@google.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-03-18T01:40:00Z","receivedAt":"2019-03-18T01:40:05Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Josh Steadmon <steadmon@google.com> writes:\n\n> On 2019.03.15 13:43, Josh Steadmon wrote:\n>> On 2019.03.14 00:49, Ævar Arnfjörð Bjarmason wrote:\n>> > \n>> > On Thu, Mar 14 2019, Josh Steadmon wrote:\n>> > \n>> > > When the value of a trace2 environment variable contains instances of\n>> > > the string \"%ISO8601%\", expand them into the current UTC timestamp in\n>> > > ISO 8601 format.\n>> > \n>> > Any reason not to just support feeding the path to strbuf_addftime(), to\n>> > e.g. support a daily/hourly log?\n>> \n>> No reason not to. Seems reasonable to me.\n>\n> Although as Junio says elsewhere in this thread, it's possible that we\n> may want to support fields other than timestamps.\n\nYup.\n\nOn the other hand.\n\nAfter seeing that the possibilities got discussed on the list, and\nthat nobody seems to be very much demanding customizability (I am\ntaking Ævar's mention of strftime as a mere \"if we were doing an\noptional timestamp, why not do so in an even more customizable way?\"\nnice-to-have, not as a \"we must allow hourly or daily log, adjusting\nfor each host's needs\" must-have), I actually am fine if we declare\nthat we've chosen the hard-coded \"if it is a directory, use the last\nportion of sid to create with O_EXCL (and if we fail, append a '.%d'\ncounter to retry)\" or something simple.  Which I think takes us\ncloser to your earlier and unpublished draft, but this time we can\nsay that we omitted customizability after making sure that there is\nnot much interest---so I think it was worth it.\n\nPeople who really want customizability can and are welcome to argue\notherwise and then I may change my assessment of the level of\ninterest in customizability, but the above is my current feeling.\n\nThanks.\n"},{"id":"371810","messageId":"e56fb73a-433c-dbe6-aa71-cdc00b1f83cd@jeffhostetler.com","threadId":"50737","inReplyTo":"20190315203836.GD47591@google.com","subject":"Re: [PATCH 0/2] Randomize / timestamp trace2 targets","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-18T12:50:05Z","receivedAt":"2019-03-18T12:50:12Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/15/2019 4:38 PM, Josh Steadmon wrote:\n> On 2019.03.15 15:18, Jeff Hostetler wrote:\n>>\n>>\n>> On 3/13/2019 7:33 PM, Josh Steadmon wrote:\n>>> Persistently enabling trace2 output is difficult because it requires\n>>> specifying a full filename. This series teaches tr2_dst_get_trace_fd()\n>>> to randomize filenames when a directory or filename prefix are given as\n>>> targets in the GIT_TR2_* envvars. It also allows expansion of a\n>>> timestamp template string into the current UTC timestamp.\n>>\n>>\n>> Does the use of envvar cause issues?  Or is it just the fixed absolute\n>> pathname?  When I started this, I was trying to keep the GIT_TRACE\n>> model.\n>>\n>> As was briefly discussed in [1] I was thinking of adding a way to\n>> have a personal and/or system setting, but not a git config variable,\n>> that would let you setup tracing without relying on environment\n>> variables.\n>>\n>> It's something that I've been wanting to do, it just got buried by\n>> $DAYJOB stuff.  I can try to bump it up if there's interest.\n>>\n>> Thanks\n>> Jeff\n>>\n>> [1] https://public-inbox.org/git/pull.108.v4.git.gitgitgadget@gmail.com/T/#mcce3b088aabc42e9867f8a9e09dd7dea5f9a773a\n> \n> Yeah in our case it's the fixed filename that's the issue. It's more\n> convenient for us to have lots of small files that are \"finished\"\n> relatively quickly, rather than one that is constantly appended to.\n> \n\nOk. Great.  So if you want to go ahead and do the \"if it's a directory\nappend the last component of the sid\" thing, I'll wait for that and\nthen add the envvar alternative being discussed in another fork of this\nthread.\n\nThanks\nJeff\n"},{"id":"371872","messageId":"20190319031754.GD6173@sigill.intra.peff.net","threadId":"50737","inReplyTo":"xmqq1s357yfj.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH 2/2] trace2: randomize/timestamp trace2 targets","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2019-03-19T03:17:54Z","receivedAt":"2019-03-19T03:17:59Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Mar 18, 2019 at 10:40:00AM +0900, Junio C Hamano wrote:\n\n> After seeing that the possibilities got discussed on the list, and\n> that nobody seems to be very much demanding customizability (I am\n> taking Ævar's mention of strftime as a mere \"if we were doing an\n> optional timestamp, why not do so in an even more customizable way?\"\n> nice-to-have, not as a \"we must allow hourly or daily log, adjusting\n> for each host's needs\" must-have), I actually am fine if we declare\n> that we've chosen the hard-coded \"if it is a directory, use the last\n> portion of sid to create with O_EXCL (and if we fail, append a '.%d'\n> counter to retry)\" or something simple.  Which I think takes us\n> closer to your earlier and unpublished draft, but this time we can\n> say that we omitted customizability after making sure that there is\n> not much interest---so I think it was worth it.\n> \n> People who really want customizability can and are welcome to argue\n> otherwise and then I may change my assessment of the level of\n> interest in customizability, but the above is my current feeling.\n\nI do not really care that much about this particular issue (and I\nhaven't even really use trace2 for anything yet). My main concern was\njust painting ourselves into a corner, and making things explicit rather\nthan implicit helps with that (i.e., having the user give us a\nplaceholder that tells us what to do instead of selecting one of several\nreasonable behaviors based on whether the path exists).\n\n-Peff\n"},{"id":"372038","messageId":"cover.1553126984.git.steadmon@google.com","threadId":"50737","inReplyTo":"cover.1552519463.git.steadmon@google.com","subject":"[PATCH v2 0/1] Write trace2 output to directories","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-21T00:16:00Z","receivedAt":"2019-03-21T00:16:05Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"Persistently enabling trace2 output is difficult because it requires\nspecifying a full filename. This series teaches tr2_dst_get_trace_fd()\nto create files underneath a given directory provided as the target of\nthe GIT_TR2_* envvars.\n\nChanges since V1:\n\n* No longer supports timestamp templates.\n* No longer supports filename prefixes.\n* Always creates filenames based on the final component of the trace2\n  SID.\n\nJosh Steadmon (1):\n  trace2: write to directory targets\n\n Documentation/technical/api-trace2.txt |  5 +++\n t/t0210-trace2-normal.sh               | 15 +++++++\n trace2/tr2_dst.c                       | 61 +++++++++++++++++++++++++-\n 3 files changed, 79 insertions(+), 2 deletions(-)\n\nRange-diff against v1:\n1:  e6b01ad4bf < -:  ---------- date: make get_time() public\n2:  17ec237ba7 < -:  ---------- trace2: randomize/timestamp trace2 targets\n-:  ---------- > 1:  59d8c6511b trace2: write to directory targets\n-- \n2.21.0.225.g810b269d1ac-goog\n\n"},{"id":"372039","messageId":"59d8c6511bc8c5fd25473c282768b38c97df9e6b.1553126984.git.steadmon@google.com","threadId":"50737","inReplyTo":"cover.1553126984.git.steadmon@google.com","subject":"[PATCH v2 1/1] trace2: write to directory targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-21T00:16:01Z","receivedAt":"2019-03-21T00:16:08Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"When the value of a trace2 environment variable is an absolute path\nreferring to an existing directory, write output to files (one per\nprocess) underneath the given directory. Files will be named according\nto the final component of the trace2 SID, followed by a counter to avoid\npotential collisions.\n\nThis makes it more convenient to collect traces for every git invocation\nby unconditionally setting the relevant trace2 envvar to a constant\ndirectory name.\n\nSigned-off-by: Josh Steadmon <steadmon@google.com>\n---\n Documentation/technical/api-trace2.txt |  5 +++\n t/t0210-trace2-normal.sh               | 15 +++++++\n trace2/tr2_dst.c                       | 61 +++++++++++++++++++++++++-\n 3 files changed, 79 insertions(+), 2 deletions(-)\n\ndiff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt\nindex 2de565fa3d..318673e8e5 100644\n--- a/Documentation/technical/api-trace2.txt\n+++ b/Documentation/technical/api-trace2.txt\n@@ -109,6 +109,11 @@ values are recognized.\n \n \tEnables the target, opens and writes to the file in append mode.\n \n+\tIf the target already exists and is a directory, the traces will be\n+\twritten to files (one per process) underneath the given directory. They\n+\twill be named according to the last component of the SID followed by a\n+\tcounter to avoid potential collisions.\n+\n `af_unix:[<socket_type>:]<absolute-pathname>`::\n \n \tEnables the target, opens and writes to a Unix Domain Socket\ndiff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh\nindex 03a0aedb1d..26c9c1b3b8 100755\n--- a/t/t0210-trace2-normal.sh\n+++ b/t/t0210-trace2-normal.sh\n@@ -80,6 +80,21 @@ test_expect_success 'normal stream, return code 1' '\n \ttest_cmp expect actual\n '\n \n+test_expect_success 'randomized filename' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir traces &&\n+\tGIT_TR2=\"$(pwd)/traces\" test-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <\"$(ls traces/*)\" >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+\n # Verb 002exit\n #\n # Explicit exit(code) from within cmd_<verb> propagates <code>.\ndiff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c\nindex fd490a43ad..0e752914dc 100644\n--- a/trace2/tr2_dst.c\n+++ b/trace2/tr2_dst.c\n@@ -1,5 +1,6 @@\n #include \"cache.h\"\n #include \"trace2/tr2_dst.h\"\n+#include \"trace2/tr2_sid.h\"\n \n /*\n  * If a Trace2 target cannot be opened for writing, we should issue a\n@@ -12,6 +13,11 @@\n  */\n #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n \n+/*\n+ * How many attempts we will make at creating a random trace output path.\n+ */\n+#define MAX_RANDOM_ATTEMPTS 10\n+\n static int tr2_dst_want_warning(void)\n {\n \tstatic int tr2env_dst_debug = -1;\n@@ -36,6 +42,53 @@ void tr2_dst_trace_disable(struct tr2_dst *dst)\n \tdst->need_close = 0;\n }\n \n+static int tr2_dst_try_random_path(struct tr2_dst *dst, const char *tgt_prefix)\n+{\n+\tint fd;\n+\tconst char *last_slash, *sid = tr2_sid_get();\n+\tstruct strbuf base_path = STRBUF_INIT, final_path = STRBUF_INIT;\n+\tunsigned attempt_count;\n+\n+\tlast_slash = strrchr(sid, '/');\n+\tif (last_slash)\n+\t\tsid = last_slash + 1;\n+\n+\tstrbuf_addstr(&base_path, tgt_prefix);\n+\tif (!is_dir_sep(base_path.buf[base_path.len - 1]))\n+\t\tstrbuf_addch(&base_path, '/');\n+\tstrbuf_addstr(&base_path, sid);\n+\n+\tfor (attempt_count = 0; attempt_count < MAX_RANDOM_ATTEMPTS; attempt_count++) {\n+\t\tstrbuf_reset(&final_path);\n+\t\tstrbuf_addbuf(&final_path, &base_path);\n+\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n+\n+\t\tfd = open(final_path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n+\t\tif (fd != -1)\n+\t\t\tbreak;\n+\t}\n+\n+\tif (fd == -1) {\n+\t\tif (tr2_dst_want_warning())\n+\t\t\twarning(\"trace2: could not open '%s' for '%s' tracing: %s\",\n+\t\t\t\tbase_path.buf, dst->env_var_name, strerror(errno));\n+\n+\t\ttr2_dst_trace_disable(dst);\n+\t\tstrbuf_release(&base_path);\n+\t\tstrbuf_release(&final_path);\n+\t\treturn 0;\n+\t}\n+\n+\tstrbuf_release(&base_path);\n+\tstrbuf_release(&final_path);\n+\n+\tdst->fd = fd;\n+\tdst->need_close = 1;\n+\tdst->initialized = 1;\n+\n+\treturn dst->fd;\n+}\n+\n static int tr2_dst_try_path(struct tr2_dst *dst, const char *tgt_value)\n {\n \tint fd = open(tgt_value, O_WRONLY | O_APPEND | O_CREAT, 0666);\n@@ -202,8 +255,12 @@ int tr2_dst_get_trace_fd(struct tr2_dst *dst)\n \t\treturn dst->fd;\n \t}\n \n-\tif (is_absolute_path(tgt_value))\n-\t\treturn tr2_dst_try_path(dst, tgt_value);\n+\tif (is_absolute_path(tgt_value)) {\n+\t\tif (is_directory(tgt_value))\n+\t\t\treturn tr2_dst_try_random_path(dst, tgt_value);\n+\t\telse\n+\t\t\treturn tr2_dst_try_path(dst, tgt_value);\n+\t}\n \n #ifndef NO_UNIX_SOCKETS\n \tif (starts_with(tgt_value, PREFIX_AF_UNIX))\n-- \n2.21.0.225.g810b269d1ac-goog\n\n"},{"id":"372048","messageId":"xmqqmulpt22e.fsf@gitster-ct.c.googlers.com","threadId":"50737","inReplyTo":"59d8c6511bc8c5fd25473c282768b38c97df9e6b.1553126984.git.steadmon@google.com","subject":"Re: [PATCH v2 1/1] trace2: write to directory targets","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-03-21T02:04:57Z","receivedAt":"2019-03-21T02:05:02Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Josh Steadmon <steadmon@google.com> writes:\n\n> diff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh\n> index 03a0aedb1d..26c9c1b3b8 100755\n> --- a/t/t0210-trace2-normal.sh\n> +++ b/t/t0210-trace2-normal.sh\n> @@ -80,6 +80,21 @@ test_expect_success 'normal stream, return code 1' '\n>  \ttest_cmp expect actual\n>  '\n>  \n> +test_expect_success 'randomized filename' '\n> +\ttest_when_finished \"rm -r traces actual expect\" &&\n> +\tmkdir traces &&\n> +\tGIT_TR2=\"$(pwd)/traces\" test-tool trace2 001return 0 &&\n> +\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <\"$(ls traces/*)\" >actual &&\n\nThis is cute.\n\nWhat we want to test for this new feature is that the directory\ntraces/ that was originally empty now has exactly one readable file,\nwhich was created by producing a trace.\n\nAnd redirecting from \"$(ls traces/*)\" would succeed only when there\nis exactly one readble file in the directory.  If it has none, or\nmore than one, the redirection will fail and we'd notice the error.\n\n> +\tcat >expect <<-EOF &&\n> +\t\tversion $V\n> +\t\tstart _EXE_ trace2 001return 0\n> +\t\tcmd_name trace2 (trace2)\n> +\t\texit elapsed:_TIME_ code:0\n> +\t\tatexit elapsed:_TIME_ code:0\n> +\tEOF\n> +\ttest_cmp expect actual\n> +'\n> +\n>  # Verb 002exit\n>  #\n>  # Explicit exit(code) from within cmd_<verb> propagates <code>.\n> diff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c\n> index fd490a43ad..0e752914dc 100644\n> --- a/trace2/tr2_dst.c\n> +++ b/trace2/tr2_dst.c\n> @@ -1,5 +1,6 @@\n>  #include \"cache.h\"\n>  #include \"trace2/tr2_dst.h\"\n> +#include \"trace2/tr2_sid.h\"\n>  \n>  /*\n>   * If a Trace2 target cannot be opened for writing, we should issue a\n> @@ -12,6 +13,11 @@\n>   */\n>  #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n>  \n> +/*\n> + * How many attempts we will make at creating a random trace output path.\n> + */\n> +#define MAX_RANDOM_ATTEMPTS 10\n\nWith the updated design, randomness is no longer the primary\nproperty of this new feature.  The fact that the names are\nautomatically assigned is.  It could be that the source of tr2_sid\nmay (or may not) be some randomness, but the point is that the\ncaller in this patch does not care how tr2_sid is computed.\n\nI'd call this max-attempts (or max-autopath-attempts, but that is\nrather long, and I do not think inside the scope of \"tr2_dst\" that\nis about \"destination\", there will be anything but the destination\npath we'd \"attempt\" with a reasonable maximum value to compute, so\nthe \"-autopath\" clarification would not buy us much)....\n\n>  static int tr2_dst_want_warning(void)\n>  {\n>  \tstatic int tr2env_dst_debug = -1;\n> @@ -36,6 +42,53 @@ void tr2_dst_trace_disable(struct tr2_dst *dst)\n>  \tdst->need_close = 0;\n>  }\n>  \n> +static int tr2_dst_try_random_path(struct tr2_dst *dst, const char *tgt_prefix)\n\n.... and I'd call this s/random/auto/ instead, if I were writing\nthis patch following the updated design.\n\n> +{\n> +\tint fd;\n> +\tconst char *last_slash, *sid = tr2_sid_get();\n> +\tstruct strbuf base_path = STRBUF_INIT, final_path = STRBUF_INIT;\n> +\tunsigned attempt_count;\n> +\n> +\tlast_slash = strrchr(sid, '/');\n> +\tif (last_slash)\n> +\t\tsid = last_slash + 1;\n> +\n> +\tstrbuf_addstr(&base_path, tgt_prefix);\n> +\tif (!is_dir_sep(base_path.buf[base_path.len - 1]))\n> +\t\tstrbuf_addch(&base_path, '/');\n> +\tstrbuf_addstr(&base_path, sid);\n\nI do not think it is such a huge deal, but you can remember the\nvalue of base_path.len at this point and then get rid of the other\nstrbuf (and copying into it).  As that will leave only one path\nvariable you need to worry about, you can shorten base_path to just\npath if you go that route.\n\n    baselen = path.len;\n\n> +\tfor (attempt_count = 0; attempt_count < MAX_RANDOM_ATTEMPTS; attempt_count++) {\n> +\t\tstrbuf_reset(&final_path);\n> +\t\tstrbuf_addbuf(&final_path, &base_path);\n> +\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n> +\t\tfd = open(final_path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n\nIf you follow the \"get rid of final_path\" route, these would become:\n\n    strbuf_setlen(&path, baselen);\n    strbuf_addf(&path, \".%d\", count);\n    fd = open(path.buf, ..., 0666);\n\n> +\t\tif (fd != -1)\n> +\t\t\tbreak;\n> +\t}\n\nAnd that way, you have one fewer strbuf to _release() at the end and\nat early exit points.\n\n> +\t\tif (tr2_dst_want_warning())\n> +\t\t\twarning(\"trace2: could not open '%s' for '%s' tracing: %s\",\n> +\t\t\t\tbase_path.buf, dst->env_var_name, strerror(errno));\n\nThis would need to become\n\n\t\twarning(\"trace2: could not open '%.*s' for '%s' tracing: %s\",\n\t\t\tpath.buf, baselen, dst->env_var_name, strerror(errno));\n\nif we go that route.\n"},{"id":"372146","messageId":"51e88650-8667-df1f-13ef-4537f2e70346@jeffhostetler.com","threadId":"50737","inReplyTo":"xmqqmulpt22e.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH v2 1/1] trace2: write to directory targets","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-21T17:43:07Z","receivedAt":"2019-03-21T17:43:11Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/20/2019 10:04 PM, Junio C Hamano wrote:\n> Josh Steadmon <steadmon@google.com> writes:\n> \n[...]\n>> +/*\n>> + * How many attempts we will make at creating a random trace output path.\n>> + */\n>> +#define MAX_RANDOM_ATTEMPTS 10\n> \n> With the updated design, randomness is no longer the primary\n> property of this new feature.  The fact that the names are\n> automatically assigned is.  It could be that the source of tr2_sid\n> may (or may not) be some randomness, but the point is that the\n> caller in this patch does not care how tr2_sid is computed.\n> \n> I'd call this max-attempts (or max-autopath-attempts, but that is\n> rather long, and I do not think inside the scope of \"tr2_dst\" that\n> is about \"destination\", there will be anything but the destination\n> path we'd \"attempt\" with a reasonable maximum value to compute, so\n> the \"-autopath\" clarification would not buy us much)....\n> \n>>   static int tr2_dst_want_warning(void)\n>>   {\n>>   \tstatic int tr2env_dst_debug = -1;\n>> @@ -36,6 +42,53 @@ void tr2_dst_trace_disable(struct tr2_dst *dst)\n>>   \tdst->need_close = 0;\n>>   }\n>>   \n>> +static int tr2_dst_try_random_path(struct tr2_dst *dst, const char *tgt_prefix)\n> \n> .... and I'd call this s/random/auto/ instead, if I were writing\n> this patch following the updated design.\n\nI agree with Junio WRT the s/random/auto/ suggestions.\n\n[...]\n>> +\tfor (attempt_count = 0; attempt_count < MAX_RANDOM_ATTEMPTS; attempt_count++) {\n>> +\t\tstrbuf_reset(&final_path);\n>> +\t\tstrbuf_addbuf(&final_path, &base_path);\n>> +\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n\nSince the last component of the SID is already very unique and\nwe're unlikely to have collisions, maybe change the above line to:\n\n\t\tif (attempt_count > 0)\n\t\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n\nand in reality expect to never have files with the suffix.\n\nUnless, that is, they turned on more than one of GIT_TR2,\nGIT_TR2_PERF, or GIT_TR2_EVENT and pointed them at the same\ndirectory, but I'm not sure if I care about that edge case\nor not.\n\n>> +\t\tfd = open(final_path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n[...]\n\nNice.  Thanks for looking into this.\nJeff\n"},{"id":"372174","messageId":"cover.1553202340.git.steadmon@google.com","threadId":"50737","inReplyTo":"cover.1552519463.git.steadmon@google.com","subject":"[PATCH v3 0/1] Write trace2 output to directories","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-21T21:09:50Z","receivedAt":"2019-03-21T21:09:58Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"Persistently enabling trace2 output is difficult because it requires\nspecifying a full filename. This series teaches tr2_dst_get_trace_fd()\nto create files underneath a given directory provided as the target of\nthe GIT_TR2_* envvars.\n\nChanges since V2:\n* No longer appends a suffix to filenames on the first creation attempt.\n* Renamed function & constant now that randomization is no longer used.\n* Simplified strbuf usage.\n\nChanges since V1:\n* No longer supports timestamp templates.\n* No longer supports filename prefixes.\n* Always creates filenames based on the final component of the trace2\n  SID.\n\nJosh Steadmon (1):\n  trace2: write to directory targets\n\n Documentation/technical/api-trace2.txt |  5 ++\n t/t0210-trace2-normal.sh               | 15 ++++++\n trace2/tr2_dst.c                       | 63 +++++++++++++++++++++++++-\n 3 files changed, 81 insertions(+), 2 deletions(-)\n\nRange-diff against v2:\n1:  59d8c6511b ! 1:  ce5258610f trace2: write to directory targets\n    @@ -23,8 +23,8 @@\n      \n     +\tIf the target already exists and is a directory, the traces will be\n     +\twritten to files (one per process) underneath the given directory. They\n    -+\twill be named according to the last component of the SID followed by a\n    -+\tcounter to avoid potential collisions.\n    ++\twill be named according to the last component of the SID (optionally\n    ++\tfollowed by a counter to avoid filename collisions).\n     +\n      `af_unix:[<socket_type>:]<absolute-pathname>`::\n      \n    @@ -37,7 +37,7 @@\n      \ttest_cmp expect actual\n      '\n      \n    -+test_expect_success 'randomized filename' '\n    ++test_expect_success 'automatic filename' '\n     +\ttest_when_finished \"rm -r traces actual expect\" &&\n     +\tmkdir traces &&\n     +\tGIT_TR2=\"$(pwd)/traces\" test-tool trace2 001return 0 &&\n    @@ -71,9 +71,9 @@\n      #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n      \n     +/*\n    -+ * How many attempts we will make at creating a random trace output path.\n    ++ * How many attempts we will make at creating an automatically-named trace file.\n     + */\n    -+#define MAX_RANDOM_ATTEMPTS 10\n    ++#define MAX_AUTO_ATTEMPTS 10\n     +\n      static int tr2_dst_want_warning(void)\n      {\n    @@ -82,45 +82,47 @@\n      \tdst->need_close = 0;\n      }\n      \n    -+static int tr2_dst_try_random_path(struct tr2_dst *dst, const char *tgt_prefix)\n    ++static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix)\n     +{\n     +\tint fd;\n     +\tconst char *last_slash, *sid = tr2_sid_get();\n    -+\tstruct strbuf base_path = STRBUF_INIT, final_path = STRBUF_INIT;\n    ++\tstruct strbuf path = STRBUF_INIT;\n    ++\tsize_t base_path_len;\n     +\tunsigned attempt_count;\n     +\n     +\tlast_slash = strrchr(sid, '/');\n     +\tif (last_slash)\n     +\t\tsid = last_slash + 1;\n     +\n    -+\tstrbuf_addstr(&base_path, tgt_prefix);\n    -+\tif (!is_dir_sep(base_path.buf[base_path.len - 1]))\n    -+\t\tstrbuf_addch(&base_path, '/');\n    -+\tstrbuf_addstr(&base_path, sid);\n    ++\tstrbuf_addstr(&path, tgt_prefix);\n    ++\tif (!is_dir_sep(path.buf[path.len - 1]))\n    ++\t\tstrbuf_addch(&path, '/');\n    ++\tstrbuf_addstr(&path, sid);\n    ++\tbase_path_len = path.len;\n     +\n    -+\tfor (attempt_count = 0; attempt_count < MAX_RANDOM_ATTEMPTS; attempt_count++) {\n    -+\t\tstrbuf_reset(&final_path);\n    -+\t\tstrbuf_addbuf(&final_path, &base_path);\n    -+\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n    ++\tfor (attempt_count = 0; attempt_count < MAX_AUTO_ATTEMPTS; attempt_count++) {\n    ++\t\tif (attempt_count > 0) {\n    ++\t\t\tstrbuf_setlen(&path, base_path_len);\n    ++\t\t\tstrbuf_addf(&path, \".%d\", attempt_count);\n    ++\t\t}\n     +\n    -+\t\tfd = open(final_path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n    ++\t\tfd = open(path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n     +\t\tif (fd != -1)\n     +\t\t\tbreak;\n     +\t}\n     +\n     +\tif (fd == -1) {\n     +\t\tif (tr2_dst_want_warning())\n    -+\t\t\twarning(\"trace2: could not open '%s' for '%s' tracing: %s\",\n    -+\t\t\t\tbase_path.buf, dst->env_var_name, strerror(errno));\n    ++\t\t\twarning(\"trace2: could not open '%.*s' for '%s' tracing: %s\",\n    ++\t\t\t\t(int) base_path_len, path.buf,\n    ++\t\t\t\tdst->env_var_name, strerror(errno));\n     +\n     +\t\ttr2_dst_trace_disable(dst);\n    -+\t\tstrbuf_release(&base_path);\n    -+\t\tstrbuf_release(&final_path);\n    ++\t\tstrbuf_release(&path);\n     +\t\treturn 0;\n     +\t}\n     +\n    -+\tstrbuf_release(&base_path);\n    -+\tstrbuf_release(&final_path);\n    ++\tstrbuf_release(&path);\n     +\n     +\tdst->fd = fd;\n     +\tdst->need_close = 1;\n    @@ -140,7 +142,7 @@\n     -\t\treturn tr2_dst_try_path(dst, tgt_value);\n     +\tif (is_absolute_path(tgt_value)) {\n     +\t\tif (is_directory(tgt_value))\n    -+\t\t\treturn tr2_dst_try_random_path(dst, tgt_value);\n    ++\t\t\treturn tr2_dst_try_auto_path(dst, tgt_value);\n     +\t\telse\n     +\t\t\treturn tr2_dst_try_path(dst, tgt_value);\n     +\t}\n-- \n2.21.0.225.g810b269d1ac-goog\n\n"},{"id":"372175","messageId":"ce5258610ffbc2e498ff33336c5c89b69468d4fd.1553202340.git.steadmon@google.com","threadId":"50737","inReplyTo":"cover.1553202340.git.steadmon@google.com","subject":"[PATCH v3 1/1] trace2: write to directory targets","fromName":"Josh Steadmon","fromEmail":"steadmon@google.com","sentAt":"2019-03-21T21:09:51Z","receivedAt":"2019-03-21T21:10:00Z","isPatch":true,"sender":{"key":"steadmon@google.com","avatar":"https://avatars.githubusercontent.com/u/2654920?v=4"},"body":"When the value of a trace2 environment variable is an absolute path\nreferring to an existing directory, write output to files (one per\nprocess) underneath the given directory. Files will be named according\nto the final component of the trace2 SID, followed by a counter to avoid\npotential collisions.\n\nThis makes it more convenient to collect traces for every git invocation\nby unconditionally setting the relevant trace2 envvar to a constant\ndirectory name.\n\nSigned-off-by: Josh Steadmon <steadmon@google.com>\n---\n Documentation/technical/api-trace2.txt |  5 ++\n t/t0210-trace2-normal.sh               | 15 ++++++\n trace2/tr2_dst.c                       | 63 +++++++++++++++++++++++++-\n 3 files changed, 81 insertions(+), 2 deletions(-)\n\ndiff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt\nindex 2de565fa3d..d0948ba250 100644\n--- a/Documentation/technical/api-trace2.txt\n+++ b/Documentation/technical/api-trace2.txt\n@@ -109,6 +109,11 @@ values are recognized.\n \n \tEnables the target, opens and writes to the file in append mode.\n \n+\tIf the target already exists and is a directory, the traces will be\n+\twritten to files (one per process) underneath the given directory. They\n+\twill be named according to the last component of the SID (optionally\n+\tfollowed by a counter to avoid filename collisions).\n+\n `af_unix:[<socket_type>:]<absolute-pathname>`::\n \n \tEnables the target, opens and writes to a Unix Domain Socket\ndiff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh\nindex 03a0aedb1d..819430658b 100755\n--- a/t/t0210-trace2-normal.sh\n+++ b/t/t0210-trace2-normal.sh\n@@ -80,6 +80,21 @@ test_expect_success 'normal stream, return code 1' '\n \ttest_cmp expect actual\n '\n \n+test_expect_success 'automatic filename' '\n+\ttest_when_finished \"rm -r traces actual expect\" &&\n+\tmkdir traces &&\n+\tGIT_TR2=\"$(pwd)/traces\" test-tool trace2 001return 0 &&\n+\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <\"$(ls traces/*)\" >actual &&\n+\tcat >expect <<-EOF &&\n+\t\tversion $V\n+\t\tstart _EXE_ trace2 001return 0\n+\t\tcmd_name trace2 (trace2)\n+\t\texit elapsed:_TIME_ code:0\n+\t\tatexit elapsed:_TIME_ code:0\n+\tEOF\n+\ttest_cmp expect actual\n+'\n+\n # Verb 002exit\n #\n # Explicit exit(code) from within cmd_<verb> propagates <code>.\ndiff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c\nindex fd490a43ad..c3d82ca6a4 100644\n--- a/trace2/tr2_dst.c\n+++ b/trace2/tr2_dst.c\n@@ -1,5 +1,6 @@\n #include \"cache.h\"\n #include \"trace2/tr2_dst.h\"\n+#include \"trace2/tr2_sid.h\"\n \n /*\n  * If a Trace2 target cannot be opened for writing, we should issue a\n@@ -12,6 +13,11 @@\n  */\n #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n \n+/*\n+ * How many attempts we will make at creating an automatically-named trace file.\n+ */\n+#define MAX_AUTO_ATTEMPTS 10\n+\n static int tr2_dst_want_warning(void)\n {\n \tstatic int tr2env_dst_debug = -1;\n@@ -36,6 +42,55 @@ void tr2_dst_trace_disable(struct tr2_dst *dst)\n \tdst->need_close = 0;\n }\n \n+static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix)\n+{\n+\tint fd;\n+\tconst char *last_slash, *sid = tr2_sid_get();\n+\tstruct strbuf path = STRBUF_INIT;\n+\tsize_t base_path_len;\n+\tunsigned attempt_count;\n+\n+\tlast_slash = strrchr(sid, '/');\n+\tif (last_slash)\n+\t\tsid = last_slash + 1;\n+\n+\tstrbuf_addstr(&path, tgt_prefix);\n+\tif (!is_dir_sep(path.buf[path.len - 1]))\n+\t\tstrbuf_addch(&path, '/');\n+\tstrbuf_addstr(&path, sid);\n+\tbase_path_len = path.len;\n+\n+\tfor (attempt_count = 0; attempt_count < MAX_AUTO_ATTEMPTS; attempt_count++) {\n+\t\tif (attempt_count > 0) {\n+\t\t\tstrbuf_setlen(&path, base_path_len);\n+\t\t\tstrbuf_addf(&path, \".%d\", attempt_count);\n+\t\t}\n+\n+\t\tfd = open(path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n+\t\tif (fd != -1)\n+\t\t\tbreak;\n+\t}\n+\n+\tif (fd == -1) {\n+\t\tif (tr2_dst_want_warning())\n+\t\t\twarning(\"trace2: could not open '%.*s' for '%s' tracing: %s\",\n+\t\t\t\t(int) base_path_len, path.buf,\n+\t\t\t\tdst->env_var_name, strerror(errno));\n+\n+\t\ttr2_dst_trace_disable(dst);\n+\t\tstrbuf_release(&path);\n+\t\treturn 0;\n+\t}\n+\n+\tstrbuf_release(&path);\n+\n+\tdst->fd = fd;\n+\tdst->need_close = 1;\n+\tdst->initialized = 1;\n+\n+\treturn dst->fd;\n+}\n+\n static int tr2_dst_try_path(struct tr2_dst *dst, const char *tgt_value)\n {\n \tint fd = open(tgt_value, O_WRONLY | O_APPEND | O_CREAT, 0666);\n@@ -202,8 +257,12 @@ int tr2_dst_get_trace_fd(struct tr2_dst *dst)\n \t\treturn dst->fd;\n \t}\n \n-\tif (is_absolute_path(tgt_value))\n-\t\treturn tr2_dst_try_path(dst, tgt_value);\n+\tif (is_absolute_path(tgt_value)) {\n+\t\tif (is_directory(tgt_value))\n+\t\t\treturn tr2_dst_try_auto_path(dst, tgt_value);\n+\t\telse\n+\t\t\treturn tr2_dst_try_path(dst, tgt_value);\n+\t}\n \n #ifndef NO_UNIX_SOCKETS\n \tif (starts_with(tgt_value, PREFIX_AF_UNIX))\n-- \n2.21.0.225.g810b269d1ac-goog\n\n"},{"id":"372178","messageId":"fc057cb5-c1c9-5466-1d45-c7d1e89a9894@jeffhostetler.com","threadId":"50737","inReplyTo":"cover.1553202340.git.steadmon@google.com","subject":"Re: [PATCH v3 0/1] Write trace2 output to directories","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-21T21:16:52Z","receivedAt":"2019-03-21T21:16:56Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/21/2019 5:09 PM, Josh Steadmon wrote:\n> Persistently enabling trace2 output is difficult because it requires\n> specifying a full filename. This series teaches tr2_dst_get_trace_fd()\n> to create files underneath a given directory provided as the target of\n> the GIT_TR2_* envvars.\n> \n> Changes since V2:\n> * No longer appends a suffix to filenames on the first creation attempt.\n> * Renamed function & constant now that randomization is no longer used.\n> * Simplified strbuf usage.\n> \n> Changes since V1:\n> * No longer supports timestamp templates.\n> * No longer supports filename prefixes.\n> * Always creates filenames based on the final component of the trace2\n>    SID.\n> \n> Josh Steadmon (1):\n>    trace2: write to directory targets\n> \n>   Documentation/technical/api-trace2.txt |  5 ++\n>   t/t0210-trace2-normal.sh               | 15 ++++++\n>   trace2/tr2_dst.c                       | 63 +++++++++++++++++++++++++-\n>   3 files changed, 81 insertions(+), 2 deletions(-)\n> \n> Range-diff against v2:\n> 1:  59d8c6511b ! 1:  ce5258610f trace2: write to directory targets\n>      @@ -23,8 +23,8 @@\n>        \n>       +\tIf the target already exists and is a directory, the traces will be\n>       +\twritten to files (one per process) underneath the given directory. They\n>      -+\twill be named according to the last component of the SID followed by a\n>      -+\tcounter to avoid potential collisions.\n>      ++\twill be named according to the last component of the SID (optionally\n>      ++\tfollowed by a counter to avoid filename collisions).\n>       +\n>        `af_unix:[<socket_type>:]<absolute-pathname>`::\n>        \n>      @@ -37,7 +37,7 @@\n>        \ttest_cmp expect actual\n>        '\n>        \n>      -+test_expect_success 'randomized filename' '\n>      ++test_expect_success 'automatic filename' '\n>       +\ttest_when_finished \"rm -r traces actual expect\" &&\n>       +\tmkdir traces &&\n>       +\tGIT_TR2=\"$(pwd)/traces\" test-tool trace2 001return 0 &&\n>      @@ -71,9 +71,9 @@\n>        #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n>        \n>       +/*\n>      -+ * How many attempts we will make at creating a random trace output path.\n>      ++ * How many attempts we will make at creating an automatically-named trace file.\n>       + */\n>      -+#define MAX_RANDOM_ATTEMPTS 10\n>      ++#define MAX_AUTO_ATTEMPTS 10\n>       +\n>        static int tr2_dst_want_warning(void)\n>        {\n>      @@ -82,45 +82,47 @@\n>        \tdst->need_close = 0;\n>        }\n>        \n>      -+static int tr2_dst_try_random_path(struct tr2_dst *dst, const char *tgt_prefix)\n>      ++static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix)\n>       +{\n>       +\tint fd;\n>       +\tconst char *last_slash, *sid = tr2_sid_get();\n>      -+\tstruct strbuf base_path = STRBUF_INIT, final_path = STRBUF_INIT;\n>      ++\tstruct strbuf path = STRBUF_INIT;\n>      ++\tsize_t base_path_len;\n>       +\tunsigned attempt_count;\n>       +\n>       +\tlast_slash = strrchr(sid, '/');\n>       +\tif (last_slash)\n>       +\t\tsid = last_slash + 1;\n>       +\n>      -+\tstrbuf_addstr(&base_path, tgt_prefix);\n>      -+\tif (!is_dir_sep(base_path.buf[base_path.len - 1]))\n>      -+\t\tstrbuf_addch(&base_path, '/');\n>      -+\tstrbuf_addstr(&base_path, sid);\n>      ++\tstrbuf_addstr(&path, tgt_prefix);\n>      ++\tif (!is_dir_sep(path.buf[path.len - 1]))\n>      ++\t\tstrbuf_addch(&path, '/');\n>      ++\tstrbuf_addstr(&path, sid);\n>      ++\tbase_path_len = path.len;\n>       +\n>      -+\tfor (attempt_count = 0; attempt_count < MAX_RANDOM_ATTEMPTS; attempt_count++) {\n>      -+\t\tstrbuf_reset(&final_path);\n>      -+\t\tstrbuf_addbuf(&final_path, &base_path);\n>      -+\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n>      ++\tfor (attempt_count = 0; attempt_count < MAX_AUTO_ATTEMPTS; attempt_count++) {\n>      ++\t\tif (attempt_count > 0) {\n>      ++\t\t\tstrbuf_setlen(&path, base_path_len);\n>      ++\t\t\tstrbuf_addf(&path, \".%d\", attempt_count);\n>      ++\t\t}\n>       +\n>      -+\t\tfd = open(final_path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n>      ++\t\tfd = open(path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n>       +\t\tif (fd != -1)\n>       +\t\t\tbreak;\n>       +\t}\n>       +\n>       +\tif (fd == -1) {\n>       +\t\tif (tr2_dst_want_warning())\n>      -+\t\t\twarning(\"trace2: could not open '%s' for '%s' tracing: %s\",\n>      -+\t\t\t\tbase_path.buf, dst->env_var_name, strerror(errno));\n>      ++\t\t\twarning(\"trace2: could not open '%.*s' for '%s' tracing: %s\",\n>      ++\t\t\t\t(int) base_path_len, path.buf,\n>      ++\t\t\t\tdst->env_var_name, strerror(errno));\n>       +\n>       +\t\ttr2_dst_trace_disable(dst);\n>      -+\t\tstrbuf_release(&base_path);\n>      -+\t\tstrbuf_release(&final_path);\n>      ++\t\tstrbuf_release(&path);\n>       +\t\treturn 0;\n>       +\t}\n>       +\n>      -+\tstrbuf_release(&base_path);\n>      -+\tstrbuf_release(&final_path);\n>      ++\tstrbuf_release(&path);\n>       +\n>       +\tdst->fd = fd;\n>       +\tdst->need_close = 1;\n>      @@ -140,7 +142,7 @@\n>       -\t\treturn tr2_dst_try_path(dst, tgt_value);\n>       +\tif (is_absolute_path(tgt_value)) {\n>       +\t\tif (is_directory(tgt_value))\n>      -+\t\t\treturn tr2_dst_try_random_path(dst, tgt_value);\n>      ++\t\t\treturn tr2_dst_try_auto_path(dst, tgt_value);\n>       +\t\telse\n>       +\t\t\treturn tr2_dst_try_path(dst, tgt_value);\n>       +\t}\n> \n\nLooks good.  Thanks.\nJeff\n"},{"id":"372196","messageId":"xmqqpnqjr3g0.fsf@gitster-ct.c.googlers.com","threadId":"50737","inReplyTo":"51e88650-8667-df1f-13ef-4537f2e70346@jeffhostetler.com","subject":"Re: [PATCH v2 1/1] trace2: write to directory targets","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-03-22T03:30:23Z","receivedAt":"2019-03-22T03:30:29Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff Hostetler <git@jeffhostetler.com> writes:\n\n>>> +\tfor (attempt_count = 0; attempt_count < MAX_RANDOM_ATTEMPTS; attempt_count++) {\n>>> +\t\tstrbuf_reset(&final_path);\n>>> +\t\tstrbuf_addbuf(&final_path, &base_path);\n>>> +\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n>\n> Since the last component of the SID is already very unique and\n> we're unlikely to have collisions, maybe change the above line to:\n>\n> \t\tif (attempt_count > 0)\n> \t\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n>\n> and in reality expect to never have files with the suffix.\n\nThat's a nice property.\n\n> Unless, that is, they turned on more than one of GIT_TR2,\n> GIT_TR2_PERF, or GIT_TR2_EVENT and pointed them at the same\n> directory, but I'm not sure if I care about that edge case\n> or not.\n\nThat actually makes me wonder if the auto generated filenames want\nto have a common trait (e.g. suffix) that allows the readers to tell\nfrom which of these environment variables the names came from.  It\nwould not be very useful if two files with the same sid component\nhad .1 suffix for GIT_TR2 trace for one session, and the same .1\nsuffix is used for GIT_TR2_PERF trace for a pair of files from\nanother session.\n\nBut let's not worry about it for now.  If people do not want them\nget mixed up and become hard to tell apart, they can always specify\ndifferent directories for different traces.\n\n>\n>>> +\t\tfd = open(final_path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n> [...]\n>\n> Nice.  Thanks for looking into this.\n> Jeff\n"},{"id":"372202","messageId":"xmqq36nfqy7u.fsf@gitster-ct.c.googlers.com","threadId":"50737","inReplyTo":"fc057cb5-c1c9-5466-1d45-c7d1e89a9894@jeffhostetler.com","subject":"Re: [PATCH v3 0/1] Write trace2 output to directories","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-03-22T05:23:17Z","receivedAt":"2019-03-22T05:23:54Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff Hostetler <git@jeffhostetler.com> writes:\n\n> On 3/21/2019 5:09 PM, Josh Steadmon wrote:\n>> Persistently enabling trace2 output is difficult because it requires\n>> specifying a full filename. This series teaches tr2_dst_get_trace_fd()\n>> to create files underneath a given directory provided as the target of\n>> the GIT_TR2_* envvars.\n> ...\n> Looks good.  Thanks.\n> Jeff\n\nThanks, both.  Will queue.\n\n"},{"id":"372244","messageId":"b0d5949a-1afa-fcce-646c-d33d51686a2f@jeffhostetler.com","threadId":"50737","inReplyTo":"xmqqpnqjr3g0.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH v2 1/1] trace2: write to directory targets","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-22T14:20:02Z","receivedAt":"2019-03-22T14:20:06Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/21/2019 11:30 PM, Junio C Hamano wrote:\n> Jeff Hostetler <git@jeffhostetler.com> writes:\n> \n>>>> +\tfor (attempt_count = 0; attempt_count < MAX_RANDOM_ATTEMPTS; attempt_count++) {\n>>>> +\t\tstrbuf_reset(&final_path);\n>>>> +\t\tstrbuf_addbuf(&final_path, &base_path);\n>>>> +\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n>>\n>> Since the last component of the SID is already very unique and\n>> we're unlikely to have collisions, maybe change the above line to:\n>>\n>> \t\tif (attempt_count > 0)\n>> \t\t\tstrbuf_addf(&final_path, \".%d\", attempt_count);\n>>\n>> and in reality expect to never have files with the suffix.\n> \n> That's a nice property.\n> \n>> Unless, that is, they turned on more than one of GIT_TR2,\n>> GIT_TR2_PERF, or GIT_TR2_EVENT and pointed them at the same\n>> directory, but I'm not sure if I care about that edge case\n>> or not.\n> \n> That actually makes me wonder if the auto generated filenames want\n> to have a common trait (e.g. suffix) that allows the readers to tell\n> from which of these environment variables the names came from.  It\n> would not be very useful if two files with the same sid component\n> had .1 suffix for GIT_TR2 trace for one session, and the same .1\n> suffix is used for GIT_TR2_PERF trace for a pair of files from\n> another session.\n\nI thought about suggesting that, but didn't think it worth the bother.\n\n> But let's not worry about it for now.  If people do not want them\n> get mixed up and become hard to tell apart, they can always specify\n> different directories for different traces.\n\nagreed. it should be very rare.  the SID is the built from\n\t\"<microseconds-since-the-epoch><dash><pid>\"\nso something would have to be seriously wrong with their\nsystem to get collision from 2 different git commands.\n\nand yes, they the advise should be to use different directories\nfor the different streams.\n\n> \n>>\n>>>> +\t\tfd = open(final_path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n>> [...]\n>>\n>> Nice.  Thanks for looking into this.\n>> Jeff\n"},{"id":"372314","messageId":"87bm21coco.fsf@evledraar.gmail.com","threadId":"50737","inReplyTo":"ce5258610ffbc2e498ff33336c5c89b69468d4fd.1553202340.git.steadmon@google.com","subject":"Re: [PATCH v3 1/1] trace2: write to directory targets","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2019-03-23T20:44:39Z","receivedAt":"2019-03-23T20:44:46Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"\nOn Thu, Mar 21 2019, Josh Steadmon wrote:\n\n> When the value of a trace2 environment variable is an absolute path\n> referring to an existing directory, write output to files (one per\n> process) underneath the given directory. Files will be named according\n> to the final component of the trace2 SID, followed by a counter to avoid\n> potential collisions.\n\nIs this \"counter to avoid collisions\" something you've seen the need to\nhave in practice, or could we just squash this on top:\n\n    diff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c\n    index c3d82ca6a4..06cbef5837 100644\n    --- a/trace2/tr2_dst.c\n    +++ b/trace2/tr2_dst.c\n    @@ -13,11 +13,6 @@\n      */\n     #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n\n    -/*\n    - * How many attempts we will make at creating an automatically-named trace file.\n    - */\n    -#define MAX_AUTO_ATTEMPTS 10\n    -\n     static int tr2_dst_want_warning(void)\n     {\n     \tstatic int tr2env_dst_debug = -1;\n    @@ -48,7 +43,6 @@ static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix)\n     \tconst char *last_slash, *sid = tr2_sid_get();\n     \tstruct strbuf path = STRBUF_INIT;\n     \tsize_t base_path_len;\n    -\tunsigned attempt_count;\n\n     \tlast_slash = strrchr(sid, '/');\n     \tif (last_slash)\n    @@ -60,17 +54,7 @@ static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix)\n     \tstrbuf_addstr(&path, sid);\n     \tbase_path_len = path.len;\n\n    -\tfor (attempt_count = 0; attempt_count < MAX_AUTO_ATTEMPTS; attempt_count++) {\n    -\t\tif (attempt_count > 0) {\n    -\t\t\tstrbuf_setlen(&path, base_path_len);\n    -\t\t\tstrbuf_addf(&path, \".%d\", attempt_count);\n    -\t\t}\n    -\n    -\t\tfd = open(path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n    -\t\tif (fd != -1)\n    -\t\t\tbreak;\n    -\t}\n    -\n    +\tfd = open(path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n     \tif (fd == -1) {\n     \t\tif (tr2_dst_want_warning())\n     \t\t\twarning(\"trace2: could not open '%.*s' for '%s' tracing: %s\",\n\nThe reason I'm raising this is that it seems like sweeping an existing\nissue under the rug. We document that the \"sid\" is \"unique\", and it's just:\n\n    <nanotime / 1000 (i.e. *nix time in microseconds)>-<pid>\n\nSo that might be a lie, and in particular I can imagine that say if\nevery machine at Google is logging traces into some magic mounted FS\nthat there'll be collisions there.\n\nBut then let's *fix that*, because we're also e.g. going to have other\nconsumers of these traces using the sid's as primary keys in a logging\nsystem.\n\nI wonder if we should just make it a bit longer, human-readable, and\ninclude a hash of the hostname:\n\n    perl -MTime::HiRes=gettimeofday -MSys::Hostname -MDigest::SHA=sha1_hex -MPOSIX=strftime -wE '\n        my ($t, $m) = gettimeofday;\n        my $host_hex = substr sha1_hex(hostname()), 0, 8;\n        my $htime = strftime(\"%Y%m%d%H%M%S\", localtime);\n        my $sid = sprintf(\"%s-%6d-%s-%s\",\n            $htime,\n            $m,\n            $host_hex,\n            $$ & 0xFFFF,\n        );\n        say $sid;\n    '\n\nWhich gets you a SID like:\n\n    20190323213918-404788-c2f5b994-19027\n\nI.e.:\n\n    <YYYYMMDDHHMMSS>-<microsecond-offset>-<8 chars of sha1(hostname -f)>-<pid>\n\nThere's obviously ways to make that more compact, but in this case I\ncouldn't see a reason to, also using UTC would be a good idea.\n\nAll the trace2 tests pass if I fake that up. Jeff H: Do you have\nanything that relies on the current format?\n\n> This makes it more convenient to collect traces for every git invocation\n> by unconditionally setting the relevant trace2 envvar to a constant\n> directory name.\n>\n> Signed-off-by: Josh Steadmon <steadmon@google.com>\n> ---\n>  Documentation/technical/api-trace2.txt |  5 ++\n>  t/t0210-trace2-normal.sh               | 15 ++++++\n>  trace2/tr2_dst.c                       | 63 +++++++++++++++++++++++++-\n>  3 files changed, 81 insertions(+), 2 deletions(-)\n>\n> diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt\n> index 2de565fa3d..d0948ba250 100644\n> --- a/Documentation/technical/api-trace2.txt\n> +++ b/Documentation/technical/api-trace2.txt\n> @@ -109,6 +109,11 @@ values are recognized.\n>\n>  \tEnables the target, opens and writes to the file in append mode.\n>\n> +\tIf the target already exists and is a directory, the traces will be\n> +\twritten to files (one per process) underneath the given directory. They\n> +\twill be named according to the last component of the SID (optionally\n> +\tfollowed by a counter to avoid filename collisions).\n> +\n>  `af_unix:[<socket_type>:]<absolute-pathname>`::\n>\n>  \tEnables the target, opens and writes to a Unix Domain Socket\n> diff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh\n> index 03a0aedb1d..819430658b 100755\n> --- a/t/t0210-trace2-normal.sh\n> +++ b/t/t0210-trace2-normal.sh\n> @@ -80,6 +80,21 @@ test_expect_success 'normal stream, return code 1' '\n>  \ttest_cmp expect actual\n>  '\n>\n> +test_expect_success 'automatic filename' '\n> +\ttest_when_finished \"rm -r traces actual expect\" &&\n> +\tmkdir traces &&\n> +\tGIT_TR2=\"$(pwd)/traces\" test-tool trace2 001return 0 &&\n> +\tperl \"$TEST_DIRECTORY/t0210/scrub_normal.perl\" <\"$(ls traces/*)\" >actual &&\n> +\tcat >expect <<-EOF &&\n> +\t\tversion $V\n> +\t\tstart _EXE_ trace2 001return 0\n> +\t\tcmd_name trace2 (trace2)\n> +\t\texit elapsed:_TIME_ code:0\n> +\t\tatexit elapsed:_TIME_ code:0\n> +\tEOF\n> +\ttest_cmp expect actual\n> +'\n> +\n>  # Verb 002exit\n>  #\n>  # Explicit exit(code) from within cmd_<verb> propagates <code>.\n> diff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c\n> index fd490a43ad..c3d82ca6a4 100644\n> --- a/trace2/tr2_dst.c\n> +++ b/trace2/tr2_dst.c\n> @@ -1,5 +1,6 @@\n>  #include \"cache.h\"\n>  #include \"trace2/tr2_dst.h\"\n> +#include \"trace2/tr2_sid.h\"\n>\n>  /*\n>   * If a Trace2 target cannot be opened for writing, we should issue a\n> @@ -12,6 +13,11 @@\n>   */\n>  #define TR2_ENVVAR_DST_DEBUG \"GIT_TR2_DST_DEBUG\"\n>\n> +/*\n> + * How many attempts we will make at creating an automatically-named trace file.\n> + */\n> +#define MAX_AUTO_ATTEMPTS 10\n> +\n>  static int tr2_dst_want_warning(void)\n>  {\n>  \tstatic int tr2env_dst_debug = -1;\n> @@ -36,6 +42,55 @@ void tr2_dst_trace_disable(struct tr2_dst *dst)\n>  \tdst->need_close = 0;\n>  }\n>\n> +static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix)\n> +{\n> +\tint fd;\n> +\tconst char *last_slash, *sid = tr2_sid_get();\n> +\tstruct strbuf path = STRBUF_INIT;\n> +\tsize_t base_path_len;\n> +\tunsigned attempt_count;\n> +\n> +\tlast_slash = strrchr(sid, '/');\n> +\tif (last_slash)\n> +\t\tsid = last_slash + 1;\n> +\n> +\tstrbuf_addstr(&path, tgt_prefix);\n> +\tif (!is_dir_sep(path.buf[path.len - 1]))\n> +\t\tstrbuf_addch(&path, '/');\n> +\tstrbuf_addstr(&path, sid);\n> +\tbase_path_len = path.len;\n> +\n> +\tfor (attempt_count = 0; attempt_count < MAX_AUTO_ATTEMPTS; attempt_count++) {\n> +\t\tif (attempt_count > 0) {\n> +\t\t\tstrbuf_setlen(&path, base_path_len);\n> +\t\t\tstrbuf_addf(&path, \".%d\", attempt_count);\n> +\t\t}\n> +\n> +\t\tfd = open(path.buf, O_WRONLY | O_CREAT | O_EXCL, 0666);\n> +\t\tif (fd != -1)\n> +\t\t\tbreak;\n> +\t}\n> +\n> +\tif (fd == -1) {\n> +\t\tif (tr2_dst_want_warning())\n> +\t\t\twarning(\"trace2: could not open '%.*s' for '%s' tracing: %s\",\n> +\t\t\t\t(int) base_path_len, path.buf,\n> +\t\t\t\tdst->env_var_name, strerror(errno));\n> +\n> +\t\ttr2_dst_trace_disable(dst);\n> +\t\tstrbuf_release(&path);\n> +\t\treturn 0;\n> +\t}\n> +\n> +\tstrbuf_release(&path);\n> +\n> +\tdst->fd = fd;\n> +\tdst->need_close = 1;\n> +\tdst->initialized = 1;\n> +\n> +\treturn dst->fd;\n> +}\n> +\n>  static int tr2_dst_try_path(struct tr2_dst *dst, const char *tgt_value)\n>  {\n>  \tint fd = open(tgt_value, O_WRONLY | O_APPEND | O_CREAT, 0666);\n> @@ -202,8 +257,12 @@ int tr2_dst_get_trace_fd(struct tr2_dst *dst)\n>  \t\treturn dst->fd;\n>  \t}\n>\n> -\tif (is_absolute_path(tgt_value))\n> -\t\treturn tr2_dst_try_path(dst, tgt_value);\n> +\tif (is_absolute_path(tgt_value)) {\n> +\t\tif (is_directory(tgt_value))\n> +\t\t\treturn tr2_dst_try_auto_path(dst, tgt_value);\n> +\t\telse\n> +\t\t\treturn tr2_dst_try_path(dst, tgt_value);\n> +\t}\n>\n>  #ifndef NO_UNIX_SOCKETS\n>  \tif (starts_with(tgt_value, PREFIX_AF_UNIX))\n"},{"id":"372357","messageId":"xmqqlg14pi2x.fsf@gitster-ct.c.googlers.com","threadId":"50737","inReplyTo":"87bm21coco.fsf@evledraar.gmail.com","subject":"Re: [PATCH v3 1/1] trace2: write to directory targets","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-03-24T12:33:58Z","receivedAt":"2019-03-24T12:34:03Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes:\n\n> The reason I'm raising this is that it seems like sweeping an existing\n> issue under the rug. We document that the \"sid\" is \"unique\", and it's just:\n>\n>     <nanotime / 1000 (i.e. *nix time in microseconds)>-<pid>\n\nIf it is just that, then it cannot be unique, can it?\n\nLet's just fix the wrong doc and move on.\n"},{"id":"372366","messageId":"87a7hkcome.fsf@evledraar.gmail.com","threadId":"50737","inReplyTo":"xmqqlg14pi2x.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH v3 1/1] trace2: write to directory targets","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2019-03-24T14:51:05Z","receivedAt":"2019-03-24T14:51:12Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"\nOn Sun, Mar 24 2019, Junio C Hamano wrote:\n\n> Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes:\n>\n>> The reason I'm raising this is that it seems like sweeping an existing\n>> issue under the rug. We document that the \"sid\" is \"unique\", and it's just:\n>>\n>>     <nanotime / 1000 (i.e. *nix time in microseconds)>-<pid>\n>\n> If it is just that, then it cannot be unique, can it?\n>\n> Let's just fix the wrong doc and move on.\n\nI don't see why we wouldn't just fix the SID generation & move on if\nwe're already carrying code purely as a work-around for it not being\nunique enough.\n\nOf course nothing is *guaranteed* to be unique, not even a 128-bit\nUUID. The point is to pick something that's \"unique enough\" given the\nproblem space, which is already one where we'll ignore I/O errors on\nwriting the file unless you opt-in to a warning.\n\nAnd it's a very useful property to have the SID be a) unique enough like\nthat so you can use a unique index for \"git events\" b) fixed-width\n(which the current one *isn't*), so you can use fixed-with indexes in\nsome logging databases c) as a bonus, be human-readable at a glance,\nhence spending slightly more space on the the YYYMM.. format in my\nsuggested SID format.\n\nI can write that patch, but first it's useful to know if this is a case\nJosh is running into, or if it's just a guard out of paranoia.\n"},{"id":"372391","messageId":"xmqqlg13ofqw.fsf@gitster-ct.c.googlers.com","threadId":"50737","inReplyTo":"87a7hkcome.fsf@evledraar.gmail.com","subject":"Re: [PATCH v3 1/1] trace2: write to directory targets","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-03-25T02:21:59Z","receivedAt":"2019-03-25T02:22:15Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes:\n\n> On Sun, Mar 24 2019, Junio C Hamano wrote:\n>\n>> Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes:\n>>\n>>> The reason I'm raising this is that it seems like sweeping an existing\n>>> issue under the rug. We document that the \"sid\" is \"unique\", and it's just:\n>>>\n>>>     <nanotime / 1000 (i.e. *nix time in microseconds)>-<pid>\n>>\n>> If it is just that, then it cannot be unique, can it?\n>>\n>> Let's just fix the wrong doc and move on.\n>\n> I don't see why we wouldn't just fix the SID generation & move on if\n> we're already carrying code purely as a work-around for it not being\n> unique enough.\n\nThe thing is, the yardstick to determine \"unique enough\" depends on\nthe caller.  In this codepath, we want the uniqueness within the\ndirectory that was given to us, and one reasonable way, among the\nmost sensible ones, is to ask open(O_CREAT|O_EXCL) and it makes 100%\nsense to fall back with suffix when \"enough\" thought by the callee\nturns out to be insufficient when judged by the caller.\n\nSo I do not see the .%d suffix a work-around at all.  I view it as\nan integral part of the whole package.\n\nBy the way, is the \"nanotime\" implementation that may be in compat/\nfine grained enough?\n\n> Of course nothing is *guaranteed* to be unique, not even a 128-bit\n> UUID. The point is to pick something that's \"unique enough\" given the\n> problem space, which is already one where we'll ignore I/O errors on\n> writing the file unless you opt-in to a warning.\n\nYes, the point is to pick something that is unique enough and then\ngive a reasonable fallback when it turns out insufficient.  I think\n\".%d\" suffix is one reasonable fallback, but I realize that it is\nnot the only reasonable fallback.  Another reasonable fallback could\nbe \"upon seeing a failure of open(O_CREAT|O_EXCL), we give up and do\nnot leave a logfile, because this should be a rare enough event as\nour assumption is sid is unique enough for everyday operation\".\n\nI could buy that, especially if the \".%d\" suffix fallback is too\nexpensive to carry and maintain into the future.  And in such a\ncase, it indeed would be a more reasonable workaround for a rare\nnon-unique sid problem to ignore and discard the log.\n\nI just did not think the \".%d\" suffix fallback is too expensive to\ncarry.\n"},{"id":"372402","messageId":"874l7rcqk9.fsf@evledraar.gmail.com","threadId":"50737","inReplyTo":"xmqqlg13ofqw.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH v3 1/1] trace2: write to directory targets","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2019-03-25T08:21:26Z","receivedAt":"2019-03-25T08:21:32Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"\nOn Mon, Mar 25 2019, Junio C Hamano wrote:\n\n> Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes:\n>\n>> On Sun, Mar 24 2019, Junio C Hamano wrote:\n>>\n>>> Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes:\n>>>\n>>>> The reason I'm raising this is that it seems like sweeping an existing\n>>>> issue under the rug. We document that the \"sid\" is \"unique\", and it's just:\n>>>>\n>>>>     <nanotime / 1000 (i.e. *nix time in microseconds)>-<pid>\n>>>\n>>> If it is just that, then it cannot be unique, can it?\n>>>\n>>> Let's just fix the wrong doc and move on.\n>>\n>> I don't see why we wouldn't just fix the SID generation & move on if\n>> we're already carrying code purely as a work-around for it not being\n>> unique enough.\n>\n> The thing is, the yardstick to determine \"unique enough\" depends on\n> the caller.  In this codepath, we want the uniqueness within the\n> directory that was given to us, and one reasonable way, among the\n> most sensible ones, is to ask open(O_CREAT|O_EXCL) and it makes 100%\n> sense to fall back with suffix when \"enough\" thought by the callee\n> turns out to be insufficient when judged by the caller.\n>\n> So I do not see the .%d suffix a work-around at all.  I view it as\n> an integral part of the whole package.\n>\n> By the way, is the \"nanotime\" implementation that may be in compat/\n> fine grained enough?\n>\n>> Of course nothing is *guaranteed* to be unique, not even a 128-bit\n>> UUID. The point is to pick something that's \"unique enough\" given the\n>> problem space, which is already one where we'll ignore I/O errors on\n>> writing the file unless you opt-in to a warning.\n>\n> Yes, the point is to pick something that is unique enough and then\n> give a reasonable fallback when it turns out insufficient.  I think\n> \".%d\" suffix is one reasonable fallback, but I realize that it is\n> not the only reasonable fallback.  Another reasonable fallback could\n> be \"upon seeing a failure of open(O_CREAT|O_EXCL), we give up and do\n> not leave a logfile, because this should be a rare enough event as\n> our assumption is sid is unique enough for everyday operation\".\n>\n> I could buy that, especially if the \".%d\" suffix fallback is too\n> expensive to carry and maintain into the future.  And in such a\n> case, it indeed would be a more reasonable workaround for a rare\n> non-unique sid problem to ignore and discard the log.\n>\n> I just did not think the \".%d\" suffix fallback is too expensive to\n> carry.\n\nOh yeah, the SID.%d fallback is easy enough, and I'd 100% agree that if\nthat was *all* it was this would all make sense. Let's just retry, just\nlike a tempfile implementation will retry.\n\nBut I'm not interested in using the SID-per-file format Josh is adding\nhere, but *am* interested in having a logging system where over a bunch\nof machines I can expect the SID to be unique with a high degree of\nprobability.\n\nSo this open(O_CREAT|O_EXCL) code is revealing a problem that we're also\ngoing to have in a different form in the\nGIT_TR2_EVENT=/var/log/one-big-file-of.json format.\n\nIt seems to me that the only reason both of these are an issue is\nsomething we can fix with the SID generation.\n"},{"id":"372439","messageId":"11e8e140-c2b6-8234-e6a3-affe69286cbf@jeffhostetler.com","threadId":"50737","inReplyTo":"87bm21coco.fsf@evledraar.gmail.com","subject":"Re: [PATCH v3 1/1] trace2: write to directory targets","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2019-03-25T16:29:32Z","receivedAt":"2019-03-25T16:29:36Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 3/23/2019 4:44 PM, Ævar Arnfjörð Bjarmason wrote:\n> \n> On Thu, Mar 21 2019, Josh Steadmon wrote:\n> \n>> When the value of a trace2 environment variable is an absolute path\n>> referring to an existing directory, write output to files (one per\n>> process) underneath the given directory. Files will be named according\n>> to the final component of the trace2 SID, followed by a counter to avoid\n>> potential collisions.\n> \n[...]\n> \n> The reason I'm raising this is that it seems like sweeping an existing\n> issue under the rug. We document that the \"sid\" is \"unique\", and it's just:\n> \n>      <nanotime / 1000 (i.e. *nix time in microseconds)>-<pid>\n> \n> So that might be a lie, and in particular I can imagine that say if\n> every machine at Google is logging traces into some magic mounted FS\n> that there'll be collisions there.\n> \n> But then let's *fix that*, because we're also e.g. going to have other\n> consumers of these traces using the sid's as primary keys in a logging\n> system.\n> \n> I wonder if we should just make it a bit longer, human-readable, and\n> include a hash of the hostname:\n> \n>      perl -MTime::HiRes=gettimeofday -MSys::Hostname -MDigest::SHA=sha1_hex -MPOSIX=strftime -wE '\n>          my ($t, $m) = gettimeofday;\n>          my $host_hex = substr sha1_hex(hostname()), 0, 8;\n>          my $htime = strftime(\"%Y%m%d%H%M%S\", localtime);\n>          my $sid = sprintf(\"%s-%6d-%s-%s\",\n>              $htime,\n>              $m,\n>              $host_hex,\n>              $$ & 0xFFFF,\n>          );\n>          say $sid;\n>      '\n> \n> Which gets you a SID like:\n> \n>      20190323213918-404788-c2f5b994-19027\n> \n> I.e.:\n> \n>      <YYYYMMDDHHMMSS>-<microsecond-offset>-<8 chars of sha1(hostname -f)>-<pid>\n> \n> There's obviously ways to make that more compact, but in this case I\n> couldn't see a reason to, also using UTC would be a good idea.\n> \n> All the trace2 tests pass if I fake that up. Jeff H: Do you have\n> anything that relies on the current format?\nI'm using the SID hierarchy to track parent and child processes,\nbut the actual format of an individual SID-component is mostly a\nblack box.\n\nI used the microseconds+pid as unique enough.  And events for new\ncommands will mostly just append to an existing index, rather than\nbeing a random insert like you'd get for a GUID.\n\nI didn't use a GUID here because that seemed overkill and a little\nbit more expensive, but perhaps that was just premature optimization\non my part.\n\n\nSo, a new fixed width format like you suggested above would be fine.\nI wonder though, if we're moving towards a stronger SID, there's no\nreason to keep the PID in it.  Which makes me wonder about the value\nof sha(hostname) too.  Perhaps, just make it a GUID or some combination\nof the UTC date and a GUID ( <YYMMDDHHMMSS>-<microseconds>-<GUID> ) or\nsomething like that.\n\nIf it helps, we can change how I'm reporting the SID between parent\nand child processes, so that the SID field in the JSON events is\njust the SID of the current process and have a peer field with the\nSID-hierarchy.  This latter field would only need to be added to the\n\"version\" or \"start\" event.  This might make post-processing a little\neasier.  Not sure it matters one way or the other.\n\nI'm open to suggestions here.\n\nJeff\n\n"}]}