[Dovecot] imaptest10 and stalled messages

Mike Brudenell pmb1 at york.ac.uk
Thu Mar 29 19:52:08 EEST 2007


Greetings -

On 28 Mar 2007, at 20:45, Timo Sirainen wrote:

>> - 12. stalled for 17 secs in LOGIN
>> - 13. stalled for 17 secs in LOGIN
> ..
>
> When this happens, can you manually log in at the same time?

Yes, but SLOWLY.  It's making me think we're pushing the machine and/ 
or its 100Mbit network card too far.  See below for the latest...


> What about running: imaptest - select=0
>
> ie. doing nothing else than login/logout. Does it still hang?

Nope: that works fine (as does imaptest -)


Latest...

I've switched to using a beefier box now: one more like the servers  
we would be buying.  This is a Sun system running Solaris 10 with 4 *  
2.2GHz Opteron processors, 4Gb RAM and a Gigabit Ethernet card.

Starting off with empty Maildirs (NFS-mounted), and non-existent  
index and control files (on local disk), I re-ran my test:

./imaptest10 user=mtest%03d clients=50 host=mail-gw5.york.ac.uk  
mbox=../imaptest/dovecot.mbox msgs=1000 secs=300

At first this looked great, logging all 50 processes in within the  
first second (assuming I'm right in thinking the N/N at the end of  
each line of imaptest output is something to do with this count?)

Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100%
                           30%                  5%
   54    7    3   16    0    0    0    0    0    4    8  50/ 50
   23   21   22   41    4    4    0    0    2   23   46  50/ 50
   35   17   16   35   22   23    0    0   12   35   70  50/ 50
   40   17   20   37   26   31    7    1   24   40   80  50/ 50
   28   17   15   35   28   40    2    0   25   28   56  50/ 50
   27   10    8   24   21   24    3    0   22   27   54  50/ 50
   43   17   21   42   34   44    8    0   32   43   86  50/ 50
   51   23   22   46   37   62    8    1   41   51  102  50/ 50
   39   24   25   44   39   53    4    1   35   39   78  50/ 50
   38   19   20   34   38   58   10    2   39   38   76  50/ 50
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100%
                           30%                  5%
   48   27   26   46   42   58   11    0   44   48   96  50/ 50
   52   23   25   48   44   63   14    2   52   52  104  50/ 50
   43   24   26   43   47   65    9    1   42   44   88  50/ 50
   39   16   23   39   42   48    9    2   37   38   76  50/ 50
   51   24   24   52   49   71   24    2   51   51  102  50/ 50
Error: BAD reply 'Error in IMAP command APPEND: Invalid arguments.'  
for command: APPEND "INBOX" () {134933+}
Error: APPEND replied BAD: Error in IMAP command APPEND: Invalid  
arguments.
   44   24   21   42   46   64   13    4   47   43   86  50/ 50
   53   23   20   48   48   65   21    5   51   54  106  50/ 50
   40   22   26   46   42   58   18    2   41   39   80  50/ 50
   43   19   20   39   41   45   19    4   41   43   86  50/ 50
   35   22   17   37   37   58   22    6   34   35   70  50/ 50

[?? I'm assuming the BAD reply was some General Nastiness in the mbox  
I'm feeding into imaptest10?  It's the dovecot.mbox file from  
dovecot.org that was suggested in a message to the list a while  
back. ??]

But then the ODDNESS starts.  I'm still a little hazy how to  
interpret the output of imaptest, but every now and then one or two  
processes stall for several seconds.  When this happens activity  
seems to grow quieter in the imaptest output: number of operations  
per second decreases and the N/N count drops.  Eventually it clears  
somehow and things spring back into life...

Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100%
                           30%                  5%
   44   24   22   47   45   61   19    5   45   44   88  50/ 50
   45   19   22   39   43   63   17    2   45   45   90  50/ 50
   42   20   20   44   44   65   22    2   45   42   84  50/ 50
- 31. stalled for 16 secs in SELECT
    0    4    4    9    9   21    9    2   21   26   52  24/ 24
   51   16   13   38   36   54    8    1   27   25   50  50/ 50
- 4. stalled for 16 secs in SELECT
- 12. stalled for 16 secs in SELECT
    0   14    9   19   21   31    9    6   30   32   64  18/ 18
    0    0    0    0    0    0    0    0    0    0    0  18/ 18
   43    6    7   14   13   18    6    0   11   11   22  50/ 50
   31   29   28   47   45   48   14    3   34   31   62  50/ 50
   43   16   23   43   43   61   22    5   44   43   86  50/ 50
- 18. stalled for 16 secs in SELECT
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100%
                           30%                  5%
    0    4    6   11   14   29   11    3   26   30   60  20/ 20
- 18. stalled for 17 secs in SELECT
    0    0    2    2    2    5    1    0    2    2    4  18/ 18
- 18. stalled for 18 secs in SELECT
    0    2    1    3    3    3    1    0    3    3    6  15/ 15
- 18. stalled for 19 secs in SELECT
    0    1    1    3    3    6    1    0    3    3    6  12/ 12
- 18. stalled for 20 secs in SELECT
    0    0    1    1    1    5    0    0    1    1    2  11/ 11
- 18. stalled for 21 secs in SELECT
    0    0    1    1    1    5    0    0    1    1    2  10/ 10
- 18. stalled for 22 secs in SELECT
    0    0    1    1    1    1    0    0    1    1    2   9/  9
- 18. stalled for 23 secs in SELECT
    0    0    0    1    1    1    0    0    0    0    0   9/  9
- 18. stalled for 24 secs in SELECT
    0    0    0    0    0    0    0    0    1    1    2   8/  8
- 18. stalled for 25 secs in SELECT
    0    0    0    1    1    1    1    0    1    1    2   7/  7
- 18. stalled for 26 secs in SELECT
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100%
                           30%                  5%
    0    0    0    0    0    0    0    0    0    0    0   7/  7
- 18. stalled for 27 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   7/  7
- 18. stalled for 28 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   7/  7
- 18. stalled for 29 secs in SELECT
    0    2    1    4    4    5    0    1    4    4    8   3/  3
- 18. stalled for 30 secs in SELECT
    0    1    2    2    2    3    0    0    1    1    2   2/  2
- 18. stalled for 31 secs in SELECT
    0    0    0    0    0    0    1    1    1    1    2   1/  1
- 18. stalled for 32 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 33 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 34 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 35 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 36 secs in SELECT
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100%
                           30%                  5%
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 37 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 38 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 39 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 40 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 41 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 42 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 43 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 44 secs in SELECT
    0    0    0    0    0    0    0    0    0    0    0   1/  1
- 18. stalled for 45 secs in SELECT
   67   15   14   28   24   31    6    0   20   18   36  50/ 50
Logi List Stat Sele Fetc Fet2 Stor Dele Expu Appe Logo
100%  50%  50% 100% 100% 100%  50% 100% 100% 100% 100%
                           30%                  5%
   32   28   24   55   54   62   15    3   35   32   64  50/ 50
   53   25   21   43   45   63   27    6   51   53  106  50/ 50
   40   19   22   43   41   57   20    3   42   41   80  50/ 50
   50   22   27   53   53   67   20    4   51   49  100  50/ 50
   49   15   18   44   40   60   21    6   45   49   98  50/ 50
   44   24   19   44   45   61   22    4   43   44   88  50/ 50
   42   24   20   42   47   64   32    7   46   42   84  50/ 50
   55   24   21   45   45   71   26    4   51   55  110  50/ 50
   33   22   22   42   44   52   19    2   35   33   66  50/ 50
   43   18   26   40   38   63   21    7   45   44   86  50/ 50

I'm hoping it's just a fault in imaptest10 rather than something  
nasty in Dovecot or itself.  Any thoughts?  (Dovecot doesn't log any  
errors during any of this activity.)


The mailstore is mounted over NFS from a NetApp filer with these  
options:

remote/read/write/nosetuid/nodevices/bg/intr/proto=tcp/noac/actimeo=0/ 
xattr/dev=4702692


The filestore containing the index and control files is local UFS- 
mounted disk with these options:

read/write/setuid/devices/intr/largefiles/logging/xattr/onerror=panic/ 
dev=154001e


dovecot -n outout is:

# /usr/local/dovecot-1.0.rc28/etc/dovecot.conf
log_path: /logfiles/mail/live/dovecot
info_log_path: /logfiles/mail/live/dovecot-info
ssl_listen: *:993
ssl_cert_file: /usr/local/dovecot/ssl/certs/imapservice-bundle.crt
ssl_key_file: /usr/local/dovecot/ssl/private/imapservice-private.key
disable_plaintext_auth: no
login_dir: /var/run/dovecot/login
login_executable: /usr/local/dovecot-1.0.rc28/libexec/dovecot/imap-login
login_process_per_connection: no
login_greeting_capability: yes
login_process_size: 64
login_processes_count: 10
max_mail_processes: 10000
mail_location: maildir:/mailstore/%1u/%u/Maildir:INDEX=/var/dovecot/ 
index/%1u/%u:CONTROL=/var/dovecot/control/%1u/%u
mmap_disable: yes
maildir_copy_with_hardlinks: yes
mail_plugins: quota imap_quota
mail_log_prefix: %Us(%u)[%p]:
imap_client_workarounds: delay-newmail outlook-idle
namespace:
   type: private
   separator: /
   inbox: yes
auth default:
   mechanisms: plain login
   cache_size: 1024
   cache_ttl: 600
   username_chars:  
abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890
   username_format: %Lu
   passdb:
     driver: shadow
   userdb:
     driver: passwd
   socket:
     type: listen
     client:
     master:
       path: /var/run/dovecot/auth-master
       mode: 384
plugin:
   quota: fs


Any thoughts?

Cheers,
Mike B-)
-- 
The Computing Service, University of York, Heslington, York Yo10 5DD, UK
Tel:+44-1904-433811  FAX:+44-1904-433740

* Unsolicited commercial e-mail is NOT welcome at this e-mail address. *




More information about the dovecot mailing list