(cyrus-imapd) auxpropfunc error invalid parameter supplied というエラーメッセージ

FreeBSDで、portsでインストールしたcyrus-imapdにて、

Oct 19 23:02:55 ホスト imap[42169]: auxpropfunc error invalid parameter supplied
Oct 19 23:41:45 ホスト lmtpunix[43597]: auxpropfunc error invalid parameter supplied
Oct 20 10:26:22 ホスト pop3s[5554]: auxpropfunc error invalid parameter supplied

というエラーメッセージが、頻繁に出るという問題が、ずっと前からありました。とくにメールが読めないわけでもなく、単にエラーメッセージがログに残るだけなので、まあいいか、と１年くらい放置していました。たまに、googleを使って調べたりしたけど、よくわからなかったし・・・

ただ、あまりにもログの量が多くて、log rotationですぐにログが消えてしまったり、newsyslog.confでログの保管期間を延ばしてやっても、重要なメッセージが埋もれて見逃す危険性もあります。

というわけで、先日、もう一度調べなおしてみたところ、cyrus-sasl2のldapdbプラグインのせいだ、との情報を見つけました。ただ、それしか書いてなかったので、どうすればいいのかわからなかったので、自力で調査してみました。

☆　☆　☆　☆　☆　☆　

私がいつもやっている調査の進め方。FreeBSDでportsを使っているから、簡単にできます。

cd /usr/ports/mail/cyrus-imapd2
make patch

のようにやって、ソース（FreeBSDパッチつき）を展開します

ソフトが出力するメッセージをキーワードにして、grepで、ソースコードの該当箇所を探します

あとは、ソースを眺めたり、printfデバッグをしたり、gdbでattachしてみたりするなど・・・

簡単じゃないですかね。泥臭いですね。ま、それも人生。

☆　☆　☆　☆　☆　☆　

auxpropfunc error invalid parameter suppliedというエラーメッセージは、auxprop.cで発生しています。どうやら、各種プラグインの初期化処理を行っているところで、初期化に失敗すると、エラーコードに応じたメッセージが表示される、ということのようです。

どのプラグインでエラーが発生したのか、まったくわからないので、auxprop.cを書き換えて、プラグインの名前を表示させるようにしました。

/* add an auxiliary property plugin */
int sasl_auxprop_add_plugin(const char *plugname,
                            sasl_auxprop_init_t *auxpropfunc)
{
    int result, out_version;
    auxprop_plug_list_t *new_item;
    sasl_auxprop_plug_t *plug;

    result = auxpropfunc(sasl_global_utils, SASL_AUXPROP_PLUG_VERSION,
                         &out_version, &plug, plugname);

    if(result != SASL_OK) {
        _sasl_log(NULL, SASL_LOG_ERR, "auxpropfunc error %s (plugin=%s)\n",
                  sasl_errstring(result, NULL, NULL),plugname);
        return result;
    }

そして、portsを使っているので、makeでコンパイル、make installでインストール。
portsの中で作業をしていると、すでにコンパイル済みのものはコンパイルされないし、インストール済みだとインストールされないので、その時々の状況に応じて、portsのworkディレクトリ内にある「.ほにゃらら」ファイルを削除したり、make FORCE_PKG_REGISTER=yes install とやって、上書きインストールしたりします。

さて、/var/log/messageを見てると、こんなかんじのログが記録されたので、やはりldapdbプラグインのせいでした。

Oct 20 15:28:33 ホスト pop3[45025]: auxpropfunc error invalid parameter supplied (plugin=ldapdb)
Oct 20 15:28:39 ホスト imap[45028]: auxpropfunc error invalid parameter supplied (plugin=ldapdb)
Oct 20 15:29:32 ホスト lmtpunix[45094]: auxpropfunc error invalid parameter supplied (plugin=ldapdb)

なお、cyrus-sasl2のldapdbプラグインは、/usr/ports/security/cyrus-sasl2-ldapdb/ から、別途インストールするようになっています。

そもそも、そのメールサーバでは、『メールを読むときの認証で使うパスワードを、LDAPに登録したパスワードにしたかった』、という希望があったため、ldapdbプラグインをインストールしていました。

ところが、実際には、ldapdbプラグインで認証するような設定にはしてなくて、imapdから、saslauthdにいき、saslauthdはpamを見に行き、pamでpam_ldapにより認証される、という動作になっていました。

認証の流れ

imapd ⇒ saslauthd ⇒ pam ⇒ pam_ldap

どうせLDAPでパスワードを統一するなら、ログイン認証などでも、pam_ldapを使うように設定しているはずでしょう。それなら、pam_ldapに任せてしまうことにすれば、わざわざcyrus-sasl2-ldapdb用に、新たにLDAPサーバの設定をする手間が減っていいじゃん、と考えていたのでした。

ldapdb.cをじっくり調べてみたところ、以下のところで、エラーになっていることがわかりました。可観測にするために、_sasl_log()を追加して、printfデバッグをやっています。

   utils->getopt(utils->getopt_context, ldapdb, "ldapdb_uri", &tmp.uri, NULL);
    _sasl_log(NULL, SASL_LOG_ERR, "ldapdb_auxprop_plug_init (plugin=%s) uri=%s\n", plugname, tmp.uri);
    if(!tmp.uri) return SASL_BADPARAM;

どうやら、ldapdbプラグインが、ldapdb_uriというパラメータを取得できなかった、つまりどのLDAPサーバを使っていいかわからないので、エラーにしているようです。

はい、たしかに設定してないので、ここでエラーになってしまうのも納得です。

プラグインは使うか使わないかわからないものなのに、このようなコードだと、LDAPサーバを指定していないと必ずエラーメッセージがでてしまうので、これはこれで少しコードの側に問題があると思いますが・・・

というわけで、auxpropfunc error invalid parameter suppliedのエラーを出なくするようにするには、一番簡単な方法としては、ldapdbプラグインを削除してしまうこと(pkg_delete cyrus-sasl2-ldapdbしてしまう)、となりました。

FreeBSDのportsでインストールした場合、プラグインは、/usr/local/lib/sasl2/にあるので、一時的に別ディレクトリに移動させてしまう、というのもいいかもしれません。

もうひとつの方法としては、ldapdb_uriというパラメータを設定してやる、というものも考えられます。

後者の方法を、試してみました。えーと、かなり手ごわかったです。そもそも、このパラメータを、どこで、どう指定するのか、わかりません。

いろいろやって、ようやく探り当てました。

cyrus-imapdを使っているわけなので、cyrus-imapdの設定ファイルに書きます。/usr/local/etc/imapd.conf になります。

このファイル中に、sasl_ldapdb_uriというキーワードで、指定します。たとえば、こんな感じです。

sasl_ldapdb_uri: ldap://127.0.0.1

いろいろなドキュメントを熟読してわかったのですが、cyrus-imapdでは、cyrus-sasl2用の設定を読み込むのに、cyrus-imapd独自のパーザを使っていて、設定キーワードの先頭に「sasl2_」がプレフィックスとして付加されるそうなのです。

ちなみに、もともと、

sasl_pwcheck_method: saslauthd

とも書いてありました。
FreeBSDでは、saslauthdを動かすために、/etc/rc.confで、

saslauthd_enable="YES"

と書きますが、もうデフォルトで設定されるパラメータとして、

saslauthd_flags="-a pam"

となっていて、このために、saslauthdは、pamを見にいくようです。

もう１つ別の方法として、プラグインがロードされないようにすればいい、と考えて、

sasl_auxprop_plugin: crammd4 plain

とかいてみたけど、だめでした。なんでだろう？

☆　☆　☆　☆　☆　☆　

いろんなソフトが要求するので、cyrus-sasl2はインストールしてはあったものの、私はぜんぜんSASLを理解していなかったんですね。最近、たくさんのドキュメントを読んで、ようやく理解しはじめてきたところです。

testsaslauthdというコマンドがあって、単純な動作テストに便利そうです。

実行例
# testsaslauthd -u nhh -p thisisapen -s AAA
0: NO "authentication failed"

/var/log/auth.logに、こんな風に出てきます。

Oct 20 17:24:42 ほげ saslauthd[62290]: do_auth         : auth failure: [user=nhh] [service=AAA] [realm=] [mech=pam] [reason=PAM auth error]