[PATCH v1 13/25] structured-logging: add timer around wt-status functions

[git@jeffhostetler.com]

From: Jeff Hostetler <jeffhost@microsoft.com>

Use a SLOG timer to record the time spend in wt_status_collect_worktree(),
wt_status_collect_changes_initial(), wt_status_collect_changes_index(),
and wt_status_collect_untracked().  These are reported in the "cmd_exit"
event.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 wt-status.c | 20 ++++++++++++++++++++
 1 file changed, 20 insertions(+)

diff --git a/wt-status.c b/wt-status.c
index d1c0514..f663a37 100644
--- a/wt-status.c
+++ b/wt-status.c
@@ -580,8 +580,11 @@ static void wt_status_collect_updated_cb(struct diff_queue_struct *q,
 
 static void wt_status_collect_changes_worktree(struct wt_status *s)
 {
+	int slog_tid;
 	struct rev_info rev;
 
+	slog_tid = slog_start_timer("status", "worktree");
+
 	init_revisions(&rev, NULL);
 	setup_revisions(0, NULL, &rev, NULL);
 	rev.diffopt.output_format |= DIFF_FORMAT_CALLBACK;
@@ -600,13 +603,18 @@ static void wt_status_collect_changes_worktree(struct wt_status *s)
 	rev.diffopt.rename_score = s->rename_score >= 0 ? s->rename_score : rev.diffopt.rename_score;
 	copy_pathspec(&rev.prune_data, &s->pathspec);
 	run_diff_files(&rev, 0);
+
+	slog_stop_timer(slog_tid);
 }
 
 static void wt_status_collect_changes_index(struct wt_status *s)
 {
+	int slog_tid;
 	struct rev_info rev;
 	struct setup_revision_opt opt;
 
+	slog_tid = slog_start_timer("status", "changes_index");
+
 	init_revisions(&rev, NULL);
 	memset(&opt, 0, sizeof(opt));
 	opt.def = s->is_initial ? empty_tree_oid_hex() : s->reference;
@@ -636,12 +644,17 @@ static void wt_status_collect_changes_index(struct wt_status *s)
 	rev.diffopt.rename_score = s->rename_score >= 0 ? s->rename_score : rev.diffopt.rename_score;
 	copy_pathspec(&rev.prune_data, &s->pathspec);
 	run_diff_index(&rev, 1);
+
+	slog_stop_timer(slog_tid);
 }
 
 static void wt_status_collect_changes_initial(struct wt_status *s)
 {
+	int slog_tid;
 	int i;
 
+	slog_tid = slog_start_timer("status", "changes_initial");
+
 	for (i = 0; i < active_nr; i++) {
 		struct string_list_item *it;
 		struct wt_status_change_data *d;
@@ -672,10 +685,13 @@ static void wt_status_collect_changes_initial(struct wt_status *s)
 			oidcpy(&d->oid_index, &ce->oid);
 		}
 	}
+
+	slog_stop_timer(slog_tid);
 }
 
 static void wt_status_collect_untracked(struct wt_status *s)
 {
+	int slog_tid;
 	int i;
 	struct dir_struct dir;
 	uint64_t t_begin = getnanotime();
@@ -683,6 +699,8 @@ static void wt_status_collect_untracked(struct wt_status *s)
 	if (!s->show_untracked_files)
 		return;
 
+	slog_tid = slog_start_timer("status", "untracked");
+
 	memset(&dir, 0, sizeof(dir));
 	if (s->show_untracked_files != SHOW_ALL_UNTRACKED_FILES)
 		dir.flags |=
@@ -722,6 +740,8 @@ static void wt_status_collect_untracked(struct wt_status *s)
 
 	if (advice_status_u_option)
 		s->untracked_in_ms = (getnanotime() - t_begin) / 1000000;
+
+	slog_stop_timer(slog_tid);
 }
 
 void wt_status_collect(struct wt_status *s)
-- 
2.9.3