{"id":236,"date":"2016-12-08T10:36:17","date_gmt":"2016-12-08T09:36:17","guid":{"rendered":"http:\/\/blog.le-vert.net\/?p=236"},"modified":"2016-12-08T17:57:08","modified_gmt":"2016-12-08T16:57:08","slug":"centreon-log-table-getting-insanely-huge","status":"publish","type":"post","link":"https:\/\/blog.le-vert.net\/?p=236","title":{"rendered":"Centreon “log” table getting insanely huge"},"content":{"rendered":"
\n\t\t\t\t\tTweet<\/a>\n\t\t\t\t<\/div><\/div>

Hi there,<\/p>\n

I’m currently migrating some old Centreons 2.5\/2.6 with Nagios\/NDO to Centreon 2.7 with Centreon-Engine\/Centreon-broker but I’m experiencing some issues with insanely large MySQL tables to migrate:<\/p>\n

\r\nroot@server:~# ls -lah \/var\/lib\/mysql\/centreon_storage\/log.*\r\n-rw-rw---- 1 mysql mysql  13K Apr 15  2015 \/var\/lib\/mysql\/centreon_storage\/log.frm\r\n-rw-rw---- 1 mysql mysql  16G Dec  8 09:18 \/var\/lib\/mysql\/centreon_storage\/log.MYD\r\n-rw-rw---- 1 mysql mysql 6.0G Dec  8 09:18 \/var\/lib\/mysql\/centreon_storage\/log.MYI\r\n<\/pre>\n
This table contains old Nagios logs and according to a forum post it’s being use when clicking on Monitoring > Event logs and is used when doing reporting actions.
\nFair enough, I don’t mind anyway of what happened last year, reporting is done on a monthly basis.<\/p>\n
So let’s see what is the oldest entry there:<\/p>\n
\r\nroot@server:~# echo 'SELECT FROM_UNIXTIME(ctime) FROM log ORDER BY ctime ASC LIMIT 1' | mysql -N centreon_storage\r\n2015-06-14 19:19:00\r\n<\/pre>\n
Sadly, it’s using unix timestamp and not MySQL datetime format, so we’ll have to do some conversion to get it humanely-readable.
\nTo be honest, when I started the cleanup the oldest entry was even older.<\/p>\n
I’m not sure if Centreon is supposed to clean this out. I guess it does, probably using one of the various cron jobs installed by Centreon but according to my experience this is highly borked and can surely lead to uncleaned entries.<\/p>\n
Let’s validate we’re not going to delete bad entries by running a select first<\/p>\n
\r\nroot@server:~# echo 'SELECT FROM_UNIXTIME(ctime), ctime, output FROM log WHERE ctime < UNIX_TIMESTAMP(\"2016-06-08 00:00:00\") LIMIT 5' | mysql -N centreon_storage\r\n2015-06-14 19:19:00\t1434309540\tMax concurrent service checks (200) has been reached.  Nudging server1:traffic_eth0 by 11 seconds...\r\n2015-06-14 19:19:00\t1434309540\tMax concurrent service checks (200) has been reached.  Nudging server1:Ping by 7 seconds...\r\n2015-06-14 19:19:00\t1434309540\tMax concurrent service checks (200) has been reached.  Nudging server2:Memory by 12 seconds...\r\n2015-06-14 19:19:00\t1434309540\tMax concurrent service checks (200) has been reached.  Nudging server3:Processor by 6 seconds...\r\n2015-06-14 19:19:01\t1434309541\tMax concurrent service checks (200) has been reached.  Nudging server3:Memory by 10 seconds...\r\n<\/pre>\n
Looks okay. Be sure to compare \"ctime\" and the converted date and play with the WHERE condition so you can be sure it's really working properly.
\nFor instance, if you swap \"2016-06-08 00:00:00\" with \"2015-06-14 19:19:01\" the last line should disappear.<\/p>\n
Once you've confirmed your not deleting anything useful, go ahead with a DELETE statement:<\/p>\n
\r\nroot@server:~# time echo 'DELETE FROM log WHERE ctime < UNIX_TIMESTAMP(\"2016-06-08 00:00:00\") LIMIT 1000000' | mysql -N centreon_storage\r\n\r\nreal\t0m51.884s\r\nuser\t0m0.000s\r\nsys\t0m0.008s\r\n<\/pre>\n
I decided to use LIMIT here, to avoid loading too much the server for an unknown time. \"time\" command has been added here so you can have a measurement of the time required to delete 1 000 000 entries (52s here).<\/p>\n
You can now recheck the oldest log you have now:<\/p>\n
\r\nroot@server:~# echo 'SELECT FROM_UNIXTIME(ctime) FROM log ORDER BY ctime ASC LIMIT 1' | mysql -N centreon_storage\r\n2015-06-19 21:29:54\r\n<\/pre>\n
It seems it'll be a long way to go before getting to june, 2016 \ud83d\ude09<\/p>\n
Bonus:
\nAll in one command, so you just have too check your term when coming back from the coffee machine to see its progress:<\/p>\n
\r\nroot@server:~# while true; do echo 'DELETE FROM log WHERE ctime < UNIX_TIMESTAMP(\"2016-06-08 00:00:00\") LIMIT 100000' | mysql -N centreon_storage && echo 'SELECT FROM_UNIXTIME(ctime) FROM log ORDER BY ctime ASC LIMIT 1' | mysql -N centreon_storage && sleep 2; done\r\n2015-06-21 01:47:32\r\n2015-06-21 10:59:55\r\n2015-06-21 19:57:21\r\n2015-06-22 04:58:59\r\n[...]\r\n<\/pre>\n
When the loop keeps outputing the same date, it means DELETE is not removing anything anymore, time to hit ctrl+c !<\/p>\n
Let's have a look to the table size now:<\/p>\n
\r\nroot@server:~# ls -lah \/var\/lib\/mysql\/centreon_storage\/log.*\r\n-rw-rw---- 1 mysql mysql  13K Apr 15  2015 \/var\/lib\/mysql\/centreon_storage\/log.frm\r\n-rw-rw---- 1 mysql mysql  16G Dec  8 10:25 \/var\/lib\/mysql\/centreon_storage\/log.MYD\r\n-rw-rw---- 1 mysql mysql 6.0G Dec  8 10:25 \/var\/lib\/mysql\/centreon_storage\/log.MYI\r\n<\/pre>\n
Uh ?<\/p>\n
Thanks to Google, it seems I need to run \"OPTIMIZE TABLE\" to reclaim the freed disk space. But there're two thing I know about optimize and huge tables like this one:
\n* It will write lock the table
\n* It will last for ages (I mean up to *days*)<\/p>\n
Let's try to make this process a bit quicker... Ever heard about eatmydata<\/a> ?
\nIt'll will disable fsync() system call, giving you some kind of write cache on steroids; drawbacks: you're not protected anymore from file corruption in case of a crash.<\/p>\n
For now, we'll take the risk and hack mysql init script to run with eatmydata:<\/p>\n
\r\nroot@server:~# sed -i 's!\/usr\/bin\/mysqld_safe > \/dev\/null!\/usr\/bin\/eatmydata \/usr\/bin\/mysqld_safe > \/dev\/null!' \/etc\/init.d\/mysql\r\nroot@server:~# systemctl --system daemon-reload\r\nroot@server:~# systemctl restart mysql\r\n<\/pre>\n
It's pretty hard to figure out if the trick worked or not. Actually, it'll set a LD_PRELOAD env variable to override libc calls with the unprotected ones.
\nThanks to \/proc, we can check this by looking at the mysqld PID attributes<\/p>\n
\r\nroot@server:~# cat \/proc\/`ps aux | grep \/usr\/sbin\/mysql | grep -v grep | awk '{ print $2 }'`\/environ | tr '\\0' '\\n'\r\n<\/pre>\n
(basically, I get \/usr\/sbin\/mysql pid which is the main MySQL server process and check \/proc\/\/environ)<\/p>\n
If it worked, you should find a line like this:<\/p>\n
\r\nLD_PRELOAD=\/usr\/lib\/libeatmydata\/libeatmydata.so \/usr\/lib\/libeatmydata\/libeatmydata.so\r\n<\/pre>\n
We can now run optimize on this table:<\/p>\n
\r\nroot@server:~# echo \"OPTIMIZE TABLE log\" | mysql centreon_storage\r\n<\/pre>\n
You can see it processing by running:<\/p>\n
\r\nwatch -n 2 ls -lah \/var\/lib\/mysql\/centreon_storage\/log.*\r\n<\/pre>\n
\r\n-rw-rw---- 1 mysql mysql  13K Dec  8 14:58 \/var\/lib\/mysql\/centreon_storage\/log.frm\r\n-rw-rw---- 1 mysql mysql  11G Dec  8 16:45 \/var\/lib\/mysql\/centreon_storage\/log.MYD\r\n-rw-rw---- 1 mysql mysql 3.1G Dec  8 16:45 \/var\/lib\/mysql\/centreon_storage\/log.MYI\r\n-rw-rw---- 1 mysql mysql 710M Dec  8 16:53 \/var\/lib\/mysql\/centreon_storage\/log.TMM\r\n<\/pre>\n
Now you will have to wait a couple of hours for the optimization to complete...<\/p>\n","protected":false},"excerpt":{"rendered":"
Hi there, I’m currently migrating some old Centreons 2.5\/2.6 with Nagios\/NDO to Centreon 2.7 with Centreon-Engine\/Centreon-broker but I’m experiencing some issues with insanely large MySQL tables to migrate: root@server:~# ls -lah \/var\/lib\/mysql\/centreon_storage\/log.* -rw-rw—- 1 mysql mysql 13K Apr 15 2015 … Continue reading →<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1],"tags":[],"_links":{"self":[{"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=\/wp\/v2\/posts\/236"}],"collection":[{"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=236"}],"version-history":[{"count":6,"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=\/wp\/v2\/posts\/236\/revisions"}],"predecessor-version":[{"id":243,"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=\/wp\/v2\/posts\/236\/revisions\/243"}],"wp:attachment":[{"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=236"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=236"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/blog.le-vert.net\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=236"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}