Forum Discussion

tub91's avatar
tub91
Icon for Cirrus rankCirrus
Mar 25, 2023
Solved

APM - Software Check Antivirus does not work on Linux platforms

Hi,
For the past few months we have configured a F5 bind mode for our Linux clients. Everything is working fine.

We would now like to add a Software check with our TrendMicro Antivirus version to verify device compliance.

We did some tests but it's not working. If instead we verify the presence of the antivirus on a Windows workstation it works correctly. Attached is the flow inserted on the APM side.

We've increased the verbosity of the APM logs to figure out what the problem might be but can't find any clues.

We see the following logs where we understand that the software check was successful and the installed antivirus version is identified but we get a deny.

 

Mar 24 18:01:56 <NameHostF5> notice apmd[6705]: 014902f7:5: /Common/VPN_LINUX:Common:93a2bb97:/Common/VPN_LINUX_act_av_software_check_ag: endpoint software detected (sdk=4.3.2568.0,type=av,id=200072,vendor_id=200107,version=20.0.0,state=,name=Trend Micro Deep Security Agent,vendor_name=Trend Micro, Inc.,db_signature=200073,db_version=,db_time=,last_scan=,engine_version=,missing_updates=).
Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490004:6: /Common/VPN_LINUX:Common:93a2bb97: Executed agent '/Common/VPN_LINUX_act_av_software_check_ag', return value 0 ('Execution Done')
Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ./AccessPolicyProcessor/SessionState.h: 'clearTempSessionAgentState()': 118: Agent did not initiated the scheduled agent
Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 662: Let's evaluate rules, total number of rules for this action=2
Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 668: Rule to evaluate = "expr {[mcget {session.check_software.last.av.result}] == 1}"
Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 668: Rule to evaluate = ""
Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 4, name = From, value = Antivirus
Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 5, name = To, value = Deny
Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 6, name = Rule, value = fallback
Mar 24 18:01:56 <NameHostF5> notice apmd[6705]: 01490005:5: /Common/VPN_LINUX:Common:93a2bb97: Following rule 'fallback' from item 'Antivirus' to ending 'Deny'

 


Can you help us understand where the problem is?

Thanks

  • Hi Tub91,

    Try using in the antivirus agent under 'status' unspecified, maybe it is a permission issue where the endpoint fails to get the status.
    As an extra input you can add the agent 'Linux check process' to make sure the AV process is up&run

     

3 Replies

  • Hi Tub91,

    Try using in the antivirus agent under 'status' unspecified, maybe it is a permission issue where the endpoint fails to get the status.
    As an extra input you can add the agent 'Linux check process' to make sure the AV process is up&run

     

  • Logs1

    Mar 24 18:01:48 <NameHostF5> notice tmm7[13835]: 01490506:5: /Common/VPN_LINUX:Common:93a2bb97: Received User-Agent header: Mozilla%2F5.0%20(X11%3B%20Ubuntu%3B%20Linux%20x86_64%3B%20rv%3A107.0)%20Gecko%2F20100101%20Firefox%2F107.0.
    Mar 24 18:01:48 <NameHostF5> notice tmm7[13835]: 01490500:5: /Common/VPN_LINUX:Common:93a2bb97: New session from client IP x.x.x.x (ST=Lombardia/CC=IT/C=EU) at VIP y.y.y.y Listener /Common/VPN_LINUX (Reputation=Unknown)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_accept()': 1640: process_accept: queueing 215
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1724: Request Received : 215
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 0, name = Profile, value = readFromSocket
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 168: bytes_received: 267, len: 267
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 190: First header received: GET /my.policy HTTP/1.1
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 463: HTTP Method received: GET
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 492: HTTP URI received: /my.policy
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 537: HTTP major version received: 1
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 538: HTTP minor version received: 1
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, client-session-id(32)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-key(24)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, profile-id(17)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, partition-id(6)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, traffic-id: 1
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-id(8)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, snapshot-id(32)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, cmp-pu: 7
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1749: start processing of the access policy. Request received: Session_ID = "93a2bb97",Profile_ID = "/Common/VPN_LINUX" Traffic-group Id = "1", Request_From = "", Clientless_Mode = "",No_Inspection_Host = "", CMP_Process_Unit = "7, mc = 0x2afac2a0b2f0"
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 1, name = Profile, value = searchProfileList
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: ::93a2bb97: AccessPolicyProcessor/AccessPolicyProcessor.cpp: '_initSession()': 661: access policy processing: 0
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 2, name = Profile, value = /Common/VPN_LINUX
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 662: Let's evaluate rules, total number of rules for this action=1
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 668: Rule to evaluate = ""
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 3, name = From, value = Start
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 4, name = To, value = Client OS
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 5, name = Rule, value = fallback
    Mar 24 18:01:48 <NameHostF5> info apmd[6705]: 01490006:6: /Common/VPN_LINUX:Common:93a2bb97: Following rule 'fallback' from item 'Start' to item 'Client OS'
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 662: Let's evaluate rules, total number of rules for this action=8
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 668: Rule to evaluate = "expr {[mcget {session.client.platform}] == "Linux"}"
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 603: variable "session.client.platform" was not found in the local cache for session "93a2bb97"
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 610: try to get it from MEMCACHED
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 632: variable found, let's add it to the local cache "session.client.platform"="Linux"(length=5)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 6, name = From, value = Client OS
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 7, name = To, value = Antivirus
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 8, name = Rule, value = Client OS Linux - Successfull
    Mar 24 18:01:48 <NameHostF5> info apmd[6705]: 01490006:6: /Common/VPN_LINUX:Common:93a2bb97: Following rule 'Client OS Linux - Successfull' from item 'Client OS' to item 'Antivirus'
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256495597312, step 9, name = Agent, value = /Common/VPN_LINUX_act_av_software_check_ag
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 603: variable "session.client.plugin" was not found in the local cache for session "93a2bb97"
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 610: try to get it from MEMCACHED
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 632: variable found, let's add it to the local cache "session.client.plugin"="0"(length=1)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 603: variable "session.client.activex" was not found in the local cache for session "93a2bb97"
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 610: try to get it from MEMCACHED
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 632: variable found, let's add it to the local cache "session.client.activex"="0"(length=1)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 603: variable "session.client.policy.use_browser_plugins" was not found in the local cache for session "93a2bb97"
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 610: try to get it from MEMCACHED
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 618: variable "session.client.policy.use_browser_plugins" for session "93a2bb97" was not found in MEMCACHED
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: AccessPolicyProcessor/AccessPolicy.cpp: 'updateISStatus()': 44: updateISStatus(awaiting_connection)
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1824: processing of access policy is done, result code=fffffff3
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'writeSessionVarToSessionDb()': 2439: syncing data with MEMCACHED
    Mar 24 18:01:48 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.policy.inspectionhost.status' set to 'awaiting_connection'
    Mar 24 18:01:48 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.policy.inspectionhost.timestamp' set to '1679677308'
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'setSessionInactive()': 1150: 93a2bb97: done with request processing
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'sendAccessPolicyResponse()': 2805: send 'redirect to EUIE' code, redirect URL="/apd_inspection_host_enter_page.eui"
    Mar 24 18:01:48 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1879:  ** done with the request processing **
    
    Mar 24 18:01:48 <NameHostF5> debug tmm5[13835]: 01490000: : Received request /my.status.eps
    Mar 24 18:01:48 <NameHostF5> debug tmm5[13835]: 01490000: 93a2bb97: Using https connection for status updates
    
    Mar 24 18:01:49 <NameHostF5> debug tmm5[13835]: 01490000: 93a2bb97: Sending chunk {"status": {"caption":"awaiting_connection","action":""  } }
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_accept()': 1640: process_accept: queueing 215
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1724: Request Received : 215
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256499808000, step 0, name = Profile, value = readFromSocket
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 168: bytes_received: 841, len: 841
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 190: First header received: POST /my.policy_host HTTP/1.1
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 463: HTTP Method received: POST
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 492: HTTP URI received: /my.policy_host
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 537: HTTP major version received: 1
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 538: HTTP minor version received: 1
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, content-length: 516
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, request-from(15)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, client-session-id(32)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-key(24)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, profile-id(17)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, partition-id(6)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, traffic-id: 1
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-id(8)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, snapshot-id(32)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, cmp-pu: 7
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parsePostParam()': 628: Param received, version(3)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parsePostParam()': 628: Param received, client_data(492)
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1749: start processing of the access policy. Request received: Session_ID = "93a2bb97",Profile_ID = "/Common/VPN_LINUX" Traffic-group Id = "1", Request_From = "inspection_host", Clientless_Mode = "",No_Inspection_Host = "", CMP_Process_Unit = "7, mc = 0x2afac2e0f2f0"
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256499808000, step 1, name = Profile, value = searchProfileList
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 603: variable "session.client.hostname" was not found in the local cache for session "93a2bb97"
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 610: try to get it from MEMCACHED
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 618: variable "session.client.hostname" for session "93a2bb97" was not found in MEMCACHED
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'set_client_data()': 1963: Set session.client.hostname: P999B3075XL
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256499808000, step 2, name = Profile, value = /Common/VPN_LINUX
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256499808000, step 3, name = Agent, value = /Common/VPN_LINUX_act_av_software_check_ag
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: AccessPolicyProcessor/AccessPolicy.cpp: 'updateISStatus()': 44: updateISStatus(agent_endpoint_check_software)
    Mar 24 18:01:49 <NameHostF5> info apmd[6705]: 01490004:6: /Common/VPN_LINUX:Common:93a2bb97: Executed agent '/Common/VPN_LINUX_act_av_software_check_ag', return value 3 ('Need User input')
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: '_executeOneAgent()': 242: user input is required
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1824: processing of access policy is done, result code=fffffff3
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'writeSessionVarToSessionDb()': 2439: syncing data with MEMCACHED
    Mar 24 18:01:49 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.client.hostname' set to 'P999B3075XL'
    Mar 24 18:01:49 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.policy.inspectionhost.status' set to 'agent_endpoint_check_software'
    Mar 24 18:01:49 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.policy.inspectionhost.timestamp' set to '1679677309'
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'setSessionInactive()': 1150: 93a2bb97: done with request processing
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'sendAccessPolicyResponse()': 2805: send 'redirect to EUIE' code, redirect URL="/agent_endpoint_linux_check_software_form.eui?at=av&an=%2FCommon%2FVPN%5FLINUX%5Fact%5Fav%5Fsoftware%5Fcheck%5Fag"
    Mar 24 18:01:49 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1879:  ** done with the request processing **
    Mar 24 18:01:49 <NameHostF5> debug tmm5[13835]: 01490000: 93a2bb97: Sending chunk {"status": {"caption":"agent_endpoint_check_software","action":""  } }
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_accept()': 1640: process_accept: queueing 215
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1724: Request Received : 215
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 0, name = Profile, value = readFromSocket
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 168: bytes_received: 2278, len: 2278
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 190: First header received: POST /my.policy_host HTTP/1.1
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 463: HTTP Method received: POST
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 492: HTTP URI received: /my.policy_host
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 537: HTTP major version received: 1
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 538: HTTP minor version received: 1
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, content-length: 1952
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, request-from(15)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, client-session-id(32)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-key(24)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, profile-id(17)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, partition-id(6)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, traffic-id: 1
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-id(8)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, snapshot-id(32)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, cmp-pu: 7
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parsePostParam()': 628: Param received, version(3)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parsePostParam()': 628: Param received, client_data(1928)

     

  • Logs2

    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1749: start processing of the access policy. Request received: Session_ID = "93a2bb97",Profile_ID = "/Common/VPN_LINUX" Traffic-group Id = "1", Request_From = "inspection_host", Clientless_Mode = "",No_Inspection_Host = "", CMP_Process_Unit = "7, mc = 0x2afac2c0d2f0"
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 1, name = Profile, value = searchProfileList
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 2, name = Profile, value = /Common/VPN_LINUX
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 3, name = Agent, value = /Common/VPN_LINUX_act_av_software_check_ag
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: AccessPolicyProcessor/AccessPolicy.cpp: 'updateISStatus()': 44: updateISStatus(agent_endpoint_check_software)
    Mar 24 18:01:56 <NameHostF5> notice apmd[6705]: 014902f7:5: /Common/VPN_LINUX:Common:93a2bb97:/Common/VPN_LINUX_act_av_software_check_ag: endpoint software detected (sdk=4.3.2568.0,type=av,id=200072,vendor_id=200107,version=20.0.0,state=,name=Trend Micro Deep Security Agent,vendor_name=Trend Micro, Inc.,db_signature=200073,db_version=,db_time=,last_scan=,engine_version=,missing_updates=).
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490004:6: /Common/VPN_LINUX:Common:93a2bb97: Executed agent '/Common/VPN_LINUX_act_av_software_check_ag', return value 0 ('Execution Done')
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ./AccessPolicyProcessor/SessionState.h: 'clearTempSessionAgentState()': 118: Agent did not initiated the scheduled agent
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 662: Let's evaluate rules, total number of rules for this action=2
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 668: Rule to evaluate = "expr {[mcget {session.check_software.last.av.result}] == 1}"
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 668: Rule to evaluate = ""
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 4, name = From, value = Antivirus
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 5, name = To, value = Deny
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 6, name = Rule, value = fallback
    Mar 24 18:01:56 <NameHostF5> notice apmd[6705]: 01490005:5: /Common/VPN_LINUX:Common:93a2bb97: Following rule 'fallback' from item 'Antivirus' to ending 'Deny'
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256497702656, step 7, name = Agent, value = /Common/VPN_LINUX_end_deny_ag
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: AccessPolicyProcessor/AccessPolicy.cpp: 'updateISStatus()': 44: updateISStatus(done)
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1824: processing of access policy is done, result code=fffffff3
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'writeSessionVarToSessionDb()': 2439: syncing data with MEMCACHED
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.count' set to '1'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.error' set to '0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.item_1.errors' set to 'Failed to get 'state'. code: -22 method: 1000 define: 'WAAPI_ERROR_ACCESS_DENIED' description: 'Defines an error when the access is denied for the invocation call requested.' Failed to get 'last_scan'. code: -22 method: 1004 define: 'WAAPI_ERROR_ACCESS_DENIED' description: 'Defines an error when the access is denied for the invocation call requested.' '
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.item_1.id' set to '200072'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.item_1.name' set to 'Trend Micro Deep Security Agent'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.item_1.signature' set to '200073'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.item_1.vendor_id' set to '200107'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.item_1.vendor_name' set to 'Trend Micro, Inc.'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.item_1.version' set to '20.0.0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.result' set to '0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.sdk' set to '4.3.2568.0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software./Common/VPN_LINUX_act_av_software_check_ag.av.state' set to '0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.count' set to '1'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.error' set to '0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.item_1.errors' set to 'Failed to get 'state'. code: -22 method: 1000 define: 'WAAPI_ERROR_ACCESS_DENIED' description: 'Defines an error when the access is denied for the invocation call requested.' Failed to get 'last_scan'. code: -22 method: 1004 define: 'WAAPI_ERROR_ACCESS_DENIED' description: 'Defines an error when the access is denied for the invocation call requested.' '
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.item_1.id' set to '200072'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.item_1.name' set to 'Trend Micro Deep Security Agent'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.item_1.signature' set to '200073'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.item_1.vendor_id' set to '200107'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.item_1.vendor_name' set to 'Trend Micro, Inc.'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.item_1.version' set to '20.0.0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.result' set to '0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.sdk' set to '4.3.2568.0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.check_software.last.av.state' set to '0'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.policy.inspectionhost.status' set to 'done'
    Mar 24 18:01:56 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.policy.inspectionhost.timestamp' set to '1679677316'
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'setSessionInactive()': 1150: 93a2bb97: done with request processing
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'sendAccessPolicyResponse()': 2805: send 'redirect to EUIE' code, redirect URL="/apd_inspection_host_exit_page.eui"
    Mar 24 18:01:56 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1879:  ** done with the request processing **
    Mar 24 18:01:56 <NameHostF5> debug tmm5[13835]: 01490000: 93a2bb97: Sending chunk {"status": {"caption":"done","action":""  } }
    Mar 24 18:01:56 <NameHostF5> debug tmm5[13835]: 01490000: 93a2bb97: Status check closed
    
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_accept()': 1640: process_accept: queueing 215
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1724: Request Received : 215
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256496649984, step 0, name = Profile, value = readFromSocket
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 168: bytes_received: 276, len: 276
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'readFromSocket()': 190: First header received: GET /my.policy?p=707245 HTTP/1.1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 463: HTTP Method received: GET
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 492: HTTP URI received: /my.policy?p=707245
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 537: HTTP major version received: 1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpRequestHeader()': 538: HTTP minor version received: 1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, client-session-id(32)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-key(24)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, profile-id(17)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, partition-id(6)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, traffic-id: 1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, session-id(8)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 585: Header received, snapshot-id(32)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parseHttpGenericHeader()': 582: Header received, cmp-pu: 7
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: HTTPParser.cpp: 'parsePostParam()': 628: Param received, p(6)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ApmD.cpp: 'process_apd_request()': 1749: start processing of the access policy. Request received: Session_ID = "93a2bb97",Profile_ID = "/Common/VPN_LINUX" Traffic-group Id = "1", Request_From = "", Clientless_Mode = "",No_Inspection_Host = "", CMP_Process_Unit = "7, mc = 0x2afac2b0c2f0"
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256496649984, step 1, name = Profile, value = searchProfileList
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256496649984, step 2, name = Profile, value = /Common/VPN_LINUX
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: queue.cpp: 'setMarker()': 387: queue::setMarker: thread id 47256496649984, step 3, name = Agent, value = /Common/VPN_LINUX_end_deny_ag
    Mar 24 18:01:57 <NameHostF5> notice apmd[6705]: 01490102:5: /Common/VPN_LINUX:Common:93a2bb97: Access policy result: Logon_Deny
    Mar 24 18:01:57 <NameHostF5> info apmd[6705]: 01490004:6: /Common/VPN_LINUX:Common:93a2bb97: Executed agent '/Common/VPN_LINUX_end_deny_ag', return value 0 ('Execution Done')
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: (null):Common:00000000: ./AccessPolicyProcessor/SessionState.h: 'clearTempSessionAgentState()': 118: Agent did not initiated the scheduled agent
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 662: Let's evaluate rules, total number of rules for this action=0
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 759: We reached a terminator - completely done with Access Policy for this session
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 778: ClientData version string is empty, fetching browscap
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 603: variable "session.client.browscap_info" was not found in the local cache for session "93a2bb97"
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 610: try to get it from MEMCACHED
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ./AccessPolicyProcessor/Session.h: 'getSessionVar()': 632: variable found, let's add it to the local cache "session.client.browscap_info"="uimode=0&ctype=Mozilla&cversion=1&cjs=1&cactivex=0&cplugin=0&cplatform=Linux&cpu=x64&ccustom_protocol=1"(length=103)
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 782: Browscap is "uimode=0&ctype=Mozilla&cversion=1&cjs=1&cactivex=0&cplugin=0&cplatform=Linux&cpu=x64&ccustom_protocol=1"
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element cactivex = 0
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element ccustom_protocol = 1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element cjs = 1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element cplatform = Linux
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element cplugin = 0
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element cpu = x64
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element ctype = Mozilla
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element cversion = 1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: AccessPolicyProcessor/AccessPolicy.cpp: 'execute()': 788: Browscap element uimode = 0
    Mar 24 18:01:57 <NameHostF5> notice apmd[6705]: 01490248:5: /Common/VPN_LINUX:Common:93a2bb97: Received client info - Hostname: P999B3075XL Type: Mozilla Version: 1 Platform: Linux CPU: x64 UI Mode: Full Javascript Support: 1 ActiveX Support: 0 Plugin Support: 0
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1824: processing of access policy is done, result code=fffffff1
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'writeSessionVarToSessionDb()': 2439: syncing data with MEMCACHED
    Mar 24 18:01:57 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.logon.page.errorcode' set to '1'
    Mar 24 18:01:57 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.logout.page.customization.group' set to '/Common/VPN_LINUX_end_deny_ag'
    Mar 24 18:01:57 <NameHostF5> info apmd[6705]: 01490007:6: /Common/VPN_LINUX:Common:93a2bb97: Session variable 'session.policy.result' set to 'deny'
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'sendAccessPolicyResponse()': 2760: DONE WITH ACCESS POLICY - send 'we are done with access policy for this session' code
    Mar 24 18:01:57 <NameHostF5> debug apmd[6705]: 01490266:7: /Common/VPN_LINUX:Common:93a2bb97: ApmD.cpp: 'process_apd_request()': 1879:  ** done with the request processing **
    Mar 24 18:01:58 <NameHostF5> notice tmm7[13835]: 01490567:5: /Common/VPN_LINUX:Common:93a2bb97: Session deleted (policy_result).