Re: long delay in getting lock on 2.4.16

2012-11-14 Thread Bron Gondwana
On Wed, Nov 14, 2012, at 12:53 PM, Deniss wrote:
 hello !
 
 I have an issue with cyrus-imapd-2.4.16 and locks.
 cmdtimer reports long time execution like this:
 
 Nov 14 08:47:15 brat5 imap[16897]: cmdtimer: 'ega9024' 'status' 'none' 
 '24.577343' '0.00'
 Nov 14 10:18:02 brat5 imap[26631]: cmdtimer: 'evijanagle' 'select' 
 'user.evijanagle.Photos' '24.136381' '0.00'
 Nov 14 10:18:02 brat5 imap[26622]: cmdtimer: 'evijanagle' 'select' 
 'user.evijanagle.Photos' '31.103348' '0.00'
 Nov 14 10:58:32 brat5 imap[30646]: cmdtimer: 'egil^k' 'status' 'none' 
 '22.480196' '0.00'
 Nov 14 10:58:32 brat5 imap[30708]: cmdtimer: 'egil^k' 'status' 'none' 
 '10.285937' '0.00'
 
 i traced down to func mailbox_lock_index() where following code produces 
 delays:
 
  if (locktype == LOCK_EXCLUSIVE)
  r = lock_blocking(mailbox-index_fd);
  else
  r = lock_shared(mailbox-index_fd);
 
 lock files are stored in tmpfs
 
 
 what is the problem may be here ?

Smells like cyr_expire is running.  Do you get cyr_expire log entries around
the same time?  It needs an exclusive lock while it repacks the index, so you
should notice that the mailbox was being repacked, and these other programs
had to wait until the lock was freed before they could open the mailbox.

This would be caused by having quite high IO wait times (or very large folders)
for those users.

Bron.
-- 
  Bron Gondwana
  br...@fastmail.fm


Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus


Re: long delay in getting lock on 2.4.16

2012-11-14 Thread Deniss
well, i see reconstruct is running in that time which has exclusive lock 
as well i assume.

thanx Brong for pointing.


On 14.11.2012 14:51, Bron Gondwana wrote:
 On Wed, Nov 14, 2012, at 12:53 PM, Deniss wrote:
 hello !

 I have an issue with cyrus-imapd-2.4.16 and locks.
 cmdtimer reports long time execution like this:

 Nov 14 08:47:15 brat5 imap[16897]: cmdtimer: 'ega9024' 'status' 'none'
 '24.577343' '0.00'
 Nov 14 10:18:02 brat5 imap[26631]: cmdtimer: 'evijanagle' 'select'
 'user.evijanagle.Photos' '24.136381' '0.00'
 Nov 14 10:18:02 brat5 imap[26622]: cmdtimer: 'evijanagle' 'select'
 'user.evijanagle.Photos' '31.103348' '0.00'
 Nov 14 10:58:32 brat5 imap[30646]: cmdtimer: 'egil^k' 'status' 'none'
 '22.480196' '0.00'
 Nov 14 10:58:32 brat5 imap[30708]: cmdtimer: 'egil^k' 'status' 'none'
 '10.285937' '0.00'

 i traced down to func mailbox_lock_index() where following code produces
 delays:

   if (locktype == LOCK_EXCLUSIVE)
   r = lock_blocking(mailbox-index_fd);
   else
   r = lock_shared(mailbox-index_fd);

 lock files are stored in tmpfs


 what is the problem may be here ?

 Smells like cyr_expire is running.  Do you get cyr_expire log entries around
 the same time?  It needs an exclusive lock while it repacks the index, so you
 should notice that the mailbox was being repacked, and these other programs
 had to wait until the lock was freed before they could open the mailbox.

 This would be caused by having quite high IO wait times (or very large 
 folders)
 for those users.

 Bron.


Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus