ZABBIX BUGS AND ISSUES

No messages in the LEVEL_WARNING log about deleted values by housekeeper (table "housekeeper")

Details

  • Zabbix ID:
    Reviewed 2.0

Description

When zabbix_server works with the DebugLevel=3 it reports to the log this message:
"Deleted <NNN> records from history and trends"

But here are not included values deleted by housekeeper for the items already deleted from configuration (table "housekeeper").
1. This lack of information could confuse when troubleshooting of DB performance.
2. It's not consistent that the housekeeper is reporting count of the deleted *outdated values* but does not report count of values for items *already deleted from configuration*.

Try to imagine a situation when some user has performed "Unlink and clear" action with some big template linked to the several hosts and in the nearest hour he felt some problem with the DB performance and he thinks - what happened ?


Here is part of DebugLevel=4 (I added several EOL for better view):

 15500:20111031:150250.029 End of housekeeping_history_and_trends():0

 15500:20111031:150250.029 Deleted 0 records from history and trends

 15500:20111031:150250.029 In housekeeping_process_log()
 15500:20111031:150250.029 query [txnlev:0] [select housekeeperid,tablename,field,value from housekeeper order by table name]
 15500:20111031:150250.029 query without transaction detected

 15500:20111031:150250.029 query [txnlev:0] [delete from history where itemid=22578 limit 100]
 15500:20111031:150250.044 deleted 100 records from table 'history'

 15500:20111031:150250.044 query without transaction detected

 15500:20111031:150250.044 query [txnlev:0] [delete from history_uint where itemid=22577 limit 100]
 15500:20111031:150250.060 deleted 100 records from table 'history_uint'

 15500:20111031:150250.060 End of housekeeping_process_log():SUCCEED
 15500:20111031:150250.060 In housekeeping_events() now:1320062561
 15500:20111031:150250.060 query [txnlev:0] [select event_history from config]
 15500:20111031:150250.060 query [txnlev:0] [select eventid from events where clock<1288526561]
 15500:20111031:150250.060 End of housekeeping_events():SUCCEED

 15500:20111031:150250.060 In housekeeping_alerts() now:1320062561
 15500:20111031:150250.060 query [txnlev:0] [select alert_history from config]
 15500:20111031:150250.060 query without transaction detected
 15500:20111031:150250.060 query [txnlev:0] [delete from alerts where clock<1288526561]
 15500:20111031:150250.060 deleted 0 records from table 'alerts'
 15500:20111031:150250.060 End of housekeeping_alerts():SUCCEED

 15500:20111031:150250.060 In housekeeping_sessions() now:1320062561
 15500:20111031:150250.060 query without transaction detected
 15500:20111031:150250.060 query [txnlev:0] [delete from sessions where lastaccess<1288526561]
 15500:20111031:150250.061 deleted 0 records from table 'sessions'
 15500:20111031:150250.061 End of housekeeping_sessions():SUCCEED
 15500:20111031:150250.061 sleeping for 3600 seconds

(in this example "MaxHousekeeperDelete=100")

As you see in the function "housekeeping_process_log()", where the values are deleted from the tables history, history_uint (and not only), no messages are added for the LOG_LEVEL_WARNING.

I ask to add these messages to log. Maybe individually per each table, maybe summarize history+trends, I don't know how is better.

If any such values were not deleted then needn't to report any messages.

Activity

Hide
Oleksiy Zagorskyi added a comment - - edited

(1) By the way, the name of function "housekeeping_process_log()" seems is not optimal.

I suggest to change it to "housekeeping_process_deleted_items()" or similar.

<dimir> I chose housekeeping_cleanup(), RESOLVED in r23553

<zalex> Excellent ! CLOSED

Show
Oleksiy Zagorskyi added a comment - - edited (1) By the way, the name of function "housekeeping_process_log()" seems is not optimal. I suggest to change it to "housekeeping_process_deleted_items()" or similar. <dimir> I chose housekeeping_cleanup(), RESOLVED in r23553 <zalex> Excellent ! CLOSED
Hide
dimir added a comment -

Fixed in development branch svn://svn.zabbix.com/branches/dev/ZBX-4298

Show
dimir added a comment - Fixed in development branch svn://svn.zabbix.com/branches/dev/ZBX-4298
Hide
dimir added a comment -

I've chosen "housekeeping_cleanup()", if nobody minds. So the report will look like this:

11921:20111125:180134.824 housekeeper deleted 0 records from history and trends, 28561 records of deleted items, 0 events, 0 alerts and 0 sessions

This will be logged on every housekeeper step even if nothing was removed. Agreed with sasha that this way there will will be no questions whether it actually was or not an attempt to delete the data.

Show
dimir added a comment - I've chosen "housekeeping_cleanup()", if nobody minds. So the report will look like this: 11921:20111125:180134.824 housekeeper deleted 0 records from history and trends, 28561 records of deleted items, 0 events, 0 alerts and 0 sessions This will be logged on every housekeeper step even if nothing was removed. Agreed with sasha that this way there will will be no questions whether it actually was or not an attempt to delete the data.
Hide
Oleksiy Zagorskyi added a comment - - edited

Dev branch tested. Works as expected. Single line for report is very-very good.

(2) I would suggest to write that line as:
housekeeper deleted: 0 records from history and trends, 28561 records of deleted items, 0 events, 0 alerts, 0 sessions
It seems for me it will be in more readable form.

<dimir> RESOLVED in r23560

<zalex> Many thanks. CLOSED.

Show
Oleksiy Zagorskyi added a comment - - edited Dev branch tested. Works as expected. Single line for report is very-very good. (2) I would suggest to write that line as: housekeeper deleted: 0 records from history and trends, 28561 records of deleted items, 0 events, 0 alerts, 0 sessions It seems for me it will be in more readable form. <dimir> RESOLVED in r23560 <zalex> Many thanks. CLOSED.
Hide
dimir added a comment -

Fixed in pre-1.8.10 r23632, pre-1.9.9 r23633.

Show
dimir added a comment - Fixed in pre-1.8.10 r23632, pre-1.9.9 r23633.
Hide
Alexander Vladishev added a comment - - edited

(1) Broken compilation of the latest trunk.

housekeeper.c: In function ‘housekeeping_cleanup’:
housekeeper.c:135: error: ‘ids_alloc’ undeclared (first use in this function)
housekeeper.c:135: error: (Each undeclared identifier is reported only once
housekeeper.c:135: error: for each function it appears in.)
housekeeper.c:135: error: ‘ids_num’ undeclared (first use in this function)
housekeeper.c: In function ‘housekeeping_alerts’:
housekeeper.c:186: warning: ‘return’ with a value, in function returning void
housekeeper.c: In function ‘housekeeping_events’:
housekeeper.c:213: warning: ‘return’ with a value, in function returning void
housekeeper.c: In function ‘main_housekeeper_loop’:
housekeeper.c:328: error: void value not ignored as it ought to be
housekeeper.c:331: error: void value not ignored as it ought to be

<dimir> sorry for the broken trunk, RESOLVED in r23663 directly in trunk

<zalex> tested. trunk r23663 compiled ok and it works.

<sasha> CLOSED with small change in r23688.

Show
Alexander Vladishev added a comment - - edited (1) Broken compilation of the latest trunk. housekeeper.c: In function ‘housekeeping_cleanup’: housekeeper.c:135: error: ‘ids_alloc’ undeclared (first use in this function) housekeeper.c:135: error: (Each undeclared identifier is reported only once housekeeper.c:135: error: for each function it appears in.) housekeeper.c:135: error: ‘ids_num’ undeclared (first use in this function) housekeeper.c: In function ‘housekeeping_alerts’: housekeeper.c:186: warning: ‘return’ with a value, in function returning void housekeeper.c: In function ‘housekeeping_events’: housekeeper.c:213: warning: ‘return’ with a value, in function returning void housekeeper.c: In function ‘main_housekeeper_loop’: housekeeper.c:328: error: void value not ignored as it ought to be housekeeper.c:331: error: void value not ignored as it ought to be <dimir> sorry for the broken trunk, RESOLVED in r23663 directly in trunk <zalex> tested. trunk r23663 compiled ok and it works. <sasha> CLOSED with small change in r23688.
Hide
richlv added a comment - - edited

(2) also :
what's the difference between "history and trends" and "records of deleted items" ? i assume the latter is not the amount of items, but the amount of history and trends values for those items ?

<dimir> "Old history and trends" is the outdated information (as configured in the item keep this and that), "records of deleted items" is all the data (basically what's in "housekeeper" table) related to removed item.

<zalex> maybe would be better to replace all words "records" to the "values"? It will be more clear.

<dimir> For me "deleted 2 values from history and trends" is not more clear than "deleted 2 records from hostory and trends". What I'd add is singular value support.

<dimir> if there are no objections, RESOLVED in r23681

<zalex> dev branch r23681 tested. it works (see 1 event):
"housekeeper deleted: 7056 records from history and trends, 0 records of deleted items, 1 event, 0 alerts, 0 sessions"
he-he, it's some "alternative" to gettext

<dimir> We decided to discard these changes as we don't have anything like it anywhere. CLOSED

Show
richlv added a comment - - edited (2) also : what's the difference between "history and trends" and "records of deleted items" ? i assume the latter is not the amount of items, but the amount of history and trends values for those items ? <dimir> "Old history and trends" is the outdated information (as configured in the item keep this and that), "records of deleted items" is all the data (basically what's in "housekeeper" table) related to removed item. <zalex> maybe would be better to replace all words "records" to the "values"? It will be more clear. <dimir> For me "deleted 2 values from history and trends" is not more clear than "deleted 2 records from hostory and trends". What I'd add is singular value support. <dimir> if there are no objections, RESOLVED in r23681 <zalex> dev branch r23681 tested. it works (see 1 event): "housekeeper deleted: 7056 records from history and trends, 0 records of deleted items, 1 event, 0 alerts, 0 sessions" he-he, it's some "alternative" to gettext <dimir> We decided to discard these changes as we don't have anything like it anywhere. CLOSED
Hide
dimir added a comment -

Oleksiy, thank you for testing!

Show
dimir added a comment - Oleksiy, thank you for testing!
Hide
dimir added a comment -

Fixed in trunk r23663.

Show
dimir added a comment - Fixed in trunk r23663.
Hide
richlv added a comment - - edited

(3) i suspect "d_clenup" is a typo

<dimir> Right, RESOLVED in pre-1.8.10 r23732, pre-1.9.9 r23733.
<sasha> CLOSED

Show
richlv added a comment - - edited (3) i suspect "d_clenup" is a typo <dimir> Right, RESOLVED in pre-1.8.10 r23732, pre-1.9.9 r23733. <sasha> CLOSED
Hide
Alexander Vladishev added a comment -

Closing resolved issue

Show
Alexander Vladishev added a comment - Closing resolved issue
Hide
dimir added a comment -

Reopening to assign to myself.

Show
dimir added a comment - Reopening to assign to myself.
Hide
dimir added a comment -

Closed.

Show
dimir added a comment - Closed.
Hide
richlv added a comment -

48 deleted events reported as 1 in 1.8.10rc1

strace output :

event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=11", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=18", 40) = 40
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=5", 39) = 39
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=9", 39) = 39
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=1", 39) = 39
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=47", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=38", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=44", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=43", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=36", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=42", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=34", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=35", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=31", 40) = 40
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=8", 39) = 39
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=30", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=40", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=37", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=13", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=39", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=33", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=46", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=29", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=48", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=41", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=14", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=32", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=10", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=27", 40) = 40
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=6", 39) = 39
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=7", 39) = 39
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=12", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=26", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=45", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=24", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=25", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=17", 40) = 40
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=2", 39) = 39
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=3", 39) = 39
event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=4", 39) = 39
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=15", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=16", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=20", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=21", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=22", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=23", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=19", 40) = 40
event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=28", 40) = 40
event_strace.13938:write(7, " 13938:20111217:175347.261 housekeeper deleted: 0 records from history and trends, 0 records of deleted items, 1 events, 0 alerts, 0 sessions\n", 142) = 142

Show
richlv added a comment - 48 deleted events reported as 1 in 1.8.10rc1 strace output : event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=11", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=18", 40) = 40 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=5", 39) = 39 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=9", 39) = 39 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=1", 39) = 39 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=47", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=38", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=44", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=43", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=36", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=42", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=34", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=35", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=31", 40) = 40 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=8", 39) = 39 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=30", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=40", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=37", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=13", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=39", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=33", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=46", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=29", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=48", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=41", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=14", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=32", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=10", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=27", 40) = 40 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=6", 39) = 39 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=7", 39) = 39 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=12", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=26", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=45", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=24", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=25", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=17", 40) = 40 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=2", 39) = 39 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=3", 39) = 39 event_strace.13938:write(6, "#\0\0\0\3delete from events where eventid=4", 39) = 39 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=15", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=16", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=20", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=21", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=22", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=23", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=19", 40) = 40 event_strace.13938:write(6, "$\0\0\0\3delete from events where eventid=28", 40) = 40 event_strace.13938:write(7, " 13938:20111217:175347.261 housekeeper deleted: 0 records from history and trends, 0 records of deleted items, 1 events, 0 alerts, 0 sessions\n", 142) = 142
Hide
Alexander Vladishev added a comment -

Fixed in the development branch svn://svn.zabbix.com/branches/dev/ZBX-4298

Show
Alexander Vladishev added a comment - Fixed in the development branch svn://svn.zabbix.com/branches/dev/ZBX-4298
Hide
dimir added a comment -

Tested successfully.

Show
dimir added a comment - Tested successfully.
Hide
Alexander Vladishev added a comment -

Available in version pre-1.8.11, r24309.

Show
Alexander Vladishev added a comment - Available in version pre-1.8.11, r24309.

People

Vote (0)
Watch (1)

Dates

  • Created:
    Updated:
    Resolved: