Chris_Phillips
Jan 13, 2012Nimbostratus
periodic summary logging with table and after?
Howdy folks,
I'm trying to basically update the per URI limiting rule given by Hoolio here http://devcentral.f5.com/Community/...fault.aspx to the modern age with tables and the after command.
I've got the actual limiting side fo things working OK, but I'm stuck trying to sort out some summary logging.
I am able to track the number of rejects per irule version and per uri and it seems ideal to be to want to log the number of rejections in a given period after there has been a rejection, and not to log anything if there have been no rejections. Rejections shuold naturally be very rare, so I don't want to be churning through irrelevant code 99.999% of the time.
So, surely we can say when we reject something, we then see if we have an "after" timer to log the total number of rejections shortly. if there is no timer, then we want to create a timer. if there is a timer, then just increment the count of rejections and move on knowing that it will be taken care of soon.
But I can't make this work. I seem to be unable to effectively track the after ID's. If I track the specific ID in a table then I can't just rely on that table entry existing or not, as the table timeouts aren't related to the after timeouts. The most watertight logic I've come up with so far looks vaguely like this... (code excerpt only run when we are rejecting connections)
set rejects [table incr "rejected_count_$tbl"]
table delete rej_log_monitor
log local0. "after info = [after info]"
log local0. "after info lookup = [after info [table lookup rej_log_monitor]]"
if {[after info] ne ""} {
set monitor_id [after info [table lookup rej_log_monitor]]
}
if {[info exists monitor_id]} {
do nothing, don't log right now
log local0. "have rej_log_monitor = [table lookup rej_log_monitor], not logging reject"
log local0. [after info]
} else {
log local0. "no rej_log_monitor: setting to log reject"
table set rej_log_monitor [after 5000 {
log local0. "TEST!"
}] 10000
log local0. "have rej_log_monitor = [table lookup rej_log_monitor], ready to log soon"
log local0. [after info [table lookup rej_log_monitor]]
}
But this is still providing nothing useful. This just ends up hanging on responding to my curl command, and comes out with varying after ID's suggesting multiple jobs somehow get created:
Jan 13 10:13:50 local/tmm info tmm[29590]: Rule _cp_t1_soap_request_limit_irule : after info =
Jan 13 10:13:50 local/tmm info tmm[29590]: Rule _cp_t1_soap_request_limit_irule : no rej_log_monitor setting to log reject
Jan 13 10:14:07 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : after info =
Jan 13 10:14:07 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : no rej_log_monitor setting to log reject
Jan 13 10:14:07 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : have rej_log_monitor = after7e9b79c, ready to log soon
Jan 13 10:14:07 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : _cp_t1_soap_request_limit_irule HTTP_REQUEST { log local0. "TEST!" }
Jan 13 10:14:08 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : after info =
Jan 13 10:14:08 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : no rej_log_monitor setting to log reject
Jan 13 10:14:08 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : have rej_log_monitor = after7e9b2cc, ready to log soon
Jan 13 10:14:08 local/tmm1 info tmm1[29591]: Rule _cp_t1_soap_request_limit_irule : _cp_t1_soap_request_limit_irule HTTP_REQUEST { log local0. "TEST!" }
the after job should surely exist in the schedule for 5 seconds, yet multiple requests one second apart provide different ID's... This isn't just a single timer boundary, happens many times in a row well within the after timer limit.
Any pointers appreciated.