Hi, i have a xg firewall with AD SSO. the users logged into the firewall are continuosly logged out after 20 minutes 2016-04-11 08:44:32 Firewall Authentication SUCCESSFUL dario.zzzz@xxxx.local 172.16.29.115 CTA N/A User dario.zzzz@xxxx.local was logged out of firewall 17703 2016-04-11 08:28:48 Firewall Authentication SUCCESSFUL dario.zzzz@xxxx.local 172.16.29.115 CTA AD User dario.zzzz@xxxx.local of group Proxy_All logged in successfully to Firewall through AD authentication mechanism from 172.16.29.115 17701 I have followed all the guides but I can not fix it thanks Emil

Hi Emil, So just looking through the log you posted I can see at 14:31:13 the Collector as part of the log off detection performed a WMI lookup on 172.16.0.22 and receieved a response that the logged on user was "administrator" DEBUG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: connecting to WMI Namespace '\\172.16.0.22\root\cimv2' DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_threadproc: Executing Function 0x455880 MSG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: username:administrator This resulted in the user emil.martini being logged off at 14:31:14. INFO [0x5ec] 12/04/2016 14:31:14 : remove_user_from_de_repositry: user emil.martini with ip 172.16.0.22 removed from DE MSG [0x5ec] 12/04/2016 14:31:14 : wrkstpoll_handle_logoff_req: user 'btzit.local\emil.martini' removed The indication is that there is a authenticated process executing on the workstation that uses the "administrator" account, when this executes windows reports the last logged on user as "administrator" Assuming that the administrator account is not used as an account in the user space, the simplest solution would be to configure the STAS environment to ignore (not track) "administrator" log on events. This can be performed ia the "Exclusion List" Tab in the STAS Client. Note: using the general "administrator" for dual purposes (i.e. as a user and to run services) can be problematic, I would suggest investigating the option of changing the context for the service/application currently running under "administrator" to a dedicated services account which can be excluded in its place.

Hi All, Could you change the settings as per the snapshot below and check if this would resolve your issue?

Hi, @ EmilMartini After hours of testing i see the users hav been logged out cuz the NTLM. The users after make the SSO with STAS they are working fine and after some time they are getting off the session. Try to put the NTLM off from Administration > Device Access > NTLM (LAN ZONE). let me know. Thanks. @ GabrieleD @ Jiri Hadamek @ Bill Roland

I've spend so many hours with this problem. But now i think i found the solution. The problem was the "Logoff Detection" (WMI) of the DC. The query was blocked by the client firewall. I created an GPO to activate the "Windows Management Intstrumentation (WMI-In)" firewall rule on all clients. And now everything is working fine. P.S. you can test the WMI rule with following command. wmic /node:x.x.x.x computersystem get username

This discussion has been locked.

You can no longer post new replies to this discussion. If you have a question you can start a new discussion

SSO AD User logout continuously

EmilMartini over 9 years ago

Hi,

i have a xg firewall with AD SSO.

the users logged into the firewall are continuosly logged out after 20 minutes

2016-04-11 08:44:32	Firewall Authentication	SUCCESSFUL	dario.zzzz@xxxx.local	172.16.29.115	CTA	N/A	User dario.zzzz@xxxx.local was logged out of firewall	17703
2016-04-11 08:28:48	Firewall Authentication	SUCCESSFUL	dario.zzzz@xxxx.local	172.16.29.115	CTA	AD	User dario.zzzz@xxxx.local of group Proxy_All logged in successfully to Firewall through AD authentication mechanism from 172.16.29.115	17701

I have followed all the guides but I can not fix it

thanks

Emil

This thread was automatically locked due to age.

Parents

0 Leon.Friend over 9 years ago

Hi Emil,

This sounds like you are probably being caught out by one of two things I suspect it is probably the first option.

- logon of alternate user account, STAS tracks singular user activity. If an authentication event happens with an alternate user account that will log the existing user out. (You can exclude specific user accounts such as those used by services from being tracked, if you have a terminal server you should also exclude that IP address)

- the log off detection being performed by the STAS collector. This mechanism will depending on what you have configured, however the collector will poll the workstation to check who is logged in, if the connection fails or it picks up an alternate username then the original user will be logged out. (You might need to check that there is nothing such as Windows Firewall blocking the connection by the collector)

While you provided an example log entry for the logon and log off for the user, can you check if there is another authentication event for the same IP address at the same time as the log off.
Cancel
Vote Up 0 Vote Down

Cancel
0 EmilMartini over 9 years ago in reply to Leon.Friend

HI Leon,

I post a STAS log from test lab, error is the same in production enviroment.

From the workstation with ip 172.16.0.22 the user's session emil.martini was disconnected while the user is still working, there aren't other services running.

Thanks a lot

Emil

STAS LOG:

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_select_expired_userinfo: select query: SELECT * FROM UserInfo WHERE flags==1 AND rowid>=0 AND expire_time<=1460464273 ORDER BY rowid ASC LIMIT 5;

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_select_expired_userinfo: --- SELECTED USER INFO FOR LOGOFF DETECTION ---

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: RowID: 52

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: User: emil.martini

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: Domain: btzit.local

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: Group: NULL

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: SourceDC: NULL

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: WrkstName: NULL

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: WrkstIP: 172.16.0.22

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: CreateTime: 1460463336

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: ExpireTime: 1460463940

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: LogonType: 0x2

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: UserSidType: 0x0

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_select_expired_userinfo: -----------------------------------------------

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_select_expired_userinfo: --- SELECTED USER INFO FOR LOGOFF DETECTION ---

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: RowID: 55

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: User: Administrator

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: Domain: btzit.local

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: Group: NULL

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: SourceDC: NULL

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: WrkstName: NULL

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: WrkstIP: 172.16.0.230

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: CreateTime: 1460463663

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: ExpireTime: 1460464268

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: LogonType: 0x2

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_log_userinfo: UserSidType: 0x0

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_select_expired_userinfo: -----------------------------------------------

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_select_expired_userinfo: 2 records selected

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_update_userinfo: update query: UPDATE UserInfo SET flags='2',expire_time='1460463940' WHERE rowid=='52';

userdb_exec_query: Query:'U'

userdb_exec_query: Query Executed, ret:101

DEBUG [0x5bc] 12/04/2016 14:31:13 : userdb_update_userinfo: update query: UPDATE UserInfo SET flags='2',expire_time='1460464268' WHERE rowid=='55';

userdb_exec_query: Query:'U'

userdb_exec_query: Query Executed, ret:101

DEBUG [0x5bc] 12/04/2016 14:31:13 : logoff_detector: UserInfo Selected: 2

DEBUG [0x5bc] 12/04/2016 14:31:13 : logoff_detector: USER: btzit.local\emil.martini RowID: 52

DEBUG [0x5bc] 12/04/2016 14:31:13 : threadpool_run: Submitting Function 0x455880

DEBUG [0x5bc] 12/04/2016 14:31:13 : threadpool_run: adding function at tail

DEBUG [0x5bc] 12/04/2016 14:31:13 : list_add_tail: first element added

DEBUG [0x5bc] 12/04/2016 14:31:13 : threadpool_run: get free thread: ThreadID: 0x5ec

DEBUG [0x5bc] 12/04/2016 14:31:13 : logoff_detector: callback submitted

DEBUG [0x5bc] 12/04/2016 14:31:13 : logoff_detector: USER: btzit.local\Administrator RowID: 55

DEBUG [0x5bc] 12/04/2016 14:31:13 : threadpool_run: Submitting Function 0x455880

DEBUG [0x5bc] 12/04/2016 14:31:13 : threadpool_run: adding function at tail

DEBUG [0x5bc] 12/04/2016 14:31:13 : threadpool_run: get free thread: ThreadID: 0x660

DEBUG [0x5ec] 12/04/2016 14:31:13 : threadpool_threadproc: New Function added

DEBUG [0x5ec] 12/04/2016 14:31:13 : threadpool_get_threadproc: Function 0x455880

DEBUG [0x5bc] 12/04/2016 14:31:13 : logoff_detector: callback submitted

DEBUG [0x5ec] 12/04/2016 14:31:13 : threadpool_threadproc: Executing Function 0x455880

DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_threadproc: New Function added

DEBUG [0x660] 12/04/2016 14:31:13 : list_remove_head: last element removed

DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_get_threadproc: Function 0x455880

DEBUG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: connecting to WMI Namespace '\\172.16.0.22\root\cimv2'

DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_threadproc: Executing Function 0x455880

MSG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: username:administrator

DEBUG [0x660] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: connecting to WMI Namespace '\\172.16.0.230\root\cimv2'

MSG [0x660] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: username:administrator

DEBUG [0x660] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: connecting to Local Namespace....

DEBUG [0x660] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: Success - Connected to WMI Namespace: \\172.16.0.230\root\cimv2

ERROR [0x660] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: Success - Proxy Blanket Security Settings
DEBUG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: Success - Connected to WMI Namespace: \\172.16.0.22\root\cimv2

ERROR [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: Success - Proxy Blanket Security Settings
ERROR [0x660] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: Success - WMI Query for: \\172.16.0.230\root\cimv2

DEBUG [0x660] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: no loggedin user found

MSG [0x660] 12/04/2016 14:31:13 : wrkstpoll_handle_logoff_req: Request received from Logoff Detector

DEBUG [0x660] 12/04/2016 14:31:13 : userdb_delete_userinfo: delete query: DELETE FROM UserInfo WHERE user=='Administrator' AND domain=='btzit.local' AND wrkst_ip=='172.16.0.230';

userdb_exec_query: Query:'D'

ERROR [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: WMI Query 'SELECT UserName FROM Win32_ComputerSystem' failed: 0x80041003

MSG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_handle_logoff_req: Request received from Logoff Detector

DEBUG [0x5ec] 12/04/2016 14:31:13 : userdb_delete_userinfo: delete query: DELETE FROM UserInfo WHERE user=='emil.martini' AND domain=='btzit.local' AND wrkst_ip=='172.16.0.22';

userdb_exec_query: Query Executed, ret:101

userdb_exec_query: Query:'D'

INFO [0x660] 12/04/2016 14:31:13 : remove_user_from_de_repositry: user Administrator with ip 172.16.0.230 removed from DE

MSG [0x660] 12/04/2016 14:31:13 : wrkstpoll_handle_logoff_req: user 'btzit.local\Administrator' removed

DEBUG [0x660] 12/04/2016 14:31:13 : list_add_tail: first element added

DEBUG [0x660] 12/04/2016 14:31:13 : wrkstpoll_handle_logoff_req: user's logout request enqueued to CR Update Queue

DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_finishnotify: Thread ID: 0x660

DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_finishnotify: Reset Event

ERROR [0x550] 12/04/2016 14:31:13 : USERINFO WAITING INFINITE
DEBUG [0x550] 12/04/2016 14:31:13 : list_remove_head: last element removed

MSG [0x550] 12/04/2016 14:31:13 : SSOclient_thread: got userinfo: USER: btzit.local\Administrator <-> Flags: 4

DEBUG [0x550] 12/04/2016 14:31:13 : SSOclient_filter_CR_subnet: Entering filter function

DEBUG [0x550] 12/04/2016 14:31:13 : SSOclient_filter_CR_subnet: authnet not specified, send reqiest to CR

ERROR [0x550] 12/04/2016 14:31:13 : SSOclient_update_CR: domain name is there with length 11 , btzit.local

ERROR [0x550] 12/04/2016 14:31:13 : USERNAME Administrator Length 14

ERROR [0x550] 12/04/2016 14:31:13 : WORKSTN IP 172.16.0.230 Length 13

ERROR [0x550] 12/04/2016 14:31:13 : DOMAIN btzit.local Length 12

ERROR [0x550] 12/04/2016 14:31:13 : SSOclient : PACKET SIZE 285 㠲5
DEBUG [0x550] 12/04/2016 14:31:13 : net_send: bytes sent: 285

DEBUG [0x550] 12/04/2016 14:31:13 : net_send: full packet sent

MSG [0x550] 12/04/2016 14:31:13 : SSOclient_thread: Logon/Logout Update sent to: 172.16.0.254:0

ERROR [0x550] 12/04/2016 14:31:13 : GETTING (USERINFO) FROM QUEUE
DEBUG [0x550] 12/04/2016 14:31:13 : list_remove_head: list is Empty

userdb_exec_query: Query Executed, ret:101

INFO [0x5ec] 12/04/2016 14:31:14 : remove_user_from_de_repositry: user emil.martini with ip 172.16.0.22 removed from DE

MSG [0x5ec] 12/04/2016 14:31:14 : wrkstpoll_handle_logoff_req: user 'btzit.local\emil.martini' removed

DEBUG [0x5ec] 12/04/2016 14:31:14 : list_add_tail: first element added

DEBUG [0x5ec] 12/04/2016 14:31:14 : wrkstpoll_handle_logoff_req: user's logout request enqueued to CR Update Queue

DEBUG [0x5ec] 12/04/2016 14:31:14 : threadpool_finishnotify: Thread ID: 0x5ec

DEBUG [0x5ec] 12/04/2016 14:31:14 : threadpool_finishnotify: Reset Event

ERROR [0x550] 12/04/2016 14:31:14 : USERINFO WAITING INFINITE
DEBUG [0x550] 12/04/2016 14:31:14 : list_remove_head: last element removed

MSG [0x550] 12/04/2016 14:31:14 : SSOclient_thread: got userinfo: USER: btzit.local\emil.martini <-> Flags: 4

DEBUG [0x550] 12/04/2016 14:31:14 : SSOclient_filter_CR_subnet: Entering filter function

DEBUG [0x550] 12/04/2016 14:31:14 : SSOclient_filter_CR_subnet: authnet not specified, send reqiest to CR

ERROR [0x550] 12/04/2016 14:31:14 : SSOclient_update_CR: domain name is there with length 11 , btzit.local

ERROR [0x550] 12/04/2016 14:31:14 : USERNAME emil.martini Length 13

ERROR [0x550] 12/04/2016 14:31:14 : WORKSTN IP 172.16.0.22 Length 12

ERROR [0x550] 12/04/2016 14:31:14 : DOMAIN btzit.local Length 12

ERROR [0x550] 12/04/2016 14:31:14 : SSOclient : PACKET SIZE 273 㜲3
DEBUG [0x550] 12/04/2016 14:31:14 : net_send: bytes sent: 273

DEBUG [0x550] 12/04/2016 14:31:14 : net_send: full packet sent

MSG [0x550] 12/04/2016 14:31:14 : SSOclient_thread: Logon/Logout Update sent to: 172.16.0.254:0

ERROR [0x550] 12/04/2016 14:31:14 : GETTING (USERINFO) FROM QUEUE
DEBUG [0x550] 12/04/2016 14:31:14 : list_remove_head: list is Empty

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: received event log notification

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: got security event: ID: 4768 <-> Type: 8

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: got Kerberos authentication event

MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: UserName: Administrator

MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: DomainName: BTZIT.LOCAL

MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: IPv6 WorkstationIP: :

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: localhost ip given from AD(127.0.0.1)
DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: finding interface with internet traffic
DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: interface found with ip 1
MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: IPv4 WorkstationIP: 172.16.0.230

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: Event ID: 4768

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: EventType: AuditSuccess

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: CreateTime: 1460464273

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: ExpireTime: 1460464878

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: LogonType: 2

DEBUG [0x5f0] 12/04/2016 14:31:14 : threadpool_run: Submitting Function 0x40a7e0

DEBUG [0x5f0] 12/04/2016 14:31:14 : threadpool_run: adding function at tail

DEBUG [0x5f0] 12/04/2016 14:31:14 : list_add_tail: first element added

DEBUG [0x5f0] 12/04/2016 14:31:14 : threadpool_run: get free thread: ThreadID: 0x5ec

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_enqueue_userinfo: callback submitted

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: userinfo enqueued to dca processor

DEBUG [0x5ec] 12/04/2016 14:31:14 : threadpool_threadproc: New Function added

DEBUG [0x5ec] 12/04/2016 14:31:14 : list_remove_head: last element removed

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: got security event: ID: 4769 <-> Type: 8

DEBUG [0x5ec] 12/04/2016 14:31:14 : threadpool_get_threadproc: Function 0x40a7e0

DEBUG [0x5ec] 12/04/2016 14:31:14 : threadpool_threadproc: Executing Function 0x40a7e0

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: got security event: ID: 4768 <-> Type: 8

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: got Kerberos authentication event

DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_log_userinfo: User: Administrator

MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: UserName: Administrator

DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_log_userinfo: Domain: btzit.local

MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: DomainName: BTZIT.LOCAL

DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_log_userinfo: WrkstIP: 172.16.0.230

MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: IPv6 WorkstationIP: :

DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_log_userinfo: CreateTime: 1460464273

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: localhost ip given from AD(127.0.0.1)
DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_log_userinfo: ExpireTime: 1460464878

DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_log_userinfo: LogonType: 2

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: finding interface with internet traffic
DEBUG [0x5ec] 12/04/2016 14:31:14 : Adding user info to db and Sophos

DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_filter_by_username

DEBUG [0x5ec] 12/04/2016 14:31:14 : userdb_handle_duplicate_userinfo: select query: SELECT * FROM UserInfo WHERE wrkst_ip=='172.16.0.230';

DEBUG [0x5ec] 12/04/2016 14:31:14 : userdb_insert_userinfo: no matching userinfo found

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: interface found with ip 1
MSG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_kerberos: IPv4 WorkstationIP: 172.16.0.230

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: Event ID: 4768

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: EventType: AuditSuccess

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: CreateTime: 1460464273

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: ExpireTime: 1460464878

DEBUG [0x5f0] 12/04/2016 14:31:14 : init_userinfo_common: LogonType: 2

DEBUG [0x5f0] 12/04/2016 14:31:14 : threadpool_run: Submitting Function 0x40a7e0

DEBUG [0x5f0] 12/04/2016 14:31:14 : threadpool_run: adding function at tail

DEBUG [0x5f0] 12/04/2016 14:31:14 : list_add_tail: first element added

DEBUG [0x5f0] 12/04/2016 14:31:14 : threadpool_run: get free thread: ThreadID: 0x660

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_enqueue_userinfo: callback submitted

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: userinfo enqueued to dca processor

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: got security event: ID: 4769 <-> Type: 8

DEBUG [0x660] 12/04/2016 14:31:14 : threadpool_threadproc: New Function added

DEBUG [0x660] 12/04/2016 14:31:14 : list_remove_head: last element removed

DEBUG [0x660] 12/04/2016 14:31:14 : threadpool_get_threadproc: Function 0x40a7e0

DEBUG [0x660] 12/04/2016 14:31:14 : threadpool_threadproc: Executing Function 0x40a7e0

DEBUG [0x660] 12/04/2016 14:31:14 : dca_log_userinfo: User: Administrator

DEBUG [0x660] 12/04/2016 14:31:14 : dca_log_userinfo: Domain: btzit.local

DEBUG [0x660] 12/04/2016 14:31:14 : dca_log_userinfo: WrkstIP: 172.16.0.230

DEBUG [0x5f0] 12/04/2016 14:31:14 : dca_eventlog: waiting for event log notification

DEBUG [0x660] 12/04/2016 14:31:14 : dca_log_userinfo: CreateTime: 1460464273

DEBUG [0x660] 12/04/2016 14:31:14 : dca_log_userinfo: ExpireTime: 1460464878

DEBUG [0x660] 12/04/2016 14:31:14 : dca_log_userinfo: LogonType: 2

DEBUG [0x660] 12/04/2016 14:31:14 : Adding user info to db and Sophos

DEBUG [0x660] 12/04/2016 14:31:14 : dca_filter_by_username

DEBUG [0x5ec] 12/04/2016 14:31:14 : userdb_insert_userinfo: UserInfo Successfully Inserted

DEBUG [0x660] 12/04/2016 14:31:14 : userdb_handle_duplicate_userinfo: select query: SELECT * FROM UserInfo WHERE wrkst_ip=='172.16.0.230';

INFO [0x5ec] 12/04/2016 14:31:14 : add_user_to_de_repositry: user Administrator with ip 172.16.0.230 and expiretime 〳ㄵ㌲㐴㌬㐱㌵㠲㜱6 added to DE

DEBUG [0x5ec] 12/04/2016 14:31:14 : list_add_tail: first element added

DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_insert_userinfo_db: userinfo enqueued in CR Update Queue

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: CreateTime: 1460464273

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: ExpireTime: 1460464878

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: Flags: 0

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: LogonType: 2

DEBUG [0x660] 12/04/2016 14:31:14 : userdb_handle_duplicate_userinfo: User 'btzit.local\Administrator' found on '172.16.0.230'

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: Offset: 0; User: Administrator

DEBUG [0x660] 12/04/2016 14:31:14 : userdb_handle_duplicate_userinfo: userinfo matched

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: Offset: 28; WrkstIP: 172.16.0.230

DEBUG [0x660] 12/04/2016 14:31:14 : userdb_insert_userinfo: matching userinfo found

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: Offset: 54; Domain: btzit.local

ERROR [0x550] 12/04/2016 14:31:14 : USERINFO WAITING INFINITE
DEBUG [0x5ec] 12/04/2016 14:31:14 : crypto_encrypt_data: data encrypted; ciphertext len: 118

DEBUG [0x550] 12/04/2016 14:31:14 : list_remove_head: last element removed

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: Sending DATA Header

MSG [0x550] 12/04/2016 14:31:14 : SSOclient_thread: got userinfo: USER: btzit.local\Administrator <-> Flags: 5

DEBUG [0x550] 12/04/2016 14:31:14 : SSOclient_filter_CR_subnet: Entering filter function

DEBUG [0x550] 12/04/2016 14:31:14 : SSOclient_filter_CR_subnet: authnet not specified, send reqiest to CR

ERROR [0x550] 12/04/2016 14:31:14 : SSOclient_update_CR: domain name is there with length 11 , btzit.local

ERROR [0x550] 12/04/2016 14:31:14 : USERNAME Administrator Length 14

DEBUG [0x5ec] 12/04/2016 14:31:14 : net_send: bytes sent: 12

DEBUG [0x5ec] 12/04/2016 14:31:14 : net_send: full packet sent

ERROR [0x550] 12/04/2016 14:31:14 : WORKSTN IP 172.16.0.230 Length 13

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: DATA Header Sent

ERROR [0x550] 12/04/2016 14:31:14 : DOMAIN btzit.local Length 12

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: Sending DATA

DEBUG [0x5ec] 12/04/2016 14:31:14 : net_send: bytes sent: 118

DEBUG [0x5ec] 12/04/2016 14:31:14 : net_send: full packet sent

DEBUG [0x5ec] 12/04/2016 14:31:14 : dcaclient_send_data: DATA Sent

ERROR [0x550] 12/04/2016 14:31:14 : SSOclient : PACKET SIZE 285 㠲5
DEBUG [0x5ec] 12/04/2016 14:31:14 : dca_add_userinfo_dcaclient: DCA Client IO succeded

DEBUG [0x5ec] 12/04/2016 14:31:14 : threadpool_finishnotify: Thread ID: 0x5ec

DEBUG [0x5ec] 12/04/2016 14:31:14 : threadpool_finishnotify: Reset Event

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: CreateTime: 1460464273

DEBUG [0x550] 12/04/2016 14:31:14 : net_send: bytes sent: 285

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: ExpireTime: 1460464878

DEBUG [0x550] 12/04/2016 14:31:14 : net_send: full packet sent

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: Flags: 0

MSG [0x550] 12/04/2016 14:31:14 : SSOclient_thread: Logon/Logout Update sent to: 172.16.0.254:0

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: LogonType: 2

ERROR [0x550] 12/04/2016 14:31:14 : GETTING (USERINFO) FROM QUEUE
DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: Offset: 0; User: Administrator

DEBUG [0x550] 12/04/2016 14:31:14 : list_remove_head: list is Empty

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: Offset: 28; WrkstIP: 172.16.0.230

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: Offset: 54; Domain: btzit.local

DEBUG [0x660] 12/04/2016 14:31:14 : crypto_encrypt_data: data encrypted; ciphertext len: 118

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: Sending DATA Header

DEBUG [0x660] 12/04/2016 14:31:14 : net_send: bytes sent: 12

DEBUG [0x660] 12/04/2016 14:31:14 : net_send: full packet sent

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: DATA Header Sent

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: Sending DATA

DEBUG [0x660] 12/04/2016 14:31:14 : net_send: bytes sent: 118

DEBUG [0x660] 12/04/2016 14:31:14 : net_send: full packet sent

DEBUG [0x660] 12/04/2016 14:31:14 : dcaclient_send_data: DATA Sent

DEBUG [0x660] 12/04/2016 14:31:14 : dca_add_userinfo_dcaclient: DCA Client IO succeded

DEBUG [0x660] 12/04/2016 14:31:14 : threadpool_finishnotify: Thread ID: 0x660

DEBUG [0x660] 12/04/2016 14:31:14 : threadpool_finishnotify: Reset Event
Cancel
Vote Up 0 Vote Down

Cancel
0 Leon.Friend over 9 years ago in reply to EmilMartini

Hi Emil,

So just looking through the log you posted I can see at 14:31:13 the Collector as part of the log off detection performed a WMI lookup on 172.16.0.22 and receieved a response that the logged on user was "administrator"

DEBUG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: connecting to WMI Namespace '\\172.16.0.22\root\cimv2'
DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_threadproc: Executing Function 0x455880
MSG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: username:administrator

This resulted in the user emil.martini being logged off at 14:31:14.

INFO [0x5ec] 12/04/2016 14:31:14 : remove_user_from_de_repositry: user emil.martini with ip 172.16.0.22 removed from DE
MSG [0x5ec] 12/04/2016 14:31:14 : wrkstpoll_handle_logoff_req: user 'btzit.local\emil.martini' removed

The indication is that there is a authenticated process executing on the workstation that uses the "administrator" account, when this executes windows reports the last logged on user as "administrator"

Assuming that the administrator account is not used as an account in the user space, the simplest solution would be to configure the STAS environment to ignore (not track) "administrator" log on events. This can be performed ia the "Exclusion List" Tab in the STAS Client.

Note: using the general "administrator" for dual purposes (i.e. as a user and to run services) can be problematic, I would suggest investigating the option of changing the context for the service/application currently running under "administrator" to a dedicated services account which can be excluded in its place.
Cancel
Vote Up 0 Vote Down

Cancel

Reply

0 Leon.Friend over 9 years ago in reply to EmilMartini

Hi Emil,

So just looking through the log you posted I can see at 14:31:13 the Collector as part of the log off detection performed a WMI lookup on 172.16.0.22 and receieved a response that the logged on user was "administrator"

DEBUG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: connecting to WMI Namespace '\\172.16.0.22\root\cimv2'
DEBUG [0x660] 12/04/2016 14:31:13 : threadpool_threadproc: Executing Function 0x455880
MSG [0x5ec] 12/04/2016 14:31:13 : wrkstpoll_workerthread_wmi: username:administrator

This resulted in the user emil.martini being logged off at 14:31:14.

INFO [0x5ec] 12/04/2016 14:31:14 : remove_user_from_de_repositry: user emil.martini with ip 172.16.0.22 removed from DE
MSG [0x5ec] 12/04/2016 14:31:14 : wrkstpoll_handle_logoff_req: user 'btzit.local\emil.martini' removed

The indication is that there is a authenticated process executing on the workstation that uses the "administrator" account, when this executes windows reports the last logged on user as "administrator"

Assuming that the administrator account is not used as an account in the user space, the simplest solution would be to configure the STAS environment to ignore (not track) "administrator" log on events. This can be performed ia the "Exclusion List" Tab in the STAS Client.

Note: using the general "administrator" for dual purposes (i.e. as a user and to run services) can be problematic, I would suggest investigating the option of changing the context for the service/application currently running under "administrator" to a dedicated services account which can be excluded in its place.
Cancel
Vote Up 0 Vote Down

Cancel

Children

0 EmilMartini over 9 years ago in reply to Leon.Friend

Hi Leon,

I create a new user and start STAS in all DC with this user.

I have excluded the user created and administrator in all STAS, the result is the same.

In DC1 STAS Show live user user emil.martini is not present, in DC2 STAS Show live user user emil.martini is present

Thanks

Emil
Cancel
Vote Up 0 Vote Down

Cancel
0 Leon.Friend over 9 years ago in reply to EmilMartini

Can we check your setup, you only have one STAS environment. When you have a multiple DC you have a Agent on both servers and the collector on one. Both agents populate the identity table on the single collector and the appliance only talks to one collector at a time. This means you can have a second collector deployed, however it is a backup collector and is only used when the primary collector is unavailable (both the agents and the appliance will switch to it)

As you can tell this means that the collector should be aware of the log on events for either DC so you should not see a situation where the user is visible in one place but not another.

Specifics of the setup for multiple domain controllers can be found at
Cancel
Vote Up 0 Vote Down

Cancel
0 EmilMartini over 9 years ago in reply to Leon.Friend

Hi Leon,

i have remove in dc2 the STAS suite and re-install in agent mode.

In sophos xg console I configure only ip dc1 STAS?

(system auth cta collector add collector-ip <dc1 ip>

collector-port 6677 collector-group 1)

Thanks

Emil
Cancel
Vote Up 0 Vote Down

Cancel
0 Leon.Friend over 9 years ago in reply to EmilMartini

Hi Emil,

Has it started to behave now?
Cancel
Vote Up 0 Vote Down

Cancel
0 EmilMartini over 9 years ago in reply to Leon.Friend

Hi Leon,

only if I deactivating , logoff detection by SATS collector seems to work best

Thanks

Emil
Cancel
Vote Up 0 Vote Down

Cancel
0 EmilMartini over 9 years ago in reply to Leon.Friend

Hi Leon,

i have disable "Enable logoff detection" but now every time marked in "Dead entry timeout" the user logout

thanks

Emil
Cancel
Vote Up 0 Vote Down

Cancel