MySQL beállítása sok konkurens kéréssel

Fórumok

Sziasztok,

Az alábbi problémával fordulnék hozzátok, melyre nem találom a jól működő megoldást:
Adott egy MySQL szerver rajta egy nem túl bonyolult 100 táblás adatbázis MySQL alapon. Az adatbázist egy szoftveren keresztül 60 ember használja egyszerre. Ez alapvetően nem sok, de mégis nagyon gyakori az alábbi két hibaüzenet:
- Deadlock found when trying to get lock; try restarting transaction
- Lock wait timeout exceeded; try restarting transaction

Illetve egy ráadás üzenet, ami bár nem biztos a konkurens kérésekkel függ össze, de mégis gyakori és látszólag semmi nem indokolja:
- Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding
Az üzenet arról árulkodik, hogy gond lenne az adatbázis szerver válaszadásával, vagy elérhetetlen lenne, vagy bármi hasonló probléma. De ez nem igaz, mert a mellette ülő (programot használó) gond nélkül használja a rendszert.

Végül pedig a log fájl, amit a MySQL szerver vezet az alábbi sorokkal van tele folyamatosan:
2018-11-21T07:41:39.653890Z 123605 [Note] Aborted connection 123605 to db: '' user: '' host: '192.168.1.252' (Got timeout reading communication packets)
2018-11-21T07:42:01.564092Z 123894 [Note] Aborted connection 123894 to db: '' user: '' host: '192.168.1.252' (Got timeout reading communication packets)
2018-11-21T07:42:06.961086Z 123786 [Note] Aborted connection 123786 to db: '' user: '' host: '192.168.1.252' (Got timeout reading communication packets)
2018-11-21T07:42:17.027146Z 124046 [Note] Aborted connection 124046 to db: '' user: '' host: '192.168.1.252' (Got timeout reading communication packets)
2018-11-21T07:42:29.759601Z 122790 [Note] Aborted connection 122790 to db: '' user: '' host: '192.168.1.252' (Got timeout reading communication packets)
2018-11-21T07:43:15.211959Z 121478 [Note] Aborted connection 121478 to db: '' user: '' host: '192.168.1.252' (Got timeout reading communication packets)

Próbáltam már program kód szinten megoldani, mert sok helyen lehet arról olvasni, hogy a programba a lekérdezéseket kell kicsit másképp megfogalmazni, de ez mind mese habbal. Olyan nyaka tekert megoldásokat javasolnak, ami abszolút nem életszerű.

Nem tudom merre keressem a hibát. Másra már nem tudok gondolni, mint hogy a szerver beállításain kellene csiszolnom. Találkozott már valaki hasonlóval? Oldott már meg valaki hasonló problémát? Előre is köszönöm az építő jellegű hozzászólásokat.

MySQL szerver konfig beállításai:

[mysqld]
#
# * Basic Settings
#
character-set-server = utf8
user = mysql
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
port = 3306
basedir = /usr
datadir = /var/lib/mysql
tmpdir = /tmp
lc-messages-dir = /usr/share/mysql
max_connections = 100
skip-external-locking

connect_timeout = 10
interactive_timeout = 100
wait_timeout = 100

#
# Instead of skip-networking the default is now to listen only on
# localhost which is more compatible and is not less secure.
bind-address = 0.0.0.0
#bind-address = 127.0.0.1

#
# * Fine Tuning
#
key_buffer_size = 128M
join_buffer_size = 16M
max_allowed_packet = 128M
table_open_cache = 128M
sort_buffer_size = 1024K
net_buffer_length = 64K
read_buffer_size = 1024K
read_rnd_buffer_size = 1024K
myisam_sort_buffer_size = 8M
thread_stack = 192K
thread_cache_size = 8
tmp_table_size = 24M
max_heap_table_size = 24M

sql_mode = STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION

# This replaces the startup script and checks MyISAM tables if needed
# the first time they are touched
myisam-recover-options = BACKUP
thread_cache_size = 16K
#table_cache = 64

#
# * Query Cache Configuration
#
query_cache_type = 1
query_cache_size = 32M
query_cache_limit = 16M

#
# * Logging and Replication
#
# Both location gets rotated by the cronjob.
# Be aware that this log type is a performance killer.
# As of 5.1 you can enable the log at runtime!
#general_log_file = /var/log/mysql/mysql.log
#general_log = 1

#
# Error log - should be very few entries.
#
log_error = /var/log/mysql/error.log

#
# Here you can see queries with especially long duration
slow_query_log = 1
slow_query_log_file = /var/log/mysql/mysqld_slow_queries.log
long_query_time = 1
#log-queries-not-using-indexes

#
# The following can be used as easy to replay backup logs or for replication.
# note: if you are setting up a replication slave, see README.Debian about
# other settings you may need to change.
server-id = 1
#log_bin = /var/log/mysql/mysql-bin.log
expire_logs_days = 10
max_binlog_size = 100M
#binlog_do_db = include_database_name
#binlog_ignore_db = include_database_name

#
# * InnoDB
#
# InnoDB is enabled by default with a 10MB datafile in /var/lib/mysql/.
# Read the manual for more InnoDB related options. There are many!
# the rest of the innodb config follows:
# don't eat too much memory, we're trying to be safe on 64Mb boxes
# you might want to bump this up a bit on boxes with more RAM
innodb_buffer_pool_size = 128M
# you may wish to change this size to be more suitable for your system
# the max is there to avoid run-away growth on your machine
innodb_data_file_path = ibdata1:10M:autoextend
# we keep this at around 25% of of innodb_buffer_pool_size
# sensible values range from 1MB to (1/innodb_log_files_in_group*innodb_buffer_pool_size)
innodb_log_file_size = 48M
# this is the default, increase it if you have very large transactions going on
innodb_log_buffer_size = 8M
# this is the default and won't hurt you
# you shouldn't need to tweak it
innodb_log_files_in_group=2
# see the innodb config docs, the other options are not always safe
innodb_flush_log_at_trx_commit = 1
innodb_lock_wait_timeout = 50
innodb_deadlock_detect = 0
innodb_file_per_table

# Uncomment this to get FEDERATED engine support
#plugin-load=federated=ha_federated.so
loose-federated

#
# * Security Features
#
# Read the manual, too, if you want chroot!
# chroot = /var/lib/mysql/
#
# For generating SSL certificates I recommend the OpenSSL GUI "tinyca".
#
# ssl-ca=/etc/mysql/cacert.pem
# ssl-cert=/etc/mysql/server-cert.pem
# ssl-key=/etc/mysql/server-key.pem

Hozzászólások

Amikor én elosztott adatbázissal programozok (optimista konkurenciakezeléssel), az az alap, hogy minden tranzakció egy retry loopban fut. Mondjuk ez nem MySQL-es tapasztalat, de itt is működhet.

- Deadlock found when trying to get lock; try restarting transaction
- Lock wait timeout exceeded; try restarting transaction

Ez a teljesen normális viselkedés, ha nincs kapcsolatszakadása

- Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding

Ez nem mysql-s hanem valami microsoft .net-s ugye? Dekstop alkalmazás? Persistens a mysql kapcsolat?

2018-11-21T07:43:15.211959Z 121478 [Note] Aborted connection 121478 to db: '' user: '' host: '192.168.1.252' (Got timeout reading communication packets)
interactive_timeout = 100
wait_timeout = 100
Ezek a timeout-ok nem ütköznek a program működésével? Simán okozhatják a connection timeout-t, időben hosszú távú kapcsolat esetében

kapcsold be a teljes logot és nézd meg milyen queryket hajtanak végre ezek a connectionok (pl 121478), ez alapján betud azonosítani a kódban a funkciót remélhetőleg

Amit megnéznék kódban pl exceptionok esetében megy-e rollback, vagy záródik-e a kapcsolat

Igen C# program desktopra.

A deadlock úgy is normális, hogy én ezt elvileg kikapcsoltam? (innodb_deadlock_detect = 0)
Nem szeretném, ha a lock miatt exceptiont generálna... várja meg a sorát a query és fusson le.

Logolok mindent, de nem látok összefüggéseket.

Minden kérés try...catch-be van és a catch ágban rollback. De amikor a kapcsolat szakad le, akkor sajnos vannak félbe hagyott kérések, ezért is a feltett kérés, mert kezd a rendszer inkonzisztens lenni.

Hát szerintem nem, mert az alábbi van a doksiban... Ez a deadlock detect konfignál:
This option is used to disable deadlock detection. On high concurrency systems, deadlock detection can cause a slowdown when numerous threads wait for the same lock. At times, it may be more efficient to disable deadlock detection and rely on the innodb_lock_wait_timeout setting for transaction rollback when a deadlock occurs.

Ez pedig a innodb_lock_wait_timeout:
The length of time in seconds an InnoDB transaction waits for a row lock before giving up. The default value is 50 seconds. A transaction that tries to access a row that is locked by another InnoDB transaction waits at most this many seconds for write access to the row before issuing the following error:

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

nincs gondom a deadlock probléma körének értelmezésével...

két külön tranzakció ugyan azon szeretne módosítani, az erősebb kutya b...ik alapon a másik deadlockot kap, de miért férhet hozzá egy másik tranzakció ahhoz, amit más használ?

azt nem értem, hogy ez szerver beállítási probléma, vagy pedig programozási probléma, viszont azt tudom, hogy nagyon nagy gázokat okoz a rendszerbe most ez a 3 jelenség

Nem az a lenyeg hogy ugyanazon szeretnenek modositani, hanem hogy egyik tranzakcio var a masikra es a masik tranzakcio var az egyikre hogy befejezodjon, de mivel egymasra varnak ez nem fog megtortenni hacsak nem timeout-ol el az egyik.
Ezeket a programodban illene kivedeni ahol erre esely van.

https://dev.mysql.com/doc/refman/8.0/en/innodb-deadlocks.html
"This section builds on the conceptual information about deadlocks in Section 14.7.5.2, “Deadlock Detection and Rollback”. It explains how to organize database operations to minimize deadlocks and the subsequent error handling required in applications. "

De hogy védesz ki a programba egy tábla lock-ot két külön gépen futó alkalmazás számára? Ezt a szervernek kellene valahogy kezelni, hiszen mi garantálja a programban azt, hogy két egyszerre indított kérés esetén nem mind a kettő azt a választ kapja, hogy szabad a pálya.

Ezer és ezer féle módon írtam már át a kódot, de lényegében nem változott semmi. Mindig ugyan ez a hiba együttes jött.

Használok egy másik alkalmazáshoz postgresql-t... ott még csak hasonló hiba sincs, pedig az elérés logikája ugyan az, amit az garantál, hogy azt is én írtam. Ott is valahogy az adatbázis rendszer oldja meg, hogy a helyére kerüljön minden.

Látni kéne, hogy mik azok a tranzakciók, amik deadlock-olódnak, akkor jóval egyszerűbb lenne konkrét javaslatot adni.

Egy javaslat, még nem hangzott el, de ilyenkor szokott felmerülni, hogy az egész tranzakció kezelést átírjuk egy saját rendszerre, ami gyakorlatilag egy singleton, és egy message queue, mielőtt ebbe belekezdenél, mindenképp írd meg a tranzakciók tartalmát ide, mert ez alapján nagyon esélyes, hogy csak azokat kell módosítani majd.

Máshogy: ezt fejtsd ki: "Olyan nyaka tekert megoldásokat javasolnak, ami abszolút nem életszerű."

Program kódra gondolsz, ami deadlockra szokott futni? Ezer féle módja van annak, hogy deadlockra fut a kód, ezer féle query-nél. De lényegében mindegyik ugyan arra vezethető vissza, viszont kódot úgy tudnék mutatni, ha ide másolom a fél kódbázist. Ez így most lehet, hogy hülyén hangzik, de mégis ez az igazság.
Naplózva lett minden adatbázis hiba (már amikor nem a kapcsolattan van probléma). Szinte minden querynél előfordul, napszaktól is függ, mert minden napszakban más az, amit többet használnak. Reggel az egyik funkciót nyomkodja mindenki, aztán egy másikra térnek át, majd délután felé kezdik úgy használni a programot, hogy mindenki mást csinál. Tehát nem igazán tudom ide másolni azt a kód részletet, ami ezt okozhatja.

Nincs erre tipikus példa, hogy hogyan orvosolnak egy ilyet, mert a tipikus példán keresztül szerintem már rá tudnám a rendszerre húzni.

Hát pl ez: https://stackoverflow.com/questions/2332768/how-to-avoid-mysql-deadlock…
Ez valóban megoldja ezt a problémát, hogyha a deleted a szokásos módja helyett egy subquery visszatérési értékét teszem IN-be? Igaz 10 éve, hogy végeztem programozói szakon, de akkor vissza isten bizony vissza megyek az adatbázis tanáromhoz megkérdezni, hogy mi erről a véleménye. Mikor egyszer azért akart megbuktatni ZH-n, mert denormalizáltam egy adatbázist, mert kb 3x gyorsabb lett a rendszer. Indokoltam a denormalizálást és esettanulmánnyal (adott esetre vonatkozóan) mégse fogadta el. Ha egy ilyen query-t írtam volna, biztos hogy a f...mra lép és hanyatt lök.

A deadlock elkerülésének nem igazán van univerzális megoldása, ezért javasoltam azt, hogy konkrét esetet vizsgáljunk. A deadlock elkerülésének egyik általános része a tábla szintű lock elkerülése, ha lehet, pl. erre egy eszköz az amit a linken is olvashatsz, hogy valami alapján sorba rendezteted a találatokat, amin végrehajtasz egy műveletet. Erre van a subquery. Lehet, hogy összetettebb, és nem elegánsnak tűnő, de működhet.

Konkrét példa nélkül marad a message queue és a singleton, gyakorlatilag a tranzakciók teljes elkerülése, ha biztosat akarsz. Ezzel biztos, hogy több időt fogsz eltölteni, mint egy konkrét deadlock debuggolásával.

A deadlock tranzakcióknál természetes dolog, meg is mondja mit kell csinálnod kezd újra a tranzakciót. eg loopoltatod, 1-2-szer aztán hibát adsz a felhasználónak ha nem megy, a deadlock megtörténhet nagy konkurenciánál, nem tudod elkerülni semmivel, le kell kezelni kliensben. pont. nincs olyan hogy hagyom futni sorba.

Ha query timeout-d van tranzakció közben, akkor a tranzakció nem rollbackelődik, csak az timeoutolt query, a sok lock-s közül, sem biztos hogy minden felszabadul, rollbackeld és kezd újra a tranzakciót(eg loop), vagy kapcsold be az innodb_rollback_on_timeout-t (ekkor nem kell rollbackelned). esetleg utána bonts kapcsolatot és connectálj újra

Ha tcp connection timeoutod van, arról nem biztos hogy a szerver tud,

- ha igen kapsz róla logot "Aborted connection...", ekkor a szerver rollbackel automatikusan, kliens elveszti a kapcsolatot (most hagyjuk ki azt az esetet amikor load-balancelt, failovernél ki mivel varázsol, ha nálad nincs ilyen)

- ha nem tud akkor kell az interactive_timeouttal, és a wait_timeouttal játszani, ami majd fel kéne szabadítsa a lockokat de ez már függ a query-ktől, környezettől, nem ajánlatos zajos hálózaton kommunikálni

de még mindig nem tudunk semmit arról mennyi id tart 1 átlagos tranzakció(10 sec?, 1 perc?, 1 óra?), és mennyi a leghosszabb?

Nem igazán értem milyen tábla lock-ról írtál, eddig erről nem volt szó, vagy az is van?

Minden kritikus adatbázis művelet try...catch között van. Catch ágban rollback az mindenhol be van építve. Ugyan így a timeout is egy exception, amit szintén elkap a catch ág, vagyis a rollback ott is biztosított. Akkor mitől válik az adatbázis mégis inkonzisztensé?

Load balancer és failover... ezek nálunk nincsenek. Egy szerveren fut az adatbázis és nincs semmi mágia benne. 60 usernél még nem láttam indokoltnak.

Mit értesz zajos hálózat alatt? Ez a kifejezés nálam nem teljesen világos.

Sajnos nehéz megmondani az átlagaos tranzakció idejét, de ha mindenképpen becsülnöm kéne, akkor 10sec alatt van mind. A leghosszabb 11sec, amit biztosan tudok.

Tábla lock: saját kezűleg semmilyen lock nincs a programba építve. Csak és kizárólag tranzakciókkal dolgozik a program. A tranzakció feltételezem nem zárolja a teljes táblát, így csak a megfogalmazás volt téves.

>Akkor mitől válik az adatbázis mégis inkonzisztensé?

eddig passz

tárolt eljárást használsz?
mert ott talán előfordulhat, hogy a parancsokat egyesével hajtja végre és ha nincs error handler benne akkor ráfuthat 1 commitra is, mielőtt a catch elkapja?

general log-ban benne van a query ami inkonzisztensé teszi?
binary log-ban benne van a query ami inkonzisztensé teszi?

Kizárnám, hogy átírjon, más által lockolt adatot, hacsak nem mégis commitolsz timeout után, csak ebből adódhat inkozisztenciád sztem

Az aborted connection üzenetet simán kaphatod, ha egy tranzakciód során 2x kapsz deadlock-t, 2x50(lock_wait_timeout) secig vársz (mivel kikapcsoltad a detectiont), és máris 100 secnél vagy, ahol meg az interactive timeout lelővi a kapcsolatot és rollbackeli a tranzakciót.

szerkesztendő: 2x49 secig vársz így nincs timeoutod

- Lock wait timeout exceeded; try restarting transaction

Szerintem az alkalmazás hibás folyamatait küszöböljétek ki. Jól megírt alkalmazás nem hagy tartós lock-ot, csak egy-egy művelet erejéig. Másképpen a konkurens adatbázishasználat ellehetetlenül ilyen üzenetekkel. A deadlock-nál nincs mire várni tovább, az egy végső állapot. Szumma szummárum, szerintem nem a DB felé kell keresni a megoldást.

Hello,

Kerlek futtas egy `Show Engine InnoDB status\G` es masold be a kimenetelt vagy kuld el privatban. Ez jo esellyel megmondja hogy hol es miert van deadlock. A deadlock nem MySQL sajatossag , egesz egyszeruen ket parhuzamos tranzakcio ugyan azokat a sorokat akarjak modositani es egymasra varnak.


=====================================
2018-11-21 12:15:35 0x7f281410b700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 22 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 809 srv_active, 0 srv_shutdown, 370 srv_idle
srv_master_thread log flush and writes: 1175
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 3460
OS WAIT ARRAY INFO: signal count 5332
RW-shared spins 0, rounds 7432, OS waits 2212
RW-excl spins 0, rounds 14113, OS waits 537
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 7432.00 RW-shared, 14113.00 RW-excl, 0.00 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 95179218
Purge done for trx's n:o < 95179218 undo n:o < 0 state: running but idle
History list length 44
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421285526310544, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526316984, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526314224, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526316064, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526315144, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526312384, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526309624, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526308704, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526319744, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526317904, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421285526311464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
188080 OS file reads, 65969 OS file writes, 1922 OS fsyncs
216.54 reads/s, 16384 avg bytes/read, 160.31 writes/s, 1.86 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 687, seg size 689, 321 merges
merged operations:
insert 334, delete mark 5, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 34673, node heap has 2 buffer(s)
Hash table size 34673, node heap has 53 buffer(s)
Hash table size 34673, node heap has 1 buffer(s)
Hash table size 34673, node heap has 15 buffer(s)
Hash table size 34673, node heap has 16 buffer(s)
Hash table size 34673, node heap has 2 buffer(s)
Hash table size 34673, node heap has 131 buffer(s)
Hash table size 34673, node heap has 39 buffer(s)
28932.14 hash searches/s, 13264.31 non-hash searches/s
---
LOG
---
Log sequence number 104451584197
Log flushed up to 104451584197
Pages flushed up to 104451583005
Last checkpoint at 104451580163
0 pending log flushes, 0 pending chkp writes
833 log i/o's done, 0.86 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137428992
Dictionary memory allocated 9660194
Buffer pool size 8191
Free buffers 1024
Database pages 6908
Old database pages 2530
Modified db pages 32
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 192500, not young 22644713
457.25 youngs/s, 40412.39 non-youngs/s
Pages read 187265, created 49302, written 64789
216.54 reads/s, 149.49 creates/s, 159.27 writes/s
Buffer pool hit rate 999 / 1000, young-making rate 3 / 1000 not 326 / 1000
Pages read ahead 98.63/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 6908, unzip_LRU len: 0
I/O sum[10960]:cur[16], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=23676, Main thread ID=139810266224384, state: sleeping
Number of rows inserted 2145624, updated 174056, deleted 19, read 87601606
5091.22 inserts/s, 0.59 updates/s, 0.00 deletes/s, 72512.43 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Tranzakció-optimalizáció gyanús a dolog. Láthatunk egy tranzakciót vagy lekérdezést a legproblémásabbak közül?

Üdv,
Marci