Annoying log message "DIGEST-MD5 common mech free"

Apparently, this message is logged whenever I commit a file to svn through SSH:

auth.log:

sshd[1085]: Accepted publickey for sylvain from *IP here* port xx ssh2
svnserve: DIGEST-MD5 common mech free

The first one is me connecting to svn through SSH, the second line comes 1 second later and is the annoying one that makes no sense at all...

This problem still occurs with libsasl2-modules 2.1.24~rc1.dfsg1+cvs2011-05-23-4ubuntu2

Hi,

I have it with libsasl2-modules 2.1.25.dfsg1-5.

On my system it is nnrpd which is logging that (on a INN2 server).

libsasl2-modules 2.1.25.dfsg1-6
from commit through svn+ssh

Hi,

it seems this bug re-appeared in Xenial:

# lsb_release -rd
Description: Ubuntu 16.04.1 LTS
Release: 16.04

# dpkg -l libsasl2-modules
ii libsasl2-modules:amd64 2.1.26.dfsg1-14b amd64

Aug 18 02:37:30 xxx slapcat: DIGEST-MD5 common mech free
Aug 18 02:37:30 xxx slapcat: message repeated 9 times: [ DIGEST-MD5 common mech free]
Aug 18 03:37:30 xxx slapcat: DIGEST-MD5 common mech free
Aug 18 03:37:30 xxx slapcat: message repeated 9 times: [ DIGEST-MD5 common mech free]
Aug 18 04:37:29 xxx slapcat: DIGEST-MD5 common mech free
Aug 18 04:37:30 xxx slapcat: message repeated 9 times: [ DIGEST-MD5 common mech free]
Aug 18 05:37:30 xxx slapcat: DIGEST-MD5 common mech free

Cheers,
Tom.

Confirmed, this is incredibly annoying. In my case, it's coming from PHP. I've got 44k of such messages in my auth.log file that covers just the last 3.5 days, and 16k of those were actually "repeated x times" messages! All coming from php or php7.0 (both pointing to the same php7.0-cli binary). I believe this is because I use php-mongodb extensively, which uses libsasl2-2.

libsasl2-modules 2.1.25.dfsg1-17build1 on Ubuntu 14.04.

FYI: The solution Debian implemented was quite trivial. Simply create the file /etc/logcheck/ignore.d.server/libsasl2-modules:
\w{3} [ :0-9]{11} [._[:alnum:]-]+ [._[:alnum:]-]+: DIGEST-MD5 common mech free

It doesn't actually fix the problem, it just ignores the pointless log messages.

FYI: From https://bugs.archlinux.org/task/44945:

Comment by Jan de Groot (JGC) - Thursday, 04 June 2015, 08:01 GMT
These messages are logged at debug level, you can change syslog config to filter out debug messages.

I will not remove this from Cyrus SASL, as debug logging is the only way to debug issues with SASL when not running interactive, for example when running a mailserver.

Fixed in Debian with 2.1.26.dfsg1-8, per the other bug.

@duke-l, can you confirm this still occurs with Xenial? Given that Xenial shipped with 2.1.26.dfsg1-14build1, which should have the corresponding fix.

@hackel, it seems like you are possibly not using entirely Ubuntu packages (given no php7.0 in 14.04), so it's not entirely clear if your use-case is justification for the 14.04 backport, but I'll open tasks to consider it at least, given the underlying issue is in the Ubuntu package.

Hi Nish,

yup, this still occurs:

root@xxx:~# slapcat -l /tmp/ldap.ldif
root@xxx:~# tail -10 /var/log/auth.log|grep slapcat
Dec 21 13:46:28 xxx slapcat: DIGEST-MD5 common mech free

Cheers,
Tom.

Hello,

we also see hundreds lines like this in xenial.

ii libsasl2-modules:amd64 2.1.26.dfsg1-14build1 amd64

File /etc/logcheck/ignore.d.server/libsasl2-modules with content suggested by hackel is already existent in xenial, it is part of package libsasl2-modules but seems not to work.

Hajo

Hello

Also in xenial but in the apache log I found

Jun 20 10:44:05 localhost apache2: DIGEST-MD5 common mech free
Jun 20 10:44:53 localhost apache2: message repeated 22 times: [ DIGEST-MD5 common mech free]

dpkg -l libsasl2-modules
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture Description
+++-=============================-===================-===================-===============================================================
ii libsasl2-modules:amd64 2.1.26.dfsg1-14buil amd64 Cyrus SASL - pluggable authentication modules

Cheers
Miguel

I also see these on 18.04 bionic server installs ...

See with just running ldapsearch after upgrade to 16.04:

```
# repeat 10 ldapsearch -x > /dev/null
# tail /var/log/auth.log
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
Apr 19 14:53:01 hostname ldapsearch: DIGEST-MD5 common mech free
```

This happens on 20.04 as well:

# lsb_release -d
Description: Ubuntu 20.04 LTS
# repeat 10 ldapsearch -x -b cn=config > /dev/null
# journalctl -n 10
-- Logs begin at Thu 2020-04-23 13:12:44 EDT, end at Wed 2020-07-01 12:20:49 EDT. --
Jul 01 12:20:48 hostname ldapsearch[727817]: DIGEST-MD5 common mech free
Jul 01 12:20:48 hostname ldapsearch[727818]: DIGEST-MD5 common mech free
Jul 01 12:20:48 hostname ldapsearch[727819]: DIGEST-MD5 common mech free
Jul 01 12:20:48 hostname ldapsearch[727820]: DIGEST-MD5 common mech free
Jul 01 12:20:48 hostname ldapsearch[727821]: DIGEST-MD5 common mech free
Jul 01 12:20:49 hostname ldapsearch[727822]: DIGEST-MD5 common mech free
Jul 01 12:20:49 hostname ldapsearch[727823]: DIGEST-MD5 common mech free
Jul 01 12:20:49 hostname ldapsearch[727824]: DIGEST-MD5 common mech free
Jul 01 12:20:49 hostname ldapsearch[727825]: DIGEST-MD5 common mech free
Jul 01 12:20:49 hostname ldapsearch[727826]: DIGEST-MD5 common mech free

There's a "new" (2015) Debian bug for this issue, which I linked to the cyrus-sasl2 task. Apparently the regexp in /etc/logcheck/ignore.d.server/libsasl2-modules which is used to ignore the annoying log message doesn't match the log message format of the newer releases. The Debian bug has a patch for it, however it would be better for this change to land in the Debian package. Ubuntu will then pick it up with the next package sync.

The Debian bug has seen no activity since 2018. I'll try to poke the maintainers.

I proposed a possible workaround here:

  https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=805310

Some feedback on it will certainly be appreciated by the package maintainers.

I don't think that changing the logcheck regexp will help here. The logcheck program doesn't actually prevent messages from being logged to syslog. All it does is scan the existing logs and optionally alert on certain types of messages. The /etc/logcheck/ignore.d.server/libsasl-modules file will prevent logcheck from alerting on certain messages, but the messages are still there in syslog. See the logcheck man page for more info:

http://manpages.ubuntu.com/manpages/focal/man8/logcheck.8.html

This is still valid for jammy. As mentioned by Kartik, in [1], a fix in /etc/logcheck/ignore.d.server/libsasl-modules should not fix the issue of getting the message spammed into the logs.

I found this issue upstream [2] with a relevant comment [3] from 2019. I pinged upstream on this issue since it would be nice to assess whether we could remove the message or find a way to opt out there.

[1] https://bugs.launchpad.net/ubuntu/+source/cyrus-sasl2/+bug/827151/comments/17
[2] https://github.com/cyrusimap/cyrus-sasl/issues/386
[3] https://github.com/cyrusimap/cyrus-sasl/issues/386#issuecomment-504710968

This was fixed in 2.1.28+dfsg-3 and should be picked up in the next merge for the kk development cycle. I am unsure if the priority here would make this eligible for an SRU though.

Fixed in https://launchpad.net/ubuntu/+source/cyrus-sasl2/2.1.28+dfsg-6

Ok, specifically this log message is fixed in 2.1.28:

    DIGEST-MD5 common mech free

Via https://git.launchpad.net/ubuntu/+source/cyrus-sasl2/tree/debian/patches/0001-plugins-digestmd5-Remove-debug-log-mech-free.patch

That patch is just in Ubuntu Kinetic for now.

But I still see a lot of DIGEST-MD5 noise in the logs when I just attempt a DIGEST-MD5 auth:
May 25 19:15:01 k1-sasl-digest ldapwhoami: DIGEST-MD5 client step 2
May 25 19:15:01 k1-sasl-digest ldapwhoami: DIGEST-MD5 parse_server_challenge()
May 25 19:15:01 k1-sasl-digest ldapwhoami: DIGEST-MD5 ask_user_info()
May 25 19:15:03 k1-sasl-digest ldapwhoami: DIGEST-MD5 client step 2
May 25 19:15:03 k1-sasl-digest ldapwhoami: DIGEST-MD5 ask_user_info()
May 25 19:15:03 k1-sasl-digest ldapwhoami: DIGEST-MD5 make_client_response()
May 25 19:15:03 k1-sasl-digest ldapwhoami: DIGEST-MD5 create_layer_keys()
May 25 19:15:03 k1-sasl-digest ldapwhoami: DIGEST-MD5 client mech dispose
May 25 19:15:03 k1-sasl-digest ldapwhoami: DIGEST-MD5 common mech dispose

All except the "common mech free" one ;)

The fix for that was committed 22 days ago: https://github.com/cyrusimap/cyrus-sasl/commit/cb549ef71c5bb646fe583697ebdcaba93267a237

And also affects kinetic. I'll reopen this bug then, as it's the same type of noise in the same plugin.

I applied that patch in cyrus-sasl2 2.1.28 from kinetic, and it did get rid of the other DIGEST-MD5 messages. But I'm having difficulties in finding a client sasl app where I can set log_level to see if with a high log_level I can restore that logging, to make sure it's working.

I tried ldapwhoami from openldap, smtptest from cyrus, and sasl-sample-client from cyrus-sasl2, but they don't seem to read a sasl-specific config file (like in /etc/sasl2/<appname>.conf) where I could set "log_level: 7" for example. I confirmed with strace that they don't even try to open such a config file.

I asked upstream for some guidance, but it's probably just a minor thing. I'll give it some time and then land this, or wait for 2.1.29 which has this committed.

Got a reply[1] from upstream, and this is expected.

I'll go ahead and MP this patch.

1. https://github.com/cyrusimap/cyrus-sasl/commit/cb549ef71c5bb646fe583697ebdcaba93267a237#r74534186

This bug was fixed in the package cyrus-sasl2 - 2.1.28+dfsg-6ubuntu1

---------------
cyrus-sasl2 (2.1.28+dfsg-6ubuntu1) kinetic; urgency=medium

  * d/p/0033-honor-log_level-option-on-clients-too.patch: honor log
    level option on clients (LP: #827151)

 -- Andreas Hasenack <email address hidden> Wed, 25 May 2022 16:41:43 -0300

Since Xenial has reached its end of standard support period, I'm marking this as Won't Fix.