MySQL InnoDB monitoring on nan

Help
1

Hi. I implemented MySQL monitoring on a MariaDB 10.x server.

The monitoring works for System, Queries, but not for InnoDB.

After looking at the problem, I found that MariaDB was complaining about not having an innodb stats table, so I needed to run “mysql_upgrade” which would create this stats table.

I ran that and don’t see any issues in the logs with the DB any more.

However, the InnoDB still isn’t graphing.

The tables do seem to exist:

MariaDB [(none)]> select table_name from information_schema.tables where table_schema='mysql' and engine='InnoDB';
+--------------------+
| table_name         |
+--------------------+
| gtid_slave_pos     |
| innodb_index_stats |
| innodb_table_stats |
+--------------------+
3 rows in set (0.16 sec)

so I’m wondering if there’s more I should do?

Searching the web, these two links seem to suggest there’s more tables required:

https://dba.stackexchange.com/questions/48166/cannot-open-table-mysql-innodb-index-stats

https://dba.stackexchange.com/questions/54608/innodb-error-table-mysql-innodb-table-stats-not-found-after-upgrade-to-mys

ie:

±---------------------+
| table_name |
±---------------------+
| innodb_index_stats |
| innodb_table_stats |
| slave_master_info |
| slave_relay_log_info |
| slave_worker_info |
±---------------------+

But they are for MySQL 5.6 and I’m running MariaDB 10.2.16 (on CentOS 7), so don’t want to add things in the MariaDB 10 that shouldn’t be there.

Please advise.

Thanks.

2

I have the same exact issue, and wonder if you found a solution

3

Unfortunately no. Wish I could help more on this one…

4

Something tells me that a slight difference with the output script on MariaDB makes it miss the extracted content of variables. For example buffer_size shows up as -1 when I run the script, but appears correctly when I do a show engine innodb status. Gonna try and dig around that. I’ll let you know if i manage to do something.

5

Im running
Server version: 5.5.56-MariaDB MariaDB Server
in CentOS 7 and the mysql scripts works correctly and retrieve innodb info without issues.

6

Darn, there must be something we’re missing then. Values corresponding to innodb returns -1. i’ll investigate further. Thanks.

7

Start with checking what command does the mysql script you have downloaded to retrieve the innodb stats.

A quick look tells me it is in line 541

...
$result        = run_query("SHOW /*!50000 ENGINE*/ INNODB STATUS", $conn); 
...

Run that command manually in your mariadb server and check the output.

8

Yep, that works.

InnoDB

2018-11-20 12:21:39 7fc2590c6700 INNODB MONITOR OUTPUT

Per second averages calculated from the last 58 seconds

BACKGROUND THREAD

srv_master_thread loops: 18411 srv_active, 0 srv_shutdown, 64569 srv_idle
srv_master_thread log flush and writes: 82807

SEMAPHORES

OS WAIT ARRAY INFO: reservation count 104060
OS WAIT ARRAY INFO: signal count 110589
Mutex spin waits 77908, rounds 1649813, OS waits 50358
RW-shared spins 49682, rounds 1556071, OS waits 50671
RW-excl spins 1605, rounds 222769, OS waits 2293
Spin rounds per wait: 21.18 mutex, 31.32 RW-shared, 138.80 RW-excl

LATEST DETECTED DEADLOCK

2018-11-20 10:42:59 7fc2590f7700
*** (1) TRANSACTION:
TRANSACTION 97412735, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)
MySQL thread id 58066, OS thread handle 0x7fc2590c6700, query id 3803564 localhost wordpress_0 updating
DELETE FROM uy1qZ_options WHERE option_name = ‘_site_transient_itsec_notification_running’
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1207 page no 192 n bits 272 index option_name of table wordpress_9.uy1qZ_options trx table locks 1 total table locks 7 trx id 97412735 lock_mode X waiting lock hold time 0 wait time before grant 0
*** (2) TRANSACTION:
TRANSACTION 97412727, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1184, 2 row lock(s)
MySQL thread id 58067, OS thread handle 0x7fc2590f7700, query id 3803569 localhost wordpress_0 updating
DELETE FROM uy1qZ_options WHERE option_name = ‘_site_transient_itsec_notification_running’
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1207 page no 192 n bits 272 index option_name of table wordpress_9.uy1qZ_options trx table locks 1 total table locks 7 trx id 97412727 lock_mode X locks rec but not gap lock hold time 0 wait time before grant 0
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1207 page no 192 n bits 272 index option_name of table wordpress_9.uy1qZ_options trx table locks 1 total table locks 7 trx id 97412727 lock_mode X waiting lock hold time 0 wait time before grant 0
*** WE ROLL BACK TRANSACTION (1)

TRANSACTIONS

Trx id counter 97652527
Purge done for trx’s n:o < 97652527 undo n:o < 0 state: running but idle
History list length 730
LIST OF TRANSACTIONS FOR EACH SESSION:
—TRANSACTION 0, not started
MySQL thread id 64894, OS thread handle 0x7fc2590c6700, query id 4334105 localhost admin init
SHOW /!50000 ENGINE/ INNODB STATUS

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, 0] , aio writes: 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
282147 OS file reads, 1120050 OS file writes, 323500 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 12.72 writes/s, 3.90 fsyncs/s

INSERT BUFFER AND ADAPTIVE HASH INDEX

Ibuf: size 1, free list len 438, seg size 440, 147 merges
merged operations:
insert 552, delete mark 2417, delete 486
discarded operations:
insert 0, delete mark 0, delete 0
184.39 hash searches/s, 45.91 non-hash searches/s

LOG

Log sequence number 52021312086
Log flushed up to 52021307465
Pages flushed up to 52021307465
Last checkpoint at 52021307465
Max checkpoint age 80826164
Checkpoint age target 78300347
Modified age 4621
Checkpoint age 4621
0 pending log writes, 0 pending chkp writes
423528 log i/o’s done, 3.93 log i/o’s/second

BUFFER POOL AND MEMORY

Total memory allocated 2235564032; in additional pool allocated 0
Total memory allocated by read views 296
Internal hash tables (constant factor + variable factor)
Adaptive hash index 53299488 (37845176 + 15454312)
Page hash 277432 (buffer pool 0 only)
Dictionary cache 12975133 (8851664 + 4123469)
File system 28655984 (812272 + 27843712)
Lock system 5313776 (5313416 + 360)
Recovery system 0 (0 + 0)
Dictionary memory allocated 4123469
Buffer pool size 131064
Buffer pool size, bytes 2147352576
Free buffers 8533
Database pages 121588
Old database pages 44931
Modified db pages 13
Percent of dirty pages(LRU & free pages): 0.010
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 40256, not young 6033744
0.00 youngs/s, 0.00 non-youngs/s
Pages read 250530, created 264420, written 474909
0.00 reads/s, 0.02 creates/s, 7.79 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: 121588, unzip_LRU len: 0
I/O sum[2824]:cur[0], unzip sum[0]:cur[0]

INDIVIDUAL BUFFER POOL INFO

—BUFFER POOL 0
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1065
Database pages 15202
Old database pages 5630
Modified db pages 1
Percent of dirty pages(LRU & free pages): 0.006
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5262, not young 741838
0.00 youngs/s, 0.00 non-youngs/s
Pages read 31328, created 33373, written 83051
0.00 reads/s, 0.02 creates/s, 0.72 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: 15202, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]
—BUFFER POOL 1
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1068
Database pages 15196
Old database pages 5624
Modified db pages 1
Percent of dirty pages(LRU & free pages): 0.006
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 4766, not young 775858
0.00 youngs/s, 0.00 non-youngs/s
Pages read 31340, created 32640, written 58567
0.00 reads/s, 0.00 creates/s, 1.16 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: 15196, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]
—BUFFER POOL 2
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1063
Database pages 15197
Old database pages 5618
Modified db pages 2
Percent of dirty pages(LRU & free pages): 0.012
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5142, not young 744537
0.00 youngs/s, 0.00 non-youngs/s
Pages read 30801, created 33305, written 65219
0.00 reads/s, 0.00 creates/s, 1.50 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: 15197, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]
—BUFFER POOL 3
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1071
Database pages 15198
Old database pages 5610
Modified db pages 1
Percent of dirty pages(LRU & free pages): 0.006
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5261, not young 731487
0.00 youngs/s, 0.00 non-youngs/s
Pages read 31544, created 33447, written 63280
0.00 reads/s, 0.00 creates/s, 1.47 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: 15198, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]
—BUFFER POOL 4
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1039
Database pages 15234
Old database pages 5611
Modified db pages 3
Percent of dirty pages(LRU & free pages): 0.018
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 4911, not young 747295
0.00 youngs/s, 0.00 non-youngs/s
Pages read 31436, created 33871, written 58717
0.00 reads/s, 0.00 creates/s, 1.26 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: 15234, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]
—BUFFER POOL 5
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1068
Database pages 15201
Old database pages 5616
Modified db pages 2
Percent of dirty pages(LRU & free pages): 0.012
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 4978, not young 772998
0.00 youngs/s, 0.00 non-youngs/s
Pages read 31584, created 32745, written 48726
0.00 reads/s, 0.00 creates/s, 0.40 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: 15201, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]
—BUFFER POOL 6
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1084
Database pages 15177
Old database pages 5610
Modified db pages 1
Percent of dirty pages(LRU & free pages): 0.006
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5171, not young 748120
0.00 youngs/s, 0.00 non-youngs/s
Pages read 30643, created 32984, written 56824
0.00 reads/s, 0.00 creates/s, 0.62 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: 15177, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]
—BUFFER POOL 7
Buffer pool size 16383
Buffer pool size, bytes 268419072
Free buffers 1075
Database pages 15183
Old database pages 5612
Modified db pages 2
Percent of dirty pages(LRU & free pages): 0.012
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 4765, not young 771611
0.00 youngs/s, 0.00 non-youngs/s
Pages read 31854, created 32055, written 40525
0.00 reads/s, 0.00 creates/s, 0.67 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: 15183, unzip_LRU len: 0
I/O sum[353]:cur[0], unzip sum[0]:cur[0]

ROW OPERATIONS

0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
0 RW transactions active inside InnoDB
0 RO transactions active inside InnoDB
0 out of 1000 descriptors used
Main thread process no. 23847, id 140469925304064, state: sleeping
Number of rows inserted 1537803, updated 44723, deleted 35397, read 71008350
0.10 inserts/s, 2.69 updates/s, 0.02 deletes/s, 1575.30 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 2
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s

END OF INNODB MONITOR OUTPUT

9

PS: sorry for the horrible formatting, i’m new to this forum, and i have no idea what happened.

10

Dont worry, it usually happens :slight_smile:

Pbin the output of manually executing the mysql script.

11

well certainly! there you go:

https://pastebin.com/njLV0Ay7

Please note that this might be a different server than the previous data, we have it deployed on a bunch of machines.

12

I think the problem is here…

The script depends on SHOW VARIABLES; having a have_innodb key but apparently that’s been removed in MariabDB 10+…

I’ve attempted to check SHOW PLUGINS; as they recommend and opened an agent PR. If you want to test the PR’s script it’s at:
https://raw.githubusercontent.com/librenms/librenms-agent/482748a1281a372f6ba1a381efd6fef48436fe45/snmp/mysql

Note that the v10 output seems slightly different so there may be some stats still missing.

13

Pretty much exactly what I thought!

Testing that script, thank you very much for that. To date, I seem to have much less -1 values.

https://pastebin.com/RujR4iYH

14

This seem to have sorted a lot of it!

InnoDB Insert Buffer is still at NAN but the rest seems to be populating. Positive step!

15

I’m actually noticing that the agent version of the mysql script looks quite a bit newer. So I’ve taken that and adjusted it for snmp extend. Maybe have another go…

https://raw.githubusercontent.com/librenms/librenms-agent/961c8128157ac96cf45c66256a93d08333ab2531/snmp/mysql

1 Like
16

You are a machine, my good sir! Pulling it and testing in the following hours :smiley:

17

New pastebin of my output if you need for debugging:

https://pastebin.com/R2XydyhG

Gonna let it roll for a few hours. Sadly, snmp crashed (unrelated) so i couldn’t collect the stats of last night to tell you if there’s some more metrics missing.

Cheers

18

It hasn’t been running for very long yet, but we sure are going somewhere.

Innodb Insert Buffer graph: no more NAN, but all data at zero

Innodb IO Pending: no NAN, but all data at zero. i’m no innodb specialist so i cannot say at all if that’s normal or not.

Rest seems to work pretty well.

19

Spoke too soon, this is odd, now i’m getting ‘Error Drawing Graph’ everywhere for the MySQL app. Investigating.

20

Output of RRDtools:

https://pastebin.com/6UNu1WyU