Important note about SSL VPN compatibility for 20.0 MR1 with EoL SFOS versions and UTM9 OS. Learn more in the release notes.
Hello Community,
this morning we faced the issue that users were not able to authenticate against the firewall. This affected the heartbeat/firewall rules were users are used, user/vpn/admin portal and SSL VPN were also unable to authenticate. The authentication service is set to a active directory domain. The default admin user was able to login to the firewall. On the firewall dashboard everything was normal, all services were running.
After our initial investigation we found that only one firewall was affected by this. During our search we noticed that a brute force attack against the SSL VPN Portal was present before the crash. It was more than usually but nothing special. The IP's are similiar to https://support.sophos.com/support/s/article/KBA-000009932?language=en_US I will attach a file with all the usernames and IP's used. We added a local ACL to combat the brute force but since it is a public facing firewall it is expected to be hit by attacks. We use 2FA so it doesn't really bother us.
After a bit more research we found the following in the access_server.log.
MESSAGE Feb 10 06:15:50.347920Z [access_server]: (update_admin_access_table): ## Admin user authentication failed from IP 68.235.46.62 malloc(): memory corruptionERROR Feb 10 06:15:50.353255Z [access_server]: Access server crashed MESSAGE Feb 10 06:15:52.616194Z [access_server]: (main_init): Starting Sophos Firewall access_server MESSAGE Feb 10 06:15:52.616216Z [access_server]: (main_init): nofile = 5050 MESSAGE Feb 10 06:15:52.616230Z [access_server]: (add_worker): GENERIC MESSAGE Feb 10 06:15:52.648675Z [access_server]: (add_worker): POSTGRES_DB MESSAGE Feb 10 06:15:52.649630Z [access_server]: (sqlite_db_init): TRIGGER 'remove_liveuser_acc' created successfully MESSAGE Feb 10 06:15:52.649749Z [access_server]: (sqlite_db_init): TRIGGER 'update_datatransfer' created successfully MESSAGE Feb 10 06:15:52.651668Z [access_server]: (add_worker): SQLITE_DB MESSAGE Feb 10 06:15:52.653565Z [access_server]: (add_worker): SQLITE_DB_2 MESSAGE Feb 10 06:15:52.653619Z [access_server]: (read_uptime_diff): UPTIME DIFF:5369961 MESSAGE Feb 10 06:15:52.654341Z [access_server]: pg_db_handle_get_citrix_config Total number of CITRIX Servers'0' MESSAGE Feb 10 06:15:52.658770Z [access_server]: (add_worker): ADS_AUTH ERROR Feb 10 06:15:52.659333Z [access_server]: pg_db_handle_get_user_accounting: row count: 0 ERROR Feb 10 06:15:52.659340Z [access_server]: (start_ippool_subsys): L2TP ip pool config failed ERROR Feb 10 06:15:52.659510Z [access_server]: pg_db_handle_get_user_accounting: row count: 0 ERROR Feb 10 06:15:52.659513Z [access_server]: (start_ippool_subsys): PPTP ip pool config failed ERROR Feb 10 06:15:52.659609Z [access_server]: pg_db_handle_get_ipsec_ip_setting: row count: 0 ERROR Feb 10 06:15:52.659631Z [access_server]: (start_ippool_subsys): IPSec ip pool config failed MESSAGE Feb 10 06:15:52.659647Z [access_server]: (add_worker): IP_POOL MESSAGE Feb 10 06:15:52.660067Z [access_server]: ippool_free_downtime_disconnected_ip: No connection was disconnected in downtime ERROR Feb 10 06:15:52.660355Z [access_server]: pg_db_handle_get_user_accounting: row count: 0 ERROR Feb 10 06:15:52.660361Z [access_server]: (start_ippool_subsys): get reserved ip pool config failed ERROR Feb 10 06:15:52.662814Z [access_server]: (_nvram_get): nvram_get(defaultlicenseuser): failed with -12 ERROR Feb 10 06:15:52.662843Z [access_server]: (get_max_allowed_users): Failed to read nvram key defaultlicenseuser MESSAGE Feb 10 06:15:52.663191Z [access_server]: (add_worker): OTP_AUTH MESSAGE Feb 10 06:15:52.663578Z [access_server]: (config_client_preferences): Maximum number of liveusers allowed: 12288 ERROR Feb 10 06:15:52.687347Z [access_server]: pg_db_handle_get_cache_configuration: Multiple rows found ERROR Feb 10 06:15:52.687362Z [access_server]: (config_get_parent_proxy_config): failed to get configuration MESSAGE Feb 10 06:15:52.688183Z [access_server]: (add_worker): OPCODE ERROR Feb 10 06:15:52.690235Z [access_server]: (pg_db_process_prepq_async): PQisBusy() > 0! MESSAGE Feb 10 06:15:52.690263Z [access_server]: (uid_init): Max number of bitmaps: 1536 MESSAGE Feb 10 06:15:52.690403Z [access_server]: (main_init): access_server: access_server started Successfully MESSAGE Feb 10 06:15:52.692372Z [access_server]: access_server: Clientless users login complete MESSAGE Feb 10 06:15:52.692482Z [access_server]: (CA_init): CAA iOS timeout = 120, Android timeout = 120 MESSAGE Feb 10 06:15:52.693511Z [access_server]: (CA_init): ClientAuth initialized MESSAGE Feb 10 06:15:52.693558Z [access_server]: (add_worker): EDIR_SYNC MESSAGE Feb 10 06:15:52.693583Z [access_server]: (do_epoll): The good ep_fd=3, the bad listen_fd=25 and the ugly tlv_fd=23
So the service crashed but was automatically restarted but it seems to was in a non functioning state. We restarted the service manually with "service access_server:restart -ds nosync". The service started with no issue and the authentication was working again.
After about 1 hour the SSL VPN service just died. We found the following in the access_server.log. The SSL VPN service died because the configuration were deleted and without a configuration the service will not be in a running state.
MESSAGE Feb 10 10:52:43.018255Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:44.819134Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:46.152608Z [access_server]: ippool_submit_request: IP free request ERROR Feb 10 10:52:46.152639Z [IP_POOL]: ippool_handle_freeip_request: ip x.x.x.x freed from assigned pool /_conf/csc/auth_utility auth_update_tbluseraccounting "{ \"userids\":[\"xyz@xyz.com\"],\"uploaddata\":[\"501668154810\"],\"downloaddata\":[\"5906779749\"],\"cycleupload\":[\"501668154810\"],\"cycledownload\":[\"5906779749\"],\"usedminutes\":[711834],\"cycleusedminutes\":[711834],\"lastusedtime\":[\"2025-02-10 11:51:03\"] }" buffer : status 0 /_conf/csc/auth_utility logout_user "{ \"userid\":\"xyz@xyz.com\",\"liveuserid\":\"560\",\"bwpolicyid\":\"\",\"ipaddress\":\"x.x.x.x\",\"setname\":\"lusers\" }" buffer : status 0 MESSAGE Feb 10 10:52:46.238896Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:47.572090Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:48.991121Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:50.310316Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:51.624240Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:52.979489Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:54.334847Z [access_server]: (config_update_group_config): UPDATING BWID IN DB MESSAGE Feb 10 10:52:55.664596Z [access_server]: (config_update_group_config): UPDATING BWID IN DB
Does anyone else face similar issues? A brute force attack like this shouldn't cause an issue like this.
Hi Jens,
Please share the access-id to check and debug further.
Thanks,
Priyanka
I can't sent you a message. It doesn't provide me with the option to do so.
Hello Jens,
Kindly try sending Priyanka or Bhavik a DM, we have adjusted settings, you should be able to send them DMs now
Thanks
Raphael Alganes
Community Support Engineer | Sophos Technical Support
Sophos Support Videos | Product Documentation | @SophosSupport | Sign up for SMS Alerts
If a post solves your question use the 'Verify Answer' link.
I just encoutered the same issue on a customers XGS4500 v21GA. Is there any kind of solution yet?
Hello Björn,
Sophos provided a hotfix for this issue.
If you have not restarted your appliance yet, check if the following file is present "/bin/access_server_hf". If it is present you need to restart the appliance to apply the hotfix. The hotfix can only be applied during a restart because it will affect all live users. That is why it is not being applied automatically even if you have the auto hotfix setting turned on. Once the hotfix is applied, the file will disappear and the issue should not happen again.
If your firewall is in a HA configuration, the hotfix should have been appied on the auxiliary device. You can check if the file is present there. It should not be there if it was applied.
If you can't restart the appliance at the moment, you can just restart the access_server service for it to start working again but this will not apply the hotfix.