| View previous topic :: View next topic |
| Author |
Message |
hanj
Veteran
Joined: 19 Aug 2003
Posts: 1487
|
 Posted: Tue Dec 04, 2018 3:07 pm Post subject: Got an error reading communication packets - mysql-5.7 |
 |
|
Hello
Since upgrading mysql to 5.7, I'm starting to see these in the mysqld.err logs from our virtmail system
| Code: |
2018-12-04T10:35:15.357762Z 7876 [Note] Aborted connection 7876 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T10:35:15.357783Z 7877 [Note] Aborted connection 7877 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T11:05:05.580072Z 8505 [Note] Aborted connection 8505 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T11:05:05.580072Z 8506 [Note] Aborted connection 8506 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T12:10:06.454693Z 9689 [Note] Aborted connection 9689 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T12:10:06.454702Z 9690 [Note] Aborted connection 9690 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T13:26:18.692548Z 11216 [Note] Aborted connection 11216 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T13:26:18.692569Z 11215 [Note] Aborted connection 11215 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T13:51:44.509329Z 11722 [Note] Aborted connection 11722 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T13:51:44.509467Z 11723 [Note] Aborted connection 11723 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T14:39:58.555844Z 12409 [Note] Aborted connection 12409 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T14:39:58.555879Z 12408 [Note] Aborted connection 12408 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets)
2018-12-04T14:45:06.126867Z 12719 [Note] Aborted connection 12719 to db: 'postfix' user: 'postfix' host: 'xxx.xxx.xxx.xxx' (Got an error reading communication packets) |
I've been chasing this problem. I emerged mysqltuner and did some tweaking to values, but these are creeping in. Not sure what the actual error from postfix is. Not seeing a matching issue in the mail logs. And mail *seems* to be working fine. I was having similar issues with amavis, but the tweaks may have taken care of those.
I made sure I ran mysql_upgrade after updating mysql, so tables should be good. I added skip-name-resolve yesterday, and I thought that fixed things, until this morning where I found these new errors.
Here are my USE flags for mysql:
| Code: | | [ebuild R ] dev-db/mysql-5.7.24:0/18::gentoo USE="latin1 perl server -cjk (-client-libs) -cracklib -debug -experimental -jemalloc -libressl -numa -profiling (-selinux) -static -static-libs -systemtap -tcmalloc -test -yassl" ABI_X86="(64) -32 (-x32)" 48,280 KiB |
Here is my my.cnf
| Code: | [client]
port = 3306
socket = /var/chroot/apache/var/run/mysqld/mysqld.sock
[mysql]
character-sets-dir=/usr/share/mysql/charsets
default-character-set=latin1
[mysqladmin]
character-sets-dir=/usr/share/mysql/charsets
default-character-set=latin1
[mysqlcheck]
character-sets-dir=/usr/share/mysql/charsets
default-character-set=latin1
[mysqldump]
character-sets-dir=/usr/share/mysql/charsets
default-character-set=latin1
[mysqlimport]
character-sets-dir=/usr/share/mysql/charsets
default-character-set=latin1
[mysqlshow]
character-sets-dir=/usr/share/mysql/charsets
default-character-set=latin1
[myisamchk]
character-sets-dir=/usr/share/mysql/charsets
[myisampack]
character-sets-dir=/usr/share/mysql/charsets
[mysqld_safe]
err-log = /var/log/mysql/mysql.err
[mysqld]
character-set-server = latin1
user = mysql
port = 3306
connect_timeout = 60
skip-name-resolve
socket = /var/chroot/apache/var/run/mysqld/mysqld.sock
pid-file = /var/run/mysqld/mysqld.pid
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow-queries.log
long_query_time = 1
log-error = /var/log/mysql/mysqld.err
basedir = /usr
datadir = /var/lib/mysql
skip-external-locking
key_buffer_size = 360M
max_allowed_packet = 1M
table_open_cache = 66
sort_buffer_size = 512K
net_buffer_length = 8K
read_buffer_size= 256K
read_rnd_buffer_size = 512K
myisam_sort_buffer_size = 8M
lc_messages_dir = /usr/share/mysql
lc_messages = en_US
sql_mode=''
skip_ssl
bind-address = xxx.xxx.xxx.xxx
query_cache_type = 1
query-cache-size = 20M
server-id = 1
tmpdir = /tmp/
innodb_buffer_pool_size = 36M
innodb_data_file_path = ibdata1:10M:autoextend:max:128M
innodb_log_file_size = 5M
innodb_log_buffer_size = 8M
innodb_log_files_in_group=2
innodb_flush_log_at_trx_commit = 1
innodb_lock_wait_timeout = 50
innodb_file_per_table
[mysqldump]
quick
max_allowed_packet = 16M
[mysql]
[isamchk]
key_buffer_size = 360M
sort_buffer_size = 20M
read_buffer = 2M
write_buffer = 2M
[myisamchk]
key_buffer_size = 20M
sort_buffer_size = 20M
read_buffer_size = 2M
write_buffer_size = 2M
[mysqlhotcopy]
interactive-timeout |
I also added slow-queries.log hoping to find something there. There was something this morning, but was related to our nightly backup with 'backadmin' user, nothing from postfix in there.
Any ideas?
Thanks!
hanji
_________________
Server Admin Blog - Uno-Code.com |
|
| Back to top |
|
 |
Hupf
Tux's lil' helper
Joined: 11 Sep 2005
Posts: 112
Location: Germany
|
|
| Back to top |
|
|
hanj
Veteran
Joined: 19 Aug 2003
Posts: 1487
|
| Posted: Wed Dec 05, 2018 6:59 pm Post subject: |
|
|
Thanks for the reply, but that's not the problem. I'm not having lookup failures related to postfix virtmail happening. My problem is related to communication packet error from mysql. The postfix virtmail handling appears to be working fine. These errors are intermittent. Also... side note, I provided the solution in the thread you provided 
hanji
_________________
Server Admin Blog - Uno-Code.com |
|
| Back to top |
|
|
Hupf
Tux's lil' helper
Joined: 11 Sep 2005
Posts: 112
Location: Germany
|
| Posted: Wed Dec 05, 2018 10:36 pm Post subject: |
|
|
| hanj wrote: | | Also... side note, I provided the solution in the thread you provided |
D'oh! You're right, didn't notice. Also your mail problem had occured some time ago. In my case however, there was a strong correlation between the two issues, i.e. whenever postfix unsuccessfully attempted to process a mail (eventually yielding the 451 reject), it would try to invoke cyrus-sasl or (tried both during debugging) courier-authlib, using sql_engine mysql. For each rejected mail, a corresponding "error reading communication packets" would be thrown. Setting "smtpd -v" in master.cf would eventually get me to the bit:
| Code: | Dec 4 03:22:50 xxx postfix/smtpd[12927]: dict_mysql: successful connection to host unix:/var/run/mysqld/mysqld.sock
Dec 4 03:22:50 xxx postfix/smtpd[12927]: maps_find: virtual_alias_maps: xxx@xxx.de: search aborted
Dec 4 03:22:50 xxx postfix/smtpd[12927]: mail_addr_find: xxx@xxx.de -> (try again) |
So maybe you could check if you have another similar configuration problem at a place that is just not critical to successful mail delivery? I.e. maybe you could also increase verbosity of your smtpd for a while and check for any "search aborted" entries which could correlate with the mysqld errors? |
|
| Back to top |
|
|
hanj
Veteran
Joined: 19 Aug 2003
Posts: 1487
|
| Posted: Thu Dec 06, 2018 2:34 pm Post subject: |
|
|
| Hupf wrote: | | hanj wrote: | | Also... side note, I provided the solution in the thread you provided |
D'oh! You're right, didn't notice. Also your mail problem had occured some time ago. In my case however, there was a strong correlation between the two issues, i.e. whenever postfix unsuccessfully attempted to process a mail (eventually yielding the 451 reject), it would try to invoke cyrus-sasl or (tried both during debugging) courier-authlib, using sql_engine mysql. For each rejected mail, a corresponding "error reading communication packets" would be thrown. Setting "smtpd -v" in master.cf would eventually get me to the bit:
| Code: | Dec 4 03:22:50 xxx postfix/smtpd[12927]: dict_mysql: successful connection to host unix:/var/run/mysqld/mysqld.sock
Dec 4 03:22:50 xxx postfix/smtpd[12927]: maps_find: virtual_alias_maps: xxx@xxx.de: search aborted
Dec 4 03:22:50 xxx postfix/smtpd[12927]: mail_addr_find: xxx@xxx.de -> (try again) |
So maybe you could check if you have another similar configuration problem at a place that is just not critical to successful mail delivery? I.e. maybe you could also increase verbosity of your smtpd for a while and check for any "search aborted" entries which could correlate with the mysqld errors? |
Interesting. Are you talking about raising the level on /etc/sasl2/smtpd.conf? I'm not seeing anything in the logs, but I bet my log level is lower.
_________________
Server Admin Blog - Uno-Code.com |
|
| Back to top |
|
|
Hupf
Tux's lil' helper
Joined: 11 Sep 2005
Posts: 112
Location: Germany
|
| Posted: Fri Dec 07, 2018 11:03 am Post subject: |
|
|
No, I was talking about /etc/postfix/master.cf
| Code: | # ==========================================================================
# service type private unpriv chroot wakeup maxproc command + args
# (yes) (yes) (no) (never) (100)
# ==========================================================================
smtp inet n - n - - smtpd -v |
This of course increases log size and should be switched off again after some time. |
|
| Back to top |
|
|
hanj
Veteran
Joined: 19 Aug 2003
Posts: 1487
|
| Posted: Fri Dec 07, 2018 6:00 pm Post subject: |
|
|
| Hupf wrote: | No, I was talking about /etc/postfix/master.cf
| Code: | # ==========================================================================
# service type private unpriv chroot wakeup maxproc command + args
# (yes) (yes) (no) (never) (100)
# ==========================================================================
smtp inet n - n - - smtpd -v |
This of course increases log size and should be switched off again after some time. |
Interesting! Never added the -v there before. Awesome. I'll do some testing over the weekend.
Thanks!
hanji
_________________
Server Admin Blog - Uno-Code.com |
|
| Back to top |
|
|
hanj
Veteran
Joined: 19 Aug 2003
Posts: 1487
|
| Posted: Sat Dec 08, 2018 3:31 pm Post subject: |
|
|
| Hupf wrote: | No, I was talking about /etc/postfix/master.cf
| Code: | # ==========================================================================
# service type private unpriv chroot wakeup maxproc command + args
# (yes) (yes) (no) (never) (100)
# ==========================================================================
smtp inet n - n - - smtpd -v |
This of course increases log size and should be switched off again after some time. |
I ran with this flag for a few hours. I saw a few mysql errors so I started digging. And found nothing out of the ordinary relating to postfix or mysql in the mail logs. I wish I could recreate the notice on my end. Very intermittent and random.
Thanks!
hanji
_________________
Server Admin Blog - Uno-Code.com |
|
| Back to top |
|
|
|
Networking & Security
