APM W3C Local Logging iRule

Question

Hi&nbsp;
We are using the local logging irule found here on devcentral: 
https://devcentral.f5.com/wiki/irules.FormattedLoggingForW3c.ashx&nbsp;
Everything seems to populate correctly, except for the HTTP::username field as seen in the log message below: 
https://devcentral.f5.com/wiki/iRules.HTTP__username.ashx&nbsp;
info: Rule/Common/LOCAL_LOGGING : virtual=/Common/F5RDP client_ip=10.26.243.122 client_port=44012 lb_server=127.1.1.3:8080 host=172.26.4.59 username= request="GET/vesk/webtop=Common/RDP&amp;webtop_type=webtop_full HTTP/1.1" server_status=200 content_length=0 resp_time=8 user_agent="Mozilla/5.0 (Windows NT 6.1; rv:26.0) Gecko/20100101 Firefox/26.0]" referer=https://172.26.1.1/my.policy&nbsp;
Any thoughts? &nbsp;
Thanks!&nbsp;

kevin_stewart · Answer

The HTTP::username command is used to retrieve the username from an HTTP Basic authentication request (Header: Authorization: Basic [bsae64-encoded user:pass]. So you would necessarily need to prompt the user for Basic authentication in order to get this value:
if { not ( [HTTP::header exists Authorization] ) } {
    set body "Authentication FailuredError: Authentication Failure"
    HTTP::respond 401 content  $body WWW-Authenticate "Basic realm=\"[HTTP::header Host]\"" Connection Close
}

tj_vreugdenhil · Answer

Hi Kevin - Since we are applying this to an APM VIP,  couldn't I just use this under the "when HTTP_REQUEST" or would I have to do something different such as your post here:
[link text](https://devcentral.f5.com/questions/apm-ssl-user-login-logout-logging)

when HTTP_REQUEST {
   set username [ACCESS::session data get session.logon.last.username]
}
when HTTP_RESPONSE {
   set log_msg ""
   append log_msg "username=$username "
   log local0. $log_msg
}

kevin_stewart · Answer

The real issue is going to be when you collect the username. The original article assumes you're getting it from an initial HTTP Basic authentication prompt. But since in this case you're probably getting it from an APM logon page, the following code may be more appropriate:&nbsp;when ACCESS_ACL_ALLOWED {
    set http_request "\"[HTTP::method] [HTTP::uri] HTTP/[HTTP::version]\""
    set http_request_time [clock clicks -milliseconds]
    set http_user_agent "\"[HTTP::header User-Agent]]\""
    set http_host [HTTP::host]
    set http_username [ACCESS::session data get session.logon.last.username]
    set client_ip [IP::remote_addr]
    set client_port [TCP::remote_port]
    set http_request_uri [HTTP::uri]
    set referer [HTTP::header value referer]
}
when HTTP_RESPONSE {
    set response_time [expr [clock clicks -milliseconds] - $http_request_time]
    set virtual [virtual]
    set content_length 0
    if { [HTTP::header exists "Content-Length"] } {
        set content_length [HTTP::header "Content-Length"]
    }
    set lb_server "[LB::server addr]:[LB::server port]"
    if { [string compare "$lb_server" ""] == 0 } {
        set lb_server ""
    }
    set status_code [HTTP::status]
    set content_type [HTTP::header "Content-type"]
    set log_msg ""
    append log_msg "virtual=$virtual "
    append log_msg "client_ip=$client_ip "
    append log_msg "client_port=$client_port "
    append log_msg "lb_server=$lb_server "
    append log_msg "host=$http_host "
    append log_msg "username=$http_username "
    append log_msg "$http_request_uri "
    append log_msg "request=$http_request "
    append log_msg "server_status=$status_code "
    append log_msg "content_type=$content_type "
    append log_msg "content_length=$content_length "
    append log_msg "resp_time=$response_time "
    append log_msg "user_agent=$http_user_agent "
    append log_msg "referer=$referer"
       log  local0. $log_msg
    log local0. $log_msg
}Notice this version is basically swapping the HTTP_REQUEST event for the ACCESS_ACL_ALLOWED event, and collecting the username in the session.logon.last.username APM session variable.&nbsp;

tj_vreugdenhil · Answer

Hi Kevin - In using the iRule above and I get a TCL error that it doesn't recognize the http_request_time in the HTTP_RESPONSE. 
So what I did was move everything out of the ACCESS_ACL_ALLOWED event except for the username variable and I again get a TCL error in the HTTP_RESPONSE but now just for the http_username. 
It looks like the ACCESS events and the HTTP events do not play nice together. 
Would something like this work: 
when HTTP_REQUEST {
   set http_request "\"[HTTP::method] [HTTP::uri] HTTP/[HTTP::version]\""
   set http_request_time [clock clicks -milliseconds]
   set http_host [HTTP::host]
   set client_ip [IP::remote_addr]
   set client_port [TCP::remote_port]
   set http_request_uri [HTTP::uri]
   set referer [HTTP::header value referer]
}

when ACCESS_SESSION_STARTED {
 set userid [ACCESS::session data get "session.logon.last.username"]
 set userip [ACCESS::session data get "session.user.clientip"] 
 set useragent [ACCESS::session data get "session.user.agent"]" 
}

when ACCESS_POLICY_COMPLETED { 
    set log_msg ""
    append log_msg "userid=$userid "
    append log_msg "userip=$userip "
    append log_msg "useragent=$useragent "
    log local0. $log_msg
}

when HTTP_RESPONSE {
    set response_time [expr [clock clicks -milliseconds] - $http_request_time]
    set virtual [virtual]
    set content_length 0
    if { [HTTP::header exists "Content-Length"] } {
        set content_length [HTTP::header "Content-Length"]
    }
    set lb_server "[LB::server addr]:[LB::server port]"
    if { [string compare "$lb_server" ""] == 0 } {
        set lb_server ""
    }
    set status_code [HTTP::status]
    set content_type [HTTP::header "Content-type"]
    append log_msg "virtual=$virtual "
    append log_msg "client_ip=$client_ip "
    append log_msg "client_port=$client_port "
    append log_msg "lb_server=$lb_server "
    append log_msg "host=$http_host "
    append log_msg "$http_request_uri "
    append log_msg "request=$http_request "
    append log_msg "server_status=$status_code "
    append log_msg "content_length=$content_length "
    append log_msg "content_type=$content_type "
    append log_msg "resp_time=$response_time "
    append log_msg "referer=$referer"
       log  local0. $log_msg
    log local0. $log_msg
}

or how about putting the username in a HTTP header like this:
when ACCESS_ACL_ALLOWED {
   set user [ACCESS::session data get "session.logon.last.username"]
   HTTP::header insert "X-USERNAME" $user
}

when HTTP_RESPONSE {
    set log_msg ""
    append log_msg "user=$user "
    log local0. $log_msg
}

I would also like to know where I can find a list of ACCESS:session data get variables?
Also would it be easier to log this data by using ASM?  
Thanks!

kevin_stewart · Answer

It looks like the ACCESS events and the HTTP events do not play nice together. &nbsp;

What version are you running, and what is your access policy doing? I've tested this on an 11.4 and 11.5 system without any errors.&nbsp;

I would also like to know where I can find a list of ACCESS:session data get variables? &nbsp;

There really is no definitive list, given that each process (ex. LDAP query, Kerberos SSO, etc.) will insert its own session variables. Your best bet is to either run an APM report in the GUI or dump the "created" session variables using the sessiondump -allkeys command in the shell. Here is a small list of common session variables though:&nbsp;
http://support.f5.com/kb/en-us/products/big-ip_apm/manuals/product/apm-config-11-4-0/apm_config_sessionvars.html?sr=35265198
&nbsp;

Also would it be easier to log this data by using ASM? &nbsp;

You could, but you could also do the same thing using the LTM request logging profile:&nbsp;
http://support.f5.com/kb/en-us/products/big-ip-aam/manuals/product/aam-implementations-11-4-0/20.html?sr=33764514&nbsp;

Forum Discussion

APM W3C Local Logging iRule

Recent Discussions

Background Tasks

Which process is consuming higher CPU

SSL bridging without SSL proxy forward

Big-IP VE edition for MacBook M4 Chip

Client SSL Profile set to Require Client Certificate breaks RDP in APM

Related Content

What is the retention time of local logs in log facilities 0 and 3

What is the retention time of local logs in log facilities 0 and 3

Select Request Logging Profile via iRule

Data Group irule Or Local LTM Policy to Allow Specific IP's, Per VIP

Applicaton security logs stopped

ABOUT DEVCENTRAL

RESOURCES

SUPPORT

PARTNERS