Forum Discussion
HTTP Payload logging breaks HTTP Keep-Alive
Afternoon all,
I've written an iRule to record the request/response payload on a REST HTTP API.
The rule looks like: when CLIENT_ACCEPTED {
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "Processing CLIENT_ACCEPTED." }
Set the payload logging flag
set log_payload 1
}
when HTTP_REQUEST priority 800 {
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Processing HTTP_REQUEST at priority 800..." }
Skip logging if no members available
if {$splunk_bypass}{
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Splunk HSL pool is down. Bypassing logging..." }
return
}
Don't allow data to be chunked
if { [HTTP::version] eq "1.1" } {
if { [HTTP::header is_keepalive] } {
HTTP::header replace "Connection" "Keep-Alive"
}
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Switching to HTTP Version 1.0." }
HTTP::version "1.0"
}
Split out request headers and munge into string
set headers [HTTP::header names]
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Request HTTP Headers = $headers" }
set request_headers "'"
foreach header $headers {
set value [HTTP::header value $header]
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Request HTTP Header $header value = $value" }
append request_headers "$header=$value "
}
set request_headers [string trimright $request_headers " "]
append request_headers "'"
}
when HTTP_REQUEST_DATA {
if { $static::PayloadLoggerDebug or $f5_connection_debug }{ log local0.debug "$log_prefix: Collected [HTTP::payload length] bytes."}
set request_payload [HTTP::payload]
}
when HTTP_RESPONSE priority 50 {
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Processing HTTP_RESPONSE at priority 50..." }
Skip logging if no members available
if {$splunk_bypass}{
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Splunk HSL pool is down. Bypassing logging..." }
return
}
Split out the response headers and munge into string
set headers [HTTP::header names]
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Response HTTP Headers = $headers" }
set response_headers "'"
foreach header $headers {
set value [HTTP::header value $header]
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Response HTTP Header $header value = $value" }
append response_headers "$header=$value "
}
set response_headers [string trimright $response_headers " "]
append response_headers "'"
Collect the response
if { $response_length > 0 } {
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Collecting $response_length bytes from response." }
HTTP::collect $response_length
}
Calculate actual content-length
set response_length_real [HTTP::payload length]
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Real response content-length = $response_length_real." }
Correct the response_length to correct value if required.
if { $response_length != $response_length_real } {
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Updated \$response_length value." }
set response_length $response_length_real
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: New \$response_length value is $response_length." }
}
}
when HTTP_RESPONSE_DATA {
if { $static::PayloadLoggerDebug or $f5_connection_debug } { log local0.debug "$log_prefix: Processing HTTP_RESPONSE_DATA." }
Gather response data
set response_payload "[HTTP::payload]"
}
A lot of the above feeds into a larger iRule framework. E.g. we use a SplunkHTTPS iRule to actually do the HSL logging out to a syslog server. The 'HTTP::collect' is also called from that iRule aswell.
However when testing this iRule, I've identified an issue whereby it appears to be breaking HTTP Keep-alive connections to some of our GF3 application servers.
Removing this rule restores the keep-alive functionality.
Any pointers on how I can maintain the keep-alive functionality and also be able to log the request/response data?
Cheers Gavin
- nitassEmployee
if { [HTTP::header is_keepalive] } { HTTP::header replace "Connection" "Keep-Alive" }
have you tried tcpdump? was connection keep-alive presented in all requests on serverside (between bigip and server)?
- GavinW_29074Nimbostratus
I was just trying that currently...
It looks like the 'Connection: Keep-Alive' value is correctly passed, along with setting the HTTP proto to 1.0.
However the response comes back with a 'Connection: close'.GET /cloudpost-web/rest/remote/3.0 HTTP/1.0 Host: client.dev.post.card.co.uk Accept: */* Connection: Keep-Alive X-Forwarded-For: x.x.x.x HTTP/1.1 200 OK X-Powered-By: Servlet/3.0 JSP/2.2 (GlassFish Server Open Source Edition 3.1.2.2 Java/Oracle Corporation/1.7) Server: GlassFish Server Open Source Edition 3.1.2.2 Content-Type: text/plain Date: Tue, 23 Dec 2014 15:31:21 GMT Connection: close POST Remote Resource 3.0
However running direct to the application server with HTTP/1.1 works correctly and the connection is kept alive...
Cheers
Gav - nitassEmployee
It looks like the 'Connection: Keep-Alive' value is correctly passed, along with setting the HTTP proto to 1.0.
could it be server configuration?
- GavinW_29074Nimbostratus
Yeh, my money is on it being an application server issue... But testing directly with a HTTP/1.1 connection results in the correct keep-alive behaviour :(
Will see if I can simulate the HTTP proto down-grade outside of the F5, and see how the app server behaves...
Cheers
- GavinW_29074Nimbostratus
OK, running a HTTP/1.0 direct against the Glassfish 3 application server yields the same came connection close behaviour...
So it indeed looks to be an issue with the application server...
Now to try and work out how to fix that... :(
Cheers
- nitassEmployeedo you really need to collect response payload? i think i do not see any action on the response payload.
- GavinW_29074NimbostratusThe response payload gets recorded in this iRule, then logged out to a syslog server in another iRule... It'd be nice to be able to log the payloads along with the access logs, but am discussing it's importance with the dev teams currently... It's a shame we can't capture the payload against a HTTP/1.1 connection... Cheers Gav
- nitassEmployee
Joanna has written request unchunker irule. it may be useful.
HTTP Request Unchunker by Joanna Knox
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