[ZBX-17069] housekeeper deleted 0 hist/trends Created: 2019 Dec 11 Updated: 2024 Apr 10 Resolved: 2019 Dec 19 |
|
| Status: | Closed |
| Project: | ZABBIX BUGS AND ISSUES |
| Component/s: | None |
| Affects Version/s: | 3.0.28 |
| Fix Version/s: | None |
| Type: | Incident report | Priority: | Trivial |
| Reporter: | Dan Wys | Assignee: | Edgars Melveris |
| Resolution: | Duplicate | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
Zabbix Appliance 3.4.10. MySQL mysql Ver 14.14 Distrib 5.7.22, for Linux (x86_64) using EditLine wrapper |
||
| Attachments: |
20191219_Zabbix_server.log
image-2019-12-17-10-05-41-969.png
|
||||||||
| Issue Links: |
|
||||||||
| Team: |  Team A |
||||||||
| Description |
|
Housekeeper is not deleteing any history and trends. It deletes all other values from tables. Housekeeper settings in zabbix_server.conf file are default, but tried to extend the frequency to 6h and it didn't help. Read:
Tables are quite huge: +----------+--------------+------------+ | Database | Table | Size in MB | +----------+--------------+------------+ | zabbix | history_uint | 85274.13 | | zabbix | history | 81378.13 | | zabbix | history_text | 8190.34 | | zabbix | trends_uint | 3663.63 | | zabbix | trends | 2517.75 | +----------+--------------+------------+ mysql> SELECT FROM_UNIXTIME(MIN(clock)) FROM `history_uint`; Earliest item value from history_uint is more than 1year old and it took 3 hours to get result: +---------------------------+ | FROM_UNIXTIME(MIN(clock)) | +---------------------------+ | 2018-04-18 12:42:23 | +---------------------------+ 1 row in set (3 hours 2 min 34.39 sec) Below are some logs. Noticed some slow queries. Any idea if the issue is known and how to resolve it? 80010:20191211:154527.042 forced execution of the housekeeper
80010:20191211:154527.042 executing housekeeper
80010:20191211:154527.170 housekeeper [deleted 0 hist/trends, 0 items/triggers, 2 events, 49 problems, 0 sessions, 0 alarms, 0 audit items in 0.075627 sec, idle for 1 hour(s)]
80010:20191211:160117.952 executing housekeeper
80010:20191211:160117.952 __zbx_zbx_setproctitle() title:'housekeeper [connecting to the database]'
80010:20191211:160117.952 In DBconnect() flag:0
80010:20191211:160117.953 End of DBconnect():0
80010:20191211:160117.954 __zbx_zbx_setproctitle() title:'housekeeper [removing old history and trends]'
80010:20191211:160117.954 In housekeeping_history_and_trends() now:1576076477
80010:20191211:160117.954 In hk_history_delete_queue_prepare_all()
80010:20191211:160117.954 query [txnlev:0] [select i.itemid,i.value_type,i.history,i.trends,h.hostid from items i,hosts h where i.hostid=h.hostid and h.status in (0,1)]
80010:20191211:160117.999 End of hk_history_delete_queue_prepare_all()
*80010:20191211:160117.999 End of housekeeping_history_and_trends():0*
80010:20191211:160117.999 __zbx_zbx_setproctitle() title:'housekeeper [removing old problems]'
80010:20191211:160117.999 In housekeeping_problems() now:1576076477
80010:20191211:160118.000 query without transaction detected
80010:20191211:160118.000 query [txnlev:0] [delete from problem where r_clock<>0 and r_clock<1575990077]
80010:20191211:160118.023 End of housekeeping_problems():130
80010:20191211:160118.023 __zbx_zbx_setproctitle() title:'housekeeper [removing old events]'
80010:20191211:160118.023 In housekeeping_process_rule() table:'events' field_name:'eventid' filter:'events.source=0 and events.object=0 and not exists (select null from problem where events.eventid=problem.eventid) and not exists (select null from problem where events.eventid=problem.r_eventid)' min_clock:1544539527 now:1576076477
80010:20191211:160118.023 query [txnlev:0] [select eventid from events where clock<1544540477 and events.source=0 and events.object=0 and not exists (select null from problem where events.eventid=problem.eventid) and not exists (select null from problem where events.eventid=problem.r_eventid) order by eventid limit 5000]
80010:20191211:160118.024 query without transaction detected
80010:20191211:160118.025 query [txnlev:0] [delete from events where eventid in (862928,862929)]
80010:20191211:160118.033 query [txnlev:0] [select eventid from events where clock<1544540477 and events.source=0 and events.object=0 and not exists (select null from problem where events.eventid=problem.eventid) and not exists (select null from problem where events.eventid=problem.r_eventid) order by eventid limit 5000]
80010:20191211:160118.034 End of housekeeping_process_rule():2
80010:20191211:160118.034 In housekeeping_process_rule() table:'events' field_name:'eventid' filter:'events.source=3 and events.object=0 and not exists (select null from problem where events.eventid=problem.eventid) and not exists (select null from problem where events.eventid=problem.r_eventid)' min_clock:1546259955 now:1576076477
80010:20191211:160118.034 End of housekeeping_process_rule():0
80010:20191211:160118.034 In housekeeping_process_rule() table:'events' field_name:'eventid' filter:'events.source=3 and events.object=4 and not exists (select null from problem where events.eventid=problem.eventid) and not exists (select null from problem where events.eventid=problem.r_eventid)' min_clock:1546453867 now:1576076477
80010:20191211:160118.034 End of housekeeping_process_rule():0
80010:20191211:160118.034 In housekeeping_process_rule() table:'events' field_name:'eventid' filter:'events.source=3 and events.object=5 and not exists (select null from problem where events.eventid=problem.eventid) and not exists (select null from problem where events.eventid=problem.r_eventid)' min_clock:1552392386 now:1576076477
80010:20191211:160118.034 End of housekeeping_process_rule():0
80010:20191211:160118.034 In housekeeping_process_rule() table:'events' field_name:'eventid' filter:'events.source=1 and events.object=1' min_clock:1576075114 now:1576076477
80010:20191211:160118.034 End of housekeeping_process_rule():0
80010:20191211:160118.034 In housekeeping_process_rule() table:'events' field_name:'eventid' filter:'events.source=1 and events.object=2' min_clock:1576075114 now:1576076477
80010:20191211:160118.034 End of housekeeping_process_rule():0
80010:20191211:160118.034 In housekeeping_process_rule() table:'events' field_name:'eventid' filter:'events.source=2 and events.object=3' min_clock:1576075114 now:1576076477
80010:20191211:160118.034 End of housekeeping_process_rule():0
80010:20191211:160118.034 __zbx_zbx_setproctitle() title:'housekeeper [removing old sessions]'
80010:20191211:160118.034 In housekeeping_sessions() now:1576076477
80010:20191211:160118.034 query without transaction detected
80010:20191211:160118.035 query [txnlev:0] [delete from sessions where lastaccess<1544540477 limit 5000]
80010:20191211:160118.035 End of housekeeping_sessions():0
80010:20191211:160118.035 __zbx_zbx_setproctitle() title:'housekeeper [removing old service alarms]'
80010:20191211:160118.035 In housekeeping_process_rule() table:'service_alarms' field_name:'servicealarmid' filter:'' min_clock:1576075114 now:1576076477
80010:20191211:160118.035 End of housekeeping_process_rule():0
80010:20191211:160118.035 __zbx_zbx_setproctitle() title:'housekeeper [removing old audit log items]'
80010:20191211:160118.035 In housekeeping_process_rule() table:'auditlog' field_name:'auditid' filter:'' min_clock:1551118390 now:1576076477
80010:20191211:160118.035 End of housekeeping_process_rule():0
80010:20191211:160118.035 __zbx_zbx_setproctitle() title:'housekeeper [removing deleted items data]'
80010:20191211:160118.035 In housekeeping_cleanup()
80010:20191211:160118.035 query [txnlev:0] [select housekeeperid,tablename,field,value from housekeeper where tablename in ('history','history_log','history_str','history_text','history_uint','trends','trends_uint','events') order by tablename]
80010:20191211:160118.036 query without transaction detected
80010:20191211:160118.036 query [txnlev:0] [delete from problem where source=3 and object=5 and objectid=218744 limit 5000]
80010:20191211:160118.037 query without transaction detected
80010:20191211:160118.037 query [txnlev:0] [delete from problem where source=3 and object=4 and objectid=218744 limit 5000]
80010:20191211:160118.037 query without transaction detected
80010:20191211:160118.037 query [txnlev:0] [delete from problem where source=3 and object=5 and objectid=218743 limit 5000]
80010:20191211:160118.038 query without transaction detected
(...) 80010:20191211:160119.398 End of housekeeping_cleanup():5912 80010:20191211:160119.398 housekeeper [deleted 0 hist/trends, 5912 items/triggers, 2 events, 130 problems, 0 sessions, 0 alarms, 0 audit items in 1.444192 sec, idle for 1 hour(s)] 80010:20191211:160119.398 __zbx_zbx_setproctitle() title:'housekeeper [*deleted 0 hist/trends,* 5912 items/triggers, 2 events, 0 sessions, 0 alarms, 0 audit items in 1.444192 sec, idle for 1 hour(s)]' *80017:20191211:160146.640 slow query: 3.333721 sec, "select distinct itemid from trends where clock>=1576072800 and (itemid between 30699 and 30703 or itemid in (28900,28901,28902,33400,33401,33402,33403,37600,37601,37602,37603,37900,37901,37902,38199,38499,38500,38501,38502,42699,42700,43299,43300,43301,43302,107200,107201,107202,215502,217003))"* *80015:20191211:160204.509 slow query: 23.082986 sec, "select distinct itemid from trends_uint where clock>=1576072800 and (itemid between 42981 and 42990 or itemid between 43280 and 43290 or itemid between 87681 and 87690 or itemid between 93979 and 93990 or itemid in (28582,29180,29181,29183,29184,29185,29188,29480,29481,29484,29488,29490,29491,30981,31280,31281,31282,31286,33050,33984,33985,33989,35483,35484,36080,36084,36085,37580,42080,54683,209180,209182,209183,214022,214023,214028,214085))"* *80014:20191211:160211.910 slow query: 32.203702 sec, "select distinct itemid from trends where clock>=1576072800 and (itemid between 28564 and 28568 or itemid between 29464 and 29469 or itemid between 30365 and 30371 or itemid between 37864 and 37870 or itemid between 38164 and 38171 or itemid between 38465 and 38470 or itemid between 42064 and 42069 or itemid in (30965,30966,30967,30968,31269,33367,42964,42965,43264,43265,43266,43268,43269,60362,60363,60370,188465,188466,188467))"* |
| Comments |
| Comment by dimir [ 2019 Dec 11 ] |
|
Is it enabled in Frontend "Administration > Housekeeping"? |
| Comment by Dan Wys [ 2019 Dec 11 ] |
|
Yes, it is enabled. |
| Comment by Edgars Melveris [ 2019 Dec 16 ] |
|
Can you add a screenshot of Administration -> General -> Housekeeping? The behavior looks exactly like when it's disabled. |
| Comment by Dan Wys [ 2019 Dec 17 ] |
|
There you go:
|
| Comment by Dan Wys [ 2019 Dec 17 ] |
|
also housekeeper settings are default as in zabbix_server.conf file: 350 # Option: HousekeepingFrequency 351 # How often Zabbix will perform housekeeping procedure (in hours). 352 # Housekeeping is removing outdated information from the database. 353 # To prevent Housekeeper from being overloaded, no more than 4 times HousekeepingFrequency 354 # hours of outdated information are deleted in one housekeeping cycle, for each item. 355 # To lower load on server startup housekeeping is postponed for 30 minutes after server start. 356 # With HousekeepingFrequency=0 the housekeeper can be only executed using the runtime control option. 357 # In this case the period of outdated information deleted in one housekeeping cycle is 4 times the 358 # period since the last housekeeping cycle, but not less than 4 hours and not greater than 4 days. 359 # 360 # Mandatory: no 361 # Range: 0-24 362 # Default: 363 # HousekeepingFrequency=1 364 365 ### Option: MaxHousekeeperDelete 366 # The table "housekeeper" contains "tasks" for housekeeping procedure in the format: 367 # [housekeeperid], [tablename], [field], [value]. 368 # No more than 'MaxHousekeeperDelete' rows (corresponding to [tablename], [field], [value]) 369 # will be deleted per one task in one housekeeping cycle. 370 # SQLite3 does not use this parameter, deletes all corresponding rows without a limit. 371 # If set to 0 then no limit is used at all. In this case you must know what you are doing! 372 # 373 # Mandatory: no 374 # Range: 0-1000000 375 # Default: 376 # MaxHousekeeperDelete=5000
|
| Comment by Edgars Melveris [ 2019 Dec 17 ] |
|
Do you have a full log from the previous time the server was restarted? If not, can you restart the server, after that increase debug level for houeskeeper and execute it manually? |
| Comment by Edgars Melveris [ 2019 Dec 17 ] |
|
Also, can you check this: select min(clock), itemid from history_uint; select itemid, value_type from items where itemid=<your itemid>; Replace <your itemid> in the second query with the itemid returned form the first query. |
| Comment by Dan Wys [ 2019 Dec 19 ] |
|
Ok so I ran: mysql> select min(clock), itemid from history_uint; ERROR 1140 (42000): In aggregated query without GROUP BY, expression #2 of SELECT list contains nonaggregated column 'zabbix.history_uint.itemid'; this is incompatible with sql_mode=only_full_group_by
So changed the select a little bit and here is the result: mysql> select min(clock), itemid from history_uint GROUP BY itemid ORDER BY min(clock) ASC LIMIT 1; +------------+--------+ | min(clock) | itemid | +------------+--------+ | 1524048143 | 37942 | +------------+--------+ 1 row in set (0.44 sec) mysql> select itemid, value_type from items where itemid=37942; +--------+------------+ | itemid | value_type | +--------+------------+ | 37942 | 0 | +--------+------------+ 1 row in set (0.00 sec)
|
| Comment by Dan Wys [ 2019 Dec 19 ] |
|
20191219_Zabbix_server.log |
| Comment by Edgars Melveris [ 2019 Dec 19 ] |
|
As per item_type description:
The history for this item shouldn't be in this table, as history_uint is for integers (value_type=3). Most probably, this is an item, that previously was saved as float and then changed to integer. There might be more of those in the tables and they cause an issue in housekeeper, as it finds this as the oldest record as starting point for data removal, but still won't delete it. |
