Forum Discussion

Robert_Sutcliff's avatar
Robert_Sutcliff
Icon for Nimbostratus rankNimbostratus
Jun 05, 2008

logging and redirects

Hi,

 

We're having problems setting up logging (similar to apache http access logs). We need to log all the relevant data onto one line, so that we don't get data from lots of concurrent requests mixed up.

 

 

To generate the one line access log - some data has to come from HTTP_REQUEST, and some from HTTP_REPONSE event - I'm using the code below.

 

 

 
 when HTTP_REQUEST { 
 set date_time_request [clock format [clock seconds] -format {%Y-%m-%d %H:%M:%S %z} ] 
 set cs_ip [IP::client_addr] 
 set cs_host [HTTP::host] 
 set cs_vhost [virtual] 
 set cs_uri [HTTP::uri] 
 set cs_method [HTTP::method] 
 set cs_bytes [HTTP::header Content-Length] 
 } 
 when HTTP_RESPONSE { 
 set sc_status [HTTP::status] 
 set sc_bytes [HTTP::header Content-Length] 
 } 
 when CLIENT_CLOSED { 
 what vars are there 
 log local0. "[info vars]" 
 do we have any variables? if not exit to prevent errors 
 if { not [info exists date_time_request] } { return } 
  
 set log_str "$cs_vhost $cs_host $cs_ip - \[$date_time_request\] \"$cs_method $cs_uri\" $sc_status $sc_bytes [IP::remote_addr]" 
 write to syslog 
 log local0. $log_str 
 }

 

 

The problem is that in other iRules we use the HTTP::respond or HTTP::redirect functions.

 

When using either of these statements we get no log at all!

 

 

These functions appear to cause the HTTP_RESPONSE event to not be evaluated. For this reason I moved the actual logging statement to CLIENT_CLOSED (which is still evaluated), and was willing to see just a couple of missing fields.

 

However I soon found that when the HTTP::respond and HTTP::redirect functions run they also appear to drop the entire TCL variable stack (for this connection).

 

 

Has anyone see a similar problem, or know of a fix or work-around?

 

Cheers,

 

Rob
application delivery
dev
devops
iRules
  • hoolio's avatar
    hoolio
    Icon for Cirrostratus rankCirrostratus
    Jun 05, 2008
    I don't think there is a way to determine that HTTP::redirect or HTTP::respond have been used to respond to an HTTP request. You could set a variable in the redirect rule(s) and then look for that in the logging rule. You could use priority to dictate that the HTTP_REQUEST event in the log rule runs after the default priority of 500 (when HTTP_REQUEST priority 501). You could then log the request/response details in HTTP_REQUEST if the request is being redirected by another rule. You'd also want to make sure to unset the variable (or set the value to 0) if the request isn't being responded to from the rule, so the variable will be valid for all HTTP requests on the same TCP connection.

    Also, someone mentioned previously that it's more efficient to save the log items in a single variable compared with using half a dozen: 

     
 when HTTP_REQUEST priority 501 { 
  
     Check if another rule on this request has issued a response 
    if {[info exists redirected] && $redirected]}{ 
  
        Log the request details now, as there won't be a server response 
       log local0. "[virtual] [HTTP::host] [IP::client_addr] - \[[clock format [clock seconds] -format {%Y-%m-%d %H:%M:%S %z}]\] \"[HTTP::method] [HTTP::uri]\" - -" 
  
    } else }{ 
  
        Request isn't being answered from the BIG-IP so save the request details for logging in HTTP_RESPONSE 
       set request_info "[virtual] [HTTP::host] [IP::client_addr] - \[[clock format [clock seconds] -format {%Y-%m-%d %H:%M:%S %z}]\] \"[HTTP::method] [HTTP::uri]\" ..." 
    } 
 } 
 when HTTP_RESPONSE { 
     Response received from the pool.  Log the request + response details 
    log local0. "$request_info + some response details" 
 } 
 when LB_FAILED { 
     Load balancing the request failed, so log the request details here? 
    log local0. "$request_info - something indicating no server response?" 
 }

    Here is an example rule which could redirect the client and set a variable to track the redirection. 

     
 when HTTP_REQUEST { 
  
     Check if some condition is true 
    if {$some_condition == 1}{ 
  
        Track that the client is being redirected 
       set redirected 1 
  
        Redirect the client 
       HTTP::redirect https://example.com 
  
    } else { 
  
        Track that the client is not being redirected 
       set redirected 0 
    } 
 }

    Aaron