maria-discuss team mailing list archive

[<Rhys.Campbell@xxxxxxxxxxxx>]

Better formatted queries and explain help people look at your problems.

Note "possible keys" for two tables is null.  Check for indexes on this table. Table definitions are also useful to include for us here.

Cheers,

Rhys

-----Original Message-----
From: Maria-discuss [mailto:maria-discuss-bounces+rhys.campbell=swisscom.com@xxxxxxxxxxxxxxxxxxx] On Behalf Of marki
Sent: 16 November 2018 17:44
To: maria-discuss@xxxxxxxxxxxxxxxxxxx
Subject: [Maria-discuss] 100% CPU on simple queries when join_buffer_size is large

Hey,

Server version: 10.0.35-MariaDB SLE 12 SP1 here

I have a problem with a query/process hanging "Copying to tmp table" and CPU at 100%


MariaDB [iplocator]> EXPLAIN SELECT *, l3l2.time AS time FROM l3l2 JOIN 
l2l1 USING (mac) JOIN l1human h ON l2l1.switch=h.switch AND 
l2l1.port=h.portid WHERE ip=INET_ATON('192.168.1.1') ORDER BY l3l2.time 
DESC
     -> ;
+------+-------------+-------+--------+---------------+---------+---------+-------------------------------------------+--------+---------------------------------+
| id   | select_type | table | type   | possible_keys | key     | 
key_len | ref                                       | rows   | Extra     
                       |
+------+-------------+-------+--------+---------------+---------+---------+-------------------------------------------+--------+---------------------------------+
|    1 | SIMPLE      | l2l1  | ALL    | NULL          | NULL    | NULL   
  | NULL                                      |  10379 | Using temporary; 
Using filesort |
|    1 | SIMPLE      | h     | eq_ref | PRIMARY       | PRIMARY | 51     
  | iplocator.l2l1.switch,iplocator.l2l1.port |      1 | Using where      
                |
|    1 | SIMPLE      | l3l2  | ALL    | NULL          | NULL    | NULL   
  | NULL                                      | 157794 | Using where      
                |
+------+-------------+-------+--------+---------------+---------+---------+-------------------------------------------+--------+---------------------------------+
3 rows in set (0.00 sec)



We have made some modifications to my.cnf for Cacti, namely:

; for cacti <3
[mysqld]
max_heap_table_size = 92M
max_allowed_packet = 16777216
tmp_table_size = 64M
join_buffer_size = 64M ; problem with iplocator when this option is set
innodb_buffer_pool_size = 462M
;ssd
innodb_doublewrite = OFF
innodb_additional_mem_pool_size = 80M
innodb_flush_log_at_timeout = 3
;ssd
innodb_read_io_threads = 32
;ssd
innodb_write_io_threads = 16


We found out by trial and error that when we do not increase 
join_buffer_size (leave at default 128k I believe) then the query 
mentioned above runs ok. However cacti would require us to increase it, 
which is when the query above will fail with said error.





=====================================
2018-11-16 16:41:17 7fbf9c202700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 15 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 13 srv_active, 0 srv_shutdown, 1 srv_idle
srv_master_thread log flush and writes: 5
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 14
OS WAIT ARRAY INFO: signal count 63
Mutex spin waits 52, rounds 366, OS waits 10
RW-shared spins 37, rounds 280, OS waits 4
RW-excl spins 14, rounds 125, OS waits 0
Spin rounds per wait: 7.04 mutex, 7.57 RW-shared, 8.93 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 702870126
Purge done for trx's n:o < 702870081 undo n:o < 0 state: running but 
idle
History list length 220
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 6, OS thread handle 0x7fbf9c202700, query id 581 
localhost root init
show engine innodb status
---TRANSACTION 702870124, not started
MySQL thread id 4, OS thread handle 0x7fbf9c24b700, query id 580 
localhost icingaweb2 cleaning up
--------
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 (read thread)
I/O thread 7 state: waiting for completed aio requests (read thread)
I/O thread 8 state: waiting for completed aio requests (read thread)
I/O thread 9 state: waiting for completed aio requests (read thread)
I/O thread 10 state: waiting for completed aio requests (read thread)
I/O thread 11 state: waiting for completed aio requests (read thread)
I/O thread 12 state: waiting for completed aio requests (read thread)
I/O thread 13 state: waiting for completed aio requests (read thread)
I/O thread 14 state: waiting for completed aio requests (read thread)
I/O thread 15 state: waiting for completed aio requests (read thread)
I/O thread 16 state: waiting for completed aio requests (read thread)
I/O thread 17 state: waiting for completed aio requests (read thread)
I/O thread 18 state: waiting for completed aio requests (read thread)
I/O thread 19 state: waiting for completed aio requests (read thread)
I/O thread 20 state: waiting for completed aio requests (read thread)
I/O thread 21 state: waiting for completed aio requests (read thread)
I/O thread 22 state: waiting for completed aio requests (read thread)
I/O thread 23 state: waiting for completed aio requests (read thread)
I/O thread 24 state: waiting for completed aio requests (read thread)
I/O thread 25 state: waiting for completed aio requests (read thread)
I/O thread 26 state: waiting for completed aio requests (read thread)
I/O thread 27 state: waiting for completed aio requests (read thread)
I/O thread 28 state: waiting for completed aio requests (read thread)
I/O thread 29 state: waiting for completed aio requests (read thread)
I/O thread 30 state: waiting for completed aio requests (read thread)
I/O thread 31 state: waiting for completed aio requests (read thread)
I/O thread 32 state: waiting for completed aio requests (read thread)
I/O thread 33 state: waiting for completed aio requests (read thread)
I/O thread 34 state: waiting for completed aio requests (write thread)
I/O thread 35 state: waiting for completed aio requests (write thread)
I/O thread 36 state: waiting for completed aio requests (write thread)
I/O thread 37 state: waiting for completed aio requests (write thread)
I/O thread 38 state: waiting for completed aio requests (write thread)
I/O thread 39 state: waiting for completed aio requests (write thread)
I/O thread 40 state: waiting for completed aio requests (write thread)
I/O thread 41 state: waiting for completed aio requests (write thread)
I/O thread 42 state: waiting for completed aio requests (write thread)
I/O thread 43 state: waiting for completed aio requests (write thread)
I/O thread 44 state: waiting for completed aio requests (write thread)
I/O thread 45 state: waiting for completed aio requests (write thread)
I/O thread 46 state: waiting for completed aio requests (write thread)
I/O thread 47 state: waiting for completed aio requests (write thread)
I/O thread 48 state: waiting for completed aio requests (write thread)
I/O thread 49 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 
0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: 0 
[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
  ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
2867 OS file reads, 24 OS file writes, 24 OS fsyncs
191.12 reads/s, 17088 avg bytes/read, 1.60 writes/s, 1.60 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 11097, seg size 11099, 152 merges
merged operations:
  insert 108, delete mark 70, delete 0
discarded operations:
  insert 0, delete mark 0, delete 0
13519.57 hash searches/s, 1502.97 non-hash searches/s
---
LOG
---
Log sequence number 1299475887198
Log flushed up to   1299475887198
Pages flushed up to 1299475527411
Last checkpoint at  1299475527411
Max checkpoint age    80826164
Checkpoint age target 78300347
Modified age          359787
Checkpoint age        359787
0 pending log writes, 0 pending chkp writes
29 log i/o's done, 1.93 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 504315904; in additional pool allocated 0
Total memory allocated by read views 368
Internal hash tables (constant factor + variable factor)
     Adaptive hash index 8657696         (7670456 + 987240)
     Page hash           480232 (buffer pool 0 only)
     Dictionary cache    2436172         (1919248 + 516924)
     File system         1027312         (812272 + 215040)
     Lock system         1200352         (1199272 + 1080)
     Recovery system     0       (0 + 0)
Dictionary memory allocated 516924
Buffer pool size        29567
Buffer pool size, bytes 484425728
Free buffers            26668
Database pages          2839
Old database pages      1067
Modified db pages       582
Percent of dirty pages(LRU & free pages): 1.972
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5, not young 0
0.33 youngs/s, 0.00 non-youngs/s
Pages read 2823, created 16, written 0
188.19 reads/s, 1.07 creates/s, 0.00 writes/s
Buffer pool hit rate 999 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 38.00/s, evicted without access 0.00/s, Random read 
ahead 0.00/s
LRU len: 2839, unzip_LRU len: 0
I/O sum[0]:cur[4], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
0 RW transactions active inside InnoDB
0 RO transactions active inside InnoDB
0 out of 1000 descriptors used
---OLDEST VIEW---
Normal read view
Read view low limit trx n:o 702870080
Read view up limit trx id 702870080
Read view low limit trx id 702870080
Read view individually stored trx ids:
-----------------
Main thread process no. 31341, id 140459967563520, state: sleeping
Number of rows inserted 11, updated 453, deleted 8, read 12982600
0.73 inserts/s, 30.20 updates/s, 0.53 deletes/s, 865448.97 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================



Can someone shed some light on this?


It seems to me the appearance of the problem might be related to a 
recent upgrade of the server which included upgrading mariadb from 
10.0.21 to 10.0.35

Thx

_______________________________________________
Mailing list: https://launchpad.net/~maria-discuss
Post to     : maria-discuss@xxxxxxxxxxxxxxxxxxx
Unsubscribe : https://launchpad.net/~maria-discuss
More help   : https://help.launchpad.net/ListHelp