Bug#606350: sasl2-bin: "Too many open files" error with PAM - recovery with saslauthd restart

[Dan White]

On 08/12/10 09:20 -0400, dteed wrote:
>This is working fine - users can authenticate against Active Directory
>when sending email over secure ports 465 and 587 on Postfix.
>
>Once every two weeks or so, saslauthd requires a restart to fix
>a failure to authenticate.  Nothing else needs to be touched
>to remedy the failure.
>
>When the failure appears, this is observed in the auth.log:
>
>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

I'd guess that would be caused by a file descriptor leak, either in
saslauthd itself or in one of your PAM modules.

Can you monitor /proc/<saslauthdpids>/fd/ to see if you can find out what
type of file descriptors are being left open?

-- 
Dan White