here is the trace:
Oct 27 14:26:14 dclx01 postfix/qmgr[1118]: 64CF5833F4:
from=<[EMAIL PROTECTED]>, size=1688, nrcpt=1 (queue active)
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): incoming buffer: [RSET]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): command looked up as
commandtype 2
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): incoming buffer:
[MAIL FROM:<[EMAIL PROTECTED]> SIZE=1688]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): command issued :cmd
[MAIL], value [FROM:<[EMAIL PROTECTED]> SIZE=1688]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): command looked up as
commandtype 4
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: misc.c, find_bounded: Found
[EMAIL PROTECTED] of length [19] between '<' and '>' so next skip [25]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): incoming buffer:
[RCPT TO:<[EMAIL PROTECTED]>]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): command issued :cmd
[RCPT], value [TO:<[EMAIL PROTECTED]>]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): command looked up as
commandtype 9
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: misc.c, find_bounded: Found
[EMAIL PROTECTED] of length [34] between '<' and '>'
so next skip [38]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dsn.c, dsnuser_init: dsnuser
initialized
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
authsql.c,auth_check_user_ext: checking user
[EMAIL PROTECTED] in alias table
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
authsql.c,auth_check_user_ext: checks [-1]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT deliver_to FROM dbmail_aliases WHERE lower(alias) =
lower('[EMAIL PROTECTED]')]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
authsql.c,auth_check_user_ext: into checking loop
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
authsql.c,auth_check_user_ext: checking user
[EMAIL PROTECTED] to |/usr/local/bin/autoreplier.py -u
[EMAIL PROTECTED] -a
[EMAIL PROTECTED] -m /var/cache/dbmail/paul-autoreply.eml
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
authsql.c,auth_check_user_ext: checking user
[|/usr/local/bin/autoreplier.py -u [EMAIL PROTECTED] -a
[EMAIL PROTECTED] -m
/var/cache/dbmail/paul-autoreply.eml] in alias table
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
authsql.c,auth_check_user_ext: checks [1]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT deliver_to FROM dbmail_aliases WHERE lower(alias) =
lower('|/usr/local/bin/autoreplier.py -u
[EMAIL PROTECTED] -a
[EMAIL PROTECTED] -m
/var/cache/dbmail/paul-autoreply.eml')]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
authsql.c,auth_check_user_ext: adding [|/usr/local/bin/autoreplier.py -u
[EMAIL PROTECTED] -a
[EMAIL PROTECTED] -m
/var/cache/dbmail/paul-autoreply.eml] to deliver_to address
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dsn.c, dsnuser_resolve: user
[EMAIL PROTECTED] found total of [1] aliases
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): incoming buffer: [DATA]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp(): command looked up as
commandtype 3
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: main(): requesting sender to
begin message.
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: lmtp.c,lmtp: whole message =
Received: from localhost (localhost.dataconsult.de [127.0.0.1]) ^Iby
mail2.data-consult.de (Postfix) with ESMTP id 64CF5833F4 ^Ifor
<[EMAIL PROTECTED]>; Thu, 27 Oct 2005 14:26:14 +0200
(CEST) X-Original-To: [EMAIL PROTECTED] Delivered-To:
[EMAIL PROTECTED] Received: from data-consult.de
[62.216.169.124] ^Iby localhost with POP3 (fetchmail-6.2.5.2) ^Ifor
[EMAIL PROTECTED] (single-drop); Thu, 27 Oct 2005
14:26:14 +0200 (CEST) Received: from localhost (dcws03 [127.0.0.1]) ^Iby
mail.data-consult.de (Postfix) with ESMTP id 33F3A140047 ^Ifor
<[EMAIL PROTECTED]>; Thu, 27 Oct 2005 14:24:56 +0200 (CEST) Received:
from mail.gmx.net (mail.gmx.net [213.165.64.20]) ^Iby
mail.data-consult.de (Postfix) with SMTP id 0519814003F ^Ifor
<[EMAIL PROTECTED]>; Thu, 27 Oct 2005 14:24:16 +0200 (CEST) Received:
(qmail 27169 invoked by uid 0); 27 Oct 2005 12:24:16 -0000 Received:
from 213.146.112.84 by www18.gmx.n
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: header.c,consume_header_line:
end of header found
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: header.c,get_rfc_size:
remaining_len = 111
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: mime_readheader(): entering
mime loop
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: mime_readheader(): found
double newline; header size: 33 lines
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [BEGIN]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT user_idnr FROM dbmail_users WHERE
userid='[EMAIL PROTECTED]@__']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: misc.c,create_unique_id:
created: b555540694757f0f2f4e666166412db6
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE name='INBOX' AND
owner_idnr='1']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: db.c, db_find_create_mailbox:
mailbox [INBOX] found
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [INSERT INTO dbmail_physmessage (messagesize, internal_date)
VALUES ('0', CURRENT_TIMESTAMP)]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [INSERT INTO dbmail_messages(mailbox_idnr, physmessage_id,
unique_id,recent_flag, status) VALUES ('2', '114752',
'b555540694757f0f2f4e666166412db6', '1', '5')]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr =
'229328']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [INSERT INTO dbmail_messageblks (is_header, messageblk, blocksize,
physmessage_id) VALUES ('1','Received: from localhost
(localhost.dataconsult.de [127.0.0.1])\n^Iby mail2.data-consult.de
(Postfix) with ESMTP id 64CF5833F4\n^Ifor
<[EMAIL PROTECTED]>; Thu, 27 Oct 2005 14:26:14 +0200
(CEST)\nX-Original-To: [EMAIL PROTECTED]:
[EMAIL PROTECTED]: from data-consult.de
[62.216.169.124]\n^Iby localhost with POP3 (fetchmail-6.2.5.2)\n^Ifor
[EMAIL PROTECTED] (single-drop); Thu, 27 Oct 2005
14:26:14 +0200 (CEST)\nReceived: from localhost (dcws03
[127.0.0.1])\n^Iby mail.data-consult.de (Postfix) with ESMTP id
33F3A140047\n^Ifor <[EMAIL PROTECTED]>; Thu, 27 Oct 2005 14:24:56 +0200
(CEST)\nReceived: from mail.gmx.net (mail.gmx.net [213.165.64.20])\n^Iby
mail.data-consult.de (Postfix) with SMTP id 0519814003F\n^Ifor
<[EMAIL PROTECTED]>; Thu, 27 Oct 2005 14:24:16 +0200 (CES
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: store_message_temp():
allocating [524288] bytes of memory for readblock
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
pipe.c,store_message_in_blocks: inserting message: gjghj --
Telefonieren Sie schon oder sparen Sie noch? NEU: GMX Phone_Flat
http://www.gmx.net/de/go/telefonie
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr =
'229328']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [INSERT INTO dbmail_messageblks (is_header, messageblk, blocksize,
physmessage_id) VALUES ('0','gjghj\n\n-- \nTelefonieren Sie schon oder
sparen Sie noch?\nNEU: GMX Phone_Flat
http://www.gmx.net/de/go/telefonie\n', '111', '114752')]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [UPDATE dbmail_messages SET unique_id =
'b555540694757f0f2f4e666166412db6', status = '0' WHERE message_idnr =
'229328']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr =
'229328']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [UPDATE dbmail_physmessage SET messagesize = '1650', rfcsize =
'1688' WHERE id = '114752']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: 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 = '229328']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: db.c,db_add_quotum_used:
adding 1650 to mailsize
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]:
db.c.user_idnr_is_delivery_user_idnr: no need to look up user_idnr for
[EMAIL PROTECTED]@__
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: pipe.c, insert_messages:
temporary msgidnr is [229328]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: insert_messages(): we need to
deliver [1] messages to external addresses
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: insert_messages(): delivering
to external addresses
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: GetConfigValue(): searching
value for config item [SENDMAIL]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: GetConfigValue(): found value
[/usr/sbin/sendmail]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: forward.c,forward: delivering
to [1] external addresses
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: forward.c,forward: opening
pipe to command /usr/local/bin/autoreplier.py -u
[EMAIL PROTECTED] -a
[EMAIL PROTECTED] -m /var/cache/dbmail/paul-autoreply.eml
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: forward.c,forward: call to
popen() successfully opened pipe [11]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: forward.c,forward: sending
message id number [229328] to forward pipe
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: forward.c,forward: ferror
reports 0, feof reports 0 on pipe 11
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: forward.c,forward: sending
lines from message 229328 on pipe 11
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: db.c,db_send_message_lines:
request for [-2] lines
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr =
'229328']
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: db.c,db_send_message_lines:
executing query [SELECT messageblk FROM dbmail_messageblks WHERE
physmessage_id='114752' ORDER BY messageblk_idnr ASC]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT messageblk FROM dbmail_messageblks WHERE
physmessage_id='114752' ORDER BY messageblk_idnr ASC]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: db.c,db_send_message_lines:
sending [-2] lines from message [229328]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: db.c,db_send_message_lines:
getting nextblock [1]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: db.c,db_send_message_lines:
getting nextblock [2]
Oct 27 14:26:14 dclx01 dbmail/lmtpd[7616]: forward.c,forward: closing pipes
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]:
serverchild.c,active_child_sig_handler: got signal [17]
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]:
serverchild.c,active_child_sig_handler: SIGCHLD received... ignoring
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: forward.c,forward: pipe closed
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT physmessage_id FROM dbmail_messages WHERE message_idnr =
'229328']
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [DELETE FROM dbmail_messages WHERE message_idnr = '229328']
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [SELECT message_idnr FROM dbmail_messages WHERE physmessage_id =
'114752']
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [DELETE FROM dbmail_physmessage WHERE id = '114752']
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [DELETE FROM dbmail_messageblks WHERE physmessage_id = '114752']
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: insert_messages(): temporary
message deleted from database
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: insert_messages(): End of
function
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: dbmysql.c,db_query: executing
query [COMMIT]
Oct 27 14:26:15 dclx01 dbmail/lmtpd[7616]: dsn.c, dsnuser_free: dsnuser
freed
Oct 27 14:26:15 dclx01 postfix/lmtp[8172]: 64CF5833F4:
to=<[EMAIL PROTECTED]>, relay=localhost[127.0.0.1],
delay=1, status=sent (215 Recipient <[EMAIL PROTECTED]> OK)
Oct 27 14:26:15 dclx01 postfix/qmgr[1118]: 64CF5833F4: removed
Oct 27 14:27:10 dclx01 postfix/smtpd[8185]: disconnect from
localhost.dataconsult.de[127.0.0.1]
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]: lmtp(): incoming buffer: [QUIT]
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]: lmtp(): command looked up as
commandtype 1
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]: PerformChildTask(): client
handling complete, closing streams
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]: serverchild.c,client_close:
closing write stream
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]: serverchild.c,client_close:
closing read stream
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]: PerformChildTask():
connection closed
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]: PerformChildTask(): waiting
for connection
Oct 27 14:27:55 dclx01 dbmail/lmtpd[7616]:
pool.c,child_reg_disconnected: [7616]
from the trace it looks like the autoforwarder is executed. when i look
into /var/cache/dbmail there is an .db file for the address.
but theres no autoreply generated. i removed the .db file and tried
again, but this doesnt help.
Paul J Stevens wrote:
>trace_level=5 please.
>
>Christian Michallek wrote:
>
>
>>hi list.
>>
>>i tried around a bit with the autoresponder.
>>http://www.dbmail.org/dokuwiki/doku.php?id=autoresponder
>>and it works when i add it with an address that does not exist yet.
>>but i want to add an autoresponse to an existing emailaddress.
>>as example i have:
>>[EMAIL PROTECTED] with the alias [EMAIL PROTECTED]
>>now i want to add an autoresponse for it with this command:
>>
>>dbmail-users -x [EMAIL PROTECTED] -t '|/usr/local/bin/autoreplier.py -u
>>[EMAIL PROTECTED] -a [EMAIL PROTECTED] -m
>>/var/cache/dbmail/test-autoreply.eml'
>>
>>i tried the same thing with the alias [EMAIL PROTECTED]
>>
>>the user gets his mail, but no autoreply.
>>
>>
>>
>
>
>
--
Mit freundlichen Grüßen / Best regards
Christian Michallek
IT Management und Integration
DATA CONSULT SYSTEMHAUS GMBH
Bahnhofstraße 26
36037 Fulda
Tel.: 0661- 9339-481
Fax: 0661- 9337-567
eMail: [EMAIL PROTECTED]
http://www.data-consult.com
