Menu
▾
▴
Re: [Assp-test] Submission with Postfix & ASSP
|
From: Daniel M. <dm...@am...> - 2018-12-16 15:29:56
|
As I don't use Mail.app (but do use Thunderbird and AquaMail on Android) my guess is different client configuration. But a couple possibilities: That shows me ASSP is connecting to Postfix via Postfix's listener on 10026. On 12/16/2018 4:38 AM, James Brown wrote: >> On 15 Dec 2018, at 3:28 am, Daniel Miller <dm...@am... >> <mailto:dm...@am...>> wrote: >> >> Ok - so you have Postfix listening. There's a few different choices >> available to have Postfix forward to ASSP. I would recommend using >> Postfix's before-queue content filter method. >> >> The entries you've setup in master.cf already are for mail that has >> been processed by ASSP and now needs delivery. Again - before >> proceeding further you need to verify things work - clients can >> connect and authenticate and send via your existing >> ASSP/Postfix/Dovecot chain. >> >> Now in master.cf: >> >> 465 inet n - n - 20 smtpd >> -osmtpd_proxy_filter <http://www.postfix.org/postconf.5.html#smtpd_proxy_filter>=127.0.0.1:10025 >> -osmtpd_client_connection_count_limit <http://www.postfix.org/postconf.5.html#smtpd_client_connection_count_limit>=10 >> >> Note the above address/port are arbitrary - pick what you want though >> the localhost address is appropriate given your setup. The >> "smtpd_client_connection_count_limit" may be adjusted as needed. It >> is also up to you whether or not to have additional validation checks >> in this Postfix listener (you should - let Postfix block out whatever >> it can before it touches ASSP otherwise there's not much point in >> this approach). >> >> The "smtpd_proxy_filter" tells Postfix to forward mail to another >> server for processing prior to delivery. So ASSP needs to be >> listening for that connection. You can use the primary listeners >> listenPort, listenPort2, and listenPortSSL but probably a better >> choice is to configure ASSP with: >> >> relayPort=127.0.0.1:10025 >> >> That matches the setting in master.cf above - and that should do it. >> To make it SSL - for the master.cf entry above for 465 add >> >> -o smtpd_tls_wrappermode=yes >> >> and in ASSP make it >> >> relayPort=SSL:127.0.0.1:10025 >> Daniel > > Hi Daniel, thanks again for your help. I’ve been trying to get this > working all weekend. Listening ports: > > $sudo lsof -i :10025 > COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME > perl 68782 root 18u IPv4 0x1117b83fd26dc88b 0t0 TCP > localhost:10025 (LISTEN) > > $ sudo lsof -i :10026 > COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME > master 89692 root 85u IPv4 0x1117b83fdbb9d20b 0t0 TCP > localhost:10026 (LISTEN) > > $ sudo lsof -i :465 > COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME > master 89692 root 102u IPv4 0x1117b83fab73ce8b 0t0 TCP *:urd > (LISTEN) > > If I try to send an email via Thunderbird I get: > > 2018-12-16 23:00:32.330688+1100 0x40dc66 Activity 0x49b2e0 > 72070 0 smtpd: (libsystem_info.dylib) Retrieve User by Name > 2018-12-16 23:00:32.331438+1100 0x40dc66 Activity 0x49b2e1 > 72070 0 smtpd: (libsystem_info.dylib) Retrieve User by Name > 2018-12-16 23:00:32.332155+1100 0x40dc66 Activity 0x49b2e2 > 72070 0 smtpd: (libsystem_info.dylib) Retrieve Group by Name > 2018-12-16 23:00:32.342027+1100 0x40dc66 Activity 0x49b2e3 > 72070 0 smtpd: (libsystem_info.dylib) Resolve user group list > 2018-12-16 23:00:32.344741+1100 0x40dc66 Info 0x0 > 72070 0 smtpd: connect from localhost[127.0.0.1] > 2018-12-16 23:02:08.138177+1100 0x40d37c Info 0x0 > 71932 0 smtpd: disconnect from localhost[127.0.0.1] ehlo=2 > starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7 > 2018-12-16 23:03:43.607388+1100 0x40dc66 Info 0x0 > 72070 0 smtpd: lost connection after UNKNOWN from > localhost[127.0.0.1] > 2018-12-16 23:03:43.607455+1100 0x40dc66 Info 0x0 > 72070 0 smtpd: disconnect from localhost[127.0.0.1] unknown=0/3 > commands=0/3 > > Nothing in mail.log and nothing from ASSP in maillog.txt. I tried with > Microsoft Outlook for Mac and had the same situation. What is the above from if it's not from mail.log? You should increase the log settings in ASSP working through this. Set ConnectionLog to verbose for a start. If that doesn't show activity - next I'd try would be ValidateSenderLog to verbose. > > But using Mail.app again it works perfectly: > > 2018-12-16 22:56:56.338582+1100 0x40d362 Info 0x0 > 71926 0 smtpd: connect from localhost[127.0.0.1] > 2018-12-16 22:56:56.578031+1100 0x40d362 Info 0x0 > 71926 0 smtpd: Anonymous TLS connection established from > localhost[127.0.0.1]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 > (256/256 bits) > 2018-12-16 22:56:56.655063+1100 0x40d378 Default 0x0 > 71931 0 trivial-rewrite: warning: database > /usr/local/etc/postfix/transport.db is older than source file > /usr/local/etc/postfix/transport Probably not the end of the world - but fix the easy stuff first. Looks like your /usr/local/etc/postfix/transport.db needs to be regenerated. > 2018-12-16 22:56:56.761289+1100 0x40d362 Activity 0x49ad34 > 71926 0 smtpd: (libsystem_info.dylib) Retrieve service by name > 2018-12-16 22:56:57.304324+1100 0x40d37c Activity 0x49ad90 > 71932 0 smtpd: (libsystem_info.dylib) Retrieve User by Name > 2018-12-16 22:56:57.305045+1100 0x40d37c Activity 0x49ad91 > 71932 0 smtpd: (libsystem_info.dylib) Retrieve User by Name > 2018-12-16 22:56:57.305746+1100 0x40d37c Activity 0x49ad92 > 71932 0 smtpd: (libsystem_info.dylib) Retrieve Group by Name > 2018-12-16 22:56:57.312412+1100 0x40d37c Activity 0x49ad93 > 71932 0 smtpd: (libsystem_info.dylib) Resolve user group list > 2018-12-16 22:56:57.315379+1100 0x40d37c Info 0x0 > 71932 0 smtpd: connect from localhost[127.0.0.1] > 2018-12-16 22:57:00.488720+1100 0x40d37c Info 0x0 > 71932 0 smtpd: Anonymous TLS connection established from > localhost[127.0.0.1]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 > (128/128 bits) > 2018-12-16 22:57:01.263857+1100 0x40d362 Info 0x0 > 71926 0 smtpd: NOQUEUE: client=localhost[127.0.0.1], > sasl_method=PLAIN, sasl_username=jl...@bo... > <mailto:sasl_username=jl...@bo...> > 2018-12-16 22:57:02.467839+1100 0x40d37c Activity 0x49ad94 > 71932 0 smtpd: (libsystem_info.dylib) Retrieve service by name > 2018-12-16 22:57:02.548724+1100 0x40d37c Info 0x0 > 71932 0 smtpd: 854ED8E602D: client=localhost[127.0.0.1] > 2018-12-16 22:57:06.622777+1100 0x40d3d8 Info 0x0 > 71933 0 cleanup: 854ED8E602D: > message-id=<BF2...@bo... > <mailto:BF2...@bo...>> > 2018-12-16 22:57:06.623801+1100 0x40181f Info 0x0 > 68623 0 qmgr: 854ED8E602D: from=<jl...@bo... > <mailto:jl...@bo...>>, size=1096, nrcpt=1 (queue active) > 2018-12-16 22:57:06.767183+1100 0x40d3eb Info 0x0 > 71936 0 pipe: 854ED8E602D: to=<jl...@bo... > <mailto:jl...@bo...>>, relay=dovecot, delay=5.9, > delays=5.8/0.02/0/0.12, dsn=2.0.0, status=sent (delivered via dovecot > service (lda(jl...@bo... > <mailto:jl...@bo...>,)Error: > net_connect_unix(/usr/local/var/run/dovecot/stats-writer) failed: P)) > 2018-12-16 22:57:06.767634+1100 0x40181f Info 0x0 > 68623 0 qmgr: 854ED8E602D: removed > 2018-12-16 22:57:07.341530+1100 0x40d362 Info 0x0 > 71926 0 smtpd: proxy-accept: END-OF-MESSAGE: 250 2.0.0 Ok: queued > as 854ED8E602D; from=<jl...@bo... > <mailto:jl...@bo...>> to=<jl...@bo... > <mailto:jl...@bo...>> proto=ESMTP helo=<[127.0.0.1]> > sasl_username=<jl...@bo... <mailto:jl...@bo...>> > 2018-12-16 22:58:07.428262+1100 0x40d362 Info 0x0 > 71926 0 smtpd: disconnect from localhost[127.0.0.1] ehlo=2 > starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=8 > > And mail.log shows: > > Dec 16 22:57:06 lda(jl...@bo... > <mailto:jl...@bo...>)<71937><+K2AKZI9FlwBGQEAYBwt+A>: Info: > msgid=<BF2...@bo... > <mailto:BF2...@bo...>>: saved > mail to INBOX Try setting "smtpd_tls_loglevel = 2" in main.cf > > While ASSP shows: > > Dec-16-18 22:56:57 [Worker_1] Info: try to connect to server at > 127.0.0.1:10026 > Dec-16-18 22:56:57 [Worker_1] Info: connected to server at 127.0.0.1:10026 > Dec-16-18 22:56:57 [Worker_1] Connected: session:7FB6906A1160 > 127.0.0.1:63176 > 127.0.0.1:10025 > 127.0.0.1:63178 > 127.0.0.1:10026 > , 21-22 > Dec-16-18 22:56:59 [Worker_1] 127.0.0.1 info: injected '250-STARTTLS' > offer in to EHLO reply > Dec-16-18 22:56:59 [Worker_1] 127.0.0.1 info: send '250-STARTTLS' - > injected for 127.0.0.1 > Dec-16-18 22:56:59 [Worker_1] 127.0.0.1 info: removed '250-STARTTLS' - > it was already injected > Dec-16-18 22:57:00 [Worker_1] 127.0.0.1 info: injected STARTTLS > request to 127.0.0.1 This tells me something is not right. If you used the directives I gave you - connections should be made via SSL and there would be no STARTTLS command issued. So I'm assuming you didn't exactly follow my config lines...or Mail.app isn't connecting to port 465. After you've enabled connection logging in ASSP things might be clearer. > I really don’t know why only Mail.app works. As a Thunderbird user I'm confident it's not a Thunderbird flaw - it's a PEBKAC issue. ;) I have more than a few myself. After enabling more logging, if things don't resolve themselves share your new logs and also a full copy of assp.cfg and the result of "postconf -n". Daniel |
