--On 1 May 2009 11:10:24 -0600 Renee <soundwreck@???> wrote:
> Thanks Ian & Bill, for your advice.
>
> Bill- I think I'm okay under the scenarios you listed in "A". "B" could
> be a different story...? My un-obfuscated logs, below, with "log_selector
> +all" should be able to shed more light on this subject.
Interesting. Alpine is connecting on port 587, and getting a "relay not
permitted" error. Then it does an RSET, and somehow manages to send the
message, to the same Exim process "[4062]".
Does your backend authenticator log authentication attempts? My guess is
that alpine is maybe trying to send email without authentication first,
then with authentication. The first attempt really ought to fail, whoever
the recipient is.
If you send to a local recipient, then this may succeed first time. It
shouldn't really. You really do want your MSA connections authenticated.
Exceptions may be permitted if you have a reason to trust the machine
sending the email.
> I did a few different tests this morning. Two from alpine on both the
> localhost (cielo) and another host within my control that has alpine
> configured to look to cielo. I won't post the log from the latter, as it
> is essentially the same, just a different sending host. I also did some
> tests from webmail (squirrelmail) and thunderbird to show the difference.
> I'll just post the log from thunderbird.
>
> It appears that there are two extra lines in the alpine output logging
> that aren't displayed when using thunderbird, etc.. First the "relay not
> permitted" line, then an "incomplete transaction" statement.
>
> Also, since I first posted, I've added mailscanner back into the loop, but
> I've already confirmed that the same problem occurs with and without
> mailscanner's involvement.
>
> alpine:
> 2009-05-01 10:49:47 [3958] SMTP connection from [129.24.125.136]:33508
> I=[129.24.125.136]:587 (TCP/IP connection count = 1)
> 2009-05-01 10:49:47 [4062] H=cielo.unm.edu [129.24.125.136]:33508
> I=[129.24.125.136]:587 F=<obscure@???> rejected RCPT <
> soundwreck@???>: relay not permitted
> 2009-05-01 10:49:47 [4062] H=cielo.unm.edu [129.24.125.136]:33508
> I=[129.24.125.136]:587 incomplete transaction (RSET) from <
> obscure@???>
> 2009-05-01 10:49:47 [4062] 1Lzvvn-00013W-Of "obscure@???" from
> env-from rewritten as "obscure@???" by submission mode
> 2009-05-01 10:49:47 [4062] 1Lzvvn-00013W-Of <= obscure@??? H=
> cielo.unm.edu [129.24.125.136]:33508 I=[129.24.125.136]:587 P=esmtpsa
> X=TLSv1:AES256-SHA:256 CV=no A=dovecot_plain:obscure S=571 id=
> alpine.GSO.2.00.0905011049180.4005@??? T="test from alpine"
> from < obscure@???> for soundwreck@???
> 2009-05-01 10:49:47 [4062] SMTP connection from
> cielo.unm.edu[129.24.125.136]:33508 I=[129.24.125.136]:587 closed by
> QUIT
> 2009-05-01 10:49:50 [4069] cwd=/var/spool/MailScanner/incoming/3969 5
> args: /usr/local/exim/bin/exim -C /usr/local/exim/etc/configure.out -Mc
> 1Lzvvn-00013W-Of
> 2009-05-01 10:49:51 [4069] 1Lzvvn-00013W-Of => soundwreck@??? F=<
> obscure@???> P=<prvs=03722334aa=obscure@???>
> R=dnslookup_batv T=external_smtp_batv S=857
> H=gmail-smtp-in.l.google.com[209.85.147.27]:25 C="250 2.0.0 OK
> 1241196591 v9si4857027wah.1" QT=4s DT=1s
> 2009-05-01 10:49:51 [4069] 1Lzvvn-00013W-Of Completed QT=4s
>
> thunderbird:
> 2009-05-01 10:51:03 [3958] SMTP connection from [129.24.124.254]:50149
> I=[129.24.125.136]:587 (TCP/IP connection count = 1)
> 2009-05-01 10:51:12 [4073] 1LzvxA-00013h-2e "obscure@???" from
> env-from rewritten as "obscure@???" by submission mode
> 2009-05-01 10:51:12 [4073] 1LzvxA-00013h-2e <= obscure@??? H=
> d00-129-24-124-254.dhcp.unm.edu [129.24.124.254]:50149
> I=[129.24.125.136]:587 P=esmtpsa X=TLSv1:AES256-SHA:256 CV=no
> A=dovecot_plain:obscure S=603 id=49FB2877.7060900@??? T="test
> from thunderbird" from <obscure@???> for soundwreck@???
> 2009-05-01 10:51:12 [4073] SMTP connection from
> d00-129-24-124-254.dhcp.unm.edu [129.24.124.254]:50149
> I=[129.24.125.136]:587 closed by QUIT
> 2009-05-01 10:51:15 [4079] cwd=/var/spool/MailScanner/incoming/4013 5
> args: /usr/local/exim/bin/exim -C /usr/local/exim/etc/configure.out -Mc
> 1LzvxA-00013h-2e
> 2009-05-01 10:51:16 [4079] 1LzvxA-00013h-2e => soundwreck@??? F=<
> obscure@???> P=<prvs=03722334aa=obscure@???>
> R=dnslookup_batv T=external_smtp_batv S=891
> H=gmail-smtp-in.l.google.com[209.85.147.27]:25 C="250 2.0.0 OK
> 1241196676 j15si4817136waf.64" QT=4s
> DT=1s
> 2009-05-01 10:51:16 [4079] 1LzvxA-00013h-2e Completed QT=4s
--
Ian Eiloart
IT Services, University of Sussex
01273-873148 x3148
For new support requests, see
http://www.sussex.ac.uk/its/help/
