Peter Eriksson
2015-Dec-15 15:52 UTC
Assert failure in 2.2.20: imap-fetch.c:554 (ctx->client->output_cmd_lock || ctx->client->output_cmd_lock == cmd)
Just got another core-dump from Dovecot's imap process on our mail server.
Dovecot 2.2.20
Solaris 10 / x86
Maildir
Output from syslog:
Dec 14 10:58:12 mail dovecot: [ID 583609 mail.crit] imap(oling): Panic: file
imap-fetch.c: line 554: assertion failed: (ctx->client->output_cmd_lock ==
NULL || ctx->client->output_cmd_lock == cmd)
Dec 14 10:58:15 mail dovecot: [ID 583609 mail.crit] imap(oling): Fatal: master:
service(imap): child 2167 killed with signal 6 (core dumped)
Checked the users' Maildir for files modified around this time and found:
-rw------- 1 oling root 15743 Dec 14 10:54 .Deleted
Messages/cur/1450099463.M318113P13582.mail,S=15743,W=16026:2,RSbcd
Don't know if it's related though.
Data from the core-dump / debugger:
# /pkg/studio/default/bin/dbx /ifm/pkg/dovecot/default/libexec/dovecot/imap
imap.2167.306
...
program terminated by signal ABRT (Abort)
0xfffffd7ffeb81eca: __lwp_kill+0x000a: jae __lwp_kill+0x18 [
0xfffffd7ffeb81ed8, .+0xe ]
Current function is default_fatal_finish
201 abort();
(dbx) where
[1] __lwp_kill(0x1, 0x6, 0xfffffe88d2948e40, 0xfffffd7ffeb827be, 0x4552555443,
0x0), at 0xfffffd7ffeb81eca
[2] _thr_kill(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7ffeb7a7d3
[3] raise(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7ffeb26fe9
[4] abort(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7ffeb05f60
=>[5] default_fatal_finish(type = LOG_TYPE_PANIC, status = 0), line 201 in
"failures.c"
[6] i_internal_fatal_handler(ctx = 0xfffffd7fffdff858, format = 0x492df0
"file %s: line %d: assertion failed: (%s)", args =
0xfffffd7fffdff840), line 670 in "failures.c"
[7] i_panic(format = 0x492df0 "file %s: line %d: assertion failed:
(%s)", ... = 0x467f4f, ...), line 275 in "failures.c"
[8] imap_fetch_more(ctx = 0x736b00, cmd = 0x7369a8), line 554 in
"imap-fetch.c"
[9] cmd_fetch(cmd = 0x7369a8), line 297 in "cmd-fetch.c"
[10] command_exec(cmd = 0x7369a8), line 172 in "imap-commands.c"
[11] client_command_input(cmd = 0x7369a8), line 948 in
"imap-client.c"
[12] client_command_input(cmd = 0x7369a8), line 1008 in
"imap-client.c"
[13] client_handle_next_command(client = 0x4d16c0, remove_io_r =
0xfffffd7fffdffa7d), line 1022 in "imap-client.c"
[14] client_handle_input(client = 0x4d16c0), line 1058 in
"imap-client.c"
[15] client_input(client = 0x4d16c0), line 1105 in "imap-client.c"
[16] io_loop_call_io(io = 0x5bab00), line 559 in "ioloop.c"
[17] io_loop_handler_run_internal(ioloop = 0x4b2580), line 211 in
"ioloop-poll.c"
[18] io_loop_handler_run(ioloop = 0x4b2580), line 607 in "ioloop.c"
[19] io_loop_run(ioloop = 0x4b2580), line 583 in "ioloop.c"
[20] master_service_run(service = 0x4b2450, callback = 0x482690 =
&`imap`main.c`client_connected(struct master_service_connection *conn)),
line 640 in "master-service.c"
[21] main(argc = 1, argv = 0xfffffd7fffdffcb8), line 442 in "main.c"
(dbx) print cmd
cmd = 0x7369a8
(dbx) print ctx->client->output_cmd_lock
ctx->client->output_cmd_lock = 0x72e0f8
(dbx) print *cmd
*cmd = {
prev = (nil)
next = 0x72e0f8
client = 0x4d16c0
pool = 0x4d1eb0
tag = 0x736ac0 "150.11"
name = 0x736ac8 "UID FETCH"
args = 0x736ad8 "12663:12665 (BODY.PEEK[]
BODYSTRUCTURE)"
cmd_flags = COMMAND_FLAG_BREAKS_SEQS
func = 0x437220 = &cmd_fetch(struct
client_command_context *cmd)
context = (nil)
module_contexts = {
arr = {
buffer = 0x736a58
element_size = 8U
}
v = 0x736a58
v_modifiable = 0x736a58
}
parser = 0x4d3d40
state = CLIENT_COMMAND_STATE_WAIT_INPUT
start_time = {
tv_sec = 1450087092
tv_usec = 924042
}
start_ioloop_wait_usecs = 119688401U
running_usecs = 0
bytes_in = 0
bytes_out = 0
sync = (nil)
uid = 1U
cancel = 0
param_error = 0
search_save_result = 0
search_save_result_used = 0
temp_executed = 0
tagline_sent = 0
}
(dbx) print *(ctx->client->output_cmd_lock)
*ctx->client->output_cmd_lock = {
prev = 0x7369a8
next = 0x72d8c8
client = 0x4d16c0
pool = 0x4d1eb0
tag = 0x72e208 "149.11"
name = 0x72e210 "UID FETCH"
args = 0x72e220 "12666 (BODY.PEEK[]
BODYSTRUCTURE)"
cmd_flags = COMMAND_FLAG_BREAKS_SEQS
func = 0x4371b0 =
&`imap`cmd-fetch.c`cmd_fetch_continue(struct client_command_context *cmd)
context = 0x72e248
module_contexts = {
arr = {
buffer = 0x72e1a8
element_size = 8U
}
v = 0x72e1a8
v_modifiable = 0x72e1a8
}
parser = 0x5bb410
state = CLIENT_COMMAND_STATE_WAIT_OUTPUT
start_time = {
tv_sec = 1450087092
tv_usec = 923420
}
start_ioloop_wait_usecs = 119688382U
running_usecs = 538U
bytes_in = 33U
bytes_out = 32994U
sync = (nil)
uid = 1U
cancel = 0
param_error = 0
search_save_result = 0
search_save_result_used = 0
temp_executed = 1U
tagline_sent = 0
}
--
[Ll.U] Peter Eriksson KITVS-IFM & ITI-NET IT.LiU.SE +46-70 518 2786
Timo Sirainen
2015-Dec-16 13:39 UTC
Assert failure in 2.2.20: imap-fetch.c:554 (ctx->client->output_cmd_lock || ctx->client->output_cmd_lock == cmd)
On 15 Dec 2015, at 17:52, Peter Eriksson <peter at ifm.liu.se> wrote:> > Just got another core-dump from Dovecot's imap process on our mail server. > > Dec 14 10:58:12 mail dovecot: [ID 583609 mail.crit] imap(oling): Panic: file imap-fetch.c: line 554: assertion failed: (ctx->client->output_cmd_lock == NULL || ctx->client->output_cmd_lock == cmd)I think this is an old bug, and I've never been able to reproduce it. But looking at the code, this should fix it: https://github.com/dovecot/core/commit/15307c2c91854e766bd9fb095d611a29b3f7572e
Peter Eriksson
2015-Dec-16 13:53 UTC
Assert failure in 2.2.20: imap-fetch.c:554 (ctx->client->output_cmd_lock || ctx->client->output_cmd_lock == cmd)
I?ve rebuilt Dovecot 2.2.21 with that patch (and the other one) now and will be having a look at the core-dump directory the coming days :-) - Peter ? [L?.U] SysAdmin KITVS-IFM & ITI-NET IT.LiU.SE +46-13-28 2786> On 16 Dec 2015, at 14:39, Timo Sirainen <tss at iki.fi> wrote: > > On 15 Dec 2015, at 17:52, Peter Eriksson <peter at ifm.liu.se> wrote: >> >> Just got another core-dump from Dovecot's imap process on our mail server. >> >> Dec 14 10:58:12 mail dovecot: [ID 583609 mail.crit] imap(oling): Panic: file imap-fetch.c: line 554: assertion failed: (ctx->client->output_cmd_lock == NULL || ctx->client->output_cmd_lock == cmd) > > I think this is an old bug, and I've never been able to reproduce it. But looking at the code, this should fix it: > > https://github.com/dovecot/core/commit/15307c2c91854e766bd9fb095d611a29b3f7572e > >