Frontend: slow query in "Graphs" page

[arli]

I'm running Zabbix server 1.6.2, monitoring ~400 hosts /~5000 items / ~2500 triggers. Everything used to be OK, but soon after upgrading to 1.6, the graphs page loading time went up to 20 minutes.

I discovered, that with old frontend (I believe it was 1.5.something), things were still fast and as a workaround, I used this for a while, but now I would like to get latest version to work as fast, as it was before.

So I looked the database processlist and found that there were two queries that took long time - they both located in include/graphs.inc.php in this function:

/*
 * Function: get_min_itemclock_by_graphid
 *
 * Description:
 *     Return the time of the 1st apearance of items included in graph in trends
 *
 * Author:
 *     Aly
 *
 */
        function get_min_itemclock_by_graphid($graphid){
                $min = 0;
                $row = DBfetch(DBselect('SELECT MIN(t.clock) as clock '.
                                                ' FROM graphs_items gi, trends t '.
                                                ' WHERE gi.graphid='.$graphid.
                                                  ' AND t.itemid = gi.itemid'));

                if(!empty($row) && $row && $row['clock'])
                        $min = $row['clock'];

                $row = DBfetch(DBselect('SELECT MIN(t.clock) as clock '.
                                                ' FROM graphs_items gi, trends_uint t '.
                                                ' WHERE gi.graphid='.$graphid.
                                                  ' AND t.itemid = gi.itemid'));

                if(!empty($row) && $row && $row['clock'])
                        $min = $min == 0 ? $row['clock'] : min($min, $row['clock']);

        return $min;
        }

When they are executed, database is really working hard - I can say this based on the cpu utilization maxed out and load is also high depending on the amount of queries.
MySQL SHOW PROCESSLIST is saying, that query is 'Sending data' for the whole time.

I've tried to use database optimizing tools such as mysqltuner-1.0.0.pl and tuning-primer.sh and tested many MySQL memory configurations.
I also learned, that when running for about a day, there are 5000 joins that are performed without indexes.

Since I've been using Zabbix by upgrading from one of the earliest versions, I re-checked that I have the same database structure and indexes as in the latest release. There were few indexes missing, but they weren't in in any of tables used by this function.
At the moment there are no index on trends nor trends_uint table, only primary keys. Is this how it's supposed to be?

And another thing - I don't know if this has anything to do with it, but I've set ZBX_MAX_PERIOD to 3 years and ZBX_PERIOD_DEFAULT to 24h in include/defines.inc.php.

my total database size 24GB
trends table holding ~60M records > 4GB
trends_uint table holding ~4.5M records > 300MB
graphs_items table holding ~5.5M records > 700KB

Current MySQL configuration:
table_cache = 256
tmp_table_size = 512M
max_heap_table_size = 512M
join_buffer_size = 8M

query_cache_limit = 32M
query_cache_size = 64M
key_buffer_size = 16M

innodb_file_per_table
innodb_buffer_pool_size = 1500M
max_allowed_packet = 16M
thread_stack = 128K
thread_cache_size = 8
sort_buffer_size = 8M

long_query_time=5
log-slow-admin-statements
log-queries-not-using-indexes
log-slow-queries=/var/log/mysql_slow-queries.log

Database server
MySQL 5.0.45
64bit Oracle Enterprise Linux 5
2 Xeon 3.4GHz CPU
6G RAM

Application server
32bit Oracle Enterprise Linux 5
1 Xeon 3GHz CPU
3G RAM

Is there anything else I can do to find the cause of this problem?

[Aly]

Perhaps you already did. We will look closer to those queries. Thank you.

[Aly]

Those queries were really inefficient. Fixed in rev. 6774. You may try downloading our Nightly build of ZABBIX pre1.6.3

P.S. also You may try adding index in table graphs_items on graphid field.

[arli]

Yes, this fixed it. Everything is nice and fast again. Great job

[jarek]

I have same problem!

I have the same problem. Opening of Graphs takes extremly long time. I've downloaded latest nightly build:

http://www.zabbix.com/downloads/nigh...bix-1.6.tar.gz

and created index:

CREATE INDEX graphs_items_graphid on graphs_items(graphid);

but it didn't help.
I have postgres 8.1 and debian etch...

[Aly]

I have the same problem. Opening of Graphs takes extremly long time. I've downloaded latest nightly build:

http://www.zabbix.com/downloads/nigh...bix-1.6.tar.gz

and created index:

CREATE INDEX graphs_items_graphid on graphs_items(graphid);

but it didn't help.
I have postgres 8.1 and debian etch...

If it didn't helped, then I assume it's note the same problem
Maybe server is too busy? Or some exact query is slow?

[jarek]

Long query...

I've found query, which takes loooong time:
2009-02-26 15:09:52 CET LOG: duration: 580560.557 ms statement: SELECT t.itemid, t.clock FROM trends_uint t WHERE (t.itemid IN (22431,22432)) ORDER BY t.itemid, t.clock limit 1
2009-02-26 15:09:52 CET LOG: duration: 572348.576 ms statement: SELECT t.itemid, t.clock FROM trends_uint t WHERE (t.itemid IN (22431,22432)) ORDER BY t.itemid, t.clock limit 1

zabbix2=# \d trends_uint
Table "public.trends_uint"
Column | Type | Modifiers
-----------+---------+----------------------------
itemid | bigint | not null default 0::bigint
clock | integer | not null default 0
num | integer | not null default 0
value_min | bigint | not null default 0::bigint
value_avg | bigint | not null default 0::bigint
value_max | bigint | not null default 0::bigint
Indexes:
"trends_uint_pkey" PRIMARY KEY, btree (itemid, clock)

zabbix2=# select count(*) from trends_uint;
count
--------
148337
(1 row)

It looks that this query does not use index, probably because of IN statement.

[jarek]

Solution

This index solves the problem:

create index trends_uint_itemid on trends_uint(itemid);

regards
Jarek

[Aly]

This query using primary key, at least "Explain" say that. On my test DB with rows > 15 000 000, this query takes less then < 0.05s.

[loshak]

Hi, after upgrading from 1.4.5 to 1.6.2, after some time, i have the same problem with graphs.... it toocked 1-10min to open page....
Did what guys said:
CREATE INDEX graphs_items_graphid on graphs_items(graphid);
It solved my problem.
Cheers to all.

[tekknokrat]

Hi, after upgrading from 1.4.5 to 1.6.2, after some time, i have the same problem with graphs.... it toocked 1-10min to open page....
Did what guys said:
CREATE INDEX graphs_items_graphid on graphs_items(graphid);
It solved my problem.
Cheers to all.

I activated statement_logging for seeing what requests are performed. I dont believe that adding an index solves the problem.
Request time for openeing the graphs page with running zabbix-server was about 2 minutes. Without it was done in a minute.

You can find statement log with timestamps between the requests here: http://pastebin.com/f4c973eef

EDIT: Just noted release of 1.6.3, and will that give a try.

[tekknokrat]

With the tips (including the graphs index) from 1.6.3 installation it is much faster now, thanks

[pHiney]

slow in 1.8.8

I know this is an old entry, but it is exactly what is happening. We get 10-20 mins before the Monitoring|graphs screen comes up, and then the 60 second refresh kicks in and off we go again. we never get to select a graph.

i have tried the two index statement suggested and that has reduced the initial screen time down to nearly a minute, and can now select a graph, but i've yet to actually see one. Graphs thru "latest data" work fine. Was something suppose to get restarted to activate the change ?

mysql> CREATE INDEX graphs_items_graphid on graphs_items(graphid);
Query OK, 17028 rows affected (2.49 sec)
Records: 17028 Duplicates: 0 Warnings: 0

mysql> create index trends_uint_itemid on trends_uint(itemid);
Query OK, 21336098 rows affected (20 min 36.70 sec)
Records: 21336098 Duplicates: 0 Warnings: 0

I'm not very good with sql, i'm a server tech, so i'm not really up to speed on how to interrogate it to find the "slow" query.

I also notice that the code referred to in this forum entry still exists

http://www.zabbix.com/forum/showthread.php?t=12637

is that because the change was invalid or just not passed thru "proper" channels.
anyway, no obvious benefit was found, so it probably wasn't that.

thanks in advance for any ideas in tracking things down (hitting debug on the initial graph screen hasn't returned anything yet - in the time it has taken to write this).

P

[pHiney]

debug

well, i get a graph. yeah. so i hit debug and i got

******************* Stats for script *************************
Total time: 1320028639.6303
Memory limit : 256M
Memory usage : 1.5M - 12M (10.5M)
Memory peak : 12M
SQL selects count: 18
SQL executes count: 7
SQL requests count: 25
Time:7.7E-5 SQL: SET NAMES utf8
Time:0.000301 SQL: SELECT * FROM nodes WHERE nodetype=1 ORDER BY nodeid
Time:0.00046 SQL: SELECT u.*,s.* FROM sessions s,users u WHERE s.sessionid='8c217820fbab4d258ce02ab6b14054ac' AND s.status=0 AND s.userid=u.userid AND ((s.lastaccess+u.autologout>1320028505) OR (u.autologout=0)) AND ((u.userid BETWEEN 000000000000000 AND 099999999999999))
Time:0.000317 SQL: SELECT MAX(g.gui_access) as gui_access FROM usrgrp g, users_groups ug WHERE ug.userid=4 AND g.usrgrpid=ug.usrgrpid
Time:0.000145 SQL: SELECT g.usrgrpid FROM usrgrp g, users_groups ug WHERE ug.userid = 4 AND g.usrgrpid = ug.usrgrpid AND g.users_status = 1 LIMIT 1 OFFSET 0
Time:0.04649 LONG SQL: UPDATE sessions SET lastaccess=1320028505 WHERE sessionid='8c217820fbab4d258ce02ab6b14054ac'
Time:0.000311 SQL: SELECT g.usrgrpid FROM usrgrp g, users_groups ug WHERE ug.userid = 4 AND g.usrgrpid = ug.usrgrpid AND g.debug_mode = 1 LIMIT 1 OFFSET 0
Time:0.025739 LONG SQL: SELECT * FROM profiles WHERE userid=4 AND ((profileid BETWEEN 000000000000000 AND 099999999999999)) ORDER BY userid ASC, profileid ASC
Time:0.000363 SQL: SELECT * FROM config WHERE ((configid BETWEEN 000000000000000 AND 099999999999999))
Time:0.000614 SQL: SELECT title1, url1, title2, url2, title3, url3, title4, url4, title5, url5 FROM user_history WHERE userid=4
Time:113.949793 LONG SQL: SELECT DISTINCT g.* FROM groups g,hosts_groups hg,hosts h WHERE ((g.groupid BETWEEN 000000000000000 AND 099999999999999)) AND hg.groupid=g.groupid AND h.hostid=hg.hostid AND h.status=0 AND EXISTS( SELECT DISTINCT i.itemid FROM items i, graphs_items gi WHERE i.hostid=hg.hostid AND i.itemid=gi.itemid)
Time:20.466661 LONG SQL: SELECT DISTINCT h.hostid, h.host,hg.groupid FROM hosts h,hosts_groups hg WHERE (hg.groupid IN (21)) AND hg.hostid=h.hostid AND ((hg.groupid BETWEEN 000000000000000 AND 099999999999999)) AND h.status=0 AND EXISTS( SELECT DISTINCT i.itemid FROM items i, graphs_items gi WHERE i.hostid=h.hostid AND i.itemid=gi.itemid)
Time:0.133822 LONG SQL: SELECT DISTINCT g.*,i.hostid FROM graphs g,graphs_items gi,items i,hosts h WHERE ((g.graphid BETWEEN 000000000000000 AND 099999999999999)) AND (i.hostid IN (11001)) AND gi.graphid=g.graphid AND i.itemid=gi.itemid AND g.graphid=gi.graphid AND h.hostid=i.hostid AND h.status<>3
Time:0.00039 SQL: SELECT MAX(g.graphtype) as graphtype, MIN(gi.yaxisside) as yaxissidel, MAX(gi.yaxisside) as yaxissider, MAX(g.height) as height FROM graphs g, graphs_items gi WHERE g.graphid=8778 AND gi.graphid=g.graphid
Time:0.000732 SQL: SELECT value_id, source FROM profiles WHERE userid=4 AND idx='web.favorite.graphids' ORDER BY profileid ASC
Time:0.000221 SQL: SELECT DISTINCT gi.itemid FROM graphs_items gi WHERE gi.graphid=8778
Time:0.000152 SQL: SELECT i.itemid, i.value_type FROM items i WHERE (i.itemid IN (44791,44792,44793))
Time:0.000133 SQL: SELECT MAX(i.history) as history, MAX(i.trends) as trends FROM items i WHERE (i.itemid IN (44791,44792,44793))
Time:0.002029 SQL: SELECT ht.itemid, MIN(ht.clock) as min_clock FROM trends_uint ht WHERE (ht.itemid IN (44791,44792,44793)) GROUP BY ht.itemid
Time:0.000417 SQL: SELECT title5, url5 FROM user_history WHERE userid=4
Time:0.001771 SQL: UPDATE user_history SET title1=title2, url1=url2, title2=title3, url2=url3, title3=title4, url3=url4, title4=title5, url4=url5, title5='S_CUSTOM_GRAPHS', url5='charts.php?graphid=8778' WHERE userid=4
Time:4.6E-5 SQL: begin
Time:0.000291 SQL: UPDATE profiles SET value_str='charts.php', type=3 WHERE userid=4 AND idx='web.menu.view.last' AND ((profileid BETWEEN 000000000000000 AND 099999999999999))
Time:0.000163 SQL: UPDATE profiles SET value_str='charts.php', type=3 WHERE userid=4 AND idx='web.paging.lastpage' AND ((profileid BETWEEN 000000000000000 AND 099999999999999))
Time:0.000902 SQL: commit
Total time spent on SQL: 134.63234
******************** End of script ***************************

does this help anyone ?

TIA
p

[pHiney]

now running 1.8.9

still happening ?

any thoughts

******************* Stats for script *************************
Total time: 1325574165.1398
Memory limit : 256M
Memory usage : 1.75M - 11.75M (10M)
Memory peak : 11.75M
SQL selects count: 22
SQL executes count: 2
SQL requests count: 24
Time:0.000237 SQL: SET NAMES utf8
Time:0.151896 LONG SQL: SELECT * FROM nodes WHERE nodetype=1 ORDER BY nodeid
Time:0.000774 SQL: SELECT u.*,s.* FROM sessions s,users u WHERE s.sessionid='55d1884d548c891f62de220a6ce24d55' AND s.status=0 AND s.userid=u.userid AND ((s.lastaccess+u.autologout>1325573771) OR (u.autologout=0)) AND ((u.userid BETWEEN 000000000000000 AND 099999999999999))
Time:0.000762 SQL: SELECT MAX(g.gui_access) as gui_access FROM usrgrp g, users_groups ug WHERE ug.userid=4 AND g.usrgrpid=ug.usrgrpid
Time:0.000291 SQL: SELECT g.usrgrpid FROM usrgrp g, users_groups ug WHERE ug.userid = 4 AND g.usrgrpid = ug.usrgrpid AND g.users_status = 1 LIMIT 1 OFFSET 0
Time:0.139305 LONG SQL: UPDATE sessions SET lastaccess=1325573771 WHERE sessionid='55d1884d548c891f62de220a6ce24d55'
Time:0.000431 SQL: SELECT g.usrgrpid FROM usrgrp g, users_groups ug WHERE ug.userid = 4 AND g.usrgrpid = ug.usrgrpid AND g.debug_mode = 1 LIMIT 1 OFFSET 0
Time:0.014438 LONG SQL: SELECT * FROM profiles WHERE userid=4 AND ((profileid BETWEEN 000000000000000 AND 099999999999999)) ORDER BY userid ASC, profileid ASC
Time:0.036657 LONG SQL: SELECT * FROM config WHERE ((configid BETWEEN 000000000000000 AND 099999999999999))
Time:0.000566 SQL: SELECT title1, url1, title2, url2, title3, url3, title4, url4, title5, url5 FROM user_history WHERE userid=4
Time:0.056397 LONG SQL: SELECT g.* FROM graphs g WHERE ((g.graphid BETWEEN 000000000000000 AND 099999999999999)) AND (g.graphid IN (7977))
Time:0.001267 SQL: SELECT DISTINCT g.groupid,gi.graphid FROM groups g,graphs_items gi,items i,hosts_groups hg WHERE ((g.groupid BETWEEN 000000000000000 AND 099999999999999)) AND (gi.graphid IN (7977)) AND hg.groupid=g.groupid AND i.itemid=gi.itemid AND hg.hostid=i.hostid
Time:0.001368 SQL: SELECT DISTINCT h.hostid,gi.graphid FROM hosts h,graphs_items gi,items i WHERE (gi.graphid IN (7977)) AND i.itemid=gi.itemid AND h.hostid=i.hostid AND ((gi.graphid BETWEEN 000000000000000 AND 099999999999999)) AND h.status IN (0,1)
Time:0.032897 LONG SQL: SELECT DISTINCT h.hostid,gi.graphid FROM hosts h,graphs_items gi,items i WHERE ((h.hostid BETWEEN 000000000000000 AND 099999999999999)) AND h.status=3 AND (gi.graphid IN (7977)) AND i.itemid=gi.itemid AND h.hostid=i.hostid AND ((gi.graphid BETWEEN 000000000000000 AND 099999999999999))
Time:368.478101 LONG SQL: SELECT DISTINCT g.* FROM groups g,hosts_groups hg,hosts h WHERE ((g.groupid BETWEEN 000000000000000 AND 099999999999999)) AND hg.groupid=g.groupid AND h.hostid=hg.hostid AND h.status=0 AND EXISTS( SELECT DISTINCT i.itemid FROM items i, graphs_items gi WHERE i.hostid=hg.hostid AND i.itemid=gi.itemid)
Time:23.805415 LONG SQL: SELECT DISTINCT h.hostid, h.host,hg.groupid FROM hosts h,hosts_groups hg WHERE (hg.groupid IN (9)) AND hg.hostid=h.hostid AND ((hg.groupid BETWEEN 000000000000000 AND 099999999999999)) AND h.status=0 AND EXISTS( SELECT DISTINCT i.itemid FROM items i, graphs_items gi WHERE i.hostid=h.hostid AND i.itemid=gi.itemid)
Time:2.004844 LONG SQL: SELECT DISTINCT g.*,i.hostid FROM graphs g,graphs_items gi,items i,hosts h WHERE ((g.graphid BETWEEN 000000000000000 AND 099999999999999)) AND (i.hostid IN (10171)) AND gi.graphid=g.graphid AND i.itemid=gi.itemid AND g.graphid=gi.graphid AND h.hostid=i.hostid AND h.status<>3
Time:0.000708 SQL: SELECT MAX(g.graphtype) as graphtype, MIN(gi.yaxisside) as yaxissidel, MAX(gi.yaxisside) as yaxissider, MAX(g.height) as height FROM graphs g, graphs_items gi WHERE g.graphid=7977 AND gi.graphid=g.graphid
Time:0.003949 SQL: SELECT value_id, source FROM profiles WHERE userid=4 AND idx='web.favorite.graphids' ORDER BY profileid ASC
Time:0.001729 SQL: SELECT DISTINCT gi.itemid FROM graphs_items gi WHERE gi.graphid=7977
Time:0.000319 SQL: SELECT i.itemid, i.value_type FROM items i WHERE (i.itemid IN (42140,42141))
Time:0.000364 SQL: SELECT MAX(i.history) as history, MAX(i.trends) as trends FROM items i WHERE (i.itemid IN (42140,42141))
Time:0.087653 LONG SQL: SELECT ht.itemid, MIN(ht.clock) as min_clock FROM history_uint ht WHERE (ht.itemid IN (42140,42141)) GROUP BY ht.itemid
Time:0.020732 LONG SQL: SELECT title5, url5 FROM user_history WHERE userid=4
Total time spent on SQL: 394.8411
******************** End of script ***************************


Zabbix server is running Yes localhost:10051
Number of hosts (monitored/not monitored/templates) 901 802 / 37 / 62
Number of items (monitored/disabled/not supported) 18524 18126 / 21 / 377
Number of triggers (enabled/disabled)[problem/unknown/ok] 1775 1553 / 222 [2 / 45 / 1506]
Number of users (online) 8 1
Required server performance, new values per second 559 -