I am running a mail server on CentOS 8, using Postfix, Dovecot (virtual users) with MariaDB. ~1 week ago, MariaDB seemingly crashed and deleted most (?!) of the users, but failed "softly" and restarted itself (albeit in a nonfunctioning state). Strangely the data tables were left intact. No idea how this happened, but it took place at or around 21 April: 2 days after updating certs with certbot. TL;DR Why can't Postfix et al connect to MariaDB? I would be eternally thankful for any information... I just want to be able to access my email! Additional Info Postfix (3.3.1) Dovecot (2.3.8) MariaDB (10.3.28) ClamAV, Nginx, OpenDKIM, OpenDMARC, php-fpm, postfixadmin, spamassassin Did the following: Had to reset root password for MariaDB (couldn't login to see what was wrong because users deleted). Saw most users gone; recreated mysql users (postfix, dovecot, postfixadmin) in Mariadb with new passwords Granted pertinent privileges to table postfix_db, postfixadmin_db Updated relevant postfix, dovecot config files with new passwords Commented out the only line plugin-load-add=auth_gssapi.so in /etc/my.cnf.d/auth_gssapi.cnf Logs Code: /var/log/maillog Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Warning: Killed with signal 15 (by pid=1 uid=0 code=kill) Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Error: auth worker: Aborted PASSV request for [email protected]: Shutting down Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Debug: sql([email protected],173.73.24.88,<pXAtUQrBctCtSRhY>): Finished passdb lookup Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Debug: auth([email protected],173.73.24.88,<pXAtUQrBctCtSRhY>): Auth request finished Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Debug: client passdb out: FAIL#0112#[email protected]#011code=temp_fail Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Warning: Timeout leak: 0x55fc0325ba70 (auth-request-handler.c:598) Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Warning: Raw backtrace for leaks: /usr/lib64/dovecot/libdovecot.so.0(io_loop_destroy+0x21c) [0x7f973b94f9dc] -> /usr/lib64/dovecot/libdovecot.so.0(master_service_deinit+0xee) [0x7f973b8c772e] -> dovecot/auth(main+0x53d) [0x55fc0324d80d] -> /lib64/libc.so.6(__libc_start_main+0xf3) [0x7f973a6e87b3] -> dovecot/auth(_start+0x2e) [0x55fc0324d88e] Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Warning: Event 0x55fc03eab910 leaked (parent=0x55fc03ed4350): auth-request.c:880 Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Warning: Event 0x55fc03eb9380 leaked (parent=0x55fc03ed4350): auth-request.c:113 Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Warning: Event 0x55fc03ed4350 leaked (parent=0x55fc03ed3ef0): auth-request.c:112 Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Warning: Event 0x55fc03ed3ef0 leaked (parent=(nil)): auth-client-connection.c:338 Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: imap-login: Debug: Ignoring unknown passdb extra field: temp Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: imap-login: Warning: auth-client: conn unix:login: Auth connection closed with 1 pending requests (max 31 secs, pid=121695, EOF) Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: imap-login: Disconnected: Shutting down (auth process communication failure): user=<[email protected]>, method=LOGIN, rip=173.73.24.88, lip=142.11.253.50, TLS, session=<YeZhTwrBb9CtSRhY> Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: imap-login: Debug: SSL alert: close notify Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: imap-login: Disconnected: Shutting down (auth service reported temporary failure): user=<[email protected]>, method=LOGIN, rip=173.73.24.88, lip=142.11.253.50, TLS, session=<pXAtUQrBctCtSRhY> Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: imap-login: Debug: SSL alert: close notify Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: anvil: Warning: Killed with signal 15 (by pid=1 uid=0 code=kill) Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth-worker(121991): Error: sql([email protected],173.73.24.88,<pXAtUQrBctCtSRhY>): Password query failed: Not connected to database Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth-worker(121991): Debug: sql([email protected],173.73.24.88,<pXAtUQrBctCtSRhY>): Finished passdb lookup Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth-worker(121991): Debug: conn unix:auth-worker (pid=120471,uid=0): auth-worker<1>: Finished Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth-worker(121991): Debug: conn unix:auth-worker (pid=120471,uid=0): Disconnected: Connection closed (fd=-1) Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: stats: Warning: Killed with signal 15 (by pid=1 uid=0 code=kill) Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: log(120465): Warning: Killed with signal 15 (by pid=1 uid=0 code=kill) Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: log(120465): Warning: Shutting down logging for 'auth-worker: ' with 1 clients Apr 28 15:51:02 hwsrv-123456 dovecot[122140]: master: Dovecot v2.3.8 (9df20d2db) starting up for imap, lmtp, pop3 Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Warning: sql: Ignoring changed user_query in /etc/dovecot/dovecot-sql.conf, because userdb sql not used. (If this is intentional, set userdb_warning_disable=yes) Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Debug: auth client connected (pid=122141) Apr 28 15:51:02 hwsrv-123456 dovecot[122144]: auth: Debug: auth client connected (pid=122142) Apr 28 15:51:30 hwsrv-123456 postfix/smtpd[122160]: connect from unknown[203.159.80.219] Apr 28 15:51:30 hwsrv-123456 postfix/smtpd[122160]: warning: connect to Milter service unix:/var/run/spamassassin/spamassassin-milter.sock: No such file or directory Apr 28 15:51:30 hwsrv-123456 postfix/smtpd[122160]: lost connection after AUTH from unknown[203.159.80.219] Apr 28 15:51:30 hwsrv-123456 postfix/smtpd[122160]: disconnect from unknown[203.159.80.219] ehlo=1 auth=0/1 commands=1/2 Apr 28 15:52:02 hwsrv-123456 postfix/pickup[122110]: warning: B2486900008E: message has been queued for 6 days Apr 28 15:52:02 hwsrv-123456 postfix/pickup[122110]: B2486900008E: uid=0 from=<root> Apr 28 15:52:02 hwsrv-123456 opendmarc[4021861]: ignoring connection from localhost Apr 28 15:52:02 hwsrv-123456 postfix/cleanup[122112]: warning: connect to Milter service unix:/var/run/spamassassin/spamassassin-milter.sock: No such file or directory Apr 28 15:52:02 hwsrv-123456 postfix/cleanup[122112]: warning: proxy:mysql:/etc/postfix/sql/virtual_alias_maps.cf lookup error for "root@localhost" Apr 28 15:52:02 hwsrv-123456 postfix/cleanup[122112]: warning: B2486900008E: virtual_alias_maps map lookup problem for root@localhost -- message not accepted, try again later Apr 28 15:52:02 hwsrv-123456 postfix/pickup[122110]: warning: B3391900008E: message has been queued for 5 days Apr 28 15:52:02 hwsrv-123456 postfix/pickup[122110]: B3391900008E: uid=0 from=<root> Apr 28 15:52:02 hwsrv-123456 opendmarc[4021861]: ignoring connection from localhost Apr 28 15:52:02 hwsrv-123456 postfix/cleanup[122112]: warning: connect to Milter service unix:/var/run/spamassassin/spamassassin-milter.sock: No such file or directory Apr 28 15:52:02 hwsrv-123456 postfix/cleanup[122112]: warning: proxy:mysql:/etc/postfix/sql/virtual_alias_maps.cf lookup error for "root@localhost" Apr 28 15:52:02 hwsrv-123456 postfix/cleanup[122112]: warning: B3391900008E: virtual_alias_maps map lookup problem for root@localhost -- message not accepted, try again later Apr 28 15:52:02 hwsrv-123456 postfix/pickup[122110]: warning: B3B59900008E: message has been queued for 4 days Apr 28 15:52:02 hwsrv-123456 postfix/pickup[122110]: B3B59900008E: uid=0 from=<root> Apr 28 15:52:02 hwsrv-123456 opendmarc[4021861]: ignoring connection from localhost Code: /var/log/mariadb/mariadb.log 2021-04-21 6:24:43 0 [Note] /usr/libexec/mysqld (initiated by: unknown): Normal shutdown 2021-04-21 6:24:43 0 [Note] InnoDB: FTS optimize thread exiting. 2021-04-21 6:24:43 0 [Note] Event Scheduler: Purging the queue. 0 events 2021-04-21 6:24:43 0 [Note] InnoDB: Starting shutdown... 2021-04-21 6:24:43 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool 2021-04-21 6:24:43 0 [Note] InnoDB: Buffer pool(s) dump completed at 210421 6:24:43 2021-04-21 6:24:45 0 [Note] InnoDB: Shutdown completed; log sequence number 8327780; transaction id 9783 2021-04-21 6:24:45 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 2021-04-21 6:24:45 0 [Note] /usr/libexec/mysqld: Shutdown complete 2021-04-21 6:24:45 0 [Note] InnoDB: Using Linux native AIO 2021-04-21 6:24:45 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2021-04-21 6:24:45 0 [Note] InnoDB: Uses event mutexes 2021-04-21 6:24:45 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 2021-04-21 6:24:45 0 [Note] InnoDB: Number of pools: 1 2021-04-21 6:24:45 0 [Note] InnoDB: Using SSE2 crc32 instructions 2021-04-21 6:24:45 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M 2021-04-21 6:24:45 0 [Note] InnoDB: Completed initialization of buffer pool 2021-04-21 6:24:45 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2021-04-21 6:24:45 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=10405217 2021-04-21 6:24:45 0 [Note] InnoDB: 128 out of 128 rollback segments are active. 2021-04-21 6:24:45 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2021-04-21 6:24:45 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2021-04-21 6:24:45 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2021-04-21 6:24:45 0 [Note] InnoDB: 10.3.28 started; log sequence number 10405226; transaction id 6978 2021-04-21 6:24:45 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool 2021-04-21 6:24:45 0 [Note] InnoDB: Buffer pool(s) load completed at 210421 6:24:45 2021-04-21 6:24:45 0 [Note] Plugin 'FEEDBACK' is disabled. 2021-04-21 6:24:45 0 [Warning] mysqld: GSSAPI plugin : default principal 'mariadb/hwsrv-123456.hostwindsdns.com@' not found in keytab 2021-04-21 6:24:45 0 [ERROR] mysqld: Server GSSAPI error (major 851968, minor 2529639093) : gss_acquire_cred failed -Unspecified GSS failure. Minor code may provide more information. Keytab FILE:/etc/krb5.keytab is nonexistent or empty. 2021-04-21 6:24:45 0 [ERROR] Plugin 'gssapi' init function returned error. 2021-04-21 6:24:45 0 [Note] Server socket created on IP: '::'. 2021-04-21 6:24:45 0 [Note] Reading of all Master_info entries succeeded 2021-04-21 6:24:45 0 [Note] Added new Master_info '' to hash table 2021-04-21 6:24:45 0 [Note] /usr/libexec/mysqld: ready for connections. Version: '10.3.28-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server 2021-04-21 6:52:59 8 [Warning] Access denied for user 'postfix'@'localhost' (using password: YES) 2021-04-21 7:48:19 9 [Warning] Access denied for user 'postfix'@'localhost' (using password: YES) 2021-04-21 9:07:23 10 [Warning] Access denied for user 'postfix'@'localhost' (using password: YES) Note: mariadb.log files have a gap from 2021-03-08 16:47:32 to 2021-04-21 6:24:43 (which is probably very telling in and of itself) Omitted thousands of identical (save for the timestamp) lines of [Warning] Access denied for user 'postfix'@'localhost' (using password: YES) Config Code: postconf -n alias_database = $alias_maps alias_maps = hash:/etc/postfix/aliases biff = no broken_sasl_auth_clients = yes command_directory = /usr/sbin compatibility_level = 2 daemon_directory = /usr/libexec/postfix data_directory = /var/lib/postfix debug_peer_level = 10 debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5 html_directory = no inet_interfaces = all inet_protocols = ipv4 mail_owner = postfix mailq_path = /usr/bin/mailq.postfix milter_default_action = accept milter_protocol = 2 meta_directory = /etc/postfix mydestination = localhost myorigin = localhost non_smtpd_milters = $smtpd_milters newaliases_path = /usr/bin/newaliases.postfix queue_directory = /var/spool/postfix readme_directory = /usr/share/doc/postfix-2.10.1/README_FILES relay_domains = * sample_directory = /usr/share/doc/postfix-2.10.1/samples sendmail_path = /usr/sbin/sendmail.postfix setgid_group = postdrop shlib_directory = no smtp_tls_security_level = may smtp_tls_loglevel = 1 smtp_use_tls = yes smtpd_milters = unix:/var/run/opendkim/opendkim.sock, unix:/var/run/opendmarc/opendmarc.sock, unix:/var/run/spamassassin/spamassassin-milter.sock smtpd_client_restrictions = permit_mynetworks, permit_sasl_authenticated smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination smtpd_relay_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination smtpd_sasl_auth_enable = yes smtpd_sasl_local_domain = $mydomain smtpd_sasl_path = /var/spool/postfix/private/auth smtpd_sasl_security_options = noanonymous smtpd_sasl_tls_security_options = $smtpd_sasl_security_options smtpd_sasl_type = dovecot smtpd_sender_restrictions = permit_mynetworks, reject_non_fqdn_sender, reject_unknown_sender_domain, permit smtpd_sender_login_maps = proxy:mysql:/etc/postfix/sql/virtual_domains_maps.cf smtpd_tls_auth_only = yes smtpd_tls_cert_file = /etc/ssl/private/fullchain.pem smtpd_tls_key_file = /etc/ssl/private/privkey.pem smtpd_tls_loglevel = 1 smtpd_tls_received_header = yes smtpd_tls_security_level = may smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache smtpd_tls_session_cache_timeout = 3600s smtpd_use_tls = yes virtual_alias_maps = proxy:mysql:/etc/postfix/sql/virtual_alias_maps.cf virtual_gid_maps = static:2000 virtual_mailbox_base = /var/www/mail/vmail virtual_mailbox_domains = proxy:mysql:/etc/postfix/sql/virtual_domains_maps.cf virtual_mailbox_maps = proxy:mysql:/etc/postfix/sql/virtual_mailbox_maps.cf virtual_minimum_uid = 2000 virtual_transport = lmtp:unix:private/dovecot-lmtp virtual_uid_maps = static:2000 unknown_local_recipient_reject_code = 550 Code: /etc/postfix/sql/virtual_alias_maps.cf user = postfix password = hosts = localhost dbname = postfix_db table = alias select_field = goto where_field = address /etc/postfix/sql/virtual_domains_maps.cf user = postfix password = hosts = localhost dbname = postfix_db table = domain select_field = domain where_field = domain /etc/postfix/sql/virtual_mailbox_maps.cf user = postfix password = hosts = localhost dbname = postfix_db table = mailbox select_field = maildir where_field = username Code: doveconf -n auth_debug = yes auth_mechanisms = plain login auth_verbose = yes default_login_user = vmail first_valid_gid = 2000 first_valid_uid = 2000 listen = * log_timestamp = "%Y-%m-%d %H:%M:%S " mail_access_groups = vmail mail_debug = yes mail_location = maildir:/var/www/mail/vmail/%d/%n namespace inbox { inbox = yes location = mailbox Drafts { auto = subscribe special_use = \Drafts } mailbox Junk { auto = subscribe special_use = \Junk } mailbox Sent { auto = subscribe special_use = \Sent } mailbox Trash { auto = subscribe special_use = \Trash } prefix = separator = / type = private } passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } protocols = imap lmtp pop3 service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0600 user = postfix } user = root } service imap-login { inet_listener imaps { port = 993 } process_min_avail = 1 user = vmail } service lmtp { unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0600 user = postfix } } service pop3-login { inet_listener pop3s { port = 995 } process_min_avail = 1 user = vmail } ssl = required ssl_cert = </etc/ssl/private/fullchain.pem ssl_dh = # hidden, use -P to show it ssl_key = # hidden, use -P to show it ssl_prefer_server_ciphers = yes userdb { args = /etc/dovecot/dovecot-sql.conf driver = static } verbose_ssl = yes Code: /etc/my.cnf [mysqld] datadir=/var/lib/mysql socket=/var/lib/mysql/mysql.sock #symbolic-links=0 skip-networking [mysqld_safe] log-error=/var/log/mariadb/mariadb.log pid-file=/var/run/mariadb/mariadb.pid # # include all files from the config directory # !includedir /etc/my.cnf.d #bind-address=127.0.0.1 innodb_flush_log_at_trx_commit=1 sync_binlog=1 [client] socket=/var/lib/mysql/mysql.sock
Not as recently as I would have liked. I had to eventually throw in the towel and just remake the tables. The database was more corrupted than my initial findings as of this posting may have indicated. All the databases and tables were present, but upon closer inspection there were no rows in them. Call it the 'neutron bomb' -- left the database "structures" standing but wiped out all the "inhabitants" (data). I've never seen anything quite like it. This is my personal email server, and while the data loss was minimal the time loss was not. Something I did not take into account when I postponed updating my backup scripts to make them more specific. Would give my right thumb to know what precipitated this...
