Guest User!

You are not Sophos Staff.

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

User login through SSO client constant login and off in 16.05.1 MR-1

I use the Sophos Single Sign-On Client (SSO) the first one in Client downloads page.

The thing happens at morning as i notice my internet connection in my desktop lost constantly, then i check the xg find there is high cpu usage with little traffic. Using top i find a "worker" process constantly running 100% (suppose it's single threaded), and "access_server" "login_user" "logout_user" apear time to time with high cpu usage. This brings me the the authentication log where i find the logs below, which is apearantly unnormal.

2017-02-13 14:33:59
Firewall Authentication
SUCCESSFUL
user@domain.local
10.18.100.146
SSO
N/A
User user@domain.local was logged out of firewall
17703
Open PCAP
2017-02-13 14:33:59
Firewall Authentication
SUCCESSFUL
user@domain.local
10.18.100.146
SSO
AD
User user@domain.local of group sys-admin logged in successfully to Firewall through AD authentication mechanism from 10.18.100.146
17701
Open PCAP
2017-02-13 14:34:00
Firewall Authentication
SUCCESSFUL
user@domain.local
10.18.100.146
SSO
N/A
User user@domain.local was logged out of firewall
17703
Open PCAP
2017-02-13 14:34:00
Firewall Authentication
SUCCESSFUL
user@domain.local
10.18.100.146
SSO
AD
User user@domain.local of group sys-admin logged in successfully to Firewall through AD authentication mechanism from 10.18.100.146
17701
Open PCAP

 

I manually stop all of the SSO Client and CPU instantly went back to normal (mostly idle).

So far i have tried reboot every thing around it and itself. I also have tried to restore a know good config backup a month ago. Rollback to the 16.01.3 MR-2. All of them didn't solve the problem.

=====edited======

unrelated

Find some thing strange, /log/syslog.log shows /bin/login is constantly restarted in a one sec interval

Feb 14 03:08:02 (none) daemon.info init: process '/bin/login' (pid 9706) exited. Scheduling for restart.
Feb 14 03:08:02 (none) daemon.info init: starting pid 9707, tty '/dev/ttyS0': '/bin/login'
Feb 14 03:08:03 (none) daemon.info init: process '/bin/login' (pid 9707) exited. Scheduling for restart.
Feb 14 03:08:03 (none) daemon.info init: starting pid 9708, tty '/dev/ttyS0': '/bin/login'



This thread was automatically locked due to age.
Parents
  • Hi,

    Which type of SSO are we looking at here? Please share some more details.

    There is an unwritten rule in the Forum which defines one question per thread. Please post the HIGH CPU issue separately.

    Thanks

  • sachingurung said:

    Hi,

    Which type of SSO are we looking at here? Please share some more details.

    There is an unwritten rule in the Forum which defines one question per thread. Please post the HIGH CPU issue separately.

    Thanks

     

    this first one in the Authentication client download page.

    Sophos Single Sign-On Client (SSO) or cyberoam client (this is heard from forum).

    I highly suspect the high CPU usage is related to client logon/logoff continuously, since every thing is normal except the authentication problem

  • Hi,

    Did you monitor if the issue resolves when the CPU levels go down? Is the issue intermittent or the Authentication never worked stable?

    Verify if the configuration is correct as in the article here. Also, show us pictures of the configuration to verify them at our end. 

    Test the working by turning off the local system FIREWALL. 

    Awaiting update.

  • The issue persistent when CPU levels go down. The issue cause computer affected having trabble access anything outside the lan. While SSO Client not working, same user using Authentication Clients (that client need manual enter the username and password upon first logon) works without problem. SSO Client with same setup has been working normally for at least two months.

    Configuration is setup acording to that. I'm not sure what you want me to show you. In my understand there only very limited thing can config here. AD should be correct since i can using other client and login to web admin. The client have only three configurable param, and i can confirm the FQDN of domain name and sophosxg ip address is correct the last matches whats in the link which is “ADS”.

    I also removed all except one Active Directory server in Authentication - Servers, but still no luck.

    I have tried disable firewall on the client and domain controller at same time, still no luck.

  • Hi,

    Take SSH to the XG and go to option 5. Device Management > 3. Advance Shell and execute the following command.

    cd /log

    tail -f access_server.log | grep username

    Please post the logs to check further.

    Thanks

  • I can't find accessserver.log, i suppose you mean access_server.log?

    If so when i stoped Authentication Clients and only run SSO Clients althrough logged in logged out event of SSO client in the authentication log continues, nothing logs to access_server.log file.

    If i run Authentication Clients (which is working currently) i can see the initial login and follow keep_alive logs in the access_server.log file.

  • Edited the actual name of the log file. Please post the logs to me so that I can check what is happening inside.

    Thanks

  • Full log is pmed

    Follows are some thing i think maybe related to the problem

    MESSAGE   Feb 15 08:36:46 [4144265024]: (main): Starting Sophos Firewall access_server
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): GENERIC
    ......

    lots of pg_db_prepare_statements

    ......
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): POSTGRES_DB
    MESSAGE   Feb 15 08:36:46 [4144265024]: sqlite_db_init: TRIGGER 'remove_liveuser_acc' created successfully
    MESSAGE   Feb 15 08:36:46 [4144265024]: sqlite_db_init: TRIGGER 'update_datatransfer' created successfully
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): SQLITE_DB
    MESSAGE   Feb 15 08:36:46 [4144265024]: pg_db_handle_get_citrix_config Total number of CITRIX Servers'0'
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): ADS_AUTH
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): RADIUS_AUTH
    ERROR     Feb 15 08:36:46 [4144265024]: pg_db_handle_get_user_accounting: row count: 0
    ERROR     Feb 15 08:36:46 [4144265024]: start_ippool_subsys: PPTP ip pool config failed
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): IP_POOL
    ERROR     Feb 15 08:36:46 [4144265024]: ippool_init:  table allocatedip created
    ERROR     Feb 15 08:36:46 [4144265024]: ippool_init:  table reservedip created
    ERROR     Feb 15 08:36:46 [4144265024]: ippool_init: table reservedip created
    MESSAGE   Feb 15 08:36:46 [4144265024]: ippool_free_downtime_disconnected_ip: No connection was disconnected in downtime
    ERROR     Feb 15 08:36:46 [4144265024]: pg_db_handle_get_user_accounting: row count: 0
    ERROR     Feb 15 08:36:46 [4144265024]: start_ippool_subsys: get reserved ip pool config failed
    ERROR     Feb 15 08:36:46 [4144265024]: nvram_get(defaultlicenseuser): failed with -12
    ERROR     Feb 15 08:36:46 [4144265024]: get_max_allowed_users: Failed to read nvram key defaultlicenseuser
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): OTP_AUTH
    ERROR     Feb 15 08:36:46 [4144265024]: pg_db_handle_get_cache_configuration: Multiple rows found
    ERROR     Feb 15 08:36:46 [4144265024]: configure_paraten_proxy_config: failed to get configuration
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): OPCODE
    ERROR     Feb 15 08:36:46 [4144265024]: (pg_db_process_prepq_async): PQisBusy() > 0!
    MESSAGE   Feb 15 08:36:46 [4144265024]: (main): access_server: access_server started Successfully
    MESSAGE   Feb 15 08:36:49 [4144265024]: access_server: Clientless users login complete
    MESSAGE   Feb 15 08:36:49 [4144265024]: (CA_init): ClientAuth initialized
    MESSAGE   Feb 15 08:36:49 [4144265024]: (add_worker): EDIR_SYNC
    MESSAGE   Feb 15 08:39:28 [4144265024]: config_update_group_config: UPDATING BWID IN DB
    MESSAGE   Feb 15 08:53:34 [4144265024]: (process_command): Client type is OS X
    MESSAGE   Feb 15 08:53:34 [4144265024]: (CA_authentication_result): User xdq authenticated (CA)
    ERROR     Feb 15 08:53:34 [4131371840]: config_resolve_datatransferid: Datatransfer Policy 0 not found

    =======

    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_bind: bind failed: Invalid credentials
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: '10.18.8.1:636': bind failed for User: 'DOMAIN\user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: ADS Authentication Failed for User:'user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_parse_error_msg: ad error no: 1326
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_bind: bind failed: Invalid credentials
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: '10.18.8.2:636': bind failed for User: 'DOMAIN\user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: ADS Authentication Failed for User:'user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_parse_error_msg: ad error no: 1326
    ERROR     Feb 16 17:23:58 [4144265024]: check_auth_result: VPN/SSLVPN/MYACC Authentication Failed

Reply
  • Full log is pmed

    Follows are some thing i think maybe related to the problem

    MESSAGE   Feb 15 08:36:46 [4144265024]: (main): Starting Sophos Firewall access_server
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): GENERIC
    ......

    lots of pg_db_prepare_statements

    ......
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): POSTGRES_DB
    MESSAGE   Feb 15 08:36:46 [4144265024]: sqlite_db_init: TRIGGER 'remove_liveuser_acc' created successfully
    MESSAGE   Feb 15 08:36:46 [4144265024]: sqlite_db_init: TRIGGER 'update_datatransfer' created successfully
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): SQLITE_DB
    MESSAGE   Feb 15 08:36:46 [4144265024]: pg_db_handle_get_citrix_config Total number of CITRIX Servers'0'
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): ADS_AUTH
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): RADIUS_AUTH
    ERROR     Feb 15 08:36:46 [4144265024]: pg_db_handle_get_user_accounting: row count: 0
    ERROR     Feb 15 08:36:46 [4144265024]: start_ippool_subsys: PPTP ip pool config failed
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): IP_POOL
    ERROR     Feb 15 08:36:46 [4144265024]: ippool_init:  table allocatedip created
    ERROR     Feb 15 08:36:46 [4144265024]: ippool_init:  table reservedip created
    ERROR     Feb 15 08:36:46 [4144265024]: ippool_init: table reservedip created
    MESSAGE   Feb 15 08:36:46 [4144265024]: ippool_free_downtime_disconnected_ip: No connection was disconnected in downtime
    ERROR     Feb 15 08:36:46 [4144265024]: pg_db_handle_get_user_accounting: row count: 0
    ERROR     Feb 15 08:36:46 [4144265024]: start_ippool_subsys: get reserved ip pool config failed
    ERROR     Feb 15 08:36:46 [4144265024]: nvram_get(defaultlicenseuser): failed with -12
    ERROR     Feb 15 08:36:46 [4144265024]: get_max_allowed_users: Failed to read nvram key defaultlicenseuser
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): OTP_AUTH
    ERROR     Feb 15 08:36:46 [4144265024]: pg_db_handle_get_cache_configuration: Multiple rows found
    ERROR     Feb 15 08:36:46 [4144265024]: configure_paraten_proxy_config: failed to get configuration
    MESSAGE   Feb 15 08:36:46 [4144265024]: (add_worker): OPCODE
    ERROR     Feb 15 08:36:46 [4144265024]: (pg_db_process_prepq_async): PQisBusy() > 0!
    MESSAGE   Feb 15 08:36:46 [4144265024]: (main): access_server: access_server started Successfully
    MESSAGE   Feb 15 08:36:49 [4144265024]: access_server: Clientless users login complete
    MESSAGE   Feb 15 08:36:49 [4144265024]: (CA_init): ClientAuth initialized
    MESSAGE   Feb 15 08:36:49 [4144265024]: (add_worker): EDIR_SYNC
    MESSAGE   Feb 15 08:39:28 [4144265024]: config_update_group_config: UPDATING BWID IN DB
    MESSAGE   Feb 15 08:53:34 [4144265024]: (process_command): Client type is OS X
    MESSAGE   Feb 15 08:53:34 [4144265024]: (CA_authentication_result): User xdq authenticated (CA)
    ERROR     Feb 15 08:53:34 [4131371840]: config_resolve_datatransferid: Datatransfer Policy 0 not found

    =======

    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_bind: bind failed: Invalid credentials
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: '10.18.8.1:636': bind failed for User: 'DOMAIN\user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: ADS Authentication Failed for User:'user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_parse_error_msg: ad error no: 1326
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_bind: bind failed: Invalid credentials
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: '10.18.8.2:636': bind failed for User: 'DOMAIN\user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_authenticate_user: ADS Authentication Failed for User:'user'
    ERROR     Feb 16 17:23:58 [4135582528]: adsauth_parse_error_msg: ad error no: 1326
    ERROR     Feb 16 17:23:58 [4144265024]: check_auth_result: VPN/SSLVPN/MYACC Authentication Failed

Children
No Data