List Info

Thread: Quota plugin, Maildir, dict backend loop problem




Quota plugin, Maildir, dict backend loop problem
country flaguser name
United States
2007-07-24 16:09:23
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',
'userexample.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/storagen", 4044) = 20
fcntl64(9, F_SETFL, O_RDWR_NONBLOCK
)  = 0
read(9, 0x9271eb8, 8192)                = -1 EAGAIN
(Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR)             = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO,
"20033411", 8) = 0
write(9, "l3SELECT current FROM quota
W"..., 112) = 112
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "11", 4)                  = 4
read(9, "1", 1)                        = 1
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "62", 4)                   = 4
read(9,
"3def10vpopmail5quota5quota7curren"..., 54) =
54
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "13", 4)                  = 4
read(9, "376", 1)                      = 1
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "n4", 4)                  = 4
read(9, "t582670292", 10)              = 10
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "55", 4)                  = 4
read(9, "3762", 5)              = 5
write(20, "O582670292n", 11)           = 11
read(10,
"B1nA1tpriv/quota/storaget-24324n"..., 4043) =
35
fcntl64(9, F_SETFL, O_RDWR_NONBLOCK
)  = 0
read(9, 0x9271eb8, 8192)                = -1 EAGAIN
(Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR)             = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO,
"20033411", 8) = 0
write(9, "63BEGIN", 10)         = 10
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "71", 4)                  = 4
read(9, "3", 7)            = 7
fcntl64(9, F_SETFL, O_RDWR_NONBLOCK
)  = 0
read(9, 0x9271eb8, 8192)                = -1 EAGAIN
(Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR)             = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO,
"20033411", 8) = 0
write(9, "2473INSERT INTO quota
(current,"..., 171) = 171
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "71", 4)                  = 4
read(9, "23", 7)            = 7
fcntl64(9, F_SETFL, O_RDWR_NONBLOCK
)  = 0
read(9, 0x9271eb8, 8192)                = -1 EAGAIN
(Resource
temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR)             = 0
setsockopt(9, SOL_SOCKET, SO_SNDTIMEO,
"20033411", 8) = 0
write(9, "73COMMIT", 11)        = 11
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO,
"20033411", 8) = 0
read(9, "71", 4)                  = 4
read(9, "2", 7)            = 7
write(10, "On", 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,  <unfinished ...>
Process 19816 detached


$ /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


Quota transaction bug? (was: Re: Quota plugin, Maildir, dict backend loop problem)
country flaguser name
New Zealand
2007-07-24 16:23:34
On Tue, Jul 24, 2007 at 02:09:23PM -0700, David Jonas
wrote:
> < SELECT current FROM quota WHERE ...
> > 513965019
> < BEGIN
> < INSERT INTO quota (current, ...
> < COMMIT
> > ??  (error_r appears to be (null))

Unrelated to the original post, but the above would appear
to be a bug to me.

Because the SELECT is done before the transaction starts,
the value in the
INSERT which is based on the SELECT may no longer be
consistent with the
actual value in that table.

I had a look through the code as I wanted to include a patch
to move the SELECT
into the transaction with this email, but I'm not familiar
enough with the
Dovecot codebase to find the code that performs the above
SQL. If anyone can
point me in the right direction I'd be happy to submit a
patch.

Jasper

Re: Quota transaction bug?
country flaguser name
United States
2007-07-24 16:46:11
Jasper Bryant-Greene wrote:
> On Tue, Jul 24, 2007 at 02:09:23PM -0700, David Jonas
wrote:
>> < SELECT current FROM quota WHERE ...
>>> 513965019
>> < BEGIN
>> < INSERT INTO quota (current, ...
>> < COMMIT
>>> ??  (error_r appears to be (null))
> 
> Unrelated to the original post, but the above would
appear to be a bug to me.
> 
> Because the SELECT is done before the transaction
starts, the value in the
> INSERT which is based on the SELECT may no longer be
consistent with the
> actual value in that table.

I don't think it uses the value. The INSERT statement that
comes next
does an UPDATE if the key exists. The value represented as 0
here is the
change in quota value:

INSERT INTO quota (current, path, username) VALUES (0,
'quota/storage',
'userexample.com') ON DUPLICATE KEY UPDATE current =
current + 0;

So it's only added to or inserted, never changed then
replaced.

> I had a look through the code as I wanted to include a
patch to move the SELECT
> into the transaction with this email, but I'm not
familiar enough with the
> Dovecot codebase to find the code that performs the
above SQL. If anyone can
> point me in the right direction I'd be happy to submit
a patch.
> 
> Jasper

Re: Quota transaction bug?
country flaguser name
New Zealand
2007-07-24 16:54:57
On Tue, Jul 24, 2007 at 02:46:11PM -0700, David Jonas
wrote:
> Jasper Bryant-Greene wrote:
> > On Tue, Jul 24, 2007 at 02:09:23PM -0700, David
Jonas wrote:
> >> < SELECT current FROM quota WHERE ...
> >>> 513965019
> >> < BEGIN
> >> < INSERT INTO quota (current, ...
> >> < COMMIT
> >>> ??  (error_r appears to be (null))
> > 
> > Unrelated to the original post, but the above
would appear to be a bug to me.
> > 
> > Because the SELECT is done before the transaction
starts, the value in the
> > INSERT which is based on the SELECT may no longer
be consistent with the
> > actual value in that table.
> 
> I don't think it uses the value. The INSERT statement
that comes next
> does an UPDATE if the key exists. The value represented
as 0 here is the
> change in quota value:
> 
> INSERT INTO quota (current, path, username) VALUES (0,
'quota/storage',
> 'userexample.com') ON DUPLICATE KEY UPDATE current =
current + 0;
> 
> So it's only added to or inserted, never changed then
replaced.

OK, so absolutely nothing about the INSERT (including
whether or not it is
performed) depends on anything about the result from the
SELECT?

Jasper

Re: Quota plugin, Maildir, dict backend loop problem
country flaguser name
Finland
2007-07-24 22:11:38
On 25.7.2007, at 0.09, David Jonas wrote:

> 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.
..
> INSERT INTO quota (current, path, username) VALUES (0,
'quota/ 
> storage',
> 'userexample.com') ON DUPLICATE KEY UPDATE current =
current + 0;

You do have a unique index key on path+username and nothing
else, right?

It worked with me last I tried..

Re: Quota plugin, Maildir, dict backend loop problem
country flaguser name
United States
2007-07-25 11:43:28
Timo Sirainen wrote:
> On 25.7.2007, at 0.09, David Jonas wrote:
> 
>> 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.
> ..
>> INSERT INTO quota (current, path, username) VALUES
(0, 'quota/storage',
>> 'userexample.com') ON DUPLICATE KEY UPDATE
current = current + 0;
>
> You do have a unique index key on path+username and
nothing else, right?

Sure do. Just like the docs.

> It worked with me last I tried..

I think I found the problem. I had an aggressive exported
CFLAGS line
from a recent memcache compile:

 CFLAGS="-O3 -march=pentium4 -mmmx -msse2"

Recompiled after clearing CFLAGS and it seems to work fine
now. Guess
something important got optimized away.

I'm having some other issues, like the entries being wildly
inaccurate
(1.6G for an account with no mail) and some updating issues.
But quotas
aren't overly pressing, so should I just wait for v1.1? Is
v1.1alpha1
stable enough for some production time? I haven't seen much
noise about
it on the list. Perhaps I should toss it in the water...

Thanks for your help,

David


[1-6]

about | contact  Other archives ( Real Estate discussion Medical topics )