Forum Discussion
tub91
Cirrus
CirrusAPM - 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
- MMarco_77
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 
tub91Logs1
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)- tub91
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).