[ZBX-4298] No messages in the LEVEL_WARNING log about deleted values by housekeeper (table "housekeeper") Created: 2011 Oct 31  Updated: 2017 May 30  Resolved: 2011 Dec 19

Status: Closed
Project: ZABBIX BUGS AND ISSUES
Component/s: Server (S)
Affects Version/s: 1.8.8
Fix Version/s: 1.8.10, 1.8.11, 1.9.9 (beta)

Type: Incident report Priority: Minor
Reporter: Oleksii Zagorskyi Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: housekeeper
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

DebugLevel=3



 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.



 Comments   
Comment by Oleksii Zagorskyi [ 2011 Oct 31 ]

(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

Comment by dimir [ 2011 Nov 25 ]

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

Comment by dimir [ 2011 Nov 25 ]

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.

Comment by Oleksii Zagorskyi [ 2011 Nov 27 ]

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.

Comment by dimir [ 2011 Nov 30 ]

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

Comment by Alexander Vladishev [ 2011 Nov 30 ]

(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.

Comment by richlv [ 2011 Nov 30 ]

(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

Comment by dimir [ 2011 Dec 01 ]

Oleksiy, thank you for testing!

Comment by dimir [ 2011 Dec 01 ]

Fixed in trunk r23663.

Comment by richlv [ 2011 Dec 01 ]

(3) i suspect "d_clenup" is a typo

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

Comment by Alexander Vladishev [ 2011 Dec 02 ]

Closing resolved issue

Comment by dimir [ 2011 Dec 02 ]

Reopening to assign to myself.

Comment by dimir [ 2011 Dec 02 ]

Closed.

Comment by richlv [ 2011 Dec 19 ]

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

Comment by Alexander Vladishev [ 2011 Dec 19 ]

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

Comment by dimir [ 2011 Dec 19 ]

Tested successfully.

Comment by Alexander Vladishev [ 2011 Dec 28 ]

Available in version pre-1.8.11, r24309.

Generated at Thu Apr 18 21:04:30 EEST 2024 using Jira 9.12.4#9120004-sha1:625303b708afdb767e17cb2838290c41888e9ff0.