Re: [exim] Understanding flow of exim log files

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?

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?

Thank you.