# Postfix saslauthd not working - timeout problem [SOLVED]

## epig

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: 

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

smtps    inet  n       -       n       -       -       smtpd

```

test saslauth: 

```

server username # testsaslauthd -u username -p password

0: OK "Success."

```

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

```
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: 

```
# 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: 

```
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: 

```
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: 

```

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

----------

## ianw1974

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/

----------

## epig

Getting closer... 

```
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: 

```
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

```

----------

## epig

I keep chipping away at this... 

After adding the postfix user to the mail group: 

```
gpasswd -a postfix mail
```

and restarting, I now get: 

```

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: 

```
# 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: 

```

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: 

```

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?

----------

## ianw1974

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:

```
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:

```
smtpd_sender_restrictions = permit_sasl_authenticated, reject_unknown_sender_domain, reject_unlisted_sender, warn_if_reject reject_unverified_sender
```

and in master.cf:

```
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.

----------

## epig

 *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:
> 
> ```
> ...

 

This is what was missing in my config. 

when I connect and sen now, here is what I get: 

```
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:

```
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

----------

## epig

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: 

```
-o smtpd_client_restrictions=permit_sasl_authenticated,reject
```

And that makes perfect sense... 

the line now reads: 

```
-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.

----------

## ianw1974

Glad you got it sorted  :Smile: 

----------

