On Mon, Oct 05, 2015 at 10:39:54PM +0200, Patrick Wagner wrote:

> Oh, and I found the following post on the cyrusl-sasl mailing list, posted by 
> Alexej Melnikov in 2006 - so there was (still is?) maybe something special 
> about Postfix's handling of cyrus-sasl?
> http://lists.andrew.cmu.edu/pipermail/cyrus-sasl/2006-April/000377.html

The Postfix callback only logs debug messages if "msg_verbose >
0", i.e. you've enabled verbose logging in Postfix with "-v" in
master.cf or debug_peer_list, ...

This is indeed insensitive to the log_level in the SASL configuration
file.  Otherwise for debug logging you'd need both "-v" in Postfix,
and a high debug level in the SASL config file.

Note however, that Postfix logging of Cyrus debug messages is tagged
with prefixes:

    msg_info("SASL authentication info: %s", message);
    msg_info("SASL authentication info: %s", message);
    msg_info("SASL authentication debug: %s", message);
    msg_info("SASL authentication trace: %s", message);
    msg_info("SASL authentication pass: %s", message);

you did not report any such prefixes in your log samples.

    Oct 05 11:55:01 mail postfix/smtpd[5883]: sql plugin try and connect to a 
host

Furthermore, you report messages in the "auth" log, but Postfix
logs to the mail log.

So the conclusion is that Cyrus is logging directly to syslog,
bypassing the Postfix logging callback.  Looks like something
similar to:

    http://lists.andrew.cmu.edu/pipermail/cyrus-sasl/2011-February/002185.html

Indeed looking at plugins/sql.c in a recent Debian Cyrus SASL package I see:

    sparams->utils->log(NULL, SASL_LOG_DEBUG,
    sparams->utils->log(NULL, SASL_LOG_DEBUG, "begin transaction");
    sparams->utils->log(NULL, SASL_LOG_DEBUG, "commit transaction");
    utils->log(NULL, SASL_LOG_DEBUG,
    utils->log(NULL, SASL_LOG_DEBUG, "sql freeing memory\n");
    utils->log(NULL, SASL_LOG_DEBUG, "sql plugin: %d", rc);
    utils->log(NULL, SASL_LOG_DEBUG, "sql plugin: %s ",
    utils->log(NULL, SASL_LOG_DEBUG, "sql plugin: %s ", zErrMsg);
    utils->log(NULL, SASL_LOG_DEBUG, "sql plugin: %s", zErrMsg);

That NULL, should be the connection handle, so that the Postfix
callback is actually found!  This bug seems to be present in the
latest commits at

    https://cgit.cyrus.foundation/cyrus-sasl/tree/plugins/sql.c

Can you take this to the Cyrus IMAP list, or the Debian/Ubuntu
maintainers?

-- 
        Viktor.

Reply via email to