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

Filter by:
  • Solution
  • Technology
Answers

iRULE to capture user credentials in SOAP-XML Payload in Clientless Mode

We have application limitation from vendor where they don't support authentication based on Multiple Domains. I am configuration iRule and APM to achieve short coming of application.

External Application-A Fat client => calls application-B using particular URI (Virtual Server on F5)

Application B URI is defined as plugins in Application A fat client.

when HTTP_REQUEST

  • HTTP::header insert "clientless-mode" 1 (iRule will put into clientless mode for /xyz URI since there are other URIs for webinterface)
  • iRule will match if http menthod id post and content-Type contains "soap+xml" -Collect HTTP content

when HTTP_REQUEST_DATA - Go through XML - Collect username "user1@domain1.com " - Collect Password "12345678"

When Access_Session_started{

Assign value collected previously to variable session.logon.last.username $username session.logon.last.password $password }

APM policy will be look like as follows:

Start => if username contains domain1 => domain1\$username => RADIUS => Allow => Deny

  => if username contains domain2 => domain1\$username => RADIUS => Allow
                           => Deny
0
Rate this Question

Answers to this Question

placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

Hi,

you can use this irule as example:

when HTTP_REQUEST {
   set apmsessionid [HTTP::cookie value MRHSession]
    if { [HTTP::cookie exists "MRHSession"] } {set apmstatus [ACCESS::session exists -state_allow $apmsessionid]} else {set apmstatus 0}
    if {!($apmstatus)} {
        # Insert Clientless-mode header to start APM in clientless mode
        if { [catch {HTTP::header insert "clientless-mode" 1} ] } {log local0. "[IP::client_addr]:[TCP::client_port] : TCL error on HTTP header insert clientless-mode : URL : [HTTP::host][HTTP::path] - Headers : [HTTP::request]"}
    }
    # Collect Post Data to be parsed in HTTP_REQUEST_DATA
    if { [HTTP::method] eq "POST" }{
        set clength 0
        if {[HTTP::header exists "Content-Length"] && [HTTP::header Content-Length] <= 1048576}{
          set clength [HTTP::header Content-Length]
        } else { set clength 1048576 }
        if { [info exists clength] && $clength > 0} { HTTP::collect $clength }
    }   
}

when HTTP_REQUEST_DATA {
   # Parse XML Data
    set xmluser [findstr [HTTP::payload] "<wsse:Username>" 15 "<"]
    set xmlpwtmp  [findstr [HTTP::payload] "<wsse:Password" 14 "<"]
    set xmlpw  [findstr $xmlpwtmp ">" 1 end]
    unset xmlpwtmp
}

when ACCESS_SESSION_STARTED {
    #Variables from HTTP REQUEST Data (XML Parsing)
    if {([info exists "xmluser"])} { ACCESS::session data set session.logon.last.username $xmluser; ACCESS::session data set session.logon.last.logonname $xmluser;  }
    if {([info exists "xmlpw"])} { ACCESS::session data set session.logon.last.password $xmlpw }

}

when ACCESS_ACL_ALLOWED {
    set user [ACCESS::session data get session.logon.last.username]
    HTTP::header insert "login" $user
    HTTP::header remove "Authorization"
}
0
Comments on this Answer
Comment made 04-Apr-2017 by AN 162

Hi Stanislas Thanks for your response.. Still it's same issue, It stuck at very first time it find and . There is 302 right after that.

Content-Type: application/soap+xml; charset=utf-8 Host: url.domain.com Content-Length: 1155 Expect: 100-continue Accept-Encoding: gzip, deflate

<s:Envelope xmlns:s="http://www.w3.org/2003/05/soap-envelope"; xmlns:a="http://www.w3.org/2005/08/addressing"><s:Header><a:Action s:mustUnderstand="1">abc/xyz/Services/2010/01/Authentication/SignIn</a:Action><a:MessageID>urn:uuid:3cxx75bd-xxxx-xxxx-b2f0-ea89a2xxxxf9</a:MessageID><a:ReplyTo><a:Address>http://www.w3.org/2005/08/addressing/anonymous</a:Address></a:ReplyTo>;12f16a0e-xxxx-4511-xxxx-6b6dxxxx2699<a:To s:mustUnderstand="1">https://url.domain.com/abc/session.svc</a:To></s:Header><s:Body>;1<accessCode i:nil="true" xmlns:i="http://www.w3.org/2001/XMLSchema-instance"/>;user1@domain1.domain.com12345678<newPassword i:nil="true" xmlns:i="http://www.w3.org/2001/XMLSchema-instance"/>;false6.5.51.0XXXXXXWindows 7 Enterprise Service Pack 1 64-bit (6.1.7601.65536)en-USPacific Standard Time</s:Body></s:Envelope>HTTP/1.0 302 Found Server: BigIP Connection: Close Content-Length: 0 Location: /my.policy Set-Cookie: LastMRH_Session=523ffc73;path=/;secure Set-Cookie: MRHSession=08a2fd4d3ca3969a91361416523ffc73;path=/;secure Set-Cookie: MRHSHint=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; path=/

Snap shoot of Capture with Following iRULE: when HTTP_REQUEST {

switch [HTTP::method] { "COPY" - "MOVE" { # Replace Destination header with http if using SSL Offloading if { [HTTP::header Destination] starts_with "https" } { HTTP::header replace Destination [string map -nocase {https http} [HTTP::header value Destination]] }

        HTTP::disable
    }
    "MKCOL" -
    "PROPPATCH"
    {
        HTTP::disable
    }
}
if { ( [HTTP::uri] contains "/abc/system.svc") || ( [HTTP::uri] contains "/abc/xyz/iSite/index.htm") || ( [HTTP::uri] contains "/zzz/Client/abc.application") || ( [HTTP::uri] contains "/abc/xyz/iSite/Common.js")}
{
    set apmsessionid [HTTP::cookie value MRHSession]
    if { [HTTP::cookie exists "MRHSession"] } {set apmstatus [ACCESS::session exists -state_allow $apmsessionid]} else {set apmstatus 0}
        if {!($apmstatus)} 
        {
         # Insert Clientless-mode header to start APM in clientless mode
            if { [catch {HTTP::header insert "clientless-mode" 1} ] } {log local0. "[IP::client_addr]:[TCP::client_port] : TCL error on HTTP header insert clientless-mode : URL : [HTTP::host][HTTP::path] - Headers : [HTTP::request]"}
         }
# Collect Post Data to be parsed in HTTP_REQUEST_DATA
    if { [HTTP::method] eq "POST" }
    {
    set clength 0
        if {[HTTP::header exists "Content-Length"] && [HTTP::header Content-Length] <= 1048576}
        {
        set clength [HTTP::header Content-Length]
        } else { set clength 1048576 }
    if { [info exists clength] && $clength > 0} { HTTP::collect $clength }
    }
}

}

when HTTP_REQUEST_DATA { # Parse XML Data set xmluser [findstr [HTTP::payload] "" 11 "<"] set xmlpwtmp [findstr [HTTP::payload] "" 10 "<"] set xmlpw [findstr $xmlpwtmp ">" 1 end] unset xmlpwtmp }

when ACCESS_SESSION_STARTED { #Variables from HTTP REQUEST Data (XML Parsing) if {([info exists "xmluser"])} { ACCESS::session data set session.logon.last.username $xmluser; ACCESS::session data set session.logon.last.logonname $xmluser; } if {([info exists "xmlpw"])} { ACCESS::session data set session.logon.last.password $xmlpw }

}

when ACCESS_ACL_ALLOWED { set user [ACCESS::session data get session.logon.last.username] HTTP::header insert "login" $user HTTP::header remove "Authorization" } Image Text

Snap shoot of Capture with WebDev Unsupport iRULE (Working Condition but without multiple domain authentication): when CLIENT_ACCEPTED { # Enable HTTP processing for all requests by default HTTP::enable }

when HTTP_REQUEST { # Selectively disable HTTP processing for specific request methods switch [HTTP::method] { "COPY" - "MOVE" { # Replace Destination header with http if using SSL Offloading if { [HTTP::header Destination] starts_with "https" } { HTTP::header replace Destination [string map -nocase {https http} [HTTP::header value Destination]] }

        HTTP::disable
    }
    "MKCOL" -
    "PROPPATCH"
    {
        HTTP::disable
    }

} } Image Text

0
placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

I found the issue. There were multiple .svc (session.svc and application.svc) being called under URI /abc/ so I changed my URL to point to /abc/ instead of particular .svc.

I found as you can see in my captures with only webDev iRule I get 100 Continue messages but When I put iRule you mentioned,, I don't see 100 Continue is it because of clientless ?

0
Comments on this Answer
Comment made 04-Apr-2017 by Stanislas Piron 6257

Hi,

Microsoft Share point is using WebDAV protocol.

You can try the APM share point authentication irule to manage authentication instead of disabling APM.

When I wrote it, I used a WebDAV server to emulate share point server!

0
Comment made 05-Apr-2017 by AN 162

Hi Stanislas,

I found iRule creates multiple APM Sessions... There were 26 session in APM from my IP to VServer. Upon clicking 3 tabs it created more total 46 apm session,.,,

Since username that I am trying to capture exist in /abc/session.svc I change my irule to following to make sure all other are clientless but http content only collected when we find /abc/session.svc. Also this should reduce APM session:

when HTTP_REQUEST { if { ( [HTTP::uri] contains "/abc/session.svc")} { set apmsessionid [HTTP::cookie value MRHSession]

        if  { [HTTP::cookie exists "MRHSession"]} {set apmstatus [ACCESS::session exists -state_allow $apmsessionid]} else {set apmstatus 0}
             if {!($apmstatus)} 
            {
            # Insert Clientless-mode header to start APM in clientless mode
            if { [catch {HTTP::header insert "clientless-mode" 1} ] } {log local0. "[IP::client_addr]:[TCP::client_port] : TCL error on HTTP header insert clientless-mode : URL : [HTTP::host][HTTP::path] - Headers : [HTTP::request]"}
            }
                if {([HTTP::method] eq "POST") }
                {
                set clength 0
                    if {[HTTP::header exists "Content-Length"] && [HTTP::header Content-Length] <= 1048576}
                    {
                    set clength [HTTP::header Content-Length]
                    } else { set clength 1048576 }
                    if { [info exists clength] && $clength > 0} { HTTP::collect $clength }
                }
     }

if { ( [HTTP::uri] contains "/abc/") || ( [HTTP::uri] contains "/abc/xyz/iSite/PowerScribe360plugin.htm") || ( [HTTP::uri] contains "/abc/Client/xyz.application")} { HTTP::header insert "clientless-mode" 1 } }

when HTTP_REQUEST_DATA { # Parse XML Data set xmluser [findstr [HTTP::payload] "" 11 "<"] set xmlpwtmp [findstr [HTTP::payload] "" 10 "<"] set xmlpw [findstr $xmlpwtmp ">" 1 end] unset xmlpwtmp }

when ACCESS_SESSION_STARTED { #Variables from HTTP REQUEST Data (XML Parsing) if {([info exists "xmluser"])} { ACCESS::session data set session.logon.last.username $xmluser; ACCESS::session data set session.logon.last.logonname $xmluser; } if {([info exists "xmlpw"])} { ACCESS::session data set session.logon.last.password $xmlpw }

}

when ACCESS_ACL_ALLOWED { set user [ACCESS::session data get session.logon.last.username] HTTP::header insert "login" $user HTTP::header remove "Authorization" } I still see multiple APM session. My apology for newbie with iRUle.. but can I have apm enable for particular URI.. I tried { ACCESS::enable } else { ACCESS::disable } but didn't work.

Also in apm logs I can only see session.logon.last.logonname but nothing being assign for session.logon.last.username

bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.access.profile to Session Var tmm.session.7a68597b.session.access.profile bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.access.profile"="/test/APP-AP"(length=23) bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.logonname" was not found in the local cache for session "7a68597b" bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.logonname to Session Var tmm.session.7a68597b.session.logon.last.logonname bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.logon.last.logonname"="user1@domain1.domain.com"(length=24) bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=0 bigip notice apmd[17408]: 01490102:5: /test/APP-AP:test:7a68597b: Access policy result: LTM+APM_Mode bigip info apmd[17408]: 01490004:6: /test/APP-AP:test:7a68597b: Executed agent '/test/APP-AP_end_allow_ag', return value 0

0
Comment made 05-Apr-2017 by Stanislas Piron 6257

You can change HTTP_REQUEST_DATA event with this:

when HTTP_REQUEST_DATA {
   # Parse XML Data
    set xmluser [findstr [HTTP::payload] "" 11 "<"]
    set xmlpwtmp  [findstr [HTTP::payload] "" 10 "<"]
    set xmlpw  [findstr $xmlpwtmp ">" 1 end]
    unset xmlpwtmp

    if { $PROFILE_RESTRICT_SINGLE_IP == 0 } {
        binary scan [md5 "$xmlpw"] H* clientless(hash)
    } else {
        binary scan [md5 "$xmlpw[TCP::client_addr]"] H* hash
    }
    set user_key "$xmluser.$hash"
    set cookie_list             [ ACCESS::user getsid $user_key ]
    if { [ llength $cookie_list ] != 0 } {
       set cookie [ ACCESS::user getkey [ lindex $cookie_list 0 ] ]
       if { $cookie != "" } {
          HTTP::cookie insert name MRHSession value $cookie
          set insert_mode 0
       }
    }
    if { $insert_mode } {
       HTTP::header insert "clientless-mode" 1
       HTTP::header insert "username" $xmluser
       HTTP::header insert "password" $xmlpw
       set clientless_mode 1
    }
}

remove this event ACCESS_SESSION_STARTED (username insert is done by the code above) and remove the following line in HTTP_REQUEST event:

if { [catch {HTTP::header insert "clientless-mode" 1} ] } {log local0. "[IP::client_addr]:[TCP::client_port] : TCL error on HTTP header insert clientless-mode : URL : [HTTP::host][HTTP::path] - Headers : [HTTP::request]"}
0
Comment made 06-Apr-2017 by AN 162

Ater removing ACCESS_SESSION_STARTED and clientless-mode line from HTTP_REQUEST.

It's complaining about TCP::client_addr Rule [/frontend/App-rule] error: /frontend/App-rule:50: error: [undefined procedure: TCP::client_addr][TCP::client_addr]

Following is my my iRule. After trouble I was able to put access::enable only for /abc/session.svc. I tried putting my username and password manually in AP and tested AP works fine. But it doesn't grab required info from iRule.

when HTTP_REQUEST { switch [HTTP::method] { "COPY" - "MOVE" { # Replace Destination header with http if using SSL Offloading if { [HTTP::header Destination] starts_with "https" } { HTTP::header replace Destination [string map -nocase {https http} [HTTP::header value Destination]] }

        HTTP::disable
    }
    "MKCOL" -
    "PROPPATCH"
    {
        HTTP::disable
    }
}

if { ( [HTTP::uri] contains "/abc/session.svc")}
    {
    ACCESS::enable
    set apmsessionid [HTTP::cookie value MRHSession] 

        if  { [HTTP::cookie exists "MRHSession"]} {set apmstatus [ACCESS::session exists -state_allow $apmsessionid]} else {set apmstatus 0}
            if {([HTTP::method] eq "POST") }
                {
                set clength 0
                    if {[HTTP::header exists "Content-Length"] && [HTTP::header Content-Length] <= 1048576}
                    {
                    set clength [HTTP::header Content-Length]
                    } else { set clength 1048576 }
                    if { [info exists clength] && $clength > 0} { HTTP::collect $clength }
                }
     } else { ACCESS::disable}

}

when HTTP_REQUEST_DATA { # Parse XML Data set xmluser [findstr [HTTP::payload] "" 11 "<"] set xmlpwtmp [findstr [HTTP::payload] "" 10 "<"] set xmlpw [findstr $xmlpwtmp ">" 1 end] unset xmlpwtmp if { $PROFILE_RESTRICT_SINGLE_IP == 0 } { binary scan [md5 "$xmlpw"] H* clientless(hash) } else { binary scan [md5 "$xmlpw[TCP::client_addr]"] H* hash } set user_key "$xmluser.$hash" set cookie_list [ ACCESS::user getsid $user_key ] if { [ llength $cookie_list ] != 0 } { set cookie [ ACCESS::user getkey [ lindex $cookie_list 0 ] ] if { $cookie != "" } { HTTP::cookie insert name MRHSession value $cookie set insert_mode 0 } } if { $insert_mode } { HTTP::header insert "clientless-mode" 1 HTTP::header insert "username" $xmluser HTTP::header insert "password" $xmlpw set clientless_mode 1 } }

when ACCESS_ACL_ALLOWED { set user [ACCESS::session data get session.logon.last.username] HTTP::header insert "login" $user HTTP::header remove "Authorization" }

0
Comment made 06-Apr-2017 by Stanislas Piron 6257

I did a mistake ... it is not [TCP::client_addr] but [IP::client_addr]

0
Comment made 06-Apr-2017 by AN 162

Now It doesn't create any APM session with new irule.. APM log is empty.,..

I was able to bring APM session down to 3 sessions with my below if condition ..

if { ( [HTTP::uri] contains "/abc/session.svc")} { ACCESS::enable . . .
} else { ACCESS::disable}

Now it creates 3 APM sessions instead of 24 ,, that is good,, I found /abc/session.svc is being called twice in whole communication.. the very first time it is being called has loginName and password in it,...I still can't figured out last apm session it creates even I tried looking into my wireshark capture the last APM session and cannot find. I can find two session IDs in wireshark

How I can make above condition to run only once very first time it find /abc/session.svc?

I revert our last iRule change and with old iRule I can see APM logs. Now I see username being fetched but not password. If I able to run iRule very first /abc/session.svc find and grab username and password. I am pretty sure it will work.

bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.logon.last.username"="user1@domain1.domain.com"(length=24) bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.domain" was not found in the local cache for session "124ad881" bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED bigipdebug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.domain to Session Var tmm.session.124ad881.session.logon.last.domain bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 557 Msg: variable "session.logon.last.domain" for session "124ad881" was not found in MEMCACHED bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.password" was not found in the local cache for session "124ad881" bigipinfo apmd[17408]: 01490006:6: /uat-frontend/Nuance-AP:uat-frontend:124ad881: Following rule 'fallback' from item 'Start' to item 'AD Auth' bigipdebug apmd[17408]: 01490011:7: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD agent: ENTER Function executeInstance bigipdebug apmd[17408]: 01490231:7: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD Agent: Configured to use /uat-frontend/AAA-Servers as a server bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED bigipdebug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.password to Session Var tmm.session.124ad881.session.logon.last.password bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.logon.last.password"=""(length=0) bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.change_password" was not found in the local cache for session "124ad881" bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED bigipdebug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.change_password to Session Var tmm.session.124ad881.session.logon.last.change_password bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 557 Msg: variable "session.logon.last.change_password" for session "124ad881" was not found in MEMCACHED bigipdebug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent bigipdebug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=2 bigipdebug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = "expr {[mcget {session.ad.last.authresult}] == 1}" bigipdebug apmd[17408]: 01490023:7: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD module: ENTER Function authenticateUser bigiperr apmd[17408]: 01490107:3: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD module: authentication with 'user1@domain1.domain.com' failed: empty password detected (-1) bigipdebug apmd[17408]: 01490111:7: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD module: authenticate(): empty password detected (-1) bigipdebug apmd[17408]: 01490024:7: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD module: LEAVE Function authenticateUser bigipinfo apmd[17408]: 01490017:6: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD agent: Auth (logon attempt:0): authenticate with 'user1@domain1.domain.com' failed bigipinfo apmd[17408]: 01490162:6: /uat-frontend/Nuance-AP:uat-frontend:124ad881: Username used for authentication contains domain information. Please enable 'Split domain from full Username' option in Logon Page if domain info should be separated from username for authentication to work properly. bigipdebug apmd[17408]: 01490012:7: /uat-frontend/Nuance-AP:uat-frontend:124ad881: AD agent: LEAVE Function executeInstance bigipinfo apmd[17408]: 01490004:6: /uat-frontend/Nuance-AP:uat-frontend:124ad881: Executed agent '/uat-frontend/Nuance-AP_act_active_directory_auth_ag', return value 0 bigipnotice apmd[17408]: 01490005:5: /uat-frontend/Nuance-AP:uat-frontend:124ad881: Following rule 'fallback' from item 'AD Auth' to ending 'Deny'

0
Comment made 06-Apr-2017 by AN 162

Thanks Stanislas Piron for looking into it.

I have snapshot of APM session Variables

Image Text Image Text

    bigip notice tmm[22893]: 01490517:5: /frontend/APP-AP:frontend:64359fff: User-Agent header is absent or empty
    bigip notice tmm[22893]: 01490500:5: /frontend/APP-AP:frontend:64359fff: New session from client IP XXX.XXX.XXX.XXX (ST=/CC=/C=) at VIP XXX.XXX.XXX.XXX Listener /frontend/APP-AP (Reputation=Unknown)
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_accept()" line: 1428 Msg: process_accept: queueing 236
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1536 Msg: process_apd_request: dequeueing 236
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1538 Msg: //=========================================
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1539 Msg:  Request received
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1540 Msg: //-----------------------------------------
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 0, name = Profile, value = readFromSocket
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "readFromSocket()" line: 132 Msg: bytes_received: 461, len: 461
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "readFromSocket()" line: 154 Msg: first header received: POST / HTTP/1.1
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 390 Msg: HTTP Method received: POST
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 419 Msg: HTTP URI received: /
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 464 Msg: HTTP major version received: 1
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 465 Msg: HTTP minor version received: 1
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, content-type: application/soap+xml; charset=utf-8
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, host: url.domain.com
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, content-length: 0
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, expect: 100-continue
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, accept-encoding: gzip, deflate
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, x-forwarded-for: XXX.XXX.XXX.XXX
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, clientless-mode: 1
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, clientless-mode: 1
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, client-session-id: 3d2aba48304ac5d40fffc2f064359fff
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, session-key: b8b0176e363454487f771a0264359fff
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, profile-id: /frontend/APP-AP
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, partition-id: frontend
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, session-id: 64359fff
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, snapshot-id:
    bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, cmp-pu: 0
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1557 Msg: Received Session Id: "64359fff"
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1559 Msg: Received Profile Id: "/frontend/APP-AP"
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1561 Msg: request-from: ""
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1563 Msg: clientless-mode: "1"
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1565 Msg: no-inspection-host-mode: ""
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1567 Msg: Received CMP Process Unit: "0, mc = 0x63002ee4"
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1569 Msg: start processing of the access policy
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 1, name = Profile, value = searchProfileList
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicyProcessor.cpp func: "_initSession()" line: 583 Msg: access policy processing: 0
    bigip debug apmd[17408]: 01490000:7: ===  This is a request for clientless mode  ===
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 2, name = Profile, value = /frontend/APP-AP
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=1
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = ""
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 3, name = From, value = Start
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 4, name = To, value = Variable Assign
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 5, name = Rule, value = fallback
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 6, name = Agent, value = /frontend/APP-AP_act_variable_assign_ag
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.username" was not found in the local cache for session "64359fff"
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.username to Session Var tmm.session.64359fff.session.logon.last.username
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.logon.last.username"="user1@domain1.domain.com"(length=24)
    bigip debug apmd[17408]: 01490000:7: modules/VariableAssignment/VariableAssignmentAgent.cpp func: "VariableAssignmentAgentexecuteInstance()" line: 1346 Msg: ConfigName: session.logon.last.domain, ConfigVal domain1.domain.com
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.password" was not found in the local cache for session "64359fff"
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
    bigip info apmd[17408]: 01490006:6: /frontend/APP-AP:frontend:64359fff: Following rule 'fallback' from item 'Start' to item 'Variable Assign'
    bigip notice apmd[17408]: 01490010:5: /frontend/APP-AP:frontend:64359fff: Username 'user1'
    bigip info apmd[17408]: 01490004:6: /frontend/APP-AP:frontend:64359fff: Executed agent '/frontend/APP-AP_act_variable_assign_ag', return value 0
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.password to Session Var tmm.session.64359fff.session.logon.last.password
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.logon.last.password"=""(length=0)
    bigip debug apmd[17408]: 01490000:7: modules/VariableAssignment/VariableAssignmentAgent.cpp func: "VariableAssignmentAgentexecuteInstance()" line: 1346 Msg: ConfigName: session.logon.last.password, ConfigVal
    bigip debug apmd[17408]: 01490000:7: modules/VariableAssignment/VariableAssignmentAgent.cpp func: "VariableAssignmentAgentexecuteInstance()" line: 1346 Msg: ConfigName: session.logon.last.username, ConfigVal user1
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=1
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = ""
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 7, name = From, value = Variable Assign
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 8, name = To, value = AD Auth
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 9, name = Rule, value = fallback
    bigip info apmd[17408]: 01490006:6: /frontend/APP-AP:frontend:64359fff: Following rule 'fallback' from item 'Variable Assign' to item 'AD Auth'
    bigip debug apmd[17408]: 01490011:7: /frontend/APP-AP:frontend:64359fff: AD agent: ENTER Function executeInstance
    bigip debug apmd[17408]: 01490231:7: /frontend/APP-AP:frontend:64359fff: AD Agent: Configured to use /frontend/AAA-Servers as a server
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 10, name = Agent, value = /frontend/APP-AP_act_active_directory_auth_ag
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.change_password" was not found in the local cache for session "64359fff"
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.change_password to Session Var tmm.session.64359fff.session.logon.last.change_password
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 557 Msg: variable "session.logon.last.change_password" for session "64359fff" was not found in MEMCACHED
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=2
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = "expr {[mcget {session.ad.last.authresult}] == 1}"
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = ""
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 11, name = From, value = AD Auth
    bigip debug apmd[17408]: 01490023:7: /frontend/APP-AP:frontend:64359fff: AD module: ENTER Function authenticateUser
    bigip err apmd[17408]: 01490107:3: /frontend/APP-AP:frontend:64359fff: AD module: authentication with 'user1' failed: empty password detected  (-1)
    bigip debug apmd[17408]: 01490111:7: /frontend/APP-AP:frontend:64359fff: AD module: authenticate(): empty password detected (-1)
    bigip debug apmd[17408]: 01490024:7: /frontend/APP-AP:frontend:64359fff: AD module: LEAVE Function authenticateUser
    bigip info apmd[17408]: 01490017:6: /frontend/APP-AP:frontend:64359fff: AD agent: Auth (logon attempt:0): authenticate with 'user1' failed
    bigip debug apmd[17408]: 01490012:7: /frontend/APP-AP:frontend:64359fff: AD agent: LEAVE Function executeInstance
    bigip info apmd[17408]: 01490004:6: /frontend/APP-AP:frontend:64359fff: Executed agent '/frontend/APP-AP_act_active_directory_auth_ag', return value 0
    bigip notice apmd[17408]: 01490005:5: /frontend/APP-AP:frontend:64359fff: Following rule 'fallback' from item 'AD Auth' to ending 'Deny'
    bigip notice apmd[17408]: 01490102:5: /frontend/APP-AP:frontend:64359fff: Access policy result: Logon_Deny
    bigip info apmd[17408]: 01490004:6: /frontend/APP-AP:frontend:64359fff: Executed agent '/frontend/APP-AP_end_deny_ag', return value 0
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 12, name = To, value = Deny
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 13, name = Rule, value = fallback
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1661041520, step 14, name = Agent, value = /frontend/APP-AP_end_deny_ag
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=0
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 595 Msg: We reached a terminator - completely done with Access Policy for this session
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 616 Msg: ClientData version string is empty, fetching browscap
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.client.browscap_info" was not found in the local cache for session "64359fff"
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.client.browscap_info to Session Var tmm.session.64359fff.session.client.browscap_info
    bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.client.browscap_info"="uimode=0&ctype=unknown&cversion=0&cjs=0&cactivex=0&cplugin=0&cplatform=unknown&cpu=unknown"(length=90)
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 620 Msg: Browscap is "uimode=0&ctype=unknown&cversion=0&cjs=0&cactivex=0&cplugin=0&cplatform=unknown&cpu=unknown"
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cactivex = 0
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cjs = 0
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cplatform = unknown
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cplugin = 0
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cpu = unknown
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element ctype = unknown
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cversion = 0
    bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element uimode = 0
    bigip notice apmd[17408]: 01490248:5: /frontend/APP-AP:frontend:64359fff: Received client info - Hostname:  Type: unknown Version: 0 Platform: unknown CPU: unknown UI Mode: Full Javascript Support: 0 ActiveX Support: 0 Plugin Support: 0
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.ad./frontend/APP-AP_act_active_directory_auth_ag.authresult' set to '0'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.ad./frontend/APP-AP_act_active_directory_auth_ag.errmsg' set to 'empty password detected'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.ad.last.authresult' set to '0'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.ad.last.errmsg' set to 'empty password detected'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.logon.last.domain' set to 'domain1.domain.com'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.logon.last.password' set to '**********'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.logon.last.username' set to 'user1'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.logon.page.errorcode' set to '1'
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.logout.page.customization.group' set to '/frontend/APP-AP_end_deny_ag'
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1624 Msg: processing of access policy is done, result code=fffffff1
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "writeSessionVarToSessionDb()" line: 2316 Msg: syncing data with MEMCACHED
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad./frontend/APP-AP_act_active_directory_auth_ag.authresult to Session Var tmm.session.64359fff.session.ad./frontend/APP-AP_act_active_directory_auth_ag.authresult
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad./frontend/APP-AP_act_active_directory_auth_ag.errmsg to Session Var tmm.session.64359fff.session.ad./frontend/APP-AP_act_active_directory_auth_ag.errmsg
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad.last.authresult to Session Var tmm.session.64359fff.session.ad.last.authresult
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad.last.errmsg to Session Var tmm.session.64359fff.session.ad.last.errmsg
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.domain to Session Var tmm.session.64359fff.session.logon.last.domain
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.password to Session Var tmm.session.64359fff.session.logon.last.password
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.username to Session Var tmm.session.64359fff.session.logon.last.username
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.page.errorcode to Session Var tmm.session.64359fff.session.logon.page.errorcode
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logout.page.customization.group to Session Var tmm.session.64359fff.session.logout.page.customization.group
    bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.policy.result to Session Var tmm.session.64359fff.session.policy.result
    bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:64359fff: Session variable 'session.policy.result' set to 'deny'
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "sendAccessPolicyResponse()" line: 2581 Msg: DONE WITH ACCESS POLICY - send 'we are done with access policy for this session' code
    bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1665 Msg:  ** done with the request processing **
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "close()" line: 208 Msg: queue::close dumping steps front to back:
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Profile = readFromSocket, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Profile = searchProfileList, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Profile = /frontend/APP-AP, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step From = Start, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step To = Variable Assign, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Rule = fallback, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Agent = /frontend/APP-AP_act_variable_assign_ag, 0 seconds
    bigip err apmd[17408]: 01490000:3: queue.cpp func: "printx()" line: 329 Msg: Queue statistics: work.size() 0, threads 40, running 0
    bigip err apmd[17408]: 01490000:3: queue.cpp func: "printx()" line: 344 Msg: Thread 23 id 1661041520 fd 236 queue time 1491496425 work time 0
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step From = Variable Assign, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step To = AD Auth, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Rule = fallback, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Agent = /frontend/APP-AP_act_active_directory_auth_ag, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step From = AD Auth, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step To = Deny, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Rule = fallback, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Agent = /frontend/APP-AP_end_deny_ag, 0 seconds
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "close()" line: 209 Msg: 0 queued descriptors remain
    bigip debug apmd[17408]: 01490000:7: queue.cpp func: "close()" line: 211 Msg: queue::close done

    Code
bigip notice tmm1[22893]: 01490517:5: /frontend/APP-AP:frontend:e9936a1b: User-Agent header is absent or empty
bigip notice tmm1[22893]: 01490500:5: /frontend/APP-AP:frontend:e9936a1b: New session from client IP XXX.XXX.XXX.XXX (ST=/CC=/C=) at VIP XXX.XXX.XXX.XXX Listener /frontend/APP-AP (Reputation=Unknown)
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_accept()" line: 1428 Msg: process_accept: queueing 236
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1536 Msg: process_apd_request: dequeueing 236
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1538 Msg: //=========================================
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1539 Msg:  Request received
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1540 Msg: //-----------------------------------------
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 0, name = Profile, value = readFromSocket
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "readFromSocket()" line: 132 Msg: bytes_received: 485, len: 485
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "readFromSocket()" line: 154 Msg: first header received: POST / HTTP/1.1
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 390 Msg: HTTP Method received: POST
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 419 Msg: HTTP URI received: /
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 464 Msg: HTTP major version received: 1
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpRequestHeader()" line: 465 Msg: HTTP minor version received: 1
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, content-type: application/soap+xml; charset=utf-8
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, host: url.domain.com
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, content-length: 0
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, expect: 100-continue
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, accept-encoding: gzip, deflate
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, connection: Keep-Alive
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, x-forwarded-for: XXX.XXX.XXX.XXX
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, clientless-mode: 1
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, clientless-mode: 1
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, client-session-id: 33140849540c2cdf5f326a62e9936a1b
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, session-key: f43cc4105195943ff9d23788e9936a1b
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, profile-id: /frontend/APP-AP
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, partition-id: frontend
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, session-id: e9936a1b
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, snapshot-id:
bigip debug apmd[17408]: 01490000:7: HTTPParser.cpp func: "parseHttpGenericHeader()" line: 513 Msg: Header received, cmp-pu: 1
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1557 Msg: Received Session Id: "e9936a1b"
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1559 Msg: Received Profile Id: "/frontend/APP-AP"
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1561 Msg: request-from: ""
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1563 Msg: clientless-mode: "1"
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1565 Msg: no-inspection-host-mode: ""
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1567 Msg: Received CMP Process Unit: "1, mc = 0x61beeee4"
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1569 Msg: start processing of the access policy
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 1, name = Profile, value = searchProfileList
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicyProcessor.cpp func: "_initSession()" line: 583 Msg: access policy processing: 0
bigip debug apmd[17408]: 01490000:7: ===  This is a request for clientless mode  ===
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 2, name = Profile, value = /frontend/APP-AP
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=1
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = ""
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 3, name = From, value = Start
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 4, name = To, value = Variable Assign
bigip info apmd[17408]: 01490006:6: /frontend/APP-AP:frontend:e9936a1b: Following rule 'fallback' from item 'Start' to item 'Variable Assign'
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 5, name = Rule, value = fallback
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 6, name = Agent, value = /frontend/APP-AP_act_variable_assign_ag
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.username" was not found in the local cache for session "e9936a1b"
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.username to Session Var tmm.session.e9936a1b.session.logon.last.username
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.logon.last.username"="user1@domain1.domain.com"(length=24)
bigip debug apmd[17408]: 01490000:7: modules/VariableAssignment/VariableAssignmentAgent.cpp func: "VariableAssignmentAgentexecuteInstance()" line: 1346 Msg: ConfigName: session.logon.last.domain, ConfigVal domain1.domain.com
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.password" was not found in the local cache for session "e9936a1b"
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.password to Session Var tmm.session.e9936a1b.session.logon.last.password
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.logon.last.password"=""(length=0)
bigip notice apmd[17408]: 01490010:5: /frontend/APP-AP:frontend:e9936a1b: Username 'user1'
bigip info apmd[17408]: 01490004:6: /frontend/APP-AP:frontend:e9936a1b: Executed agent '/frontend/APP-AP_act_variable_assign_ag', return value 0
bigip info apmd[17408]: 01490006:6: /frontend/APP-AP:frontend:e9936a1b: Following rule 'fallback' from item 'Variable Assign' to item 'AD Auth'
bigip debug apmd[17408]: 01490011:7: /frontend/APP-AP:frontend:e9936a1b: AD agent: ENTER Function executeInstance
bigip debug apmd[17408]: 01490231:7: /frontend/APP-AP:frontend:e9936a1b: AD Agent: Configured to use /frontend/AAA-Servers as a server
bigip debug apmd[17408]: 01490000:7: modules/VariableAssignment/VariableAssignmentAgent.cpp func: "VariableAssignmentAgentexecuteInstance()" line: 1346 Msg: ConfigName: session.logon.last.password, ConfigVal
bigip debug apmd[17408]: 01490000:7: modules/VariableAssignment/VariableAssignmentAgent.cpp func: "VariableAssignmentAgentexecuteInstance()" line: 1346 Msg: ConfigName: session.logon.last.username, ConfigVal user1
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=1
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = ""
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 7, name = From, value = Variable Assign
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 8, name = To, value = AD Auth
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 9, name = Rule, value = fallback
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 10, name = Agent, value = /frontend/APP-AP_act_active_directory_auth_ag
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.logon.last.change_password" was not found in the local cache for session "e9936a1b"
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.change_password to Session Var tmm.session.e9936a1b.session.logon.last.change_password
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 557 Msg: variable "session.logon.last.change_password" for session "e9936a1b" was not found in MEMCACHED
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=2
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = "expr {[mcget {session.ad.last.authresult}] == 1}"
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 538 Msg: Rule to evaluate = ""
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 11, name = From, value = AD Auth
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 12, name = To, value = Deny
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 13, name = Rule, value = fallback
bigip debug apmd[17408]: 01490023:7: /frontend/APP-AP:frontend:e9936a1b: AD module: ENTER Function authenticateUser
bigip err apmd[17408]: 01490107:3: /frontend/APP-AP:frontend:e9936a1b: AD module: authentication with 'user1' failed: empty password detected  (-1)
bigip debug apmd[17408]: 01490111:7: /frontend/APP-AP:frontend:e9936a1b: AD module: authenticate(): empty password detected (-1)
bigip debug apmd[17408]: 01490024:7: /frontend/APP-AP:frontend:e9936a1b: AD module: LEAVE Function authenticateUser
bigip info apmd[17408]: 01490017:6: /frontend/APP-AP:frontend:e9936a1b: AD agent: Auth (logon attempt:0): authenticate with 'user1' failed
bigip debug apmd[17408]: 01490012:7: /frontend/APP-AP:frontend:e9936a1b: AD agent: LEAVE Function executeInstance
bigip info apmd[17408]: 01490004:6: /frontend/APP-AP:frontend:e9936a1b: Executed agent '/frontend/APP-AP_act_active_directory_auth_ag', return value 0
bigip notice apmd[17408]: 01490005:5: /frontend/APP-AP:frontend:e9936a1b: Following rule 'fallback' from item 'AD Auth' to ending 'Deny'
bigip notice apmd[17408]: 01490102:5: /frontend/APP-AP:frontend:e9936a1b: Access policy result: Logon_Deny
bigip info apmd[17408]: 01490004:6: /frontend/APP-AP:frontend:e9936a1b: Executed agent '/frontend/APP-AP_end_deny_ag', return value 0
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "setMarker()" line: 377 Msg: queue::setMarker: thread id 1639988080, step 14, name = Agent, value = /frontend/APP-AP_end_deny_ag
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/SessionState.h func: "clearTempSessionAgentState()" line: 110 Msg: Agent did not initiated the scheduled agent
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 532 Msg: Let's evaluate rules, total number of rules for this action=0
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 595 Msg: We reached a terminator - completely done with Access Policy for this session
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 616 Msg: ClientData version string is empty, fetching browscap
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 542 Msg: variable "session.client.browscap_info" was not found in the local cache for session "e9936a1b"
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 549 Msg: try to get it from MEMCACHED
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.client.browscap_info to Session Var tmm.session.e9936a1b.session.client.browscap_info
bigip debug apmd[17408]: 01490000:7: ./AccessPolicyProcessor/Session.h func: "getSessionVar()" line: 571 Msg: variable found, lets add it to the local cache "session.client.browscap_info"="uimode=0&ctype=unknown&cversion=0&cjs=0&cactivex=0&cplugin=0&cplatform=unknown&cpu=unknown"(length=90)
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 620 Msg: Browscap is "uimode=0&ctype=unknown&cversion=0&cjs=0&cactivex=0&cplugin=0&cplatform=unknown&cpu=unknown"
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cactivex = 0
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cjs = 0
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cplatform = unknown
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cplugin = 0
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cpu = unknown
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element ctype = unknown
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element cversion = 0
bigip debug apmd[17408]: 01490000:7: AccessPolicyProcessor/AccessPolicy.cpp func: "execute()" line: 626 Msg: Browscap element uimode = 0
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1624 Msg: processing of access policy is done, result code=fffffff1
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "writeSessionVarToSessionDb()" line: 2316 Msg: syncing data with MEMCACHED
bigip notice apmd[17408]: 01490248:5: /frontend/APP-AP:frontend:e9936a1b: Received client info - Hostname:  Type: unknown Version: 0 Platform: unknown CPU: unknown UI Mode: Full Javascript Support: 0 ActiveX Support: 0 Plugin Support: 0
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.ad./frontend/APP-AP_act_active_directory_auth_ag.authresult' set to '0'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.ad./frontend/APP-AP_act_active_directory_auth_ag.errmsg' set to 'empty password detected'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.ad.last.authresult' set to '0'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.ad.last.errmsg' set to 'empty password detected'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.logon.last.domain' set to 'domain1.domain.com'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.logon.last.password' set to '**********'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.logon.last.username' set to 'user1'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.logon.page.errorcode' set to '1'
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.logout.page.customization.group' set to '/frontend/APP-AP_end_deny_ag'
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad./frontend/APP-AP_act_active_directory_auth_ag.authresult to Session Var tmm.session.e9936a1b.session.ad./frontend/APP-AP_act_active_directory_auth_ag.authresult
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad./frontend/APP-AP_act_active_directory_auth_ag.errmsg to Session Var tmm.session.e9936a1b.session.ad./frontend/APP-AP_act_active_directory_auth_ag.errmsg
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad.last.authresult to Session Var tmm.session.e9936a1b.session.ad.last.authresult
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.ad.last.errmsg to Session Var tmm.session.e9936a1b.session.ad.last.errmsg
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.domain to Session Var tmm.session.e9936a1b.session.logon.last.domain
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.password to Session Var tmm.session.e9936a1b.session.logon.last.password
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.last.username to Session Var tmm.session.e9936a1b.session.logon.last.username
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logon.page.errorcode to Session Var tmm.session.e9936a1b.session.logon.page.errorcode
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.logout.page.customization.group to Session Var tmm.session.e9936a1b.session.logout.page.customization.group
bigip debug apmd[17408]: 01490000:7: memcache.c func: "mc_convert_session_var_to_mc_key()" line: 2564 Msg: Converted Var: session.policy.result to Session Var tmm.session.e9936a1b.session.policy.result
bigip info apmd[17408]: 01490007:6: /frontend/APP-AP:frontend:e9936a1b: Session variable 'session.policy.result' set to 'deny'
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "sendAccessPolicyResponse()" line: 2581 Msg: DONE WITH ACCESS POLICY - send 'we are done with access policy for this session' code
bigip debug apmd[17408]: 01490000:7: ApmD.cpp func: "process_apd_request()" line: 1665 Msg:  ** done with the request processing **
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "close()" line: 208 Msg: queue::close dumping steps front to back:
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Profile = readFromSocket, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Profile = searchProfileList, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Profile = /frontend/APP-AP, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step From = Start, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step To = Variable Assign, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Rule = fallback, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Agent = /frontend/APP-AP_act_variable_assign_ag, 0 seconds
bigip err apmd[17408]: 01490000:3: queue.cpp func: "printx()" line: 329 Msg: Queue statistics: work.size() 0, threads 40, running 0
bigip err apmd[17408]: 01490000:3: queue.cpp func: "printx()" line: 344 Msg: Thread 3 id 1639988080 fd 236 queue time 1491496428 work time 0
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step From = Variable Assign, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step To = AD Auth, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Rule = fallback, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Agent = /frontend/APP-AP_act_active_directory_auth_ag, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step From = AD Auth, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step To = Deny, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Rule = fallback, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "printx()" line: 347 Msg: Step Agent = /frontend/APP-AP_end_deny_ag, 0 seconds
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "close()" line: 209 Msg: 0 queued descriptors remain
bigip debug apmd[17408]: 01490000:7: queue.cpp func: "close()" line: 211 Msg: queue::close done
0
Comment made 10-Apr-2017 by AN 162

@ Stanislas Piron I figured it out... I changed HTTP_Request_DATA to following:

when HTTP_REQUEST_DATA {
 # Parse XML Data
 set xmluserdata [findstr [HTTP::payload] "<loginName>" 10 "</password>"]
 set xmluser [findstr $xmluserdata ">" 1 "</loginName>"]
 set xmlpw [findstr $xmluserdata "<password>" 10 end]
 }

Now I can see password variable being assigned. As I mentioned previously, /abc/session.svc is being called twice very first time has password but second time it include only username.. How I can run following condition to run only once:

if { ( [HTTP::uri] contains "/abc/session.svc")}
        {
        ACCESS::enable
        HTTP::header insert "clientless-mode" 1
        set apmsessionid [HTTP::cookie value MRHSession] 
            if  { [HTTP::cookie exists "MRHSession"]} {set apmstatus [ACCESS::session exists -state_allow $apmsessionid]} else {set apmstatus 0}
                if {!($apmstatus)} 
                {
                # Insert Clientless-mode header to start APM in clientless mode
                if { [catch {HTTP::header insert "clientless-mode" 1} ] } {log local0. "[IP::client_addr]:[TCP::client_port] : TCL error on HTTP header insert clientless-mode : URL : [HTTP::host][HTTP::path] - Headers : [HTTP::request]"}
                }
                if {([HTTP::method] eq "POST") }
                    {
                    set clength 0
                        if {[HTTP::header exists "Content-Length"] &amp;&amp; [HTTP::header Content-Length] &lt;= 1048576}
                        {
                        set clength [HTTP::header Content-Length]
                        } else { set clength 1048576 }
                        if { [info exists clength] &amp;&amp; $clength &gt; 0} { HTTP::collect $clength }
                    }
         } else { ACCESS::disable}

Thanks for your assistance

0
Comment made 10-Apr-2017 by Stanislas Piron 6257

Hi,

This part of my irule is there to follow user session:

  if { $PROFILE_RESTRICT_SINGLE_IP == 0 } {
        binary scan [md5 "$xmlpw"] H* clientless(hash)
    } else {
        binary scan [md5 "$xmlpw[TCP::client_addr]"] H* hash
    }
    set user_key "$xmluser.$hash"
    set cookie_list             [ ACCESS::user getsid $user_key ]
    if { [ llength $cookie_list ] != 0 } {
       set cookie [ ACCESS::user getkey [ lindex $cookie_list 0 ] ]
       if { $cookie != "" } {
          HTTP::cookie insert name MRHSession value $cookie
          set insert_mode 0
       }
    }

The goal is to keep an ID you can use for next requests (in my example, username.[hash of password and client IP address])

you can use the same method with only username and hash of IP address (not as secure as password hash)

0
Comment made 10-Apr-2017 by AN 162

I have following iRule as you suggested I removed ACCESS_SESSION_STARTED and following line from HTTP_REQUEST:

if { [catch {HTTP::header insert "clientless-mode" 1} ] } {log local0. "[IP::client_addr]:[TCP::client_port] : TCL error on HTTP header insert clientless-mode : URL : [HTTP::host][HTTP::path] - Headers : [HTTP::request]"}

when HTTP_REQUEST {
    switch [HTTP::method]
    {
        "COPY" -
        "MOVE"
        {
            # Replace Destination header with http if using SSL Offloading
            if { [HTTP::header Destination] starts_with "https" }
            {
                HTTP::header replace Destination [string map -nocase {https http} [HTTP::header value Destination]]
            }

            HTTP::disable
        }
        "MKCOL" -
        "PROPPATCH"
        {
            HTTP::disable
        }
    }

    if { ( [HTTP::uri] contains "/abc/session.svc")}
        {
        ACCESS::enable
        set apmsessionid [HTTP::cookie value MRHSession] 
            if  { [HTTP::cookie exists "MRHSession"]} {set apmstatus [ACCESS::session exists -state_allow $apmsessionid]} else {set apmstatus 0}
                if {!($apmstatus)} 
                {
                # Insert Clientless-mode header to start APM in clientless mode
                }
                if {([HTTP::method] eq "POST") }
                    {
                    set clength 0
                        if {[HTTP::header exists "Content-Length"] && [HTTP::header Content-Length] <= 1048576}
                        {
                        set clength [HTTP::header Content-Length]
                        } else { set clength 1048576 }
                        if { [info exists clength] && $clength > 0} { HTTP::collect $clength }
                    }
         } else { ACCESS::disable}
}

when HTTP_REQUEST_DATA {
   # Parse XML Data
    set xmluserdata [findstr [HTTP::payload] "<loginName>" 10 "</password>"]
    #set xmlpwtmp [findstr [HTTP::payload] "<password>" 10 "</password>"]
    set xmluser [findstr $xmluserdata ">" 1 "</loginName>"]
    set xmlpw [findstr $xmluserdata "<password>" 10 end]
    #unset xmlpwtmp
    if { $PROFILE_RESTRICT_SINGLE_IP == 0 } {
        binary scan [md5 "$xmlpw"] H* clientless(hash)
    } else {
        binary scan [md5 "$xmlpw[IP::client_addr]"] H* hash
    }
    set user_key "$xmluser.$hash"
    set cookie_list             [ ACCESS::user getsid $user_key ]
    if { [ llength $cookie_list ] != 0 } {
       set cookie [ ACCESS::user getkey [ lindex $cookie_list 0 ] ]
       if { $cookie != "" } {
          HTTP::cookie insert name MRHSession value $cookie
          set insert_mode 0
       }
    }
    if { $insert_mode } {
       HTTP::header insert "clientless-mode" 1
       HTTP::header insert "username" $xmluser
       HTTP::header insert "password" $xmlpw
       set clientless_mode 1
    }
}

when ACCESS_ACL_ALLOWED {
    set user [ACCESS::session data get session.logon.last.username]
    HTTP::header insert "login" $user
    HTTP::header remove "Authorization"
}

Do we still need ACCESS_ACL_ALLOWED ??

0
Comment made 10-Apr-2017 by AN 162

As soon as I assign above iRule I stop receiving APM Logs.. APM profile is not being called... I checked LTM logs and Found following:

    bigiperr tmm1[22893]: 01220001:3: TCL error: /frontend/App-iRule-modified-2 <HTTP_REQUEST_DATA> - can't read "PROFILE_RESTRICT_SINGLE_IP": no such variable     while executing "if { $PROFILE_RESTRICT_SINGLE_IP == 0 } {         binary scan [md5 "$xmlpw"] H* clientless(hash)     } else {         binary scan [md5 "$xmlpw[IP::cli..."
   bigiperr tmm[22893]: 01220001:3: TCL error: /frontend/App-iRule-modified-2 <HTTP_REQUEST_DATA> - can't read "PROFILE_RESTRICT_SINGLE_IP": no such variable     while executing "if { $PROFILE_RESTRICT_SINGLE_IP == 0 } {         binary scan [md5 "$xmlpw"] H* clientless(hash)     } else {         binary scan [md5 "$xmlpw[IP::cli..."

I am using version 12.1.1 Build 2.0.204 Hotfix HF2

0
Comment made 11-Apr-2017 by AN 162

@ Stanislas Piron Shouldn't we have variable PROFILE_RESTRICT_SINGLE_IP define some value before we call at if { $PROFILE_RESTRICT_SINGLE_IP == 0 }.

we have cokkie_list define before its IF condition set cookie_list [ ACCESS::user getsid $user_key ]

0