Tracking requests and responses

use HTTP::request_num:

 

 

when HTTP_REQUEST {

 

log "Request [HTTP::request_num]"

 

}

 

when HTTP_RESPONSE {

 

log "Response [HTTP::request_num]"

 

}

Thank you for the tip - but unfortunately these are not unique numbers. I tailed the output after updating the iRule and found that the http::request_num was showing many duplicates for different unique requests.

 

 

I then looked up the HTTP::request_num and found it "returns the number of HTTP requests that a client made on the connection" so these numbers will never be unique. We avg 500,000 hits per day and pull a lot of stats from our existing apache logs. So need a solution that ties request and response metrics uniquely.

 

 

With our apache custom log a unique identifier isn't as important because both the request and response are on the same log line (apache doesn't even log until it gets the response or times out).

 

 

Since in this case each request/response pairing is logged separately it is an issue (the same is true of sendmail logs, there is a unique identifier which allows you to correlate the message as it transverses the mail subsystems).

 

 

Any other ideas?

 

 

Thanks again.

Why not just set the variables in the request and print everything in the response?

when HTTP_REQUEST {
  set http_request_time [clock clicks -milliseconds]
  set client_ip [IP::remote_addr]
  set client_request "[HTTP::method]/[HTTP::host][HTTP::uri]"
  set client_browser [HTTP::header User-Agent]
  set client_referer [HTTP::header exists Referer]
  set http_version [HTTP::version]
  set jsess_cookie [HTTP::cookie exists JSESSIONID]
}
when HTTP_RESPONSE {
  set http_response_time [ clock clicks -milliseconds ]
  log local0. "
Client IP: $client_ip, \
Requesting: $client_request, \
        Browser: $client_browser, \
        Referer: $client_referer, \
        HTTP version $http_version, \
        JSESSION Cookie: $jsess_cookie, \
HTTP status: [HTTP::status], \
Response Size: [HTTP::payload length], \
Duration: [expr $http_response_time - $http_request_time]"
}

Here's a sample of the output

Apr 20 11:39:18 tmm tmm[27297]: Rule apache_like_log : Client IP: 10.1.1., Requesting: GET/10.1.1.2/cacti/graph_image.php?local_graph_id=954&rra_id=0&view_type=tree&graph_start=1177000723&graph_end=1177087123, Browser: Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; Q312461; .NET CLR 1.0.3705; .NET CLR 1.1.4322; .NET CLR 2.0.50727; InfoPath.1), Referer: 1, HTTP version 1.1, JSESSION Cookie: 0, HTTP status: 200, Response Size: 989, Duration: 878

That's the suggestion I would have given, but with one modification. I'd suggest using a single string instead of multiple ones. Less overhead is always better...

when HTTP_REQUEST {
  set http_request_time [clock clicks -milliseconds]
  set request_log_line "Client IP: [IP::remote_addr], requesting: [HTTP::method]/[HTTP::host][HTTP::uri], browser: [HTTP::header User-Agent], Referer: [HTTP::header exists Referer], HTTP version [HTTP::version], JSESSION Cookie: [HTTP::cookie exists JSESSIONID], SSL: [SSL::cipher name]/[SSL::cipher version]/[SSL::cipher bits]"
}
when HTTP_RESPONSE {
  set http_response_time [ clock clicks -milliseconds ]
  log local0. "$request_log_line, HTTP status: [HTTP::status], Response Size: [HTTP::payload length], Duration: [expr $http_response_time - $http_request_time] "
}

-Joe

what's efficiency, anyway... :-)

 

 

Good call, Joe!

Thank you both!

 

 

I think this is the solution I am looking for. I really appreciate both of your efforts!

 

 

Cheers

Hello,

 

 

Thank you again for the responses to my initial inquiry. I have a follow up question in regards to the following two items:

 

 

HTTP::header exists Referer

 

HTTP::cookie exists JSESSIONID

 

 

These return integer values - I need to get the URL returned for the referer and the actual session ID for the JSESSIONID (eg. AB139DD9528EFA30971A6144EA0C1D55.clusterinstance).

 

 

I also tried to reformat the output of the log file so I could parse it easily. I tried the following modification:

 

 

when HTTP_REQUEST {

 

set http_request_time [clock clicks -milliseconds]

 

set request_log_line "\

 

[HTTP::request_num],\

 

[IP::remote_addr],\

 

[HTTP::method],\

 

[HTTP::version],\

 

[HTTP::host],\

 

\"[HTTP::uri]\",\

 

\"[HTTP::header Referer]\",

 

\"[HTTP::header User-Agent]\",\

 

\"[HTTP::cookie JSESSIONID]",\

 

[SSL::cipher name],\

 

[SSL::cipher version],\

 

[SSL::cipher bits]"

 

}

 

 

when HTTP_RESPONSE {

 

set http_response_time [ clock clicks -milliseconds ]

 

log local0. "$request_log_line, \

 

HTTP status: [HTTP::status], \

 

Response Size: [HTTP::payload length], \

 

Duration: [expr $http_response_time - $http_request_time]"

 

}

 

 

The error I received was:

 

 

01070151:3: Rule [Halogen_Logging] error: line 12: [parse error: extra characters after close-quote] [SSL::cipher name [SSL::cipher version [SSL::cipher bits]] line 23: [use curly braces to avoid double substitution] [$http_response_time]"

 

 

I was trying to ensure that all well controlled fields were separated by commas and fields that could contain a comma were enclosed in quotes.

 

 

Thanks again for any assistance.

Looks like you didn't escape the terminating quote on the "HTTP::cookie JSESSIONID" line...

when HTTP_REQUEST {
set http_request_time [clock clicks -milliseconds]
set request_log_line "\
[HTTP::request_num],\
[IP::remote_addr],\
[HTTP::method],\
[HTTP::version],\
[HTTP::host],\
\"[HTTP::uri]\",\
\"[HTTP::header Referer]\",
\"[HTTP::header User-Agent]\",\
\"[HTTP::cookie JSESSIONID]\",\
[SSL::cipher name],\
[SSL::cipher version],\
[SSL::cipher bits]"
}

Give that a shot...

-Joe

[HTTP::header exists HEADER_NAME] will return 1 if the header HEADER_NAME has a value set and 0 if the header doesn't have a value. To get the actual value, you can use [HTTP::header value HEADER_NAME]. If the header isn't set, I think the command will return a null string. So you could just use 'value' instead of 'exists'.

 

 

Aaron

Thanks Aaron,

 

 

Exactly what I was looking for.

 

 

I appreciate the help.

 

 

Cheers