Re: [exim] Understanding flow of exim log files

Top Page
Delete this message
Reply to this message
Author: Heiko Schlittermann
Date:  
To: exim-users
Subject: Re: [exim] Understanding flow of exim log files
Hello Chip,

Chip <jeffschips@???> (Fr 08 Jun 2012 20:47:56 CEST):
> On 6/8/2012 2:23 PM, Heiko Schlittermann wrote:
> > Chip <jeffschips@???> (Fr 08 Jun 2012 19:11:39 CEST):
> >> Below is a snippet of a log file which has raised my suspicion. The
> >> names and identities of the innocent (and not so innocent) have been
> >> obscured. I am trying to understand the *flow* of the traffic and what
> >> actually happened.
> >>
> >> Any help on the flow and what messages were delivered, where, would be
> >> greatly appreciated.
> >
> > Obscuring logs is mostly a bad idea, since it prevents helpful people
> > from checking e.g. MX records of related domains, or prevents from doing
> > some tests against the mentioned servers.
> >
> > And not linebreaking the logs is helpful too. (I re-unbroke the lines).
> >
> > 2012-06-08 12:51:36 SMTP connection from [77.248.xx.xxx]:63305 (TCP/IP
> connection count = 1)
> > 2012-06-08 12:51:37 H=(wzhfmiaqb) [77.248.xx.xxx]:63305 rejected MAIL
> <lakenxxxxxx@???>: Access denied - Invalid HELO name (See
> RFC2821 4.1.1.1)
> > 2012-06-08 12:51:37 SMTP connection from (wzhfmiaqb)
> [77.248.xx.xxx]:63305 closed by DROP in ACL
> >
> > So far the connection was rejected by the logging host. If an invalid
> > HELO should lead to such drastic action?? How do you accept mails for
> > postmaster@…?
> >
> > 2012-06-08 12:51:42 SMTP connection from [124.12.xx.xxx]:60909 (TCP/IP
> connection count = 1)
> > 2012-06-08 12:51:48 1Sd2Pb-0007mS-He <= dawnxxx@???
> H=124-12-xx-xxx.dynamic.xxx.xxx.tw (pa91lxxx.com) [124.12.xx.xxx]:60909
> P=smtp S=982 id=30v18f98p29-09887224-926q7p37@lkcttldr T="This is It & "
> for bluey@???
> > 2012-06-08 12:51:48 cwd=/var/spool/exim 3 args: /usr/sbin/exim -Mc
> 1Sd2Pb-0007mS-He
> > 2012-06-08 12:51:48 1Sd2Pb-0007mS-He check_mail_permissions could not
> determine the sender domain [message_exim_id=1Sd2Pb-0007mS-He
> sender_host_address=124.12.xxx.xxx recipients_count=1]
> >
> > check_mail_permissions … never have seen it. Probably cpanel? But it
> > doesn't seem like a reason for rejecting the mail, because the the exim
> > spool id appears on the next lines again, until exim logs the
> > "Completed" line. This ("Completed") is a strong indication that the
> > "transaction" is done. The => lines are a strong indication for a
> > successful delivery to the local mailbox and for the remote delivery.
> >
> > 2012-06-08 12:51:48 1Sd2Pb-0007mS-He => bluey <bluey@???>
> P=<dawnxxx@???> R=virtual_user T=virtual_userdelivery
> > 2012-06-08 12:51:49 1Sd2Pb-0007mS-He => jeffxxx@???
> <bluey@???> P=<dawnxxx@???> R=lookuphost
> T=remote_smtp H=gmail-smtp-in.l.google.com [173.194.77.27]
> X=TLSv1:RC4-SHA:128
> > 2012-06-08 12:51:49 1Sd2Pb-0007mS-He Completed
> > 2012-06-08 12:51:50 SMTP connection from 124.12.xx.xxx (pa91lxxx.com)
> [124.12.xx.xxx]:60909 closed by QUIT
> >
> > After all, this second connection lead to two mail deliveries, one local
> > and one remote. It does not look unusual, except the fact of the
> > rejection at the MAIL command already.
> >
> >


> Thank you for the hints. I hesitate to include actual, proper email
> addresses and ip addresses because nefarious users will potentially
> harvest them. What is the preferred method for posting a snippet of a
> log to protect such things?


There is no alternative, I think. At least, the way you've choosen is
better than obfuscating with with near to real life addresses… May be
I meant: obfuscation should be done in a sensible way, not hiding the
important details. And sometimes it's not obvious which parts of the log
are the most important ones.

> In any event, if your analysis is correct, as you say, there should have
> been two email deliveries. However, the one directed to
> jeffxxx@??? never arrived and I'm wondering if someone is using my
> server as a relay somehow to send out the message to the second delivery
> you mentioned. In your analysis , to whom (ip adddress or above email
> address) would the second delivery gone?


The first delivery
     => bluey <bluey@???> 
is the local one.


The second
    => jeffxxx@??? <bluey@???> P=<dawn…> 
       was sent via a TLS connection to one of the google mail


The return path used is <dawn…> - the same you see in the incoming <=
line. The "jeffxxx@??? <blue…>" looks like the result of some
forwarding action, or alias expansion, done on behalf of
bluey@???, if I'm not wrong.

The second delivery went to the google mail server (173.194.77.27), sent to
jeffxxx@???.

--
Heiko