Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-12-04 Thread Timo Sirainen
On Wed, 2007-11-28 at 08:09 -0700, Jackie Hunt wrote:
  Problem was that it was reading a 50MB mail in 12kB blocks, and Dovecot
  wasn't handling that very well. Fixed:
  
  http://hg.dovecot.org/dovecot-1.0/rev/0fba164c6ba6
  http://hg.dovecot.org/dovecot-1.0/rev/edd95f9c6ba4
 
 That's awesome!  Thanks so much Timo, you always come through!  
 I'll install the fixes ASAP.

Actually that didn't fix it completely for mbox. This should really fix
it: http://hg.dovecot.org/dovecot-1.0/rev/212777918121



signature.asc
Description: This is a digitally signed message part


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-12-04 Thread Dave McGuire

On Dec 4, 2007, at 9:09 AM, Stewart Dean wrote:
I found this interesting...Finland has just come out tops again in  
the latest PISA evaluation of secondary school student science  
prowess as it has been for some years.  The US, no surprise, comes  
out in the middle as Joe and Jill SixPack think that achievement in  
anything much less math and science (they're hard!) is for geeks.

http://news.bbc.co.uk/1/hi/education/4073753.stm
http://en.wikipedia.org/wiki/ 
Programme_for_International_Student_Assessment

Must be those long winters where there's nothing to do but study :)


  Oh, don't get me started.  I'm so sick of the BudLight-swilling,  
NASCAR-watching, WalMart-loving morons that I'm about ready to go  
find a deserted island somewhere.


 -Dave

--
Dave McGuire
Port Charlotte, FL
Farewell Ophelia, 9/22/1991 - 7/25/2007





Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-11-28 Thread Jackie Hunt
 Problem was that it was reading a 50MB mail in 12kB blocks, and Dovecot
 wasn't handling that very well. Fixed:
 
 http://hg.dovecot.org/dovecot-1.0/rev/0fba164c6ba6
 http://hg.dovecot.org/dovecot-1.0/rev/edd95f9c6ba4

That's awesome!  Thanks so much Timo, you always come through!  
I'll install the fixes ASAP.

Jackie
---
Jackie Hunt   
ACNSVoice:  (970) 663-3789 
Colorado State University   FAX:(970) 491-1958
Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-11-27 Thread Timo Sirainen
On Tue, 2007-11-27 at 11:38 -0700, Jackie Hunt wrote:
  Thanks for the suggestion on the truss command, Timo:
 
  truss -d -rO -w1
 
 We have seen the imap process consuming 100% CPU again, and this time I
 was able to get a trace, but it's too long to post to the list.  I've sent
 a copy to Timo.  Let me know if anyone else would like a copy of it.
 
 This user is running Thunderbird on Solaris, and has at least two
 IMAP connections open continuously, one to a UofW server running on
 Solaris (I think), the other to Dovecot running on AIX.  He has problems
 with the Dovecot connection hanging on him each morning.  Thunderbird
 shows an hourglass, but he gets not indication of what is happening.
 He has to shut down Thunderbird to get it working again.  It's a bit
 ironic/humorous, but his UofW connection is fine in Thunderbird, and
 that's how he notifies me his Dovecot imap is hung up.

Problem was that it was reading a 50MB mail in 12kB blocks, and Dovecot
wasn't handling that very well. Fixed:

http://hg.dovecot.org/dovecot-1.0/rev/0fba164c6ba6
http://hg.dovecot.org/dovecot-1.0/rev/edd95f9c6ba4



signature.asc
Description: This is a digitally signed message part


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-11-20 Thread Jackie Hunt
:w On Mon, 2007-11-19 at 16:12 -0500, Stewart Dean wrote:
  I think I'm seeing this with TBird and 1.0.7...with my own account!  It
  may even be a Tbird problem.
  I have a 4way mail server, so when I get 25%, it's 100% of one
  processor. I tried killing the imap process on the server and  it can
  back at 9% and climbed quickly back up to 25%.  It wasn't until I
  shutdown my TBird session that a clean imap session was established.
 
 You could truss the process or do something else to find out what
 Thunderbird and Dovecot are talking to each others. If shutting down
 Thunderbird dropped the load, it sounds like a bug in Thunderbird. Some
 clients have been known to keep requesting same data over and over again
 from the server in some situations. If I could see what the IMAP traffic
 looks like, I might be able to add a workaround to it.
 

What Stewart describes sounds exactly like what we are seeing.  Killing the
imap process doesn't change anything, it requires the client to be shut down
to avoid using 100% CPU.  We have a user who was seeing this every morning.  
However, something has changed and he now sees it about every 7 to 10 days.  
Another interesting note is that he didn't see the issue when we were
running U of Wash's imap server.

Thanks for the suggestion on the truss command, Timo:

truss -d -rO -w1

I'll definitely post my results when I have some.

Jackie
---
Jackie Hunt   
ACNSVoice:  (970) 663-3789 
Colorado State University   FAX:(970) 491-1958
Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-11-19 Thread Stewart Dean
I think I'm seeing this with TBird and 1.0.7...with my own account!  It 
may even be a Tbird problem.
I have a 4way mail server, so when I get 25%, it's 100% of one 
processor. I tried killing the imap process on the server and  it can 
back at 9% and climbed quickly back up to 25%.  It wasn't until I 
shutdown my TBird session that a clean imap session was established.



Jackie Hunt wrote:

Is this behavior cured, or do you continue to see it?




No, the behavior isn't cured.  We still continue to see it 
with various clients.  I have posted a couple of truss outputs,
but so far no resolution.  


Sorry for the slow response.  I've been fighting other fires.

Jackie


  

Jackie Hunt wrote:


On Mon, 2007-09-03 at 12:37 +0200, Robert Tomanek wrote:



Hi,

Sunday, September 2, 2007, 22:42:37, you wrote:
  
  

0x0806049d in imap_sync_more (ctx=3D0x80d9770) at imap-sync.c:104
104 if (ctx-seq =3D=3D 0) {
  
  

 A short follow-up on this, looks like an infinite loop to me, unless
 some threading magic is supposed to happen here:
  
  

Fixed: http://hg.dovecot.org/dovecot-1.0/rev/8e86137a04fb



We also are seeing imap processes consuming 100% CPU.  We have
installed Dovecot v1.0.5 and still see the problem.  I have a user 
who can pretty reliably reproduce the problem.  It occurs each

morning after the imap connection has been idling all night.  The
user is running Thunderbird 2.0.0.6 (I think) on Solaris.  On the
client side, he see an hourglass that never goes away, has to shut
down Thunderbird.

Below is a log, which shows how the CPU is being used (the ps commands
are done one right after another) and a dbx trace of the state of
the imap process.  I'm hoping that's enough info to figure out what's
happening.

Thanks much,
Jackie
---
Jackie Hunt   
ACNSVoice:  (970) 663-3789 
Colorado State University   FAX:(970) 491-1958

Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]


$ ps -ef | grep -i xx | grep imap
  xx  43004  92942  74 07:15:33  - 38:54 imap 
$ ps -ef | grep -i xx | grep imap
  xx  43004  92942  81 07:15:33  - 38:58 imap 
$ ps -ef | grep -i xx | grep imap
  xx  43004  92942 120 07:15:33  - 39:01 imap 
$ dbx -a 43004

Waiting to attach to process 43004 ...
Successfully attached to imap.
warning: Directory containing imap could not be determined.
Apply 'use' command to initialize source path.

Type 'help' for help.
reading symbolic information ...
stopped in pread at 0xd01f06cc
0xd01f06cc (pread+0x30) 80410014lwz   r2,0x14(r1)
(dbx) step
stopped in istream-file._read at line 120 in file 
could not read istream-file.c
(dbx) use src lib src/lib src/lib-storage/index/mbox src/lib-mail 
src/lib-storage/index src/lib-storage src/imap src/imap-login
(dbx) use
src lib src/lib src/lib-storage/index/mbox src/lib-mail src/lib-storage/index src/lib-storage src/imap src/imap-login 
(dbx) where

istream-file._read(stream = 0x200274a8), line 120 in istream-file.c
i_stream_read(stream = 0x200274cc), line 58 in istream.c
istream-raw-mbox._read(stream = 0x20028ab8), line 160 in istream-raw-mbox.c
i_stream_read(stream = 0x20028adc), line 58 in istream.c
istream-limit._read(stream = 0x20031458), line 56 in istream-limit.c
i_stream_read(stream = 0x2003147c), line 58 in istream.c
istream-header-filter._read(stream = 0x2004aa98), line 234 in 
istream-header-filter.c
i_stream_read(stream = 0x2004aabc), line 58 in istream.c
i_stream_read_data(stream = 0x2004aabc, data = 0x2ff22630, size = 0x2ff22638, threshold = 
1), line 250 in istream.c
message_get_body_size(input = 0x2004aabc, body = 0x2002827c, has_nuls = (nil)), line 107 
in message-size.c
index_mail_init_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
0x2ff227b8), line 502 in index-mail.c
mbox_mail_get_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), 
line 206 in mbox-mail.c
mail_get_stream(mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), line 
107 in mail.c
imap-fetch-body.fetch_body(ctx = 0x200205e0, mail = 0x200281a8, context = 0x20020858), 
line 331 in imap-fetch-body.c
imap_fetch(ctx = 0x200205e0), line 291 in imap-fetch.c
cmd_fetch(cmd = 0x2001e35c), line 163 in cmd-fetch.c
cmd_uid(cmd = 0x2001e35c), line 19 in cmd-uid.c
client_handle_input(cmd = 0x2001e35c), line 344 in client.c
client_handle_input(cmd = 0x2001e35c), line 398 in client.c
_client_input(context = 0x2001e318), line 441 in client.c
io_loop_handler_run(ioloop = 0x2001d0e8), line 199 in ioloop-poll.c
io_loop_run(ioloop = 0x2001d0e8), line 329 in ioloop.c
main(argc = 1, argv = 0x2ff22b50, envp = 0x2ff22b58), line 290 in main.c
(dbx) list
   58   return _stream-read(_stream);
   59   }
   60   
   61   void i_stream_skip(struct istream *stream, uoff_t count)

   62   

Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-11-19 Thread Timo Sirainen
On Sun, 2007-10-21 at 00:47 +0300, Timo Sirainen wrote:
 On Wed, 2007-10-10 at 10:50 -0600, Jackie Hunt wrote:
  Attached is the truss for the imap process we are seeing which is
  chewing up CPU.  We've seen this issue on several different clients,
  usually first thing in the morning.  Shutting down the client and
  restarting always seems to get Dovecot back in sync.   Hope we can
  get some help with this.   We're running 1.0.5.  Thanks!
 
 The truss output looks like Dovecot re-reads the entire mbox file for
 each FETCH command. Did you use NFS? Do you have mbox_dirty_syncs=yes
 (default)?
 
 Anyway this isn't an infinite loop in Dovecot. It's processing multiple
 FETCH commands. Maybe the client got stuck somehow and just keeps
 sending the same command over and over again? Would have been nice to
 see the entire FETCH command and its output. truss -r0 -w1 does that I
 think.

truss -d -r0 -w1 for future reference. That includes nice timestamps
and also shows the IMAP traffic.



signature.asc
Description: This is a digitally signed message part


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-11-19 Thread Timo Sirainen
On Mon, 2007-11-19 at 16:12 -0500, Stewart Dean wrote:
 I think I'm seeing this with TBird and 1.0.7...with my own account!  It 
 may even be a Tbird problem.
 I have a 4way mail server, so when I get 25%, it's 100% of one 
 processor. I tried killing the imap process on the server and  it can 
 back at 9% and climbed quickly back up to 25%.  It wasn't until I 
 shutdown my TBird session that a clean imap session was established.

You could truss the process or do something else to find out what
Thunderbird and Dovecot are talking to each others. If shutting down
Thunderbird dropped the load, it sounds like a bug in Thunderbird. Some
clients have been known to keep requesting same data over and over again
from the server in some situations. If I could see what the IMAP traffic
looks like, I might be able to add a workaround to it.



signature.asc
Description: This is a digitally signed message part


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-11-15 Thread Jackie Hunt
 
 Is this behavior cured, or do you continue to see it?
 

No, the behavior isn't cured.  We still continue to see it 
with various clients.  I have posted a couple of truss outputs,
but so far no resolution.  

Sorry for the slow response.  I've been fighting other fires.

Jackie


 Jackie Hunt wrote:
  On Mon, 2007-09-03 at 12:37 +0200, Robert Tomanek wrote:
  
  Hi,
 
  Sunday, September 2, 2007, 22:42:37, you wrote:

  0x0806049d in imap_sync_more (ctx=3D0x80d9770) at imap-sync.c:104
  104 if (ctx-seq =3D=3D 0) {

   A short follow-up on this, looks like an infinite loop to me, unless
   some threading magic is supposed to happen here:

  Fixed: http://hg.dovecot.org/dovecot-1.0/rev/8e86137a04fb
  
 
  We also are seeing imap processes consuming 100% CPU.  We have
  installed Dovecot v1.0.5 and still see the problem.  I have a user 
  who can pretty reliably reproduce the problem.  It occurs each
  morning after the imap connection has been idling all night.  The
  user is running Thunderbird 2.0.0.6 (I think) on Solaris.  On the
  client side, he see an hourglass that never goes away, has to shut
  down Thunderbird.
 
  Below is a log, which shows how the CPU is being used (the ps commands
  are done one right after another) and a dbx trace of the state of
  the imap process.  I'm hoping that's enough info to figure out what's
  happening.
 
  Thanks much,
  Jackie
  ---
  Jackie Hunt   
  ACNSVoice:  (970) 663-3789 
  Colorado State University   FAX:(970) 491-1958
  Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]
 
 
  $ ps -ef | grep -i xx | grep imap
xx  43004  92942  74 07:15:33  - 38:54 imap 
  $ ps -ef | grep -i xx | grep imap
xx  43004  92942  81 07:15:33  - 38:58 imap 
  $ ps -ef | grep -i xx | grep imap
xx  43004  92942 120 07:15:33  - 39:01 imap 
  $ dbx -a 43004
  Waiting to attach to process 43004 ...
  Successfully attached to imap.
  warning: Directory containing imap could not be determined.
  Apply 'use' command to initialize source path.
 
  Type 'help' for help.
  reading symbolic information ...
  stopped in pread at 0xd01f06cc
  0xd01f06cc (pread+0x30) 80410014lwz   r2,0x14(r1)
  (dbx) step
  stopped in istream-file._read at line 120 in file 
  could not read istream-file.c
  (dbx) use src lib src/lib src/lib-storage/index/mbox src/lib-mail 
  src/lib-storage/index src/lib-storage src/imap src/imap-login
  (dbx) use
  src lib src/lib src/lib-storage/index/mbox src/lib-mail 
  src/lib-storage/index src/lib-storage src/imap src/imap-login 
  (dbx) where
  istream-file._read(stream = 0x200274a8), line 120 in istream-file.c
  i_stream_read(stream = 0x200274cc), line 58 in istream.c
  istream-raw-mbox._read(stream = 0x20028ab8), line 160 in 
  istream-raw-mbox.c
  i_stream_read(stream = 0x20028adc), line 58 in istream.c
  istream-limit._read(stream = 0x20031458), line 56 in istream-limit.c
  i_stream_read(stream = 0x2003147c), line 58 in istream.c
  istream-header-filter._read(stream = 0x2004aa98), line 234 in 
  istream-header-filter.c
  i_stream_read(stream = 0x2004aabc), line 58 in istream.c
  i_stream_read_data(stream = 0x2004aabc, data = 0x2ff22630, size = 
  0x2ff22638, threshold = 1), line 250 in istream.c
  message_get_body_size(input = 0x2004aabc, body = 0x2002827c, has_nuls = 
  (nil)), line 107 in message-size.c
  index_mail_init_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size 
  = 0x2ff227b8), line 502 in index-mail.c
  mbox_mail_get_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
  0x2ff227b8), line 206 in mbox-mail.c
  mail_get_stream(mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
  0x2ff227b8), line 107 in mail.c
  imap-fetch-body.fetch_body(ctx = 0x200205e0, mail = 0x200281a8, context = 
  0x20020858), line 331 in imap-fetch-body.c
  imap_fetch(ctx = 0x200205e0), line 291 in imap-fetch.c
  cmd_fetch(cmd = 0x2001e35c), line 163 in cmd-fetch.c
  cmd_uid(cmd = 0x2001e35c), line 19 in cmd-uid.c
  client_handle_input(cmd = 0x2001e35c), line 344 in client.c
  client_handle_input(cmd = 0x2001e35c), line 398 in client.c
  _client_input(context = 0x2001e318), line 441 in client.c
  io_loop_handler_run(ioloop = 0x2001d0e8), line 199 in ioloop-poll.c
  io_loop_run(ioloop = 0x2001d0e8), line 329 in ioloop.c
  main(argc = 1, argv = 0x2ff22b50, envp = 0x2ff22b58), line 290 in main.c
  (dbx) list
 58   return _stream-read(_stream);
 59   }
 60   
 61   void i_stream_skip(struct istream *stream, uoff_t count)
 62   {
 63   struct _istream *_stream = stream-real_stream;
 64   size_t data_size;
 65   
 66   data_size = _stream-pos - _stream-skip;
 67   if (count = data_size) {
  (dbx) dump
  i_stream_read(stream = 0x2003147c), line 58 in 

Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-10-10 Thread Jackie Hunt
Attached is the truss for the imap process we are seeing which is
chewing up CPU.  We've seen this issue on several different clients,
usually first thing in the morning.  Shutting down the client and
restarting always seems to get Dovecot back in sync.   Hope we can
get some help with this.   We're running 1.0.5.  Thanks!

Jackie Hunt
ACNSVoice:  (970) 663-3789
Colorado State University   FAX:(970) 491-1958
Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]

On Sun, 30 Sep 2007, Timo Sirainen wrote:

 On Wed, 2007-09-26 at 09:12 -0600, Jackie Hunt wrote:
  istream-file._read(stream = 0x200274a8), line 120 in istream-file.c
  i_stream_read(stream = 0x200274cc), line 58 in istream.c
  istream-raw-mbox._read(stream = 0x20028ab8), line 160 in 
  istream-raw-mbox.c
  i_stream_read(stream = 0x20028adc), line 58 in istream.c
  istream-limit._read(stream = 0x20031458), line 56 in istream-limit.c
  i_stream_read(stream = 0x2003147c), line 58 in istream.c
  istream-header-filter._read(stream = 0x2004aa98), line 234 in 
  istream-header-filter.c
  i_stream_read(stream = 0x2004aabc), line 58 in istream.c
  i_stream_read_data(stream = 0x2004aabc, data = 0x2ff22630, size = 
  0x2ff22638, threshold = 1), line 250 in istream.c
  message_get_body_size(input = 0x2004aabc, body = 0x2002827c, has_nuls = 
  (nil)), line 107 in message-size.c
  index_mail_init_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size 
  = 0x2ff227b8), line 502 in index-mail.c
  mbox_mail_get_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
  0x2ff227b8), line 206 in mbox-mail.c
  mail_get_stream(mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
  0x2ff227b8), line 107 in mail.c
  imap-fetch-body.fetch_body(ctx = 0x200205e0, mail = 0x200281a8, context = 
  0x20020858), line 331 in imap-fetch-body.c
  imap_fetch(ctx = 0x200205e0), line 291 in imap-fetch.c
  cmd_fetch(cmd = 0x2001e35c), line 163 in cmd-fetch.c
  cmd_uid(cmd = 0x2001e35c), line 19 in cmd-uid.c
  client_handle_input(cmd = 0x2001e35c), line 344 in client.c
  client_handle_input(cmd = 0x2001e35c), line 398 in client.c
  _client_input(context = 0x2001e318), line 441 in client.c
  io_loop_handler_run(ioloop = 0x2001d0e8), line 199 in ioloop-poll.c
  io_loop_run(ioloop = 0x2001d0e8), line 329 in ioloop.c

 This looks like a normal UID FETCH command. Are you sure Dovecot is
 doing infinite looping here, or if it's just that Thunderbird is sending
 the same UID FETCH command over and over?

 If it's Dovecot doing the infinite loop, could you truss the process for
 a while and show me the output?

 Or it would be good to know which one of these functions is looping. Can
 you set breakpoints and continue the execution? With gdb I'd do:

 b imap_fetch
 continue
 // does it stop? if not, ^C and try the next one:
 b fetch_body
 continue
 b mail_get_stream
 continue
 ..etc..

 The last breakpoint where it doesn't stop is looping.


truss.log.gz
Description: Binary data


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-30 Thread Timo Sirainen
On Wed, 2007-09-26 at 09:12 -0600, Jackie Hunt wrote:
 istream-file._read(stream = 0x200274a8), line 120 in istream-file.c
 i_stream_read(stream = 0x200274cc), line 58 in istream.c
 istream-raw-mbox._read(stream = 0x20028ab8), line 160 in istream-raw-mbox.c
 i_stream_read(stream = 0x20028adc), line 58 in istream.c
 istream-limit._read(stream = 0x20031458), line 56 in istream-limit.c
 i_stream_read(stream = 0x2003147c), line 58 in istream.c
 istream-header-filter._read(stream = 0x2004aa98), line 234 in 
 istream-header-filter.c
 i_stream_read(stream = 0x2004aabc), line 58 in istream.c
 i_stream_read_data(stream = 0x2004aabc, data = 0x2ff22630, size = 0x2ff22638, 
 threshold = 1), line 250 in istream.c
 message_get_body_size(input = 0x2004aabc, body = 0x2002827c, has_nuls = 
 (nil)), line 107 in message-size.c
 index_mail_init_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
 0x2ff227b8), line 502 in index-mail.c
 mbox_mail_get_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
 0x2ff227b8), line 206 in mbox-mail.c
 mail_get_stream(mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
 0x2ff227b8), line 107 in mail.c
 imap-fetch-body.fetch_body(ctx = 0x200205e0, mail = 0x200281a8, context = 
 0x20020858), line 331 in imap-fetch-body.c
 imap_fetch(ctx = 0x200205e0), line 291 in imap-fetch.c
 cmd_fetch(cmd = 0x2001e35c), line 163 in cmd-fetch.c
 cmd_uid(cmd = 0x2001e35c), line 19 in cmd-uid.c
 client_handle_input(cmd = 0x2001e35c), line 344 in client.c
 client_handle_input(cmd = 0x2001e35c), line 398 in client.c
 _client_input(context = 0x2001e318), line 441 in client.c
 io_loop_handler_run(ioloop = 0x2001d0e8), line 199 in ioloop-poll.c
 io_loop_run(ioloop = 0x2001d0e8), line 329 in ioloop.c

This looks like a normal UID FETCH command. Are you sure Dovecot is
doing infinite looping here, or if it's just that Thunderbird is sending
the same UID FETCH command over and over?

If it's Dovecot doing the infinite loop, could you truss the process for
a while and show me the output?

Or it would be good to know which one of these functions is looping. Can
you set breakpoints and continue the execution? With gdb I'd do:

b imap_fetch
continue
// does it stop? if not, ^C and try the next one:
b fetch_body
continue
b mail_get_stream
continue
..etc..

The last breakpoint where it doesn't stop is looping.


signature.asc
Description: This is a digitally signed message part


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-26 Thread Jackie Hunt
 On Mon, 2007-09-03 at 12:37 +0200, Robert Tomanek wrote:
  Hi,
 
  Sunday, September 2, 2007, 22:42:37, you wrote:
   0x0806049d in imap_sync_more (ctx=3D0x80d9770) at imap-sync.c:104
   104 if (ctx-seq =3D=3D 0) {
 
   A short follow-up on this, looks like an infinite loop to me, unless
   some threading magic is supposed to happen here:
 
 Fixed: http://hg.dovecot.org/dovecot-1.0/rev/8e86137a04fb

We also are seeing imap processes consuming 100% CPU.  We have
installed Dovecot v1.0.5 and still see the problem.  I have a user 
who can pretty reliably reproduce the problem.  It occurs each
morning after the imap connection has been idling all night.  The
user is running Thunderbird 2.0.0.6 (I think) on Solaris.  On the
client side, he see an hourglass that never goes away, has to shut
down Thunderbird.

Below is a log, which shows how the CPU is being used (the ps commands
are done one right after another) and a dbx trace of the state of
the imap process.  I'm hoping that's enough info to figure out what's
happening.

Thanks much,
Jackie
---
Jackie Hunt   
ACNSVoice:  (970) 663-3789 
Colorado State University   FAX:(970) 491-1958
Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]


$ ps -ef | grep -i xx | grep imap
  xx  43004  92942  74 07:15:33  - 38:54 imap 
$ ps -ef | grep -i xx | grep imap
  xx  43004  92942  81 07:15:33  - 38:58 imap 
$ ps -ef | grep -i xx | grep imap
  xx  43004  92942 120 07:15:33  - 39:01 imap 
$ dbx -a 43004
Waiting to attach to process 43004 ...
Successfully attached to imap.
warning: Directory containing imap could not be determined.
Apply 'use' command to initialize source path.

Type 'help' for help.
reading symbolic information ...
stopped in pread at 0xd01f06cc
0xd01f06cc (pread+0x30) 80410014lwz   r2,0x14(r1)
(dbx) step
stopped in istream-file._read at line 120 in file 
could not read istream-file.c
(dbx) use src lib src/lib src/lib-storage/index/mbox src/lib-mail 
src/lib-storage/index src/lib-storage src/imap src/imap-login
(dbx) use
src lib src/lib src/lib-storage/index/mbox src/lib-mail src/lib-storage/index 
src/lib-storage src/imap src/imap-login 
(dbx) where
istream-file._read(stream = 0x200274a8), line 120 in istream-file.c
i_stream_read(stream = 0x200274cc), line 58 in istream.c
istream-raw-mbox._read(stream = 0x20028ab8), line 160 in istream-raw-mbox.c
i_stream_read(stream = 0x20028adc), line 58 in istream.c
istream-limit._read(stream = 0x20031458), line 56 in istream-limit.c
i_stream_read(stream = 0x2003147c), line 58 in istream.c
istream-header-filter._read(stream = 0x2004aa98), line 234 in 
istream-header-filter.c
i_stream_read(stream = 0x2004aabc), line 58 in istream.c
i_stream_read_data(stream = 0x2004aabc, data = 0x2ff22630, size = 0x2ff22638, 
threshold = 1), line 250 in istream.c
message_get_body_size(input = 0x2004aabc, body = 0x2002827c, has_nuls = (nil)), 
line 107 in message-size.c
index_mail_init_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
0x2ff227b8), line 502 in index-mail.c
mbox_mail_get_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
0x2ff227b8), line 206 in mbox-mail.c
mail_get_stream(mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 
0x2ff227b8), line 107 in mail.c
imap-fetch-body.fetch_body(ctx = 0x200205e0, mail = 0x200281a8, context = 
0x20020858), line 331 in imap-fetch-body.c
imap_fetch(ctx = 0x200205e0), line 291 in imap-fetch.c
cmd_fetch(cmd = 0x2001e35c), line 163 in cmd-fetch.c
cmd_uid(cmd = 0x2001e35c), line 19 in cmd-uid.c
client_handle_input(cmd = 0x2001e35c), line 344 in client.c
client_handle_input(cmd = 0x2001e35c), line 398 in client.c
_client_input(context = 0x2001e318), line 441 in client.c
io_loop_handler_run(ioloop = 0x2001d0e8), line 199 in ioloop-poll.c
io_loop_run(ioloop = 0x2001d0e8), line 329 in ioloop.c
main(argc = 1, argv = 0x2ff22b50, envp = 0x2ff22b58), line 290 in main.c
(dbx) list
   58   return _stream-read(_stream);
   59   }
   60   
   61   void i_stream_skip(struct istream *stream, uoff_t count)
   62   {
   63   struct _istream *_stream = stream-real_stream;
   64   size_t data_size;
   65   
   66   data_size = _stream-pos - _stream-skip;
   67   if (count = data_size) {
(dbx) dump
i_stream_read(stream = 0x2003147c), line 58 in istream.c
_stream = 0x20031458
(dbx) up
istream-header-filter._read(stream = 0x2004aa98), line 234 in 
istream-header-filter.c
(dbx) list
  234   if ((ret = i_stream_read(mstream-input)) == -2) {
  235   if (stream-skip == 0)
  236   return -2;
  237   }
  238   stream-istream.stream_errno = 
mstream-input-stream_errno;
  239   stream-istream.eof = mstream-input-eof;
  240   stream-buffer 

Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-09 Thread Robert Tomanek
Hi,

Saturday, September 8, 2007, 2:29:45, you wrote:
  0x0806049d in imap_sync_more (ctx=0x80d9770) at imap-sync.c:104
  104 if (ctx-seq == 0) {
 
  A short follow-up on this, looks like an infinite loop to me, unless
  some threading magic is supposed to happen here:

 Fixed: http://hg.dovecot.org/dovecot-1.0/rev/8e86137a04fb

 Compiled the new version, so far so good...

 Thanks!

-- 
Best regards,
 Robert Tomanekmailto:[EMAIL PROTECTED]



Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-07 Thread Jackie Hunt
 
 Hello Jackie,
 
   Unfortunately, I am not really moving forward with that as I do not
   have much insight into the context structure in question. I guess we
   need to wait until Timo answers my e-mail.

Yes, haven't seen much from him lately.  Must be busy or vacation...

   On the other hand, nice the hear I am not the only person with this
   problem :-|

I think I've also seen these posted in the past from users.  We hadn't
experienced it until recently, just went into production this summer.

   Jackie, is there a chance you could confirm my doubts by doing what
   I did in mid:[EMAIL PROTECTED] and the
   original message? This way we would be sure we are talking about the
   same problem cause here since 'Dovecot hangs' sounds a bit generic.
   I think the stack trace and the variable values should be enough to
   confirm it.

Sorry, don't know about the mid: protocol.  Not sure how to get to the
reference you sent.  From your email it looks like gdb has the ability
to attach to a running process.  We have dbx which I don't believe 
can do that.  It would be nice to confirm our issues are the same though.
What I'd really like is to find a way to recreate the problem.

Jackie
---
Jackie Hunt   
ACNSVoice:  (970) 663-3789 
Colorado State University   FAX:(970) 491-1958
Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-07 Thread bhayden

On Sep 7 2007, Jackie Hunt wrote:


Sorry, don't know about the mid: protocol.  Not sure how to get to the
reference you sent.  From your email it looks like gdb has the ability
to attach to a running process.  We have dbx which I don't believe 
can do that.  It would be nice to confirm our issues are the same though.

What I'd really like is to find a way to recreate the problem.


Start dbx, and type 'attach pid' at its prompt.

-Brian Hayden
OIT Internet Services,
University of Minnesota


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-07 Thread Timo Sirainen
On Mon, 2007-09-03 at 12:37 +0200, Robert Tomanek wrote:
 Hi,
 
 Sunday, September 2, 2007, 22:42:37, you wrote:
  0x0806049d in imap_sync_more (ctx=0x80d9770) at imap-sync.c:104
  104 if (ctx-seq == 0) {
 
  A short follow-up on this, looks like an infinite loop to me, unless
  some threading magic is supposed to happen here:

Fixed: http://hg.dovecot.org/dovecot-1.0/rev/8e86137a04fb



signature.asc
Description: This is a digitally signed message part


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-06 Thread Jackie Hunt
 
 Hi,
 
  I have yet another problem with Dovecot: sometimes (rarely, maybe
  once every few days) one of the imap processes will 'hang',
  consuming all available CPU time. It does not seem to 'finish' in any
  reasonable amount of time (in one instance I waited a few days). 

 
  Robert Tomanek mailto:[EMAIL PROTECTED]

We have also seen this behavior, running Dovecot 1.0 on AIX.  
Thanks for your debug work on it Robert.

Jackie
---
Jackie Hunt   
ACNSVoice:  (970) 663-3789 
Colorado State University   FAX:(970) 491-1958
Fort Collins, CO  80523 Email:  [EMAIL PROTECTED]


Re: [Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-03 Thread Robert Tomanek
Hi,

Sunday, September 2, 2007, 22:42:37, you wrote:
 0x0806049d in imap_sync_more (ctx=0x80d9770) at imap-sync.c:104
 104 if (ctx-seq == 0) {

 A short follow-up on this, looks like an infinite loop to me, unless
 some threading magic is supposed to happen here:
 (gdb) step
 120 if (ctx-sync_rec.seq1  ctx-messages_count)
 (gdb)
 104 if (ctx-seq == 0) {
 (gdb)
 117 if (ctx-sync_rec.seq2  ctx-messages_count) {
 (gdb)
 120 if (ctx-sync_rec.seq1  ctx-messages_count)
 (gdb)
 104 if (ctx-seq == 0) {
 (gdb)
 117 if (ctx-sync_rec.seq2  ctx-messages_count) {
 (gdb)
 120 if (ctx-sync_rec.seq1  ctx-messages_count)
 (gdb) print ctx-seq
 $1 = 8317
 (gdb) print ctx-sync_rec.seq1
 $2 = 8318
 (gdb) print ctx-sync_rec.seq2
 $3 = 8320
 (gdb) print ctx-messages_count
 $4 = 8317

 The corresponding code in imap-sync.c is:
103:for (;;) {
104:if (ctx-seq == 0) {
105:/* get next one */
106:ret = mailbox_sync_next(ctx-sync_ctx,
107:ctx-sync_rec);
108:if (ret = 0) {
109:if (ret == 0) {
110:/* all finished ok */
111:ret = 1;
112:}
113:break;
114:}
115:}
116:
117:   if (ctx-sync_rec.seq2  ctx-messages_count) {
118:/* don't send change notifications of messages we
119:   haven't even announced to client yet */
120:if (ctx-sync_rec.seq1  ctx-messages_count)
121:continue;
122:ctx-sync_rec.seq2 = ctx-messages_count;
123:}
 ...
185:}

-- 
Best regards,
 Robert Tomanek   mailto:[EMAIL PROTECTED]



[Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)

2007-09-02 Thread Robert Tomanek
Hi,

 I have yet another problem with Dovecot: sometimes (rarely, maybe
 once every few days) one of the imap processes will 'hang',
 consuming all available CPU time. It does not seem to 'finish' in any
 reasonable amount of time (in one instance I waited a few days). This
 process will not even exit gracefully, it needs to be killed with
 'kill -9 PID'.

 It has just happened again. The output from gdb is:
 # gdb attach 29401
 GNU gdb 6.3
 Copyright 2004 Free Software Foundation, Inc.
 GDB is free software, covered by the GNU General Public License, and you are
 welcome to change it and/or distribute copies of it under certain conditions.
 Type show copying to see the conditions.
 There is absolutely no warranty for GDB.  Type show warranty for details.
 This GDB was configured as i586-suse-linux...attach: No such file or 
 directory.
 
 Attaching to process 29401
 Reading symbols from /usr/local/libexec/dovecot/imap...done.
 Using host libthread_db library /lib/tls/libthread_db.so.1.
 Reading symbols from /lib/libdl.so.2...done.
 Loaded symbols for /lib/libdl.so.2
 Reading symbols from /lib/tls/libc.so.6...done.
 Loaded symbols for /lib/tls/libc.so.6
 Reading symbols from /lib/ld-linux.so.2...done.
 Loaded symbols for /lib/ld-linux.so.2
 0x0806049d in imap_sync_more (ctx=0x80d9770) at imap-sync.c:104
 104 if (ctx-seq == 0) {
 (gdb) bt full
 #0  0x0806049d in imap_sync_more (ctx=0x80d9770) at imap-sync.c:104
 flags = 1075042320
 keywords = value optimized out
 str = (string_t *) 0x80c31e0
 ret = 1
 #1  0x08060797 in cmd_sync_continue (cmd=0x80ccdbc) at imap-sync.c:207
 ctx = (struct cmd_sync_context *) 0x80cf000
 ret = value optimized out
 #2  0x0805ad5a in _client_output (context=0x80ccd78) at client.c:465
 cmd = (struct client_command_context *) 0x80ccdbc
 ret = 0
 #3  0x080af0bd in stream_send_io (context=0x80cceb0) at ostream-file.c:356
 ostream = (struct ostream *) 0x80ccee0
 ret = value optimized out
 #4  0x080aa441 in io_loop_handler_run (ioloop=0x80cb9b0) at ioloop-epoll.c:203
 ctx = (struct ioloop_handler_context *) 0x80cb9d8
 list = (struct io_list *) 0x80d7780
 io = (struct io *) 0x80dc430
 tv = {tv_sec = 2, tv_usec = 540048}
 events_count = 4
 t_id = 2
 msecs = value optimized out
 ret = 1
 i = 0
 j = 1
 call = value optimized out
 #5  0x080a9889 in io_loop_run (ioloop=0x80cb9b0) at ioloop.c:329
 No locals.
 #6  0x08062087 in main (argc=1, argv=0xbaf4, envp=0xbafc) at 
 main.c:290
 plugin_dir = value optimized out

 Mail log does not reveal anything immediately interesting.

 Thoughts?

 Server config ('dovecot -n -c /etc/dovecot/dovecot.conf'):
 # 1.0.3: /etc/dovecot/dovecot.conf
 base_dir: /var/run/dovecot/
 protocols: imap imaps pop3 pop3s
 ssl_ca_file: /etc/ssl/current/cacert.pem
 ssl_cert_file: /etc/ssl/current/server.pem
 ssl_key_file: /etc/ssl/current/private.pem
 disable_plaintext_auth: no
 login_dir: /var/run/dovecot//login
 login_executable(default): /usr/local/libexec/dovecot/imap-login
 login_executable(imap): /usr/local/libexec/dovecot/imap-login
 login_executable(pop3): /usr/local/libexec/dovecot/pop3-login
 first_valid_uid: 50
 mail_debug: yes
 mail_drop_priv_before_exec: yes
 mail_executable(default): /usr/local/libexec/dovecot/imap
 mail_executable(imap): /usr/local/libexec/dovecot/imap
 mail_executable(pop3): /usr/local/libexec/dovecot/pop3
 mail_plugin_dir(default): /usr/local/lib/dovecot/imap
 mail_plugin_dir(imap): /usr/local/lib/dovecot/imap
 mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3
 mail_log_prefix: %Us(%u)(%p):
 pop3_uidl_format(default):
 pop3_uidl_format(imap):
 pop3_uidl_format(pop3): %08Xu%08Xv
 auth default:
   debug_passwords: yes
   passdb:
 driver: passwd-file
 args: /etc/dovecot/passwd
   userdb:
 driver: passwd-file
 args: /etc/dovecot/passwd
   socket:
 type: listen
 client:
   path: /var/spool/postfix/private/auth
   mode: 432
   user: postfix
   group: postfix

-- 
Best regards,
 Robert Tomanek mailto:[EMAIL PROTECTED]