Sure...
I wasn't sure exactly what might be relevant, so I'm including a much
larger portion of the log file. I think the relevant part (at least the
part that I quoted from my original email, is near the bottom of the
log. I think it's relevant since the problem I'm having is that
thunderbird can't open any messages. In fact I just did a little more
testing. I installed a fresh copy of dbmail-2.0.4 and have it running
against a copy of the dbmail database that 2.0.1 is working with. I
also created a new account within Thunderbird to connect to the new imap
server. It connected fine, found all my mailboxes, but was not able to
find any messages within any of the folders. Very weird since all this
works fine with the same data and a 2.0.1 dbmail.
Anyway here is more detail from a not working 2.0.4 imap session.
Thanks for you help.
Mar 22 09:48:34 bait dbmail/imap4d[12292]: COMMAND: [86 select "INBOX"]
Mar 22 09:48:34 bait dbmail/imap4d[12292]: arg[0]: 'INBOX'
Mar 22 09:48:34 bait dbmail/imap4d[12292]: IMAPClientHandler():
Executing command select...
Mar 22 09:48:34 bait dbmail/imap4d[12292]: db.c,db_findmailbox: looking
for mailbox with FQN [INBOX].
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE name='INBOX' AND
owner_idnr='4']
Mar 22 09:48:34 bait dbmail/imap4d[12292]: db.c,db_acl_has_right:
checking ACL for user [4] on mailbox [11]
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE mailbox_idnr =
'11' AND owner_idnr = '4']
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT no_select FROM dbmail_mailboxes WHERE mailbox_idnr = '11']
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT
permission,seen_flag,answered_flag,deleted_flag,flagged_flag,recent_flag,draft_flag
FROM dbmail_mailboxes WHERE mailbox_idnr = '11']
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT 'a',COUNT(*) FROM dbmail_messages WHERE mailbox_idnr='11'
AND (status='0' OR status='1') UNION SELECT 'b',COUNT(*) FROM
dbmail_messages WHERE mailbox_idnr='11' AND (status='0' OR status='1')
AND seen_flag=1 UNION SELECT 'c',COUNT(*) FROM dbmail_messages WHERE
mailbox_idnr='11' AND (status='0' OR status='1') AND recent_flag=1]
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT message_idnr FROM dbmail_messages WHERE mailbox_idnr =
'11' AND status < '2' ORDER BY message_idnr ASC]
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT message_idnr + 1 FROM dbmail_messages ORDER BY
message_idnr DESC LIMIT 1]
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT MIN(message_idnr) FROM dbmail_messages WHERE mailbox_idnr
= '11' AND status < '2' AND seen_flag = '0']
Mar 22 09:48:34 bait dbmail/imap4d[12292]: IMAPClientHandler(): Finished
command select
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT
permission,seen_flag,answered_flag,deleted_flag,flagged_flag,recent_flag,draft_flag
FROM dbmail_mailboxes WHERE mailbox_idnr = '11']
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT 'a',COUNT(*) FROM dbmail_messages WHERE mailbox_idnr='11'
AND (status='0' OR status='1') UNION SELECT 'b',COUNT(*) FROM
dbmail_messages WHERE mailbox_idnr='11' AND (status='0' OR status='1')
AND seen_flag=1 UNION SELECT 'c',COUNT(*) FROM dbmail_messages WHERE
mailbox_idnr='11' AND (status='0' OR status='1') AND recent_flag=1]
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT message_idnr FROM dbmail_messages WHERE mailbox_idnr =
'11' AND status < '2' ORDER BY message_idnr ASC]
Mar 22 09:48:34 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT message_idnr + 1 FROM dbmail_messages ORDER BY
message_idnr DESC LIMIT 1]
Mar 22 09:48:35 bait dbmail/imap4d[12292]: IMAPClientHandler(): line
read for PID 12292
Mar 22 09:48:35 bait dbmail/imap4d[12292]: COMMAND: [87 UID fetch 1:*
(FLAGS)]
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[0]: 'fetch'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[1]: '1:*'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[2]: '('
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[3]: 'FLAGS'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[4]: ')'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: IMAPClientHandler():
Executing command uid...
Mar 22 09:48:35 bait dbmail/imap4d[12292]: db.c,db_acl_has_right:
checking ACL for user [4] on mailbox [11]
Mar 22 09:48:35 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE mailbox_idnr =
'11' AND owner_idnr = '4']
Mar 22 09:48:35 bait dbmail/imap4d[12292]: next_fetch_item(): args[idx =
2] = FLAGS (returning 3)
Mar 22 09:48:35 bait dbmail/imap4d[12292]: dbpgsql.c,db_free_result:
trying to free a result set that is already NULL!
Mar 22 09:48:35 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT seen_flag, answered_flag, deleted_flag, flagged_flag,
draft_flag, recent_flag, TO_CHAR(internal_date, 'YYYY-MM-DD HH24:MI:SS'
), rfcsize, message_idnr FROM dbmail_messages msg, dbmail_physmessage pm
WHERE pm.id = msg.physmessage_id AND message_idnr BETWEEN '1' AND
'821550' AND mailbox_idnr = '11' AND status < '2' ORDER BY message_idnr ASC]
Mar 22 09:48:35 bait dbmail/imap4d[12292]: ic_fetch(): no parsing at all
Mar 22 09:48:35 bait dbmail/imap4d[12292]: _ic_fetch(): no parsing, into
fetch loop
Mar 22 09:48:35 bait last message repeated 619 times
Mar 22 09:48:35 bait dbmail/imap4d[12292]: IMAPClientHandler(): Finished
command uid
Mar 22 09:48:35 bait dbmail/imap4d[12292]: IMAPClientHandler(): line
read for PID 12292
Mar 22 09:48:35 bait dbmail/imap4d[12292]: COMMAND: [88 UID fetch
54165:819563,821018:821397 (UID RFC822.SIZE FLAGS
BODY.PEEK[HEADER.FIELDS (From To Cc Subject Date Message-ID Priority
X-Priority References Newsgroups In-Reply-To Content-Type)])]
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[0]: 'fetch'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[1]:
'54165:819563,821018:821397'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[2]: '('
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[3]: 'UID'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[4]: 'RFC822.SIZE'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[5]: 'FLAGS'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[6]: 'BODY.PEEK'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[7]: '['
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[8]: 'HEADER.FIELDS'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[9]: '('
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[10]: 'From'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[11]: 'To'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[12]: 'Cc'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[13]: 'Subject'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[14]: 'Date'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[15]: 'Message-ID'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[16]: 'Priority'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[17]: 'X-Priority'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[18]: 'References'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[19]: 'Newsgroups'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[20]: 'In-Reply-To'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[21]: 'Content-Type'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[22]: ')'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[23]: ']'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: arg[24]: ')'
Mar 22 09:48:35 bait dbmail/imap4d[12292]: IMAPClientHandler():
Executing command uid...
Mar 22 09:48:35 bait dbmail/imap4d[12292]: db.c,db_acl_has_right:
checking ACL for user [4] on mailbox [11]
Mar 22 09:48:35 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE mailbox_idnr =
'11' AND owner_idnr = '4']
Mar 22 09:48:35 bait dbmail/imap4d[12292]: next_fetch_item(): args[idx =
2] = UID (returning 3)
Mar 22 09:48:35 bait dbmail/imap4d[12292]: next_fetch_item(): args[idx =
3] = RFC822.SIZE (returning 4)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: next_fetch_item(): args[idx =
4] = FLAGS (returning 5)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: next_fetch_item(): args[idx =
22] = ] (returning 23)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: dbpgsql.c,db_free_result:
trying to free a result set that is already NULL!
Mar 22 09:48:36 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT seen_flag, answered_flag, deleted_flag, flagged_flag,
draft_flag, recent_flag, TO_CHAR(internal_date, 'YYYY-MM-DD HH24:MI:SS'
), rfcsize, message_idnr FROM dbmail_messages msg, dbmail_physmessage pm
WHERE pm.id = msg.physmessage_id AND message_idnr BETWEEN '54165' AND
'819563' AND mailbox_idnr = '11' AND status < '2' ORDER BY message_idnr ASC]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: Fetching msgID 54165 (fetch
num 54166)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT messageblk FROM dbmail_messageblks blk, dbmail_messages
msg WHERE blk.physmessage_id = msg.physmessage_id AND msg.message_idnr =
'54165' ORDER BY blk.messageblk_idnr ASC LIMIT 1]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): entering
mime loop
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): mimeloop
finished
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): no valid
mime headers found
Mar 22 09:48:36 bait dbmail/imap4d[12292]: db.c,db_get_main_header:
error parsing header of message [54165]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: Fetching msgID 54285 (fetch
num 54286)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT messageblk FROM dbmail_messageblks blk, dbmail_messages
msg WHERE blk.physmessage_id = msg.physmessage_id AND msg.message_idnr =
'54285' ORDER BY blk.messageblk_idnr ASC LIMIT 1]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): entering
mime loop
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): mimeloop
finished
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): no valid
mime headers found
Mar 22 09:48:36 bait dbmail/imap4d[12292]: db.c,db_get_main_header:
error parsing header of message [54285]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: Fetching msgID 54320 (fetch
num 54321)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT messageblk FROM dbmail_messageblks blk, dbmail_messages
msg WHERE blk.physmessage_id = msg.physmessage_id AND msg.message_idnr =
'54320' ORDER BY blk.messageblk_idnr ASC LIMIT 1]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): entering
mime loop
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): mimeloop
finished
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): no valid
mime headers found
Mar 22 09:48:36 bait dbmail/imap4d[12292]: db.c,db_get_main_header:
error parsing header of message [54320]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: Fetching msgID 54371 (fetch
num 54372)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT messageblk FROM dbmail_messageblks blk, dbmail_messages
msg WHERE blk.physmessage_id = msg.physmessage_id AND msg.message_idnr =
'54371' ORDER BY blk.messageblk_idnr ASC LIMIT 1]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): entering
mime loop
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): mimeloop
finished
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): no valid
mime headers found
Mar 22 09:48:36 bait dbmail/imap4d[12292]: db.c,db_get_main_header:
error parsing header of message [54371]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: Fetching msgID 54422 (fetch
num 54423)
Mar 22 09:48:36 bait dbmail/imap4d[12292]: dbpgsql.c,db_query: executing
query [SELECT messageblk FROM dbmail_messageblks blk, dbmail_messages
msg WHERE blk.physmessage_id = msg.physmessage_id AND msg.message_idnr =
'54422' ORDER BY blk.messageblk_idnr ASC LIMIT 1]
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): entering
mime loop
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): mimeloop
finished
Mar 22 09:48:36 bait dbmail/imap4d[12292]: mime_readheader(): no valid
mime headers found
Mar 22 09:48:36 bait dbmail/imap4d[12292]: db.c,db_get_main_header:
error parsing header of message [54422]
Paul J Stevens wrote:
Matthew,
Could you please include the actual imap COMMAND in the trace? That
way we can see better what's actually going on here. Looks to me like
your database may be corrupted (messages without messageblks or
something similar).
The differences between 2.0.1 and 2.0.4 are very small, but mostly
related to postgres' slowness wrt MAX() and SUM(). I'm not sure
however, that is relevant here. Not without seeing the COMMAND that
is....
Matthew T. O'Connor wrote:
I posted something about this when I tried to upgrade to dbmail
2.0.3, but no one responded. When dbmail 2.0.4 came out I thought I
would give it a shot to see if it fixed the problem, but alas it did
not. So here is a little more detail:
I have a working dbmail w/ postgresql install cirrca 2.0.1. When I
tried to update to dbmail 2.0.3 (and now 2.0.4) I could no longer
retrive messages via IMAP. From the older working dbmail I get a log
like this:
