# [SOLVED]postfix/dovecot: auth process broken/no worthy mechs

## chaoscommander

I've tried to get a mailserver to run on my Gentoo box I intend to use as a server for everything I don't want to trust the cloud with anymore, but I can't manage. I read just about every instruction manual or how-to guide I found, restarted from scratch twice and still I end up stuck.

Guide I followed at the last try: https://wiki.archlinux.org/index.php/Simple_Virtual_User_Mail_System

Outcome: Postfix is running, Dovecot is running. I can set up accounts with PostfixAdmin and mail sent to the server is received, I can read it locally on the server using a text editor.

What doesn't work: SMTP outgoing, POP3, IMAP. Trying to connect with Thunderbird I get "wrong password". Trying telnet on POP3 or IMAP yields the reply "Auth process broken" and a forced disconnect before I could even HELO. I have subscribed to a relay server for outgoing mail because I'm on a dynamic IP, I've set up the box to authenticate itself to the relay with the proper credentials (retried that several times following different guides all apparently correct, judging from people positively commenting on them), but the relay always says "nope, you need to auth" - I guess that's related to the errors above.

I've been googling around for solutions but couldn't find any that worked, so I'm officially giving up before I flip the table.

If any of you have knowledge, time to spare and a bit of patience with a noob who used to think he wasn't a noob until this started, I'd really appreciate it.

Now, I'm sure you need config files, log files etc., but since all those non-helpful guides left me utterly confused, I have no idea where to start. So.. tell me what you need and I'll happily provide.Last edited by chaoscommander on Thu Mar 20, 2014 8:01 pm; edited 1 time in total

----------

## hydrapolic

Try to make your log files more verbose, perhaps also set the debug parameters.

Can you please show the output of

# dovecot -n

And also what you have in you log files after you set everything to debug and verbose mode.

----------

## chaoscommander

output of dovecot -n:

```
# 2.2.9: /etc/dovecot/dovecot.conf

doveconf: Warning: NOTE: You can get a new clean config file with: doveconf -n > dovecot-new.conf

doveconf: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:104: add auth_ prefix to all settings inside auth {} and remove the auth {} section completely

doveconf: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:106: passdb sql {} has been replaced by passdb { driver=sql }

doveconf: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:109: userdb prefetch {} has been replaced by userdb { driver=prefetch }

doveconf: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:111: auth_user has been replaced by service auth { user }

# OS: Linux 3.10.17-gentoo x86_64 Gentoo Base System release 2.2 

auth_mechanisms = plain login

listen = *, [::]

login_greeting = blah

mail_home = /home/vmail/%d/%u

mail_location = maildir:~

namespace inbox {

  inbox = yes

  location = 

  mailbox Drafts {

    special_use = \Drafts

  }

  mailbox Junk {

    special_use = \Junk

  }

  mailbox Sent {

    special_use = \Sent

  }

  mailbox "Sent Messages" {

    special_use = \Sent

  }

  mailbox Trash {

    special_use = \Trash

  }

  prefix = 

}

passdb {

  args = *

  driver = pam

}

passdb {

  args = /etc/dovecot/dovecot-sql.conf.ext

  driver = sql

}

passdb {

  args = /etc/dovecot/dovecot-sql.conf

  driver = sql

}

protocols = imap pop3

service auth {

  unix_listener /var/spool/postfix/private/auth {

    group = postfix

    mode = 0660

    user = postfix

  }

  unix_listener auth-master {

    group = mail

    mode = 0600

    user = mail

  }

  unix_listener auth-userdb {

    group = postfix

    user = postfix

  }

  user = nobody

}

ssl_cert = </etc/dovecot/server.pem

ssl_key = </etc/dovecot/private/server.key

userdb {

  driver = passwd

}

userdb {

  args = /etc/dovecot/dovecot-sql.conf.ext

  driver = sql

}

userdb {

  driver = prefetch

}

```

```
 19 11:07:06 postfix/smtp[3242]: warning: SASL authentication failure: No worthy mechs found

Mar 19 11:07:06 postfix/smtp[3242]: 478D4EE1F57: SASL authentication failed; cannot authenticate to server smtp-relay.tld [IP]: no mechanism available

```

Trying stuff..

```
telnet localhost 143

Trying ::1...

Connected to localhost.

Escape character is '^]'.

* BYE Disconnected: Auth process broken

Connection closed by foreign host.

telnet localhost 110

Trying ::1...

Connected to localhost.

Escape character is '^]'.

-ERR Disconnected: Auth process broken

Connection closed by foreign host.

```

SMTP works, as stated above.

Logs:

```
Mar 19 11:17:47 dovecot: auth: Fatal: sql /etc/dovecot/dovecot-sql.conf: Can't open configuration file /etc/dovecot/dovecot-sql.conf: No such file or directory
```

Oh.. wait.. checking where that vanished to.. *facepalm*

Err, okay. Now at least the auth process isn't broken anymore. But I still can't connect to my SMTP relay:

```
 19 11:07:06 postfix/smtp[3242]: warning: SASL authentication failure: No worthy mechs found

Mar 19 11:07:06 postfix/smtp[3242]: 478D4EE1F57: SASL authentication failed; cannot authenticate to server smtp-relay.tld [IP]: no mechanism available

```

I also can't login with Thunderbird:

```
Mar 19 12:00:33 postfix/smtpd[6906]: initializing the server-side TLS engine

Mar 19 12:00:33 dovecot: imap-login: Aborted login (no auth attempts in 0 secs): user=<>, rip=192.168.0.1 [router], lip=192.168.0.101 [client], session=<j9vIj/P0RQDAqAAB>

Mar 19 12:00:33 postfix/smtpd[6906]: connect from router[192.168.0.1]

Mar 19 12:00:33 postfix/smtpd[6906]: disconnect from router[192.168.0.1]

Mar 19 12:02:02 dovecot: auth: Error: PLAIN(alias,192.168.0.1,<lettermuddle1>): Request 6859.1 timed out after 150 secs, state=1

Mar 19 12:02:32 dovecot: imap-login: Disconnected: Inactivity during authentication (disconnected while authenticating, waited 180 secs): user=<>, method=PLAIN, rip=192.168.0.1, lip=192.168.0.101, TLS, session=<lettermuddle1>

Mar 19 12:03:16 dovecot: auth: Error: PLAIN(alias@mydomain.tld,192.168.0.1,<lettermuddle2>): Request 6909.1 timed out after 150 secs, state=1
```

Any pointers, please?  :Smile: 

----------

## hydrapolic

For what reason you have the SQL passdb twice?

```

passdb {

  args = /etc/dovecot/dovecot-sql.conf.ext

  driver = sql

}

passdb {

  args = /etc/dovecot/dovecot-sql.conf

  driver = sql

} 

```

Please post the content of those files. Also, please post the output of `postconf -n` and `emerge --info postfix dovecot`.

----------

## chaoscommander

edit: I edited identifying info in all conf files etc. posted here, of course where it says "mydomain.tld" and such I put in my real domain.

 *hydrapolic wrote:*   

> For what reason you have the SQL passdb twice?

 

I honestly don't remember which tutorial told me to add and modify what and why. Not unlikely that confusion will turn out to be the cause of the issue. Ok, let's see..

the only lines not commented out in /etc/dovecot/dovecot-sql.conf.ext:

```

driver = mysql

connect = host=/var/run/mysql.sock user=postfix_user password=[...] dbname=postfix_db

default_pass_scheme = MD5-CRYPT

password_query = SELECT username as user, password, '/home/vmail/%d/%u' as userdb_home, 'maildir:/home/vmail/%d/%u' as userdb_mail, 5000 as userdb_uid, 5000 as userdb_gid FROM mailbox WHERE username = '%u' AND active = '1'

user_query = SELECT '/home/vmail/%d/%u' as home, 'maildir:/home/vmail/%d/%u' as mail, 5000 AS uid, 5000 AS gid, concat('dirsize:storage=', quota) AS quota FROM mailbox WHERE username = '%u' AND active = '1'

password_query = SELECT CONCAT('/var/mail/', maildir) AS userdb_home, username as user, password, CONCAT('*:bytes=', quota) 

AS quota_rule FROM mailbox WHERE username = '%u' AND active = 1

```

/etc/dovecot/dovecot-sql.conf:

```

driver = mysql

connect = host=localhost dbname=postfix_db user=postfix_user password=[...]

# The new name for MD5 is MD5-CRYPT so you might need to change this depending on version

default_pass_scheme = MD5-CRYPT

# Get the mailbox

user_query = SELECT '/home/vmail/%d/%u' as home, 'maildir:/home/vmail/%d/%u' as mail, 5000 AS uid, 5000 AS gid, concat('dirsize:storage=',  quota) AS quota FROM mailbox W$

# Get the password

password_query = SELECT username as user, password, '/home/vmail/%d/%u' as userdb_home, 'maildir:/home/vmail/%d/%u' as userdb_mail, 5000 as  userdb_uid, 5000 as userdb_gi$

# If using client certificates for authentication, comment the above and uncomment the following

#password_query = SELECT null AS password, ‘%u’ AS user

```

You're right, this seems at least partly redundant, which one should I use? Damn, this is a little embarassing  :Razz: 

postconf -n:

```

broken_sasl_auth_clients = yes                                                                                                                                              

command_directory = /usr/sbin                                                                                                                                               

config_directory = /etc/postfix                                                                                                                                             

daemon_directory = /usr/libexec/postfix                                                                                                                                     

data_directory = /var/lib/postfix                                                                                                                                           

debug_peer_level = 2

debug_peer_list = 192.168.0.100

debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5

default_destination_concurrency_limit = 10

home_mailbox = .maildir/

html_directory = no

inet_interfaces = all

inet_protocols = ipv4

local_destination_concurrency_limit = 2

local_recipient_maps = $virtual_mailbox_maps

local_transport = virtual

mail_owner = postfix

mailq_path = /usr/bin/mailq

manpage_directory = /usr/share/man

mydestination = mydomain.tld, localhost.mydomain.tld, localhost

mydomain = mydomain.tld

myhostname = mydomain.tld

mynetworks = 192.168.0.0/24, 127.0.0.0/8

newaliases_path = /usr/bin/newaliases

queue_directory = /var/spool/postfix

readme_directory = no

relayhost = smtp-relay.tld

sample_directory = /etc/postfix

sendmail_path = /usr/sbin/sendmail

setgid_group = postdrop

smtp_sasl_auth_enable = yes

smtp_sasl_password_maps = hash:/etc/postfix/saslpass

smtp_tls_note_starttls_offer = yes

smtp_use_tls = yes

smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination

smtpd_relay_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination

smtpd_sasl_local_domain = $mydomain

smtpd_sasl_path = /var/run/dovecot/auth-client

smtpd_sasl_security_options = noanonymous

smtpd_sasl_tls_security_options = $smtpd_sasl_security_options

smtpd_sasl_type = dovecot

smtpd_tls_CAfile = /etc/postfix/cacert.pem

smtpd_tls_auth_only = yes

smtpd_tls_cert_file = /etc/postfix/newcert.pem

smtpd_tls_key_file = /etc/postfix/newkey.pem

smtpd_tls_loglevel = 3

smtpd_tls_received_header = yes

smtpd_tls_session_cache_timeout = 3600s

smtpd_use_tls = yes

tls_random_source = dev:/dev/random

unknown_local_recipient_reject_code = 550

virtual_alias_maps = proxy:mysql:/etc/postfix/virtual_alias_maps.cf

virtual_gid_maps = static:5000

virtual_mailbox_base = /home/vmail

virtual_mailbox_domains = proxy:mysql:/etc/postfix/virtual_domains_maps.cf

virtual_mailbox_limit = 512000000

virtual_mailbox_maps = proxy:mysql:/etc/postfix/virtual_mailbox_maps.cf

virtual_minimum_uid = 5000

virtual_transport = virtual

virtual_uid_maps = static:5000

postconf: warning: /etc/postfix/main.cf: unused parameter: smtpd_sasl2_auth_enable=yes
```

emerge --info postfix dovecot:

```

Portage 2.2.8-r1 (hardened/linux/amd64, gcc-4.7.3, glibc-2.17, 3.10.17-gentoo x86_64)

=================================================================

                         System Settings

=================================================================

System uname: Linux-3.10.17-gentoo-x86_64-Intel-R-_Atom-TM-_CPU_330_@_1.60GHz-with-gentoo-2.2

KiB Mem:     1792212 total,   1537936 free

KiB Swap:    2097148 total,   2097148 free

Timestamp of tree: Mon, 17 Mar 2014 20:30:01 +0000

ld GNU ld (GNU Binutils) 2.23.2

distcc 3.1 x86_64-pc-linux-gnu [disabled]

app-shells/bash:          4.2_p45

dev-lang/python:          2.7.5-r3, 3.3.3

dev-util/cmake:           2.8.11.2

dev-util/pkgconfig:       0.28

sys-apps/baselayout:      2.2

sys-apps/openrc:          0.12.4

sys-apps/sandbox:         2.6-r1

sys-devel/autoconf:       2.13, 2.69

sys-devel/automake:       1.11.6, 1.12.6, 1.13.4

sys-devel/binutils:       2.23.2

sys-devel/gcc:            4.7.3-r1

sys-devel/gcc-config:     1.7.3

sys-devel/libtool:        2.4.2

sys-devel/make:           3.82-r4

sys-kernel/linux-headers: 3.9 (virtual/os-headers)

sys-libs/glibc:           2.17

Repositories: gentoo

ACCEPT_KEYWORDS="amd64"

ACCEPT_LICENSE="*"

CBUILD="x86_64-pc-linux-gnu"

CFLAGS="-march=core2 -O2 -pipe"

CHOST="x86_64-pc-linux-gnu"

CONFIG_PROTECT="/etc"

CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php5.5/ext-active/ /etc/php/cgi-php5.5/ext-active/ /etc/php/cli-php5.5/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo"

CXXFLAGS="-march=core2 -O2 -pipe"

DISTDIR="/usr/portage/distfiles"

FCFLAGS="-O2 -pipe"

FEATURES="assume-digests binpkg-logs candy config-protect-if-modified distlocks ebuild-locks fixlafiles merge-sync news parallel-fetch preserve-libs protect-owned sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync xattr"

FFLAGS="-O2 -pipe"

GENTOO_MIRRORS="http://de-mirror.org/gentoo/"

LANG="de_DE.UTF-8"

LDFLAGS="-Wl,-O1 -Wl,--as-needed"

MAKEOPTS="-j5"

PKGDIR="/usr/portage/packages"

PORTAGE_CONFIGROOT="/"

PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages"

PORTAGE_TMPDIR="/var/tmp"

PORTDIR="/usr/portage"

PORTDIR_OVERLAY=""

USE="aac acl acpi alsa amd64 apache2 berkdb branding bzip2 cdda cdr cli cracklib crypt css cxx dbus dri dvd dvdr ftp gdbm hardened iconv icu ipv6 justify mmx modules mtp multilib ncurses nls nptl openmp pam pax_kernel pcre readline session sse sse2 ssl symlink tcpd unicode urandom vcd xcb xft xtpax zlib" ABI_X86="64" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" APACHE2_MODULES="authn_core authz_core socache_shmcb unixd actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" CALLIGRA_FEATURES="kexi words flow plan sheets stage tables krita karbon braindump author" CAMERAS="ptp2" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" LINGUAS="de" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php5-5" PYTHON_SINGLE_TARGET="python2_7" PYTHON_TARGETS="python2_7 python3_3" RUBY_TARGETS="ruby19 ruby20" USERLAND="GNU" VIDEO_CARDS="vesa fbdev" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account"

Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LC_ALL, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, SYNC, USE_PYTHON

=================================================================

                        Package Settings

=================================================================

mail-mta/postfix-2.10.2 was built with the following:

USE="berkdb dovecot-sasl hardened mysql pam sasl ssl -cdb -doc -ldap -ldap-bind -mbox -memcached -nis -postgres (-selinux) -sqlite -vda"

CFLAGS="-march=core2 -O2 -pipe -Wno-comment"

CXXFLAGS="-march=core2 -O2 -pipe -Wno-comment"

net-mail/dovecot-2.2.9 was built with the following:

USE="bzip2 ipv6 maildir mysql pam ssl tcpd zlib -caps -cydir -doc -imapc -kerberos -ldap -lucene -managesieve -mbox -mdbox -pop3c -postgres -sdbox (-selinux) -sieve -solr -sqlite -static-libs -suid -vpopmail"
```

----------

## chaoscommander

Since I'm not that sleepy yet I decided to poke around a bit. I found the place where dovecot-sql.conf.ext is pulled in and commented it out since it appears to be completely useless, at least how I set it up. Then I crawled through the log and found I apparently also had this problem: http://www.techques.com/question/2-297960/Dovecot:-auth-sockets-permissions

I applied the proposed fix and the error that "nobody" couldn't run auth_worker has stopped occuring.

I still can't log in, but the error looks different now:

```
Mar 20 01:05:52 dovecot: imap(alias@mydomain.tld): Error: user alias@mydomain.tld: Couldn't drop privileges: User is missing UID (see mail_uid setting)
```

Ok. Went to /etc/dovecot/conf.d/10-mail.conf and set mail_uid and mail_gid to "vmail".

And IMAP now works! \o/  :Very Happy:   Mail doesn't arrive in Thunderbird yet, apparently I still gotta figure out how to make postfix put stuff into the vmail directory instead of /home/user/.mailbox/.

The other remaining problem is that I can't auth to my SMTP relay because of "no worthy mechs".

Sleep for now. If anyone wants to drop a hint, as always I'll be happy, otherwise I'll continue digging tomorrow.

----------

## chaoscommander

I shall update you!

I know these are more or less "obvious" errors, but seeing how long it took me to find out, maybe someone who googles around for these will find this thread useful.

Postfix delivered incoming mail to /home/username/.mailbox because it was set to do so in main.cf. If you want mail to be delivered to a vmail directory, change it like so:

```
# DELIVERY TO MAILBOX

#

# The home_mailbox parameter specifies the optional pathname of a

# mailbox file relative to a user's home directory. The default

# mailbox file is /var/spool/mail/user or /var/mail/user.  Specify

# "Maildir/" for qmail-style delivery (the / is required).

#

#home_mailbox = Mailbox

#home_mailbox = .maildir/

# The mail_spool_directory parameter specifies the directory where

# UNIX-style mailboxes are kept. The default setting depends on the

# system type.

#

mail_spool_directory = /home/vmail/

#mail_spool_directory = /var/spool/mail
```

Afterwards I noticed that dovecot was looking for my mails in /home/vmail/alias@mydomain.tld while postfix was delivering them to /home/vmail/alias/. fixed the empty inbox by editing /etc/dovecot/conf.d/10-mail.conf so dovecot would look for my mail in the right place:

```

old:

mail_home = /home/vmail/%d/%u

new:

mail_home = /home/vmail/%d/%n

```

Now I can finally see all those non-delivery notifications! #notsureifyay

Okay, for the last one: outgoing SMTP auth failure.

I'm trying to implement this: http://www.postfix.org/SASL_README.html#client_sasl_policy

Nope, doesn't work.

----------

## nativemad

Hi, 

I would just hook postfix to dovecot for smtp-auth...

http://wiki2.dovecot.org/HowTo/PostfixAndDovecotSASL

main.cf:

```

smtpd_sasl_auth_enable = yes 

smtpd_sasl2_auth_enable = yes 

smtpd_sasl_type = dovecot

smtpd_sasl_path = private/auth

smtpd_sasl_security_options = noanonymous 

smtpd_sasl_local_domain = domain.ltd

broken_sasl_auth_clients = yes
```

dovecot.conf:

```
service auth {

  unix_listener /var/spool/postfix/private/auth {

    group = postfix

    mode = 0660

    user = postfix

  }

  user = vmail

}
```

HTH, Cheers

----------

## chaoscommander

I already was using dovecot for this, but with smtpd_sasl_path = /run/dovecot/auth-worker.

Oh great! I tried private/auth which didn't work either, reset everything to how it was before (or so I think), and now IMAP is out of order again.

```
Mar 20 15:18:24 dovecot: imap-login: Disconnected (no auth attempts in 1 secs): user=<>, rip=192.168.0.1, lip=192.168.0.101, TLS: SSL_read() failed: error:14094418:SSL routines:SSL3_READ_BYTES:tlsv1 alert unknown ca: SSL alert number 48, session=<iUEtcQr18ADAqAAB>
```

Last edited by chaoscommander on Thu Mar 20, 2014 2:29 pm; edited 2 times in total

----------

## nativemad

ok, but that failure now looks like an ssl config failure! Check dovecots ssl_cert and ssl_key options.

What error messages do you get if you try to auth through smtp?

----------

## chaoscommander

Thunderbird says: The server doesn't support the chosen auth mechanism. Sounds familliar.

How could this suddenly turn into a SSL problem? I didn't touch the SSL certs or anything.

Edit: Ah, that's why you ask. No, it's just that Thunderbird complains about the unknown CA because the certs are self-signed. I think.

----------

## chaoscommander

Ok, no, that last log entry was unrelated, see above. This is the problem:

```
Mar 20 15:32:02 dovecot: auth: Error: net_connect_unix(auth-worker) in directory /run/dovecot failed: Permission denied (euid=65534(nobody) egid=65534(nobody) missing +r perm: /run/dovecot/auth-worker, dir owned by 0:0 mode=0755)
```

Which is funny because I didn't change any permissions..

----------

## nativemad

my /run/dovecot/auth-worker looks like this: -This should really be the default...

srw------- 1 dovecot root       0 Jan 21 11:06 /run/dovecot/auth-worker

But my private/auth folder looks like that:

srw-rw---- 1 postfix postfix 0 Jan 21 11:06 /var/spool/postfix/private/auth

The error means that not even dovecot is able to use it's socket right now!

I'd chown that to dovecot:postfix... and  chmod it so that also the postfix group has read/write (140660).

----------

## chaoscommander

My files look the same as yours.

I tried chown/chmod like you proposed anyway, but I suppose they don't do anything. Indeed - nothing changed and the error remains.

----------

## nativemad

But you restarted the service right!?   :Rolling Eyes: 

Can you show the whole dovecot-startup-logs as well as a try via imap or pop?

Also the postfix logs for an auth attempt would be interesting.

----------

## chaoscommander

 *nativemad wrote:*   

> But you restarted the service right!?   

 

Of course I did!

 *Quote:*   

> Can you show the whole dovecot-startup-logs as well as a try via imap or pop?
> 
> Also the postfix logs for an auth attempt would be interesting.

 

Disclaimer: I know about these warnings. I assumed they are just because I used old manuals and that they have nothing to do with what's wrong. So I focused on fixing errors and malfunctions first. If I'm wrong about this, please correct me.

dovecot startup

```

Mar 20 16:36:20  dovecot: master: Dovecot v2.2.9 starting up (core dumps disabled)

Mar 20 16:36:21  dovecot: config: Warning: NOTE: You can get a new clean config file with: doveconf -n > dovecot-new.conf

Mar 20 16:36:21  dovecot: config: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:104: add auth_ prefix to all settings inside auth {} and remove the auth {} section completely

Mar 20 16:36:21  dovecot: config: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:106: passdb sql {} has been replaced by passdb { driver=sql }

Mar 20 16:36:21  dovecot: config: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:109: userdb prefetch {} has been replaced by userdb { driver=prefetch }

Mar 20 16:36:21  dovecot: config: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:111: auth_user has been replaced by service auth { user }

Mar 20 16:36:26  dovecot: auth: Warning: sql: Ignoring changed user_query in /etc/dovecot/dovecot-sql.conf, because userdb sql not used. (If this is intentional, set userdb_warning_disable=yes)

Mar 20 16:36:27  dovecot: auth: Error: net_connect_unix(auth-worker) in directory /run/dovecot failed: Permission denied (euid=65534(nobody) egid=65534(nobody) missing +r perm: /run/dovecot/auth-worker, dir owned by 0:0 mode=0755)

```

telnet localhost 143

```

Trying ::1...

Connected to localhost.

Escape character is '^]'.

+OK Welcome.

USER username

+OK

PASS password

[...silence for a long time, non-responsive to POP commands]

Connection closed by foreign host.

```

Server log:

```

Mar 20 17:00:37 dovecot: auth: Error: PLAIN(username,::1,<AE/lettermuddle>): Request 6624.1 timed out after 151 secs, state=1

Mar 20 17:00:45 dovecot: pop3-login: Disconnected: Inactivity during authentication (disconnected while authenticating, waited 159 secs): user=<>, method=PLAIN, rip=::1, lip=::1, secured, session=<AE/lettermuddle>

```

telnet localhost 143

```
Trying ::1...

Connected to localhost.

Escape character is '^]'.

* OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=LOGIN] Welcome.

? LOGIN user password

[silence for quite a while...]

* OK Waiting for authentication process to respond..

[silence...]

* BYE Disconnected for inactivity during authentication.

Connection closed by foreign host.

```

Logs for that: 

```

Mar 20 17:06:06 dovecot: auth: Error: net_connect_unix(auth-worker) in directory /run/dovecot failed: Permission denied (euid=65534(nobody) egid=65534(nobody) missing +r perm: /run/dovecot/auth-worker, dir owned by 0:0 mode=0755)

Mar 20 17:08:11 dovecot: imap-login: Disconnected: Inactivity during authentication (disconnected while authenticating, waited 125 secs): user=<>, method=PLAIN, rip=::1, lip=::1, secured, session=<more muddled letters>

```

telnet localhost 25

```

Trying ::1...

Trying 127.0.0.1...

Connected to localhost.

Escape character is '^]'.

220 mydomain.tld ESMTP Postfix

EHLO localhost

250-mydomain.tld

250-PIPELINING

250-SIZE 10240000

250-VRFY

250-ETRN

250-STARTTLS

250-ENHANCEDSTATUSCODES

250-8BITMIME

250 DSN

auth

503 5.5.1 Error: authentication not enabled

```

server-side log:

```

Mar 20 16:45:02 postfix/smtpd[6558]: connection established

Mar 20 16:45:02 postfix/smtpd[6558]: master_notify: status 0

Mar 20 16:45:02 postfix/smtpd[6558]: name_mask: resource

Mar 20 16:45:02 postfix/smtpd[6558]: name_mask: software

Mar 20 16:45:02 postfix/smtpd[6558]: connect from localhost[127.0.0.1]

Mar 20 16:45:02 postfix/smtpd[6558]: match_list_match: localhost: no match

Mar 20 16:45:02 postfix/smtpd[6558]: match_list_match: 127.0.0.1: no match

Mar 20 16:45:02 postfix/smtpd[6558]: match_list_match: localhost: no match

Mar 20 16:45:02 postfix/smtpd[6558]: match_list_match: 127.0.0.1: no match

Mar 20 16:45:02 postfix/smtpd[6558]: match_hostname: localhost ~? 192.168.0.100

Mar 20 16:45:02 postfix/smtpd[6558]: match_hostaddr: 127.0.0.1 ~? 192.168.0.100

Mar 20 16:45:02 postfix/smtpd[6558]: match_list_match: localhost: no match

Mar 20 16:45:02 postfix/smtpd[6558]: match_list_match: 127.0.0.1: no match

Mar 20 16:45:02 postfix/smtpd[6558]: smtp_stream_setup: maxtime=300 enable_deadline=0

Mar 20 16:45:02 postfix/smtpd[6558]: match_hostname: localhost ~? 192.168.0.0/24

Mar 20 16:45:02 postfix/smtpd[6558]: match_hostaddr: 127.0.0.1 ~? 192.168.0.0/24

Mar 20 16:45:02 postfix/smtpd[6558]: match_hostname: localhost ~? 127.0.0.0/8

Mar 20 16:45:02 postfix/smtpd[6558]: match_hostaddr: 127.0.0.1 ~? 127.0.0.0/8

Mar 20 16:45:02 postfix/smtpd[6558]: > localhost[127.0.0.1]: 220 mydomain.tld ESMTP Postfix

Mar 20 16:45:05 postfix/smtpd[6558]: < localhost[127.0.0.1]: EHLO localhost

Mar 20 16:45:05 postfix/smtpd[6558]: match_list_match: localhost: no match

Mar 20 16:45:05 postfix/smtpd[6558]: match_list_match: 127.0.0.1: no match

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-mydomain.tld

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-PIPELINING

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-SIZE 10240000

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-VRFY

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-ETRN

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-STARTTLS

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-ENHANCEDSTATUSCODES

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250-8BITMIME

Mar 20 16:45:05 postfix/smtpd[6558]: > localhost[127.0.0.1]: 250 DSN

Mar 20 16:45:12  postfix/smtpd[6558]: < localhost[127.0.0.1]: auth

Mar 20 16:45:12 postfix/smtpd[6558]: > localhost[127.0.0.1]: 503 5.5.1 Error: authentication not enabled

```

----------

## nativemad

ok, lets get pop/imap working again first...

Set user = dovecot in dovecot.conf under service auth where now it is set to nobody (according to your post earlier).

----------

## chaoscommander

Done that. Dovecot appears to be using auth-worker again, sasl plain login are listed as capabilities for POP3. I can login to IMAP via telnet and Thunderbird. I can receive messages. Phew.

So, back to the relay trouble. I finally found the right switch to make the logs more verbose, here's what happens when I send an e-mail (just the part where the remote server is involved):

```

Mar 20 18:52:56  postfix/smtp[2590]: smtp_connect_addr: trying: relay.tld port 25...

Mar 20 18:52:56 postfix/smtp[2590]: vstream_tweak_tcp: TCP_MAXSEG 1368

Mar 20 18:52:56  postfix/smtp[2590]: global TLS level: may

Mar 20 18:52:56  postfix/smtp[2590]: match_hostname: relay.tld ~? 192.168.0.100

Mar 20 18:52:56  postfix/smtp[2590]: match_hostaddr: [IP] ~? 192.168.0.100

Mar 20 18:52:56  postfix/smtp[2590]: match_list_match: relay.tld: no match

Mar 20 18:52:56  postfix/smtp[2590]: match_list_match: [IP]: no match

Mar 20 18:52:56  postfix/smtp[2590]: smtp_stream_setup: maxtime=300 enable_deadline=0

Mar 20 18:52:56  postfix/smtp[2590]: < relay.tld:25: 220 relay.tld rmsmtp 3.1.0a 5adb508466

Mar 20 18:52:56  postfix/smtp[2590]: > relay.tld:25: EHLO mydomain.tld

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-EASYSMTP

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-8BITMIME

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-SIZE 102400000

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-AUTH PLAIN LOGIN

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250 STARTTLS

Mar 20 18:52:57  postfix/smtp[2590]: server features: 0x103b size 102400000

Mar 20 18:52:57  postfix/smtp[2590]: smtp_stream_setup: maxtime=300 enable_deadline=0

Mar 20 18:52:57  postfix/smtp[2590]: > relay.tld:25: STARTTLS

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 220 go ahead

Mar 20 18:52:57  postfix/smtp[2590]: send attr request = seed

Mar 20 18:52:57  postfix/smtp[2590]: send attr size = 32

Mar 20 18:52:57  postfix/smtp[2590]: private/tlsmgr: wanted attribute: status

Mar 20 18:52:57  postfix/smtp[2590]: input attribute name: status

Mar 20 18:52:57  postfix/smtp[2590]: input attribute value: 0

Mar 20 18:52:57  postfix/smtp[2590]: private/tlsmgr: wanted attribute: seed

Mar 20 18:52:57  postfix/smtp[2590]: input attribute name: seed

Mar 20 18:52:57  postfix/smtp[2590]: input attribute value: randomstuff

Mar 20 18:52:57  postfix/smtp[2590]: private/tlsmgr: wanted attribute: (list terminator)

Mar 20 18:52:57  postfix/smtp[2590]: input attribute name: (end)

Mar 20 18:52:57  postfix/smtp[2590]: smtp_stream_setup: maxtime=300 enable_deadline=0

Mar 20 18:52:57  postfix/smtp[2590]: > relay.tld:25: EHLO mydomain.tld

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-EASYSMTP

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-8BITMIME

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-SIZE 102400000

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250-AUTH PLAIN LOGIN

Mar 20 18:52:57  postfix/smtp[2590]: < relay.tld:25: 250 STARTTLS

Mar 20 18:52:57  postfix/smtp[2590]: server features: 0x103b size 102400000

Mar 20 18:52:57  postfix/smtp[2590]: maps_find: smtp_sasl_passwd: hash:/etc/postfix/saslpass(0,lock|fold_fix): relay.tld = relayuser:pass

Mar 20 18:52:57  postfix/smtp[2590]: smtp_sasl_passwd_lookup: host `relay.tld' user `relayuser' pass `pass'

Mar 20 18:52:57  postfix/smtp[2590]: starting new SASL client

Mar 20 18:52:57  postfix/smtp[2590]: name_mask: noplaintext

Mar 20 18:52:57  postfix/smtp[2590]: name_mask: noanonymous

Mar 20 18:52:57  postfix/smtp[2590]: smtp_sasl_authenticate: relay.tld:25: SASL mechanisms PLAIN LOGIN

Mar 20 18:52:57  postfix/smtp[2590]: warning: SASL authentication failure: No worthy mechs found

Mar 20 18:52:57  postfix/smtp[2590]: E17C5EE001D: SASL authentication failed; cannot authenticate to server relay.tld: no mechanism available

Mar 20 18:52:57  postfix/smtp[2590]: smtp_stream_setup: maxtime=300 enable_deadline=0

Mar 20 18:52:57  postfix/smtp[2590]: > relay.tld:25: QUIT

```

----------

## nativemad

Ahhhh... i thought you'd have problems with incoming smtp auths - which is done by dovecot! Sorry for the confusion!

i think the problem is here:

Mar 20 18:52:57  postfix/smtp[2590]: name_mask: noplaintext 

Mar 20 18:52:57  postfix/smtp[2590]: name_mask: noanonymous 

Mar 20 18:52:57  postfix/smtp[2590]: smtp_sasl_authenticate: relay.tld:25: SASL mechanisms PLAIN LOGIN 

is smtpd_sasl_security_options still set to noanonymous exclusively, or do you got a noplaintext also in the meantime? -The remoteserver only allows plain.

----------

## chaoscommander

Yeah, now I'm confused too, I have no idea where that 'noplaintext' is coming from. It's not in main.cf. Anywhere else it could be?

----------

## nativemad

can you telnet into the remote smtp server and do a ehlo? Just to get the listing and get sure what that server really wants...

does postconf show it?

----------

## chaoscommander

postconf shows something else: smtp_sasl_security_options (minus the d) = noplaintext, noanonymous - same for lmtp_sasl_... I'll try to specify that to noanonymous too.

Ha! That was it! *dances* \o\  /o/ \o/

Thank you very much for your help  :Smile:  Finally. I've been working on this (on and off) for weeks.

----------

## hydrapolic

The official documentation is also great, needs some time to read (even multiple times), but then you'll have it under control  :Smile: 

http://www.postfix.org/documentation.html

http://wiki2.dovecot.org

----------

