gvfs:trace2:data: status deserialization information

Add trace2 region and data events describing attempts to deserialize
status data using a status cache.

A category:status, label:deserialize region is pushed around the
deserialize code.

Deserialization results when reading from a file are:
    category:status, path   = <path>
    category:status, polled = <number_of_attempts>
    category:status, result = "ok" | "reject"

When reading from STDIN are:
    category:status, path   = "STDIN"
    category:status, result = "ok" | "reject"

Status will fallback and run a normal status scan when a "reject"
is reported (unless "--deserialize-wait=fail").

If "ok" is reported, status was able to use the status cache and
avoid scanning the workdir.

Additionally, a cmd_mode is emitted for each step: collection,
deserialization, and serialization.  For example, if deserialization
is attempted and fails and status falls back to actually computing
the status, a cmd_mode message containing "deserialize" is issued
and then a cmd_mode for "collect" is issued.

Also, if deserialization fails, a data message containing the
rejection reason is emitted.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
This commit is contained in:
Jeff Hostetler 2018-09-26 11:21:22 -04:00 коммит произвёл Johannes Schindelin
Родитель d8a0437e5b
Коммит e2283ac458
3 изменённых файлов: 82 добавлений и 5 удалений

Просмотреть файл

@ -163,6 +163,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;
@ -226,7 +227,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;
}
@ -1718,6 +1721,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 &&
@ -1761,6 +1775,7 @@ skip_init:
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;
@ -1778,6 +1793,7 @@ skip_init:
fd = -1;
}
trace2_cmd_mode("collect");
wt_status_collect(&s);
if (0 <= fd)
@ -1792,6 +1808,7 @@ skip_init:
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);
}

Просмотреть файл

@ -3,6 +3,22 @@
#include "pkt-line.h"
#include "trace.h"
static void set_deserialize_reject_reason(const char *reason)
{
trace2_data_string("status", the_repository, "deserialize/reject",
reason);
}
int wt_status_deserialize_access(const char *path, int mode)
{
int a = access(path, mode);
if (a != 0)
set_deserialize_reject_reason("status-cache/access");
return a;
}
static struct trace_key trace_deserialize = TRACE_KEY_INIT(DESERIALIZE);
enum deserialize_parse_strategy {
@ -49,6 +65,7 @@ static int my_validate_index(const struct cache_time *mtime_reported)
struct cache_time mtime_observed_on_disk;
if (lstat(path, &st)) {
set_deserialize_reject_reason("index/not-found");
trace_printf_key(&trace_deserialize, "could not stat index");
return DESERIALIZE_ERR;
}
@ -56,6 +73,7 @@ static int my_validate_index(const struct cache_time *mtime_reported)
mtime_observed_on_disk.nsec = ST_MTIME_NSEC(st);
if ((mtime_observed_on_disk.sec != mtime_reported->sec) ||
(mtime_observed_on_disk.nsec != mtime_reported->nsec)) {
set_deserialize_reject_reason("index/mtime-changed");
trace_printf_key(&trace_deserialize,
"index mtime changed [des %d %d][obs %d %d]",
mtime_reported->sec, mtime_reported->nsec,
@ -81,10 +99,12 @@ static int my_validate_excludes(const char *path, const char *key, const char *l
r = (strcmp(line, sb.buf) ? DESERIALIZE_ERR : DESERIALIZE_OK);
if (r == DESERIALIZE_ERR)
if (r == DESERIALIZE_ERR) {
set_deserialize_reject_reason("excludes/changed");
trace_printf_key(&trace_deserialize,
"%s changed [cached '%s'][observed '%s']",
key, line, sb.buf);
}
strbuf_release(&sb);
return r;
@ -140,6 +160,7 @@ static int wt_deserialize_v1_header(struct wt_status *s, int fd)
&index_mtime.sec,
&index_mtime.nsec);
if (nr_fields != 2) {
set_deserialize_reject_reason("v1-header/invalid-index-mtime");
trace_printf_key(&trace_deserialize, "invalid index_mtime (%d) '%s'",
nr_fields, line);
return DESERIALIZE_ERR;
@ -223,6 +244,7 @@ static int wt_deserialize_v1_header(struct wt_status *s, int fd)
/* status_format */
if (skip_prefix(line, "sha1_commit ", &arg)) {
if (get_oid_hex(arg, &s->oid_commit)) {
set_deserialize_reject_reason("v1-header/invalid-commit-sha");
trace_printf_key(&trace_deserialize, "invalid sha1_commit");
return DESERIALIZE_ERR;
}
@ -238,19 +260,23 @@ static int wt_deserialize_v1_header(struct wt_status *s, int fd)
}
/* prefix */
set_deserialize_reject_reason("v1-header/unexpected-line");
trace_printf_key(&trace_deserialize, "unexpected line '%s'", line);
return DESERIALIZE_ERR;
}
if (!have_required_index_mtime) {
set_deserialize_reject_reason("v1-header/missing-index-mtime");
trace_printf_key(&trace_deserialize, "missing '%s'", "index_mtime");
return DESERIALIZE_ERR;
}
if (!have_required_core_excludes) {
set_deserialize_reject_reason("v1-header/missing-core-excludes");
trace_printf_key(&trace_deserialize, "missing '%s'", "core_excludes");
return DESERIALIZE_ERR;
}
if (!have_required_repo_excludes) {
set_deserialize_reject_reason("v1-header/missing-repo-excludes");
trace_printf_key(&trace_deserialize, "missing '%s'", "repo_excludes");
return DESERIALIZE_ERR;
}
@ -337,6 +363,7 @@ static int wt_deserialize_v1_changed_items(const struct wt_status *cmd_s,
* So we reject the status cache and let the fallback
* code run.
*/
set_deserialize_reject_reason("v1-data/unmerged");
trace_printf_key(
&trace_deserialize,
"reject: V2 format and umerged file: %s",
@ -478,6 +505,7 @@ static int wt_deserialize_v1(const struct wt_status *cmd_s, struct wt_status *s,
* the serialized data
*/
if (validate_untracked_files_arg(cmd_s->show_untracked_files, &s->show_untracked_files, &untracked_strategy)) {
set_deserialize_reject_reason("args/untracked-files");
trace_printf_key(&trace_deserialize, "reject: show_untracked_file: command: %d, serialized : %d",
cmd_s->show_untracked_files,
s->show_untracked_files);
@ -485,6 +513,7 @@ static int wt_deserialize_v1(const struct wt_status *cmd_s, struct wt_status *s,
}
if (validate_ignored_files_arg(cmd_s->show_ignored_mode, s->show_ignored_mode, &ignored_strategy)) {
set_deserialize_reject_reason("args/ignored-mode");
trace_printf_key(&trace_deserialize, "reject: show_ignored_mode: command: %d, serialized: %d",
cmd_s->show_ignored_mode,
s->show_ignored_mode);
@ -518,6 +547,7 @@ static int wt_deserialize_v1(const struct wt_status *cmd_s, struct wt_status *s,
return DESERIALIZE_ERR;
continue;
}
set_deserialize_reject_reason("v1-data/unexpected-line");
trace_printf_key(&trace_deserialize, "unexpected line '%s'", line);
return DESERIALIZE_ERR;
}
@ -539,6 +569,7 @@ static int wt_deserialize_parse(const struct wt_status *cmd_s, struct wt_status
if (version == 1)
return wt_deserialize_v1(cmd_s, s, fd);
}
set_deserialize_reject_reason("status-cache/unsupported-version");
trace_printf_key(&trace_deserialize, "missing/unsupported version");
return DESERIALIZE_ERR;
}
@ -559,6 +590,7 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
* Check the path spec on the current command
*/
if (cmd_s->pathspec.nr > 1) {
set_deserialize_reject_reason("args/multiple-pathspecs");
trace_printf_key(&trace_deserialize, "reject: multiple pathspecs");
return DESERIALIZE_ERR;
}
@ -569,6 +601,7 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
*/
if (cmd_s->pathspec.nr == 1 &&
my_strcmp_null(cmd_s->pathspec.items[0].match, "")) {
set_deserialize_reject_reason("args/root-pathspec");
trace_printf_key(&trace_deserialize, "reject: pathspec");
return DESERIALIZE_ERR;
}
@ -585,20 +618,24 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
* or "--ignored" settings).
*/
if (cmd_s->is_initial != des_s->is_initial) {
set_deserialize_reject_reason("args/is-initial-changed");
trace_printf_key(&trace_deserialize, "reject: is_initial");
return DESERIALIZE_ERR;
}
if (my_strcmp_null(cmd_s->branch, des_s->branch)) {
set_deserialize_reject_reason("args/branch-changed");
trace_printf_key(&trace_deserialize, "reject: branch");
return DESERIALIZE_ERR;
}
if (my_strcmp_null(cmd_s->reference, des_s->reference)) {
set_deserialize_reject_reason("args/reference-changed");
trace_printf_key(&trace_deserialize, "reject: reference");
return DESERIALIZE_ERR;
}
/* verbose */
/* amend */
if (cmd_s->whence != des_s->whence) {
set_deserialize_reject_reason("args/whence-changed");
trace_printf_key(&trace_deserialize, "reject: whence");
return DESERIALIZE_ERR;
}
@ -632,19 +669,23 @@ static int wt_deserialize_fd(const struct wt_status *cmd_s, struct wt_status *de
/* hints */
/* ahead_behind_flags */
if (cmd_s->detect_rename != des_s->detect_rename) {
set_deserialize_reject_reason("args/detect-rename-changed");
trace_printf_key(&trace_deserialize, "reject: detect_rename");
return DESERIALIZE_ERR;
}
if (cmd_s->rename_score != des_s->rename_score) {
set_deserialize_reject_reason("args/rename-score-changed");
trace_printf_key(&trace_deserialize, "reject: rename_score");
return DESERIALIZE_ERR;
}
if (cmd_s->rename_limit != des_s->rename_limit) {
set_deserialize_reject_reason("args/rename-limit-changed");
trace_printf_key(&trace_deserialize, "reject: rename_limit");
return DESERIALIZE_ERR;
}
/* status_format */
if (!oideq(&cmd_s->oid_commit, &des_s->oid_commit)) {
set_deserialize_reject_reason("args/commit-changed");
trace_printf_key(&trace_deserialize, "reject: sha1_commit");
return DESERIALIZE_ERR;
}
@ -733,15 +774,18 @@ static int try_deserialize_read_from_file(const struct wt_status *cmd_s,
enum wt_status_deserialize_wait dw,
struct wt_status *des_s)
{
int k, limit;
int k = 0;
int limit;
int result = DESERIALIZE_ERR;
/*
* For "fail" or "no", try exactly once to read the status cache.
* Return an error if the file is stale.
*/
if (dw == DESERIALIZE_WAIT__FAIL || dw == DESERIALIZE_WAIT__NO)
return try_deserialize_read_from_file_1(cmd_s, path, des_s);
if (dw == DESERIALIZE_WAIT__FAIL || dw == DESERIALIZE_WAIT__NO) {
result = try_deserialize_read_from_file_1(cmd_s, path, des_s);
goto done;
}
/*
* Wait for the status cache file to refresh. Wait duration can
@ -766,6 +810,12 @@ static int try_deserialize_read_from_file(const struct wt_status *cmd_s,
sleep_millisec(100);
}
done:
trace2_data_string("status", the_repository, "deserialize/path", path);
trace2_data_intmax("status", the_repository, "deserialize/polled", k);
trace2_data_string("status", the_repository, "deserialize/result",
((result == DESERIALIZE_OK) ? "ok" : "reject"));
trace_printf_key(&trace_deserialize,
"wait polled=%d result=%d '%s'",
k, result, path);
@ -791,6 +841,8 @@ int wt_status_deserialize(const struct wt_status *cmd_s,
struct wt_status des_s;
int result;
trace2_region_enter("status", "deserialize", the_repository);
if (path && *path && strcmp(path, "0")) {
result = try_deserialize_read_from_file(cmd_s, path, dw, &des_s);
} else {
@ -801,8 +853,14 @@ int wt_status_deserialize(const struct wt_status *cmd_s,
* term, since we cannot read stdin multiple times.
*/
result = wt_deserialize_fd(cmd_s, &des_s, 0);
trace2_data_string("status", the_repository, "deserialize/path", "STDIN");
trace2_data_string("status", the_repository, "deserialize/result",
((result == DESERIALIZE_OK) ? "ok" : "reject"));
}
trace2_region_leave("status", "deserialize", the_repository);
if (result == DESERIALIZE_OK) {
wt_status_get_state(cmd_s->repo, &des_s.state, des_s.branch &&
!strcmp(des_s.branch, "HEAD"));

Просмотреть файл

@ -243,6 +243,8 @@ int wt_status_deserialize(const struct wt_status *cmd_s,
const char *path,
enum wt_status_deserialize_wait dw);
int wt_status_deserialize_access(const char *path, int mode);
/*
* A helper routine for serialize and deserialize to compute
* metadata for the user-global and repo-local excludes files.