[Dovecot] imap process consuming 100% CPU (Dovecot 1.0.3)
Jackie Hunt
jackie at yuma.acns.colostate.edu
Thu Nov 15 19:55:32 EET 2007
>
> 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
> > ACNS Voice: (970) 663-3789
> > Colorado State University FAX: (970) 491-1958
> > Fort Collins, CO 80523 Email: jackie.hunt at colostate.edu
> >
> >
> > $ ps -ef | grep -i xxxxxx | grep imap
> > xxxxxx 43004 92942 74 07:15:33 - 38:54 imap
> > $ ps -ef | grep -i xxxxxx | grep imap
> > xxxxxx 43004 92942 81 07:15:33 - 38:58 imap
> > $ ps -ef | grep -i xxxxxx | grep imap
> > xxxxxx 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) 80410014 lwz 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 = i_stream_get_data(mstream->input, &pos);
> > 241 } else {
> > 242 ret = 0;
> > 243 }
> > (dbx) dump
> > istream-header-filter._read(stream = 0x2004aa98), line 234 in "istream-header-filter.c"
> > mstream = 0x2004aa98
> > ret = 4094
> > pos = 1
> > (dbx) up
> > i_stream_read(stream = 0x2004aabc), line 58 in "istream.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 = 0x2004aabc), line 58 in "istream.c"
> > _stream = 0x2004aa98
> > (dbx) up
> > i_stream_read_data(stream = 0x2004aabc, data = 0x2ff22630, size = 0x2ff22638, threshold = 1), line 250 in "istream.c"
> > (dbx) list
> > 250 ret = i_stream_read(stream);
> > 251 if (ret > 0)
> > 252 read_more = TRUE;
> > 253 } while (ret > 0);
> > 254
> > 255 *data = i_stream_get_data(stream, size);
> > 256 return ret == -2 ? -2 :
> > 257 (read_more || ret == 0 ? 0 : -1);
> > 258 }
> > 259
> > (dbx) dump
> > i_stream_read_data(stream = 0x2004aabc, data = 0x2ff22630, size = 0x2ff22638, threshold = 1), line 250 in "istream.c"
> > read_more = 0
> > ret = 0
> > (dbx) up
> > message_get_body_size(input = 0x2004aabc, body = 0x2002827c, has_nuls = (nil)), line 107 in "message-size.c"
> > (dbx) list
> > 107 } while (i_stream_read_data(input, &msg, &size, 1) > 0);
> > 108
> > 109 i_stream_skip(input, 1);
> > 110 body->physical_size++;
> > 111
> > 112 body->virtual_size = body->physical_size + missing_cr_count;
> > 113 i_assert(body->virtual_size >= body->physical_size);
> > 114 }
> > 115
> > 116 void message_size_add(struct message_size *dest,
> > (dbx) dump
> > message_get_body_size(input = 0x2004aabc, body = 0x2002827c, has_nuls = (nil)), line 107 in "message-size.c"
> > last_cr = 0
> > missing_cr_count = 83389
> > msg = "dd"
> > i = 4095
> > size = 1
> > (dbx) up
> > index_mail_init_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), line 502 in "index-mail.c"
> > (dbx) list
> > 502 message_get_body_size(data->stream,
> > 503 &data->body_size, NULL);
> > 504 data->body_size_set = TRUE;
> > 505 }
> > 506 }
> > 507
> > 508 *body_size = data->body_size;
> > 509 }
> > 510
> > 511 if (data->hdr_size_set && data->body_size_set) {
> > (dbx) dump
> > index_mail_init_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), line 502 in "index-mail.c"
> > data = 0x2002820c
> > mail = 0x200281a8
> > (dbx) up
> > mbox_mail_get_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), line 206 in "mbox-mail.c"
> > (dbx) list
> > 206 return index_mail_init_stream(mail, hdr_size, body_size);
> > 207 }
> > 208
> > 209 struct mail_vfuncs mbox_mail_vfuncs = {
> > 210 index_mail_free,
> > 211 index_mail_set_seq,
> > 212
> > 213 index_mail_get_flags,
> > 214 index_mail_get_keywords,
> > 215 index_mail_get_parts,
> > (dbx) dump
> > mbox_mail_get_stream(_mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), line 206 in "mbox-mail.c"
> > raw_stream = 0x2ff22780
> > mbox = 0x20024a98
> > data = 0x2002820c
> > mail = 0x200281a8
> > offset = 804398928
> > (dbx) up
> > mail_get_stream(mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), line 107 in "mail.c"
> > (dbx) list
> > 107 return p->v.get_stream(mail, hdr_size, body_size);
> > 108 }
> > 109
> > 110 const char *mail_get_special(struct mail *mail, enum mail_fetch_field field)
> > 111 {
> > 112 struct mail_private *p = (struct mail_private *)mail;
> > 113
> > 114 return p->v.get_special(mail, field);
> > 115 }
> > 116
> > (dbx) dump
> > mail_get_stream(mail = 0x200281a8, hdr_size = 0x2ff227a8, body_size = 0x2ff227b8), line 107 in "mail.c"
> > p = 0x200281a8
> > (dbx) up
> > imap-fetch-body.fetch_body(ctx = 0x200205e0, mail = 0x200281a8, context = 0x20020858), line 331 in "imap-fetch-body.c"
> > (dbx) list
> > 331 body->section[0] == 'H' ? NULL : &body_size);
> > 332 if (ctx->cur_input == NULL)
> > 333 return -1;
> > 334
> > 335 i_stream_ref(ctx->cur_input);
> > 336 ctx->update_partial = TRUE;
> > 337
> > 338 switch (body->section[0]) {
> > 339 case '\0':
> > 340 /* BODY[] - fetch everything */
> > (dbx) dump
> > imap-fetch-body.fetch_body(ctx = 0x200205e0, mail = 0x200281a8, context = 0x20020858), line 331 in "imap-fetch-body.c"
> > fetch_size = 0x20011dd8
> > hdr_size = (physical_size = 843, virtual_size = 843, lines = 15)
> > body = 0x20020858
> > body_size = (physical_size = 804398512, virtual_size = 12, lines = 0)
> > (dbx) up
> > imap_fetch(ctx = 0x200205e0), line 291 in "imap-fetch.c"
> > (dbx) list
> > 291 ret = handlers[ctx->cur_handler].
> > 292 handler(ctx, ctx->cur_mail,
> > 293 handlers[ctx->cur_handler].context);
> > 294 t_pop();
> > 295
> > 296 if (ret == 0)
> > 297 return 0;
> > 298
> > 299 if (ret < 0) {
> > 300 if (ctx->cur_mail->expunged) {
> > (dbx) dump
> > imap_fetch(ctx = 0x200205e0), line 291 in "imap-fetch.c"
> > handlers = 0x200206f8
> > count = 3
> > ret = 1
> > (dbx) up
> > cmd_fetch(cmd = 0x2001e35c), line 163 in "cmd-fetch.c"
> > (dbx) list
> > 163 if ((ret = imap_fetch(ctx)) == 0) {
> > 164 /* unfinished */
> > 165 client->command_pending = TRUE;
> > 166 cmd->func = cmd_fetch_continue;
> > 167 cmd->context = ctx;
> > 168 return FALSE;
> > 169 }
> > 170 if (ret < 0)
> > 171 ctx->failed = TRUE;
> > 172
> > (dbx) dump
> > cmd_fetch(cmd = 0x2001e35c), line 163 in "cmd-fetch.c"
> > messageset = "11988"
> > search_arg = 0x200205a8
> > ctx = 0x200205e0
> > args = 0x2001e590
> > ret = 536954712
> > client = 0x2001e318
> > (dbx) up
> > cmd_uid(cmd = 0x2001e35c), line 19 in "cmd-uid.c"
> > (dbx) list
> > 19 return cmd->func(cmd);
> > 20 } else {
> > 21 client_send_tagline(cmd, t_strconcat(
> > 22 "BAD Unknown UID command ", cmd_name, NULL));
> > 23 return TRUE;
> > 24 }
> > 25 }
> > (dbx) dump
> > cmd_uid(cmd = 0x2001e35c), line 19 in "cmd-uid.c"
> > cmd_name = "fetch"
> > (dbx) up
> > client_handle_input(cmd = 0x2001e35c), line 344 in "client.c"
> > (dbx) list
> > 344 if (cmd->func(cmd) || cmd->param_error) {
> > 345 /* command execution was finished */
> > 346 if (!cmd->param_error)
> > 347 client->bad_counter = 0;
> > 348 _client_reset_command(client);
> > 349 return TRUE;
> > 350 }
> > 351
> > 352 /* unfinished */
> > 353 if (client->command_pending)
> > (dbx) dump
> > client_handle_input(cmd = 0x2001e35c), line 344 in "client.c"
> > client = 0x2001e318
> > (dbx) up
> > client_handle_input(cmd = 0x2001e35c), line 398 in "client.c"
> > (dbx) list
> > 398 client_handle_input(cmd);
> > 399 }
> > 400
> > 401 return TRUE;
> > 402 }
> > 403
> > 404 void _client_input(void *context)
> > 405 {
> > 406 struct client *client = context;
> > 407 struct client_command_context *cmd = &client->cmd;
> > (dbx) dump
> > client_handle_input(cmd = 0x2001e35c), line 398 in "client.c"
> > client = 0x2001e318
> > (dbx) up
> > _client_input(context = 0x2001e318), line 441 in "client.c"
> > (dbx) list
> > 441 ret = client_handle_input(cmd);
> > 442 t_pop();
> > 443 } while (ret && !client->disconnected);
> > 444 o_stream_uncork(client->output);
> > 445 client->handling_input = FALSE;
> > 446
> > 447 if (client->command_pending)
> > 448 client->input_pending = TRUE;
> > 449
> > 450 if (client->output->closed)
> > (dbx) dump
> > _client_input(context = 0x2001e318), line 441 in "client.c"
> > ret = 2
> > cmd = 0x2001e35c
> > client = 0x2001e318
> > (dbx) up
> > io_loop_handler_run(ioloop = 0x2001d0e8), line 199 in "ioloop-poll.c"
> > (dbx) list
> > 199 io->callback(io->context);
> > 200 if (t_pop() != t_id) {
> > 201 i_panic("Leaked a t_pop() call in "
> > 202 "I/O handler %p",
> > 203 (void *)io->callback);
> > 204 }
> > 205 }
> > 206 }
> > 207 }
> > 208 }
> > (dbx) dump
> > io_loop_handler_run(ioloop = 0x2001d0e8), line 199 in "ioloop-poll.c"
> > t_id = 2
> > tv = (tv_sec = 1, tv_usec = 54083)
> > msecs = 1055
> > pollfd = 0x2001d148
> > ctx = 0x2001d118
> > ret = 0
> > io = 0x2001e4e8
> > call = 1
> > (dbx) up
> > io_loop_run(ioloop = 0x2001d0e8), line 329 in "ioloop.c"
> > (dbx) list
> > 329 io_loop_handler_run(ioloop);
> > 330 }
> > 331
> > 332 void io_loop_stop(struct ioloop *ioloop)
> > 333 {
> > 334 ioloop->running = FALSE;
> > 335 }
> > 336
> > 337 void io_loop_set_running(struct ioloop *ioloop)
> > 338 {
> > (dbx) dump
> > io_loop_run(ioloop = 0x2001d0e8), line 329 in "ioloop.c"
> > (dbx) up
> > main(argc = 1, argv = 0x2ff22b50, envp = 0x2ff22b58), line 290 in "main.c"
> > (dbx) list
> > 290 io_loop_run(ioloop);
> > 291 main_deinit();
> > 292
> > 293 io_loop_destroy(&ioloop);
> > 294 lib_deinit();
> > 295
> > 296 return 0;
> > 297 }
> > (dbx) dump
> > main(argc = 1, argv = 0x2ff22b50, envp = 0x2ff22b58), line 290 in "main.c"
> > (dbx) up
> > __start() at 0x100001d8
> > (dbx) list
> > no source file
> > (dbx) dump
> > __start() at 0x100001d8
> > (dbx) cont
> >
> > execution completed
> > (dbx) quit
> > $
> >
>
> --
> ====
> Stewart Dean, Unix System Admin, Henderson Computer Resources
> Center of Bard College, Annandale-on-Hudson, New York 12504
> sdean at bard.edu voice: 845-758-7475, fax: 845-758-7035
>
Jackie Hunt
ACNS Voice: (970) 663-3789
Colorado State University FAX: (970) 491-1958
Fort Collins, CO 80523 Email: jackie.hunt at colostate.edu
More information about the dovecot
mailing list