Still having lots of mysql errors

ozy · 2024-10-22T08:01:17+00:00

Hello, Running current gromox-2.35.0.g5b29178-lp155.1.1.x86_64, I still got lots of mysql errors: 2024-10-22 0:12:37 1930 [Warning] Aborted connection 193...

ozy

Mine are on 15.5 so I don't think this matters 😉

@mwilliams Let me know if you need any more info for this, thank you

WalterH

I have one system on 15.6, no errors in systemd logging, second system is a 15.5 system, also no errors.
I search for errors, with this command: journalctl | grep "Got timeout reading communication packets". I also searched with journalctl | grep "Aborted connection" but I did not found any errors.

crpb

/var/log/mysql/mysqld.log

WalterH

15.6 System, the errors have disappeared since 22.11.2024, this was the update date to 15.6.
On 15.5 system, I see some of these errors in log. Will update to 15.6 on weekend and report back.

ozy

So I did upgrade my home server to 15.6 (thank you for the tutorial btw).

But I still get those same mysql errors. It took about 8 hours for the first errors to show up

2024-11-25 21:43:11 0 [Note] Starting MariaDB 10.11.9-MariaDB source revision 0e8fb977b00983d98c4c35e39bc1f36463095938 server_uid CzjX84zIt+PNvBguxsELxwGNBKw= as process 1543
2024-11-25 21:43:11 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
2024-11-25 21:43:11 0 [Note] InnoDB: Number of transaction pools: 1
2024-11-25 21:43:11 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
2024-11-25 21:43:11 0 [Note] InnoDB: Using Linux native AIO
2024-11-25 21:43:11 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
2024-11-25 21:43:11 0 [Note] InnoDB: Completed initialization of buffer pool
2024-11-25 21:43:11 0 [Note] InnoDB: Buffered log writes (block size=512 bytes)
2024-11-25 21:43:11 0 [Note] InnoDB: End of log at LSN=1770278584
2024-11-25 21:43:11 0 [Note] InnoDB: 128 rollback segments are active.
2024-11-25 21:43:11 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2024-11-25 21:43:11 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
2024-11-25 21:43:11 0 [Note] InnoDB: log sequence number 1770278584; transaction id 7312143
2024-11-25 21:43:11 0 [Note] Plugin 'FEEDBACK' is disabled.
2024-11-25 21:43:11 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2024-11-25 21:43:11 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-25 21:43:11 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.11.9-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-25 21:43:12 0 [Note] InnoDB: Buffer pool(s) load completed at 241125 21:43:12
2024-11-26  5:43:12 8 [Warning] Aborted connection 8 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-11-26  5:43:12 19 [Warning] Aborted connection 19 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-11-26  5:43:12 18 [Warning] Aborted connection 18 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-11-26  5:43:12 21 [Warning] Aborted connection 21 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-11-26  5:43:14 13 [Warning] Aborted connection 13 to db: 'grochat' user: 'grochat' host: 'localhost' (Got timeout reading communication packets)
2024-11-26  6:43:12 7286 [Warning] Aborted connection 7286 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-11-26  7:43:12 14579 [Warning] Aborted connection 14579 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-11-26  8:43:12 21855 [Warning] Aborted connection 21855 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)

Current mariadb setup is grommunio's vanilla setup, and is of course 15.6:

mail:/usr/libexec/gromox # rpm -qa | grep mariadb
mariadb-errormessages-10.11.9-150600.4.6.1.noarch
mariadb-10.11.9-150600.4.6.1.x86_64
mariadb-client-10.11.9-150600.4.6.1.x86_64
libmariadb3-3.1.22-150600.16.3.x86_64

crpb

Well i almost thought so but did wanna try first because one live system has the following config too and still showed a few errors but i actually added these settings on both fresh systems and nothing happened till then.
and i think

/etc/my.cnf.d/grommunio.cnf

[mariadb]
connect_timeout=3600
max_allowed_packet=256M
net_read_timeout=3600
net_write_timeout=3600
read_rnd_buffer_size=8M
sort_buffer_size=8M
table_cache=1000
thread_cache_size=512
wait_timeout=288000

but those settings are not unknown to you so i guess you also have them still enabled?

I will point my finger in the direction of grommunio-index for now 🙊

ozy

but those settings are not unknown to you so i guess you also have them still enabled?

So I tried to be as much "grommunio-vaniall" as possible, hence I disabled my tuning file.
I've created it again, let's see what hapens in the next few days.
I've also checked that they are well applied with SHOW GLOBAL VARIABLES LIKE "%timeout%"

@WalterH Would you mind giving the output of SHOW GLOBAL VARIABLES LIKE '%log_warning%'; ?

WalterH

Hope this helps?

MariaDB [(none)]> SHOW GLOBAL VARIABLES LIKE '%log_warning%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_warnings  | 2     |
+---------------+-------+
1 row in set (0.003 sec)

MariaDB [(none)]>

Same value on most systems.

ozy

@WalterH Well I wondered if your setup just didn't log the warnings (eg log_warnings=1), since this was default in earlier mariadb versions. Depending on your setup age, perhaps defaults could have been kept.

So, I've updated to OpenSUSE 15.6 + latest gromox 2.37 and applied the mariadb tuning.
I still got these errors.

crpb

Well, maybe you could enable some debug loggin in mysqld to see which friggin client/application is connecting and which doesn't do the sane thing of saying goodbye when it's finished?

maybe this: https://mariadb.com/kb/en/error-log/#verbosity-level-4

or even go nuts and use '9' 😛

WalterH

Interesting, on some SuSE 15.6 systems, I do not see this errors. On some 15.6 systems I also see this errors. Fortunately placing this configuration file and restarting mariadb helps a lot.

Edit /etc/my.cnf.d/grommunio.cnf and add this content:

# fix for grommunio abort connection to db ...
# https://community.grommunio.com/d/1769-solved-mail-delivery-issues-for-popimap-in-latest-grommunio-releases/5
[mariadb]
wait_timeout=288000
connect_timeout = 3600
#

Restart Maria DB
systemctl restart mysql

crpb

WalterH wait_timeout=288000

Now that value is just nasty! and i must confess i didn't see it until this moment... o_0..
Will change that to something *sane* everywhere now..

EDIT: and the default is also a bit bonkers (8Hours) https://mariadb.com/kb/en/server-system-variables/#wait_timeout

WalterH

crpb 288000 is 8 hours.

crpb

WalterH 288000 is 8 hours.

remove a zero and i'm with you 😛

echo $((288000/60/60)) $((28800/60/60))

crpb

Anyhow, reduced it to '3600' and watching for anything but i guess this won't affect anything other than not using 80/eighty hours anymore 😛

2024-11-28 20:48:33 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:33 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.11.9-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:33 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:33

───────────────────────────────────────────────────────────────────────
2024-11-28 20:54:56 0 [Note] Added new Master_info '' to hash table
2024-11-28 20:54:56 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:54:56 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:54:56

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:26 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:26 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.11.9-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:26 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:26

───────────────────────────────────────────────────────────────────────
2024-11-28 20:54:31 0 [Note] Added new Master_info '' to hash table
2024-11-28 20:54:31 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:54:31 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:54:31

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:31 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:31 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:31 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:31

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:32 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:32 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.11.9-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:32 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:32

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:32 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:32
2024-11-28 20:48:32 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:32 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:32 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:32 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:32 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:32

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:32 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:32 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:32 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:32

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:11 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:11 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:11 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:11

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:30 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:30 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:31 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:31

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:33 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:33 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:33 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:33

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:32 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:32 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:32 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:32

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:32 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:32 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:32 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:32

───────────────────────────────────────────────────────────────────────
2024-11-28 20:48:32 0 [Note] Plugin 'FEEDBACK' is disabled.
2024-11-28 20:48:32 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-11-28 20:48:32 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.6.18-MariaDB'  socket: '/run/mysql/mysql.sock'  port: 3306  MariaDB package
2024-11-28 20:48:32 0 [Note] InnoDB: Buffer pool(s) load completed at 241128 20:48:32

WalterH

We will see.

crpb

i additionally activated the following on two test-systems to see which fooding query(id) was actually used to maybe find out where it's coming from.

general_log
general_log_file=/var/log/mysql/mariadb.log

i wouldn't recommend it on a live system 😛

crpb

If you can, set the mysql-stuff to less than 80 hours and here comes the finisher:

disable grommunio-fetchmail.timer if not needed
I again got *hourly* warnings and looked through the timers and that one was just spitting in my eye.

Will see how it behaves during the week but i think we have a winner.

Why this would happen with that timer/service i can't really imagine other than there would be some kind icky leftover state when it's finished and that especially on systems which don't even use fetchmail.
And this would just survive because the admin-api will keep it alive. But that is most likely as a grommunio-admin call does spent some time on talking to it's api as we know :>

WalterH

I guess, this have nothing to do with fetchmail.

I see this errors a random time, here the list from today:

2024-12-02  0:48:51 5998 [Warning] Aborted connection 5998 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  1:13:15 6070 [Warning] Aborted connection 6070 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  1:48:51 6201 [Warning] Aborted connection 6201 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  2:48:51 6415 [Warning] Aborted connection 6415 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  3:25:19 6662 [Warning] Aborted connection 6662 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  3:27:23 6665 [Warning] Aborted connection 6665 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  3:37:47 6695 [Warning] Aborted connection 6695 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  3:48:51 6753 [Warning] Aborted connection 6753 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  4:48:51 6956 [Warning] Aborted connection 6956 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  5:25:36 7066 [Warning] Aborted connection 7066 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  5:48:51 7140 [Warning] Aborted connection 7140 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  6:48:52 7330 [Warning] Aborted connection 7330 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  7:48:52 7558 [Warning] Aborted connection 7558 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  8:19:51 7683 [Warning] Aborted connection 7683 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  8:21:45 7692 [Warning] Aborted connection 7692 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  8:22:44 7990 [Warning] Aborted connection 7990 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  8:22:44 7989 [Warning] Aborted connection 7989 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  8:43:40 8064 [Warning] Aborted connection 8064 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  8:43:40 8063 [Warning] Aborted connection 8063 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  8:48:51 7824 [Warning] Aborted connection 7824 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  9:24:03 8244 [Warning] Aborted connection 8244 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  9:24:03 8243 [Warning] Aborted connection 8243 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  9:41:06 8088 [Warning] Aborted connection 8088 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)
2024-12-02  9:42:14 8412 [Warning] Aborted connection 8412 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  9:42:14 8411 [Warning] Aborted connection 8411 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got an error reading communication packets)
2024-12-02  9:48:51 8125 [Warning] Aborted connection 8125 to db: 'grommunio' user: 'grommunio' host: 'localhost' (Got timeout reading communication packets)

I also see communication errors and timeouts!
System is on Open SuSE 15.6 with latest grommunio 2.37.0.ae11dd0.

ozy

@mwilliams Do you have enough data yet ?

« Previous Page