introduce driver call debugging

do that by wrapping the actual stores into proxies.

the proxy driver's code is auto-generated from function templates, some
parameters, and the declarations of the driver functions themselves.
attempts to do it with CPP macros turned out to be a nightmare.

src/.gitignore

@@ -1,3 +1,4 @@
+/drv_proxy.inc
 /mbsync
 /mdconvert
 /tst_timers

src/Makefile.am

@@ -3,10 +3,14 @@ compat_dir = compat
 endif
 SUBDIRS = $(compat_dir)
 
-mbsync_SOURCES = main.c sync.c config.c util.c socket.c driver.c drv_imap.c drv_maildir.c
+mbsync_SOURCES = main.c sync.c config.c util.c socket.c driver.c drv_imap.c drv_maildir.c drv_proxy.c
 mbsync_LDADD = $(DB_LIBS) $(SSL_LIBS) $(SOCK_LIBS) $(SASL_LIBS) $(Z_LIBS)
 noinst_HEADERS = common.h config.h driver.h sync.h socket.h
 
+drv_proxy.$(OBJEXT): drv_proxy.inc
+drv_proxy.inc: $(srcdir)/driver.h $(srcdir)/drv_proxy.c $(srcdir)/drv_proxy_gen.pl
+	perl $(srcdir)/drv_proxy_gen.pl $(srcdir)/driver.h $(srcdir)/drv_proxy.c drv_proxy.inc
+
 mdconvert_SOURCES = mdconvert.c
 mdconvert_LDADD = $(DB_LIBS)
 if with_mdconvert
@@ -24,4 +28,6 @@ man_MANS = mbsync.1 $(mdconvert_man)
 exampledir = $(docdir)/examples
 example_DATA = mbsyncrc.sample
 
-EXTRA_DIST = run-tests.pl $(example_DATA) $(man_MANS)
+EXTRA_DIST = drv_proxy_gen.pl run-tests.pl $(example_DATA) $(man_MANS)
+
+CLEANFILES = drv_proxy.inc

src/common.h

@@ -70,7 +70,9 @@ typedef unsigned int uint;
 #define DEBUG_NET_ALL   0x08
 #define DEBUG_SYNC      0x10
 #define DEBUG_MAIN      0x20
-#define DEBUG_ALL       (0xFF & ~DEBUG_NET_ALL)
+#define DEBUG_DRV       0x40
+#define DEBUG_DRV_ALL   0x80
+#define DEBUG_ALL       (0xFF & ~(DEBUG_NET_ALL | DEBUG_DRV_ALL))
 #define QUIET           0x100
 #define VERYQUIET       0x200
 #define PROGRESS        0x400

src/driver.h

@@ -87,6 +87,7 @@ typedef struct message {
 
 typedef struct store {
 	struct store *next;
+	driver_t *driver;
 	store_conf_t *conf; /* foreign */
 } store_t;
 
@@ -124,9 +125,11 @@ typedef struct {
 #define LIST_PATH       2
 #define LIST_PATH_MAYBE 4
 
+#define xint int  // For auto-generation of appropriate printf() formats.
+
 struct driver {
 	/* Return driver capabilities. */
-	int (*get_caps)( store_t *ctx );
+	xint (*get_caps)( store_t *ctx );
 
 	/* Parse configuration. */
 	int (*parse_store)( conffile_t *cfg, store_conf_t **storep );
@@ -192,7 +195,7 @@ struct driver {
 	/* Invoked before load_box(), this informs the driver which operations (OP_*)
 	 * will be performed on the mailbox. The driver may extend the set by implicitly
 	 * needed or available operations. Returns this possibly extended set. */
-	int (*prepare_load_box)( store_t *ctx, int opts );
+	xint (*prepare_load_box)( store_t *ctx, xint opts );
 
 	/* Load the message attributes needed to perform the requested operations.
 	 * Consider only messages with UIDs between minuid and maxuid (inclusive)
@@ -260,8 +263,10 @@ void free_generic_messages( message_t * );
 
 void parse_generic_store( store_conf_t *store, conffile_t *cfg );
 
+store_t *proxy_alloc_store( store_t *real_ctx, const char *label );
+
 #define N_DRIVERS 2
 extern driver_t *drivers[N_DRIVERS];
-extern driver_t maildir_driver, imap_driver;
+extern driver_t maildir_driver, imap_driver, proxy_driver;
 
 #endif

src/drv_imap.c

@@ -1708,6 +1708,7 @@ imap_alloc_store( store_conf_t *conf, const char *label )
 	ctx->pending_append = &ctx->pending;
 
   gotsrv:
+	ctx->gen.driver = &imap_driver;
 	ctx->gen.conf = conf;
 	ctx->label = label;
 	ctx->ref_count = 1;

src/drv_maildir.c

@@ -226,6 +226,7 @@ maildir_alloc_store( store_conf_t *gconf, const char *label ATTR_UNUSED )
 	maildir_store_t *ctx;
 
 	ctx = nfcalloc( sizeof(*ctx) );
+	ctx->gen.driver = &maildir_driver;
 	ctx->gen.conf = gconf;
 	ctx->uvfd = -1;
 	init_wakeup( &ctx->lcktmr, lcktmr_timeout, ctx );

src/drv_proxy.c

@@ -0,0 +1,335 @@
+/*
+ * mbsync - mailbox synchronizer
+ * Copyright (C) 2017 Oswald Buddenhagen <ossi@users.sf.net>
+ *
+ *  This program is free software; you can redistribute it and/or modify
+ *  it under the terms of the GNU General Public License as published by
+ *  the Free Software Foundation; either version 2 of the License, or
+ *  (at your option) any later version.
+ *
+ *  This program is distributed in the hope that it will be useful,
+ *  but WITHOUT ANY WARRANTY; without even the implied warranty of
+ *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ *  GNU General Public License for more details.
+ *
+ *  You should have received a copy of the GNU General Public License
+ *  along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ *
+ * As a special exception, mbsync may be linked with the OpenSSL library,
+ * despite that library's more restrictive license.
+ */
+
+#include "driver.h"
+
+#include <limits.h>
+#include <stdlib.h>
+
+typedef struct {
+	store_t gen;
+	const char *label; // foreign
+	int ref_count;
+	driver_t *real_driver;
+	store_t *real_store;
+
+	void (*bad_callback)( void *aux );
+	void *bad_callback_aux;
+} proxy_store_t;
+
+static void ATTR_PRINTFLIKE(1, 2)
+debug( const char *msg, ... )
+{
+	va_list va;
+
+	va_start( va, msg );
+	vdebug( DEBUG_DRV, msg, va );
+	va_end( va );
+}
+
+static void ATTR_PRINTFLIKE(1, 2)
+debugn( const char *msg, ... )
+{
+	va_list va;
+
+	va_start( va, msg );
+	vdebugn( DEBUG_DRV, msg, va );
+	va_end( va );
+}
+
+static const char Flags[] = { 'D', 'F', 'R', 'S', 'T' };
+
+static char *
+proxy_make_flags( int flags, char *buf )
+{
+	uint i, d;
+
+	for (d = 0, i = 0; i < as(Flags); i++)
+		if (flags & (1 << i))
+			buf[d++] = Flags[i];
+	buf[d] = 0;
+	return buf;
+}
+
+static void
+proxy_store_deref( proxy_store_t *ctx )
+{
+	if (!--ctx->ref_count)
+		free( ctx );
+}
+
+static int curr_tag;
+
+typedef struct {
+	int ref_count;
+	int tag;
+	proxy_store_t *ctx;
+} gen_cmd_t;
+
+static gen_cmd_t *
+proxy_cmd_new( proxy_store_t *ctx, int sz )
+{
+	gen_cmd_t *cmd = nfmalloc( sz );
+	cmd->ref_count = 2;
+	cmd->tag = ++curr_tag;
+	cmd->ctx = ctx;
+	ctx->ref_count++;
+	return cmd;
+}
+
+static void
+proxy_cmd_done( gen_cmd_t *cmd )
+{
+	if (!--cmd->ref_count) {
+		proxy_store_deref( cmd->ctx );
+		free( cmd );
+	}
+}
+
+#if 0
+//# TEMPLATE GETTER
+static @type@proxy_@name@( store_t *gctx )
+{
+	proxy_store_t *ctx = (proxy_store_t *)gctx;
+
+	@type@rv = ctx->real_driver->@name@( ctx->real_store );
+	debug( "%sCalled @name@, ret=@fmt@\n", ctx->label, rv );
+	return rv;
+}
+//# END
+
+//# TEMPLATE REGULAR
+static @type@proxy_@name@( store_t *gctx@decl_args@ )
+{
+	proxy_store_t *ctx = (proxy_store_t *)gctx;
+
+	@pre_print_args@
+	debug( "%sEnter @name@@print_fmt_args@\n", ctx->label@print_pass_args@ );
+	@print_args@
+	@type@rv = ctx->real_driver->@name@( ctx->real_store@pass_args@ );
+	debug( "%sLeave @name@, ret=@fmt@\n", ctx->label, rv );
+	return rv;
+}
+//# END
+
+//# TEMPLATE REGULAR_VOID
+static void proxy_@name@( store_t *gctx@decl_args@ )
+{
+	proxy_store_t *ctx = (proxy_store_t *)gctx;
+
+	@pre_print_args@
+	debug( "%sEnter @name@@print_fmt_args@\n", ctx->label@print_pass_args@ );
+	@print_args@
+	ctx->real_driver->@name@( ctx->real_store@pass_args@ );
+	debug( "%sLeave @name@\n", ctx->label );
+	@action@
+}
+//# END
+
+//# TEMPLATE CALLBACK
+typedef struct {
+	gen_cmd_t gen;
+	void (*callback)( @decl_cb_args@void *aux );
+	void *callback_aux;
+	@decl_state@
+} @name@_cmd_t;
+
+static void
+proxy_@name@_cb( @decl_cb_args@void *aux )
+{
+	@name@_cmd_t *cmd = (@name@_cmd_t *)aux;
+
+	@pre_print_cb_args@
+	debug( "%s[% 2d] Callback enter @name@@print_fmt_cb_args@\n", cmd->gen.ctx->label, cmd->gen.tag@print_pass_cb_args@ );
+	@print_cb_args@
+	cmd->callback( @pass_cb_args@cmd->callback_aux );
+	debug( "%s[% 2d] Callback leave @name@\n", cmd->gen.ctx->label, cmd->gen.tag );
+	proxy_cmd_done( &cmd->gen );
+}
+
+static void
+proxy_@name@( store_t *gctx@decl_args@, void (*cb)( @decl_cb_args@void *aux ), void *aux )
+{
+	proxy_store_t *ctx = (proxy_store_t *)gctx;
+
+	@name@_cmd_t *cmd = (@name@_cmd_t *)proxy_cmd_new( ctx, sizeof(@name@_cmd_t) );
+	cmd->callback = cb;
+	cmd->callback_aux = aux;
+	@assign_state@
+	@pre_print_args@
+	debug( "%s[% 2d] Enter @name@@print_fmt_args@\n", ctx->label, cmd->gen.tag@print_pass_args@ );
+	@print_args@
+	ctx->real_driver->@name@( ctx->real_store@pass_args@, proxy_@name@_cb, cmd );
+	debug( "%s[% 2d] Leave @name@\n", ctx->label, cmd->gen.tag );
+	proxy_cmd_done( &cmd->gen );
+}
+//# END
+
+//# UNDEFINE list_store_print_fmt_cb_args
+//# UNDEFINE list_store_print_pass_cb_args
+//# DEFINE list_store_print_cb_args
+	if (sts == DRV_OK) {
+		for (string_list_t *box = boxes; box; box = box->next)
+			debug( "  %s\n", box->string );
+	}
+//# END
+
+//# DEFINE load_box_pre_print_args
+	static char ubuf[12];
+//# END
+//# DEFINE load_box_print_fmt_args , [%d,%s] (new >= %d, seen <= %d)
+//# DEFINE load_box_print_pass_args , minuid, (maxuid == INT_MAX) ? "inf" : (nfsnprintf( ubuf, sizeof(ubuf), "%d", maxuid ), ubuf), newuid, seenuid
+//# DEFINE load_box_print_args
+	if (excs.size) {
+		debugn( "  excs:" );
+		for (int t = 0; t < excs.size; t++)
+			debugn( " %d", excs.data[t] );
+		debug( "\n" );
+	}
+//# END
+//# DEFINE load_box_pre_print_cb_args
+	static char fbuf[as(Flags) + 1];
+//# END
+//# DEFINE load_box_print_fmt_cb_args , sts=%d, total=%d, recent=%d
+//# DEFINE load_box_print_pass_cb_args , sts, total_msgs, recent_msgs
+//# DEFINE load_box_print_cb_args
+	if (sts == DRV_OK) {
+		for (message_t *msg = msgs; msg; msg = msg->next)
+			debug( "  uid=%5d, flags=%4s, size=%6d, tuid=%." stringify(TUIDL) "s\n",
+			       msg->uid, (msg->status & M_FLAGS) ? (proxy_make_flags( msg->flags, fbuf ), fbuf) : "?", msg->size, *msg->tuid ? msg->tuid : "?" );
+	}
+//# END
+
+//# DEFINE find_new_msgs_print_fmt_cb_args , sts=%d
+//# DEFINE find_new_msgs_print_pass_cb_args , sts
+//# DEFINE find_new_msgs_print_cb_args
+	if (sts == DRV_OK) {
+		for (message_t *msg = msgs; msg; msg = msg->next)
+			debug( "  uid=%5d, tuid=%." stringify(TUIDL) "s\n", msg->uid, msg->tuid );
+	}
+//# END
+
+//# DEFINE fetch_msg_decl_state
+	msg_data_t *data;
+//# END
+//# DEFINE fetch_msg_assign_state
+	cmd->data = data;
+//# END
+//# DEFINE fetch_msg_print_fmt_args , uid=%d, want_flags=%s, want_date=%s
+//# DEFINE fetch_msg_print_pass_args , msg->uid, !(msg->status & M_FLAGS) ? "yes" : "no", data->date ? "yes" : "no"
+//# DEFINE fetch_msg_pre_print_cb_args
+	static char fbuf[as(Flags) + 1];
+	proxy_make_flags( cmd->data->flags, fbuf );
+//# END
+//# DEFINE fetch_msg_print_fmt_cb_args , flags=%s, date=%ld, size=%d
+//# DEFINE fetch_msg_print_pass_cb_args , fbuf, cmd->data->date, cmd->data->len
+//# DEFINE fetch_msg_print_cb_args
+	if (sts == DRV_OK && (DFlags & DEBUG_DRV_ALL)) {
+		printf( "%s=========\n", cmd->gen.ctx->label );
+		fwrite( cmd->data->data, cmd->data->len, 1, stdout );
+		printf( "%s=========\n", cmd->gen.ctx->label );
+		fflush( stdout );
+	}
+//# END
+
+//# DEFINE store_msg_pre_print_args
+	static char fbuf[as(Flags) + 1];
+	proxy_make_flags( data->flags, fbuf );
+//# END
+//# DEFINE store_msg_print_fmt_args , flags=%s, date=%ld, size=%d, to_trash=%s
+//# DEFINE store_msg_print_pass_args , fbuf, data->date, data->len, to_trash ? "yes" : "no"
+//# DEFINE store_msg_print_args
+	if (DFlags & DEBUG_DRV_ALL) {
+		printf( "%s>>>>>>>>>\n", ctx->label );
+		fwrite( data->data, data->len, 1, stdout );
+		printf( "%s>>>>>>>>>\n", ctx->label );
+		fflush( stdout );
+	}
+//# END
+
+//# DEFINE set_msg_flags_pre_print_args
+	static char fbuf1[as(Flags) + 1], fbuf2[as(Flags) + 1];
+	proxy_make_flags( add, fbuf1 );
+	proxy_make_flags( del, fbuf2 );
+//# END
+//# DEFINE set_msg_flags_print_fmt_args , uid=%d, add=%s, del=%s
+//# DEFINE set_msg_flags_print_pass_args , uid, fbuf1, fbuf2
+
+//# DEFINE trash_msg_print_fmt_args , uid=%d
+//# DEFINE trash_msg_print_pass_args , msg->uid
+
+//# DEFINE free_store_action
+	proxy_store_deref( ctx );
+//# END
+
+//# DEFINE cancel_store_action
+	proxy_store_deref( ctx );
+//# END
+#endif
+
+//# SPECIAL commit_cmds
+static void
+proxy_commit_cmds( store_t *gctx )
+{
+	// Currently a dummy in all real drivers.
+	(void) gctx;
+}
+
+//# SPECIAL set_bad_callback
+static void
+proxy_set_bad_callback( store_t *gctx, void (*cb)( void *aux ), void *aux )
+{
+	proxy_store_t *ctx = (proxy_store_t *)gctx;
+
+	ctx->bad_callback = cb;
+	ctx->bad_callback_aux = aux;
+}
+
+static void
+proxy_invoke_bad_callback( proxy_store_t *ctx )
+{
+	debug( "%sCallback enter bad store\n", ctx->label );
+	ctx->bad_callback( ctx->bad_callback_aux );
+	debug( "%sCallback leave bad store\n", ctx->label ); \
+}
+
+//# EXCLUDE alloc_store
+store_t *
+proxy_alloc_store( store_t *real_ctx, const char *label )
+{
+	proxy_store_t *ctx;
+
+	ctx = nfcalloc( sizeof(*ctx) );
+	ctx->gen.driver = &proxy_driver;
+	ctx->gen.conf = real_ctx->conf;
+	ctx->ref_count = 1;
+	ctx->label = label;
+	ctx->real_driver = real_ctx->driver;
+	ctx->real_store = real_ctx;
+	ctx->real_driver->set_bad_callback( ctx->real_store, (void (*)(void *))proxy_invoke_bad_callback, ctx );
+	return &ctx->gen;
+}
+
+//# EXCLUDE parse_store
+//# EXCLUDE cleanup
+//# EXCLUDE get_fail_state
+
+#include "drv_proxy.inc"

src/drv_proxy_gen.pl

@@ -0,0 +1,169 @@
+#!/usr/bin/perl
+#
+# mbsync - mailbox synchronizer
+# Copyright (C) 2017 Oswald Buddenhagen <ossi@users.sf.net>
+#
+#  This program is free software; you can redistribute it and/or modify
+#  it under the terms of the GNU General Public License as published by
+#  the Free Software Foundation; either version 2 of the License, or
+#  (at your option) any later version.
+#
+#  This program is distributed in the hope that it will be useful,
+#  but WITHOUT ANY WARRANTY; without even the implied warranty of
+#  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+#  GNU General Public License for more details.
+#
+#  You should have received a copy of the GNU General Public License
+#  along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+# As a special exception, mbsync may be linked with the OpenSSL library,
+# despite that library's more restrictive license.
+#
+
+use strict;
+use warnings;
+
+die("Usage: $0 driver.h drv_proxy.c drv_proxy.inc\n")
+	if ($#ARGV != 2);
+
+my ($in_header, $in_source, $out_source) = @ARGV;
+
+my %templates;
+my %defines;
+my %excluded;
+my %special;
+
+open(my $ins, $in_source) or die("Cannot open $in_source: $!\n");
+my $template;
+my $define;
+my $conts;
+while (<$ins>) {
+	if ($template) {
+		if (/^\/\/\# END$/) {
+			$templates{$template} = $conts;
+			$template = undef;
+		} else {
+			$conts .= $_;
+		}
+	} elsif ($define) {
+		if (/^\/\/\# END$/) {
+			$defines{$define} = $conts;
+			$define = undef;
+		} else {
+			$conts .= $_;
+		}
+	} else {
+		if (/^\/\/\# TEMPLATE (\w+)$/) {
+			$template = $1;
+			$conts = "";
+		} elsif (/^\/\/\# DEFINE (\w+)$/) {
+			$define = $1;
+			$conts = "";
+		} elsif (/^\/\/\# DEFINE (\w+) (.*)$/) {
+			$defines{$1} = $2;
+		} elsif (/^\/\/\# UNDEFINE (\w+)$/) {
+			$defines{$1} = "";
+		} elsif (/^\/\/\# EXCLUDE (\w+)$/) {
+			$excluded{$1} = 1;
+		} elsif (/^\/\/\# SPECIAL (\w+)$/) {
+			$special{$1} = 1;
+		}
+	}
+}
+close($ins);
+
+open(my $inh, $in_header) or die("Cannot open $in_header: $!\n");
+my $sts = 0;
+my $cont = "";
+while (<$inh>) {
+	if ($sts == 0) {
+		if (/^struct driver \{$/) {
+			$sts = 1;
+		}
+	} elsif ($sts == 1) {
+		if (/^\};$/) {
+			$sts = 0;
+		} else {
+			$cont .= $_;
+		}
+	}
+}
+close($inh);
+
+$cont =~ s,\n, ,g;
+$cont =~ s,/\*.*?\*/, ,g;
+$cont =~ s,\h+, ,g;
+my @ptypes = map { s,^ ,,r } split(/;/, $cont);
+pop @ptypes;  # last one is empty
+
+my @cmd_table;
+
+sub make_args($)
+{
+	$_ = shift;
+	s/(?:^|(?<=, ))(?:const )?\w+ \*?//g;
+	return $_;
+}
+
+sub type_to_format($)
+{
+	$_ = shift;
+	s/xint /\%\#x/g;
+	s/int /\%d/g;
+	s/const char \*/\%s/g;
+	return $_;
+}
+
+sub make_format($)
+{
+	$_ = type_to_format(shift);
+	s/, (\%\#?.)(\w+)/, $2=$1/g;
+	return $_;
+}
+
+open(my $outh, ">".$out_source) or die("Cannot create $out_source: $!\n");
+
+for (@ptypes) {
+	/^([\w* ]+)\(\*(\w+)\)\( (.*) \)$/ or die("Cannot parse prototype '$_'\n");
+	my ($cmd_type, $cmd_name, $cmd_args) = ($1, $2, $3);
+	if (defined($excluded{$cmd_name})) {
+		push @cmd_table, "0";
+		next;
+	}
+	push @cmd_table, "proxy_$cmd_name";
+	next if (defined($special{$cmd_name}));
+	my %replace;
+	$replace{'name'} = $cmd_name;
+	$replace{'type'} = $cmd_type;
+	$cmd_args =~ s/^store_t \*ctx// or die("Arguments '$cmd_args' don't start with 'store_t *ctx'\n");
+	if ($cmd_type eq "void " && $cmd_args =~ s/, void \(\*cb\)\( (.*)void \*aux \), void \*aux$//) {
+		my $cmd_cb_args = $1;
+		$replace{'decl_cb_args'} = $cmd_cb_args;
+		$replace{'pass_cb_args'} = make_args($cmd_cb_args);
+		my $cmd_print_cb_args = $cmd_cb_args =~ s/(.*), $/, $1/r;
+		$replace{'print_pass_cb_args'} = make_args($cmd_print_cb_args);
+		$replace{'print_fmt_cb_args'} = make_format($cmd_print_cb_args);
+		$template = "CALLBACK";
+	} elsif ($cmd_name =~ /^get_/) {
+		$template = "GETTER";
+		$replace{'fmt'} = type_to_format($cmd_type);
+	} elsif ($cmd_type eq "void ") {
+		$template = "REGULAR_VOID";
+	} else {
+		$template = "REGULAR";
+		$replace{'fmt'} = type_to_format($cmd_type);
+	}
+	$replace{'decl_args'} = $cmd_args;
+	$replace{'print_pass_args'} = $replace{'pass_args'} = make_args($cmd_args);
+	$replace{'print_fmt_args'} = make_format($cmd_args);
+	for (keys %defines) {
+		$replace{$1} = $defines{$_} if (/^${cmd_name}_(.*)$/);
+	}
+	my $text = $templates{$template};
+	$text =~ s/^\h*\@(\w+)\@\n/$replace{$1} \/\/ ""/smeg;
+	$text =~ s/\@(\w+)\@/$replace{$1} \/\/ ""/eg;
+	print $outh $text."\n";
+}
+
+print $outh "struct driver proxy_driver = {\n".join("", map { "\t$_,\n" } @cmd_table)."};\n";
+close $outh;

src/main.c

@@ -462,6 +462,10 @@ main( int argc, char **argv )
 						op = VERBOSE | DEBUG_ALL;
 					else if (!strcmp( opt, "-crash" ))
 						op = DEBUG_CRASH;
+					else if (!strcmp( opt, "-driver" ))
+						op = VERBOSE | DEBUG_DRV;
+					else if (!strcmp( opt, "-driver-all" ))
+						op = VERBOSE | DEBUG_DRV | DEBUG_DRV_ALL;
 					else if (!strcmp( opt, "-maildir" ))
 						op = VERBOSE | DEBUG_MAILDIR;
 					else if (!strcmp( opt, "-main" ))
@@ -648,6 +652,12 @@ main( int argc, char **argv )
 				case 'C':
 					op |= DEBUG_CRASH;
 					break;
+				case 'd':
+					op |= DEBUG_DRV | VERBOSE;
+					break;
+				case 'D':
+					op |= DEBUG_DRV | DEBUG_DRV_ALL | VERBOSE;
+					break;
 				case 'm':
 					op |= DEBUG_MAILDIR | VERBOSE;
 					break;
@@ -811,14 +821,20 @@ sync_chans( main_vars_t *mvars, int ent )
 		if (mvars->skip)
 			goto next2;
 		mvars->state[M] = mvars->state[S] = ST_FRESH;
-		if (mvars->chan->stores[M]->driver->get_caps( 0 ) & mvars->chan->stores[S]->driver->get_caps( 0 ) & DRV_VERBOSE)
+		if ((DFlags & DEBUG_DRV) || (mvars->chan->stores[M]->driver->get_caps( 0 ) & mvars->chan->stores[S]->driver->get_caps( 0 ) & DRV_VERBOSE))
 			labels[M] = "M: ", labels[S] = "S: ";
 		else
 			labels[M] = labels[S] = "";
 		for (t = 0; t < 2; t++) {
-			mvars->drv[t] = mvars->chan->stores[t]->driver;
+			driver_t *drv = mvars->chan->stores[t]->driver;
-			mvars->ctx[t] = mvars->drv[t]->alloc_store( mvars->chan->stores[t], labels[t] );
+			store_t *ctx = drv->alloc_store( mvars->chan->stores[t], labels[t] );
-			mvars->drv[t]->set_bad_callback( mvars->ctx[t], store_bad, AUX );
+			if (DFlags & DEBUG_DRV) {
+				drv = &proxy_driver;
+				ctx = proxy_alloc_store( ctx, labels[t] );
+			}
+			mvars->drv[t] = drv;
+			mvars->ctx[t] = ctx;
+			drv->set_bad_callback( ctx, store_bad, AUX );
 		}
 		for (t = 0; ; t++) {
 			info( "Opening %s store %s...\n", str_ms[t], mvars->chan->stores[t]->name );
@@ -1008,11 +1024,6 @@ store_listed( int sts, string_list_t *boxes, void *aux )
 	case DRV_CANCELED:
 		return;
 	case DRV_OK:
-		if (DFlags & DEBUG_MAIN) {
-			debug( "got mailbox list from %s:\n", str_ms[t] );
-			for (box = boxes; box; box = box->next)
-				debug( "  %s\n", box->string );
-		}
 		for (box = boxes; box; box = box->next) {
 			if (mvars->ctx[t]->conf->flat_delim) {
 				string_list_t *nbox;

src/mbsync.1

@@ -83,12 +83,16 @@ Display version information.
 \fB-V\fR, \fB--verbose\fR
 Enable \fIverbose\fR mode, which displays what is currently happening.
 .TP
-\fB-D\fR[\fBC\fR][\fBm\fR][\fBM\fR][\fBn\fR|\fBN\fR][\fBs\fR]\fR]\fR,\
+\fB-D\fR[\fBC\fR][\fBd\fR|\fBD\fR][\fBm\fR][\fBM\fR][\fBn\fR|\fBN\fR][\fBs\fR]\fR]\fR,\
- \fB--debug\fR[\fB-crash\fR|\fB-maildir\fR|\fB-main\fR|\fB-net\fR|\fB-net-all\fR|\fB-sync\fR]
+ \fB--debug\fR[\fB-crash\fR|\fB-driver\fR|\fB-driver-all\fR|\fB-maildir\fR|\fB-main\fR|\fB-net\fR|\fB-net-all\fR|\fB-sync\fR]
 Enable debugging categories:
 .in +4
 \fBC\fR, \fBcrash\fR - use built-in crash handler
 .br
+\fBd\fR, \fBdriver\fR - print driver calls (metadata only)
+.br
+\fBD\fR, \fBdriver-all\fR - print driver calls (including messages)
+.br
 \fBm\fR, \fBmaildir\fR - print maildir debug info
 .br
 \fBM\fR, \fBmain\fR - print main debug info

src/sync.c

@@ -1003,7 +1003,7 @@ sync_boxes( store_t *ctx[], const char *names[], int present[], channel_conf_t *
 			sync_bail3( svars );
 			return;
 		}
-		svars->drv[t] = ctx[t]->conf->driver;
+		svars->drv[t] = ctx[t]->driver;
 		svars->drv[t]->set_bad_callback( ctx[t], store_bad, AUX );
 	}
 	/* Both boxes must be fully set up at this point, so that error exit paths
@@ -1284,10 +1284,6 @@ box_opened2( sync_vars_t *svars, int t )
 				}
 			}
 			sort_int_array( mexcs.array );
-			debugn( "  exception list is:" );
-			for (t = 0; t < mexcs.array.size; t++)
-				debugn( " %d", mexcs.array.data[t] );
-			debug( "\n" );
 		} else {
 			minwuid = 1;
 		}
@@ -1336,10 +1332,6 @@ load_box( sync_vars_t *svars, int t, int minwuid, int_array_t mexcs )
 		seenuid = svars->maxuid[t];
 	}
 	info( "Loading %s...\n", str_ms[t] );
-	if (maxwuid == INT_MAX)
-		debug( "loading %s [%d,inf] (new >= %d, seen <= %d)\n", str_ms[t], minwuid, svars->newuid[t], seenuid );
-	else
-		debug( "loading %s [%d,%d] (new >= %d, seen <= %d)\n", str_ms[t], minwuid, maxwuid, svars->newuid[t], seenuid );
 	svars->drv[t]->load_box( svars->ctx[t], minwuid, maxwuid, svars->newuid[t], seenuid, mexcs, box_loaded, AUX );
 }
 
@@ -1372,7 +1364,6 @@ box_loaded( int sts, message_t *msgs, int total_msgs, int recent_msgs, void *aux
 	int uid, no[2], del[2], alive, todel, t1, t2;
 	int sflags, nflags, aflags, dflags;
 	uint hashsz, idx;
-	char fbuf[16]; /* enlarge when support for keywords is added */
 
 	if (check_ret( sts, aux ))
 		return;
@@ -1406,10 +1397,6 @@ box_loaded( int sts, message_t *msgs, int total_msgs, int recent_msgs, void *aux
 		if (tmsg->srec) /* found by TUID */
 			continue;
 		uid = tmsg->uid;
-		if (DFlags & DEBUG_SYNC) {
-			make_flags( tmsg->flags, fbuf );
-			printf( tmsg->size ? "  message %5d, %-4s, %6d: " : "  message %5d, %-4s: ", uid, fbuf, tmsg->size );
-		}
 		idx = (uint)((uint)uid * 1103515245U) % hashsz;
 		while (srecmap[idx].uid) {
 			if (srecmap[idx].uid == uid) {
@@ -1419,12 +1406,10 @@ box_loaded( int sts, message_t *msgs, int total_msgs, int recent_msgs, void *aux
 			if (++idx == hashsz)
 				idx = 0;
 		}
-		debug( "new\n" );
 		continue;
 	  found:
 		tmsg->srec = srec;
 		srec->msg[t] = tmsg;
-		debug( "pairs %5d\n", srec->uid[1-t] );
 	}
 	free( srecmap );