Как подтюнить связку freeradius3+mysql 5.7

[veca16]

Доброго времени суток! Решили обратиться на форум так как у самих уже не выходит. История такая мы переходили с Nodeny 50.33 на Nodeny Plus с переходом нам помогли сам процесс проходит нормально и вроди все работало нормально на стенде. Но когда пришло время выкатить в продакшин всплыли проблемы с тюнингом. База данных mysql 5.7 стоит на Freebsd 12.1 машина с 4 ядрами 24 Гига оперативки freeradius 3, авторизация pppoe (mpd5) на отдельных брасах.
При выкатывании машины в продакшин начали появляться дисконекты по логу с радиус сервера определили что упирается в лимиты и подтюнили радиус вот конфик с тюнингом:

Код:

sql {
    driver = "rlm_sql_mysql"
    mysql {
        warnings = auto
    }
    server = "localhost"
    port = 3306
    login = "XXXXXX"
    password = "XXXXXXXXX"
    radius_db = "nod"

    authorize_check_query = "call radcheck('%{User-Name}', 1)"
    authorize_reply_query = "call radreply('%{User-Name}', '%{User-Password}')"
    accounting {
        reference = "%{tolower:type.%{Acct-Status-Type}.query}"
        type {
            start {
                query = "call radupdate('%{User-Name}','%{Framed-IP-Address}',\
                        'user=%{Calling-Station-Id};nas=%{NAS-IP-Address};ses=%{Acct-Session-Id}')"
            }
            interim-update {
                query = "${..start.query}"
            }
            stop {
                query = "call radstop('%{User-Name}', '%{Framed-IP-Address}')"
            }
        }
    }
    post-auth {
        query = "call radupdate('%{User-Name}','%{reply:Framed-IP-Address}',\
                'user=%{Calling-Station-Id};nas=%{NAS-IP-Address};ses=%{Acct-Session-Id}')"
    }
 pool {
        start = ${thread[pool].start_servers}
        min = ${thread[pool].min_spare_servers}
        max = ${thread[pool].max_servers}
        spare = ${thread[pool].max_spare_servers}
        uses = 0
        retry_delay = 30
        lifetime = 0
        idle_timeout = 60
        }

При небольшом нагрузочном тестировании все было нормально после этого фикса но когда ночью попробовали опять в продакшин то в радиус лог начали сыпать ошибки:
 Error: (1399273) Ignoring duplicate packet from client bras port 64555 - ID: 15 due to unfinished request in component <core> module <queue>
WARNING: (0) sql: WARNING: Cannot do check groups when group_membership_query is not set

Немного погуглив решили поставить немного больше таймаут на mpd:

Код:

radius:
        set radius server XX.XX.XX.XX hardpass 1812 1813
        set radius retries 3
        [color=orange][b]set radius timeout 40[/b][/color]
        set radius me XX.XX.XX.XX
        set auth acct-update 45
        set auth enable radius-auth
        set auth enable radius-acct
        set radius enable message-authentic

Это нам вначале помогло и в логе кроме ошибки
WARNING: (0) sql: WARNING: Cannot do check groups when group_membership_query is not set
ничего не было но недолго.
Буквльно через час когда уже было утро и авторизованных клиентов стало добавляться (в среднем на пике 7000 авторизованых) опять начали сыпать ошибки в радиус лог:

Код:

Error: Unresponsive child for request 1394975, in component accounting module sql
WARNING: (1394876) WARNING: Module rlm_sql became unblocked
Error: 23 requests have been waiting in the processing queue for 38 seconds.  Check that all databases are running properly!

и очень редко ошибка
Error: (1399273) Ignoring duplicate packet from client bras port 64555 - ID: 15 due to unfinished request in component <core> module <queue>

Судя по сообщениям похоже на то что нужен тюнинг mysql или настроек радиуса связанных с mysql.
Насколько сам смог а что ребята подсказали mysql подтюнили но эфекта пока нету, вот мой my.cnf

Код:

[mysqld]
innodb_buffer_pool_size     = 16512M
innodb_file_per_table       = 1
innodb_flush_method         = O_DIRECT
innodb_flush_log_at_trx_commit  = 0
sql_mode=ONLY_FULL_GROUP_BY,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
#sql_mode=IGNORE_SPACE,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION

log_bin_trust_function_creators = 1
#key_buffer = 1200M
thread_stack = 512K
thread_cache_size = 32
#table_cache = 60000
net_buffer_length = 32
query_cache_limit = 2M
query_cache_size = 1024M
myisam_sort_buffer_size = 256M
tmp_table_size = 256M
max_heap_table_size = 128M
read_buffer_size = 2M
read_rnd_buffer_size = 4M
sort_buffer_size = 2M
join_buffer_size = 4M
max_allowed_packet = 1024M
max_sort_length = 512
max_connections = 7000
#max_connect_errors = 50
#max_user_connections = 25


#thread_concurrency = 12
skip-character-set-client-handshake
skip-name-resolve
log-bin=mysql-bin
max_binlog_size= 500M
expire_logs_days = 3

server-id  = 1
[mysqldump]
quick
max_allowed_packet = 16M

[mysql]
no-auto-rehash

[myisamchk]
key_buffer_size = 256M
sort_buffer_size = 256M
read_buffer = 2M
write_buffer = 2M

[mysqlhotcopy]
interactive-timeout

Кто сталкивался с такими ошибками и приходилось тюнить под такие нагрузки пожалуйста подскажите а то мы уже не знаем куда дальше тюнить и копать. Заранее спасибо!

P.S. Да кстати с этой нагрузкой на этой же машине Nodeny 50.33 практически без никакого тюнинга работает без проблем.

[Efendy]

WARNING: (0) sql: WARNING

это скорее всего можно игнорировать, к производительности не относится

Ignoring duplicate packet from client

это может быть косвенным свидетельством, что не справляется база данных. Но скорее всего это не относится к железу, его мощности и т.д. Скорее всего это dead locks в mysql. Давай это проверим. Покажи в mysql:

Код:

SHOW ENGINE INNODB STATUS;

[veca16]

Добрый день Станислав!

Код:

mysql> SHOW ENGINE INNODB STATUS;
| InnoDB |      | 
=====================================
2020-07-21 13:22:45 0xd193d8300 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 45 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 522 srv_active, 0 srv_shutdown, 5590 srv_idle
srv_master_thread log flush and writes: 6112
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 66902
OS WAIT ARRAY INFO: signal count 55705
RW-shared spins 0, rounds 1913, OS waits 543
RW-excl spins 0, rounds 34504, OS waits 717
RW-sx spins 101, rounds 2448, OS waits 32
Spin rounds per wait: 1913.00 RW-shared, 34504.00 RW-excl, 24.24 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 14220109
Purge done for trx's n:o < 14220099 undo n:o < 0 state: running but idle
History list length 19
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 281510627802176, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627801272, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627800368, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627799464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627798560, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627797656, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627796752, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627795848, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627794944, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627794040, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627793136, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627792232, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627791328, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627790424, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627787712, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627788616, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627789520, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627786808, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627785904, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (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
8374 OS file reads, 12340 OS file writes, 6610 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 5501, seg size 5503, 17 merges
merged operations:
 insert 1513, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 4515341, node heap has 422 buffer(s)
Hash table size 4515341, node heap has 1 buffer(s)
Hash table size 4515341, node heap has 19 buffer(s)
Hash table size 4515341, node heap has 3 buffer(s)
Hash table size 4515341, node heap has 16 buffer(s)
Hash table size 4515341, node heap has 22 buffer(s)
Hash table size 4515341, node heap has 50 buffer(s)
Hash table size 4515341, node heap has 19 buffer(s)
835.54 hash searches/s, 11.44 non-hash searches/s
---
LOG
---
Log sequence number 39656901458
Log flushed up to   39656901458
Pages flushed up to 39656901458
Last checkpoint at  39656901449
0 pending log flushes, 0 pending chkp writes
1396 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 18690342912
Dictionary memory allocated 271757
Buffer pool size   1114029
Free buffers       1104616
Database pages     8861
Old database pages 3275
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 31, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 8334, created 527, written 8558
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 8861, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size   139254
Free buffers       137972
Database pages     1211
Old database pages 467
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1173, created 38, written 1258
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1211, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size   139261
Free buffers       138177
Database pages     1015
Old database pages 373
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 12, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 978, created 37, written 344
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1015, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size   139248
Free buffers       137984
Database pages     1192
Old database pages 423
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 9, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1067, created 125, written 2257
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1192, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size   139261
Free buffers       138158
Database pages     1035
Old database pages 377
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 969, created 66, written 1482
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1035, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size   139248
Free buffers       138117
Database pages     1060
Old database pages 401
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1013, created 47, written 1014
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1060, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size   139252
Free buffers       137985
Database pages     1198
Old database pages 447
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1124, created 74, written 735
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1198, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size   139248
Free buffers       138120
Database pages     1061
Old database pages 394
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1012, created 49, written 674
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1061, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size   139257
Free buffers       138103
Database pages     1089
Old database pages 393
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 998, created 91, written 794
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1089, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=12763, Main thread ID=56075682560, state: sleeping
Number of rows inserted 67230, updated 38, deleted 33511, read 22567239
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 3296.46 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Но это без нагрузки и еще немного подтюнили, мне Михаил подсказал что можно попробовать.
Завтра утром попробуем и тогда напишу получилось или нет.

[Efendy]

Да, в логе пока нет дедлоков. Постарайтесь запустить mysql с ключем innodb_print_all_deadlocks, тогда он все дедлоки будет записывать в файл (а иначе мы просто увидим последний дедлок, а он может не быть ключевым).

https://dev.mysql.com/doc/refman/5.7/en/innodb-parameters.html#sysvar_innodb_print_all_deadlocks

[veca16]

Доброе утро! Тест под нагрузкой. Вижу локи есть.

Код:

mysql> SHOW ENGINE INNODB STATUS;
| InnoDB |      | 
=====================================
2020-07-22 06:59:44 0xd1658d700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 47 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2990 srv_active, 0 srv_shutdown, 175 srv_idle
srv_master_thread log flush and writes: 3165
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1993509
OS WAIT ARRAY INFO: signal count 1190120
RW-shared spins 0, rounds 408390, OS waits 148383
RW-excl spins 0, rounds 14955663, OS waits 118485
RW-sx spins 57739, rounds 1304243, OS waits 21902
Spin rounds per wait: 408390.00 RW-shared, 14955663.00 RW-excl, 22.59 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 15463958
Purge done for trx's n:o < 15463956 undo n:o < 0 state: running but idle
History list length 31
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 281510627797656, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627792232, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627801272, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627821160, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627815736, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627814832, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627813024, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627811216, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627800368, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627794944, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627794040, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627793136, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627791328, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627790424, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627809408, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627805792, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627789520, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627813928, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627810312, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627804888, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627798560, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627796752, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627795848, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627786808, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627819352, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627817544, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627807600, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627818448, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627802176, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627803984, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627816640, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627785904, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 15463954, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 491, OS thread handle 56266637568, query id 3347250 localhost nodeny update
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
------- TRX HAS BEEN WAITING 0 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 698 page no 217 n bits 200 index PRIMARY of table `bill`.`auth_now` trx id 15463954 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

------------------
---TRANSACTION 15463953, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 483, OS thread handle 56209500928, query id 3347243 localhost nodeny update
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
------- TRX HAS BEEN WAITING 0 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 698 page no 217 n bits 200 index PRIMARY of table `bill`.`auth_now` trx id 15463953 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

------------------
---TRANSACTION 15463952, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
6 lock struct(s), heap size 1136, 4 row lock(s), undo log entries 1
MySQL thread id 433, OS thread handle 56266636288, query id 3347236 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 15463948, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 492, OS thread handle 56290334976, query id 3347225 localhost nodeny update
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
------- TRX HAS BEEN WAITING 0 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 698 page no 217 n bits 200 index PRIMARY of table `bill`.`auth_now` trx id 15463948 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

------------------
---TRANSACTION 15463936, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
7 lock struct(s), heap size 1136, 5 row lock(s), undo log entries 1
MySQL thread id 500, OS thread handle 56290333696, query id 3347191 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (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
18166 OS file reads, 52058 OS file writes, 16908 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 30.83 writes/s, 8.45 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 5501, seg size 5503, 45 merges
merged operations:
 insert 249, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 4515457, node heap has 427 buffer(s)
Hash table size 4515457, node heap has 1 buffer(s)
Hash table size 4515457, node heap has 28 buffer(s)
Hash table size 4515457, node heap has 1731 buffer(s)
Hash table size 4515457, node heap has 17 buffer(s)
Hash table size 4515457, node heap has 23 buffer(s)
Hash table size 4515457, node heap has 50 buffer(s)
Hash table size 4515457, node heap has 20 buffer(s)
50469.95 hash searches/s, 3528.31 non-hash searches/s
---
LOG
---
Log sequence number 40001362513
Log flushed up to   40001349486
Pages flushed up to 39994056380
Last checkpoint at  39994054438
0 pending log flushes, 0 pending chkp writes
5060 log i/o's done, 1.98 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 18690342912
Dictionary memory allocated 271757
Buffer pool size   1114049
Free buffers       1092671
Database pages     19081
Old database pages 6975
Modified db pages  842
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 8, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 18125, created 956, written 41747
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 19081, unzip_LRU len: 0
I/O sum[0]:cur[88], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size   139259
Free buffers       136415
Database pages     2557
Old database pages 940
Modified db pages  113
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2493, created 64, written 5323
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2557, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size   139264
Free buffers       136658
Database pages     2319
Old database pages 853
Modified db pages  45
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 4, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2257, created 62, written 1595
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2319, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size   139247
Free buffers       136298
Database pages     2664
Old database pages 963
Modified db pages  204
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2430, created 234, written 8250
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2664, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size   139264
Free buffers       136661
Database pages     2315
Old database pages 841
Modified db pages  99
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2190, created 125, written 7122
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2315, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size   139248
Free buffers       136700
Database pages     2260
Old database pages 838
Modified db pages  81
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2177, created 83, written 4755
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2260, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size   139261
Free buffers       136492
Database pages     2483
Old database pages 910
Modified db pages  125
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2340, created 143, written 5526
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2483, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size   139256
Free buffers       136703
Database pages     2265
Old database pages 816
Modified db pages  90
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2099, created 166, written 5341
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2265, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size   139250
Free buffers       136744
Database pages     2218
Old database pages 814
Modified db pages  85
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2139, created 79, written 3835
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2218, unzip_LRU len: 0
I/O sum[0]:cur[11], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Process ID=1632, Main thread ID=56075681280, state: sleeping
Number of rows inserted 16993929, updated 261585, deleted 9309, read 94575409
27388.18 inserts/s, 103.17 updates/s, 0.17 deletes/s, 122145.06 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

[Efendy]

Ок. Разбираюсь. А не получилось с innodb_print_all_deadlocks? вдруг последние локи, что ты дал нечастые и на самом деле проблема не в них

и покажи

Код:

show create procedure set_auth;

потому что sql отличается от того, что в инстале биллинга

[Efendy]

Похоже в insert on duplicate key update к дедлокам приводит поле id. Которое по сути не нужно)

Обычно, во всех таблицах есть это поле (может называться иначе) - оно уникальное и предназначено для того, чтобы через него ссылаться на конкретную запись. Чтобы по id можно было изменить или удалить.

Конкретно, в NoDeny оно, кажется нигде не используется - я просмотрел код и немного потестировал после удаления этого поля. Т.е в NoDeny нет никакой необходимости обращаться по id  к записям в таблице auth_now.

Насколько опасно вот прямо сейчас без глубокого тестирования удалить поле id на продакшине? Лично я считаю, что это не опасно ибо если что-то пойдет не так - можно это поле добавить либо же тупо грохнуть таблицу и создать заново. Эта таблица предназначена для отображения текущих авторизаций и данные там так или иначе грохаются по окончанию авторизации.

Удаление поля:

Код:

alter table auth_now drop id;

Если что-то не так, создание таблицы заново:

Код:

DROP  TABALE auth_now;
CREATE TABLE `auth_now` (
  `id` bigint(20) NOT NULL AUTO_INCREMENT,
  `ip` varchar(15) NOT NULL,
  `start` int(10) unsigned NOT NULL DEFAULT '0',
  `last` int(10) unsigned NOT NULL DEFAULT '0',
  `properties` text NOT NULL,
  PRIMARY KEY (`id`),
  UNIQUE KEY `ip` (`ip`),
  KEY `start` (`start`),
  KEY `last` (`last`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8;

[veca16]

Спасибо большое Станислав. Потестируем, надеюсь єто решит нашу проблему.
Как будут результаты отпишусь.

[veca16]

Доброе утро. Проверили под нагрузкой, начали с утра сначала все было нормально, ошибок в radius log не было. После запуска noserver на первом брасе начали появляться локи в базе, хотя в radius log ошибок небыло.
После запуска noserver на втором брасе пару раз появились ошибки в radius.log
Error: (156054) Ignoring duplicate packet from client bras port 59195 - ID: 140 due to unfinished request in component accounting module sql
И локов стало больше частота появления примерно раз в 10 секунд.
Посли запуска noserver на всех брасах ошибок в radius.log не наблюдаю хотя локи есть но они другие:

Код:

| InnoDB |      | 
=====================================
2020-07-25 06:26:20 0xcf12b4900 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 11 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2917 srv_active, 0 srv_shutdown, 185 srv_idle
srv_master_thread log flush and writes: 3102
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 62112
--Thread 55580940288 has waited at trx0undo.ic line 179 for 0  seconds the semaphore:
X-lock on RW-latch at 0x97084ffd8 created in file buf0buf.cc line 1468
a writer (thread id 56074836480) has reserved it in mode  SX
number of readers 0, waiters flag 1, lock_word: 10000000
Last time read locked in file trx0undo.ic line 198
Last time write locked in file /usr/ports/databases/mysql57-server/work/mysql-5.7.29/storage/innobase/buf/buf0flu.cc line 1206
--Thread 56075652352 has waited at trx0purge.cc line 162 for 0  seconds the semaphore:
Mutex at 0xd0e5f7d60, Mutex REDO_RSEG created trx0rseg.cc:219, lock var 1

OS WAIT ARRAY INFO: signal count 56178
RW-shared spins 0, rounds 24740, OS waits 3013
RW-excl spins 0, rounds 653054, OS waits 5511
RW-sx spins 7412, rounds 157855, OS waits 1990
Spin rounds per wait: 24740.00 RW-shared, 653054.00 RW-excl, 21.30 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 17566701
Purge done for trx's n:o < 17566687 undo n:o < 0 state: running
History list length 63
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 281510627798560, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627819352, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627803080, not started
mysql tables in use 1, locked 1
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627800368, not started
mysql tables in use 1, locked 1
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627799464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627821160, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627813928, not started
mysql tables in use 1, locked 1
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627796752, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627787712, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627820256, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627794040, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627790424, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627789520, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627810312, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627818448, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627817544, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627795848, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627809408, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627813024, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 281510627785904, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 17566700, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 344, OS thread handle 55581702400, query id 3549477 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566699, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 350, OS thread handle 55580946688, query id 3549470 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566698, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 354, OS thread handle 55581354496, query id 3549463 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566697, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 349, OS thread handle 55581708800, query id 3549462 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566696, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 325, OS thread handle 55580942848, query id 3549449 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566695, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 316, OS thread handle 55580944128, query id 3549442 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566694, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 324, OS thread handle 55581703680, query id 3549435 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566693, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 258, OS thread handle 55580936448, query id 3549433 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566692, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 341, OS thread handle 55580947968, query id 3549431 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566691, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 347, OS thread handle 55580945408, query id 3549414 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566690, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 328, OS thread handle 55580937728, query id 3549412 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566689, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 340, OS thread handle 55581710080, query id 3549404 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566688, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 333, OS thread handle 55585752064, query id 3549393 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566683, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 315, OS thread handle 55581353216, query id 3549386 localhost nodeny query end
INSERT INTO auth_now SET
        ip = usr_ip,
        properties = auth_properties,
        start = UNIX_TIMESTAMP(),
        last = UNIX_TIMESTAMP()
    ON DUPLICATE KEY UPDATE
        properties = auth_properties,
        last = UNIX_TIMESTAMP()
---TRANSACTION 17566682, ACTIVE (PREPARED) 0 sec
mysql tables in use 1, locked 1

--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 22, 0, 0] ,
 ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 1; buffer pool: 1
27343 OS file reads, 33590 OS file writes, 8048 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 14.64 writes/s, 2.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 5501, seg size 5503, 80 merges
merged operations:
 insert 80, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 4515457, node heap has 424 buffer(s)
Hash table size 4515457, node heap has 1 buffer(s)
Hash table size 4515457, node heap has 19 buffer(s)
Hash table size 4515457, node heap has 1739 buffer(s)
Hash table size 4515457, node heap has 6 buffer(s)
Hash table size 4515457, node heap has 24 buffer(s)
Hash table size 4515457, node heap has 50 buffer(s)
Hash table size 4515457, node heap has 19 buffer(s)
46370.97 hash searches/s, 1476.50 non-hash searches/s
---
LOG
---
Log sequence number 40918580532
Log flushed up to   40918571686
Pages flushed up to 40910301356
Last checkpoint at  40909448935
1 pending log flushes, 0 pending chkp writes
4027 log i/o's done, 1.18 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 18690342912
Dictionary memory allocated 269725
Buffer pool size   1114049
Free buffers       1083517
Database pages     28250
Old database pages 10337
Modified db pages  789
Pending reads      0
Pending writes: LRU 0, flush list 34, single page 0
Pages made young 3, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 27291, created 959, written 27899
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 28250, unzip_LRU len: 0
I/O sum[0]:cur[1376], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size   139259
Free buffers       135225
Database pages     3747
Old database pages 1365
Modified db pages  71
Pending reads      0
Pending writes: LRU 0, flush list 3, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3643, created 104, written 3890
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3747, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size   139264
Free buffers       135456
Database pages     3523
Old database pages 1309
Modified db pages  28
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3458, created 65, written 2360
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3523, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size   139247
Free buffers       135334
Database pages     3628
Old database pages 1319
Modified db pages  144
Pending reads      0
Pending writes: LRU 0, flush list 3, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3405, created 223, written 3662
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3628, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size   139264
Free buffers       135572
Database pages     3407
Old database pages 1264
Modified db pages  83
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3370, created 37, written 4604
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3407, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size   139248
Free buffers       135494
Database pages     3469
Old database pages 1267
Modified db pages  135
Pending reads      0
Pending writes: LRU 0, flush list 6, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3350, created 119, written 3420
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3469, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size   139261
Free buffers       135304
Database pages     3671
Old database pages 1335
Modified db pages  135
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3484, created 187, written 3693
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3671, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size   139256
Free buffers       135543
Database pages     3428
Old database pages 1247
Modified db pages  120
Pending reads      0
Pending writes: LRU 0, flush list 22, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3300, created 128, written 3227
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3428, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size   139250
Free buffers       135589
Database pages     3377
Old database pages 1231
Modified db pages  73
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 3281, created 96, written 3043
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3377, unzip_LRU len: 0
I/O sum[0]:cur[172], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=1626, Main thread ID=56075648512, state: sleeping
Number of rows inserted 23479162, updated 312491, deleted 557, read 120725277
25449.23 inserts/s, 116.99 updates/s, 0.27 deletes/s, 111452.41 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

[Efendy]

Не надо путать локи и дедлоки! Локи - это совершенно нормальный и НУЖНЫЙ механизм. Lock (замОк в переводе) нужен для того, чтобы временно заблокировать запись от параллельного изменения. Представьте, что параллельно делаются 2 запроса на изменение баланса:
1) получили баланс, добавили 5 грн
2) получили баланс, добавили 10 грн
И, допустим, баланс 15 грн и он был получен одновременно, тогда первый запрос установит баланс равным 15+5=20 грн, а второй 15+10 = 25 грн. А должно быть 30. Чтобы такого не было и нужны локи.

А вот чего нужно бояться это дед (мертвых) локов, когда локи заблокированы таким образов, что не могут быть разблокированы. Тогда у нас записи в залоченном состоянии, пользователи стучатся на авторизацию, а в ответ ничего не получают. Оттуда и идет повторная посылка пакетов.

Если Ignoring duplicate packet не так много, то можно игнорить - тут пишут, что послан дублирующий пакет, значит на первый ответа не должался и послал второй, ничего страшного, если такого не очень много.

В любом случае, если стало меньше - уже хорошо.

В твоем файле, который мне передали, дедлоков нет, так что я сейчас создам отдельную тему, может твой случай поможет другим

[veca16]

Спасибо большое Станислав что посказали и разьяснили. Я думаю теперь уже мы спокойно перенесем биллинг в продакшин и будем работать уже на Nodeny+.