spmfilter signal 11
Patrick Ben Koetter
I've installed, built and configured spmfilter, spmfilter-clamav and
spmfilter-spamassassin as documented on your website. When I send a test
message it crashes and Postfix delivers the message to the mailbox.
Some test details:
Linux:
$ cat /etc/lsb-release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=10.04
DISTRIB_CODENAME=lucid
DISTRIB_DESCRIPTION="Ubuntu 10.04 LTS"
spmfilter:
spmfilter-0.4.1
spmfilter-clamav-0.1.1
spmfilter-spamassassin-0.1
spmfilter gets called as user mail.
spool permissions:
$ ls -ld /var/spool/spam/
drwxrwxrwx 2 root root 4096 2010-05-24 00:24 /var/spool/spam/
Debug output is here (On a sidenote: Constantly replying "wtf" as an error
message is not useful output):
May 24 00:45:35 x300 postfix/smtpd[4243]: connect from localhost.localdomain[127.0.0.1]
May 24 00:45:52 x300 postfix/smtpd[4243]: E457C403B1: client=localhost.localdomain[127.0.0.1]
May 24 00:46:22 x300 postfix/cleanup[4247]: E457C403B1: message-id=<201005232245...@patrick.example.com>
May 24 00:46:22 x300 postfix/qmgr[4224]: E457C403B1: from=<p...@patrick.example.com>, size=389, nrcpt=1 (queue active)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+132): settings->engine: smtpd
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+134): settings->modules: clamav
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+136): settings->module_fail: 3
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+137): settings->nexthop: 127.0.0.1:2525
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+140): settings->backend: sql
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+143): settings->backend_connection: failover
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+155): settings->add_header: 1
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+161): settings->max_size: 0
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+166): settings->tls: 0
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+169): settings->tls_pass: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+197): settings->sql_driver: sqlite
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+198): settings->sql_name: /etc/spmfilter/spmfilter.db
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+204): settings->sql_port: 0
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+205): settings->sql_user: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+206): settings->sql_pass: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+207): settings->sql_user_query: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+208): settings->sql_encoding: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+209): settings->sql_max_connections: 3
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+263): settings->ldap_uri: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+269): settings->ldap_port: 389
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+270): settings->ldap_binddn: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+271): settings->ldap_bindpw: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+272): settings->ldap_base: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+273): settings->ldap_referrals: 0
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+274): settings->ldap_scope: subtree
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+275): settings->ldap_user_query: (null)
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+290): settings->nexthop_fail_code: 451
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[settings] smf_settings_parse_config(+291): settings->nexthop_fail_msg: Requested action aborted: local error in processi
ng
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[session] smf_session_get(+42): initialize session data
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'EHLO patrick.example.com'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+421): SMTP: 'ehlo' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+427): session->helo: patrick.example.com
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'XFORWARD NAME=localhost.localdomain ADDR=127.0.0.1'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+435): SMTP: 'xforward name' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+437): session->xforward_addr: 127.0.0.1
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'XFORWARD PROTO=SMTP HELO=foo SOURCE=LOCAL'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+435): SMTP: 'xforward name' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+437): session->xforward_addr: 127.0.0.1
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'XFORWARD PROTO=SMTP HELO=foo SOURCE=LOCAL'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'MAIL FROM:<p...@patrick.example.com>'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+455): SMTP: 'mail from' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+518): session->envelope_from: p...@patrick.example.com
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+527): [p...@patrick.example.com] is local [1]
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'RCPT TO:<p...@patrick.example.com>'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+545): SMTP: 'rcpt to' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+562): session->envelope_to[0]: p...@patrick.example.com
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+567): [p...@patrick.example.com] is local [1]
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'DATA'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+588): SMTP: 'data' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] process_data(+272): using spool file: '/var/spool/spmfilter/spmfilter.YA7VCV'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'Received: from foo (localhost.localdomain [127.0.0.1])'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'by patrick.example.com (Postfix) with SMTP id E457C403B1'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'for <p...@patrick.example.com>; Mon, 24 May 2010 00:45:46 +0200 (CEST)'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'From: Patrick <p...@patrick.example.com>'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'To: Patrick <p...@patrick.example.com>'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'Subject: foo'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'Message-Id: <201005232245...@patrick.example.com>'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'Date: Mon, 24 May 2010 00:45:46 +0200 (CEST)'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: ''
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+605): SMTP: got empty line
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'bar'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: '.'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+602): SMTP: wtf?!
May 24 00:46:22 x300 postfix/smtp[4250]: E457C403B1: to=<p...@patrick.example.com>, relay=127.0.0.1[127.0.0.1]:10025, delay=36, delays=36/0.01/0.02/0, dsn=5.0.0, status=bounced (host 127.0.0.1[127.0.0.1] said: 502 Eh? WTF was that? (in reply to end of DATA command))
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'QUIT'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+383): SMTP: 'quit' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[session] smf_session_free(+67): destroy session data
May 24 00:46:22 x300 postfix/spawn[4251]: warning: command /usr/local/sbin/spmfilter killed by signal 11
May 24 00:46:22 x300 postfix/cleanup[4254]: C9201403B5: message-id=<201005232246...@patrick.example.com>
May 24 00:46:22 x300 postfix/qmgr[4224]: C9201403B5: from=<>, size=2298, nrcpt=1 (queue active)
May 24 00:46:22 x300 postfix/bounce[4253]: E457C403B1: sender non-delivery notification: C9201403B5
May 24 00:46:22 x300 postfix/qmgr[4224]: E457C403B1: removed
May 24 00:46:22 x300 postfix/local[4255]: C9201403B5: to=<p...@patrick.example.com>, relay=local, delay=0.05, delays=0.02/0.02/0/0.01, dsn=2.0.0, status=sent (delivered to mailbox)
May 24 00:46:22 x300 postfix/qmgr[4224]: C9201403B5: removed
May 24 00:46:25 x300 postfix/smtpd[4243]: disconnect from localhost.localdomain[127.0.0.1]
Any ideas?
Thanks,
p@rick
--
state of mind
Digitale Kommunikation
http://www.state-of-mind.de
Franziskanerstraße 15 Telefon +49 89 3090 4664
81669 München Telefax +49 89 3090 4666
Amtsgericht München Partnerschaftsregister PR 563
--
Sie haben diese Nachricht erhalten, da Sie der Google Groups-Gruppe spmfilter users beigetreten sind.
Wenn Sie Nachrichten in dieser Gruppe posten möchten, senden Sie eine E-Mail an spmfilt...@googlegroups.com.
Wenn Sie aus dieser Gruppe austreten möchten, senden Sie eine E-Mail an spmfilter-use...@googlegroups.com.
Besuchen Sie die Gruppe unter http://groups.google.com/group/spmfilter-users?hl=de, um weitere Optionen zu erhalten.
Axel Steiner
> Any ideas?
The "wtf" reply is used for unknown smtp commands, and yes, the reply could
be more meaningful. It seems that spmfilter thinks, the data command is already
done...I'll check this.
I've seen, that you've configured a SQLite database as backend,
but without a sql user query. In that case the log messages
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'MAIL FROM:<p...@patrick.example.com>'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+455): SMTP: 'mail from' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+518): session->envelope_from: p...@patrick.example.com
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+527): [p...@patrick.example.com] is local [1]
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+380): client smtp dialog: 'RCPT TO:<p...@patrick.example.com>'
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+545): SMTP: 'rcpt to' received
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+562): session->envelope_to[0]: p...@patrick.example.com
May 24 00:46:22 x300 spmfilter[4252]: [0x8439e28] Debug:[smtpd] load(+567): [p...@patrick.example.com] is local [1]
are a little bit confusing. They are indicating that the email address p...@patrick.example.com
is found in the local sqlite datebase, but without a sql query it's not possible. Maybe
it's a bug, I've to check it.
Bye,
Axel
Patrick Ben Koetter
I fixed that and spmfilter is able to tell my recipient is local now.
Then I did a more or less RFC compliant telnet session where I sent required
headers (except for the date since I was too lazy to run date -R on a second
terminal).
Results:
- spmfilter stopped yelling 'wtf' at me. That's good. ;)
I will investigate a little more, since I changed two things at the same
time and I am not sure if adding a database or doing an RFC compliant
session did the trick.
- But I believe spmfilter rejected the message when it shouldn't. Take a look
at the log below. I sent the message as envelope sender "<>" and if I read
the log correctly spmfilter rejected that sender, which it must not.
May 24 22:22:16 x300 postfix/smtpd[3277]: connect from localhost.localdomain[127.0.0.1]
May 24 22:22:35 x300 postfix/smtpd[3277]: D4F914036F: client=localhost.localdomain[127.0.0.1]
May 24 22:23:21 x300 postfix/cleanup[3281]: D4F914036F: message-id=<201005242022...@patrick.example.com>
May 24 22:23:21 x300 postfix/qmgr[1789]: D4F914036F: from=<>, size=363, nrcpt=1 (queue active)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+132): settings->engine: smtpd
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+134): settings->modules: clamav
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+136): settings->module_fail: 3
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+137): settings->nexthop: 127.0.0.1:2525
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+140): settings->backend: sql
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+143): settings->backend_connection: failover
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+155): settings->add_header: 1
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+161): settings->max_size: 0
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+166): settings->tls: 0
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+169): settings->tls_pass: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+197): settings->sql_driver: sqlite
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+198): settings->sql_name: /etc/spmfilter/spmfilter.db
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+204): settings->sql_port: 0
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+205): settings->sql_user: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+206): settings->sql_pass: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+207): settings->sql_user_query: SELECT * FROM users WHERE email='%s'
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+208): settings->sql_encoding: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+209): settings->sql_max_connections: 3
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+263): settings->ldap_uri: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+269): settings->ldap_port: 389
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+270): settings->ldap_binddn: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+271): settings->ldap_bindpw: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+272): settings->ldap_base: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+273): settings->ldap_referrals: 0
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+274): settings->ldap_scope: subtree
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+275): settings->ldap_user_query: (null)
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+290): settings->nexthop_fail_code: 451
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[settings] smf_settings_parse_config(+291): settings->nexthop_fail_msg: Requested action aborted: local error in processing
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[session] smf_session_get(+42): initialize session data
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+380): client smtp dialog: 'EHLO patrick.example.com'
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+421): SMTP: 'ehlo' received
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+427): session->helo: patrick.example.com
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+380): client smtp dialog: 'XFORWARD NAME=localhost.localdomain ADDR=127.0.0.1'
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+435): SMTP: 'xforward name' received
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+437): session->xforward_addr: 127.0.0.1
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+380): client smtp dialog: 'XFORWARD PROTO=SMTP HELO=localhost SOURCE=LOCAL'
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+380): client smtp dialog: 'MAIL FROM:<>'
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+455): SMTP: 'mail from' received
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+518): session->envelope_from:
May 24 22:23:21 x300 postfix/smtp[3282]: D4F914036F: to=<p...@patrick.example.com>, relay=127.0.0.1[127.0.0.1]:10025, delay=52, delays=52/0.01/0.02/0, dsn=5.0.0, status=bounced (host 127.0.0.1[127.0.0.1] said: 501 Syntax: MAIL FROM:<address> (in reply to MAIL FROM command))
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+380): client smtp dialog: 'RSET'
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+592): SMTP: 'rset' received
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[session] smf_session_free(+67): destroy session data
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[session] smf_session_get(+42): initialize session data
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+380): client smtp dialog: 'QUIT'
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[smtpd] load(+383): SMTP: 'quit' received
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[session] smf_session_free(+67): destroy session data
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[spmfilter] main(+131): processing time: 0.00000 sec.
May 24 22:23:21 x300 spmfilter[3284]: [0x835ae28] Debug:[spmfilter] main(+131): processing time: 0.00000 sec.
May 24 22:23:21 x300 postfix/qmgr[1789]: D4F914036F: removed
May 24 22:23:23 x300 postfix/smtpd[3277]: disconnect from localhost.localdomain[127.0.0.1]
>
> Bye,
> Axel
Axel Steiner
> I fixed that and spmfilter is able to tell my recipient is local now.
> Then I did a more or less RFC compliant telnet session where I sent required
> headers (except for the date since I was too lazy to run date -R on a second
> terminal).
>
> Results:
> - spmfilter stopped yelling 'wtf' at me. That's good. ;)
> I will investigate a little more, since I changed two things at the same
> time and I am not sure if adding a database or doing an RFC compliant
> session did the trick.
At the moment I can't reproduce the error :-/
> - But I believe spmfilter rejected the message when it shouldn't. Take a look
> at the log below. I sent the message as envelope sender "<>" and if I read
> the log correctly spmfilter rejected that sender, which it must not.
>
occur only if a nullsender is received. I'll fix this and provide you
a patch for further testing, when I'm done.
Bye,
Axel
Axel Steiner
> You are right, I've found a bug in handling the mail from command. This will
> occur only if a nullsender is received. I'll fix this and provide you
> a patch for further testing, when I'm done.
As promised, I've fixed now the problem with nullsender and some other stuff.
The patch should apply cleanly to the 0.4.1 tarball.
Bye,
Axel