mysqlcheck mariadb 10.11 - too many processes

[Ralph]

Debain12 amd64 & arm64
KH latest

Ich beobachte seit einiger Zeit ein sehr seltsames Verhalten beim ausführen von mysqlcheck unter mariadb 10.11 ...
mysqlcheck generiert hier mitlerweile bei 2 Systemen über 1000 "Idle" processes (alles kworker) ...anfangs ist das nur bei einem arm64 System aufgetreten seit Sonntag auch bei einem amd64. Ca. 30 Datenbanken sind momentan vorhanden, nichts grösseres oder ungewöhnliches dabei.

Sieht so aus als ob mariadb Prozesse nicht richtig beendet oder unnötige öffnet bzw. den Speicher dazu nur verzögert freigibt ... der output von mysqlcheck zeigt keine Fehler, auch nichts im mysql error.log.
Nach 10 min. gehen die Prozesse wieder runter auf 250 ... Problem zeigt sich nur bei einem mysqlcheck.
Bislang zeigen 2 KVM Systeme (16GB RAM, 8 vcore) dieses Verhalten ... im laufenden Betrieb gibt es keine Probleme oder Fehler.

Code: Select all

mysqlcheck --auto-repair --optimize --all-database

Prozesse:
Total 1247
Running 0
Idle 1090
Sleeping 157
Stopped 0
Zombie 0

Code: Select all

Tasks: 1272 total,   1 running, 1271 sleeping,   0 stopped,   0 zombie
%Cpu(s):  2.5 us,  2.9 sy,  0.0 ni, 94.2 id,  0.1 wa,  0.0 hi,  0.2 si,  0.0 st 
MiB Mem :  15613.8 total,    390.9 free,   4675.7 used,  11345.7 buff/cache     
MiB Swap:   5120.0 total,   4605.5 free,    514.5 used.  10938.0 avail Mem 

# 10 min nach dem mysqlcheck
Tasks: 248 total,   1 running, 247 sleeping,   0 stopped,   0 zombie
%Cpu(s): 20.0 us,  0.0 sy,  0.0 ni, 80.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st 
MiB Mem :  15613.8 total,   1485.5 free,   3706.2 used,  11270.6 buff/cache     
MiB Swap:   5120.0 total,   4599.0 free,    521.0 used.  11907.6 avail Mem

# mysqladmin processlist
+-----+---------+-----------+---------+---------+------+----------+------------------+----------+
| Id  | User    | Host      | db      | Command | Time | State    | Info             | Progress |
+-----+---------+-----------+---------+---------+------+----------+------------------+----------+
| 600 | keyhelp | localhost | keyhelp | Sleep   | 72   |          |                  | 0.000    |
| 604 | keyhelp | localhost | keyhelp | Sleep   | 10   |          |                  | 0.000    |
| 629 | root    | localhost |         | Query   | 0    | starting | show processlist | 0.000    |
+-----+---------+-----------+---------+---------+------+----------+------------------+----------+

hab auch mal versucht die Mysql Speichernutzung zu reduzieren - keine Änderung

Code: Select all

[mysqld]
# MySQL Tuning
#max_connections         = 200
key_buffer_size         = 16M
max_allowed_packet      = 16M
thread_stack            = 192K
thread_cache_size       = 8
tmp_table_size          = 32M
max_heap_table_size     = 32M
thread_cache_size       = 150
table_cache             = 8192
table_definition_cache  = 600
open_files_limit        = 32544
max_allowed_packet      = 16M
# InnoDB Configuration
innodb_file_per_table   = 1
innodb_buffer_pool_size = 143M
innodb_log_file_size = 32M
innodb_stats_on_metadata = 0
# Query Cache Configuration
query_cache_type  = 0
query_cache_size   = 0
read_rnd_buffer_size =16K

auch diese berechnung passt nicht wirklich ...

Code: Select all

2024-12-04 10:53:46 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2024-12-04 10:53:46 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.

Resultat:

Code: Select all

Tasks: 1556 total,   1 running, 1555 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.3 us,  0.4 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st 
MiB Mem :  15613.8 total,   1243.2 free,   3790.5 used,  11289.8 buff/cache     
MiB Swap:   5120.0 total,   4599.0 free,    521.0 used.  11823.2 avail Mem

Hab vorhin noch folgendes dazu gefunden:
https://stackoverflow.com/questions/780 ... obs-finish

[Ralph]

Aborted connection warnings - davon gibt es jede Menge ... seht ihr das auch?

Code: Select all

cat /var/log/mysql/error.log | grep error

Code: Select all

2024-12-01 15:06:06 7101 [Warning] Aborted connection 7101 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 15:06:06 7100 [Warning] Aborted connection 7100 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 15:06:06 7099 [Warning] Aborted connection 7099 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 15:06:06 7098 [Warning] Aborted connection 7098 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 15:06:06 7102 [Warning] Aborted connection 7102 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 17:00:05 1398 [Warning] Aborted connection 1398 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 17:00:05 1397 [Warning] Aborted connection 1397 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 17:00:05 1399 [Warning] Aborted connection 1399 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 17:00:05 1400 [Warning] Aborted connection 1400 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)
2024-12-01 17:00:05 1401 [Warning] Aborted connection 1401 to db: 'keyhelp' user: 'keyhelp' host: 'localhost' (Got an error reading communication packets)

auf loglevel 2 ... kurzfristige drops könnten eventl. die vielen Prozesse beim mysqlcheck erklären, ist aber auch eher eine vage Vermutung ...

mysqltuner sagt

You are using n unsupported version for production environments
Upgrade as soon as possible to a supported version !
Your MySQL version 10.11.6-MariaDB-0+deb12u1 is EOL software! Upgrade soon!

außerdem

Code: Select all

[--] Up for: 1h 20m 30s (22K q [4.583 qps], 2K conn, TX: 37M, RX: 4M)
[--] Reads / Writes: 89% / 11%
[--] Binary logging is disabled
[--] Physical Memory     : 15.2G
[--] Max MySQL memory    : 3.1G
[--] Other process memory: 0B
[--] Total buffers: 335.0M global + 18.6M per thread (151 max threads)
[--] P_S Max memory usage: 0B
[--] Galera GCache Max memory usage: 0B
[OK] Maximum reached memory usage: 576.5M (3.69% of installed RAM)
[OK] Maximum possible memory usage: 3.1G (20.11% of installed RAM)
[OK] Overall possible memory usage with other process is compatible with memory available
[OK] Slow queries: 0% (0/22K)
[OK] Highest usage of available connections: 8% (13/151)
[OK] Aborted connections: 0.00%  (0/2596)
[!!] Name resolution is active: a reverse name resolution is made for each new connection and can reduce performance
[OK] Query cache is disabled by default due to mutex contention on multiprocessor machines.
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 382 sorts)
[OK] No joins without indexes
[OK] Temporary tables created on disk: 9% (128 on disk / 1K total)
[OK] Thread cache hit rate: 99% (13 created / 2K connections)
[OK] Table cache hit rate: 77% (20K hits / 25K requests)
[!!] table_definition_cache (600) is less than number of tables (2269) 
[OK] Open file limit used: 1% (987/80K)
[OK] Table locks acquired immediately: 100% (4K immediate / 4K locks)

General recommendations:
    You are using n unsupported version for production environments
    Upgrade as soon as possible to a supported version !
    Check warning line(s) in /var/log/mysql/error.log file
    Check error line(s) in /var/log/mysql/error.log file
    MySQL was started within the last 24 hours - recommendations may be inaccurate
    Configure your accounts with ip or subnets only, then update your configuration with skip-name-resolve=1
    Performance schema should be activated for better diagnostics
Variables to adjust:
    skip-name-resolve=1
    table_definition_cache(600) > 2269 or -1 (autosizing if supported)
    performance_schema=ON
    key_buffer_size (~ 3M)
    innodb_buffer_pool_size (>= 465.8M) if possible.

skip-name-resolve=1 macht soweit ich das in Erinnerung habe irgendwo Probleme ...
ansonsten ist da auch nichts handfestes dabei was die 1000+ idle processes erklären würde.
Sieht für mich eher nach einen mariadb bug aus, vieleicht auch wieder ein plumper (ohne viel überlegen zu müssen) security fix auf die schnelle

### edit ###
habe die tuning.cnf mal nach dem Gutdünken von mysqltuner angepasst, ausser skip-name-resolve ... ändert auch nichts

[Alexander]

You are using n unsupported version for production environments
Upgrade as soon as possible to a supported version !
Your MySQL version 10.11.6-MariaDB-0+deb12u1 is EOL software! Upgrade soon!

Ggf. solltest du mal deinen mysqltuner aktualisieren.

skip-name-resolve=1

Das sollte nur relevant sein, wenn auch Verbindungen darüber reinkommen.

Aborted connection warnings - davon gibt es jede Menge ... seht ihr das auch?

Ab und an treten diese mal auf, laut journalctl konnte ich aber auch nichts spannendes im umliegenden Zeitraum erkennen.
Prinzipiell könnte es sich bei diesen terminierten Verbindungen auch über von Postfix, Dovecot, Amavis, Proftpd aufgebauten Verbindungen handeln, die laufen auch über den `keyhelp` Nutzer.

[Ralph]

Ab und an treten diese mal auf, laut journalctl konnte ich aber auch nichts spannendes im umliegenden Zeitraum erkennen.
Prinzipiell könnte es sich bei diesen terminierten Verbindungen auch über von Postfix, Dovecot, Amavis, Proftpd aufgebauten Verbindungen handeln, die laufen auch über den `keyhelp` Nutzer.

Ja, es wirkt schon etwas mysteriös

Jedenfalls die configs scheinen keinen Einfluß auf dieses mysqlcheck idle processes Problem zu haben ... was die keyhelp User Logs betreffen da habe ich vorhin auch welche einiger User (website requests) gefunden die ebenfalls "Aborted connection" warungen zeigen (websites zeigen keine Probleme).
Also ich denke es ist ein MariaDB Ding ... ob das auch mit mysqlcheck zusammenhängt, könnte sein, aber es könnte auch ein Bug im mysqlcheck Part sein
Die leeren Prozesse verschwinden ja nach 5-10 Minuten wieder und ansonsten kann ich keine echten Fehlfunktionen feststellen ...

Was meinst Du dazu ... kann das ignoriert werden?

[Alexander]

Na wenn es nur auftritt, wenn man mysqlcheck ausführt, sollte es doch kein Problem sein. Ist ja sicher nicht so, dass du permanent mysqlcheck laufen lässt. Ggf. beim Hersteller nachfragen .

Auf meinem test-System (Debian 12, nichts weiter drauf außer KeyHelp), seh ich übrigens nichts ungewöhnliches beim Aufruf von mysqlcheck. Kein wirklicher anstieg der Prozesse etc.

[Tobi]

Abgebrochene Datenbankverbindungen kommen immer und überall vor.
Das ist aus meiner Sicht nix besonderes.
Und auch nix worüber man sich Sorgen machen muss.

[Ralph]

Auf meinem test-System (Debian 12, nichts weiter drauf außer KeyHelp), seh ich übrigens nichts ungewöhnliches beim Aufruf von mysqlcheck. Kein wirklicher anstieg der Prozesse etc.

na ja ... sleeping
Tasks: 1556 total, 1 running, 1555 sleeping

Bisher habe ich dises Verhalten nur bei mariadb 10.11 gesehen bei anderen Systemen mit sehr vielen großen Datenbanken mit z.b. mariadb 10.5, bleiben keine schlafenden Prozesse während dem check ... auch alle vorigen Versionen haben da keine Probleme gemacht.

Vieleicht liegt es hierbei an der --optimize Option wenn ein recreate erfolgt

note : Table does not support optimize, doing recreate + analyze instead

ich teste es später mal ohne --optimize, oder das --optimize als extra task erst nach dem repair

[Ralph]

ja, es wird nur bei Verwendung von --optimize verursacht

Code: Select all

tablexxxx
note     : Table does not support optimize, doing recreate + analyze instead
status   : OK

hab noch flush_method ergänzt, aber da ändert sich nichts weiter

Code: Select all

innodb_flush_log_at_trx_commit  = 0
innodb_flush_method             = O_DIRECT

CPU last ist alles im grünen Bereich ...

mysqltuner

Code: Select all

[!!] Key buffer used: 18.9% (2.5M used / 13.0M cache)
[OK] Key buffer size / total MyISAM indexes: 13.0M/12.6M
[!!] Read Key buffer hit rate: 70.6% (1K cached / 370 reads)
[OK] Write Key buffer hit rate: 98.6% (71 cached / 70 writes)
 
-------- InnoDB Metrics ----------------------------------------------------------------------------
[--] InnoDB is enabled.
[OK] InnoDB File per table is activated
[OK] InnoDB buffer pool / data size: 466.0M/464.8M
[OK] Ratio InnoDB log file size / InnoDB Buffer pool size: 116.0M * 1/466.0M should be equal to 25%
[--] Number of InnoDB Buffer Pool Chunk: 64 for 1 Buffer Pool Instance(s)
[OK] Innodb_buffer_pool_size aligned with Innodb_buffer_pool_chunk_size & Innodb_buffer_pool_instances
[!!] InnoDB Read buffer efficiency: 0% (-28841 hits/ 0 total)
[OK] InnoDB Write log efficiency: 98.24% (422428 hits/ 430003 total)
[OK] InnoDB log waits: 0.00% (0 waits / 7575 writes)

[Ralph]

Damit komme ich dann noch knapp über 1000 anstatt 1500 Prozesse

Code: Select all

mysqlcheck --all-databases --optimize --skip-write-binlog

aber ich habe das --optimize vorerst mal rausgenommen beim mysqlcheck.

Es handelt sich hier nur um "kworker" Prozesse mit 0 % CPU last die bei einem mysqlcheck --optimize "doing recreate + analyze instead" verursacht werden,
vieleicht hat ja noch jemand eine Idee ...

Code: Select all

root       42798  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/0:123-dio/sda1]
root       42799  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/3:102-dio/sda1]
root       42800  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/4:113-dio/sda1]
root       42801  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/5:111-dio/sda1]
root       42802  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/0:124-dio/sda1]
root       42803  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/4:114-dio/sda1]
root       42804  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/5:112-dio/sda1]
root       42805  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/0:125-dio/sda1]
root       42806  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/3:103-dio/sda1]
root       42807  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/4:115-dio/sda1]
root       42808  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/5:113-dio/sda1]
root       42809  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/0:126-dio/sda1]
root       42810  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/3:104-dio/sda1]
root       42811  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/4:116-dio/sda1]
root       42812  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/5:114-dio/sda1]
root       42813  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/0:127-dio/sda1]
root       42814  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/3:105-dio/sda1]
root       42815  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/4:117-dio/sda1]
root       42816  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/5:115-dio/sda1]
root       42817  0.0  0.0      0     0 ?        I    17:28   0:00 [kworker/0:128-dio/sda1]

[Tobi]

aber ich habe das --optimize vorerst mal rausgenommen beim mysqlcheck.

Würde ich definitiv nicht empfehlen.

Ein Backup ohne vorheriges optimize kann zur Folge haben, dass zwar ein Backup erstellt wird, der Restore aber nicht klappt falls die Datenbank gecrasht war.

Ist mir bei Joomla! nicht nur einmal passiert.

[Ralph]

Ein Backup ohne vorheriges optimize kann zur Folge haben, dass zwar ein Backup erstellt wird, der Restore aber nicht klappt falls die Datenbank gecrasht war.

hm, also check und repair werden ja weiterhin ausgeführt

Code: Select all

mysqlcheck --auto-repair --all-databases

aber vieleicht ist es besser so wie Du sagst ... der kurze kworker process peak sollte das System verkraften

Vieleicht liegt es irgendwo im ibdata1 file bzw. ib_buffer_pool, ib_logfile0, ibtmp1 ...
Wenn ich mysql stoppe und die files umbenenne sollten diese doch nach einem mysql start wieder neu angelegt werden, oder?

Code: Select all

systemctl stop mysql
mv /var/lib/mysql/ibdata1 /var/lib/mysql/ibdata1.bak
...
systemctl start mysql

[Ralph]

Default ist table type InnoDB mit innodb_file_per_table ja aktiv ... also sollte ibdata1 von Anfang an damit arbeiten, es sei denn das bei dump imports innodb_file_per_table nicht greift, daher meine Überlegung ibdata1 neu zu generieren (sollte aber somit unnötig sein).
Durch Imports sind hier zwar auch einige MyISAM tables vorhanden, aber das sollte kein Problem darstellen.

Aber wie auch immer, beim reinen mysqlcheck werden auf beiden Systemen keine Fehler gefunden - alles sauber.
Die 1000+ Prozesse werden nur mit der Option "optimize" beim mysqlcheck durch recreate der vielen (standard) InnoDB tables verursacht (vermutlich ein mariadb bug).
Wer eigene Tasks via mysqlcheck durchführt mit vielen DBs und InnoDB tables wird vermutlich auch dieses Verhalten bei mariadb 10.11 feststellen können.

Ist es denn überhaupt noch sinnvoll bei default type InnoDB "optimize" im mysqlcheck (all databases) zu verwenden?
Dies sollte doch ausreichen:

Code: Select all

mysqlcheck --auto-repair --all-databases

InnoDB unterstützt die optimize Option nicht wie bei table type MyISAM, ist quasi nur eine Fake Defragmentierung via recreate.

[Ralph]

Ich hatte wg. dem Prozess Problem heute morgen ein leicht ungutes Gefühl und habe mal auf einem Test System einen Full MySQL Dump importiert
Der Import ca. 330 MB läuft etwa 5 Min. und bricht dann ab mit einem ERROR 1698

import:

Code: Select all

mysql -uroot -p mysql < mysql.sql
# oder
mysql -umysqladmin -p mysql < mysql.sql

Der dump wurde manuell erstellt via:

Code: Select all

mysqldump --opt --system=all --insert-ignore --allow-keywords --flush-logs --hex-blob --quote-names --all-databases > /backup/mysql.sql

Code: Select all

ERROR 1698 (28000) at line 500337: Access denied for user 'root'@'localhost'
ERROR 1698 (28000) at line 500345: Access denied for user 'mysqladmin'@'localhost'

line 500337 usw. ist ein ziemlich am Ende ein Part wo mehrere CREATE USER Befehle ausgeführt werden z.b.

Code: Select all

CREATE USER IF NOT EXISTS `snappymail`@`localhost` IDENTIFIED BY PASSWORD '*xxxxxxxxxxxxxxxxxxxxxxxxxxxxx';

Die Datenbanken und Tablellen scheinen größtenteils importiert zu werden bis zu diesem CREATE USER Part ...

Könnte es daran liegen dass bei der Erstellung eines eigenen Full Backups "--system=all" NICHT verwendet werden darf?

Ich weiß, es gibt auch unter /home/keyhelp/keyhelp.backup/dumps/mysql.sql einen dump, möchte trotzdem gerne wissen was schiefgelaufen ist (teste ich gleich auch noch).

[Ralph]

OK, der keyhelp dump wurde problemlos importiert, hat außerdem ca. 20 MB weniger als meiner
keyhelp dump 363MB (funktioniert incl. user)
custom dump: 381MB (bricht ab mit Access denied)

zum testen standard dump erstellt mit:

Code: Select all

mysqldump -u root -p --all-databases > all-databases.sql

zeigt aber nun
ERROR 1045 (28000): Access denied for user 'mysqladmin'@'localhost' (using password: YES)

Auf dem Test System sehe ich beim mysqlcheck mit --optimize weniger Prozesse, wird wohl daran liegen dass hier nichts produktives drauf läuft:
Tasks: 464 total, 1 running, 463 sleeping

Bitte verratet mir doch wie ich einen brauchbaren custom full dump erstellen kann der importiert werden kann, dann brauche ich heute keine Valium mehr und ich bin Euch ewig dankbar ... und ich verärgere Euch nie wieder (versprochen)

[Ralph]

Am ibdata liegt es nicht, auf dem Testsystem wird es auch nur minimal kleiner und ab mariadb 10.5 wird das von mariadb managed und sollte nicht mehr neu generiert werden ... kann schon mal bei sehr großen Datenbanken vorkommen die dann dadurch entsprechend viele Prozesse generieren, aber bei gerade mal 76 MB, schließe ich es aus.

Code: Select all

76M     /var/lib/mysql/ibdata1

Ich lasse erstmal alles so wie es ist, nur das optimize nehme ich aus meinem task raus.

Eine neue Kategorie "Unerklärliche Phänomene" wäre auch nicht übel