Merge trace2 experimental regions

Includes gvfs-specific commits from these pull requests:

	microsoft#158
	microsoft#159
	microsoft#160
	microsoft#164

Signed-off-by: Derrick Stolee <dstolee@microsoft.com>

Author: jeffhostetler

builtin/checkout.c

@@ -13,6 +13,7 @@
 #include "lockfile.h"
 #include "merge-recursive.h"
 #include "object-store.h"
+#include "packfile.h"
 #include "parse-options.h"
 #include "refs.h"
 #include "remote.h"
@@ -951,8 +952,16 @@ static void update_refs_for_switch(const struct checkout_opts *opts,
 	remove_branch_state(the_repository, !opts->quiet);
 	strbuf_release(&msg);
 	if (!opts->quiet &&
-	    (new_branch_info->path || (!opts->force_detach && !strcmp(new_branch_info->name, "HEAD"))))
+	    (new_branch_info->path || (!opts->force_detach && !strcmp(new_branch_info->name, "HEAD")))) {
+		unsigned long nr_unpack_entry_at_start;
+
+		trace2_region_enter("tracking", "report_tracking", the_repository);
+		nr_unpack_entry_at_start = get_nr_unpack_entry();
 		report_tracking(new_branch_info);
+		trace2_data_intmax("tracking", NULL, "report_tracking/nr_unpack_entries",
+				   (intmax_t)(get_nr_unpack_entry() - nr_unpack_entry_at_start));
+		trace2_region_leave("tracking", "report_tracking", the_repository);
+	}
 }
 
 static int add_pending_uninteresting_ref(const char *refname,

builtin/commit.c

@@ -162,6 +162,7 @@ static int opt_parse_porcelain(const struct option *opt, const char *arg, int un
 static int do_serialize = 0;
 static char *serialize_path = NULL;
 
+static int reject_implicit = 0;
 static int do_implicit_deserialize = 0;
 static int do_explicit_deserialize = 0;
 static char *deserialize_path = NULL;
@@ -225,7 +226,7 @@ static int opt_parse_deserialize(const struct option *opt, const char *arg, int
 		}
 		if (!deserialize_path || !*deserialize_path)
 			do_explicit_deserialize = 1; /* read stdin */
-		else if (access(deserialize_path, R_OK) == 0)
+		else if (wt_status_deserialize_access(deserialize_path, R_OK) == 0)
 			do_explicit_deserialize = 1; /* can read from this file */
 		else {
 			/*
@@ -1564,6 +1565,8 @@ static int git_status_config(const char *k, const char *v, void *cb)
 		if (v && *v && access(v, R_OK) == 0) {
 			do_implicit_deserialize = 1;
 			deserialize_path = xstrdup(v);
+		} else {
+			reject_implicit = 1;
 		}
 		return 0;
 	}
@@ -1739,6 +1742,17 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 
 	if (try_deserialize)
 		goto skip_init;
+	/*
+	 * If we implicitly received a status cache pathname from the config
+	 * and the file does not exist, we silently reject it and do the normal
+	 * status "collect".  Fake up some trace2 messages to reflect this and
+	 * assist post-processors know this case is different.
+	 */
+	if (!do_serialize && reject_implicit) {
+		trace2_cmd_mode("implicit-deserialize");
+		trace2_data_string("status", the_repository, "deserialize/reject",
+				   "status-cache/access");
+	}
 
 	enable_fscache(0);
 	if (status_format != STATUS_FORMAT_PORCELAIN &&
@@ -1782,6 +1796,7 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 		if (s.relative_paths)
 			s.prefix = prefix;
 
+		trace2_cmd_mode("deserialize");
 		result = wt_status_deserialize(&s, deserialize_path, dw);
 		if (result == DESERIALIZE_OK)
 			return 0;
@@ -1799,6 +1814,7 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 			fd = -1;
 	}
 
+	trace2_cmd_mode("collect");
 	wt_status_collect(&s);
 
 	if (0 <= fd)
@@ -1813,6 +1829,7 @@ int cmd_status(int argc, const char **argv, const char *prefix)
 		if (fd_serialize < 0)
 			die_errno(_("could not serialize to '%s'"),
 				  serialize_path);
+		trace2_cmd_mode("serialize");
 		wt_status_serialize_v1(fd_serialize, &s);
 		close(fd_serialize);
 	}

cache-tree.c

@@ -224,15 +224,15 @@ static void discard_unused_subtrees(struct cache_tree *it)
 	}
 }
 
-int cache_tree_fully_valid(struct cache_tree *it)
+static int cache_tree_fully_valid_1(struct cache_tree *it)
 {
 	int i;
 	if (!it)
 		return 0;
 	if (it->entry_count < 0 || !has_object_file(&it->oid))
 		return 0;
 	for (i = 0; i < it->subtree_nr; i++) {
-		if (!cache_tree_fully_valid(it->down[i]->cache_tree))
+		if (!cache_tree_fully_valid_1(it->down[i]->cache_tree))
 			return 0;
 	}
 	return 1;
@@ -243,6 +243,17 @@ static int must_check_existence(const struct cache_entry *ce)
 	return !(has_promisor_remote() && ce_skip_worktree(ce));
 }
 
+int cache_tree_fully_valid(struct cache_tree *it)
+{
+	int result;
+
+	trace2_region_enter("cache_tree", "fully_valid", NULL);
+	result = cache_tree_fully_valid_1(it);
+	trace2_region_leave("cache_tree", "fully_valid", NULL);
+
+	return result;
+}
+
 static int update_one(struct cache_tree *it,
 		      struct cache_entry **cache,
 		      int entries,
@@ -797,13 +808,13 @@ void prime_cache_tree(struct repository *r,
 		      struct index_state *istate,
 		      struct tree *tree)
 {
-	trace2_region_enter("cache-tree", "prime_cache_tree", the_repository);
+	trace2_region_enter("cache-tree", "prime_cache_tree", r);
 	cache_tree_free(&istate->cache_tree);
 	istate->cache_tree = cache_tree();
 
 	prime_cache_tree_rec(r, istate->cache_tree, tree);
 	istate->cache_changed |= CACHE_TREE_CHANGED;
-	trace2_region_leave("cache-tree", "prime_cache_tree", the_repository);
+	trace2_region_leave("cache-tree", "prime_cache_tree", r);
 }
 
 /*

compat/mingw.c

@@ -3755,6 +3755,8 @@ int wmain(int argc, const wchar_t **wargv)
 
 	SetConsoleCtrlHandler(handle_ctrl_c, TRUE);
 
+	trace2_initialize_clock();
+
 	maybe_redirect_std_handles();
 	adjust_symlink_flags();
 	fsync_object_files = FSYNC_OBJECT_FILES_ON;

object-file.c

@@ -979,6 +979,8 @@ static int read_object_process(const struct object_id *oid)
 
 	start = getnanotime();
 
+	trace2_region_enter("subprocess", "read_object", the_repository);
+
 	if (!subprocess_map_initialized) {
 		subprocess_map_initialized = 1;
 		hashmap_init(&subprocess_map, (hashmap_cmp_fn)cmd2process_cmp,
@@ -995,13 +997,16 @@ static int read_object_process(const struct object_id *oid)
 		if (subprocess_start(&subprocess_map, &entry->subprocess, cmd,
 				     start_read_object_fn)) {
 			free(entry);
-			return -1;
+			err = -1;
+			goto leave_region;
 		}
 	}
 	process = &entry->subprocess.process;
 
-	if (!(CAP_GET & entry->supported_capabilities))
-		return -1;
+	if (!(CAP_GET & entry->supported_capabilities)) {
+		err = -1;
+		goto leave_region;
+	}
 
 	sigchain_push(SIGPIPE, SIG_IGN);
 
@@ -1050,6 +1055,10 @@ static int read_object_process(const struct object_id *oid)
 
 	trace_performance_since(start, "read_object_process");
 
+leave_region:
+	trace2_region_leave_printf("subprocess", "read_object", the_repository,
+				   "result %d", err);
+
 	return err;
 }
 

packfile.c

@@ -1662,6 +1662,13 @@ static void *read_object(struct repository *r,
 	return content;
 }
 
+static unsigned long g_nr_unpack_entry;
+
+unsigned long get_nr_unpack_entry(void)
+{
+	return g_nr_unpack_entry;
+}
+
 void *unpack_entry(struct repository *r, struct packed_git *p, off_t obj_offset,
 		   enum object_type *final_type, unsigned long *final_size)
 {
@@ -1675,6 +1682,8 @@ void *unpack_entry(struct repository *r, struct packed_git *p, off_t obj_offset,
 	int delta_stack_nr = 0, delta_stack_alloc = UNPACK_ENTRY_STACK_PREALLOC;
 	int base_from_cache = 0;
 
+	g_nr_unpack_entry++;
+
 	write_pack_access_log(p, obj_offset);
 
 	/* PHASE 1: drill down to the innermost base object */

packfile.h

@@ -196,4 +196,9 @@ int is_promisor_object(const struct object_id *oid);
 int load_idx(const char *path, const unsigned int hashsz, void *idx_map,
 	     size_t idx_size, struct packed_git *p);
 
+/*
+ * Return the number of objects fetched from a packfile.
+ */
+unsigned long get_nr_unpack_entry(void);
+
 #endif

read-cache.c

@@ -1819,7 +1819,10 @@ static int read_index_extension(struct index_state *istate,
 {
 	switch (CACHE_EXT(ext)) {
 	case CACHE_EXT_TREE:
+		trace2_region_enter("index", "read/extension/cache_tree", NULL);
 		istate->cache_tree = cache_tree_read(data, sz);
+		trace2_data_intmax("index", NULL, "read/extension/cache_tree/bytes", (intmax_t)sz);
+		trace2_region_leave("index", "read/extension/cache_tree", NULL);
 		break;
 	case CACHE_EXT_RESOLVE_UNDO:
 		istate->resolve_undo = resolve_undo_read(data, sz);
@@ -2087,6 +2090,17 @@ static void *load_index_extensions(void *_data)
 	return NULL;
 }
 
+static void *load_index_extensions_threadproc(void *_data)
+{
+	void *result;
+
+	trace2_thread_start("load_index_extensions");
+	result = load_index_extensions(_data);
+	trace2_thread_exit();
+
+	return result;
+}
+
 /*
  * A helper function that will load the specified range of cache entries
  * from the memory mapped file and add them to the given index.
@@ -2163,12 +2177,17 @@ static void *load_cache_entries_thread(void *_data)
 	struct load_cache_entries_thread_data *p = _data;
 	int i;
 
+	trace2_thread_start("load_cache_entries");
+
 	/* iterate across all ieot blocks assigned to this thread */
 	for (i = p->ieot_start; i < p->ieot_start + p->ieot_blocks; i++) {
 		p->consumed += load_cache_entry_block(p->istate, p->ce_mem_pool,
 			p->offset, p->ieot->entries[i].nr, p->mmap, p->ieot->entries[i].offset, NULL);
 		p->offset += p->ieot->entries[i].nr;
 	}
+
+	trace2_thread_exit();
+
 	return NULL;
 }
 
@@ -2321,7 +2340,7 @@ int do_read_index(struct index_state *istate, const char *path, int must_exist)
 			int err;
 
 			p.src_offset = extension_offset;
-			err = pthread_create(&p.pthread, NULL, load_index_extensions, &p);
+			err = pthread_create(&p.pthread, NULL, load_index_extensions_threadproc, &p);
 			if (err)
 				die(_("unable to create load_index_extensions thread: %s"), strerror(err));
 
@@ -3018,9 +3037,13 @@ static int do_write_index(struct index_state *istate, struct tempfile *tempfile,
 	if (!strip_extensions && !drop_cache_tree && istate->cache_tree) {
 		struct strbuf sb = STRBUF_INIT;
 
+		trace2_region_enter("index", "write/extension/cache_tree", NULL);
 		cache_tree_write(&sb, istate->cache_tree);
 		err = write_index_ext_header(f, eoie_c, CACHE_EXT_TREE, sb.len) < 0;
 		hashwrite(f, sb.buf, sb.len);
+		trace2_data_intmax("index", NULL, "write/extension/cache_tree/bytes", (intmax_t)sb.len);
+		trace2_region_leave("index", "write/extension/cache_tree", NULL);
+
 		strbuf_release(&sb);
 		if (err)
 			return -1;

remote.c

@@ -2106,7 +2106,16 @@ int format_tracking_info(struct branch *branch, struct strbuf *sb,
 	char *base;
 	int upstream_is_gone = 0;
 
+	trace2_region_enter("tracking", "stat_tracking_info", NULL);
 	sti = stat_tracking_info(branch, &ours, &theirs, &full_base, 0, abf);
+	trace2_data_intmax("tracking", NULL, "stat_tracking_info/ab_flags", abf);
+	trace2_data_intmax("tracking", NULL, "stat_tracking_info/ab_result", sti);
+	if (sti >= 0 && abf == AHEAD_BEHIND_FULL) {
+	    trace2_data_intmax("tracking", NULL, "stat_tracking_info/ab_ahead", ours);
+	    trace2_data_intmax("tracking", NULL, "stat_tracking_info/ab_behind", theirs);
+	}
+	trace2_region_leave("tracking", "stat_tracking_info", NULL);
+
 	if (sti < 0) {
 		if (!full_base)
 			return 0;

trace2/tr2_tgt_event.c

@@ -33,7 +33,7 @@ static struct tr2_dst tr2dst_event = { TR2_SYSENV_EVENT, 0, 0, 0, 0 };
  * event target.  Use the TR2_SYSENV_EVENT_NESTING setting to increase
  * region details in the event target.
  */
-static int tr2env_event_max_nesting_levels = 2;
+static int tr2env_event_max_nesting_levels = 4;
 
 /*
  * Use the TR2_SYSENV_EVENT_BRIEF to omit the <time>, <file>, and