Forum Discussion
table command causing abort of rule event HTTP_REQUEST
Hello everyone,
This is my first dig into iRules, and I'm hitting an issue with the table command that is aborting my rule. I'm essentially trying to rate limit requests per URI per ASPNET Session ID. I've been working with the iRule for a couple days, so I know it's not at its best and has excessive logging (for the purposes of figuring this out). I'm testing with a backend server that doesn't use ASP, so I'm setting it statically in the iRule as a failsafe for now. I'm building that up now for testing.. but hit some snags.
The main issue is the table command aborting the rule execution. I was originally putting many of the table lookups directly into the if statements, but I was able to resolve an abort earlier in the rule by setting to a variable first.
Here are the logs:
[admin@LTM1:ModuleNotLicensed:Active:Standalone] ~ tail /var/log/ltm
Jun 6 11:07:23 LTM1 info tmm1[8579]: 01220009:6: Pending rule event HTTP_REQUEST aborted for 192.168.21.102:58079->10.202.20.170:80 (listener: /Common/Drupal_HTTP)
Jun 6 11:07:23 LTM1 info tmm[8579]: Rule /Common/JSESSIONRateLimit : iRule_Rate-Limiter: HTTP_REQUEST Matched
Jun 6 11:07:23 LTM1 info tmm[8579]: Rule /Common/JSESSIONRateLimit : iRule_Rate-Limiter: No session cookie found. Quitting..
Jun 6 11:07:23 LTM1 info tmm[8579]: Rule /Common/JSESSIONRateLimit : iRule_Rate-Limiter: Got URI, /drupal/themes/garland/images/bg-content-right.png, making key: session1_/drupal/themes/garland/images/bg-content-right.png
Jun 6 11:07:23 LTM1 info tmm[8579]: 01220009:6: Pending rule event HTTP_REQUEST aborted for 192.168.21.102:58080->10.202.20.170:80 (listener: /Common/Drupal_HTTP)
Jun 6 11:07:23 LTM1 info tmm1[8579]: Rule /Common/JSESSIONRateLimit : iRule_Rate-Limiter: HTTP_REQUEST Matched
Jun 6 11:07:23 LTM1 info tmm1[8579]: Rule /Common/JSESSIONRateLimit : iRule_Rate-Limiter: No session cookie found. Quitting..
Jun 6 11:07:23 LTM1 info tmm1[8579]: Rule /Common/JSESSIONRateLimit : iRule_Rate-Limiter: Got URI, /drupal/themes/garland/images/bg-content-right.png, making key: session1_/drupal/themes/garland/images/bg-content-right.png
Jun 6 11:07:23 LTM1 info tmm1[8579]: Rule /Common/JSESSIONRateLimit : iRule_Rate-Limiter: Matched second else.. not following conditionals.
Jun 6 11:07:23 LTM1 info tmm1[8579]: 01220009:6: Pending rule event HTTP_REQUEST aborted for 192.168.21.102:58081->10.202.20.170:80 (listener: /Common/Drupal_HTTP)
`
Here is the rule:
`when HTTP_REQUEST {
log local0. "iRule_Rate-Limiter: HTTP_REQUEST Matched"
set maxReqs 5
set cooldownTimer 30
set sampleTimer 30
set timeout 30
if { [HTTP::cookie exists "ASP.NET_SessionId"] } {
set aspid [HTTP::cookie ASP.NET_SessionId]
log local0. "iRule_Rate-Limiter: SESSION Cookie present: $aspid"
} else {
log local0. "iRule_Rate-Limiter: No session cookie found. Quitting.."
pool Drupal_Pool
event HTTP_REQUEST disable
set aspid "session1"
}
set reqURI [string tolower [HTTP::uri]]
set key "$aspid"
append key "_$reqURI"
log local0. "iRule_Rate-Limiter: Got URI, $reqURI, making key: $key"
set onCooldown [table lookup -subtable "Cooldowns" $key]
if { $onCooldown != "" } {
log local0. "iRule_Rate-Limiter: Key: $key is already on cooldown, sending HTTP:429 status code."
HTTP::respond 429
} else {
log local0. "iRule_Rate-Limiter: Matched second else.. not following conditionals."
set currCount [table add $key 1]
if { $currCount == "" } {
table set $key 1 $timeout $sampleTimer
log local0. "iRule_Rate-Limiter: First attempt for $key, adding to table for tracking."
} else {
if { ($currCount <= $maxReqs) } {
table incr $key 1
incr currCount
log local0. "iRule_Rate-Limiter: $key not on timeout, but not first request. Incrementing count to $currCount in session table."
} else {
HTTP::respond 429
table set -subtable "Cooldowns" $key "yes" $timeout $cooldownTimer
log local0. "iRule_Rate-Limiter: $key triggered cooldown with $currCount attempts. Adding to cooldown table."
}
}
}
}
Note that the rule is aborting at this line of code (line 31):
set currCount [table add $key 1]
Any help here is greatly appreciated, as I can't find anything outlining why this occurs. It's a small rule, and a simple lookup so I don't see why it would cause the rule to suspend indefinitely.
Thanks! Ryan
- nitassEmployee
Pending rule event HTTP_REQUEST aborted for ... (listener: /Common/Drupal_HTTP)
i may be wrong but i think it means connection is terminated (for whatever reason) before irule is complete.
by the way, these are my comments.
1) for static variable (e.g. maxReqs, cooldownTimer, sampleTimer, timeout),
static
https://clouddocs.f5.com/api/irules/static.html
2) in No session cookie found. Quitting section, you may use "return" to exit the current event. event disable does not exit from the event.
event
https://clouddocs.f5.com/api/irules/event.html
irule [root@ve11a:Active:In Sync] config tmsh list ltm rule qux ltm rule qux { when HTTP_REQUEST { log local0. "priority 500: before" event HTTP_REQUEST disable log local0. "priority 500: after" } when HTTP_REQUEST priority 600 { log local0. "priority 600" } when HTTP_RESPONSE { log local0. "priority 500" } } /var/log/ltm [root@ve11a:Active:In Sync] config tail -f /var/log/ltm Jun 8 11:45:34 ve11a info tmm[9801]: Rule /Common/qux HTTP_REQUEST: priority 500: before Jun 8 11:45:34 ve11a info tmm[9801]: Rule /Common/qux HTTP_REQUEST: priority 500: after Jun 8 11:45:35 ve11a info tmm[9801]: Rule /Common/qux HTTP_RESPONSE: priority 500
3) in set currCount [table add $key 1] section, when will table add return null?
table
- Ryan_126004NimbostratusThanks for the feedback on static variables and return versus event commands. I'll adjust my rule. If the rule is being aborted because the connection is terminated before it completes execution, then.. I'm a bit confused. Without the iRule, the web page loads just fine. Would this also be if the HTTP request completes before the rule is completely executed? When I access the server with the iRule in place, I get no response at all. Is there maybe a better event to trigger this on that would prevent these issues? I'm essentially trying to stop the connection to the backend server and return HTTP 429 is it hits too many requests per URI over 30 seconds. The currCount would return 0 if it's the first attempt at that URI for the current ASPNET Session ID in the last 30 seconds.
- nitassEmployee
The currCount would return 0 if it's the first attempt at that URI for the current ASPNET Session ID in the last 30 seconds.
isn't it one? anyway, it is not going to be null, is it?
Returns the entry's value after the set operation is complete.
Would this also be if the HTTP request completes before the rule is completely executed?
i do not think http request is complete because if it is, irule should be complete too, shouldn't it?
have you tried tcpdump? tcpdump may show what happens on the connection.
- Ryan_126004NimbostratusGood point.. it would always return 1. I originally was using just table set, but changed it to see if the abort would stop occurring. My understanding was that it wouldn't complete without the iRule, either, but wanted to ask just to be sure. I have done a tcpdump, and the connection looks completely normal. No early terminations, fins, rst, etc.. Again, everything is fine without the iRule.. could something in the iRule be causing this? It doesn't seem like the rule is hitting any piece where it actually interferes with the connection before it is aborting.
- nitassEmployee
I have done a tcpdump, and the connection looks completely normal. No early terminations, fins, rst, etc..
you checked connection matching the log, didn't you? for example, in the following log, you saw response to client 192.168.21.102 port 58079, didn't you?
Jun 6 11:07:23 LTM1 info tmm1[8579]: 01220009:6: Pending rule event HTTP_REQUEST aborted for 192.168.21.102:58079->10.202.20.170:80 (listener: /Common/Drupal_HTTP)
- Ryan_126004NimbostratusYes, this is also a lab LTM, so it was the only connection to the box other than my SSH session.
- nitassEmployeein that case, i think it may be good to open a support case.
- Ryan_126004NimbostratusI contacted support. It turns out the event disable was causing this problem even though that conditional wasn't matching and the rule wasn't being aborted until after that line in the rule. I removed it and it works fine.
Recent Discussions
Related Content
* Getting Started on DevCentral
* Community Guidelines
* Community Terms of Use / EULA
* Community Ranking Explained
* Community Resources
* Contact the DevCentral Team
* Update MFA on account.f5.com