Topic: Not receiving certain emails

[Bozely]

Hi all,

We've recently come across a problem where we are not receiving email from a specific sender, what makes this strange is that the sender mails one of two recipients sometimes both at the same time and it's hit and miss whether we receive the mail. When both are included on the email sometimes one will receive the email and the other won't and vica versa.

Looking at the examples they interchange between CC and TO fields which I thought might point towards issues with the email header information or the way we handle it.

The sender doesn't receive bounce emails so it would seem it black holes somewhere, anyhow have a look at the log for an email he sent that never arrived in a mailbox.

Code: [Select]

2009-03-18 16:08:11.015286500 6755 Accepted connection 3/40 from 207.5.72.81 / exsmtp014-4.exch014.msoutlookonline.net
2009-03-18 16:08:11.016177500 6755 Connection from exsmtp014-4.exch014.msoutlookonline.net [207.5.72.81]
2009-03-18 16:08:11.017003500 6755 running plugin (set_hooks): peers
2009-03-18 16:08:11.017596500 6755 trying to get config for peers/0
2009-03-18 16:08:11.018057500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.018566500 6755 trying to get config for peers/0
2009-03-18 16:08:11.019004500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.020140500 6755 peers hooking valid_auth
2009-03-18 16:08:11.020535500 6755 peers hooking set_hooks
2009-03-18 16:08:11.021036500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.021704500 6755 logging::logterse hooking queue
2009-03-18 16:08:11.022116500 6755 logging::logterse hooking deny
2009-03-18 16:08:11.022524500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.023329500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.024081500 6755 check_earlytalker hooking connect
2009-03-18 16:08:11.024479500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.024954500 6755 count_unrecognized_commands hooking connect
2009-03-18 16:08:11.025501500 6755 count_unrecognized_commands hooking unrecognized_command
2009-03-18 16:08:11.025926500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.026470500 6755 check_relay hooking connect
2009-03-18 16:08:11.027067500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.027565500 6755 check_norelay hooking connect
2009-03-18 16:08:11.028161500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.028768500 6755 require_resolvable_fromhost hooking mail
2009-03-18 16:08:11.029341500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.029977500 6755 check_basicheaders hooking data_post
2009-03-18 16:08:11.030495500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.030990500 6755 dnsbl hooking connect
2009-03-18 16:08:11.031463500 6755 dnsbl hooking rcpt
2009-03-18 16:08:11.031916500 6755 dnsbl hooking disconnect
2009-03-18 16:08:11.032388500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.032985500 6755 check_badmailfrom hooking rcpt
2009-03-18 16:08:11.033351500 6755 check_badmailfrom hooking mail
2009-03-18 16:08:11.033857500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.034422500 6755 check_badrcptto_patterns hooking rcpt
2009-03-18 16:08:11.034919500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.035503500 6755 check_badrcptto hooking rcpt
2009-03-18 16:08:11.036002500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.036495500 6755 check_spamhelo hooking ehlo
2009-03-18 16:08:11.036855500 6755 check_spamhelo hooking helo
2009-03-18 16:08:11.037427500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.038132500 6755 check_goodrcptto hooking rcpt
2009-03-18 16:08:11.038521500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.039086500 6755 rcpt_ok hooking rcpt
2009-03-18 16:08:11.039595500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.040321500 6755 tnef2mime hooking data_post
2009-03-18 16:08:11.040711500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.041328500 6755 spamassassin hooking data_post
2009-03-18 16:08:11.041836500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.042464500 6755 virus::clamav hooking data_post
2009-03-18 16:08:11.043087500 6755 trying to get config for plugin_dirs
2009-03-18 16:08:11.043757500 6755 queue::qmail_2dqueue hooking queue
2009-03-18 16:08:11.044328500 6755 Plugin peers, hook set_hooks returned DECLINED,
2009-03-18 16:08:11.044840500 6755 running plugin (connect): check_earlytalker
2009-03-18 16:08:12.044853500 6755 check_earlytalker plugin: remote host said nothing spontaneous, proceeding
2009-03-18 16:08:12.045243500 6755 Plugin check_earlytalker, hook connect returned DECLINED,
2009-03-18 16:08:12.045579500 6755 running plugin (connect): count_unrecognized_commands
2009-03-18 16:08:12.045963500 6755 Plugin count_unrecognized_commands, hook connect returned DECLINED,
2009-03-18 16:08:12.046282500 6755 running plugin (connect): check_relay
2009-03-18 16:08:12.046678500 6755 trying to get config for relayclients
2009-03-18 16:08:12.047400500 6755 trying to get config for morerelayclients
2009-03-18 16:08:12.047910500 6755 Plugin check_relay, hook connect returned DECLINED,
2009-03-18 16:08:12.048237500 6755 running plugin (connect): check_norelay
2009-03-18 16:08:12.048609500 6755 trying to get config for norelayclients
2009-03-18 16:08:12.049180500 6755 Plugin check_norelay, hook connect returned DECLINED,
2009-03-18 16:08:12.049515500 6755 running plugin (connect): dnsbl
2009-03-18 16:08:12.049886500 6755 dnsbl plugin: RBLSMTPD not set for 207.5.72.81
2009-03-18 16:08:12.050217500 6755 trying to get config for dnsbl_allow
2009-03-18 16:08:12.050842500 6755 trying to get config for dnsbl_zones
2009-03-18 16:08:12.051658500 6755 dnsbl plugin: Checking 81.72.5.207.zen.spamhaus.org for TXT record in the background
2009-03-18 16:08:12.053931500 6755 dnsbl plugin: Checking 81.72.5.207.dnsbl-2.uceprotect.net for TXT record in the background
2009-03-18 16:08:12.056065500 6755 dnsbl plugin: Checking 81.72.5.207.bl.spamcop.net for TXT record in the background
2009-03-18 16:08:12.058207500 6755 dnsbl plugin: Checking 81.72.5.207.dnsbl.ahbl.org for TXT record in the background
2009-03-18 16:08:12.060324500 6755 dnsbl plugin: Checking 81.72.5.207.multihop.dsbl.org for TXT record in the background
2009-03-18 16:08:12.062350500 6755 dnsbl plugin: Checking 81.72.5.207.list.dsbl.org for TXT record in the background
2009-03-18 16:08:12.064360500 6755 dnsbl plugin: Checking 81.72.5.207.dnsbl-1.uceprotect.net for TXT record in the background
2009-03-18 16:08:12.066055500 6755 dnsbl plugin: Checking 81.72.5.207.combined.njabl.org for TXT record in the background
2009-03-18 16:08:12.068144500 6755 dnsbl plugin: Checking 81.72.5.207.psbl.surriel.com for TXT record in the background
2009-03-18 16:08:12.070343500 6755 Plugin dnsbl, hook connect returned DECLINED,
2009-03-18 16:08:12.070769500 6755 trying to get config for smtpgreeting
2009-03-18 16:08:12.071250500 6755 220 rotaserv01.mail.ourserver.com ESMTP
2009-03-18 16:08:12.071679500 6755 trying to get config for timeoutsmtpd
2009-03-18 16:08:12.242382500 6755 dispatching EHLO exsmtp014-4.exch014.msoutlookonline.net
2009-03-18 16:08:12.242385500 6755 running plugin (ehlo): check_spamhelo
2009-03-18 16:08:12.242387500 6755 trying to get config for badhelo
2009-03-18 16:08:12.242388500 6755 Plugin check_spamhelo, hook ehlo returned DECLINED,
2009-03-18 16:08:12.242390500 6755 trying to get config for tls_before_auth
2009-03-18 16:08:12.242392500 6755 trying to get config for me
2009-03-18 16:08:12.244283500 6755 trying to get config for databytes
2009-03-18 16:08:12.244285500 6755 trying to get config for databytes
2009-03-18 16:08:12.244287500 6755 250-mail.ourserver.com Hi exsmtp014-4.exch014.msoutlookonline.net [207.5.72.81]
2009-03-18 16:08:12.244289500 6755 250-PIPELINING
2009-03-18 16:08:12.244290500 6755 250-8BITMIME
2009-03-18 16:08:12.244291500 6755 250 SIZE 15000000
2009-03-18 16:08:12.416378500 6755 dispatching MAIL FROM:<sender@server.com> SIZE=8418
2009-03-18 16:08:12.416381500 6755 full from_parameter: FROM:<sender@server.com> SIZE=8418
2009-03-18 16:08:12.416383500 6755 from email address : [<sender@server.com>]
2009-03-18 16:08:12.416384500 6755 running plugin (mail): require_resolvable_fromhost
2009-03-18 16:08:12.416386500 6755 trying to get config for invalid_resolvable_fromhost
2009-03-18 16:08:12.423800500 6755 trying to get config for require_resolvable_fromhost
2009-03-18 16:08:12.454096500 6755 Plugin require_resolvable_fromhost, hook mail returned DECLINED,
2009-03-18 16:08:12.454460500 6755 running plugin (mail): check_badmailfrom
2009-03-18 16:08:12.454859500 6755 trying to get config for badmailfrom
2009-03-18 16:08:12.455390500 6755 Plugin check_badmailfrom, hook mail returned DECLINED,
2009-03-18 16:08:12.455802500 6755 getting mail from <sender@server.com>
2009-03-18 16:08:12.456135500 6755 250 <sender@server.com>, sender OK - how exciting to get mail from you!
2009-03-18 16:08:12.625158500 6755 dispatching RSET
2009-03-18 16:08:12.625160500 6755 250 OK
2009-03-18 16:08:12.796360500 6755 dispatching QUIT
2009-03-18 16:08:12.801370500 6755 trying to get config for me
2009-03-18 16:08:12.801372500 6755 221 mail.ourserver.com closing connection. Have a wonderful day.
2009-03-18 16:08:12.801374500 6755 click, disconnecting
2009-03-18 16:08:12.801376500 6755 running plugin (disconnect): dnsbl
2009-03-18 16:08:12.801377500 6755 Plugin dnsbl, hook disconnect returned DECLINED,

I have examined this log against a successfully received email and it appears to be missing the vitals like a "TO" field.

As I see it it seems the senders email appears to be at fault but I'd like an opinion as to whether it's perhaps our server settings that are causing the issues before advising them to look at the problem.

Regards, Boz

[CharlieBrady]

Yes, the sender's email server has sent "RSET" and then "QUIT".

Apparently that can be a failure mode of Outlook <-> Exchange communications:

http://office-outlook.com/outlook-forum/index.php/mv/tree/97793/#page_top

What I said below is still true:

Someone should ask the admin of that system why it did that. Since it appears to be a Microsoft Exchange server, perhaps the admin won't know and won't be able to find out.

Edit: Hmmm, somehow I inadvertently edited my early response. I intended to followup with a new message, quoting the first. Apologies for any confusion.

[Bozely]

Charlie thanks for the response, really appreciate it.

I've checked that the server is receiving SMTP requests online and like i've said previously as far as I am aware this is the only sender we have a problem.

We don't know what your server settings are because you have doctored the logs.

What do you need to see from the doctored logs to see to check my smtp settings?