Housekeeper bug?

[w3orc]

i found that my history_uint table grows day by day without any reasons for this. Housekeeper is working, global option for history item store is 7 days, but there is much older data.

 select *,from_unixtime(clock)  from history_uint where from_unixtime(clock) < '2017-12-27 12:21:13' limit 10;
+--------+------------+-------+-----------+----------------------+
| itemid | clock      | value | ns        | from_unixtime(clock) |
+--------+------------+-------+-----------+----------------------+
|  27373 | 1511774473 |     1 | 268955582 | 2017-11-27 12:21:13  |
|  27373 | 1511774503 |     1 | 800288560 | 2017-11-27 12:21:43  |
|  27373 | 1511774533 |     1 | 505862683 | 2017-11-27 12:22:13  |
|  27373 | 1511774563 |     1 | 529794027 | 2017-11-27 12:22:43  |
|  27373 | 1511774593 |     1 | 314871869 | 2017-11-27 12:23:13  |
|  27373 | 1511774623 |     1 | 520640020 | 2017-11-27 12:23:43  |
|  27373 | 1511774653 |     1 | 733799533 | 2017-11-27 12:24:13  |
|  27373 | 1511774683 |     1 |  71274059 | 2017-11-27 12:24:43  |
|  27373 | 1511774713 |     1 | 966276693 | 2017-11-27 12:25:13  |
|  27373 | 1511774743 |     1 | 722119137 | 2017-11-27 12:25:43  |
+--------+------------+-------+-----------+----------------------+

curent system date

# date
Thu Jun 28 11:30:38 MSK 2018

select history, value_type from items where itemid = 27373;
+---------+------------+
| history | [B]value_type[/B] |
+---------+------------+
|       7 |       [B]   4[/B] |
+---------+------------+

I checked value type and is 4. 4 is text, why then its history is in history_uint table?

Housekeeper options and zabbix version.

# grep House /etc/zabbix/zabbix_server.conf 
### Option: HousekeepingFrequency
#    Housekeeping is removing outdated information from the database.
#    To prevent Housekeeper from being overloaded, no more than 4 times HousekeepingFrequency
#    With HousekeepingFrequency=0 the housekeeper can be only executed using the runtime control option.
HousekeepingFrequency=12
### Option: MaxHousekeeperDelete
#    No more than 'MaxHousekeeperDelete' rows (corresponding to [tablename], [field], [value])
MaxHousekeeperDelete=0


# zabbix_server --version
zabbix_server (Zabbix) 3.0.9

Is this a known problem?

[kernbug]

Hi,

And what about this settings (https://www.zabbix.com/documentation...tion/general)?

[w3orc]

Hi,

And what about this settings (https://www.zabbix.com/documentation...tion/general)?

As i said, 7 days for history.

[kernbug]

As i said, 7 days for history.

Ok, try to execute manually housekeeper and check log file for an errors:

 zabbix_server -c /some/config/path/zabbix_server.conf -R housekeeper_execute

[w3orc]

Ok, try to execute manually housekeeper and check log file for an errors:

zabbix_server -c /some/config/path/zabbix_server.conf -R housekeeper_execute

580:20180629:142832.594 forced execution of the housekeeper
   580:20180629:142832.594 executing housekeeper
   580:20180629:142837.129 slow query: 4.523147 sec, "delete from history where itemid=23252 and clock<1529666912"
   580:20180629:143058.102 slow query: 23.870991 sec, "delete from history_uint where itemid=24408 and clock<1525622088"
   580:20180629:143110.796 slow query: 12.694047 sec, "delete from history_uint where itemid=24409 and clock<1525622126"
   580:20180629:143134.459 slow query: 3.289258 sec, "delete from history_uint where itemid=25010 and clock<1529666912"
   580:20180629:143219.394 slow query: 25.553402 sec, "delete from history_uint where itemid=25246 and clock<1523030109"
   580:20180629:143230.268 slow query: 3.655530 sec, "delete from history_uint where itemid=25251 and clock<1523030109"
   580:20180629:143252.338 slow query: 3.841204 sec, "delete from history_uint where itemid=25306 and clock<1523030111"
   580:20180629:143258.470 slow query: 6.131787 sec, "delete from history_uint where itemid=25307 and clock<1523030111"
   580:20180629:143303.273 slow query: 4.636615 sec, "delete from history_uint where itemid=25308 and clock<1523030111"
   580:20180629:143327.124 slow query: 3.461423 sec, "delete from history_uint where itemid=25326 and clock<1523030111"
   580:20180629:143420.371 slow query: 20.493714 sec, "delete from history_uint where itemid=25686 and clock<1528214161"
   580:20180629:143449.301 slow query: 19.391681 sec, "delete from history_uint where itemid=25859 and clock<1528214144"
   580:20180629:143640.878 slow query: 8.458145 sec, "delete from history_uint where itemid=26917 and clock<1528214246"
   580:20180629:143706.229 slow query: 4.014955 sec, "delete from history_uint where itemid=27580 and clock<1529666912"
   580:20180629:143714.398 slow query: 4.042690 sec, "delete from history_uint where itemid=27808 and clock<1528214144"
   580:20180629:143803.259 slow query: 13.836990 sec, "delete from history_uint where itemid=28204 and clock<1525622093"
   580:20180629:143806.352 slow query: 3.093092 sec, "delete from history_uint where itemid=28205 and clock<1525622100"
   580:20180629:143818.027 slow query: 4.073560 sec, "delete from history_uint where itemid=28303 and clock<1525622106"
   580:20180629:143829.055 slow query: 3.980975 sec, "delete from history_uint where itemid=28351 and clock<1525622092"
   580:20180629:143834.442 slow query: 5.386750 sec, "delete from history_uint where itemid=28352 and clock<1525622104"
   580:20180629:143840.246 slow query: 3.362591 sec, "delete from history_uint where itemid=28354 and clock<1529666912"
   580:20180629:143849.028 slow query: 5.732533 sec, "delete from history_uint where itemid=28357 and clock<1529666912"
   580:20180629:143857.178 slow query: 3.749913 sec, "delete from history_uint where itemid=28360 and clock<1529666912"
   580:20180629:143900.220 slow query: 3.041283 sec, "delete from history_uint where itemid=28361 and clock<1529666912"
   580:20180629:143903.472 slow query: 3.251989 sec, "delete from history_uint where itemid=28362 and clock<1529666912"
   580:20180629:143907.743 slow query: 3.436975 sec, "delete from history_uint where itemid=28373 and clock<1529666912"
   580:20180629:143916.668 slow query: 8.925127 sec, "delete from history_uint where itemid=28374 and clock<1529666912"
   580:20180629:143930.461 slow query: 13.792476 sec, "delete from history_uint where itemid=28375 and clock<1529666912"
   580:20180629:143937.965 slow query: 7.503827 sec, "delete from history_uint where itemid=28376 and clock<1529666912"
   580:20180629:143945.463 slow query: 7.498668 sec, "delete from history_uint where itemid=28377 and clock<1529666912"
   580:20180629:143951.039 slow query: 4.837870 sec, "delete from history_uint where itemid=28384 and clock<1529666912"
   580:20180629:143955.029 slow query: 3.104383 sec, "delete from history_uint where itemid=28386 and clock<1529666912"
   580:20180629:144002.312 slow query: 3.190949 sec, "delete from history_uint where itemid=28390 and clock<1529666912"
   580:20180629:144007.055 slow query: 4.743278 sec, "delete from history_uint where itemid=28391 and clock<1529666912"
   580:20180629:144010.315 slow query: 3.260204 sec, "delete from history_uint where itemid=28392 and clock<1529666912"
   580:20180629:144051.537 slow query: 3.082666 sec, "delete from history_uint where itemid=28607 and clock<1529666912"
   580:20180629:144136.003 slow query: 3.023195 sec, "delete from history_uint where itemid=28850 and clock<1529666912"
   580:20180629:144210.132 slow query: 3.600435 sec, "delete from trends_uint where itemid=26444 and clock<1498735712"
   580:20180629:144214.617 slow query: 3.303200 sec, "delete from trends_uint where itemid=27001 and clock<1498735712"
   580:20180629:144218.841 slow query: 3.515733 sec, "delete from trends_uint where itemid=27294 and clock<1498735712"
   580:20180629:144242.249 slow query: 3.218642 sec, "delete from trends_uint where itemid=27522"
   580:20180629:144246.112 slow query: 3.301289 sec, "delete from trends_uint where itemid=27527"
   580:20180629:144250.976 slow query: 3.928875 sec, "delete from trends_uint where itemid=27682"
   580:20180629:144255.333 slow query: 3.658704 sec, "delete from trends_uint where itemid=27687"
   580:20180629:144311.538 slow query: 3.305273 sec, "delete from trends_uint where itemid=27518"
   580:20180629:144326.715 housekeeper [deleted 4046905 hist/trends, 344197 items, 185 events, 0 sessions, 0 alarms, 0 audit items in 894.119670 sec, idle for 12 hour(s)]

[kloczek]

i found that my history_uint table grows day by day without any reasons for this. Housekeeper is working, global option for history item store is 7 days, but there is much older data.

 select *,from_unixtime(clock) from history_uint where from_unixtime(clock) < '2017-12-27 12:21:13' limit 10;
+--------+------------+-------+-----------+----------------------+
| itemid | clock | value | ns | from_unixtime(clock) |
+--------+------------+-------+-----------+----------------------+
| 27373 | 1511774473 | 1 | 268955582 | 2017-11-27 12:21:13 |
| 27373 | 1511774503 | 1 | 800288560 | 2017-11-27 12:21:43 |
| 27373 | 1511774533 | 1 | 505862683 | 2017-11-27 12:22:13 |
| 27373 | 1511774563 | 1 | 529794027 | 2017-11-27 12:22:43 |
| 27373 | 1511774593 | 1 | 314871869 | 2017-11-27 12:23:13 |
| 27373 | 1511774623 | 1 | 520640020 | 2017-11-27 12:23:43 |
| 27373 | 1511774653 | 1 | 733799533 | 2017-11-27 12:24:13 |
| 27373 | 1511774683 | 1 | 71274059 | 2017-11-27 12:24:43 |
| 27373 | 1511774713 | 1 | 966276693 | 2017-11-27 12:25:13 |
| 27373 | 1511774743 | 1 | 722119137 | 2017-11-27 12:25:43 |
+--------+------------+-------+-----------+----------------------+

curent system date

[CODE]

Let me point on one detail in above.
Column with ns is not 0. It means that you are using zabbix trapper items -> sometimes using such items means that in such cases it is hard to predict exact number of monitoring data points -> daily growth of the DB size is unpredictable.

[w3orc]

Let me point on one detail in above.
Column with ns is not 0. It means that you are using zabbix trapper items -> sometimes using such items means that in such cases it is hard to predict exact number of monitoring data points -> daily growth of the DB size is unpredictable.

Sure, but how about that fact that data is not deleting? Data is about 8 month old... its a little bit weird with my curent housekeeper options.

[kloczek]

Sure, but how about that fact that data is not deleting? Data is about 8 month old... its a little bit weird with my curent housekeeper options.

You are not forcing to use global history period -> you are using per items definition of history periods -> in some items definitions history period is so long that history data still cannot be deleted.

[w3orc]

You are not forcing to use global history period -> you are using per items definition of history periods -> in some items definitions history period is so long that history data still cannot be deleted.

Forcing.
However, there are still items withs 90 history days in db. dont know how it happens. Maybe this are template items,and they dont have history and can be kept with this values.

select itemid,history  from items where history > 7 ;
+--------+---------+
| itemid | history |
+--------+---------+
|  22444 |      90 |
|  22450 |      90 |
|  22700 |      90 |
|  22720 |      90 |
|  22735 |      90 |
|  22746 |      90 |
|  22760 |      90 |
|  22767 |      90 |
|  22779 |      90 |
|  22789 |      90 |
|  22796 |      90 |
|  22798 |      90 |
|  22867 |      90 |
|  22907 |      90 |
|  22944 |      90 |
|  22947 |      90 |
|  22984 |      90 |
|  22987 |      90 |
|  23024 |      90 |
|  23027 |      90 |
|  23067 |      90 |
|  23162 |      90 |
|  23163 |      90 |
|  23329 |      90 |
|  23540 |      90 |
|  23542 |      90 |
|  23554 |      90 |
|  23575 |      90 |
|  23576 |      90 |
|  23577 |      90 |
|  23578 |      90 |
|  23579 |      90 |
|  23595 |      90 |
|  23596 |      90 |
|  23599 |      90 |
|  23600 |      90 |
|  23601 |      90 |
|  23602 |      90 |
|  23603 |      90 |
|  23604 |      90 |
|  23605 |      90 |
|  23606 |      90 |
|  23607 |      90 |
|  23608 |      90 |
|  23631 |      90 |
|  23632 |      90 |
|  23633 |      90 |
|  23823 |      90 |
|  23824 |      90 |
|  23965 |      90 |
|  23966 |      90 |
|  24013 |      90 |
|  24014 |      90 |
|  24061 |      90 |
|  24062 |      90 |
|  24109 |      90 |
|  24110 |      90 |
|  24307 |      90 |
|  24308 |      90 |
|  24428 |      90 |
|  24429 |      90 |
|  24971 |      90 |
|  24972 |      90 |
|  25053 |      90 |
|  25054 |      90 |
|  25094 |      90 |
|  25095 |      90 |
|  25242 |      90 |
|  25243 |      90 |
|  25302 |      90 |
|  25303 |      90 |
|  25575 |      90 |
|  25576 |      90 |
|  25685 |      30 |
|  25686 |      30 |
|  25687 |      30 |
|  25688 |      30 |
|  25689 |      30 |
|  25690 |      30 |
|  25768 |      90 |
|  25769 |      90 |
|  25794 |      90 |
|  25795 |      90 |
|  25858 |      30 |
|  25859 |      30 |
|  25860 |      30 |
|  25861 |      30 |
|  25862 |      30 |
|  25863 |      30 |
|  25872 |      90 |
|  25873 |      90 |
|  25922 |      90 |
|  25923 |      90 |
|  25972 |      90 |
|  25973 |      90 |
|  26010 |      90 |
|  26011 |      90 |
|  26048 |      90 |
|  26409 |      90 |
|  26410 |      90 |
|  26525 |      90 |
|  26526 |      90 |
|  26586 |      90 |
|  26587 |      90 |
|  26648 |      90 |
|  26649 |      90 |
|  26710 |      90 |
|  26711 |      90 |
|  26858 |      90 |
|  26859 |      90 |
|  26916 |      30 |
|  26917 |      30 |
|  26918 |      30 |
|  26919 |      30 |
|  26920 |      30 |
|  26921 |      30 |
|  26933 |      90 |
|  26934 |      90 |
|  26974 |      30 |
|  26975 |      30 |
|  26976 |      30 |
|  26977 |      30 |
|  26978 |      30 |
|  26979 |      30 |
|  26989 |      90 |
|  26990 |      90 |
|  27110 |      90 |
|  27111 |      90 |
|  27174 |      90 |
|  27175 |      90 |
|  27244 |      90 |
|  27247 |      90 |
|  27248 |      90 |
|  27249 |      90 |
|  27250 |      90 |
|  27251 |      90 |
|  27252 |      90 |
|  27253 |      90 |
|  27254 |      90 |
|  27255 |      90 |
|  27256 |      90 |
|  27257 |      90 |
|  27258 |      90 |
|  27259 |      90 |
|  27260 |      90 |
|  27261 |      90 |
|  27262 |      90 |
|  27344 |      30 |
|  27345 |      30 |
|  27346 |      30 |
|  27347 |      30 |
|  27348 |      30 |
|  27349 |      30 |
|  27374 |      90 |
|  27375 |      90 |
|  27426 |      90 |
|  27427 |      90 |
|  27538 |      90 |
|  27539 |      90 |
|  27591 |      90 |
|  27592 |      90 |
|  27700 |      90 |
|  27701 |      90 |
|  27757 |      90 |
|  27758 |      90 |
|  27807 |      30 |
|  27808 |      30 |
|  27809 |      30 |
|  27810 |      30 |
|  27811 |      30 |
|  27812 |      30 |
|  27813 |      90 |
|  27814 |      90 |
|  27875 |      90 |
|  27876 |      90 |
|  27921 |      90 |
|  27922 |      90 |
|  27967 |      90 |
|  27968 |      90 |
|  28052 |      90 |
|  28053 |      90 |
|  28116 |      90 |
|  28117 |      90 |
|  28166 |      90 |
|  28167 |      90 |
|  28215 |      90 |
|  28216 |      90 |
|  28264 |      90 |
|  28265 |      90 |
|  28313 |      90 |
|  28314 |      90 |
|  28430 |      90 |
|  28431 |      90 |
|  28565 |      90 |
|  28566 |      90 |
|  28652 |      90 |
|  28653 |      90 |
|  28710 |      90 |
|  28711 |      90 |
|  28808 |      90 |
|  28809 |      90 |
|  28863 |      90 |
|  28864 |      90 |
+--------+---------+

And 90 stil < 8 month

fresh query

select *,from_unixtime(clock) from history_uint where from_unixtime(clock) < '2017-12-27 12:21:13' limit 10;
+--------+------------+-------+-----------+----------------------+
| itemid | clock      | value | ns        | from_unixtime(clock) |
+--------+------------+-------+-----------+----------------------+
|  27373 | 1511774473 |     1 | 268955582 | 2017-11-27 12:21:13  |
|  27373 | 1511774503 |     1 | 800288560 | 2017-11-27 12:21:43  |
|  27373 | 1511774533 |     1 | 505862683 | 2017-11-27 12:22:13  |
|  27373 | 1511774563 |     1 | 529794027 | 2017-11-27 12:22:43  |
|  27373 | 1511774593 |     1 | 314871869 | 2017-11-27 12:23:13  |
|  27373 | 1511774623 |     1 | 520640020 | 2017-11-27 12:23:43  |
|  27373 | 1511774653 |     1 | 733799533 | 2017-11-27 12:24:13  |
|  27373 | 1511774683 |     1 |  71274059 | 2017-11-27 12:24:43  |
|  27373 | 1511774713 |     1 | 966276693 | 2017-11-27 12:25:13  |
|  27373 | 1511774743 |     1 | 722119137 | 2017-11-27 12:25:43  |
+--------+------------+-------+-----------+----------------------+
10 rows in set (0.07 sec)

[kloczek]

select *,from_unixtime(clock) from history_uint where from_unixtime(clock) < '2017-12-27 12:21:13' limit 10;
+--------+------------+-------+-----------+----------------------+
| itemid | clock | value | ns | from_unixtime(clock) |
+--------+------------+-------+-----------+----------------------+
| 27373 | 1511774473 | 1 | 268955582 | 2017-11-27 12:21:13 |
| 27373 | 1511774503 | 1 | 800288560 | 2017-11-27 12:21:43 |
| 27373 | 1511774533 | 1 | 505862683 | 2017-11-27 12:22:13 |
| 27373 | 1511774563 | 1 | 529794027 | 2017-11-27 12:22:43 |
| 27373 | 1511774593 | 1 | 314871869 | 2017-11-27 12:23:13 |
| 27373 | 1511774623 | 1 | 520640020 | 2017-11-27 12:23:43 |
| 27373 | 1511774653 | 1 | 733799533 | 2017-11-27 12:24:13 |
| 27373 | 1511774683 | 1 | 71274059 | 2017-11-27 12:24:43 |
| 27373 | 1511774713 | 1 | 966276693 | 2017-11-27 12:25:13 |
| 27373 | 1511774743 | 1 | 722119137 | 2017-11-27 12:25:43 |
+--------+------------+-------+-----------+----------------------+
10 rows in set (0.07 sec)

Check do you still have those itemid items on some host or template. It may be series of data which are no longer assigned to any items metric.
Possible cause: you've deleted the item with itemid=27373. This is causing add to hosekeeper table record to delete all history rows with iemid=27373 on next HK cycle.
If you deleted accidentally housekeepr table content entirety or only this row such series of old data and now you have some dangling series of data which housekeeper will never be able to remove.
You can query items table to find all itemid which are still in use to find those itemids which no longer connected to any itemid items table content.

Seems like you are quite familiar with queering SQL DB content straight so I wold be not surprised if you would be fiddling with DB content time to time.
Is that possible that something like this happened in the past or someone deleted housekeeper table content in the past?
If I'm not wrong just minimise such interaction to absolute minimum ad tell you colleagues to not use any delete, update or insert type queries
Zabbix has enough reach frontend application functions to not use DB access straight.

Generally housekeeping oldest data not by delete oldest data using delete queries but by dropping oldest partition solves two issues:
- dropping such unconnected to any existing in zabbix cgf tables series of data
- reduces drastically IO overhead on delete oldest data.
I would recommend stop worry about some unconnected to some existing items series of data (if it is the case) and apply ASAP partitioning of history* tables. This will solve on one go this issue and many more issues which are usually making sluggish DB backend.

[w3orc]

Check do you still have those itemid items on some host or template. It may be series of data which are no longer assigned to any items metric.
Possible cause: you've deleted the item with itemid=27373. This is causing add to hosekeeper table record to delete all history rows with iemid=27373 on next HK cycle.
If you deleted accidentally housekeepr table content entirety or only this row such series of old data and now you have some dangling series of data which housekeeper will never be able to remove.
You can query items table to find all itemid which are still in use to find those itemids which no longer connected to any itemid items table content.

Thx for idea. I didnt thinked in this way. I will try later to check what items a still not deleted.
Seems i begin to understand, someone changed items type and they were not deleted. New data of itemid 27373 is in right table.

select *,from_unixtime(clock) from [B]history_text[/B] where itemid = 27373 limit 1;
+---------+--------+------------+-------+-----------+----------------------+
| id      | itemid | clock      | value | ns        | from_unixtime(clock) |
+---------+--------+------------+-------+-----------+----------------------+
| 2720758 |  27373 | 1529678023 | 1     | 175590875 | [B]2018-06-22 17:33:43 [/B] |
+---------+--------+------------+-------+-----------+----------------------+

i will try later to find out how much data is not deleted, seems its not so much and this was wrong way of thinking. I will try to think in way of your previous suggestion

Column with ns is not 0. It means that you are using zabbix trapper items -> sometimes using such items means that in such cases it is hard to predict exact number of monitoring data points -> daily growth of the DB size is unpredictable

it realy makes sense...

Seems like you are quite familiar with queering SQL DB content straight so I wold be not surprised if you would be fiddling with DB content time to time.
Is that possible that something like this happened in the past or someone deleted housekeeper table content in the past?
If I'm not wrong just minimise such interaction to absolute minimum ad tell you colleagues to not use any delete, update or insert type queries
Zabbix has enough reach frontend application functions to not use DB access straight.

lol. No, just selects for diferent reports for bosses

Generally housekeeping oldest data not by delete oldest data using delete queries but by dropping oldest partition solves two issues:
- dropping such unconnected to any existing in zabbix cgf tables series of data
- reduces drastically IO overhead on delete oldest data.
I would recommend stop worry about some unconnected to some existing items series of data (if it is the case) and apply ASAP partitioning of history* tables. This will solve on one go this issue and many more issues which are usually making sluggish DB backend.

it is a little server with 30 hosts, that why i was so wonder that db grow more then 40gb and still grows, but i will try if woudnt find another way. Thx!