Learn F5 Technologies, Get Answers & Share Community Solutions Join DevCentral

Filter by:
  • Solution
  • Technology
Answers

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

0
Rate this Question

Answers to this Question

placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER
  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)?

0
placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

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

0
placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

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

could it be server configuration?

0
placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

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
Gav

0
placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

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
Gav

0
Comments on this Answer
Comment made 24-Dec-2014 by nitass 13357
do you really need to collect response payload? i think i do not see any action on the response payload.
0
Comment made 24-Dec-2014 by GavinW 156
The 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
0
placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

Joanna has written request unchunker irule. it may be useful.

HTTP Request Unchunker by Joanna Knox
https://devcentral.f5.com/wiki/iRules.HTTP%20Request%20Unchunker.ashx

0