Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
Postfix saslauthd not working - timeout problem [SOLVED]
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Networking & Security
View previous topic :: View next topic  
Author Message
epig
Tux's lil' helper
Tux's lil' helper


Joined: 16 Feb 2005
Posts: 86

PostPosted: Mon Jul 20, 2015 7:22 pm    Post subject: Postfix saslauthd not working - timeout problem [SOLVED] Reply with quote

Hi

I am trying to set up Postfix with saslauthd towards pam/authdaemon and I have run into a little snag.

Everything seems to work OK:

Set Postfix to smtps since I like to use port 465 for SSL:

Code:
from /etc/postfic/master.cf:

smtps    inet  n       -       n       -       -       smtpd


test saslauth:

Code:

server username # testsaslauthd -u username -p password
0: OK "Success."



Telnet in on port 465 to see what Postfix has to say about it:

Code:
220 mailserver.domain.com ESMTP Postfix (3.0.1)
EHLO domain.com
250-grond.baastad.net
250-PIPELINING
250-SIZE 20480000
250-VRFY
250-ETRN
250-AUTH LOGIN PLAIN
250-AUTH=LOGIN PLAIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
quit
221 2.0.0 Bye


Connection to host lost.


Relevant parts of /etc/postfix/main.cf:
Code:
# Postifx to SASL authentication
broken_sasl_auth_clients = yes
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous
smtpd_sasl_local_domain =
smtpd_sasl_authenticated_header = no
smtpd_recipient_restrictions = permit_sasl_authenticated, permit_mynetworks, reject_unauth_destination


My /etc/sasl2/smtpd.conf looks like this:

Code:
pwcheck_method: authdaemond
mech_list: LOGIN PLAIN
sql_select: dummy
authdaemond_path: /var/lib/courier/authdaemon/socket


and my /etc/conf.d/saslauthd looks like this after removing the commented stuff:

Code:
SASLAUTHD_OPTS="-a pam"


Yet.... When I try to connect and send an e-mail through my mail client I get a time out and the following log entries:
Code:

Jul 20 21:02:45 [postfix/smtpd] connect from customer.isp.com.[111.222.333.444]
Jul 20 21:04:25 [postfix/smtpd] lost connection after UNKNOWN from customer.isp.com.[111.222.333.444]
Jul 20 21:04:25 [postfix/smtpd] disconnect from customer.isp.com.[111.222.333.444]
 unknown=0/3 commands=0/3



So... Is there something obvious I forgot?


Last edited by epig on Sat Jul 25, 2015 11:23 am; edited 1 time in total
Back to top
View user's profile Send private message
ianw1974
Guru
Guru


Joined: 18 Oct 2006
Posts: 387
Location: UK and Poland

PostPosted: Thu Jul 23, 2015 11:00 am    Post subject: Reply with quote

Test with telnet to see more. This article will explain how to use telnet and pass the AUTH LOGIN parameters to login with your user and password

http://community.plus.net/library/email/testing-smtp-authentication-using-telnet/
_________________
Ian Walker

Light travels faster than sound. This is why some people appear bright until you hear them speak.........

Linux Systems Limited | Masternode Monitoring
Back to top
View user's profile Send private message
epig
Tux's lil' helper
Tux's lil' helper


Joined: 16 Feb 2005
Posts: 86

PostPosted: Thu Jul 23, 2015 1:59 pm    Post subject: Reply with quote

Getting closer...

Code:
220 host.domain.com ESMTP Postfix (3.0.1)
ehlo realy
250-host.comain.com
250-PIPELINING
250-SIZE 20480000
250-VRFY
250-ETRN
250-AUTH LOGIN PLAIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
auth login
334 VXNlcm5hbWU6
XXYYXX=334 UGFzc3dvcmQ6
XXYYXXRR=535 5.7.8 Error: authentication failed: generic failure
quit
221 2.0.0 Bye


It seems to me that Postfix does not communicate with saslauthd for some reason.
Hence, the problem should logically reside in the postix config (/etc/postfix/main.cf) somewhere?

EDIT: Updated with log entries:

Code:
Jul 23 16:16:37 [postfix/smtpd] connect from XXX.XXX.XXX.XXX.customer.isp.net[111.222.333.444]
Jul 23 16:16:59 [postfix/smtpd] warning: XXX.XXX.XXX.XXX.customer.isp.net[111.222.333.444]: SASL login authentication failed: generic failure
Jul 23 16:17:05 [postfix/smtpd] disconnect from XXX.XXX.XXX.XXX.customer.isp.net[111.222.333.444] ehlo=1 auth=0/1 quit=1 commands=2/3
Back to top
View user's profile Send private message
epig
Tux's lil' helper
Tux's lil' helper


Joined: 16 Feb 2005
Posts: 86

PostPosted: Thu Jul 23, 2015 6:41 pm    Post subject: Reply with quote

I keep chipping away at this...

After adding the postfix user to the mail group:

Code:
gpasswd -a postfix mail


and restarting, I now get:
Code:

220 host.domain.net ESMTP Postfix (3.0.1)
ehlo relay
250-host.domain.net
250-PIPELINING
250-SIZE 20480000
250-VRFY
250-ETRN
250-AUTH LOGIN PLAIN
250-AUTH=LOGIN PLAIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
auth login
334 VXNlcm5hbWU6
XXXXXX
=334 UGFzc3dvcmQ6
YYYYYYY
235 2.7.0 Authentication successful


So that works now.

However... using port 25 is not an option, nor is it a good idea in m book, so I have to set up TLS to use port 465.

I have made some headway on this, but I still have some way to go.

Rather than making a new thread I will just post it up here...

I generated the certs and whatnon as exlpained in this howto:
https://wiki.gentoo.org/wiki/Complete_Virtual_Mail_Server/SSL_Certificates

And enabled TLS in main.cf:

Code:
# SSL Authentication
smtpd_tls_security_level = may
smtpd_tls_auth_only = yes
smtpd_tls_loglevel = 3
smtpd_tls_key_file = /etc/ssl/postfix/server.key
smtpd_tls_cert_file = /etc/ssl/postfix/grond_server.pem
smtpd_tls_CAfile = /etc/ssl/certs/cacert.org_root.pem
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
tls_random_source = dev:/dev/urandom


Everything looks good from what I can see, but I get a Relay Access Denied:

Code:

Jul 23 20:28:48 [postfix/smtpd] connect from customer.isp.com.[111.222.333.444]
Jul 23 20:28:48 [postfix/smtpd] setting up TLS connection from customer.isp.com.[111.222.333.444]
Jul 23 20:28:48 [postfix/smtpd] customer.isp.com.[111.222.333.444] : TLS cipher list "aNULL:-aNULL:ALL:!EXPORT:!LOW:+RC4:@STRENGTH"
Jul 23 20:28:48 [postfix/smtpd] SSL_accept:before/accept initialization
Jul 23 20:28:48 [postfix/smtpd] read from 039B6540 [039BC300] (11 bytes => 11 (0xB))
Jul 23 20:28:48 [postfix/smtpd] 0000 16 03 01 02 00 01 00 01|fc 03 03                 ........ ...
Jul 23 20:28:48 [postfix/smtpd] read from 039B6540 [039BC30E] (506 bytes => 506 (0x1FA))
Jul 23 20:28:48 [postfix/smtpd] 0000 9b 4f 77 49 39 21 8b f9|1e 72 57 06 2e 3f 78 22  .OwI9!.. .rW..?x"
Jul 23 20:28:48 [postfix/smtpd] 0010 45 11 27 8d e3 3f 1e d0|42 2e a5 68 24 1b 53 55  E.'..?.. B..h$.SU
Jul 23 20:28:48 [postfix/smtpd] 0020 20 d7 cc 7a ef bd 71 9e|92 34 3e fc 5a cf 97 01   ..z..q. .4>.Z...
Jul 23 20:28:48 [postfix/smtpd] 0030 fb bc b1 cf 48 d6 be 79|b6 62 a6 98 10 e0 a2 f5  ....H..y .b......
Jul 23 20:28:48 [postfix/smtpd] 0040 1b 00 16 c0 2b c0 2f c0|0a c0 09 c0 13 c0 14 00  ....+./. ........
Jul 23 20:28:48 [postfix/smtpd] 0050 33 00 39 00 2f 00 35 00|0a 01 00 01 9d 00 00 00  3.9./.5. ........
Jul 23 20:28:48 [postfix/smtpd] 0060 16 00 14 00 00 11 67 72|6f 6e 64 2e 62 61 61 73  ......gr ond.baas
Jul 23 20:28:48 [postfix/smtpd] 0070 74 61 64 2e 6e 65 74 ff|01 00 01 00 00 0a 00 08  tad.net. ........
Jul 23 20:28:48 [postfix/smtpd] 0080 00 06 00 17 00 18 00 19|00 0b 00 02 01 00 00 23  ........ .......#
Jul 23 20:28:48 [postfix/smtpd] 0090 00 c0 c5 9c af 2f c5 1d|2e 29 ca 6c ae 2c b4 17  ...../.. .).l.,..
Jul 23 20:28:48 [postfix/smtpd] 00a0 22 aa 10 f0 33 c4 ce b0|cf 3c b5 70 55 7e 14 36  "...3... .<.pU~.6
Jul 23 20:28:48 [postfix/smtpd] 00b0 c3 1e bd 67 11 54 57 17|66 bb 31 af 42 58 3e c5  ...g.TW. f.1.BX>.
Jul 23 20:28:48 [postfix/smtpd] 00c0 bd a1 33 ec 73 14 78 d6|59 e1 c8 39 85 df e9 60  ..3.s.x. Y..9...`
Jul 23 20:28:48 [postfix/smtpd] 00d0 be c3 86 69 00 d4 a2 f9|77 c3 95 96 b8 63 f0 fb  ...i.... w....c..
Jul 23 20:28:48 [postfix/smtpd] 00e0 6f ee d3 11 cd 12 f5 ae|75 77 70 f2 22 da bd b3  o....... uwp."...
Jul 23 20:28:48 [postfix/smtpd] 00f0 9b 01 d0 6a cb a5 4b 4c|f2 e3 cf 87 db 59 4e 57  ...j..KL .....YNW
Jul 23 20:28:48 [postfix/smtpd] 0100 8e d7 18 74 9a b0 7e 05|3f 68 7e 9e 8a a0 ae 3f  ...t..~. ?h~....?
Jul 23 20:28:48 [postfix/smtpd] 0110 86 af da 50 14 97 1d 97|ed f5 ba b1 0e 3d f2 78  ...P.... .....=.x
Jul 23 20:28:48 [postfix/smtpd] 0120 a9 21 3b 18 5d 8f 09 c8|ca 25 10 f4 fe 19 9e 71  .!;.]... .%.....q
Jul 23 20:28:48 [postfix/smtpd] 0130 e0 43 9e 6b 34 3b dc 3a|85 76 8c 69 e8 cf 2d bc  .C.k4;.: .v.i..-.
Jul 23 20:28:48 [postfix/smtpd] 0140 85 62 79 a2 9a f9 c8 41|4d af cc 38 d9 1a 79 1a  .by....A M..8..y.
Jul 23 20:28:48 [postfix/smtpd] 0150 3a 10 00 05 00 05 01 00|00 00 00 00 0d 00 16 00  :....... ........
Jul 23 20:28:48 [postfix/smtpd] 0160 14 04 01 05 01 06 01 02|01 04 03 05 03 06 03 02  ........ ........
Jul 23 20:28:48 [postfix/smtpd] 0170 03 04 02 02 02 00 15 00|81                       ........ .
Jul 23 20:28:48 [postfix/smtpd] 0179 - <SPACES/NULLS>
Jul 23 20:28:48 [postfix/smtpd] customer.isp.com.[111.222.333.444] : Decrypting session ticket, key expiration: 1437677864
Jul 23 20:28:48 [postfix/smtpd] SSL_accept:SSLv3 read client hello A
Jul 23 20:28:48 [postfix/smtpd] SSL_accept:SSLv3 write server hello A
Jul 23 20:28:48 [postfix/smtpd] SSL_accept:SSLv3 write change cipher spec A
Jul 23 20:28:48 [postfix/smtpd] SSL_accept:SSLv3 write finished A
Jul 23 20:28:48 [postfix/smtpd] write to 039B6540 [039AC400] (137 bytes => 137 (0x89))
Jul 23 20:28:48 [postfix/smtpd] 0000 16 03 03 00 51 02 00 00|4d 03 03 a1 9d bd 4d f1  ....Q... M.....M.
Jul 23 20:28:48 [postfix/smtpd] 0010 0f 70 71 88 1f eb cb f5|dd 1f 31 39 4a 22 4e 3a  .pq..... ..19J"N:
Jul 23 20:28:48 [postfix/smtpd] 0020 c8 00 3e b5 9b a6 98 c0|c0 06 22 20 d7 cc 7a ef  ..>..... .." ..z.
Jul 23 20:28:48 [postfix/smtpd] 0030 bd 71 9e 92 34 3e fc 5a|cf 97 01 fb bc b1 cf 48  .q..4>.Z .......H
Jul 23 20:28:48 [postfix/smtpd] 0040 d6 be 79 b6 62 a6 98 10|e0 a2 f5 1b c0 2f 00 00  ..y.b... ...../..
Jul 23 20:28:48 [postfix/smtpd] 0050 05 ff 01 00 01 00 14 03|03 00 01 01 16 03 03 00  ........ ........
Jul 23 20:28:48 [postfix/smtpd] 0060 28 3a 83 3e 46 a9 34 9b|1b 26 0c 67 58 2c f1 6f  (:.>F.4. .&.gX,.o
Jul 23 20:28:48 [postfix/smtpd] 0070 dc 84 c8 16 38 ea 68 e1|d9 cd ac bc 06 b6 16 d1  ....8.h. ........
Jul 23 20:28:48 [postfix/smtpd] 0080 7a 74 4b 2a c6 18 bd 7f|30                       ztK*.... 0
Jul 23 20:28:48 [postfix/smtpd] SSL_accept:SSLv3 flush data
Jul 23 20:28:48 [postfix/smtpd] read from 039B6540 [039BC303] (5 bytes => -1 (0xFFFFFFFFFFFFFFFF))
Jul 23 20:28:48 [postfix/smtpd] read from 039B6540 [039BC303] (5 bytes => 5 (0x5))
Jul 23 20:28:48 [postfix/smtpd] 0000 14 03 03 00 01                                   .....
Jul 23 20:28:48 [postfix/smtpd] read from 039B6540 [039BC308] (1 bytes => 1 (0x1))
Jul 23 20:28:48 [postfix/smtpd] 0000 01                                               .
Jul 23 20:28:48 [postfix/smtpd] read from 039B6540 [039BC303] (5 bytes => 5 (0x5))
Jul 23 20:28:48 [postfix/smtpd] 0000 16 03 03 00 28                                   ....(
Jul 23 20:28:48 [postfix/smtpd] read from 039B6540 [039BC308] (40 bytes => 40 (0x28))
Jul 23 20:28:48 [postfix/smtpd] 0000 00 00 00 00 00 00 00 00|55 7c 84 b8 20 12 2f 39  ........ U|.. ./9
Jul 23 20:28:48 [postfix/smtpd] 0010 a6 8f ee a6 f3 41 26 08|f0 ba a4 e8 c5 29 d0 8e  .....A&. .....)..
Jul 23 20:28:48 [postfix/smtpd] 0020 1a 3d a9 f0 17 da a1 f1|                         .=......
Jul 23 20:28:48 [postfix/smtpd] SSL_accept:SSLv3 read finished A
Jul 23 20:28:48 [postfix/smtpd] customer.isp.com.[111.222.333.444] : Reusing old session (RFC 5077 session ticket)
Jul 23 20:28:48 [postfix/smtpd] Anonymous TLS connection established from customer.isp.com.[111.222.333.444] : TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
Jul 23 20:28:48 [postfix/smtpd] B81AB202D41: client=customer.isp.com.[111.222.333.444] , sasl_method=PLAIN, sasl_username=username
Jul 23 20:28:48 [postfix/smtpd] B81AB202D41: reject: RCPT from customer.isp.com.[111.222.333.444] : 554 5.7.1 <user@gmail.com>: Relay access denied; from=<user@domain.net> to=<user@gmail.com> proto=ESMTP helo=<[192.168.0.11]>


My Thunderbird client throws this error:

Code:

An error occurred while sending mail. The mail server responded: 
5.7.1 <user@gmail.com>: Relay access denied.
 Please check the message recipient "user@gmail.com" and try again


Any ideas?
Back to top
View user's profile Send private message
ianw1974
Guru
Guru


Joined: 18 Oct 2006
Posts: 387
Location: UK and Poland

PostPosted: Fri Jul 24, 2015 7:22 pm    Post subject: Reply with quote

When you used telnet to test it did you put the full email address then? Or just the username without the @mydomain.com or whatever? Check and verify this with your Thunderbird config.

My config looks like this:

Code:
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous
broken_sasl_auth_clients = yes
smtpd_sasl_local_domain =
smtpd_use_tls = yes
smtpd_tls_key_file = /etc/postfix/key.pem
smtpd_tls_cert_file = /etc/postfix/cert.pem
smtpd_tls_CAfile = /etc/postfix/cacert.pem
smtpd_tls_loglevel = 3
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
tls_preempt_cipherlist = yes
tls_random_source = dev:/dev/urandom


in main.cf I also have this:

Code:
smtpd_sender_restrictions = permit_sasl_authenticated, reject_unknown_sender_domain, reject_unlisted_sender, warn_if_reject reject_unverified_sender


and in master.cf:

Code:
smtps     inet  n       -       -       -       -       smtpd


if you are using port 25 with TLS enabled, this is also fine to use, as a TLS connection on port 25 is also encrypted. That should be enough to get it working. If you are still getting problems with sending, this isn't to do with you logging in but rather the rest of your config for accepting and relaying the message is the problem and hence the error in your logs about relay access denied. Something else is interrupting the process. Without seeing the full config and knowing a bit more about the setup, it will be hard for me to help you further as I don't know what the rest of your config settings are and the corresponding order of sender restrictions or recipient restrictions.

I have both TLS on port 25 and SMTPS on 465.

One more thing, check Thunderbird config, because from what I remember ages ago when I use it, it will generally send on the first configured account if you have multiple accounts, so check/verify that if you have multiple email accounts, that each one uses the corresponding mail server config for sending, rather than a global one. There is a way to select for each account, which server to use for sending. Just to make sure it's not passing the wrong username/password.
_________________
Ian Walker

Light travels faster than sound. This is why some people appear bright until you hear them speak.........

Linux Systems Limited | Masternode Monitoring
Back to top
View user's profile Send private message
epig
Tux's lil' helper
Tux's lil' helper


Joined: 16 Feb 2005
Posts: 86

PostPosted: Sat Jul 25, 2015 11:13 am    Post subject: Reply with quote

ianw1974 wrote:
When you used telnet to test it did you put the full email address then? Or just the username without the @mydomain.com or whatever? Check and verify this with your Thunderbird config.


Just user name. Both sides.
ianw1974 wrote:

in main.cf I also have this:

Code:
smtpd_sender_restrictions = permit_sasl_authenticated, reject_unknown_sender_domain, reject_unlisted_sender, warn_if_reject reject_unverified_sender




This is what was missing in my config.
when I connect and sen now, here is what I get:
Code:
Jul 25 13:00:44 [postfix/smtpd] Anonymous TLS connection established from customer.isp.com.[111.222.333.444]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
Jul 25 13:00:44 [postfix/smtpd] D434B20191A: client=customer.isp.com.[111.222.333.444], sasl_method=PLAIN, sasl_username=username


so that works just fine.
ianw1974 wrote:

I have both TLS on port 25 and SMTPS on 465.


As do I, nut using port 25 isn't an option since my ISP seems to be blocking that. But 465 works fine now.

However, I also run amavisd-new spam filtering which, in the next step, rejects my e-mail:

Code:
Jul 25 13:00:45 [postfix/smtpd] connect from localhost[127.0.0.1]
Jul 25 13:00:45 [postfix/smtpd] NOQUEUE: reject: RCPT from localhost[127.0.0.1]: 554 5.7.1 <localhost[127.0.0.1]>: Client host rejected: Access denied; from=<user@domain.net> to=<user@gmail.com> proto=ESMTP helo=<localhost>
Jul 25 13:00:45 [amavis] (17256-17) smtp resp to RCPT (pip) (<user@gmail.com>): 554 5.7.1 <localhost[127.0.0.1]>: Client host rejected: Access denied
Jul 25 13:00:45 [amavis] (17256-17) Negative SMTP resp. to DATA: 554 5.5.1 Error: no valid recipients
Jul 25 13:00:45 [postfix/smtpd] disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=0/1 data=0/1 rset=1 quit=1 commands=4/6
Jul 25 13:00:45 [amavis] (17256-17) (!)FWD from <user@domain.net> -> <user@gmail.com>,BODY=7BIT 554 5.7.1 from MTA(smtp:[127.0.0.1]:10025): 554 5.7.1 <localhost[127.0.0.1]>: Client host rejected: Access denied
Jul 25 13:00:45 [amavis] (17256-17) Blocked MTA-BLOCKED {RejectedOpenRelay}, [111.222.333.444] [111.222.333.444] <user@domain.net> -> <user@gmail.com>, Message-ID: <55B36C5D.7000002@baastad.net>, mail_id: 7IGVMNnL3rxW, Hits: -0.199, size: 3916, 536 ms



But thank you for the help. I will keep chipping away at this and make an amavis thread later if needed.


Last edited by epig on Sat Jul 25, 2015 6:56 pm; edited 1 time in total
Back to top
View user's profile Send private message
epig
Tux's lil' helper
Tux's lil' helper


Joined: 16 Feb 2005
Posts: 86

PostPosted: Sat Jul 25, 2015 5:22 pm    Post subject: Reply with quote

I found the problem.

As I read logs and tried to wrap my head around what was wrong I noticed that all incoming mail was rejected as well.

From what I can tell it was this line in master.cf that caused the problem:

Code:
-o smtpd_client_restrictions=permit_sasl_authenticated,reject


And that makes perfect sense...

the line now reads:

Code:
-o smtpd_client_restrictions=
as the imposed restrictions are located in main.cf.

Mail is now relayed from localhost after the user has initially authenticated to Postfix, and only for authenticated users.
Tested and tried with incorrect usernames/passwords and so on, and this seems to be working as intended.

Again, thanks for the help, I don't think I would have been able to figure this one out on my own.
Back to top
View user's profile Send private message
ianw1974
Guru
Guru


Joined: 18 Oct 2006
Posts: 387
Location: UK and Poland

PostPosted: Sat Jul 25, 2015 5:42 pm    Post subject: Reply with quote

Glad you got it sorted :)
_________________
Ian Walker

Light travels faster than sound. This is why some people appear bright until you hear them speak.........

Linux Systems Limited | Masternode Monitoring
Back to top
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Networking & Security All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum