Can someone help me decipher whats going on in these log files? I've added my own comments there, but as I'm not experienced mail admin I could do with an experienced eye ;)
The bit which gets me is that the SPF section causes the message rejection, even though the domain the mail is being sent from is a very, very well known company. Is it simply that they don't have SPF headers set on their domain?
If so.. what are the safest settings I could use on my server to allow legit email but block spam?
I've got domainkeys, SPF and spamhaus blacklists running, but SPF seems to be causing some problems.
Thanks a lot for any help :)
Remote mailserver connects and begins negotiation
Oct 20 18:30:59 msvsc01-g09np postfix/smtpd[29264]: connect from unknown[192.208.34.37]
Oct 20 17:30:59 msvsc01-g09np postfix/smtpd[29264]: NOQUEUE: client=unknown[192.208.34.37]
Oct 20 17:30:59 msvsc01-g09np postfix/smtpd[29269]: BD5B9292AF1: client=unknown[192.208.34.37]
Oct 20 18:30:59 msvsc01-g09np before-queue[29266]: check handlers for addr: xxxxxxxxxxxxxxxx.com
Oct 20 18:30:59 msvsc01-g09np before-queue[29266]: check handlers for addr: yyyyyyyyyyyyyyyy.com
Oct 20 18:30:59 msvsc01-g09np before-queue[29266]: check handlers for addr: zzzzzzzzzzzzzzzz.com
Oct 20 18:30:59 msvsc01-g09np before-queue[29266]: Processing handlers...
Oct 20 18:30:59 msvsc01-g09np before-remote[29268]: check handlers for addr: xxxxxxxxxxxxxxxx.com
Oct 20 18:30:59 msvsc01-g09np before-remote[29268]: check handlers for addr: yyyyyyyyyyyyyyyy.com
Oct 20 18:30:59 msvsc01-g09np before-remote[29268]: check handlers for addr: zzzzzzzzzzzzzzzz.com
Oct 20 18:30:59 msvsc01-g09np before-remote[29268]: Processing handlers...
Qmail handling
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: hook_dir = '/usr/local/psa/handlers/before-queue'
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: recipient[3] = yyyyyyyyyyyyyyyy.com
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/yyyyyyyyyyyyyyyy.com '
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-MZX9NW/executable'
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: handlers_stderr: PASS
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: call_handlers: PASS during call '/usr/local/psa/handlers/info/20-drweb-MZX9NW/executable' handler
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: recipient[4] = 'zzzzzzzzzzzzzzzz.com'
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/zzzzzzzzzzzzzzzz.com'
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-FoRKet/executable'
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: handlers_stderr: PASS
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: call_handlers: PASS during call '/usr/local/psa/handlers/info/20-drweb-FoRKet/executable' handler
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spf-d7R8jL/executable'
DrWeb Virus Check
Oct 20 18:31:00 msvsc01-g09np qmail-queue[29271]: scan: the message(drweb.tmp.j0zApu) sent by xxxxxxxxxxxxxxxx.com to rcpts is passed
SPF Checking
Oct 20 18:31:00 msvsc01-g09np spf filter[29273]: Starting spf filter...
Oct 20 18:31:00 msvsc01-g09np spf filter[29273]: Error code: (2) Could not find a valid SPF record
Oct 20 18:31:00 msvsc01-g09np spf filter[29273]: Failed to query MAIL-FROM: No DNS data for 'cadbury.com'.
Oct 20 18:31:00 msvsc01-g09np spf filter[29273]: SPF result: none
Oct 20 18:31:00 msvsc01-g09np spf filter[29273]: SPF status: REJECT
SPF Checked and Failed?! = Message rejected. 504 error returned.
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: handlers_stderr: REJECT
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: call_handlers: REJECT during call '/usr/local/psa/handlers/info/10-spf-d7R8jL/executable' handler
Oct 20 18:31:00 msvsc01-g09np before-queue[29266]: call_handlers: stop call handlers from dir '/usr/local/psa/handlers/before-queue/global'
Oct 20 17:31:00 msvsc01-g09np postfix/smtpd[29264]: disconnect from unknown[192.208.34.37]
Oct 20 18:31:00 msvsc01-g09np before-remote[29268]: Lost connection
Oct 20 18:31:00 msvsc01-g09np before-remote[29268]: Some error occured
Oct 20 17:31:00 msvsc01-g09np postfix/smtpd[29269]: lost connection after DATA from unknown[127.0.0.1]
Oct 20 17:31:00 msvsc01-g09np postfix/smtpd[29269]: disconnect from unknown[127.0.0.1]
If the domain in question is cadbury.com or cadburyschweppes.com, which is the PTR of the IP address in the logs...then no, the SPF records do not exist.
You might want to look at not failing when there is no SPF record, only when the SPF record does not match the IP address you are talking to. Not every domain has an SPF record, and it is not a requirement for sending email...