Re: [PATCH v3 1/8] [RFC] dir: convert trace calls to trace2 equivalents

"Elijah Newren via GitGitGadget" [off-list ref] writes:

+static void trace2_read_directory_statistics(struct dir_struct *dir,
+					     struct repository *repo)
+{
+	if (!dir->untracked)
+		return;
+	trace2_data_intmax("read_directory", repo,
+			   "node-creation", dir->untracked->dir_created);
+	trace2_data_intmax("read_directory", repo,
+			   "gitignore-invalidation",
+			   dir->untracked->gitignore_invalidated);
+	trace2_data_intmax("read_directory", repo,
+			   "directory-invalidation",
+			   dir->untracked->dir_invalidated);
+	trace2_data_intmax("read_directory", repo,
+			   "opendir", dir->untracked->dir_opened);
+}
+

This obviously looks like an equivalent to what happens in the
original inside the "if (dir->untracked)" block.

And we have a performance_{enter,leave} pair replaced with
a region_[enter,leave} pair. 

-	trace_performance_enter();
+	trace2_region_enter("dir", "read_directory", istate->repo);
  ...
-	trace_performance_leave("read directory %.*s", len, path);
+	trace2_region_leave("dir", "read_directory", istate->repo);

 	if (dir->untracked) {
 		static int force_untracked_cache = -1;
-		static struct trace_key trace_untracked_stats = TRACE_KEY_INIT(UNTRACKED_STATS);
 
 		if (force_untracked_cache < 0)
 			force_untracked_cache =
 				git_env_bool("GIT_FORCE_UNTRACKED_CACHE", 0);
-		trace_printf_key(&trace_untracked_stats,
-				 "node creation: %u\n"
-				 "gitignore invalidation: %u\n"
-				 "directory invalidation: %u\n"
-				 "opendir: %u\n",
-				 dir->untracked->dir_created,
-				 dir->untracked->gitignore_invalidated,
-				 dir->untracked->dir_invalidated,
-				 dir->untracked->dir_opened);
 		if (force_untracked_cache &&
 			dir->untracked == istate->untracked &&
 		    (dir->untracked->dir_opened ||

Removal of the trace_printf() in the middle made the body of this
if() statement much less distracting, which is good.

This slightly changes the semantics in that the original did an
equivalent emitting from inside the "if (dir->untracked)" block, but
this call is hoisted outside, and the new helper knows how to be
silent when untracked thing is not in effect, so the net effect at
this step is the same.  And if we ever add tracing statics that is
relevant when !dir->untracked is true, the new code organization is
easier to work with.

The only curious thing is the guard "if (trace2_is_enabled())";
correctness-wise, are there bad things going to happen if it is not
here, or is this a performance hack, or is it more for its
documentation value (meaning, it would be a bug if we later added
things that are irrelevant when trace is not enabled to the helper)?

Style.  SP on both sides of "()".

+	# From the GIT_TRACE2_PERF data of the form
+	#    $TIME $FILE:$LINE | d0 | main | data | r1 | ? | ? | read_directo | $RELEVANT_STAT
+	# extract the $RELEVANT_STAT fields.  We don't care about region_enter
+	# or region_leave, or stats for things outside read_directory.
+	INPUT_FILE=$1
+	OUTPUT_FILE=$2
+	grep data.*read_directo $INPUT_FILE \
+	    | cut -d "|" -f 9 \
+	    >$OUTPUT_FILE

Style.  Wrapping the line after pipe '|' will allow you to omit the
backslash.  Also quote the redirection target, i.e. >"$OUTPUT_FILE",
to help certain vintage of bash.

Those who are more familiar with the trace2 infrastructure may want
to further comment, but it looked obvious and straightforward to me.

Thanks.

On Sun, May 9, 2021 at 9:49 PM Junio C Hamano [off-list ref] wrote:

"Elijah Newren via GitGitGadget" [off-list ref] writes:

quoted

+static void trace2_read_directory_statistics(struct dir_struct *dir,
+                                          struct repository *repo)
+{
+     if (!dir->untracked)
+             return;
+     trace2_data_intmax("read_directory", repo,
+                        "node-creation", dir->untracked->dir_created);
+     trace2_data_intmax("read_directory", repo,
+                        "gitignore-invalidation",
+                        dir->untracked->gitignore_invalidated);
+     trace2_data_intmax("read_directory", repo,
+                        "directory-invalidation",
+                        dir->untracked->dir_invalidated);
+     trace2_data_intmax("read_directory", repo,
+                        "opendir", dir->untracked->dir_opened);
+}
+

This obviously looks like an equivalent to what happens in the
original inside the "if (dir->untracked)" block.

And we have a performance_{enter,leave} pair replaced with
a region_[enter,leave} pair.

quoted

-     trace_performance_enter();
+     trace2_region_enter("dir", "read_directory", istate->repo);
  ...
-     trace_performance_leave("read directory %.*s", len, path);
+     trace2_region_leave("dir", "read_directory", istate->repo);

quoted

      if (dir->untracked) {
              static int force_untracked_cache = -1;
-             static struct trace_key trace_untracked_stats = TRACE_KEY_INIT(UNTRACKED_STATS);

              if (force_untracked_cache < 0)
                      force_untracked_cache =
                              git_env_bool("GIT_FORCE_UNTRACKED_CACHE", 0);
-             trace_printf_key(&trace_untracked_stats,
-                              "node creation: %u\n"
-                              "gitignore invalidation: %u\n"
-                              "directory invalidation: %u\n"
-                              "opendir: %u\n",
-                              dir->untracked->dir_created,
-                              dir->untracked->gitignore_invalidated,
-                              dir->untracked->dir_invalidated,
-                              dir->untracked->dir_opened);
              if (force_untracked_cache &&
                      dir->untracked == istate->untracked &&
                  (dir->untracked->dir_opened ||

Removal of the trace_printf() in the middle made the body of this
if() statement much less distracting, which is good.

quoted

@@ -2811,6 +2818,9 @@ int read_directory(struct dir_struct *dir, struct index_state *istate,
                      FREE_AND_NULL(dir->untracked);
              }
      }
+
+     if (trace2_is_enabled())
+             trace2_read_directory_statistics(dir, istate->repo);

This slightly changes the semantics in that the original did an
equivalent emitting from inside the "if (dir->untracked)" block, but
this call is hoisted outside, and the new helper knows how to be
silent when untracked thing is not in effect, so the net effect at
this step is the same.  And if we ever add tracing statics that is
relevant when !dir->untracked is true, the new code organization is
easier to work with.

The only curious thing is the guard "if (trace2_is_enabled())";
correctness-wise, are there bad things going to happen if it is not
here, or is this a performance hack, or is it more for its
documentation value (meaning, it would be a bug if we later added
things that are irrelevant when trace is not enabled to the helper)?

No, there's nothing bad that would happen here.  It was a combination
of a performance hack and documentation in case
trace2_read_directory_statistics() started gaining other code besides
trace2_*() calls, but which code was only relevant when trace2 was
enabled.

Turns out, though, that Jeff's suggestion to also print the path in
the statistics is going to require me creating a temporary strbuf so
that I can get a NUL-terminated string.  We only want to do that when
trace2_is_enabled(), so that will make the introduction of that check
a bit more natural.

quoted

@@ -57,6 +57,19 @@ iuc () {
      return $ret
 }

+get_relevant_traces() {

Style.  SP on both sides of "()".

Will fix.

quoted

+     # From the GIT_TRACE2_PERF data of the form
+     #    $TIME $FILE:$LINE | d0 | main | data | r1 | ? | ? | read_directo | $RELEVANT_STAT
+     # extract the $RELEVANT_STAT fields.  We don't care about region_enter
+     # or region_leave, or stats for things outside read_directory.
+     INPUT_FILE=$1
+     OUTPUT_FILE=$2
+     grep data.*read_directo $INPUT_FILE \
+         | cut -d "|" -f 9 \
+         >$OUTPUT_FILE

Style.  Wrapping the line after pipe '|' will allow you to omit the
backslash.  Also quote the redirection target, i.e. >"$OUTPUT_FILE",
to help certain vintage of bash.

Will fix.