The following issue has been REOPENED.
======================================================================
http://www.dbmail.org/mantis/view.php?id=579
======================================================================
Reported By: LordVan
Assigned To: paul
======================================================================
Project: DBMail
Issue ID: 579
Category: IMAP daemon
Reproducibility: always
Severity: major
Priority: high
Status: feedback
target:
======================================================================
Date Submitted: 01-May-07 18:24 CEST
Last Modified: 22-Sep-07 13:28 CEST
======================================================================
Summary: squirrelmail reports imap connection dropped when
search returns 0 or too many (not sure how many that is) results
Description:
Error when 0 results available:
ERROR: Connection dropped by IMAP server.
Query: SEARCH CHARSET ISO-8859-1 ALL SUBJECT {9} linux-dvb
when searching with lots of results:
ERROR: Connection dropped by IMAP server.
Query: SEARCH CHARSET ISO-8859-1 ALL SUBJECT {12} mplayer-user
works fine when returning up to at least 620 results ..
query run on inbox with 12000 emails ..
======================================================================
Relationships ID Summary
----------------------------------------------------------------------
has duplicate 0000607 error when I want to list all my messages
has duplicate 0000614 dbmail-imapd exited on signal 11
has duplicate 0000622 imapd crashes on fetching headers
======================================================================
----------------------------------------------------------------------
LordVan - 03-May-07 10:27
----------------------------------------------------------------------
one thing i just tried.
I added a filter to squirrelmail which i knew would move around 600 emails
from my inbox. it took a while, but it did work without any problems. and
it did deliver emails ok to my inbox (see ticket 561 - will add this there
too just in case)
----------------------------------------------------------------------
aaron - 09-May-07 23:15
----------------------------------------------------------------------
Please test latest SVN (rev 2546 or newer) and see if it makes Squirrelmail
happy.
----------------------------------------------------------------------
LordVan - 11-May-07 14:34
----------------------------------------------------------------------
tested with version from just now i think 2551 or so ..
get this when searching for something i know is not in my inbox using
squirrelmail:
ERROR: Bad or malformed request.
Query: FETCH (FLAGS UID RFC822.SIZE INTERNALDATE BODY.PEEK[HEADER.FIELDS
(Date To Cc From Subject X-Priority Importance Priority Content-Type)])
Server responded: invalid message range specified
when searching for a string which returns too many results:
ERROR: Connection dropped by IMAP server.
Query: SEARCH CHARSET ISO-8859-1 ALL SUBJECT {12} mplayer-user
since i don't have the time to put loggin on debug or anything i just got
some of those lines in my logs:
dbmail.err:
row number 0 is out of range 0..-1
May 11 13:27:51 Error:[server] pool.c,set_lock(+65): Error setting lock.
Trying again.
May 11 13:33:25 Error:[server] pool.c,set_lock(+65): Error setting lock.
Trying again.
postgresql log:
LOG: unexpected EOF on client connection
----------------------------------------------------------------------
LordVan - 15-May-07 14:02
----------------------------------------------------------------------
another - possibly completely seperate issue is when trying to use threaded
view on squirrelmail:
ERROR: Connection dropped by IMAP server.
Query: THREAD REFERENCES ISO-8859-1 ALL
----------------------------------------------------------------------
LordVan - 22-May-07 11:55
----------------------------------------------------------------------
this error seems to be more frequent now with rc2 .
----------------------------------------------------------------------
LordVan - 22-May-07 12:54
----------------------------------------------------------------------
ok i think i got something useful now (tcpdump rulez! :)
It seems that for some reason dbmail imapd does not like the search
command from squirrelmail (at least not all the time ..)
this is what i did to reproduce it (as you can see it doesn't seem to like
the {13} length specifier ... i looked this up in section 6.4.4 on
http://www.faqs.org/rfcs/rfc3501.html):
A002 SELECT "INBOX"
* 2150 EXISTS
* 473 RECENT
* FLAGS (\Seen \Answered \Deleted \Flagged \Draft)
* OK [PERMANENTFLAGS (\Seen \Answered \Deleted \Flagged \Draft)]
* OK [UIDNEXT 361474] Predicted next UID
* OK [UIDVALIDITY 2] UID value
* OK [UNSEEN 8] first unseen message
A002 OK [READ-WRITE] SELECT completed
A003 UID SEARCH CHARSET ISO-8859-1 ALL FROM "planetrecruit"
* SEARCH 279517 280042 280046 280048 280063 284957 285574 285576 291713
291715 291730 291732 303309 304022 304024 304027 304029 304047 310087
310619 310650 310655 310657 310670 310672 316586 317081 317090 317092
328177 328641 328653 328655 328658 328660 328662 335864 336387 336391
336392 336408 342564 342848 342850 350223 350227 350229 359683 360324
360329 360331 360337 360339
A003 OK SEARCH completed
A004 UID SEARCH CHARSET ISO-8859-1 ALL FROM {13} "planetrecruit"
A004 BAD invalid arguments to SEARCH
A005 LOGOUT
* BYE dbmail imap server kisses you goodbye
A005 OK completed
Connection closed by foreign host.
----------------------------------------------------------------------
paul - 22-May-07 13:40
----------------------------------------------------------------------
That's not it.
If SM really sends
A004 UID SEARCH CHARSET ISO-8859-1 ALL FROM {13} "planetrecruit"
then sm is seriously broken.
This is what my test looks like:
x uid search charset iso8859-1 all from {13}
+ OK gimme that string
planetrecruit
* SEARCH
x OK SEARCH completed
----------------------------------------------------------------------
LordVan - 22-May-07 14:36
----------------------------------------------------------------------
hmm ok .. i'll check that .. u are right it might just be because the error
is displayed on a webpage (cuz cr -> whitespace ..)
i'll investigate. .. maybe squirrelmail can write imap commands to a file
or something.. (i dont' want dbmail as a whole to log that much .. or can
i set it to just log from dbmail-imapd?)
----------------------------------------------------------------------
LordVan - 22-May-07 14:38
----------------------------------------------------------------------
by the way i also get it in the 'folder' - frame of squirrelmail.
ERROR: Connection dropped by IMAP server.
Query: STATUS "Drafts" (MESSAGES UNSEEN RECENT)
when i run that command manually it works just fine (the folder is empty
btw)
----------------------------------------------------------------------
paul - 26-May-07 19:05
----------------------------------------------------------------------
I just fixed a problem where SM tripped over empty search results.
----------------------------------------------------------------------
paul - 08-Jun-07 13:46
----------------------------------------------------------------------
I now have independent confirmation. The connection dropped is also seen to
happen during FETCH on large mailboxes:
x login user pass
x examine INBOX
x FETCH 1:* (FLAGS UID RFC822.SIZE INTERNALDATE BODY.PEEK[HEADER.FIELDS
(Date To Cc From Subject X-Priority Importance Priority Content-Type)])
x logout
----------------------------------------------------------------------
froeske - 13-Jun-07 18:07
----------------------------------------------------------------------
I have the same Problem with about 700 Messages in the Inbox, sometimes it
works, sometimes it gives the following message:
ERROR: Connection dropped by IMAP server.
Query: FETCH
1683877,1708358,1737576,1743290,1750664,1780879,1782632,1795451,1797878,1798953,1799063,1802503,1802590,1805095,1807084
(FLAGS UID RFC822.SIZE INTERNALDATE BODY.PEEK[HEADER.FIELDS (Date To Cc
>From Subject X-Priority Importance Priority Content-Type)])
----------------------------------------------------------------------
jasb - 13-Jun-07 19:07
----------------------------------------------------------------------
I have about 3000 messages in my mailbox, and when i search something via
squirrelmail, it always has that behavior
----------------------------------------------------------------------
froeske - 16-Jun-07 16:01
----------------------------------------------------------------------
I did some more trials.
As I stated in another article
(http://www.dbmail.org/mantis/view.php?id=181#607), dbmail crashes, when
squirrelmail
printed this error. In the Log, i can read something like
Jun 14 18:33:21 pure08 kernel: dbmail-imapd[5367]: segfault at
0000000002588288 rip 00002b1cf65963d8 rsp 00007fffb5115920 error 6
I made imap available via xinetd and now, this message is gone. Even when
I do the command that squirrel claims dbmail closes the connection
repeatedly manually (with dbmail-imapd -n), dbmail does not crash nor
prints an error in any way.
----------------------------------------------------------------------
paul - 16-Jun-07 22:32
----------------------------------------------------------------------
To track this down I need a backtrace of a crashed dbmail.
I can tell you how to create one, if you can spare the time and effort.
----------------------------------------------------------------------
froeske - 17-Jun-07 10:43
----------------------------------------------------------------------
Yes, Paul, please tell me, I will try my best (I can do it on Tuesday, when
I come back)
----------------------------------------------------------------------
paul - 17-Jun-07 13:55
----------------------------------------------------------------------
1. build dbmail with debugging symbols: CFLAGS=+-g
2. make sure you don't strip the binaries after compilation
3. allow creation of core dumps: ulimit -c 500000
4. run the unstripped imapd binary, hit with squirrelmail until it
crashes
5. find the core dumps. these should end up in the homedir of the user
running the imapd, or in a tmp directory
6. bundle the imapd binary, the modules (/usr/lib/dbmail/), and the core
file in a tarfile and send it to me.
----------------------------------------------------------------------
bjohnson - 23-Jun-07 09:13
----------------------------------------------------------------------
Perhaps this is a different bug, but I'm going to post here to start
because it might be related.
I'm not having segfaults, but I do have a problem with squirrelmail
reporting "ERROR: Connection dropped by IMAP server.
Query: THREAD REFERENCES ISO-8859-1 ALL" every time I try to open a
particular INBOX.
Attached is a trace level 5 of the thread that serviced this request.
If I change the squirrelmail config with:
$allow_thread_sort = false;
Then I can get to the INBOX about 50% of the time, with the other 50%
producing this message:
"ERROR: Connection dropped by IMAP server.
Query: FETCH
430388,430444,430476,430542,430550,430579,430612,430614,430661,430832,430862,430864,430866,431118,431191
(FLAGS UID RFC822.SIZE INTERNALDATE BODY.PEEK[HEADER.FIELDS (Date To Cc
>From Subject X-Priority Importance Priority Content-Type)])"
So far, at least on one account, this is 100% reproducible.
Also, I should say that this is not a large INBOX, it has < 50 messages.
----------------------------------------------------------------------
paul - 23-Jun-07 10:44
----------------------------------------------------------------------
Please upload the trace you refer to.
Also: thread references is *not* supported by dbmail. However, dbmail
should not disconnect but simply return with a 'TAG THREAD' response.
(actually, it should return a 'TAG BAD' response).
----------------------------------------------------------------------
joshmarshall - 02-Jul-07 02:44
----------------------------------------------------------------------
Hi,
I am getting the error:
ERROR: Connection dropped by IMAP server.
Query: FETCH 1:* (FLAGS UID RFC822.SIZE INTERNALDATE
BODY.PEEK[HEADER.FIELDS (Date To Cc From Subject X-Priority Importance
Priority Content-Type)])
This happens regularly, although it seems to work sometimes and sometimes
not. I have attached a level 10 trace (using stable Debian 2.2.5 package)
which has an example of a fetch that works and a fetch that doesn't
(happened within seconds of each other).
I don't notice anything in the logs that show that it has crashed, however
the mail log seems to just stop getting messages and the task is no longer
running.
----------------------------------------------------------------------
joshmarshall - 02-Jul-07 02:55
----------------------------------------------------------------------
I can confirm that with squirrelmail, the first request for the folder list
with IMAP works fine, it's the second request that fails (which is why I
see a 50% success rate) - so if I use inetd there is a new imapd for each
request and it works 100%.
Hope that helps.
----------------------------------------------------------------------
paul - 02-Jul-07 10:18
----------------------------------------------------------------------
Josh, that helped a lot. I've finally managed to reproduce this bug. I
think I've fixed it in the 2.2 branch.
----------------------------------------------------------------------
LordVan - 22-Sep-07 13:28
----------------------------------------------------------------------
still error from squirrelmail on search on some folders:
ERROR: Connection dropped by IMAP server.
Query: SEARCH CHARSET ISO-8859-1 ALL FROM {8}
archonia
log file on setting 5:
Sep 22 12:21:01 lordvan dbmail/smtp[22698]: Debug:[misc]
misc.c,dbmail_imap_append_alist_as_plist(+1890): handling a standard
address [(null)] [EMAIL PROTECTED]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[db]
dbmodule.c,db_query(+145): last query took [29] seconds
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Info:[db]
dbmodule.c,db_query(+147): slow query [SELECT message_idnr FROM
dbmail_messages m JOIN dbmail_physmessage p ON m.physmessage_id=p.id JOIN
dbmail_headervalue v ON v.physmessage_id=p.id JOIN dbmail_headername n ON
v.headername_id=n.id WHERE mailbox_idnr = 2 AND status IN (0,1) AND
headername ILIKE 'from' AND SUBSTRING(headervalue,0,255) ILIKE
'%archonia%' ORDER BY message_idnr] took [29] seconds
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Message:[db]
dbmodule.c,db_query(+149): slow query [SELECT message_idnr FROM
dbmail_messages m JOIN dbmail_physmessage p ON m.physmessage_id=p.id JOIN
dbmail_headervalue v ON v.physmessage_id=p.id JOIN dbmail_headername n ON
v.headername_id=n.id WHERE mailbox_idnr = 2 AND status IN (0,1) AND
headername ILIKE 'from' AND SUBSTRING(headervalue,0,255) ILIKE
'%archonia%' ORDER BY message_idnr] took [29] seconds
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[mailbox]
dbmail-mailbox.c,_do_search(+1582): [0x80a4100] depth [2] type [5] rows
[28]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[misc]
misc.c,g_tree_merge(+1269): (0x80bf1e0) (0x807ec00): a[714] [AND] b[714]
-> a[714]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[mailbox]
dbmail-mailbox.c,_merge_search(+1659): [0x8092700] leaf [0] depth [1] type
[2] found [714]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[misc]
misc.c,g_tree_merge(+1269): (0x80bf1e0) (0x80c2ba0): a[714] [AND] b[714]
-> a[714]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[mailbox]
dbmail-mailbox.c,_merge_search(+1659): [0x80937a8] leaf [1] depth [2] type
[2] found [714]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[misc]
misc.c,g_tree_merge(+1269): (0x80bf1e0) (0x80c2bc0): a[714] [AND] b[28] ->
a[28]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[mailbox]
dbmail-mailbox.c,_merge_search(+1659): [0x80a4100] leaf [1] depth [2] type
[5] found [28]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[mailbox]
dbmail-mailbox.c,dbmail_mailbox_search(+1691): found [28] ids
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1525): RESPONSE: [*
SEARCH 1038657 1043300 1044322 1066364 1066366 1066384 1066395 1094485
1134994 1138645 1165118 11...]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Error:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1515): write to client
socket failed
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Info:[imap]
imap4.c,IMAPClientHandler(+317): Finished command uid [0]
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Debug:[serverchild]
serverchild.c,PerformChildTask(+379): client handling complete, closing
streams
Sep 22 12:21:29 lordvan dbmail/imap4d[22679]: Info:[serverchild]
serverchild.c,PerformChildTask(+381): connection closed
Sep 22 12:21:59 lordvan dbmail/imap4d[22661]: Debug:[server]
server.c,server_run(+291): MainSigHandler(): got signal [15]
Sep 22 12:21:59 lordvan dbmail/imap4d[22664]: Message:[server]
pool.c,manage_stop_children(+475): General stop requested. Killing
children...
Sep 22 12:22:01 lordvan dbmail/imap4d[22661]: Debug:[server]
server.c,server_run(+291): MainSigHandler(): got signal [15]
Sep 22 12:22:01 lordvan dbmail/imap4d[22664]: Info:[server]
server.c,server_run(+284): server done, restart = [0]
Sep 22 12:22:03 lordvan dbmail/imap4d[22661]: Debug:[server]
server.c,server_run(+306): server has exited, exit status [0]
Sep 22 12:22:03 lordvan dbmail/imap4d[22661]: Info:[serverparent]
serverparent.c,serverparent_mainloop(+181): leaving main loop
Sep 22 12:22:03 lordvan dbmail/imap4d[22661]: Info:[imapd]
imapd.c,main(+67): exit
Sep 22 12:22:03 lordvan dbmail/imap4d[22814]: Message:[server]
pool.c,child_register(+299): register child [22814]
Sep 22 12:22:03 lordvan dbmail/imap4d[22817]: Message:[server]
pool.c,child_register(+299): register child [22817]
Sep 22 12:22:03 lordvan dbmail/imap4d[22810]: Message:[server]
pool.c,scoreboard_state(+590): Scoreboard state: children [2/10], spares
[2 (2 - 4)]
the last couple of lines are from me restarting dbmail-imapd again after
changing log level back...
Issue History
Date Modified Username Field Change
======================================================================
01-May-07 18:24 LordVan New Issue
03-May-07 10:27 LordVan Note Added: 0002132
09-May-07 23:15 aaron Note Added: 0002148
11-May-07 14:34 LordVan Note Added: 0002156
14-May-07 17:08 jasb Issue Monitored: jasb
15-May-07 14:02 LordVan Note Added: 0002175
22-May-07 11:55 LordVan Note Added: 0002202
22-May-07 12:54 LordVan Note Added: 0002203
22-May-07 13:40 paul Note Added: 0002204
22-May-07 14:36 LordVan Note Added: 0002205
22-May-07 14:38 LordVan Note Added: 0002206
26-May-07 19:05 paul Note Added: 0002216
08-Jun-07 13:46 paul Note Added: 0002233
08-Jun-07 13:46 paul Assigned To => paul
08-Jun-07 13:46 paul Priority normal => high
08-Jun-07 13:46 paul Status new => confirmed
13-Jun-07 18:03 froeske Issue Monitored: froeske
13-Jun-07 18:07 froeske Note Added: 0002237
13-Jun-07 18:07 froeske Note Edited: 0002237
13-Jun-07 19:07 jasb Note Added: 0002238
16-Jun-07 16:01 froeske Note Added: 0002242
16-Jun-07 22:28 paul Relationship added has duplicate 0000607
16-Jun-07 22:32 paul Note Added: 0002243
17-Jun-07 10:43 froeske Note Added: 0002244
17-Jun-07 13:55 paul Note Added: 0002245
19-Jun-07 22:04 nethzt Issue Monitored: nethzt
23-Jun-07 09:13 bjohnson Note Added: 0002251
23-Jun-07 10:44 paul Note Added: 0002253
23-Jun-07 10:52 bjohnson File Added:
dbmail-connection-dropped-by-imap-server.log.gz
28-Jun-07 09:49 paul Relationship added has duplicate 0000614
02-Jul-07 02:44 joshmarshall Note Added: 0002270
02-Jul-07 02:44 joshmarshall File Added: squirrelmail.txt.gz
02-Jul-07 02:55 joshmarshall Note Added: 0002271
02-Jul-07 10:18 paul Note Added: 0002272
02-Jul-07 10:32 paul Status confirmed => resolved
02-Jul-07 10:32 paul Resolution open => fixed
02-Jul-07 10:32 paul Fixed in Version => 2.2.6
09-Jul-07 14:49 paul Relationship added has duplicate 0000622
22-Sep-07 13:28 LordVan Status resolved => feedback
22-Sep-07 13:28 LordVan Resolution fixed => reopened
22-Sep-07 13:28 LordVan Note Added: 0002374
======================================================================
_______________________________________________
Dbmail-dev mailing list
Dbmail-dev@dbmail.org
http://twister.fastxs.net/mailman/listinfo/dbmail-dev
