[Dovecot] Corrupted transaction log file / record size too small
Steven Winikoff
smw at alcor.concordia.ca
Tue Sep 30 09:08:27 EEST 2008
I recently upgradeded dovecot on one of our servers from version 1.0.10
to version 1.1.3. Ever since, we've been seeing occasional errors
similar to this sequence (with the username and IP addresses elided):
Sep 30 00:09:56 alcor dovecot: pop3-login: Login: [4954], XXXX, NNN.NNN.NN.NNN
Sep 30 00:09:56 alcor dovecot: wrapper[5006]: pop3, XXXX, NNN.NNN.NN.NNN
Sep 30 00:09:56 alcor dovecot: pop3[5006] XXXX, NNN.NNN.NN.NNN: Corrupted transaction log file /home/XXXX/.imap/INBOX/dovecot.index.log: record size too small (type=0x40, offset=12224, size=0)
Sep 30 00:09:56 alcor dovecot: pop3[5006] XXXX, NNN.NNN.NN.NNN: Couldn't init INBOX: Internal error occurred. Refer to server log for more information. [2008-09-30 00:09:56]
Sep 30 00:09:56 alcor dovecot: pop3[5006] XXXX, NNN.NNN.NN.NNN: Mailbox init failed top=0/0, retr=0/0, del=0/0, size=0, xfer=0/95
System and dovecot configuration details are appended.
I saw an archived mailing list message from January 2007 which may be
relevant (www.mailinglistarchive.com/dovecot at dovecot.org/msg07908.html),
in which the original poster's symptoms disappeared when he recompiled
dovecot with gcc-3.4.0 instead of using gcc-3.1. In my case I used
gcc-4.1.2, so I don't know if that's still relevant (and if so, what
other version to use instead).
In the output of `dovecot -n` which follows,
/local/pkg/dovecot/localmods/wrapper.imap is a locally written program
which registers the user's IMAP or POP connection in the lastlog file
and also ensures that the user's shell is considered valid. I'd be
surprised if this is relevant, but I've appended the source code in
case it may be (and/or in case anyone else may find it useful!).
I've been working around the problem by deleting the contents of
~user/.imap for affected users, but I'd really prefer to fix it
properly. :-) Any suggestions would be gratefully received.
Thanks,
- Steven
# server type = SunFire X4100 (two dual-core Opteron CPUs)
# OS = Linux (Slamd64 12.0)
# file system type = XFS
# uname -a
Linux alcor 2.6.25.2 #1 SMP Fri May 16 07:06:34 EDT 2008 x86_64 x86_64 x86_64 GNU/Linux
# dovecot --version
1.1.3
# (limit descriptors 4096; dovecot -n)
# 1.1.3: /local/pkg/dovecot/root-dovecot-1.1.3/etc/dovecot.conf
base_dir: /local/pkg/dovecot/data/var/run/dovecot
syslog_facility: local0
protocols: imap imaps pop3 pop3s
listen(default): *:143
listen(imap): *:143
listen(pop3): *:110
ssl_listen(default): *:993
ssl_listen(imap): *:993
ssl_listen(pop3): *:995
ssl_cert_file: /public/apache/ssl/combined.cert
ssl_key_file: /public/apache/ssl/key.pem
disable_plaintext_auth: no
login_dir: /local/pkg/dovecot/data/var/run
login_executable(default): /local/pkg/dovecot/root-dovecot-1.1.3/libexec/dovecot/imap-login
login_executable(imap): /local/pkg/dovecot/root-dovecot-1.1.3/libexec/dovecot/imap-login
login_executable(pop3): /local/pkg/dovecot/root-dovecot-1.1.3/libexec/dovecot/pop3-login
login_user: nul-mail
login_log_format_elements: [%p] %u %r %c
login_greeting_capability(default): yes
login_greeting_capability(imap): yes
login_greeting_capability(pop3): no
login_processes_count: 6
login_max_processes_count: 512
max_mail_processes: 1024
verbose_proctitle: yes
first_valid_uid: 111
mail_location: mbox:~/:INBOX=/var/spool/mail/%u
mail_full_filesystem_access: yes
mail_executable(default): /local/pkg/dovecot/localmods/wrapper.imap
mail_executable(imap): /local/pkg/dovecot/localmods/wrapper.imap
mail_executable(pop3): /local/pkg/dovecot/localmods/wrapper.pop3
mail_plugin_dir(default): /local/pkg/dovecot/root-dovecot-1.1.3/lib/dovecot/imap
mail_plugin_dir(imap): /local/pkg/dovecot/root-dovecot-1.1.3/lib/dovecot/imap
mail_plugin_dir(pop3): /local/pkg/dovecot/root-dovecot-1.1.3/lib/dovecot/pop3
mail_log_prefix: %Ls[%p] %u, %r:
imap_capability(default): IMAP4rev1 QUOTA SASL-IR SORT THREAD=REFERENCES MULTIAPPEND UNSELECT LITERAL+ IDLE CHILDREN NAMESPACE LOGIN-REFERRALS
imap_capability(imap): IMAP4rev1 QUOTA SASL-IR SORT THREAD=REFERENCES MULTIAPPEND UNSELECT LITERAL+ IDLE CHILDREN NAMESPACE LOGIN-REFERRALS
imap_capability(pop3):
imap_client_workarounds(default): delay-newmail tb-extra-mailbox-sep
imap_client_workarounds(imap): delay-newmail tb-extra-mailbox-sep
imap_client_workarounds(pop3):
pop3_client_workarounds(default):
pop3_client_workarounds(imap):
pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh
pop3_logout_format(default): top=%t/%p, retr=%r/%b, del=%d/%m, size=%s
pop3_logout_format(imap): top=%t/%p, retr=%r/%b, del=%d/%m, size=%s
pop3_logout_format(pop3): top=%t/%p, retr=%r/%b, del=%d/%m, size=%s, xfer=%i/%o
auth default:
cache_negative_ttl: 0
passdb:
driver: shadow
userdb:
driver: passwd
# source code for /local/pkg/dovecot/localmods/wrapper.imap
# and /local/pkg/dovecot/localmods/wrapper.pop3
# follows:
8<---------------------------- cut here -------------------------->8
/*
* wrapper.c -- login wrapper program for dovecot
*
* Steven Winikoff
* 2008/01/31
*
* Part of this program is based on code written by Sylvain Robitaille.
*
* The intention is twofold:
*
* 1) ensure that IMAP and POP sessions are registered in the
* system's lastlog file
*
* 2) ensure that all IMAP and POP users have a valid login shell
*
* Rather than hack the code for the dovecot server directly, this use
* of a wrapper is based on dovecot's intrinsic "post-login scripting"
* facility; for details, see http://wiki.dovecot.org/PostLoginScripting
*/
#include <unistd.h>
#include <stdlib.h>
#include <string.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <lastlog.h>
#include <fcntl.h>
#include <pwd.h>
#include <syslog.h>
#include <errno.h>
#include <time.h>
#define STRLEN 1024+1
#define LASTLOG "/var/adm/lastlog"
#define NEWSHELL "/local/paths/newshell"
#define BLOCKSHELL "/local/paths/blocksh"
#define REAL_IMAP_SERVER "/local/paths/dovecot-imap"
#define REAL_POP3_SERVER "/local/paths/dovecot-pop3"
#define REAL_IMAP_NAME "dovecot-imap"
#define REAL_POP3_NAME "dovecot-pop3"
#define LOGNAME "dovecot: wrapper"
int valid_shell(char *);
void update_lastlog(uid_t, char *, char *);
/*-----------------------------------------------------------------------*/
int main(int argc, char **argv)
{
char service[STRLEN];
char server[STRLEN], server_name[STRLEN], *u, *rh;
int unknown_service = 0, len;
struct passwd *p;
/** the service name we've been invoked to wrap is determined **/
/** by the last four characters of our own basename ("imap" or **/
/** "pop3"): **/
len = strlen(argv[0]);
(void)strcpy(service, argv[0] + (len-4));
if (strcmp(service, "imap") == 0)
{
(void)strcpy(server, REAL_IMAP_SERVER);
(void)strcpy(server_name, REAL_IMAP_NAME);
}
else if (strcmp(service, "pop3") == 0)
{
(void)strcpy(server, REAL_POP3_SERVER);
(void)strcpy(server_name, REAL_POP3_NAME);
}
else
{
unknown_service = 1;
}
/** prepare to log: **/
openlog(LOGNAME, LOG_PID, LOG_LOCAL0);
if (unknown_service)
{
syslog(LOG_INFO, "can't handle unknown service '%s'", service);
exit(1);
}
/** $USER is the only way we can determine who called us: **/
if (! (u = getenv("USER")))
{
syslog(LOG_INFO, "aborting: no value supplied for $USER");
exit(2);
}
/** likewise, $IP is our only source for the host we were called **/
/** from: **/
if (! (rh = getenv("IP")))
{
syslog(LOG_INFO, "aborting: no value supplied for (remote host) $IP");
exit(3);
}
/** grab $USER's password file entry: **/
if (! (p = getpwnam(u)))
{
syslog(LOG_INFO, "aborting: can't find a passwd entry for %s", u);
exit(4);
}
/** is this user blocked? **/
if (strcmp(p->pw_shell, BLOCKSHELL) == 0)
{
/** yes, so we're out of here: **/
syslog(LOG_INFO, "aborting: %s is blocked", u);
exit(5);
}
/** okay, but is the user's shell recognized? **/
if (! valid_shell(p->pw_shell))
{
syslog(LOG_INFO, "aborting: %s has invalid shell %s",
u, p->pw_shell);
exit(6);
}
/** update the user's lastlog entry: **/
update_lastlog(p->pw_uid, service, rh);
/** now run the real program for the requested service: **/
syslog(LOG_INFO, "%s, %s, %s", service, u, rh);
argv[0] = server_name;
(void) execv(server, argv);
/** if we're still here, execv() failed: **/
syslog(LOG_INFO, "execv(%s) FAILED (%s), %s, %s",
server_name, strerror(errno), u, rh);
return(7);
}
/*-----------------------------------------------------------------------*/
int valid_shell(char *s)
/*
* return 1 if s represents a valid login shell, or 0 otherwise
*
* for our purposes, "valid" means anything returned by getusershell(3),
* or NEWSHELL as a special case
*/
{
char *next_shell;
/** a NULL pointer can't be a valid shell: **/
if (! s) return(0);
/** NEWSHELL is always valid: **/
if (strcmp(s, NEWSHELL) == 0) return(1);
/** okay, we have to consult /etc/shells: **/
while ((next_shell = getusershell()) != NULL)
{
if (strcmp(s, next_shell) == 0)
{
endusershell();
return(1);
}
}
/** if we're still here, we don't have a valid shell: **/
endusershell();
return(0);
}
/*-----------------------------------------------------------------------*/
void update_lastlog(uid_t uid, char *service, char *remote_system)
/*
* records the user's activity in the system lastlog file.
*
* Sylvain Robitaille (using code borrowed from the ssh source)
*
* 1997/11/21
* 2000/07/31 (call with the uid as a parameter)
*
*/
{
int fd;
struct lastlog ll;
const char *lastlog = LASTLOG;
/** initialize the lastlog structure: **/
memset(&ll, 0, sizeof(ll));
/** fill in the data: **/
ll.ll_time = time(NULL);
strncpy(ll.ll_line, service, sizeof(ll.ll_line));
strncpy(ll.ll_host, remote_system, sizeof(ll.ll_host));
/** update the lastlog file: **/
if ((fd = open(lastlog, O_RDWR)) >= 0)
{
lseek(fd, (off_t)(uid * sizeof(ll)), 0);
if(write(fd, &ll, sizeof(ll)) != sizeof(ll))
{
syslog(LOG_INFO, "Could not write %.100s: %.100s",
lastlog, strerror(errno));
}
close(fd);
}
else
{
syslog(LOG_INFO, "Could not open %.100s: %.100s",
lastlog, strerror(errno));
}
}
8<---------------------------- cut here -------------------------->8
________________________________________________________________________
Steven Winikoff |
Concordia University | Doyle's Law:
Montreal, QC, Canada | Expenditures shall rise
smw at alcor.concordia.ca | automatically to absorb any
http://alcor.concordia.ca/~smw | increased income.
More information about the dovecot
mailing list