[Dovecot] Problem with fts found against Dovecot hg; examples + trace attached
Asheesh Laroia
asheesh at asheesh.org
Sun Oct 21 10:56:09 EEST 2007
I've been wanting to try out Squat for full-text indexing for a while now, so I
finally gave it a whirl. I did a fresh pull from hg. I have it enabled, but
it's taking *forever* to do a query. (Using alpine, I issued a Select command
for all messages with some word anywhere, which presumably caused the Squat
indexer to run.) I think Dovecot is infinite looping.
I thought something was wrong when I attached strace to it for five minutes and
saw no calls to read() or open(). I can reproduce the "select takes forever"
on a tiny Maildir with 5 messages:
http://paulproteus.acm.jhu.edu/bug-report/2007-10-21/broken.tar.gz
I've also attached the *.in and *.out files that I think are related to this
IMAP conversation.
On a different IMAP conversation with the same "SEARCH takes forever" problem,
I attached a gdb to the running Dovecot and got this backtrace:
(gdb) bt
#0 parse_next_body_to_boundary (ctx=0x85746e8, block_r=0xbf92325c)
at message-parser.c:332
#1 0x080c1b7d in message_parser_parse_next_block (ctx=0x85746e8,
block_r=0xbf92325c) at message-parser.c:717
#2 0xb7f582c2 in fts_mailbox_search_next_nonblock (ctx=0x811c0c0,
mail=0x811d380, tryagain_r=0xbf9232bb) at fts-storage.c:175
#3 0x0805f3e6 in cmd_search_more (cmd=0x80feec0) at cmd-search.c:74
#4 0x0805f768 in cmd_search_more_callback (cmd=0x80feec0) at
cmd-search.c:112
#5 0x080ce8eb in io_loop_handle_timeouts (ioloop=0x80fb250,
update_run_now=true) at ioloop.c:264
#6 0x080cf309 in io_loop_handler_run (ioloop=0x80fb250) at
ioloop-poll.c:159
#7 0x080ce7c8 in io_loop_run (ioloop=0x80fb250) at ioloop.c:303
#8 0x08068c9c in main (argc=135213400, argv=0xbf923464, envp=0xbf92346c)
at main.c:293
So I do know that it's using the fts system. Every few minutes, I've
interrupted it in gdb, and I have gotten these messages back from gdb:
Program received signal SIGINT, Interrupt.
parse_next_body_to_boundary (ctx=0x85746e8, block_r=0xbf92325c)
at message-parser.c:332
332 if (data[i] == '\n') {
(gdb) cont
Continuing.
[wait a few minutes]
Program received signal SIGINT, Interrupt.
parse_next_body_to_boundary (ctx=0x85746e8, block_r=0xbf92325c)
at message-parser.c:331
331 for (; i < block_r->size; i++) {
(gdb) cont
Continuing.
[wait a few minutes]
Program received signal SIGINT, Interrupt.
parse_next_body_to_boundary (ctx=0x85746e8, block_r=0xbf92325c)
at message-parser.c:332
332 if (data[i] == '\n') {
The ctx and block_r are the same at each point I interrupt it. This sounds
like an infinite loop to me if it can't exit this for minutes and minutes.
Furthermore, for the past couple of minutes, when I do this:
(gdb) print block_r[0]
$8 = {part = 0x80f3158, hdr = 0x0,
data = 0x8240d08 "\n<DIV><BR></DIV>Perhaps, but it is important to note
that this is a dissenting<BR>opinion, not part of the actual text of the
Holt bill.<BR><BR><BR>--- In <A
href=\"mailto:TrueVote at yahoogroups.com\">Tru"...,
size = 8192}
I always get the same response back.
I've linked to a fairly small Maildir (five messages) that reproduces the
problem for me. It's possible that only one of those messages is actually
at fault; I haven't tried with any Maildir smaller than five messages.
Is there something more I can do to help fix this problem? I'm happy to do
anything reasonable further if you deem it useful.
-- Asheesh.
--
Bolub's Fourth Law of Computerdom:
Project teams detest weekly progress reporting because it so
vividly manifests their lack of progress.
-------------- next part --------------
00000004 CAPABILITY
00000005 SELECT ttestt
03000006 SEARCH UNANSWERED UNDELETED UNSEEN
03000007 FETCH 5 FLAGS
03000008 FETCH 1:5 (UID ENVELOPE BODY.PEEK[HEADER.FIELDS (Newsgroups Content-MD5 Content-Disposition Content-Language Content-Location resent-to resent-date resent-from resent-cc resent-subject List-Help List-Unsubscribe List-Subscribe List-Post List-Owner List-Archive Followup-To References)] INTERNALDATE RFC822.SIZE FLAGS)
03000009 SEARCH TEXT bbq
-------------- next part --------------
* OK [RAWLOG TIMESTAMP] 2007-10-21 00:45:15
* CAPABILITY IMAP4rev1 SASL-IR SORT THREAD=REFERENCES MULTIAPPEND UNSELECT LITERAL+ IDLE CHILDREN NAMESPACE LOGIN-REFERRALS UIDPLUS LIST-EXTENDED
00000004 OK Capability completed.
* FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
* OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags permitted.
* 5 EXISTS
* 0 RECENT
* OK [UNSEEN 1] First unseen.
* OK [UIDVALIDITY 1192952151] UIDs valid
* OK [UIDNEXT 6] Predicted next UID
00000005 OK [READ-WRITE] Select completed.
* SEARCH 1 2 3 4 5
03000006 OK Search completed.
* 5 FETCH (FLAGS ())
03000007 OK Fetch completed.
* 1 FETCH (UID 1 INTERNALDATE "21-Oct-2007 00:35:38 -0700" RFC822.SIZE 49586 FLAGS () ENVELOPE ("Sat, 14 Jul 2007 02:50:43 -0000" "[TrueVote] Re: More on the thomas.loc.gov link" (("Thomas L. Jones" NIL "DrJones" "alum.MIT.edu")) ((NIL NIL "TrueVote" "yahoogroups.com")) (("Thomas L. Jones" NIL "DrJones" "alum.MIT.edu")) ((NIL NIL "TrueVote" "yahoogroups.com")) NIL NIL "<019f01c7c5c0$620b5110$6701a8c0 at your0cdc4f5844>" "<f79dm3+tng1 at eGroups.com>") BODY[HEADER.FIELDS (NEWSGROUPS CONTENT-MD5 CONTENT-DISPOSITION CONTENT-LANGUAGE CONTENT-LOCATION RESENT-TO RESENT-DATE RESENT-FROM RESENT-CC RESENT-SUBJECT LIST-HELP LIST-UNSUBSCRIBE LIST-SUBSCRIBE LIST-POST LIST-OWNER LIST-ARCHIVE FOLLOWUP-TO REFERENCES)] {67}
List-Unsubscribe: <mailto:TrueVote-unsubscribe at yahoogroups.com>
)
* 2 FETCH (UID 2 INTERNALDATE "21-Oct-2007 00:35:38 -0700" RFC822.SIZE 64455 FLAGS () ENVELOPE ("Fri, 13 Jul 2007 23:39:20 -0400" "Re: [TrueVote] Re: More on the thomas.loc.gov link" (("Ray Mondor" NIL "raymondor" "rcn.com")) ((NIL NIL "TrueVote" "yahoogroups.com")) (("Ray Mondor" NIL "raymondor" "rcn.com")) ((NIL NIL "TrueVote" "yahoogroups.com")("Thomas L. Jones" NIL "DrJones" "alum.MIT.edu")) NIL NIL NIL "<01b101c7c5c8$90a768d0$6701a8c0 at your0cdc4f5844>") BODY[HEADER.FIELDS (NEWSGROUPS CONTENT-MD5 CONTENT-DISPOSITION CONTENT-LANGUAGE CONTENT-LOCATION RESENT-TO RESENT-DATE RESENT-FROM RESENT-CC RESENT-SUBJECT LIST-HELP LIST-UNSUBSCRIBE LIST-SUBSCRIBE LIST-POST LIST-OWNER LIST-ARCHIVE FOLLOWUP-TO REFERENCES)] {106}
References: <f79dm3+tng1 at eGroups.com>
List-Unsubscribe: <mailto:TrueVote-unsubscribe at yahoogroups.com>
)
* 3 FETCH (UID 3 INTERNALDATE "21-Oct-2007 00:35:38 -0700" RFC822.SIZE 76507 FLAGS () ENVELOPE ("Sat, 14 Jul 2007 00:53:40 -0400" "Re: [TrueVote] Re: More on the thomas.loc.gov link" (("Ray Mondor" NIL "raymondor" "rcn.com")) ((NIL NIL "TrueVote" "yahoogroups.com")) (("Ray Mondor" NIL "raymondor" "rcn.com")) ((NIL NIL "jmc27106" "earthlink.net")(NIL NIL "TrueVote" "yahoogroups.com")("Thomas L. Jones" NIL "DrJones" "alum.MIT.edu")) NIL NIL NIL "<01cc01c7c5d2$f2dcd030$6701a8c0 at your0cdc4f5844>") BODY[HEADER.FIELDS (NEWSGROUPS CONTENT-MD5 CONTENT-DISPOSITION CONTENT-LANGUAGE CONTENT-LOCATION RESENT-TO RESENT-DATE RESENT-FROM RESENT-CC RESENT-SUBJECT LIST-HELP LIST-UNSUBSCRIBE LIST-SUBSCRIBE LIST-POST LIST-OWNER LIST-ARCHIVE FOLLOWUP-TO REFERENCES)] {119}
References: <3849-22007761442131343 at earthlink.net>
List-Unsubscribe: <mailto:TrueVote-unsubscribe at yahoogroups.com>
)
* 4 FETCH (UID 4 INTERNALDATE "21-Oct-2007 00:35:38 -0700" RFC822.SIZE 66021 FLAGS () ENVELOPE ("Sat, 14 Jul 2007 00:21:31 -0400" "Re: [TrueVote] Re: More on the thomas.loc.gov link" (("jmc27106 at earthlink.net" NIL "jmc27106" "earthlink.net")) ((NIL NIL "TrueVote" "yahoogroups.com")) ((NIL NIL "jmc27106" "earthlink.net")) (("Ray Mondor" NIL "raymondor" "rcn.com")(NIL NIL "TrueVote" "yahoogroups.com")("Thomas L. Jones" NIL "DrJones" "alum.MIT.edu")) NIL NIL NIL "<3849-22007761442131343 at earthlink.net>") BODY[HEADER.FIELDS (NEWSGROUPS CONTENT-MD5 CONTENT-DISPOSITION CONTENT-LANGUAGE CONTENT-LOCATION RESENT-TO RESENT-DATE RESENT-FROM RESENT-CC RESENT-SUBJECT LIST-HELP LIST-UNSUBSCRIBE LIST-SUBSCRIBE LIST-POST LIST-OWNER LIST-ARCHIVE FOLLOWUP-TO REFERENCES)] {67}
List-Unsubscribe: <mailto:TrueVote-unsubscribe at yahoogroups.com>
)
* 5 FETCH (UID 5 INTERNALDATE "21-Oct-2007 00:35:38 -0700" RFC822.SIZE 61191 FLAGS () ENVELOPE ("Tue, 17 Jul 2007 06:11:48 -0000" "[TrueVote] Re: More on the thomas.loc.gov link" (("Thomas L. Jones" NIL "DrJones" "alum.MIT.edu")) ((NIL NIL "TrueVote" "yahoogroups.com")) (("Thomas L. Jones" NIL "DrJones" "alum.MIT.edu")) ((NIL NIL "TrueVote" "yahoogroups.com")) NIL NIL "<3849-22007761442131343 at earthlink.net>" "<f7hmj4+tb60 at eGroups.com>") BODY[HEADER.FIELDS (NEWSGROUPS CONTENT-MD5 CONTENT-DISPOSITION CONTENT-LANGUAGE CONTENT-LOCATION RESENT-TO RESENT-DATE RESENT-FROM RESENT-CC RESENT-SUBJECT LIST-HELP LIST-UNSUBSCRIBE LIST-SUBSCRIBE LIST-POST LIST-OWNER LIST-ARCHIVE FOLLOWUP-TO REFERENCES)] {67}
List-Unsubscribe: <mailto:TrueVote-unsubscribe at yahoogroups.com>
)
03000008 OK Fetch completed.
More information about the dovecot
mailing list