SASL auth failure dovecot/postfix

[Tazman Deville]

I have two servers, both running wheezy with dovecot/postfix for mail.
They were both sending/receiving mail fine 24 hours ago.
Now neither is.
On one, I've done nothing to alter anything with either postfix or
dovecot in the last 24 hours.
On the other, I generated a new smtpd.key and smptd.crt for postfix,
restarted postfix and dovecot...and I thought I'd done something wrong,
until I found that the other server is also having the same problem.

On both servers, I ran aptitude updates yesterday.
I generally update them both weekly.
They were both sending/receiving mail fine before that.
They seem to both receive, but not send mail now.

I can only assume something from aptitude updates broke my mail servers.
How do I diagnose and resolve this matter?

taz

[Tazman Deville]

Post by Tazman Deville
I have two servers, both running wheezy with dovecot/postfix for mail.
They were both sending/receiving mail fine 24 hours ago.
Now neither is.
On one, I've done nothing to alter anything with either postfix or
dovecot in the last 24 hours.
On the other, I generated a new smtpd.key and smptd.crt for postfix,
restarted postfix and dovecot...and I thought I'd done something wrong,
until I found that the other server is also having the same problem.
On both servers, I ran aptitude updates yesterday.
I generally update them both weekly.
They were both sending/receiving mail fine before that.
They seem to both receive, but not send mail now.
I can only assume something from aptitude updates broke my mail servers.
How do I diagnose and resolve this matter?
taz

Incidentally, I have tried sending/receiving with both mutt and
squirrelmail on accounts for both servers.
Again, I confirm, they can receive mail fine, but no account
on either server can send mail, either with mutt or squirrelmail.
In both cases, the same error: SASL authentication failure.
In some cases, then mutt asks for the password for the smtp account.
I provide that, and it continues to fail.
I find this odd, since I have the passwords in my muttrc files,
and, as mentioned above, everything was working fine yesterday,
both sending and receiving.

taz

[Jonathan Dowland]

If mail is not sending, you need to look at the postfix logs and see if
there's an explanation for a test mail. dovecot will not be relevant
unless you are using send-over-IMAP which is unlikely. Can you share
some relevant log lines?

[Tazman Deville]

Post by Jonathan Dowland
If mail is not sending, you need to look at the postfix logs and see if
there's an explanation for a test mail. dovecot will not be relevant
unless you are using send-over-IMAP which is unlikely. Can you share
some relevant log lines?

tail of mail.log on same server with above error looks relatively
Disconnected: Logged out in=117 out=1469
mpid=17024, secured, session=<l0nIq1T0FgB/AAAB>
Disconnected: Logged out in=85 out=708
Mar 11 14:27:03 myownsite postfix/anvil[16975]: statistics: max
connection rate 1/60s for (smtp:209.170.84.20) at Mar 11 14:23:43
Mar 11 14:27:03 myownsite postfix/anvil[16975]: statistics: max
connection count 1 for (smtp:209.170.84.20) at Mar 11 14:23:43
Mar 11 14:27:03 myownsite postfix/anvil[16975]: statistics: max cache
size 1 at Mar 11 14:23:43
Mar 11 13:52:16 myownsite postfix/smtpd[16685]: warning: SASL
authentication failure: Password verification failed
authentication failure
Mar 11 13:57:58 myownsite postfix/smtpd[16797]: warning: SASL
authentication failure: Password verification failed
authentication failure
Mar 11 13:59:51 myownsite postfix/smtpd[16823]: warning: SASL
authentication failure: Password verification failed
authentication failure

Perhaps this is relevant:
telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.localdomain.
Escape character is '^]'.
220 myownsite.me ESMTP Postfix (Debian/GNU)
ehlo localhost
250-myownsite.me
250-PIPELINING
250-SIZE 30720000
250-VRFY
250-ETRN
250-STARTTLS
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
quit
221 2.0.0 Bye

looks okay there, yes?

taz

[Tom Furie]

Post by Tazman Deville

Mar 11 13:52:16 myownsite postfix/smtpd[16685]: warning: SASL
authentication failure: Password verification failed
authentication failure

telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.localdomain.
Escape character is '^]'.
220 myownsite.me ESMTP Postfix (Debian/GNU)
ehlo localhost
250-myownsite.me
250-PIPELINING
250-SIZE 30720000
250-VRFY
250-ETRN
250-STARTTLS
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
quit
221 2.0.0 Bye
looks okay there, yes?

That looks okay in as much as you are able to connect to the SMTP
server, however you haven't tried to authenticate with it which is where
you are having problems. You were having trouble connecting to dovecot
on the evening of the 10th due to the database being overloaded, but
that problem resolved itself when the server load came down to
manageable levels, and you have said you are having no problem receiving
mail. Dovecot is not part of the equation.

The log segment above indicates a failure to authenticate with the SMTP
server. What backend are you using for that authentication, the same
mySQL database? Are both servers using the same backend?

Cheers,
Tom

[Tazman Deville]

Post by Tom Furie

Post by Tazman Deville

Mar 11 13:52:16 myownsite postfix/smtpd[16685]: warning: SASL
authentication failure: Password verification failed
authentication failure

telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.localdomain.
Escape character is '^]'.
220 myownsite.me ESMTP Postfix (Debian/GNU)
ehlo localhost
250-myownsite.me
250-PIPELINING
250-SIZE 30720000
250-VRFY
250-ETRN
250-STARTTLS
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
quit
221 2.0.0 Bye
looks okay there, yes?

That looks okay in as much as you are able to connect to the SMTP
server, however you haven't tried to authenticate with it which is where
you are having problems. You were having trouble connecting to dovecot
on the evening of the 10th due to the database being overloaded, but
that problem resolved itself when the server load came down to
manageable levels, and you have said you are having no problem receiving
mail. Dovecot is not part of the equation.
The log segment above indicates a failure to authenticate with the SMTP
server. What backend are you using for that authentication, the same
mySQL database? Are both servers using the same backend?

Both servers are nearly identically configured (just different domains
and users).
One has been running Wheezy several months longer, but they're both on
wheezy now, anyway.
I essentially set them up, initially, when running squeeze, according to
the instructions here:
https://library.linode.com/email/postfix/dovecot-mysql-debian-6-squeeze
although 1) they are not on linode (one is on contabo in germany, the
other is here in my office), and 2), they were both updated to Wheezy
since then (and configs for both dovecot and postfix had to be altered
at that time, but that was months ago for both, and both were working
until this morning).
They both use mysql (well, mariadb) auth for both dovecot and postfix.
I have confirmed that I can connect to the DB on either server with the
mail admin account configured in postfix.
Yet, I can not send mail.
I'm stumped.
They were working yesterday during the day. I ran aptitude update, then
safe-upgrade later in the evening.
Then today, they can not send mail.
As far as I recall, postfix was not updated yesterday.
Nor was mariadb, dovecot, or anything else I can imagine is significant
here. Aside from mail, the servers have slightly different software
installed. One received 1 update, the other 3.
I do not believe they were the same at all (as in the 1 update one the
first server was not the same as any of the 3 on the other).
Still, they're having apparently identical problems now, and the only
thing that has changed on either since they were working was running the
aptitude updates.
All the logs seem to be telling me is that SASL auth is failing,
which I know. They do not tell me why or wherein lies the failure.

taz
:wq

[Tom Furie]

Post by Tazman Deville
They both use mysql (well, mariadb) auth for both dovecot and postfix.
I have confirmed that I can connect to the DB on either server with the
mail admin account configured in postfix.
Yet, I can not send mail.

Do they connect to the same database for authentication against both
dovecot and postfix? Can you connect to the database as a normal user?
How many users are having the problem?

Post by Tazman Deville
As far as I recall, postfix was not updated yesterday.
Nor was mariadb, dovecot, or anything else I can imagine is significant
here. Aside from mail, the servers have slightly different software
installed. One received 1 update, the other 3.
I do not believe they were the same at all (as in the 1 update one the
first server was not the same as any of the 3 on the other).

It might help to know exactly which packages were updated -
/var/log/apt/{history,term}.log and /var/log/dpkg.log
should have the information.

Post by Tazman Deville
Still, they're having apparently identical problems now, and the only
thing that has changed on either since they were working was running the
aptitude updates.
All the logs seem to be telling me is that SASL auth is failing,
which I know. They do not tell me why or wherein lies the failure.

Does /var/log/auth.log have any further details?

Cheers,
Tom

[Tazman Deville]

Post by Tom Furie

Post by Tazman Deville
They both use mysql (well, mariadb) auth for both dovecot and postfix.
I have confirmed that I can connect to the DB on either server with the
mail admin account configured in postfix.
Yet, I can not send mail.

Do they connect to the same database for authentication against both
dovecot and postfix? Can you connect to the database as a normal user?
How many users are having the problem?

There are few users on either server, and all I've tested are unable to
send mail.
In both servers, there is 1 mail DB for both dovecot and postfix, yes.

Post by Tom Furie

Post by Tazman Deville
As far as I recall, postfix was not updated yesterday.
Nor was mariadb, dovecot, or anything else I can imagine is
significant
here. Aside from mail, the servers have slightly different software
installed. One received 1 update, the other 3.
I do not believe they were the same at all (as in the 1 update one the
first server was not the same as any of the 3 on the other).

It might help to know exactly which packages were updated -
/var/log/apt/{history,term}.log and /var/log/dpkg.log
should have the information.

tail history.log for one of the servers:

Start-Date: 2014-03-04 15:30:45
Upgrade: mariadb-server:i386 (5.5.35+maria-1~wheezy,
5.5.36+maria-1~wheezy), php5:i386 (5.4.4-14+deb7u7, 5.4.4-14+deb7u8),
php5-sqlite:i386 (5.4.4-14+deb7u7, 5.4.4-14+deb7u8), mysql-common:i386
(5.5.35+maria-1~wheezy, 5.5.36+maria-1~wheezy), libgnutls26:i386
(2.12.20-7, 2.12.20-8+deb7u1), php5-gd:i386 (5.4.4-14+deb7u7,
5.4.4-14+deb7u8), xulrunner-27:i386 (27.0-2~bpo70+1, 27.0.1-1~bpo70+1),
php-pear:i386 (5.4.4-14+deb7u7, 5.4.4-14+deb7u8), iceweasel:i386
(27.0-2~bpo70+1, 27.0.1-1~bpo70+1), php5-curl:i386 (5.4.4-14+deb7u7,
5.4.4-14+deb7u8), libmozjs-dev:i386 (27.0-2~bpo70+1, 27.0.1-1~bpo70+1),
mariadb-client:i386 (5.5.35+maria-1~wheezy, 5.5.36+maria-1~wheezy),
libmozjs27d:i386 (27.0-2~bpo70+1, 27.0.1-1~bpo70+1),
libmariadbclient18:i386 (5.5.35+maria-1~wheezy, 5.5.36+maria-1~wheezy),
mariadb-server-core-5.5:i386 (5.5.35+maria-1~wheezy,
5.5.36+maria-1~wheezy), php5-mcrypt:i386 (5.4.4-14+deb7u7,
5.4.4-14+deb7u8), libmysqlclient18:i386 (5.5.35+maria-1~wheezy,
5.5.36+maria-1~wheezy), php5-intl:i386 (5.4.4-14+deb7u7,
5.4.4-14+deb7u8), mariadb-common:i386 (5.5.35+maria-1~wheezy,
5.5.36+maria-1~wheezy), php5-mysql:i386 (5.4.4-14+deb7u7,
5.4.4-14+deb7u8), php5-cli:i386 (5.4.4-14+deb7u7, 5.4.4-14+deb7u8),
mariadb-server-5.5:i386 (5.5.35+maria-1~wheezy, 5.5.36+maria-1~wheezy),
mariadb-client-core-5.5:i386 (5.5.35+maria-1~wheezy,
5.5.36+maria-1~wheezy), libapache2-mod-php5:i386 (5.4.4-14+deb7u7,
5.4.4-14+deb7u8), mariadb-client-5.5:i386 (5.5.35+maria-1~wheezy,
5.5.36+maria-1~wheezy), php5-common:i386 (5.4.4-14+deb7u7,
5.4.4-14+deb7u8), xulrunner-dev:i386 (27.0-2~bpo70+1, 27.0.1-1~bpo70+1)
End-Date: 2014-03-04 15:32:56

Start-Date: 2014-03-10 23:32:28
Upgrade: udisks:i386 (1.0.4-7, 1.0.4-7wheezy1)
End-Date: 2014-03-10 23:32:50


I thought that might be getting us somewhere, since mariadb is in
there,
but that was on the 4th, and the server was working until today, the
11th.


Now tail term.log for the same server as above:

Processing triggers for menu ...
Log ended: 2014-03-04 15:32:56

Log started: 2014-03-10 23:32:28
(Reading database ... 220649 files and directories currently
installed.)
Preparing to replace udisks 1.0.4-7 (using
.../udisks_1.0.4-7wheezy1_i386.deb) ...
Unpacking replacement udisks ...
Processing triggers for man-db ...
Setting up udisks (1.0.4-7wheezy1) ...
Log ended: 2014-03-10 23:32:50

The other servers shows the same updates on the 4th, plus this from the
10th in history.log:

Start-Date: 2014-03-10 23:13:25
Upgrade: libyaml-libyaml-perl:amd64 (0.38-3, 0.38-3+deb7u1)
End-Date: 2014-03-10 23:13:37
and this in tail term.log
[ ok ] Reloading web server config: apache2.
Log ended: 2014-03-04 21:32:51

Log started: 2014-03-10 23:13:25
(Reading database ... 90014 files and directories currently installed.)
Preparing to replace libyaml-libyaml-perl 0.38-3 (using
.../libyaml-libyaml-perl_0.38-3+deb7u1_amd64.deb) ...
Unpacking replacement libyaml-libyaml-perl ...
Processing triggers for man-db ...
Setting up libyaml-libyaml-perl (0.38-3+deb7u1) ...
Log ended: 2014-03-10 23:13:37

So the updates they received yesterday don't look relevant,
but they were both working until today.

I've tried using mutt here from my desktop, and also on each server
over
ssh, plus, they both have squirrelmail on the servers, and I've tried
that. In all cases, I am receiving mail normally and can log in an read
it, but can not send anything out.

Post by Tom Furie

Post by Tazman Deville
Still, they're having apparently identical problems now, and the only
thing that has changed on either since they were working was
running the

:> > aptitude updates.

Post by Tom Furie

Post by Tazman Deville
All the logs seem to be telling me is that SASL auth is failing,
which I know. They do not tell me why or wherein lies the failure.

Does /var/log/auth.log have any further details?

Ah! Perhaps this will be useful.
I just logged in with mutt, received mail, and tried to send one
message, and get this from tail auth.log:

Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin Parse the
username ***@liberame.org
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin try and
connect to a host
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin trying to
open db 'mail' on host '127.0.0.1'
Mar 11 19:33:32 myownsite saslauthd[1850]: PAM unable to
dlopen(pam_mysql.so): /lib/security/pam_mysql.so: symbol
make_scrambled_password, version libmysqlclient_18 not defined in file
libmysqlclient.so.18 with link time reference
Mar 11 19:33:32 myownsite saslauthd[1850]: PAM adding faulty module:
pam_mysql.so
Mar 11 19:33:32 myownsite saslauthd[1850]: DEBUG: auth_pam:
pam_authenticate failed: Module is unknown
Mar 11 19:33:32 myownsite saslauthd[1850]: do_auth : auth
failure: [user=***@liberame.org] [service=smtp] [realm=liberame.org]
[mech=pam] [reason=PAM auth error]
Mar 11 19:33:37 myownsite mutt: DIGEST-MD5 common mech free
Mar 11 19:33:40 myownsite sudo: tazman : TTY=pts/0 ; PWD=/var/log ;
USER=root ; COMMAND=/usr/bin/tail auth.log
Mar 11 19:33:40 myownsite sudo: pam_unix(sudo:session): session opened
for user root by tazman(uid=0)

taz
:wq

[Tazman Deville]

Post by Tazman Deville

Post by Tom Furie

Post by Tazman Deville
They both use mysql (well, mariadb) auth for both dovecot and postfix.
I have confirmed that I can connect to the DB on either server with the
mail admin account configured in postfix.
Yet, I can not send mail.

Does /var/log/auth.log have any further details?

Ah! Perhaps this will be useful.
I just logged in with mutt, received mail, and tried to send one
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin Parse the
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin try and
connect to a host
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin trying to
open db 'mail' on host '127.0.0.1'
Mar 11 19:33:32 myownsite saslauthd[1850]: PAM unable to
dlopen(pam_mysql.so): /lib/security/pam_mysql.so: symbol
make_scrambled_password, version libmysqlclient_18 not defined in file
libmysqlclient.so.18 with link time reference
pam_mysql.so
pam_authenticate failed: Module is unknown
Mar 11 19:33:32 myownsite saslauthd[1850]: do_auth : auth
[mech=pam] [reason=PAM auth error]
Mar 11 19:33:37 myownsite mutt: DIGEST-MD5 common mech free
Mar 11 19:33:40 myownsite sudo: tazman : TTY=pts/0 ; PWD=/var/log ;
USER=root ; COMMAND=/usr/bin/tail auth.log
Mar 11 19:33:40 myownsite sudo: pam_unix(sudo:session): session opened
for user root by tazman(uid=0)

Well, with this pam error, I found an Arch thread here:
https://bbs.archlinux.org/viewtopic.php?id=177758
so it looks like it is a known problem,
but I have not yet found a solution (short of dumping mariadb and moving
back to mysql, which I'd rather not, if I can avoid it).

taz

[Tony Baldwin]

Post by Tazman Deville
https://bbs.archlinux.org/viewtopic.php?id=177758
so it looks like it is a known problem,
but I have not yet found a solution (short of dumping mariadb and moving
back to mysql, which I'd rather not, if I can avoid it).

Looks like the instructions here:
http://pastie.org/8784056
will resolve the problem.
Downgrade of the mariadb server and client and the libmysqlclient18 library.
Oh, and the pastebin neglects to mention, when you downgrade the libmysqlclient,
it removes mariadb-server and mariadb-client.
Just after that, do
apt-get install mariadb-server and mariadb-client and it installs the previous version,
according to the repo added to sources.list.
Now we're running a slightly older version of all those packages, a version that worked.
If this messages reaches the list, it's because that's what I did on the server here in the office,
and I'll have your server, Taz, up and running momentarily, as well.

IMHO, a downgrade is not the ideal resolution, but if it gets the job done...
Still better than moving back to mysql, imho.

:D
Tony

[Tom Furie]

Post by Tazman Deville
There are few users on either server, and all I've tested are unable to
send mail.
In both servers, there is 1 mail DB for both dovecot and postfix, yes.

If both dovecot and postfix are using the same authentication mechanism
it's very odd that only one of them works.

Post by Tazman Deville
Start-Date: 2014-03-04 15:30:45
Upgrade: mariadb-server:i386 (5.5.35+maria-1~wheezy,

While exploring this I've discovered that there are no Debian packages
of mariadb except in sid. Which repository are you using for these
packages, Arch?

My best guess about the timing of the failure would be that while
mysql/mariadb was upgraded on the 4th, the service wasn't actually
restarted until you were having the load issues.

Post by Tazman Deville
Ah! Perhaps this will be useful.
I just logged in with mutt, received mail, and tried to send one
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin Parse the
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin try and
connect to a host
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin trying to
open db 'mail' on host '127.0.0.1'
Mar 11 19:33:32 myownsite saslauthd[1850]: PAM unable to
dlopen(pam_mysql.so): /lib/security/pam_mysql.so: symbol
make_scrambled_password, version libmysqlclient_18 not defined in file
libmysqlclient.so.18 with link time reference
pam_mysql.so
pam_authenticate failed: Module is unknown
Mar 11 19:33:32 myownsite saslauthd[1850]: do_auth : auth
[mech=pam] [reason=PAM auth error]
Mar 11 19:33:37 myownsite mutt: DIGEST-MD5 common mech free
Mar 11 19:33:40 myownsite sudo: tazman : TTY=pts/0 ; PWD=/var/log ;
USER=root ; COMMAND=/usr/bin/tail auth.log
Mar 11 19:33:40 myownsite sudo: pam_unix(sudo:session): session opened
for user root by tazman(uid=0)

If pam_mysql support has been dropped in the latest version of mariadb,
you could try running an older version which does have support.
Alternatively you could find out what mechanisms the new version
supports and change your system accordingly.

Downgrading packages can be tricky, and since I don't know the
dependency tree around mariadb I won't be able to help there. One option
would be to remove mariadb and anything that has a hard dependency on
it, get the required previous versions from the archives (you probably
still have them in /var/cache/apt/), install them by dpkg and set them
to hold status. Make sure you have good backups before doing any of
that.

Cheers,
Tom

[Tony Baldwin]

Post by Tom Furie

Post by Tazman Deville
There are few users on either server, and all I've tested are unable to
send mail.
In both servers, there is 1 mail DB for both dovecot and postfix, yes.

If both dovecot and postfix are using the same authentication mechanism
it's very odd that only one of them works.

In the end, we determined it was a problem with libmysqlclient18 and
pam-mysql. Only postfix needs the pam module (dovecot does not).

Post by Tom Furie
While exploring this I've discovered that there are no Debian packages
of mariadb except in sid. Which repository are you using for these
packages, Arch?

The MariaDB project maintains repos for us.
See
https://downloads.mariadb.org/mariadb/repositories/#mirror=syringa&distro=Debian

Post by Tom Furie
My best guess about the timing of the failure would be that while
mysql/mariadb was upgraded on the 4th, the service wasn't actually
restarted until you were having the load issues.

You know, that makes sense.

Post by Tom Furie

Post by Tazman Deville
Ah! Perhaps this will be useful.
I just logged in with mutt, received mail, and tried to send one
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin Parse the
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin try and
connect to a host
Mar 11 19:33:32 myownsite postfix/smtpd[32642]: sql plugin trying to
open db 'mail' on host '127.0.0.1'
Mar 11 19:33:32 myownsite saslauthd[1850]: PAM unable to
dlopen(pam_mysql.so): /lib/security/pam_mysql.so: symbol
make_scrambled_password, version libmysqlclient_18 not defined in file
libmysqlclient.so.18 with link time reference
pam_mysql.so
pam_authenticate failed: Module is unknown
Mar 11 19:33:32 myownsite saslauthd[1850]: do_auth : auth
[mech=pam] [reason=PAM auth error]
Mar 11 19:33:37 myownsite mutt: DIGEST-MD5 common mech free
Mar 11 19:33:40 myownsite sudo: tazman : TTY=pts/0 ; PWD=/var/log ;
USER=root ; COMMAND=/usr/bin/tail auth.log
Mar 11 19:33:40 myownsite sudo: pam_unix(sudo:session): session opened
for user root by tazman(uid=0)

If pam_mysql support has been dropped in the latest version of mariadb,
you could try running an older version which does have support.
Alternatively you could find out what mechanisms the new version
supports and change your system accordingly.

This is what we ended up doing, rolling back to an older version of
mariadb, libmysqlclient18, etc.

I posted the relevant instructions (where to get the older pkgs, etc.)
earlier.
Both Taz' server and the other are both sending mail again (I'm sending
this message from the office server. Taz rents a VPS on another server
of mine, and we co-admin some sites).

Tony

[Tom Furie]

Post by Tony Baldwin
This is what we ended up doing, rolling back to an older version of
mariadb, libmysqlclient18, etc.
I posted the relevant instructions (where to get the older pkgs, etc.)
earlier.
Both Taz' server and the other are both sending mail again (I'm sending
this message from the office server. Taz rents a VPS on another server
of mine, and we co-admin some sites).

Yeah, I saw your response with much more definitive information had
arrived between me starting my reply and sending it. Good to know you
got the problem solved and what the fix was.

Cheers,
Tom

[Tazman Deville]

Post by Tom Furie

Post by Tony Baldwin
This is what we ended up doing, rolling back to an older version of
mariadb, libmysqlclient18, etc.
I posted the relevant instructions (where to get the older pkgs, etc.)
earlier.
Both Taz' server and the other are both sending mail again (I'm sending
this message from the office server. Taz rents a VPS on another server
of mine, and we co-admin some sites).

Yeah, I saw your response with much more definitive information had
arrived between me starting my reply and sending it. Good to know you
got the problem solved and what the fix was.

everything seems in order over here now.
RESOLVED!

:-D
Taz

[Jonathan Dowland]

Post by Tom Furie

Post by Tazman Deville
telnet localhost 25

(snip)

Post by Tom Furie
That looks okay in as much as you are able to connect to the SMTP
server, however you haven't tried to authenticate with it which is where
you are having problems.

Agreed.

For the benefit of anyone else following along who may not know of this,
but 'swaks' is a great tool for testing this sort-of thing. It can
handle TLS and authentication (which are hard to type by hand!)

[Tazman Deville]

Post by Jonathan Dowland
If mail is not sending, you need to look at the postfix logs and see if
there's an explanation for a test mail. dovecot will not be relevant
unless you are using send-over-IMAP which is unlikely. Can you share
some relevant log lines?

You trimmed relevant stuff...nonetheless,
I am using IMAP not POP for these accounts,
but afaik, I'm sending over SMTP.
mysql(127.0.0.1): Connect failed to database (mail): Can't connect to
MySQL server on '127.0.0.1' (111) - waiting for 125 seconds before
retry
on one server, but not such thing on the other
I think mariadb was overworked last night (since moved some sites off
this server, CPU load was massive, but now ok).

It's probably relevant that I do not see such error this morning,
but only from last night, and only on the server where mysql/mariadb
processes were skyrocketing until I moved some stuff around.
No such error on the other server that's having precisely the same mail
woes (but not similar problems with mariadb).

taz

[Tazman Deville]

Post by Jonathan Dowland
If mail is not sending, you need to look at the postfix logs and see if
there's an explanation for a test mail. dovecot will not be relevant
unless you are using send-over-IMAP which is unlikely. Can you share
some relevant log lines?

You trimmed relevant stuff...nonetheless,
I am using IMAP not POP for these accounts,
but afaik, I'm sending over SMTP.

Now, that I look, I'm seeing this in the mail.err logs:
Mar 10 22:04:58 myownsite dovecot: auth-worker(13988): Error:
mysql(127.0.0.1): Connect failed to database (mail): Can't connect to
MySQL server on '127.0.0.1' (111) - waiting for 125 seconds before
retry
on one server, but not such thing on the other
I think mariadb was overworked last night (since moved some sites off
this server, CPU load was massive, but now ok).

tail of mail.log on same server with above error looks relatively
normal:
Mar 11 14:25:54 myownsite dovecot: imap(***@myownsite.me):
Disconnected: Logged out in=117 out=1469
Mar 11 14:26:43 myownsite dovecot: imap-login: Login:
user=<***@myownsite.me>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1,
mpid=17024, secured, session=<l0nIq1T0FgB/AAAB>
Mar 11 14:26:43 myownsite dovecot: imap(***@myownsite.me):
Disconnected: Logged out in=85 out=708
Mar 11 14:27:03 myownsite postfix/anvil[16975]: statistics: max
connection rate 1/60s for (smtp:209.170.84.20) at Mar 11 14:23:43
Mar 11 14:27:03 myownsite postfix/anvil[16975]: statistics: max
connection count 1 for (smtp:209.170.84.20) at Mar 11 14:23:43
Mar 11 14:27:03 myownsite postfix/anvil[16975]: statistics: max cache
size 1 at Mar 11 14:23:43

both servers show similar in mail.warn:
Mar 11 13:52:16 myownsite postfix/smtpd[16685]: warning: SASL
authentication failure: Password verification failed
Mar 11 13:52:16 myownsite postfix/smtpd[16685]: warning:
myownsite.me[178.238.226.185]: SASL PLAIN authentication failed:
authentication failure
Mar 11 13:57:58 myownsite postfix/smtpd[16797]: warning: SASL
authentication failure: Password verification failed
Mar 11 13:57:58 myownsite postfix/smtpd[16797]: warning:
myownsite.me[178.238.226.185]: SASL PLAIN authentication failed:
authentication failure
Mar 11 13:59:51 myownsite postfix/smtpd[16823]: warning: SASL
authentication failure: Password verification failed
Mar 11 13:59:51 myownsite postfix/smtpd[16823]: warning:
myownsite.me[178.238.226.185]: SASL PLAIN authentication failed:
authentication failure

I can't for the life of me determine anything useful from these.

Taz

[Tazman Deville]

mysql(127.0.0.1): Connect failed to database (mail): Can't connect to
MySQL server on '127.0.0.1' (111) - waiting for 125 seconds before
retry
on one server, but not such thing on the other
I think mariadb was overworked last night (since moved some sites off
this server, CPU load was massive, but now ok).

It is really hard to help without you trying to make straightforward
tests and posting the resulting log file entries. Output of dovecot -n
and postconf -n would help as well.

Why don't you explain what "straightforward tests" means, then.
I tried to send mail and showed you what the logs show.
What else am I to do?

I can't imagine there being a problem with my postconf or dovecot
configurations, since they were both working fine 24 hours ago before I
ran aptitude update && safe-upgrade

Nonetheless:
postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
broken_sasl_auth_clients = yes
config_directory = /etc/postfix
dovecot_destination_recipient_limit = 1
html_directory = /usr/share/doc/postfix/html
inet_interfaces = all
mailbox_size_limit = 0
message_size_limit = 30720000
mydestination = mail.myownsite.me, localhost, localhost.localdomain
myhostname = myownsite.me
mynetworks = 127.0.0.0/8
myorigin = /etc/mailname
proxy_read_maps = $local_recipient_maps $mydestination
$virtual_alias_maps $virtual_alias_domains $virtual_mailbox_maps
$virtual_mailbox_domains $relay_recipient_maps $relay_domains
$canonical_maps $sender_canonical_maps $recipient_canonical_maps
$relocated_maps $transport_maps $mynetworks $virtual_mailbox_limit_maps
readme_directory = /usr/share/doc/postfix
recipient_delimiter = +
relayhost =
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_recipient_restrictions = permit_mynetworks,
permit_sasl_authenticated, reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
smtpd_tls_cert_file = /etc/postfix/smtpd.cert
smtpd_tls_key_file = /etc/postfix/smtpd.key
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_use_tls = yes
virtual_alias_domains =
virtual_alias_maps =
proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf,
mysql:/etc/postfix/mysql-virtual_email2email.cf
virtual_gid_maps = static:5000
virtual_mailbox_base = /home/vmail
virtual_mailbox_domains =
proxy:mysql:/etc/postfix/mysql-virtual_domains.cf
virtual_mailbox_maps =
proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf
virtual_transport = dovecot
virtual_uid_maps = static:5000

dovecot -n
# 2.1.7: /etc/dovecot/dovecot.conf
# OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.4 ext4
log_timestamp = "%Y-%m-%d %H:%M:%S "
mail_location = maildir:/home/vmail/%d/%n/Maildir
namespace {
inbox = yes
location =
prefix = INBOX.
separator = .
type = private
}
passdb {
args = /etc/dovecot/dovecot-sql.conf
driver = sql
}
protocols = imap pop3
service auth {
user = root
}
ssl_cert = </etc/dovecot/dovecot.pem
ssl_key = </etc/dovecot/private/dovecot.pem
userdb {
args = uid=5000 gid=5000 home=/home/vmail/%d/%n
allow_all_users=yes
driver = static
}
protocol lda {
auth_socket_path = /var/run/dovecot/auth-userdb
log_path = /home/vmail/dovecot-deliver.log
mail_plugins = sieve
postmaster_address = ***@myownsite.me
}
protocol pop3 {
pop3_uidl_format = %08Xu%08Xv
}

(does not reflect actually indentation, posting into vim
with this last made weird indentation).
I almost feel I should be pastebinning this stuff, and not
sending so much text to the list.:wq

taz

[Jochen Spieker]

mysql(127.0.0.1): Connect failed to database (mail): Can't connect to
MySQL server on '127.0.0.1' (111) - waiting for 125 seconds before
retry
on one server, but not such thing on the other
I think mariadb was overworked last night (since moved some sites off
this server, CPU load was massive, but now ok).

It is really hard to help without you trying to make straightforward
tests and posting the resulting log file entries. Output of dovecot -n
and postconf -n would help as well.

However, this log file snippet suggests that you are authenticating
users using a local MySQL database that cannot be contacted currently.
If you moved it off the server, you should definitely move it back.

J.