I have a Postfix mail server running Debian Squeeze. SASL authentication for secure SMTP is supported by saslauthd which relies on pam, which relies on winbind.
This pattern seems to be reoccuring every couple of weeks:
- Initially, there are no errors in /var/log/auth.log - postfix SMTP is working well
Errors appear in the log after a week or more:
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM unable to dlopen(/lib/security/pam_winbind.so): /lib/security/pam_winbind.so: cannot open shared object file: Too many open files Dec 5 15:45:22 myhostname saslauthd[32586]: PAM adding faulty module: /lib/security/pam_winbind.so
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM unable to dlopen(/lib/security/pam_deny.so): /lib/security/pam_deny.so: cannot open shared object file: Too many open files
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM adding faulty module: /lib/security/pam_deny.so
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM _pam_load_conf_file: unable to open /etc/pam.d/common-auth
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM error loading (null)
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM _pam_init_handlers: error reading /etc/pam.d/other
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM _pam_init_handlers: [Critical error - immediate abort]
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM error reading PAM configuration file
Dec 5 15:45:22 myhostname saslauthd[32586]: PAM pam_start: failed to initialize handlers
Dec 5 15:45:22 myhostname saslauthd[32586]: DEBUG: auth_pam: pam_start failed: Critical error - immediate abort
Dec 5 15:45:22 myhostname saslauthd[32586]: do_auth : auth failure: [user=dteed] [service=smtp] [realm=] [mech=pam] [reason=PAM start error]
Dec 5 15:45:32 myhostname saslauthd[32586]: server_exit : master exited: 32586
Dec 5 15:45:32 myhostname saslauthd[1696]: detach_tty : master pid is: 1696
Dec 5 15:45:32 myhostname saslauthd[1696]: ipc_init : listening on socket: /var/run/saslauthd/mux
At this time authentication will always fail. It can be verified in testsaslauthd. Simply restarting saslauthd corrects the problem for another week or two.
I've searched for the error on too many open files and there is nothing solid on what this indicates. Some of the pam modules it complains cannot be opened have nothing to do with the job saslauthd is handling of simply SASL authentication over winbind.
Here is the /etc/pam.d/smtp :
account required pam_permit.so
auth sufficient pam_winbind.so debug
auth required pam_deny.so
I don't want to run saslauthd in the debug (foreground) method. I don't think I need more saslauthd processes - I'm running 5 and this was sufficient on a previous lower powered server. The secure SMTP is an option which is not widely used by our users, but there is probably one connection every couple of minutes using it.
This seems to be a reported bug in samba's winbind, although it was saslauthd which complained. Here is the bug report:
https://bugzilla.samba.org/show_bug.cgi?id=7265
A workaround, until this is released, is to restart winbind and saslauthd every few days (in a cron).