Refactor logging logic.

Also, introduce new option 'logger-prefix' to determine the prefix of
each log line.

Closes: #942725.

10 files changed, 126 insertions, 90 deletions

diff --git a/Changelog b/Changelog
index 964fab8..48481dd 100644
--- a/Changelog
+++ b/Changelog
@@ -48,6 +48,8 @@ interimap (0.5) upstream;
    --debug mode in order to avoid inadvertently receiving credentials in
    bug reports.  --debug can be set twice to spell out these commands in
    full.
+ + interimap: new option 'log-prefix' to control the prefix of each log
+   entry, depending on the component name and relevant mailbox.
  - libinterimap: bugfix: hierarchy delimiters in LIST responses were
    returned as an escaped quoted special, like "\\", not as a single
    character (backslash in this case).
diff --git a/doc/interimap.1.md b/doc/interimap.1.md
index febec28..ee92668 100644
--- a/doc/interimap.1.md
+++ b/doc/interimap.1.md
@@ -290,6 +290,19 @@ Valid options are:
     default these messages are written to the error output.)  This
     option is only available in the default section.
 
+*log-prefix*
+
+:   A `printf`(3)-like format string to use as prefix for each log
+    message.  Interpreted sequences are `%n` and `%m`, expanding
+    respectively to the component name (*local*/*remote*) and to the
+    name of the mailbox relevant for the log entry.  Conditions on a
+    specifier `%X` can be obtained with `%?X?then?` or `%?X?then&else?`,
+    which expands to *then* if the `%X` specifier expands to a non-empty
+    string, and to *else* (or the empty string if there is no else
+    condition) if it doesn't.  Literal `%` characters need to be escaped
+    as `%%`, while `&`, `?` and `\` characters need to be `\`-escaped.
+    (Default: `%?n?%?m?%n(%m)&%n?: ?`.)
+
 *type*
 
 :   One of `imap`, `imaps` or `tunnel`.
diff --git a/interimap b/interimap
index afe18e9..87c3a64 100755
--- a/interimap
+++ b/interimap
@@ -79,13 +79,14 @@ my $CONF = do {
                , [qw/_ local remote/]
                , database => qr/\A(\P{Control}+)\z/
                , logfile => qr/\A(\/\P{Control}+)\z/
+               , 'log-prefix' => qr/\A(\P{Control}*)\z/
                , 'list-reference' => qr/\A([\x01-\x09\x0B\x0C\x0E-\x7F]*)\z/
                , 'list-mailbox' => qr/\A([\x01-\x09\x0B\x0C\x0E-\x7F]+)\z/
                , 'list-select-opts' => qr/\A([\x20\x21\x23\x24\x26\x27\x2B-\x5B\x5E-\x7A\x7C-\x7E]*)\z/
                , 'ignore-mailbox' => qr/\A([\x01-\x09\x0B\x0C\x0E-\x7F]+)\z/
                );
 };
-my ($DBFILE, $LOGGER_FD, %LIST);
+my ($DBFILE, %LOGGER_CONF, %LIST);
 
 {
     $CONF->{_} //= {};
@@ -95,16 +96,15 @@ my ($DBFILE, $LOGGER_FD, %LIST);
     die "Missing option database" unless defined $DBFILE;
     $DBFILE = xdg_basedir( XDG_DATA_HOME => ".local/share", $NAME, $DBFILE );
 
+    $LOGGER_CONF{'logger-prefix'} = $CONF->{_}->{'log-prefix'} // "%?n?%?m?%n(%m)&%n?: ?";
     if (defined (my $l = $CONF->{_}->{logfile})) {
         require 'POSIX.pm';
         require 'Time/HiRes.pm';
-        open $LOGGER_FD, '>>', $l or die "Can't open $l: $!\n";
-        $LOGGER_FD->autoflush(1);
-        my $flags = fcntl($LOGGER_FD, F_GETFD, 0)       or die "fcntl F_GETFD: $!";
-        fcntl($LOGGER_FD, F_SETFD, $flags | FD_CLOEXEC) or die "fcntl F_SETFD: $!";
-    }
-    elsif ($CONFIG{debug}) {
-        $LOGGER_FD = \*STDERR;
+        open my $fd, '>>', $l or die "Can't open $l: $!\n";
+        $fd->autoflush(1);
+        my $flags = fcntl($fd, F_GETFD, 0)       or die "fcntl F_GETFD: $!";
+        fcntl($fd, F_SETFD, $flags | FD_CLOEXEC) or die "fcntl F_SETFD: $!";
+        $LOGGER_CONF{'logger-fd'} = $fd;
     }
 
     $LIST{mailbox} = [@ARGV];
@@ -149,8 +149,7 @@ my ($IMAP, $lIMAP, $rIMAP);
 sub cleanup() {
     undef $_ foreach grep defined, ($IMAP, $lIMAP, $rIMAP);
     logger(undef, "Cleaning up...") if $CONFIG{debug};
-    $LOGGER_FD->close() if defined $LOGGER_FD and defined $LOGGER_FD->fileno
-                            and $LOGGER_FD->fileno != fileno STDERR;
+    $LOGGER_CONF{'logger-fd'}->close() if defined $LOGGER_CONF{'logger-fd'};
     $DBH->disconnect() if defined $DBH;
 }
 $SIG{INT} = sub { msg(undef, $!); cleanup(); exit 1; };
@@ -181,31 +180,25 @@ $SIG{TERM} = sub { cleanup(); exit 0; };
 }
 
 sub msg($@) {
+    my %h = ( %LOGGER_CONF, name => shift );
+    return Net::IMAP::InterIMAP::log(\%h, @_);
+}
+sub msg2($$@) {
     my $name = shift;
-    return unless @_;
-    logger($name, @_) if defined $LOGGER_FD and defined $LOGGER_FD->fileno
-        and $LOGGER_FD->fileno != fileno STDERR;
-    my $prefix = defined $name ? "$name: " : '';
-    print STDERR $prefix, @_, "\n";
+    my $mailbox = mbx_name($name => shift);
+    my %h = ( %LOGGER_CONF, name => $name, mailbox => $mailbox );
+    return Net::IMAP::InterIMAP::log(\%h, @_);
 }
 sub logger($@) {
-    my $name = shift;
-    return unless @_ and defined $LOGGER_FD;
-    my $prefix = '';
-    if (defined $LOGGER_FD and defined $LOGGER_FD->fileno
-            and $LOGGER_FD->fileno != fileno STDERR) {
-        my ($s, $us) = Time::HiRes::gettimeofday();
-        $prefix = POSIX::strftime("%b %e %H:%M:%S", localtime($s)).".$us ";
-    }
-    $prefix .= "$name: " if defined $name;
-    $LOGGER_FD->say($prefix, @_);
+    my %h = ( %LOGGER_CONF, name => shift );
+    return Net::IMAP::InterIMAP::logger(\%h, @_);
 }
 sub fail($@) {
     my $name = shift;
     msg($name, "ERROR: ", @_);
     exit 1;
 }
-logger(undef, ">>> $NAME $VERSION");
+logger(undef, ">>> $NAME $VERSION") if $CONFIG{debug};
 
 
 #############################################################################
@@ -216,7 +209,7 @@ foreach my $name (qw/local remote/) {
     $config{$_} = $CONFIG{$_} foreach grep {defined $CONFIG{$_}} qw/quiet debug/;
     $config{enable} = 'QRESYNC';
     $config{name} = $name;
-    $config{'logger-fd'} = $LOGGER_FD if defined $LOGGER_FD;
+    $config{$_} = $LOGGER_CONF{$_} foreach keys %LOGGER_CONF;
     $config{'compress'} //= ($name eq 'local' ? 0 : 1);
     $config{keepalive} = 1 if $CONFIG{watch} and $config{type} ne 'tunnel';
 
@@ -447,7 +440,7 @@ sub db_create_mailbox($$) {
     $sth->bind_param(1, $mailbox,    SQL_BLOB);
     $sth->bind_param(2, $subscribed, SQL_BOOLEAN);
     my $r = $sth->execute();
-    msg("database", fmt("Created mailbox %d", $mailbox));
+    msg("database", "Created mailbox ", mbx_pretty($mailbox));
     return $r;
 }
 
@@ -474,6 +467,7 @@ sub mbx_name($$) {
     }
     return defined $name ? ($CONF->{$name}->{"list-reference"} . $mailbox) : $mailbox;
 }
+sub mbx_pretty($) { return mbx_name(undef, $_[0]); }
 
 # Transform mailbox name from local/remote IMAP server to the internal representation
 # (with \0 as hierarchy delimiters and without reference prefix).  Return undef if
@@ -553,7 +547,7 @@ if (defined $COMMAND and $COMMAND eq 'delete') {
                 $sth->execute();
             }
             $DBH->commit();
-            msg("database", fmt("Removed mailbox %d", $mailbox));
+            msg("database", "Removed mailbox ", mbx_pretty($mailbox));
         }
     }
     exit 0;
@@ -579,11 +573,14 @@ elsif (defined $COMMAND and $COMMAND eq 'rename') {
     foreach my $name (qw/local remote/) {
         my $mbx = mbx_name($name, $to);
         next unless $CONFIG{target}->{$name} and mbx_exists($name, $mbx);
-        fail($name, fmt("Mailbox %s exists.  Run `$NAME --target=$name --delete %d` to delete.", $mbx, $to));
+        fail($name, "Mailbox $mbx exists. Run `$NAME --target=$name --delete ",
+                        mbx_pretty($to), "` to delete.");
     }
 
     # ensure the target name doesn't already exist in the database
-    fail("database", fmt("Mailbox %d exists.  Run `$NAME --target=database --delete %d` to delete.", $to, $to))
+    my $to_pretty = mbx_pretty($to);
+    fail("database", "Mailbox $to_pretty exists. Run `$NAME --target=database ",
+                        "--delete $to_pretty` to delete.")
         if $CONFIG{target}->{database} and defined db_get_mailbox_idx($to);
 
 
@@ -624,7 +621,8 @@ elsif (defined $COMMAND and $COMMAND eq 'rename') {
         $r += $sth_rename_children->execute();
 
         $DBH->commit();
-        msg("database", fmt("Renamed mailbox %d to %d", $from, $to)) if $r > 0;
+        msg("database", "Renamed mailbox ", mbx_pretty($from), " to ",
+                            mbx_pretty($to)) if $r > 0;
     }
     exit 0;
 }
@@ -703,7 +701,8 @@ sub sync_mailbox_list() {
         }
         elsif ($lExists or $rExists) {
             # $mailbox is on one server only
-            fail("database", fmt("Mailbox %d exists.  Run `$NAME --target=database --delete %d` to delete.", $mailbox, $mailbox))
+            my $str = mbx_pretty($mailbox);
+            fail("database", "Mailbox $str exists. Run `$NAME --target=database --delete $str` to delete.")
                 if defined $idx;
             my ($name1, $name2, $mbx1, $mbx2) = $lExists ? ("local", "remote", $lMailbox, $rMailbox)
                                                          : ("remote", "local", $rMailbox, $lMailbox);
@@ -733,8 +732,7 @@ sub download_missing($$$@) {
     my @set = @_;
     my @uids;
 
-    my ($target, $f) = $source eq 'local' ? ('remote', '%l') : ('local', '%r');
-    my $prefix = fmt("%s($f)", $source, $mailbox) unless $CONFIG{quiet};
+    my $target = $source eq 'local' ? 'remote' : 'local';
 
     my ($buff, $bufflen) = ([], 0);
     undef $buff if ($target eq 'local' ? $lIMAP : $rIMAP)->incapable('MULTIAPPEND');
@@ -747,7 +745,7 @@ sub download_missing($$$@) {
             my $from = first { defined $_ and @$_ } @{$mail->{ENVELOPE}}[2,3,4];
             $from = (defined $from and defined $from->[0]->[2] and defined $from->[0]->[3])
                   ? $from->[0]->[2].'@'.$from->[0]->[3] : '';
-            msg($prefix, "UID $mail->{UID} from <$from> ($mail->{INTERNALDATE})");
+            msg2($source => $mailbox, "UID $mail->{UID} from <$from> ($mail->{INTERNALDATE})");
         }
         callback_new_message($idx, $mailbox, $source, $mail, \@uids, $buff, \$bufflen)
     });
@@ -762,9 +760,9 @@ sub flag_conflict($$$$$) {
 
     my %flags = map {$_ => 1} (split(/ /, $lFlags), split(/ /, $rFlags));
     my $flags = join ' ', sort(keys %flags);
-    msg(undef, fmt("WARNING: Conflicting flag update in %d for local UID $lUID (%s) ".
-                   "and remote UID $rUID (%s). Setting both to the union (%s).",
-                   $mailbox, $lFlags, $rFlags, $flags));
+    msg(undef, "WARNING: Conflicting flag update in ", mbx_pretty($mailbox),
+                " for local UID $lUID ($lFlags) and remote UID $rUID ($rFlags).",
+                " Setting both to the union ($flags).");
     return $flags
 }
 
@@ -914,7 +912,8 @@ sub repair($) {
             }
             else {
                 # conflict
-                msg(undef, fmt("WARNING: Missed flag update in %d for (lUID,rUID) = ($lUID,$rUID). Repairing.", $mailbox))
+                msg(undef, "WARNING: Missed flag update in ", mbx_pretty($mailbox),
+                                " for (lUID,rUID) = ($lUID,$rUID). Repairing.")
                     if $lModSeq <= $cache->{lHIGHESTMODSEQ} and $rModSeq <= $cache->{rHIGHESTMODSEQ};
                 # set both $lUID and $rUID to the union of $lFlags and $rFlags
                 my $flags = flag_conflict($mailbox, $lUID => $lFlags, $rUID => $rFlags);
@@ -926,7 +925,8 @@ sub repair($) {
         }
         elsif (!defined $lModified->{$lUID} and !defined $rModified->{$rUID}) {
             push @delete_mapping, $lUID;
-            msg(undef, fmt("WARNING: Pair (lUID,rUID) = ($lUID,$rUID) vanished from %d. Repairing.", $mailbox))
+            msg(undef, "WARNING: Pair (lUID,rUID) = ($lUID,$rUID) vanished from ",
+                            mbx_pretty($mailbox), ". Repairing.")
                 unless $lVanished{$lUID} and $rVanished{$rUID};
         }
         elsif (!defined $lModified->{$lUID}) {
@@ -934,7 +934,7 @@ sub repair($) {
             if ($lVanished{$lUID}) {
                 push @rToRemove, $rUID;
             } else {
-                msg(fmt("local(%l)", $mailbox), "WARNING: UID $lUID disappeared. Downloading remote UID $rUID again.");
+                msg2(local => $mailbox, "WARNING: UID $lUID disappeared. Redownloading remote UID $rUID.");
                 push @rMissing, $rUID;
             }
         }
@@ -943,7 +943,7 @@ sub repair($) {
             if ($rVanished{$rUID}) {
                 push @lToRemove, $lUID;
             } else {
-                msg(fmt("remote(%r)",$mailbox), "WARNING: UID $rUID disappeared. Downloading local UID $lUID again.");
+                msg2(remote => $mailbox, "WARNING: UID $rUID disappeared. Redownloading local UID $lUID.");
                 push @lMissing, $lUID;
             }
         }
@@ -973,17 +973,17 @@ sub repair($) {
     # Process UID found in IMAP but not in the mapping table.
     my @lDunno = keys %lVanished;
     my @rDunno = keys %rVanished;
-    msg(fmt("remote(%r)",$mailbox), "WARNING: No match for ".($#lDunno+1)." vanished local UID(s) "
+    msg2(remote => $mailbox, "WARNING: No match for ".($#lDunno+1)." vanished local UID(s) "
                             .compact_set(@lDunno).". Ignoring.") if @lDunno;
-    msg(fmt("local(%l)",$mailbox),  "WARNING: No match for ".($#rDunno+1)." vanished remote UID(s) "
+    msg2(local => $mailbox,  "WARNING: No match for ".($#rDunno+1)." vanished remote UID(s) "
                             .compact_set(@rDunno).". Ignoring.") if @rDunno;
 
     foreach my $lUID (keys %$lModified) {
-        msg(fmt("remote(%r)",$mailbox), "WARNING: No match for modified local UID $lUID. Downloading again.");
+        msg2(remote => $mailbox, "WARNING: No match for modified local UID $lUID. Redownloading.");
         push @lMissing, $lUID;
     }
     foreach my $rUID (keys %$rModified) {
-        msg(fmt("local(%l)",$mailbox), "WARNING: No match for modified remote UID $rUID. Downloading again.");
+        msg2(local => $mailbox, "WARNING: No match for modified remote UID $rUID. Redownloading.");
         push @rMissing, $rUID;
     }
 
@@ -1063,9 +1063,9 @@ sub sync_known_messages($$) {
                 }
             }
 
-            msg(fmt("remote(%r)",$mailbox), "WARNING: No match for ".($#lDunno+1)." vanished local UID(s) "
+            msg2(remote => $mailbox, "WARNING: No match for ".($#lDunno+1)." vanished local UID(s) "
                                     .compact_set(@lDunno).". Ignoring.") if @lDunno;
-            msg(fmt("local(%l)",$mailbox),  "WARNING: No match for ".($#rDunno+1)." vanished remote UID(s) "
+            msg2(local => $mailbox,  "WARNING: No match for ".($#rDunno+1)." vanished remote UID(s) "
                                     .compact_set(@rDunno).". Ignoring.") if @rDunno;
 
             $lIMAP->remove_message(@lToRemove) if @lToRemove;
@@ -1098,7 +1098,7 @@ sub sync_known_messages($$) {
                 my ($rUID) = $sth_get_remote_uid->fetchrow_array();
                 die if defined $sth_get_remote_uid->fetch(); # safety check
                 if (!defined $rUID) {
-                    msg(fmt("remote(%r)",$mailbox), "WARNING: No match for modified local UID $lUID. Try '--repair'.");
+                    msg2(remote => $mailbox, "WARNING: No match for modified local UID $lUID. Try '--repair'.");
                 } elsif (defined (my $rFlags = $rModified->{$rUID})) {
                     unless ($lFlags eq $rFlags) {
                         my $flags = flag_conflict($mailbox, $lUID => $lFlags, $rUID => $rFlags);
@@ -1119,7 +1119,7 @@ sub sync_known_messages($$) {
                 my ($lUID) = $sth_get_local_uid->fetchrow_array();
                 die if defined $sth_get_local_uid->fetch(); # safety check
                 if (!defined $lUID) {
-                    msg(fmt("local(%l)",$mailbox), "WARNING: No match for modified remote UID $rUID. Try '--repair'.");
+                    msg2(local => $mailbox, "WARNING: No match for modified remote UID $rUID. Try '--repair'.");
                 } elsif (!exists $lModified->{$lUID}) {
                     # conflicts are taken care of above
                     $lToUpdate{$rFlags} //= [];
@@ -1151,8 +1151,7 @@ sub callback_new_message($$$$;$$$) {
 
     my $length = length ${$mail->{RFC822}};
     if ($length == 0) {
-        my $prefix = $name eq "local" ? "local(%l)" : "remote(%r)";
-        msg(fmt($prefix, $mailbox), "WARNING: Ignoring new 0-length message (UID $mail->{UID})");
+        msg2($name => $mailbox, "WARNING: Ignoring new 0-length message (UID $mail->{UID})");
         return;
     }
 
@@ -1192,7 +1191,7 @@ sub callback_new_message_flush($$$@) {
     });
     my ($lUIDs, $rUIDs) = $name eq 'local' ? (\@sUID,\@tUID) : (\@tUID,\@sUID);
     for (my $k=0; $k<=$#messages; $k++) {
-        logger(undef, fmt("Adding mapping (lUID,rUID) = ($lUIDs->[$k],$rUIDs->[$k]) for %d", $mailbox))
+        logger(undef, "Adding mapping (lUID,rUID) = ($lUIDs->[$k],$rUIDs->[$k]) for ", mbx_pretty($mailbox))
             if $CONFIG{debug};
         $sth->bind_param(1, $idx,         SQL_INTEGER);
         $sth->bind_param(2, $lUIDs->[$k], SQL_INTEGER);
@@ -1322,7 +1321,7 @@ sub db_get_cache_by_idx($) {
         next unless grep { $_ eq $row->[1] } @MAILBOXES; # skip ignored mailboxes
 
         ($IDX, $MAILBOX) = @$row;
-        msg(undef, fmt("Resuming interrupted sync for %d", $MAILBOX));
+        msg(undef, "Resuming interrupted sync for ", mbx_pretty($MAILBOX));
         my $cache = db_get_cache_by_idx($IDX) // die; # safety check
         my ($lMailbox, $rMailbox) = map {mbx_name($_, $MAILBOX)} qw/local remote/;
 
diff --git a/lib/Net/IMAP/InterIMAP.pm b/lib/Net/IMAP/InterIMAP.pm
index 2d1f644..bb27009 100644
--- a/lib/Net/IMAP/InterIMAP.pm
+++ b/lib/Net/IMAP/InterIMAP.pm
@@ -17,6 +17,7 @@
 #----------------------------------------------------------------------
 
 package Net::IMAP::InterIMAP v0.0.5;
+use v5.10.0;
 use warnings;
 use strict;
 
@@ -280,7 +281,8 @@ our $IMAP_text;
 #
 #   - 'name': An optional instance name to include in log messages.
 #
-#   - 'logger-fd': An optional filehandle to use for debug output.
+#   - 'logger-fd': An optional filehandle to use for debug output
+#     (default: STDERR).
 #
 #   - 'keepalive': Whether to enable sending of keep-alive messages.
 #     (type=imap or type=imaps).
@@ -289,6 +291,7 @@ sub new($%) {
     my $class = shift;
     my $self = { @_ };
     bless $self, $class;
+    require 'Time/HiRes.pm' if defined $self->{'logger-fd'};
 
     # the IMAP state: one of 'UNAUTH', 'AUTH', 'SELECTED' or 'LOGOUT'
     # (cf RFC 3501 section 3)
@@ -378,11 +381,6 @@ sub new($%) {
     # are considered.
     $self->{_MODIFIED} = {};
 
-    if (defined $self->{'logger-fd'} and defined $self->{'logger-fd'}->fileno
-            and $self->{'logger-fd'}->fileno != fileno STDERR) {
-        require 'Time/HiRes.pm';
-    }
-
     # wait for the greeting
     my $x = $self->_getline();
     $x =~ s/\A\* (OK|PREAUTH) // or $self->panic($x);
@@ -539,32 +537,55 @@ sub DESTROY($) {
 
 # $self->log($message, [...])
 # $self->logger($message, [...])
-#   Log a $message.  The latter method is used to log in the 'logger-fd', and
-#   add timestamps.
+#   Log a $message.  The latter method is used to log in the 'logger-fd'
+#   (and adds timestamps).
 sub log($@) {
     my $self = shift;
     return unless @_;
-    $self->logger(@_) if defined $self->{'logger-fd'} and defined $self->{'logger-fd'}->fileno
-        and $self->{'logger-fd'}->fileno != fileno STDERR;
-    my $prefix = $self->{name} // '';
-    $prefix .= "($self->{_SELECTED})" if $self->{_STATE} eq 'SELECTED';
-    $prefix .= ': ' unless $prefix eq '';
-    print STDERR $prefix, @_, "\n";
+    my $prefix = _logger_prefix($self);
+    if (defined (my $fd = $self->{'logger-fd'})) {
+        say $fd _date(), " ", $prefix, @_;
+    }
+    say STDERR $prefix, @_;
 }
 sub logger($@) {
     my $self = shift;
-    return unless @_ and defined $self->{'logger-fd'};
-    my $prefix = '';
-    if (defined $self->{'logger-fd'}->fileno and defined $self->{'logger-fd'}->fileno
-            and $self->{'logger-fd'}->fileno != fileno STDERR) {
-        my ($s, $us) = Time::HiRes::gettimeofday();
-        $prefix = POSIX::strftime("%b %e %H:%M:%S", localtime($s)).".$us";
-        $prefix .= ' ' if defined $self->{name} or $self->{_STATE} eq 'SELECTED';
-    }
-    $prefix .= $self->{name} if defined $self->{name};
-    $prefix .= "($self->{_SELECTED})" if $self->{_STATE} eq 'SELECTED';
-    $prefix .= ': ' unless $prefix eq '';
-    $self->{'logger-fd'}->say($prefix, @_);
+    return unless @_;
+    my $prefix = _logger_prefix($self);
+    if (defined (my $fd = $self->{'logger-fd'})) {
+        say $fd _date(), " ", $prefix, @_;
+    } else {
+        say STDERR $prefix, @_;
+    }
+}
+sub _date() {
+    my ($s, $us) = Time::HiRes::gettimeofday();
+    my $t = POSIX::strftime("%b %e %H:%M:%S", localtime($s));
+    return "$t.$us"; # millisecond precision
+}
+
+# $self->_logger_prefix()
+#   Format a prefix for logging with printf(3)-like sequences:
+#     %n: the object name
+#     %m: mailbox, either explicit named or selected
+sub _logger_prefix($) {
+    my $self = shift;
+    my $format = $self->{'logger-prefix'} // return "";
+
+    my %seq = ( "%" => "%", m => $self->{mailbox}, n => $self->{name} );
+    $seq{m} //= $self->{_SELECTED} // die
+        if defined $self->{_STATE} and $self->{_STATE} eq 'SELECTED';
+
+    do {} while
+        # rewrite conditionals (loop because of nesting)
+        $format =~ s#%\? ([[:alpha:]]) \?
+                ( (?: (?> (?: [^%&?\\] | %[^?] | \\[&?\\] )+ ) | (?R) )* )
+         (?: \& ( (?: (?> (?: [^%&?\\] | %[^?] | \\[&?\\] )+ ) | (?R) )*) )?
+            \?# ($seq{$1} // "") ne "" ? $2 : ($3 // "") #agex;
+
+    $format =~ s#\\([&?\\])#$1#g; # unescape remaining '&', '?' and '\'
+    $format =~ s#%([%mn])# $seq{$1} #ge;
+    return $format;
 }
 
 
diff --git a/pullimap b/pullimap
index 81811e9..dcbe59b 100755
--- a/pullimap
+++ b/pullimap
@@ -233,7 +233,8 @@ sub smtp_send(@) {
 my $IMAP = do {
     my %config = (%$CONF, %CONFIG{qw/quiet debug/}, name => $ARGV[0]);
     $config{keepalive} = 1 if defined $CONFIG{idle};
-    $config{'logger-fd'} = \*STDERR if $CONFIG{debug};
+    $config{'logger-prefix'} = "%?n?%?m?%n(%m)&%n?: ?";
+    delete $config{mailbox}; # use SELECTed mailbox in log messages
     Net::IMAP::InterIMAP::->new( %config );
 };
 
diff --git a/tests/01-rename-exists-db/run b/tests/01-rename-exists-db/run
index 29cb075..aad7c44 100644
--- a/tests/01-rename-exists-db/run
+++ b/tests/01-rename-exists-db/run
@@ -9,6 +9,6 @@ doveadm -u "local"  mailbox delete "t.o"
 doveadm -u "remote" mailbox delete "t\\o"
 
 ! interimap --rename "root.from" "t.o"
-xgrep -Fx 'database: ERROR: Mailbox t.o exists.  Run `interimap --target=database --delete t.o` to delete.' <"$STDERR"
+xgrep -Fx 'database: ERROR: Mailbox t.o exists. Run `interimap --target=database --delete t.o` to delete.' <"$STDERR"
 
 # vim: set filetype=sh :
diff --git a/tests/01-rename-exists-local/run b/tests/01-rename-exists-local/run
index 17d8fcc..d82a0a4 100644
--- a/tests/01-rename-exists-local/run
+++ b/tests/01-rename-exists-local/run
@@ -8,6 +8,6 @@ check_mailbox_list
 doveadm -u "remote" mailbox delete "t\\o"
 
 ! interimap --rename "root.from" "t.o"
-xgrep -Fx 'local: ERROR: Mailbox t.o exists.  Run `interimap --target=local --delete t.o` to delete.' <"$STDERR"
+xgrep -Fx 'local: ERROR: Mailbox t.o exists. Run `interimap --target=local --delete t.o` to delete.' <"$STDERR"
 
 # vim: set filetype=sh :
diff --git a/tests/01-rename-exists-remote/run b/tests/01-rename-exists-remote/run
index c867a77..28af1fc 100644
--- a/tests/01-rename-exists-remote/run
+++ b/tests/01-rename-exists-remote/run
@@ -8,6 +8,6 @@ check_mailbox_list
 doveadm -u "local" mailbox delete "t.o"
 
 ! interimap --rename "root.from" "t.o"
-xgrep -Fx 'remote: ERROR: Mailbox t\o exists.  Run `interimap --target=remote --delete t.o` to delete.' <"$STDERR"
+xgrep -Fx 'remote: ERROR: Mailbox t\o exists. Run `interimap --target=remote --delete t.o` to delete.' <"$STDERR"
 
 # vim: set filetype=sh :
diff --git a/tests/03-sync-mailbox-list/run b/tests/03-sync-mailbox-list/run
index e9fda06..b506204 100644
--- a/tests/03-sync-mailbox-list/run
+++ b/tests/03-sync-mailbox-list/run
@@ -24,7 +24,7 @@ check_mailbox_list -s
 # delete a mailbox one server and verify that synchronization fails as it's still in the database
 doveadm -u "remote" mailbox delete "foo~baz"
 ! interimap
-xgrep -Fx 'database: ERROR: Mailbox foo.baz exists.  Run `interimap --target=database --delete foo.baz` to delete.' <"$STDERR"
+xgrep -Fx 'database: ERROR: Mailbox foo.baz exists. Run `interimap --target=database --delete foo.baz` to delete.' <"$STDERR"
 interimap --target="database" --delete "foo.baz"
 xgrep -Fx 'database: Removed mailbox foo.baz' <"$STDERR"
 interimap # create again
@@ -33,7 +33,7 @@ xgrep -Fx 'remote: Created mailbox foo~baz' <"$STDERR"
 
 doveadm -u "local" mailbox delete "foo.bar"
 ! interimap
-xgrep -Fx 'database: ERROR: Mailbox foo.bar exists.  Run `interimap --target=database --delete foo.bar` to delete.' <"$STDERR"
+xgrep -Fx 'database: ERROR: Mailbox foo.bar exists. Run `interimap --target=database --delete foo.bar` to delete.' <"$STDERR"
 interimap --target="database" --delete "foo.bar"
 xgrep -Fx 'database: Removed mailbox foo.bar' <"$STDERR"
 interimap
diff --git a/tests/05-repair/run b/tests/05-repair/run
index 15553e0..66f9ce9 100644
--- a/tests/05-repair/run
+++ b/tests/05-repair/run
@@ -77,10 +77,10 @@ xcgrep 5 '^WARNING: Conflicting flag update in foo\.bar ' <"$STDERR"
 xcgrep 1 -E '^WARNING: Pair \(lUID,rUID\) = \([0-9]+,[0-9]+\) vanished from foo\.bar\. Repairing\.$' <"$STDERR"
 
 # 6-1 (luid 2 <-> ruid 10 is gone from both)
-xcgrep 5 -E '^local\(foo\.bar\): WARNING: UID [0-9]+ disappeared\. Downloading remote UID [0-9]+ again\.$' <"$STDERR"
+xcgrep 5 -E '^local\(foo\.bar\): WARNING: UID [0-9]+ disappeared. Redownloading remote UID [0-9]+\.$' <"$STDERR"
 
 # 6-1 (luid 2 <-> ruid 10 is gone from both)
-xcgrep 3 -E '^remote\(foo~bar\): WARNING: UID [0-9]+ disappeared\. Downloading local UID [0-9]+ again\.$' <"$STDERR"
+xcgrep 3 -E '^remote\(foo~bar\): WARNING: UID [0-9]+ disappeared. Redownloading local UID [0-9]+\.$' <"$STDERR"
 
 xgrep -E '^local\(baz\): Removed 24 UID\(s\) ' <"$STDERR"
 xgrep -E '^remote\(baz\): Removed 5 UID\(s\) ' <"$STDERR"
@@ -92,7 +92,7 @@ xgrep -E '^remote\(foo~bar\): Updated flags \(\\Answered \\Seen\) for UID 8$'  <
 xgrep -E '^remote\(foo~bar\): Updated flags \(\\Answered\) for UID 3,12,16$'   <"$STDERR"
 
 # luid 17
-xcgrep 1 -E '^remote\(foo~bar\): WARNING: No match for modified local UID [0-9]+\. Downloading again\.' <"$STDERR"
+xcgrep 1 -E '^remote\(foo~bar\): WARNING: No match for modified local UID [0-9]+. Redownloading\.' <"$STDERR"
 
 xgrep -E '^local\(foo\.bar\): Added 5 UID\(s\) ' <"$STDERR"
 xgrep -E '^remote\(foo~bar\): Added 4 UID\(s\) ' <"$STDERR"