From d74af51fa18a2448736186f70853372f234aa418 Mon Sep 17 00:00:00 2001 From: Oswald Buddenhagen Date: Tue, 1 Mar 2022 15:16:07 +0100 Subject: [PATCH] rework interrupt-resume autotesting instead of doing two runs for each journal entry, do one run for each "write" operation, be it a journal entry or a writing driver call. this saves runs between which no visible change occurred, which yields a 33% improvement in runtime. we now also exclude the final entry purge from the test, as it's really kinda pointless, and we'd have to jump through additional hoops (simulate an atomic commit of the state) to make it reliable in all cases. note that this also adds a few steps, which actually uncovered a bug in the expunge sequencing. amends efd72b85. --- src/common.h | 3 ++- src/drv_proxy.c | 10 ++++++++++ src/drv_proxy_gen.pl | 8 +++++++- src/main.c | 7 +++++++ src/run-tests.pl | 21 ++++++++++++++++----- src/sync.c | 12 +++++++++--- src/sync_state.c | 6 ++---- src/util.c | 2 +- 8 files changed, 54 insertions(+), 15 deletions(-) diff --git a/src/common.h b/src/common.h index 09883e5..bb557e6 100644 --- a/src/common.h +++ b/src/common.h @@ -124,7 +124,7 @@ BIT_ENUM( // Global options extern int Verbosity; extern int DFlags; -extern int JLimit; +extern int JLimit, JCount; extern int UseFSync; // Global constants (inited by main()) @@ -132,6 +132,7 @@ extern int Pid; extern char Hostname[256]; extern const char *Home; +void countStep( void ); void stats( void ); /* util.c */ diff --git a/src/drv_proxy.c b/src/drv_proxy.c index 0713cd7..0cca3a5 100644 --- a/src/drv_proxy.c +++ b/src/drv_proxy.c @@ -212,6 +212,7 @@ proxy_@name@_cb( @decl_cb_args@void *aux ) @name@_cmd_t *cmd = (@name@_cmd_t *)aux; proxy_store_t *ctx = cmd->ctx; + @count_step@ @print_cb_args_tpl@ cmd->callback( @pass_cb_args@cmd->callback_aux ); debug( "%s[% 2d] Callback leave @name@\n", ctx->label, cmd->tag ); @@ -251,6 +252,10 @@ static @type@proxy_@name@( store_t *gctx@decl_args@, void (*cb)( @decl_cb_args@v debug( " %s\n", box->string ); //# END +//# DEFINE create_box_counted 1 + +//# DEFINE delete_box_counted 1 + //# DEFINE prepare_load_box_print_fmt_args , opts=%s //# DEFINE prepare_load_box_print_pass_args , fmt_opts( opts ).str //# DEFINE prepare_load_box_print_fmt_ret %s @@ -313,13 +318,18 @@ static @type@proxy_@name@( store_t *gctx@decl_args@, void (*cb)( @decl_cb_args@v fflush( stdout ); } //# END +//# DEFINE store_msg_counted 1 //# DEFINE set_msg_flags_checked 1 //# DEFINE set_msg_flags_print_fmt_args , uid=%u, add=%s, del=%s //# DEFINE set_msg_flags_print_pass_args , cmd->uid, fmt_flags( cmd->add ).str, fmt_flags( cmd->del ).str +//# DEFINE set_msg_flags_counted 1 //# DEFINE trash_msg_print_fmt_args , uid=%u //# DEFINE trash_msg_print_pass_args , cmd->msg->uid +//# DEFINE trash_msg_counted 1 + +//# DEFINE close_box_counted 1 //# DEFINE commit_cmds_print_args proxy_flush_checked_cmds( ctx ); diff --git a/src/drv_proxy_gen.pl b/src/drv_proxy_gen.pl index d3388d9..3fda58c 100755 --- a/src/drv_proxy_gen.pl +++ b/src/drv_proxy_gen.pl @@ -176,7 +176,13 @@ for (@ptypes) { $replace{'print_fmt_args'} = make_format($cmd_args); } for (keys %defines) { - $replace{$1} = delete $defines{$_} if (/^${cmd_name}_(.*)$/); + next if (!/^${cmd_name}_(.*)$/); + my ($key, $val) = ($1, delete $defines{$_}); + if ($key eq 'counted') { + $replace{count_step} = "countStep();\n"; + } else { + $replace{$key} = $val; + } } my %used; my $text = $templates{$template}; diff --git a/src/main.c b/src/main.c index 3c1deae..892af95 100644 --- a/src/main.c +++ b/src/main.c @@ -132,6 +132,13 @@ crashHandler( int n ) } #endif +void +countStep( void ) +{ + if (!--JLimit) + exit( 100 ); +} + int main( int argc, char **argv ) { diff --git a/src/run-tests.pl b/src/run-tests.pl index da488ce..ef9f5e0 100755 --- a/src/run-tests.pl +++ b/src/run-tests.pl @@ -783,10 +783,19 @@ sub test_impl($$$$) exit 1; } - my ($nj, $njl) = (undef, 0); + my ($nj, $njl, $nje) = (undef, 0, 0); if ($$rtx{state} != $$sx{state}) { $nj = readfile("near/.mbsyncstate.journal"); - $njl = (@$nj - 1) * 2; + STEPS: { + for (reverse @$ret) { + if (/^### (\d+) steps, (\d+) entries ###$/) { + $njl = int($1) - 1; + $nje = int($2); + last STEPS; + } + } + die("Cannot extract step count.\n"); + } my ($jxc, $jret) = runsync($async, "-0 --no-expunge", "2-replay.log"); my $jrcs = readstate() if (!$jxc); @@ -835,13 +844,15 @@ sub test_impl($$$$) mkchan($sx); my ($nxc, $nret) = runsync($async, "-Ts$l", "4-interrupt.log"); - if ($nxc != (100 + ($l & 1)) << 8) { + if ($nxc != 100 << 8) { print "Interrupting at step $l/$njl failed.\n"; print "Debug output:\n"; print @$nret; exit 1; } + my $pnnj = readfile("near/.mbsyncstate.journal"); + ($nxc, $nret) = runsync($async, "-Tj", "5-resume.log"); my $nrtx = readchan($$sx{state}) if (!$nxc); if ($nxc || cmpchan($nrtx, $tx)) { @@ -851,9 +862,9 @@ sub test_impl($$$$) print "Options:\n"; print " [ ".join(", ", map('"'.qm($_).'"', @$sfx))." ]\n"; my $nnj = readfile("near/.mbsyncstate.journal"); - my $ln = int($l / 2); + my $ln = $#$pnnj; print "Journal:\n".join("", @$nnj[0..$ln])."-------\n".join("", @$nnj[($ln + 1)..$#$nnj])."\n"; - print "Full journal:\n".join("", @$nj)."\n"; + print "Full journal:\n".join("", @$nj[0..$nje])."=======\n".join("", @$nj[($nje + 1)..$#$nj])."\n"; if (!$nxc) { print "Expected result:\n"; printchan($tx); diff --git a/src/sync.c b/src/sync.c index 2e84283..9c43ad1 100644 --- a/src/sync.c +++ b/src/sync.c @@ -1719,9 +1719,15 @@ box_closed_p2( sync_vars_t *svars, int t ) if (!(svars->state[t^1] & ST_CLOSED)) return; - // All the journalling done in this function is merely for the autotest - - // the operations are idempotent, and we're about to commit the new state - // right afterwards anyway. + // All logging done in this function is merely for the journal replay + // autotest - the operations are idempotent, and we're about to commit + // the new state right afterwards anyway. Therefore, it would also + // make no sense to cover it by the interrupt-resume autotest (which + // would also add unreasonable complexity, as the maxuid bumps and entry + // purge must be consistent). + + if (DFlags & KEEPJOURNAL) + printf( "### %d steps, %d entries ###\n", -JLimit, JCount ); for (t = 0; t < 2; t++) { // Committing maxuid is delayed until all messages were propagated, to diff --git a/src/sync_state.c b/src/sync_state.c index 7887846..52935e4 100644 --- a/src/sync_state.c +++ b/src/sync_state.c @@ -439,8 +439,6 @@ jFprintf( sync_vars_t *svars, const char *msg, ... ) { va_list va; - if (JLimit && !--JLimit) - exit( 101 ); if (!svars->jfp) { create_state( svars ); if (!(svars->jfp = fopen( svars->jname, svars->replayed ? "a" : "w" ))) { @@ -454,8 +452,8 @@ jFprintf( sync_vars_t *svars, const char *msg, ... ) va_start( va, msg ); vFprintf( svars->jfp, msg, va ); va_end( va ); - if (JLimit && !--JLimit) - exit( 100 ); + countStep(); + JCount++; } void diff --git a/src/util.c b/src/util.c index 7654b13..fc8d1d6 100644 --- a/src/util.c +++ b/src/util.c @@ -15,7 +15,7 @@ int Verbosity = TERSE; int DFlags; -int JLimit; +int JLimit, JCount; int UseFSync = 1; int Pid;