I upgraded from dbmail 2.0.10 to dbmail 2.2.1 last week. I have one
user that is getting this error message when mail delivery is attempted.
The complaint from the logs seems to be that the INBOX doesn't exist
(and there is an error in creating it). The INBOX does exist, so I'm
not sure what the problem is.
<[EMAIL PROTECTED]>: host localhost[127.0.0.1] said: 511 Recipient
<[EMAIL PROTECTED]> Permanent Failure Address Status Bad destination
mailbox address (in reply to end of DATA command)
mysql> select mailbox_idnr,name,owner_idnr from dbmail_mailboxes where
owner_idnr=16;
+--------------+------------------+------------+
| mailbox_idnr | name | owner_idnr |
+--------------+------------------+------------+
| 38 | Drafts | 16 |
| 32 | INBOX | 16 |
| 54 | INBOX/ABC | 16 |
| 57 | INBOX/DEF | 16 |
| 52 | INBOX/GHI | 16 |
| 51 | INBOX/JKL | 16 |
| 56 | INBOX/MNO | 16 |
| 53 | INBOX/PQR | 16 |
| 58 | INBOX/STU | 16 |
| 36 | Sent | 16 |
| 37 | Trash | 16 |
+--------------+------------------+------------+
11 rows in set (0.00 sec)
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Info:[serverchild]
serverchild.c,select_and_accept(+252): received connection
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Info:[serverchild]
serverchild.c,select_and_accept(+275): connection accepted
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Message:[serverchild]
serverchild.c,PerformChildTask(+339): incoming connection from
[127.0.0.1 (ginger)] by pid [3612]
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[serverchild]
serverchild.c,PerformChildTask(+365): client info init complete, calling
client handler
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+255): incoming buffer: [LHLO ns4.example.com]
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+269): command issued :cmd [LHLO], value [ns4.example.com]
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+277): command looked up as commandtype 0
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+255): incoming buffer: [MAIL FROM:<[EMAIL PROTECTED]> SIZE=2536]
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+269): command issued :cmd [MAIL], value
[FROM:<[EMAIL PROTECTED]> SIZE=2536]
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+277): command looked up as commandtype 4
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Info:[misc]
misc.c,find_bounded(+338): Found [EMAIL PROTECTED] of length [23] between
'<' and '>' so next skip [29]
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+255): incoming buffer: [RCPT TO:<[EMAIL PROTECTED]>]
Nov 27 17:00:19 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+269): command issued :cmd [RCPT], value
[TO:<[EMAIL PROTECTED]>]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+277): command looked up as commandtype 9
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[misc]
misc.c,find_bounded(+338): Found [EMAIL PROTECTED] of length [18]
between '<' and '>' so next skip [22]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[dsn]
dsn.c,dsnuser_init(+215): dsnuser initialized
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[dsn]
dsn.c,dsnuser_resolve(+558): checking if [EMAIL PROTECTED] is a valid
username, alias, or catchall.
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+219): checking user [EMAIL PROTECTED]
in alias table
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+236): checks [0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT deliver_to FROM dbmail_aliases
WHERE lower(alias) = lower('[EMAIL PROTECTED]') AND lower(alias) <>
lower(deliver_to)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+270): into checking loop
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+276): checking user [EMAIL PROTECTED] to
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+219): checking user [] in alias table
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+236): checks [1]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT deliver_to FROM dbmail_aliases
WHERE lower(alias) = lower('') AND lower(alias) <> lower(deliver_to)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+258): adding [] to deliver_to address
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+276): checking user [EMAIL PROTECTED] to 16
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+219): checking user [16] in alias table
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+236): checks [1]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT deliver_to FROM dbmail_aliases
WHERE lower(alias) = lower('16') AND lower(alias) <> lower(deliver_to)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[auth]
authsql.c,auth_check_user_ext(+258): adding [16] to deliver_to address
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[dsn]
dsn.c,address_has_alias(+262): user [EMAIL PROTECTED] found total of
[2] aliases
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[dsn]
dsn.c,dsnuser_resolve(+565): delivering [EMAIL PROTECTED] as an alias.
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+255): incoming buffer: [DATA]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+277): command looked up as commandtype 3
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+532): requesting sender to begin message.
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[message]
dbmail-message.c,_set_content_from_stream(+469): parse message
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[lmtp]
lmtp.c,lmtp(+563): whole message = Received: by ns4.example.com
(Postfix, from userid 106) ^Iid CDDA05B1F2; Mon, 27 Nov 2006 17:00:19
-0500 (EST) Received: from localhost (ginger [127.0.0.1]) ^Iby
ns4.example.com (Postfix) with ESMTP id BDC3D5B1F7 ^Ifor
<[EMAIL PROTECTED]>; Mon, 27 Nov 2006 17:00:18 -0500 (EST)
X-Virus-Scanned: by frontline (amavisd-new) at example.com X-Spam-Score:
-0.15 X-Spam-Level: X-Spam-Status: No, score=-0.15 tagged_above=-10000
required=10000 ^Itests=[AWL=0.875, BAYES_00=-2.599, HTML_MESSAGE=0.001,
^IHTML_SHORT_LENGTH=1.574, SPF_PASS=-0.001] Received: from
ns4.example.com ([127.0.0.1]) ^Iby localhost (ginger.example.com
[127.0.0.1]) (amavisd-new, port 10024) ^Iwith ESMTP id bsuUrpPUY7l4 for
<[EMAIL PROTECTED]>; ^IMon, 27 Nov 2006 17:00:16 -0500 (EST)
Received-SPF: pass (ginger.example.com: domain of [EMAIL PROTECTED]
designates 66.249.92.171 as permitted sender) Received: from
ug-out-1314.google.com (ug-out-1314.google.com [66.249.92.171]) ^I
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [BEGIN]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT user_idnr FROM dbmail_users
WHERE lower(userid) = lower('[EMAIL PROTECTED]@__')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[misc]
misc.c,create_unique_id(+109): created: 27ed9ab458ba3649aab843832ff7ebb3
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox(+2296): looking for mailbox with FQN [INBOX].
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT mailbox_idnr FROM
dbmail_mailboxes WHERE name LIKE 'INBOX' AND owner_idnr=1]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_find_create_mailbox(+3129): mailbox [INBOX] found
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_physmessage
(messagesize, internal_date) VALUES (0, CURRENT_TIMESTAMP)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO
dbmail_messages(mailbox_idnr, physmessage_id, unique_id,recent_flag,
status) VALUES (4, 69220, '27ed9ab458ba3649aab843832ff7ebb3', 1, 5)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT physmessage_id FROM
dbmail_messages WHERE message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_messageblks
(is_header, messageblk,blocksize, physmessage_id) VALUES (1,'Received:
by ns4.example.com (Postfix, from userid 106)^Iid CDDA05B1F2;\n^IMon, 27
Nov 2006 17:00:19 -0500 (EST)\nReceived: from localhost (ginger
[127.0.0.1])^Iby ns4.example.com (Postfix)\n^Iwith ESMTP id
BDC3D5B1F7^Ifor <[EMAIL PROTECTED]>;\n^IMon, 27 Nov 2006 17:00:18 -0500
(EST)\nX-Virus-Scanned: by frontline (amavisd-new) at
example.com\nX-Spam-Score: -0.15\nX-Spam-Level: \nX-Spam-Status: No,
score=-0.15 tagged_above=-10000 required=10000\n^Itests=[AWL=0.875,
BAYES_00=-2.599, HTML_MESSAGE=0.001,\n^IHTML_SHORT_LENGTH=1.574,
SPF_PASS=-0.001]\nReceived: from ns4.example.com ([127.0.0.1])\n^Iby
localhost (ginger.example.com [127.0.0.1]) (amavisd-new, port
10024)\n^Iwith ESMTP id bsuUrpPUY7l4 for <[EMAIL PROTECTED]>;\n^IMon, 27
Nov 2006 17:00:16 -0500 (EST)\nReceived-SPF: pass (ginger.example.com:
domain of [EMAIL PROTECTED] 66.249
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[message]
dbmail-message.c,dbmail_message_store(+861): allocating [524288] bytes
of memory for readblock
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[delivery]
pipe.c,store_message_in_blocks(+477): inserting message
[------=_Part_67882_2444685.1164664812927 Content-Type: text/plain;
charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit
Content-Disposition: inline Please ignore
------=_Part_67882_2444685.1164664812927 Content-Type: text/html;
charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition:
inline Please ignore<br> ------=_Part_67882_2444685.1164664812927-- ]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT physmessage_id FROM
dbmail_messages WHERE message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_messageblks
(is_header, messageblk,blocksize, physmessage_id) VALUES
(0,'------=_Part_67882_2444685.1164664812927\nContent-Type: text/plain;
charset=ISO-8859-1; format=flowed\nContent-Transfer-Encoding:
7bit\nContent-Disposition: inline\n\nPlease
ignore\n\n------=_Part_67882_2444685.1164664812927\nContent-Type:
text/html; charset=ISO-8859-1\nContent-Transfer-Encoding:
7bit\nContent-Disposition: inline\n\nPlease
ignore<br>\n\n------=_Part_67882_2444685.1164664812927--\n', 385, 69220)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [UPDATE dbmail_messages SET unique_id =
'27ed9ab458ba3649aab843832ff7ebb3', status = 0 WHERE message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT physmessage_id FROM
dbmail_messages WHERE message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [UPDATE dbmail_physmessage SET
messagesize = 2542, rfcsize = 2597 WHERE id = 69220]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT dbmail_mailboxes.owner_idnr FROM
dbmail_mailboxes, dbmail_messages WHERE dbmail_mailboxes.mailbox_idnr =
dbmail_messages.mailbox_idnr AND dbmail_messages.message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,user_idnr_is_delivery_user_idnr(+4320): no need to look up
user_idnr for [EMAIL PROTECTED]@__]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='Content-Type']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES
(1,69220,'multipart/alternative;
^Iboundary=\"----=_Part_67882_2444685.1164664812927\"')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='Date']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (2,69220,'Mon, 27
Nov 2006 15:00:12 -0700')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='DomainKey-Signature']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES
(44,69220,'a=rsa-sha1; q=dns; c=nofws; s=beta; d=gmail.com;
h=received:message-id:date:from:to:subject:mime-version:content-type;
b=R6FbmpZu/XouTXrYWzMXT2HMH7VCGbTuOyJilK09nxVQFkNn2+AKucIV963W+Bv1CWNdsTlbUmnuRi3zRciqb3Hr00CIbBuqeT8vrW+vSHGuwbNrx0wie08iFMlR9SGVFo2aEu85r4AYcNMmsWBhx/9WCobFjAp8MisgE9ZTNXU=')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='From']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (3,69220,'Bernard
Johnson <[EMAIL PROTECTED]>')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='Message-ID']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES
(4,69220,'<[EMAIL PROTECTED]>')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='Received']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (5,69220,'by
10.67.97.17 with HTTP; Mon, 27 Nov 2006 14:00:12 -0800 (PST)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (5,69220,'from
ns4.example.com ([127.0.0.1])^Iby localhost (ginger.example.com
[127.0.0.1]) (amavisd-new, port 10024)^Iwith ESMTP id bsuUrpPUY7l4 for
<[EMAIL PROTECTED]>;^IMon, 27 Nov 2006 17:00:16 -0500 (EST)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (5,69220,'from
localhost (ginger [127.0.0.1])^Iby ns4.example.com (Postfix) with ESMTP
id BDC3D5B1F7^Ifor <[EMAIL PROTECTED]>; Mon, 27 Nov 2006 17:00:18 -0500
(EST)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (5,69220,'by
ug-out-1314.google.com with SMTP id s2so1109069uge for
<[EMAIL PROTECTED]>; Mon, 27 Nov 2006 14:00:13 -0800 (PST)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (5,69220,'by
ns4.example.com (Postfix, from userid 106)^Iid CDDA05B1F2; Mon, 27 Nov
2006 17:00:19 -0500 (EST)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (5,69220,'from
ug-out-1314.google.com (ug-out-1314.google.com [66.249.92.171])^Iby
ns4.example.com (Postfix) with ESMTP id 504DD5B1F2^Ifor
<[EMAIL PROTECTED]>; Mon, 27 Nov 2006 17:00:16 -0500 (EST)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (5,69220,'by
10.67.26.7 with SMTP id d7mr207261ugj.1164664812988; Mon, 27 Nov
2006 14:00:12 -0800 (PST)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='Received-SPF']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (6,69220,'pass
(ginger.example.com: domain of [EMAIL PROTECTED] designates 66.249.92.171
as permitted sender)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='Subject']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (9,69220,'test
mesage - please ignore (#1)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='To']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES
(10,69220,'[EMAIL PROTECTED]')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='X-Spam-Level']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (16,69220,'')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='X-Spam-Score']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (17,69220,'-0.15')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='X-Spam-Status']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (18,69220,'No,
score=-0.15 tagged_above=-10000 required=10000^Itests=[AWL=0.875,
BAYES_00=-2.599, HTML_MESSAGE=0.001,^IHTML_SHORT_LENGTH=1.574,
SPF_PASS=-0.001]')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='X-TMDA-Action']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (19,69220,'OK
(headers \"^X-Spam-Level:\\s\\*{0,1}\" ok)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT id FROM dbmail_headername WHERE
headername='X-Virus-Scanned']
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_headervalue
(headername_id, physmessage_id, headervalue) VALUES (20,69220,'by
frontline (amavisd-new) at example.com')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_tofield
(physmessage_id, toname, toaddr) VALUES (69220,'','[EMAIL PROTECTED]')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_fromfield
(physmessage_id, fromname, fromaddr) VALUES (69220,'Bernard
Johnson','[EMAIL PROTECTED]')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_datefield
(physmessage_id, datefield) VALUES (69220,'2006-11-27 22:00:12')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_subjectfield
(physmessage_id, subjectfield) VALUES (69220,'test mesage - please
ignore (#1)')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[misc]
misc.c,dbmail_imap_append_alist_as_plist(+1824): handling a standard
address [Bernard Johnson] [EMAIL PROTECTED]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[misc]
misc.c,dbmail_imap_append_alist_as_plist(+1824): handling a standard
address [(null)] [EMAIL PROTECTED]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_envelope
(physmessage_id, envelope) VALUES (69220,'(\"Mon, 27 Nov 2006 15:00:12
-0700\" \"test mesage - please ignore (#1)\" ((\"Bernard Johnson\" NIL
\"blat\" \"gmail.com\")) ((\"Bernard Johnson\" NIL \"blat\"
\"gmail.com\")) ((\"Bernard Johnson\" NIL \"blat\" \"gmail.com\")) ((NIL
NIL \"blarg\" \"example.com\")) NIL NIL NIL
\"<[EMAIL PROTECTED]>\")')]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[delivery]
pipe.c,insert_messages(+547): temporary msgidnr is [163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[delivery]
pipe.c,insert_messages(+570): calling sort_and_deliver for useridnr [16]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[sort]
sort.c,sort_and_deliver(+55): Destination [EMAIL PROTECTED] useridnr
[16], mailbox [(null)], source [0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[misc]
misc.c,find_bounded(+313): Found nothing between '+' and '@'
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT name FROM dbmail_sievescripts
WHERE owner_idnr = 16 AND active = 1]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[sort]
sort.c,sort_deliver_to_mailbox(+136): useridnr [16] mailbox [INBOX]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox(+2296): looking for mailbox with FQN [INBOX].
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT mailbox_idnr FROM
dbmail_mailboxes WHERE name LIKE 'INBOX' AND owner_idnr=16]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_find_create_mailbox(+3129): mailbox [INBOX] found
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sort]
sort.c,sort_deliver_to_mailbox(+150): Checking if we have the right to
post incoming messages
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT
permission,seen_flag,answered_flag,deleted_flag,flagged_flag,recent_flag,draft_flag
FROM dbmail_mailboxes WHERE mailbox_idnr = 32]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_acl_has_right(+3956): checking ACL [post_flag] for user [16] on
mailbox [32]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT owner_idnr FROM dbmail_mailboxes
WHERE mailbox_idnr = 32]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_acl_has_right(+3966): mailbox [32] is owned by user [16], is
that also [16]?
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_acl_has_right(+3970): mailbox [32] is owned by user [16], giving
all rights
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[sort]
sort.c,sort_deliver_to_mailbox(+175): user [16] has right to deliver
mail to [INBOX]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT pm.messagesize FROM
dbmail_physmessage pm, dbmail_messages msg WHERE pm.id =
msg.physmessage_id AND message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT 1 FROM dbmail_users WHERE
user_idnr = 16 AND (maxmail_size > 0) AND (curmail_size + 2542 >
maxmail_size)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[misc]
misc.c,create_unique_id(+109): created: 10611a38fe9bfe0c629e1e437081e7bf
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_messages
(mailbox_idnr,physmessage_id, seen_flag, answered_flag, deleted_flag,
flagged_flag, recent_flag, draft_flag, unique_id, status) SELECT 32,
physmessage_id, seen_flag, answered_flag, deleted_flag, flagged_flag,
recent_flag, draft_flag, '10611a38fe9bfe0c629e1e437081e7bf', status FROM
dbmail_messages WHERE message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,user_idnr_is_delivery_user_idnr(+4320): no need to look up
user_idnr for [EMAIL PROTECTED]@__]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,user_quotum_inc(+336): adding 2542 to mailsize
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [UPDATE dbmail_users SET curmail_size =
curmail_size + 2542 WHERE user_idnr = 16]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Message:[sort]
sort.c,sort_deliver_to_mailbox(+195): message id=163059, size=2542 is
inserted
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[sort]
sort.c,sort_and_deliver(+112): Keep was not cancelled. Message will be
delivered by default.
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[delivery]
pipe.c,insert_messages(+577): successful sort_and_deliver for useridnr [16]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[delivery]
pipe.c,insert_messages(+570): calling sort_and_deliver for useridnr [0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[sort]
sort.c,sort_and_deliver(+55): Destination [EMAIL PROTECTED] useridnr
[0], mailbox [(null)], source [0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[misc]
misc.c,find_bounded(+313): Found nothing between '+' and '@'
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT name FROM dbmail_sievescripts
WHERE owner_idnr = 0 AND active = 1]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[sort]
sort.c,sort_deliver_to_mailbox(+136): useridnr [0] mailbox [INBOX]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox(+2296): looking for mailbox with FQN [INBOX].
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT mailbox_idnr FROM
dbmail_mailboxes WHERE name LIKE 'INBOX' AND owner_idnr=0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox_owner(+2411): no mailbox found
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[db]
db.c,db_mailbox_create_with_parents(+2885): Creating mailbox [INBOX]
source [6] for user [0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox(+2296): looking for mailbox with FQN [INBOX].
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT mailbox_idnr FROM
dbmail_mailboxes WHERE name LIKE 'INBOX' AND owner_idnr=0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox_owner(+2411): no mailbox found
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_imap_split_mailbox(+2750): Splitting mailbox [INBOX] simple name
[INBOX] namespace [(null)] username [(null)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_imap_split_mailbox(+2785): Preparing mailbox [INBOX]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox(+2296): looking for mailbox with FQN [INBOX].
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT mailbox_idnr FROM
dbmail_mailboxes WHERE name LIKE 'INBOX' AND owner_idnr=0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[db]
db.c,db_findmailbox_owner(+2411): no mailbox found
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [INSERT INTO dbmail_mailboxes (name,
owner_idnr,seen_flag, answered_flag, deleted_flag, flagged_flag,
recent_flag, draft_flag, permission) VALUES ('INBOX', 0, 1, 1, 1, 1, 1,
1, 2)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Error:[sql]
dbmysql.c,db_query(+288): [Cannot add or update a child row: a foreign
key constraint fails] [INSERT INTO dbmail_mailboxes (name,
owner_idnr,seen_flag, answered_flag, deleted_flag, flagged_flag,
recent_flag, draft_flag, permission) VALUES ('INBOX', 0, 1, 1, 1, 1, 1,
1, 2)]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Error:[db]
db.c,db_createmailbox(+3054): could not create mailbox
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Error:[db]
db.c,db_find_create_mailbox(+3114): could not create mailbox [INBOX]
because [Database error while creating]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Error:[sort]
sort.c,sort_deliver_to_mailbox(+139): mailbox [INBOX] not found
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Info:[sort]
sort.c,sort_and_deliver(+112): Keep was not cancelled. Message will be
delivered by default.
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Error:[delivery]
pipe.c,insert_messages(+582): permanent failure sort_and_deliver for
useridnr [0]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[delivery]
pipe.c,insert_messages(+636): deliver [0] messages to external addresses
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT physmessage_id FROM
dbmail_messages WHERE message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [DELETE FROM dbmail_messages WHERE
message_idnr = 163058]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [SELECT message_idnr FROM
dbmail_messages WHERE physmessage_id = 69220]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[delivery]
pipe.c,insert_messages(+658): temporary message deleted from database. Done.
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[sql]
dbmysql.c,db_query(+286): query [COMMIT]
Nov 27 17:00:20 ginger dbmail/lmtpd[3612]: Debug:[dsn]
dsn.c,dsnuser_free(+241): dsnuser freed