Hello,
I've been working with the quota plugin(s) the past few days and have been having some real trouble. Only a few entries are appearing in the database, a couple more when I restarted dovecot. None of the current entries were being updated either.
I think I've tracked it down to somewhere in the dict backend. I put in a few i_info() statements and recompiled. A few queries get through, then it seems to try the same query about three times and then no new more queries at all (the i_info is right after the allocation of the query string). I couldn't find any errors in the log.
An strace of the dict pid shows the following loop. Dovecot -n to follow as well.
A quick tcpdump showed a loop something like this:
< SELECT current FROM quota WHERE ...
513965019 < BEGIN < INSERT INTO quota (current, ... < COMMIT ?? (error_r appears to be (null)) .. repeat ..
In all my tests it appears that the quota value being set during the loop is 0, but that would be the most common case anyway. An insert query would look like this:
INSERT INTO quota (current, path, username) VALUES (0, 'quota/storage', 'user@example.com') ON DUPLICATE KEY UPDATE current = current + 0;
Help on what to do/try next would greatly be appreciated.
Thanks,
David
$ strace -p 19816
epoll_wait(5, {{EPOLLIN, {u32=153555248, u64=153555248}}, {EPOLLIN,
{u32=153601240, u64=153601240}}, {EPOLLIN|EPOLLHUP, {u32=153567344,
u64=153567344}}}, 29, 2147483647) = 3
gettimeofday({1185308526, 494477}, {420, 0}) = 0
read(20, "Lpriv/quota/storage\n", 4044) = 20
fcntl64(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(9, 0x9271eb8, 8192) = -1 EAGAIN (Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR) = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
write(9, "l\0\0\0\3SELECT current FROM quota W"..., 112) = 112
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "\1\0\0\1", 4) = 4
read(9, "\1", 1) = 1
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "6\0\0\2", 4) = 4
read(9, "\3def\10vpopmail\5quota\5quota\7curren"..., 54) = 54
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "\1\0\0\3", 4) = 4
read(9, "\376", 1) = 1
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "\n\0\0\4", 4) = 4
read(9, "\t582670292", 10) = 10
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "\5\0\0\5", 4) = 4
read(9, "\376\0\0\2\0", 5) = 5
write(20, "O582670292\n", 11) = 11
read(10, "B1\nA1\tpriv/quota/storage\t-24324\n"..., 4043) = 35
fcntl64(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(9, 0x9271eb8, 8192) = -1 EAGAIN (Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR) = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
write(9, "\6\0\0\0\3BEGIN", 10) = 10
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "\7\0\0\1", 4) = 4
read(9, "\0\0\0\3\0\0\0", 7) = 7
fcntl64(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(9, 0x9271eb8, 8192) = -1 EAGAIN (Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR) = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
write(9, "\247\0\0\0\3INSERT INTO quota (current,"..., 171) = 171
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "\7\0\0\1", 4) = 4
read(9, "\0\2\0\3\0\0\0", 7) = 7
fcntl64(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(9, 0x9271eb8, 8192) = -1 EAGAIN (Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR) = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
write(9, "\7\0\0\0\3COMMIT", 11) = 11
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
read(9, "\7\0\0\1", 4) = 4
read(9, "\0\0\0\2\0\0\0", 7) = 7
write(10, "O\n", 2) = 2
read(14, "", 3998) = 0
epoll_ctl(5, EPOLL_CTL_DEL, 14, {0, {u32=153567344, u64=153567344}}) = 0
close(14) = 0
epoll_wait(5, {{EPOLLIN|EPOLLHUP, {u32=153601240, u64=153601240}}}, 29,
2147483647) = 1
gettimeofday({1185308526, 500644}, {420, 0}) = 0
read(10, "", 4008) = 0
epoll_ctl(5, EPOLL_CTL_DEL, 10, {0, {u32=153601240, u64=153601240}}) = 0
close(10) = 0
epoll_wait(5,
$ /usr/local/dovecot/sbin/dovecot -n
# 1.0.2: /etc/dovecot.conf protocols: imap pop3 ssl_disable: yes disable_plaintext_auth: no login_dir: /usr/local/dovecot/var/run/dovecot/login login_executable(default): /usr/local/dovecot/libexec/dovecot/imap-login login_executable(imap): /usr/local/dovecot/libexec/dovecot/imap-login login_executable(pop3): /usr/local/dovecot/libexec/dovecot/pop3-login login_greeting: postoffice.no-ip.com login_log_format_elements: user=<%u@%d> method=%m rip=%r lip=%l %c login_process_per_connection: no verbose_proctitle: yes first_valid_uid: 89 maildir_stat_dirs: yes maildir_copy_with_hardlinks: yes mail_executable(default): /usr/local/dovecot/libexec/dovecot/imap mail_executable(imap): /usr/local/dovecot/libexec/dovecot/imap mail_executable(pop3): /usr/local/dovecot/libexec/dovecot/pop3 mail_plugins(default): quota imap_quota mail_plugins(imap): quota imap_quota mail_plugins(pop3): quota mail_plugin_dir(default): /usr/local/dovecot/lib/dovecot/imap mail_plugin_dir(imap): /usr/local/dovecot/lib/dovecot/imap mail_plugin_dir(pop3): /usr/local/dovecot/lib/dovecot/pop3 mail_log_prefix: %Us(%u)[%p]: pop3_uidl_format(default): pop3_uidl_format(imap): pop3_uidl_format(pop3): %f pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh auth default: cache_size: 100 cache_ttl: 600 user: nobody username_translation: %@ username_format: %Lu verbose: yes passdb: driver: sql args: /etc/dovecot-sql.conf userdb: driver: prefetch plugin: quota: dict:storage=102400000 proxy::quotadict dict: quotadict: mysql:/etc/dovecot-dict-quota.conf
$ cat /etc/dovecot-dict-quota.conf connect = host=192.168.15.25 dbname=vpopmail user=xxx password=xxx table = quota select_field = current where_field = path username_field = username
$ cat /etc/redhat-release Red Hat Enterprise Linux ES release 4 (Nahant Update 5)
$ rpm -qa | grep -i mysql MySQL-devel-standard-4.1.22-0.rhel4 MySQL-shared-standard-4.1.22-0.rhel4 MySQL-client-standard-4.1.22-0.rhel4
$ lsof -c dict -n COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME dict 19816 root cwd DIR 8,5 4096 464289 /usr/local/dovecot/var/run/dovecot dict 19816 root rtd DIR 8,7 4096 2 / dict 19816 root txt REG 8,5 1868454 464309 /usr/local/dovecot/libexec/dovecot/dict dict 19816 root mem REG 8,7 47404 160369 /lib/libnss_files-2.3.4.so dict 19816 root mem REG 8,7 112168 160456 /lib/ld-2.3.4.so dict 19816 root mem REG 8,7 1529008 163193 /lib/tls/libc-2.3.4.so dict 19816 root mem REG 8,7 16732 165083 /lib/libdl-2.3.4.so dict 19816 root mem REG 8,7 213772 165079 /lib/tls/libm-2.3.4.so dict 19816 root mem REG 8,7 107800 165077 /lib/tls/libpthread-2.3.4.so dict 19816 root mem REG 8,7 28476 165086 /lib/libcrypt-2.3.4.so dict 19816 root mem REG 8,7 97120 165087 /lib/libnsl-2.3.4.so dict 19816 root 0r CHR 1,3 1797 /dev/null dict 19816 root 1r CHR 1,3 1797 /dev/null dict 19816 root 2w FIFO 0,7 52832717 pipe dict 19816 root 3u unix 0xf4e58180 52832640 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 4r CHR 1,9 466 /dev/urandom dict 19816 root 5r 0000 0,8 0 52832719 eventpoll dict 19816 root 6r FIFO 0,7 52832720 pipe dict 19816 root 7w FIFO 0,7 52832720 pipe dict 19816 root 8u unix 0xf6fac480 52884208 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 9u IPv4 52832745 TCP 192.168.15.55:46058->192.168.15.25:mysql (ESTABLISHED) dict 19816 root 10u unix 0xdae69240 52881759 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 11u unix 0xf36af680 52884148 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 12u unix 0xf505f6c0 52881064 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 13u unix 0xd5d84280 52884278 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 15u unix 0xd1ab9b00 52883941 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 16u unix 0xf6faca80 52884264 /usr/local/dovecot/var/run/dovecot/dict-server dict 19816 root 17u unix 0xf63cb1c0 52884235 /usr/local/dovecot/var/run/dovecot/dict-server