Created attachment 199685 [details] saslauthd core dump Saslauthd exits with signal 11 after a failed smtp auth. Release: FreeBSD 11.2-RELEASE-p2 Packages: cyrus-imapd30-3.0.8_1 cyrus-sasl-2.1.27 cyrus-sasl-saslauthd-2.1.27 cyrus-sasl-sql-2.1.27 pam_mysql-0.7.r1_5 postfix-3.3.2_1,1 Backtrace (saslauthd.core): (gdb) bt #0 0x000000080277db7a in pthread_rwlock_rdlock () from /lib/libthr.so.3 #1 0x000000080386482f in free_vio_ssl_acceptor_fd () from /usr/local/lib/mysql/libmysqlclient.so.20 #2 0x000000080465a201 in ssl_cipher_get_evp () from /usr/lib/libssl.so.8 #3 0x000000080465c4d9 in SSL_COMP_get_compression_methods () from /usr/lib/libssl.so.8 #4 0x0000000804624b2c in SSL_library_init () from /usr/lib/libssl.so.8 #5 0x0000000803863cae in ssl_start () from /usr/local/lib/mysql/libmysqlclient.so.20 #6 0x000000080383127f in mysql_server_init () from /usr/local/lib/mysql/libmysqlclient.so.20 #7 0x000000080383ad37 in mysql_init () from /usr/local/lib/mysql/libmysqlclient.so.20 #8 0x0000000803403c0f in ?? () #9 0x0000000000000000 in ?? () (gdb) /usr/local/sbin/saslauthd -a pam -c -m /var/run/saslauthd -r -n 1 -d log: saslauthd[37708] :num_procs : 1 saslauthd[37708] :mech_option: NULL saslauthd[37708] :run_path : /var/run/saslauthd saslauthd[37708] :auth_mech : pam saslauthd[37708] :mmaped shared memory segment on file: /var/run/saslauthd/cache.mmap saslauthd[37708] :bucket size: 96 bytes saslauthd[37708] :stats size : 36 bytes saslauthd[37708] :timeout : 28800 seconds saslauthd[37708] :cache table: 985828 total bytes saslauthd[37708] :cache table: 1711 slots saslauthd[37708] :cache table: 10266 buckets saslauthd[37708] :flock file opened at /var/run/saslauthd/cache.flock saslauthd[37708] :using accept lock file: /var/run/saslauthd/mux.accept saslauthd[37708] :master pid is: 0 saslauthd[37708] :listening on socket: /var/run/saslauthd/mux saslauthd[37708] :using process model saslauthd[37708] :acquired accept lock saslauthd[37708] :released accept lock saslauthd[37708] :attempting a read lock on slot: 183 saslauthd[37708] :[login=xxx@xxx.xxx] [service=smtp] [realm=xxx.xxx]: not found, update pending saslauthd[37708] :attempting to release lock on slot: 183 saslauthd[37708] :auth failure: [user=xxx@xxx.xxx] [service=smtp] [realm=xxx.xxx] [mech=pam] [reason=PAM auth error] saslauthd[37708] :acquired accept lock saslauthd[37708] :released accept lock saslauthd[37708] :attempting a read lock on slot: 183 saslauthd[37708] :[login=xxx@xxx.xxx] [service=smtp] [realm=xxx.xxx]: not found, update pending saslauthd[37708] :attempting to release lock on slot: 183 Segmentation fault (core dumped) /var/log/maillog: Nov 30 13:22:05 host postfix/smtpd[40472]: warning: SASL authentication failure: Password verification failed Nov 30 13:22:05 host postfix/smtpd[40472]: warning: xxx.xxx.xxx[ddd.ddd.ddd.ddd]: SASL PLAIN authentication failed: authentication failure Nov 30 13:22:06 host postfix/smtpd[40472]: warning: SASL authentication failure: size read failed Nov 30 13:22:06 host postfix/smtpd[40472]: warning: xxx.xxx.xxx[ddd.ddd.ddd.ddd]: SASL LOGIN authentication failed: generic failure
(In reply to Alexandru Ciobanu from comment #0) Is this with OpenSSL 1.0.2 or 1.1.0+
(In reply to Nathan from comment #1) % openssl version OpenSSL 1.0.2o-freebsd 27 Mar 2018
(In reply to Alexandru Ciobanu from comment #2) Building in poudriere with that version of OpenSSL to see if I can find the suspecting files; My theory is ports r485191 update fixed the build for OpenSSL 1.1.0+ but doesn't have conditionals for older OpenSSL
(In reply to Nathan from comment #3) After trying to fix it, I believe I'm not going to be able to, sorry
(In reply to Nathan from comment #4) Thank you for this hint! Using openssl111-1.1.1a seems to work indeed. I've rebuilt pam_mysql and cyrus-sasl-saslauthd; saslauthd works as expected, no segmentation violation. # grep "ssl" /etc/make.conf DEFAULT_VERSIONS+=ssl=openssl111 # ldd /usr/local/lib/pam_mysql.so /usr/local/lib/pam_mysql.so: libmysqlclient.so.20 => /usr/local/lib/mysql/libmysqlclient.so.20 (0x801400000) libz.so.6 => /lib/libz.so.6 (0x8019b7000) libm.so.5 => /lib/libm.so.5 (0x801bcf000) librt.so.1 => /usr/lib/librt.so.1 (0x801dfc000) libexecinfo.so.1 => /usr/lib/libexecinfo.so.1 (0x802002000) libssl.so.11 => /usr/local/lib/libssl.so.11 (0x802205000) libcrypto.so.11 => /usr/local/lib/libcrypto.so.11 (0x802600000) libcrypt.so.5 => /lib/libcrypt.so.5 (0x802ae2000) libthr.so.3 => /lib/libthr.so.3 (0x802d01000) libc.so.7 => /lib/libc.so.7 (0x800823000) libssl.so.8 => /usr/lib/libssl.so.8 (0x802f29000) libcrypto.so.8 => /lib/libcrypto.so.8 (0x803200000) libc++.so.1 => /usr/lib/libc++.so.1 (0x80366f000) libcxxrt.so.1 => /lib/libcxxrt.so.1 (0x80393d000) libgcc_s.so.1 => /lib/libgcc_s.so.1 (0x803b5c000) libelf.so.2 => /lib/libelf.so.2 (0x803d6b000) # /usr/local/sbin/saslauthd -a pam -c -m /var/run/saslauthd -r -n 1 -d saslauthd[11497] :num_procs : 1 saslauthd[11497] :mech_option: NULL saslauthd[11497] :run_path : /var/run/saslauthd saslauthd[11497] :auth_mech : pam saslauthd[11497] :mmaped shared memory segment on file: /var/run/saslauthd/cache.mmap saslauthd[11497] :bucket size: 96 bytes saslauthd[11497] :stats size : 36 bytes saslauthd[11497] :timeout : 28800 seconds saslauthd[11497] :cache table: 985828 total bytes saslauthd[11497] :cache table: 1711 slots saslauthd[11497] :cache table: 10266 buckets saslauthd[11497] :flock file opened at /var/run/saslauthd/cache.flock saslauthd[11497] :using accept lock file: /var/run/saslauthd/mux.accept saslauthd[11497] :master pid is: 0 saslauthd[11497] :listening on socket: /var/run/saslauthd/mux saslauthd[11497] :using process model saslauthd[11497] :acquired accept lock saslauthd[11497] :released accept lock saslauthd[11497] :attempting a read lock on slot: 183 saslauthd[11497] :[login=xxx@xxx.xxx] [service=smtp] [realm=xxx.xxx]: not found, update pending saslauthd[11497] :attempting to release lock on slot: 183 saslauthd[11497] :auth failure: [user=xxx@xxx.xxx] [service=smtp] [realm=xxx.xxx] [mech=pam] [reason=PAM auth error] saslauthd[11497] :acquired accept lock
For what it's worth, using openssl-1.0.2q,1 crashes saslauthd too: #0 0x00000008022b8b7a in pthread_rwlock_rdlock () from /lib/libthr.so.3 #1 0x0000000803c6482f in free_vio_ssl_acceptor_fd () from /usr/local/lib/mysql/libmysqlclient.so.20 #2 0x0000000804a4fd41 in ssl_cipher_get_evp () from /usr/local/lib/libssl.so.9 #3 0x0000000804a51ff9 in SSL_COMP_get_compression_methods () from /usr/local/lib/libssl.so.9 #4 0x0000000804a56bcc in SSL_library_init () from /usr/local/lib/libssl.so.9 #5 0x0000000803c63cae in ssl_start () from /usr/local/lib/mysql/libmysqlclient.so.20 #6 0x0000000803c3127f in mysql_server_init () from /usr/local/lib/mysql/libmysqlclient.so.20 #7 0x0000000803c3ad37 in mysql_init () from /usr/local/lib/mysql/libmysqlclient.so.20 #8 0x0000000803803c0f in ?? () #9 0x0000000000000000 in ?? ()
As far as I can see your back trace, it seems something wrong in mysql through pam.
Indeed. The PAM debug log doesn't give too much info: Dec 9 11:57:19 host saslauthd[95523]: in openpam_dispatch(): calling pam_sm_authenticate() in /usr/local/lib/pam_mysql.so Dec 9 11:57:19 host saslauthd[95523]: in pam_get_data(): entering: 'pam_mysql' Dec 9 11:57:19 host saslauthd[95523]: in pam_get_data(): returning PAM_NO_MODULE_DATA Dec 9 11:57:19 host saslauthd[95523]: in pam_set_data(): entering: 'pam_mysql' Dec 9 11:57:19 host saslauthd[95523]: in pam_set_data(): returning PAM_SUCCESS Dec 9 11:57:19 host saslauthd[95523]: in pam_get_user(): entering Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): entering: PAM_USER Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): returning PAM_SUCCESS Dec 9 11:57:19 host saslauthd[95523]: in pam_get_user(): returning PAM_SUCCESS Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): entering: PAM_RHOST Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): returning PAM_SUCCESS Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): entering: PAM_AUTHTOK Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): returning PAM_SUCCESS Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): entering: PAM_CONV Dec 9 11:57:19 host saslauthd[95523]: in pam_get_item(): returning PAM_SUCCESS Dec 9 11:57:19 host saslauthd[95523]: in pam_set_item(): entering: PAM_AUTHTOK Dec 9 11:57:19 host saslauthd[95523]: in pam_set_item(): returning PAM_SUCCESS Dec 9 11:57:19 host saslauthd[95523]: in openpam_dispatch(): /usr/local/lib/pam_mysql.so: pam_sm_authenticate(): authentication error Dec 9 11:57:19 host saslauthd[95523]: DEBUG: auth_pam: pam_authenticate failed: authentication error Any hints about debugging this are greatly appreciated.