Francois,
Please try 2.1.1 (or a recent 2.1 snapshot) instead of 2.1.0. Some problems with
inserting headervalues were fixed since 2.1.0.
François-Xavier Le Louarn wrote:
> Paul J Stevens a écrit :
>
>> I'm not much interested in postfix traces. I want trace_level=5
>> dbmail-smtp traces.
>>
>> Try to cat such a message straight into dbmail-smtp from the commandline.
>>
>> Do know how to use gdb? A backtrace would be very useful.
>>
>>
> All right. I've attached the two cases: the logs when the I do a
> 'postfix flush' and the logs of cat'ing the mail directly to
> dbmail-smtp, from the command line. It looks like it's not liking the
> headers.
>
> As for gdb, I've used it but how should I get the backtrace?
>
> Thanks,
> FX.
>
>
> ------------------------------------------------------------------------
>
> After a postfix flush, this is what I get in the maillog:
>
> Jun 29 13:59:12 localhost dbmail/smtp[10506]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost dbmail/smtp[10506]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost postfix/nqmgr[6733]: 3A2AB114B64: from=<[EMAIL
> PROTECTED]>, size=2057, nrcpt=1 (queue active)
> Jun 29 13:59:12 localhost postfix/nqmgr[6733]: 3BB9C114B63: from=<[EMAIL
> PROTECTED]>, size=22662, nrcpt=1 (queue active)
> Jun 29 13:59:12 localhost postfix/pipe[10505]: 21C1B114B61: to=<[EMAIL
> PROTECTED]>,relay=dbmail, delay=94527, status=deferred (Command died with
> signal 11: "/usr/local/sbin/dbmail-smtp")
> Jun 29 13:59:12 localhost dbmail/smtp[10510]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost dbmail/smtp[10510]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost postfix/nqmgr[6733]: 77E74114B5F: from=<[EMAIL
> PROTECTED]>, size=677386, nrcpt=1 (queue active)
> Jun 29 13:59:12 localhost postfix/nqmgr[6733]: D364C114B66: from=<[EMAIL
> PROTECTED]>, size=243457, nrcpt=1 (queue active)
> Jun 29 13:59:12 localhost postfix/nqmgr[6733]: D1307114B59: from=<[EMAIL
> PROTECTED]>, size=2043, nrcpt=1 (queue active)
> Jun 29 13:59:12 localhost dbmail/smtp[10514]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost dbmail/smtp[10514]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost postfix/nqmgr[6733]: CA547114B62: from=<[EMAIL
> PROTECTED]>, size=629039, nrcpt=1 (queue active)
> Jun 29 13:59:12 localhost dbmail/smtp[10517]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost postfix/nqmgr[6733]: 53CA7114B60: from=<[EMAIL
> PROTECTED]>, size=7376, nrcpt=1 (queue active)
> Jun 29 13:59:12 localhost postfix/pipe[10507]: 9420E114B65: to=<[EMAIL
> PROTECTED]>,relay=dbmail, delay=76018, status=deferred (Command died with
> signal 11: "/usr/local/sbin/dbmail-smtp")
> Jun 29 13:59:12 localhost dbmail/smtp[10517]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:12 localhost postfix/pipe[10511]: 945BA114B56: to=<[EMAIL
> PROTECTED]>,relay=dbmail, delay=165085, status=deferred (Command died with
> signal 11: "/usr/local/sbin/dbmail-smtp")
> Jun 29 13:59:13 localhost postfix/nqmgr[6733]: A74A5114B67: from=<[EMAIL
> PROTECTED]>, size=679249, nrcpt=1 (queue active)
> Jun 29 13:59:13 localhost postfix/pipe[10505]: 3A2AB114B64: to=<[EMAIL
> PROTECTED]>,relay=dbmail, delay=82206, status=deferred (Command died with
> signal 11: "/usr/local/sbin/dbmail-smtp")
> Jun 29 13:59:13 localhost dbmail/smtp[10520]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10520]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10528]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10528]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10530]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10530]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10522]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10522]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10523]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10523]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10524]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10524]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10535]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 13:59:13 localhost dbmail/smtp[10535]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
>
> -----
>
> If I cat the mail directly into dbmail-smtp, from the command line:
>
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list():
> mimelist currently has [0] nodes
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list(): mail
> address parser starting
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list():
> total fields in header 0
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list():
> found 0 emailaddresses
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list(): mail
> address parser finished
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list():
> mimelist currently has [0] nodes
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list(): mail
> address parser starting
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list():
> total fields in header 0
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list():
> found 0 emailaddresses
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: mail_address_build_list(): mail
> address parser finished
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: main(): no return path found.
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: authsql.c,auth_check_user_ext:
> checking user [EMAIL PROTECTED] in alias table
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: authsql.c,auth_check_user_ext:
> checks [-1]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT deliver_to FROM dbmail_aliases WHERE lower(alias) =
> lower('[EMAIL PROTECTED]') AND lower(alias) <> lower(deliver_to)]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: authsql.c,auth_check_user_ext:
> into checking loop
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: authsql.c,auth_check_user_ext:
> checking user [EMAIL PROTECTED] to 3
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: authsql.c,auth_check_user_ext:
> checking user [3] in alias table
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: authsql.c,auth_check_user_ext:
> checks [1]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT deliver_to FROM dbmail_aliases WHERE lower(alias) = lower('3')
> AND lower(alias) <> lower(deliver_to)]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: authsql.c,auth_check_user_ext:
> adding [3] to deliver_to address
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dsn.c, dsnuser_resolve: user
> [EMAIL PROTECTED] found total of [1] aliases
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [BEGIN]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT user_idnr FROM dbmail_users WHERE userid='[EMAIL PROTECTED]@__']
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: misc.c,create_unique_id:
> created:701816680e98e05978e5c6bf568afa51
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE name='INBOX' AND
> owner_idnr='1']
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: db.c, db_find_create_mailbox:
> mailbox [INBOX] found
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [INSERT INTO dbmail_physmessage (messagesize, internal_date) VALUES
> ('0', CURRENT_TIMESTAMP)]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [INSERT INTO dbmail_messages(mailbox_idnr, physmessage_id,
> unique_id,recent_flag, status) VALUES ('5', '959',
> '701816680e98e05978e5c6bf568afa51', '1', '5')]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr = '1524']
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [INSERT INTO dbmail_messageblks(is_header, messageblk,blocksize,
> physmessage_id)VALUES ('1','X-Invalid-Header: C/ 629039
> 312 [EMAIL
> PROTECTED]"client_name=reserv6.server5.comA^\client_address=193.49.225.20A4message_origin=reserv6.server5.com[193.49.225.20]A
> [EMAIL PROTECTED]@myserver.comM^O \n^I629351NNReceived: from
> reserv6.server5.com (reserv6.server5.com\n^I[193.49.225.20])N7\n^Iby
> mail.myserver.com (Postfix) with ESMTP id CA547114B62N<\n^Ifor <[EMAIL
> PROTECTED]>; Tue, 28 Jun 2005 14:41:02 +0200 (CEST)NLReceived:
> from\n^Icreinnovsigrid (creinnovsigrid.server5.com [134.206.68.3])NT
> by\n^Ireserv6.server5.com (8.13.3/jtpda-5.3.1) with SMTP idj5SCdJXs013548N+
> ;\n^ITue, 28 Jun 2005 14:39:19 +0200N6Message-ID:\n^I<[EMAIL
> PROTECTED]>N,From: \"SIGRID\"\n^I<si
grid.Jun 29 14:03:13 localhost dbmail/smtp[10561]:
dbmail-message.c,dbmail_message_store: allocating [524288] bytes of memory for
readblock
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: pipe.c,store_message_in_blocks:
> inserting message:
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr = '1524']
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [INSERT INTO dbmail_messageblks(is_header, messageblk,blocksize,
> physmessage_id)VALUES ('0','\n', '1', '959')]
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [UPDATE dbmail_messages SET unique_id =
> '701816680e98e05978e5c6bf568afa51', status = '0' WHERE message_idnr = '1524']
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr = '1524']
> Jun 29 14:03:13 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [UPDATE dbmail_physmessage SET messagesize = '4377', rfcsize = '4418'
> WHERE id = '959']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> 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 = '1524']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: db.c,db_add_quotum_used: adding
> 4377 to mailsize
> Jun 29 14:03:14 localhost dbmail/smtp[10561]:
> db.c.user_idnr_is_delivery_user_idnr: looking up user_idnr for [EMAIL
> PROTECTED]@__
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT user_idnr FROM dbmail_users WHERE userid='[EMAIL PROTECTED]@__']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT id FROM dbmail_headername WHERE headername='X-Invalid-Header']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [INSERT INTO dbmail_headervalue (headername_id, physmessage_id,
> headervalue) VALUES (80,959,'C/ 629039 312
> 1T')]
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT id FROM dbmail_headername WHERE
> headername='X-DBMail-PhysMessage-ID']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [INSERT INTO dbmail_headervalue (headername_id, physmessage_id,
> headervalue) VALUES (10,959,'959')]
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: pipe.c, insert_messages:
> temporary msgidnr is [1524]
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: pipe.c, insert_messages:
> calling sort_and_deliver for useridnr [3]
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE name='INBOX' AND
> owner_idnr='3']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: db.c, db_find_create_mailbox:
> mailbox [INBOX] found
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT pm.messagesize FROM dbmail_physmessage pm, dbmail_messages msg
> WHERE pm.id = msg.physmessage_id AND message_idnr = '1524']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT 1 FROM dbmail_users WHERE user_idnr = '3' AND (maxmail_size >
> 0) AND (curmail_size + '4377' > maxmail_size)]
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: misc.c,create_unique_id:
> created:6508d47dfded037bf2691eab8caeafad
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> 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 '1', physmessage_id, seen_flag, answered_flag,
> deleted_flag, flagged_flag, recent_flag, draft_flag,
> '6508d47dfded037bf2691eab8caeafad', status FROM dbmail_messages WHERE
> message_idnr = '1524']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: db.c,db_add_quotum_used: adding
> 4377 to mailsize
> Jun 29 14:03:14 localhost dbmail/smtp[10561]:
> db.c.user_idnr_is_delivery_user_idnr: no need to look up user_idnr for [EMAIL
> PROTECTED]@__
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [UPDATE dbmail_users SET curmail_size = curmail_size + '4377' WHERE
> user_idnr= '3']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmail-message.c,
> sort_and_deliver: message id=1525, size=4377 is inserted
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: pipe.c, insert_messages:
> successful sort_and_deliver for useridnr [3]
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: insert_messages(): we need to
> deliver [0] messages to external addresses
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr = '1524']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [DELETE FROM dbmail_messages WHERE message_idnr = '1524']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [SELECT message_idnr FROM dbmail_messages WHERE physmessage_id = '959']
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: insert_messages(): temporary
> message deleted from database
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: insert_messages(): End of
> function
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dbmysql.c,db_query: executing
> query [COMMIT]
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: main(): freeing dsnuser list
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: dsn.c, dsnuser_free: dsnuser
> freed
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: main(): freeing all other lists
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: main(): they're all free. we're
> done.
> Jun 29 14:03:14 localhost dbmail/smtp[10561]: main(): exit code is [0].
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Dbmail mailing list
> [email protected]
> https://mailman.fastxs.nl/mailman/listinfo/dbmail
--
________________________________________________________________
Paul Stevens mailto:[EMAIL PROTECTED]
NET FACILITIES GROUP PGP: finger [EMAIL PROTECTED]
The Netherlands________________________________http://www.nfg.nl
