maria-discuss team mailing list archive

[marki <ubuntu1@xxxxxxxxx>]

Not sure how to better format a wide output which is the natural output of EXPLAIN.

Maybe indexes are missing but there is not very much data inside thoes tables. As I mentioned the problem seems to have appeared after a mariadb update.

I can provide more details when I'm back to my pc.

On November 16, 2018 7:21:41 PM GMT+01:00, Rhys.Campbell@xxxxxxxxxxxx wrote:
>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