Postfix/Dovecot 崩潰後無法連接到 MariaDB

我在 CentOS 8 上使用Postfix、Dovecot（虛擬使用者）和MariaDB執行郵件伺服器。

大約 1 週前，Mariadb 似乎崩潰並刪除了大多數（？！）使用者，但“軟”失敗並重新啟動（儘管處於非執行狀態）。奇怪的是，數據表完好無損。不知道這是怎麼發生的，但它發生在 4 月 21 日左右：使用certbot更新證書後 2 天。

TL；DR為什麼 postfix et al 不能連接到 MariaDB？首先是什麼導致了它？如何？

我將永遠感謝能夠訪問我的電子郵件的任何資訊！

附加資訊

系統：

• 後綴 (3.3.1)
• 鴿舍 (2.3.8)
• MariaDB (10.3.28)
• ClamAV、Nginx、OpenDKIM、OpenDMARC、php-fpm、postfixadmin、spamassassin

做了以下事情：

1. 必須重置 MariaDB 的 root 密碼（由於使用者已刪除，無法登錄以查看問題所在）。
2. 看到大多數使用者消失了；使用新密碼在 Mariadb 中重新創建了 mysql 使用者 ( postfix, dovecot, )postfixadmin
3. 授予 table 相關權限postfix_db，postfixadmin_db
4. 使用新密碼更新了相關的 postfix、dovecot 配置文件
5. 註釋掉唯一的plugin-load-add=auth_gssapi.so一行/etc/my.cnf.d/auth_gssapi.cnf

• 這減少了很多警告/錯誤

日誌

/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 admin@domain3.com: Shutting down
Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Debug: sql(admin@domain3.com,173.73.24.88,<pXAtUQrBctCtSRhY>): Finished passdb lookup
Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Debug: auth(admin@domain3.com,173.73.24.88,<pXAtUQrBctCtSRhY>): Auth request finished
Apr 28 15:51:02 hwsrv-123456 dovecot[120465]: auth: Debug: client passdb out: FAIL#0112#011user=admin@domain3.com#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=<admin@domain6.com>, 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=<admin@domain3.com>, 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(admin@domain3.com,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(admin@domain3.com,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

/var/log/mariadb/mariadb.log

注意：mariadb.log文件之間有間隔（這本身可能很2021-03-08 16:47:32能說明問題）2021-04-21 6:24:43

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)

省略：數千個相同的（除了時間戳）行[Warning] Access denied for user 'postfix'@'localhost' (using password: YES)

配置

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
manpage_directory                   = /usr/share/man
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

tls_random_source                   = dev:/dev/urandom

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

/etc/postfix/sql/virtual_alias_maps.cf

/etc/postfix/sql/virtual_domains_maps.cf

/etc/postfix/sql/virtual_mailbox_maps.cf

user = postfix
password = abcdefg12345
hosts = localhost
dbname = postfix_db
table = alias
select_field = goto
where_field = address


user = postfix
password = abcdefg12345
hosts = localhost
dbname = postfix_db
table = domain
select_field = domain
where_field = domain


user = postfix
password = abcdefg12345
hosts = localhost
dbname = postfix_db
table = mailbox
select_field = maildir
where_field = username

doveconf -n

# 2.3.8 (9df20d2db): /etc/dovecot/dovecot.conf
# OS: Linux 4.18.0-240.10.1.el8_3.x86_64 x86_64 CentOS Linux release 8.3.2011 xfs
# Hostname: hwsrv-123456.hostwindsdns.com

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

/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

猜測？

鑑於

• MariaDB 崩潰了（有點災難性地），

其次是

1. 無法連接到 mariadb，
2. 許多錯誤的基於配置的錯誤（例如 gssapi 選項），以及
3. 該時間段沒有日誌文件（可能被覆蓋），

…從邏輯上講，MariaDB 因可能的損壞/破壞而崩潰？並通過一些無意義的設置恢復到恢復狀態或預設狀態。

TL;DR：故事的寓意是定期備份您的數據庫（比我更經常）。最終不得不認輸，只是重新製作桌子。

這是我的個人電子郵件伺服器，雖然數據失去很小，但時間損失卻不是。當我推遲更新我的備份腳本以使它們更具體、包羅萬象時，我沒有考慮到一些事情。

該數據庫的損壞程度比我在此發佈時的初步調查結果可能表明的要嚴重。所有數據庫和表都存在，但仔細檢查後發現其中沒有行。稱之為“中子炸彈”——讓數據庫“結構”保持原狀，但消滅所有“居民”（數據）。

會讓我的右手拇指知道是什麼導致了這個……

引用自：https://serverfault.com/questions/1061905