[RESOLVED] WAPT agent disconnects

alain17 · July 15, 2022 - 10:25

Good morning,

I'm currently running a WAPT Enterprise server version 2.2 on Ubuntu 20.04 LTS and I'm having a problem with my Windows clients. Some work perfectly (remain connected) while others disconnect from the server very quickly (appear disconnected even though they can be pinged). I followed the topic on antivirus and that of this user who is experiencing disconnection problems also.

I executed the following command on a client machine that disconnects, as a non-privileged user:

Code: Select all

"c:\Program Files (x86)\wapt\runwaptservice.bat" -ldebug

The result that emerged was as follows:

Code: Select all

2022-07-15 09:19:57,091 [waptcore MainThread 16644] DEBUG Thread 16644 is connecting to wapt db
2022-07-15 09:19:57,094 [waptcore MainThread 16644] DEBUG DB Start transaction
2022-07-15 09:19:57,094 [waptcore MainThread 16644] DEBUG DB commit
2022-07-15 09:19:57,127 [waptservice MainThread 16644] INFO Setting hiberboot_enabled to 0
2022-07-15 09:19:57,129 [waptcore MainThread 16644] DEBUG Thread 16644 is connecting to wapt db
2022-07-15 09:19:57,129 [waptcore MainThread 16644] DEBUG DB Start transaction
2022-07-15 09:19:57,130 [waptcore MainThread 16644] DEBUG DB commit
Disabling Windows auto update service, using WaptWUA instead
2022-07-15 09:19:57,159 [waptwua MainThread 16644] CRITICAL Unable to set waptwua policies : __enter__
2022-07-15 09:19:57,159 [wapttasks MainThread 16644] INFO Service Configuration: {'config_filename': 'c:\\Program Files (x86)\\wapt\\wapt-get.ini', 'waptservice_user': None, 'waptservice_password': None, 'MAX_HISTORY': 30, 'waptservice_port': 8088, 'dbpath': 'c:\\Program Files (x86)\\wapt\\db\\waptdb.sqlite', 'loglevel': 'debug', 'log_directory': 'c:\\Program Files (x86)\\wapt\\log', 'waptserver': <WaptServer https://waptserver.domaine.local>, 'hiberboot_enabled': 0, 'max_gpo_script_wait': 180, 'pre_shutdown_timeout': 180, 'log_to_windows_events': False, 'allow_user_service_restart': False, 'signature_clockskew': 21600, 'notify_user': False, 'waptservice_admin_filter': False, 'enable_remote_repo': False, 'local_repo_path': 'c:\\Program Files (x86)\\wapt\\repository', 'local_repo_sync_task_period': '2h', 'local_repo_time_for_sync_start': None, 'local_repo_time_for_sync_end': None, 'local_repo_limit_bandwidth': None, 'wol_port': '7,9', 'wol_relay': False, 'service_auth_type': 'system', 'verify_cert_ldap': False, 'download_after_update_with_waptupdate_task_period': True, 'forced_installs_task_period': '2m', 'reconfig_on_network_change': False, 'loglevel_waptcore': None, 'loglevel_waptservice': None, 'loglevel_waptws': None, 'loglevel_waptdb': None, 'loglevel_websocket': None, 'loglevel_waitress': None, 'loglevel_wapttasks': None}
2022-07-15 09:19:57,159 [wapttasks MainThread 16644] INFO Starting task queue
2022-07-15 09:19:57,160 [wapttasks MainThread 16644] INFO Tasks queue running
2022-07-15 09:19:57,160 [wapttasks WaptTaskManager 7028] INFO Wapt tasks management initialized with c:\Program Files (x86)\wapt\wapt-get.ini configuration
2022-07-15 09:19:57,161 [wapttasks MainThread 16644] INFO Starting waitress waptservice on port 8088
2022-07-15 09:19:57,162 [waptservice SocketIOClient 20008] INFO No password set for local waptservice, using local computer security
2022-07-15 09:19:57,163 [waptcore WaptTaskManager 7028] DEBUG Thread 7028 is connecting to wapt db
2022-07-15 09:19:57,165 [waptcore SocketIOClient 20008] DEBUG Thread 20008 is connecting to wapt db
2022-07-15 09:19:57,165 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:19:57,165 [waptcore WaptTaskManager 7028] DEBUG DB commit
2022-07-15 09:19:57,166 [waptcore SocketIOClient 20008] DEBUG DB Start transaction
2022-07-15 09:19:57,167 [waptcore SocketIOClient 20008] DEBUG DB commit
2022-07-15 09:19:57,168 [waitress MainThread 16644] INFO Serving on http://127.0.0.1:8088
2022-07-15 09:19:57,249 [wapttasks SocketIOClient 20008] INFO Starting socketio on "https://waptserver.domaine.local:443" Thread id 20008
2022-07-15 09:19:57,249 [waptws SocketIOClient 20008] DEBUG Certificate checking : False
2022-07-15 09:19:57,250 [waptcore WaptTaskManager 7028] DEBUG Host certificate c:\Program Files (x86)\wapt\private\4C4C4544-0035-4710-804A-B3C04F434233.crt not found, not using it for auth on repo global
2022-07-15 09:19:57,252 [waptcore WaptTaskManager 7028] DEBUG Host certificate c:\Program Files (x86)\wapt\private\4C4C4544-0035-4710-804A-B3C04F434233.crt not found, not using it for auth on repo wapt
2022-07-15 09:19:57,252 [waptcore WaptTaskManager 7028] INFO Main repository: https://waptserver.domaine.local/wapt
2022-07-15 09:19:57,253 [waptcore WaptTaskManager 7028] DEBUG Host certificate c:\Program Files (x86)\wapt\private\4C4C4544-0035-4710-804A-B3C04F434233.crt not found, not using it for auth on repo wapt-host
2022-07-15 09:19:57,254 [wapttasks WaptTaskManager 7028] INFO Core Configuration: {'wapt_base_dir': 'c:\\Program Files (x86)\\wapt', 'waptserver': <WaptServer https://waptserver.domaine.local>, 'config_filename': 'c:\\Program Files (x86)\\wapt\\wapt-get.ini', 'proxies': {'http': '', 'https': ''}, 'repositories': [<WaptRepo https://waptserver.domaine.local/wapt>, <WaptHostRepo https://waptserver.domaine.local/wapt-host for host_id 4C4C4544-0035-4710-804A-B3C04F434233 >], 'personal_certificate_path': '', 'public_certs_dir': 'c:\\Program Files (x86)\\wapt\\ssl', 'package_cache_dir': 'c:\\Program Files (x86)\\wapt\\cache', 'dbpath': 'c:\\Program Files (x86)\\wapt\\db\\waptdb.sqlite', 'use_http_proxy_for_repo': False, 'use_http_proxy_for_server': False, 'limit_bandwidth': None, 'locales': ['fr'], 'custom_tags': [], 'packages_whitelist': None, 'packages_blacklist': None, 'maturities': ['PROD'], 'host_uuid': '4C4C4544-0035-4710-804A-B3C04F434233', 'use_fqdn_as_uuid': False, 'use_hostpackages': True, 'use_ad_groups': False, 'use_repo_rules': False, 'host_profiles': [], 'host_organizational_unit_dn': 'OU=WAPT Test,OU=Ordinateurs,DC=Domaine,DC=local', 'host_ad_site': None, 'waptaudit_task_period': '2h', 'hiberboot_enabled': '0', 'max_gpo_script_wait': 180.0, 'pre_shutdown_timeout': 180.0, 'uninstallkey_timeout': 120, 'check_certificates_validity': True, 'token_lifetime': 86400}
2022-07-15 09:19:57,254 [wapttasks WaptTaskManager 7028] INFO Wapt tasks queue started
2022-07-15 09:19:57,850 [waptws SocketIOClient 20008] WARNING Exception PermissionError(13, 'Permission denied'), waiting 1.3s before retrying
2022-07-15 09:19:59,426 [waptws SocketIOClient 20008] WARNING Exception PermissionError(13, 'Permission denied'), waiting 2.2750000000000004s before retrying
2022-07-15 09:20:02,026 [waptws SocketIOClient 20008] WARNING Exception PermissionError(13, 'Permission denied'), waiting 3.9812500000000006s before retrying
2022-07-15 09:20:06,093 [waptws SocketIOClient 20008] WARNING Exception PermissionError(13, 'Permission denied'), waiting 6.967187500000001s before retrying
2022-07-15 09:20:07,320 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:07,426 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "GET /licences.json HTTP/1.1" 200 7952
2022-07-15 09:20:07,428 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:07,428 [waptcore WaptTaskManager 7028] DEBUG DB rollback
2022-07-15 09:20:07,432 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:07,435 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:07,435 [waptcore WaptTaskManager 7028] DEBUG Remove unknown repositories from packages table and params ("wapt","wapt-host")
2022-07-15 09:20:07,436 [waptcore WaptTaskManager 7028] DEBUG Check last-modified header for wapt to avoid unecessary update
2022-07-15 09:20:07,436 [waptcore WaptTaskManager 7028] DEBUG Checking availability of https://waptserver.domaine.local/wapt/Packages
2022-07-15 09:20:07,437 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:07,532 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "HEAD /wapt/Packages HTTP/1.1" 200 0
2022-07-15 09:20:07,533 [waptcore WaptTaskManager 7028] INFO Index from https://waptserver.domaine.local/wapt has not been updated (last update 2022-07-11T07:09:54), skipping update
2022-07-15 09:20:07,533 [waptcore WaptTaskManager 7028] DEBUG Check last-modified header for wapt-host to avoid unecessary update
2022-07-15 09:20:07,534 [waptcore WaptTaskManager 7028] DEBUG Checking availability of wapt-host
2022-07-15 09:20:07,534 [waptcore WaptTaskManager 7028] DEBUG Trying to get  host package for 4C4C4544-0035-4710-804A-B3C04F434233 at https://waptserver.domaine.local/wapt-host/4C4C4544-0035-4710-804A-B3C04F434233.wapt
2022-07-15 09:20:07,535 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:07,624 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "HEAD /wapt-host/4C4C4544-0035-4710-804A-B3C04F434233.wapt HTTP/1.1" 200 0
2022-07-15 09:20:07,625 [waptcore WaptTaskManager 7028] INFO Index from https://waptserver.domaine.local/wapt-host has not been updated (last update 2022-07-08T09:23:28), skipping update
2022-07-15 09:20:07,626 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:07,626 [waptcore WaptTaskManager 7028] DEBUG DB rollback
2022-07-15 09:20:07,626 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 4567, in _update_repos_list\n    self.write_param(\'host_capabilities_fingerprint\', new_capa)\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 8018, in write_param\n    self.waptdb.set_param(name, value)\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:07,627 [wapttasks WaptTaskManager 7028] CRITICAL Error for update in check_scheduled_tasks: attempt to write a readonly database
2022-07-15 09:20:07,627 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:07,628 [waptcore WaptTaskManager 7028] DEBUG DB commit
2022-07-15 09:20:13,222 [waptws SocketIOClient 20008] WARNING Exception PermissionError(13, 'Permission denied'), waiting 12.192578125000002s before retrying
2022-07-15 09:20:17,637 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:17,725 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "GET /licences.json HTTP/1.1" 200 7952
2022-07-15 09:20:17,726 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:17,727 [waptcore WaptTaskManager 7028] DEBUG DB rollback
2022-07-15 09:20:17,727 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:17,729 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:17,730 [waptcore WaptTaskManager 7028] DEBUG Remove unknown repositories from packages table and params ("wapt","wapt-host")
2022-07-15 09:20:17,730 [waptcore WaptTaskManager 7028] DEBUG Check last-modified header for wapt to avoid unecessary update
2022-07-15 09:20:17,730 [waptcore WaptTaskManager 7028] DEBUG Checking availability of https://waptserver.domaine.local/wapt/Packages
2022-07-15 09:20:17,731 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:17,821 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "HEAD /wapt/Packages HTTP/1.1" 200 0
2022-07-15 09:20:17,822 [waptcore WaptTaskManager 7028] INFO Index from https://waptserver.domaine.local/wapt has not been updated (last update 2022-07-11T07:09:54), skipping update
2022-07-15 09:20:17,823 [waptcore WaptTaskManager 7028] DEBUG Check last-modified header for wapt-host to avoid unecessary update
2022-07-15 09:20:17,826 [waptcore WaptTaskManager 7028] DEBUG Checking availability of wapt-host
2022-07-15 09:20:17,826 [waptcore WaptTaskManager 7028] DEBUG Trying to get  host package for 4C4C4544-0035-4710-804A-B3C04F434233 at https://waptserver.domaine.local/wapt-host/4C4C4544-0035-4710-804A-B3C04F434233.wapt
2022-07-15 09:20:17,826 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:17,895 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "HEAD /wapt-host/4C4C4544-0035-4710-804A-B3C04F434233.wapt HTTP/1.1" 200 0
2022-07-15 09:20:17,896 [waptcore WaptTaskManager 7028] INFO Index from https://waptserver.domaine.local/wapt-host has not been updated (last update 2022-07-08T09:23:28), skipping update
2022-07-15 09:20:17,897 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:17,897 [waptcore WaptTaskManager 7028] DEBUG DB rollback
2022-07-15 09:20:17,898 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 4567, in _update_repos_list\n    self.write_param(\'host_capabilities_fingerprint\', new_capa)\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 8018, in write_param\n    self.waptdb.set_param(name, value)\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:17,898 [wapttasks WaptTaskManager 7028] CRITICAL Error for update in check_scheduled_tasks: attempt to write a readonly database
2022-07-15 09:20:17,898 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:17,898 [waptcore WaptTaskManager 7028] DEBUG DB commit
2022-07-15 09:20:23,435 [wapttasks MainThread 16644] INFO Waptservice stopped
2022-07-15 09:20:25,848 [waptws SocketIOClient 20008] WARNING Exception PermissionError(13, 'Permission denied'), waiting 21.337011718750006s before retrying
2022-07-15 09:20:27,919 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:27,994 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "GET /licences.json HTTP/1.1" 200 7952
2022-07-15 09:20:27,998 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:27,999 [waptcore WaptTaskManager 7028] DEBUG DB rollback
2022-07-15 09:20:28,000 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:28,011 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:28,012 [waptcore WaptTaskManager 7028] DEBUG Remove unknown repositories from packages table and params ("wapt","wapt-host")
2022-07-15 09:20:28,013 [waptcore WaptTaskManager 7028] DEBUG Check last-modified header for wapt to avoid unecessary update
2022-07-15 09:20:28,014 [waptcore WaptTaskManager 7028] DEBUG Checking availability of https://waptserver.domaine.local/wapt/Packages
2022-07-15 09:20:28,015 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:28,085 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "HEAD /wapt/Packages HTTP/1.1" 200 0
2022-07-15 09:20:28,086 [waptcore WaptTaskManager 7028] INFO Index from https://waptserver.domaine.local/wapt has not been updated (last update 2022-07-11T07:09:54), skipping update
2022-07-15 09:20:28,087 [waptcore WaptTaskManager 7028] DEBUG Check last-modified header for wapt-host to avoid unecessary update
2022-07-15 09:20:28,087 [waptcore WaptTaskManager 7028] DEBUG Checking availability of wapt-host
2022-07-15 09:20:28,087 [waptcore WaptTaskManager 7028] DEBUG Trying to get  host package for 4C4C4544-0035-4710-804A-B3C04F434233 at https://waptserver.domaine.local/wapt-host/4C4C4544-0035-4710-804A-B3C04F434233.wapt
2022-07-15 09:20:28,088 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:28,156 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "HEAD /wapt-host/4C4C4544-0035-4710-804A-B3C04F434233.wapt HTTP/1.1" 200 0
2022-07-15 09:20:28,157 [waptcore WaptTaskManager 7028] INFO Index from https://waptserver.domaine.local/wapt-host has not been updated (last update 2022-07-08T09:23:28), skipping update
2022-07-15 09:20:28,158 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:28,158 [waptcore WaptTaskManager 7028] DEBUG DB rollback
2022-07-15 09:20:28,158 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 4567, in _update_repos_list\n    self.write_param(\'host_capabilities_fingerprint\', new_capa)\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 8018, in write_param\n    self.waptdb.set_param(name, value)\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']
2022-07-15 09:20:28,159 [wapttasks WaptTaskManager 7028] CRITICAL Error for update in check_scheduled_tasks: attempt to write a readonly database
2022-07-15 09:20:28,159 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:28,159 [waptcore WaptTaskManager 7028] DEBUG DB commit
2022-07-15 09:20:38,177 [urllib3.connectionpool WaptTaskManager 7028] DEBUG Starting new HTTPS connection (1): waptserver.domaine.local:443
2022-07-15 09:20:38,250 [urllib3.connectionpool WaptTaskManager 7028] DEBUG https://waptserver.domaine.local:443 "GET /licences.json HTTP/1.1" 200 7952
2022-07-15 09:20:38,251 [waptcore WaptTaskManager 7028] DEBUG DB Start transaction
2022-07-15 09:20:38,252 [waptcore WaptTaskManager 7028] DEBUG DB rollback
2022-07-15 09:20:38,252 [waptcore WaptTaskManager 7028] DEBUG Error at DB exit attempt to write a readonly database, rollbacking
['  File "c:\\Program Files (x86)\\wapt\\common.py", line 347, in set_param\n    self.execute(\'insert or replace into wapt_params(name,value,create_date,ptype) values (?,?,?,?)\', (name, value, datetime2isodate(), ptype))\n', '  File "c:\\Program Files (x86)\\wapt\\common.py", line 397, in execute\n    return self.db.execute(query, args)\n']

I've noticed numerous "CRITICAL" errors in the log, that the agent is having trouble applying the WUA policy, and that the scheduled tasks also seem to be malfunctioning. What worries me a bit is that these test clients were only installed very recently (2 weeks max). Have I misconfigured my agent? I still need to update it before deploying WAPT to our hundred or so workstations.

Our antivirus software isn't reporting any WAPT utility blocks, so I'm wondering what could be going on... do you have any ideas? All users are running without privileges. I tried running the debug command as administrator, and it worked without any problems.

Thank you in advance for your ideas.

alain17 · July 18, 2022 - 3:59 PM

Good morning,

After doing some research, I understood that the runwaptservice.bat executable should always be run as administrator, and that therefore nothing was wrong in my test without administrator privileges.

This does not, however, solve the problem: some workstations have their agent crashing regularly. Apparently, it is possible to restart WAPT using the command:

Code: Select all

wapt-get restart-waptservice

Is there a way to automate this, for example with a scheduled task? I can't find the setuphelpers documentation as mentioned here and who could help me.

July 18, 2022 - 6:37 PM

Hello,

the agent shouldn't crash like that.

Do you have any messages in the Event Viewer related to this crash? Do you see anything unusual in c:\program files (x86)\wapt\log?

Regards,

Denis

alain17 · August 12, 2022 - 08:23

Good morning,

I checked the logs and event log this morning on a machine affected by these disconnections to recover what I could. In the WAPT logs, I found the following:

Code: Select all

Disabling Windows auto update service, using WaptWUA instead
2022-08-12 07:19:32,315 [wapttasks MainThread 7640] INFO Service Configuration: {'config_filename': 'C:\\Program Files (x86)\\wapt\\wapt-get.ini', 'waptservice_user': None, 'waptservice_password': None, 'MAX_HISTORY': 30, 'waptservice_port': 8088, 'dbpath': 'C:\\Program Files (x86)\\wapt\\db\\waptdb.sqlite', 'loglevel': 'warning', 'log_directory': 'C:\\Program Files (x86)\\wapt\\log', 'waptserver': <WaptServer https://waptserver.domaine.local>, 'hiberboot_enabled': 0, 'max_gpo_script_wait': 180, 'pre_shutdown_timeout': 180, 'log_to_windows_events': False, 'allow_user_service_restart': False, 'signature_clockskew': 21600, 'notify_user': False, 'waptservice_admin_filter': False, 'enable_remote_repo': False, 'local_repo_path': 'C:\\Program Files (x86)\\wapt\\repository', 'local_repo_sync_task_period': '2h', 'local_repo_time_for_sync_start': None, 'local_repo_time_for_sync_end': None, 'local_repo_limit_bandwidth': None, 'wol_port': '7,9', 'wol_relay': False, 'service_auth_type': 'system', 'verify_cert_ldap': False, 'download_after_update_with_waptupdate_task_period': True, 'forced_installs_task_period': '2m', 'reconfig_on_network_change': False, 'loglevel_waptcore': None, 'loglevel_waptservice': None, 'loglevel_waptws': None, 'loglevel_waptdb': None, 'loglevel_websocket': None, 'loglevel_waitress': None, 'loglevel_wapttasks': None}
2022-08-12 07:19:32,316 [wapttasks MainThread 7640] INFO Starting task queue
2022-08-12 07:19:32,317 [wapttasks MainThread 7640] INFO Tasks queue running
2022-08-12 07:19:32,317 [wapttasks WaptTaskManager 6372] INFO Wapt tasks management initialized with C:\Program Files (x86)\wapt\wapt-get.ini configuration
2022-08-12 07:19:32,319 [wapttasks MainThread 7640] INFO Starting waitress waptservice on port 8088
2022-08-12 07:19:32,421 [wapttasks SocketIOClient 6556] INFO Starting socketio on "https://waptserver.domaine.local:443" Thread id 6556
2022-08-12 07:19:32,466 [wapttasks WaptTaskManager 6372] INFO Core Configuration: {'wapt_base_dir': 'C:\\Program Files (x86)\\wapt', 'waptserver': <WaptServer https://waptserver.domaine.local>, 'config_filename': 'C:\\Program Files (x86)\\wapt\\wapt-get.ini', 'proxies': {'http': '', 'https': ''}, 'repositories': [<WaptRepo https://waptserver.domaine.local/wapt>, <WaptHostRepo https://waptserver.domaine.local/wapt-host for host_id 4C4C4544-0035-4710-804A-B3C04F434233 >], 'personal_certificate_path': '', 'public_certs_dir': 'C:\\Program Files (x86)\\wapt\\ssl', 'package_cache_dir': 'C:\\Program Files (x86)\\wapt\\cache', 'dbpath': 'C:\\Program Files (x86)\\wapt\\db\\waptdb.sqlite', 'use_http_proxy_for_repo': False, 'use_http_proxy_for_server': False, 'limit_bandwidth': None, 'locales': ['fr'], 'custom_tags': [], 'packages_whitelist': None, 'packages_blacklist': None, 'maturities': ['PROD'], 'host_uuid': '4C4C4544-0035-4710-804A-B3C04F434233', 'use_fqdn_as_uuid': False, 'use_hostpackages': True, 'use_ad_groups': False, 'use_repo_rules': False, 'host_profiles': [], 'host_organizational_unit_dn': 'OU=WAPT Test,OU=Ordinateurs,DC=Domaine,DC=local', 'host_ad_site': None, 'waptaudit_task_period': '2h', 'hiberboot_enabled': '0', 'max_gpo_script_wait': 180.0, 'pre_shutdown_timeout': 180.0, 'uninstallkey_timeout': 120, 'check_certificates_validity': True, 'token_lifetime': 86400}
2022-08-12 07:19:32,466 [wapttasks WaptTaskManager 6372] INFO Wapt tasks queue started
2022-08-12 07:19:32,523 [waptws SocketIOClient 6556] WARNING Exception ConnectionError(MaxRetryError("HTTPSConnectionPool(host='waptserver.domaine.local', port=443): Max retries exceeded with url: /get_websocket_auth_token (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x079AEEF8>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))")), waiting 2.6s before retrying
2022-08-12 07:19:35,272 [wapttasks SocketIOClient 6556] INFO Socketio connection params have changed. Socketio needs reconnect
2022-08-12 07:19:35,273 [wapttasks SocketIOClient 6556] INFO Creating socketio client: https://waptserver.domaine.local:443 client auth cert: ('C:\\Program Files (x86)\\wapt\\private\\4C4C4544-0035-4710-804A-B3C04F434233.crt', 'C:\\Program Files (x86)\\wapt\\private\\4C4C4544-0035-4710-804A-B3C04F434233.pem') proxies: None verify_cert: False
2022-08-12 07:19:35,273 [wapttasks SocketIOClient 6556] INFO Connecting Socketio to https://waptserver.domaine.local:443
2022-08-12 07:19:35,342 [wapttasks SocketIOClient 6556] INFO WS read loop for 120s
2022-08-12 07:19:42,847 [wapttasks WaptTaskManager 6372] INFO Add task Mise à jour de la liste des paquets disponibles to queue
2022-08-12 07:19:42,849 [wapttasks WaptTaskManager 6372] INFO Add task Audit de 8 packages (tâche #-1) to queue
2022-08-12 07:19:42,849 [wapttasks WaptTaskManager 6372] INFO Add task Informer le serveur du statut de cette machine to queue
2022-08-12 07:19:42,856 [wapttasks WaptTaskManager 6372] INFO Running task Mise à jour de la liste des paquets disponibles created by SCHEDULER
Get packages index from [<WaptRepo https://waptserver.domaine.local/wapt>, <WaptHostRepo https://waptserver.domaine.local/wapt-host for host_id 4C4C4544-0035-4710-804A-B3C04F434233 >]
2022-08-12 07:19:44,070 [wapttasks WaptTaskManager 6372] INFO update_server_status successful (data size 62647)
2022-08-12 07:19:44,098 [wapttasks WaptTaskManager 6372] INFO Running task Audit de 8 packages (tâche #2) created by SCHEDULER
Auditing pla-waptwua
Auditing pla-vcredist2015-2022
Auditing DC=Domaine=local
OK: No setup.py
Auditing pla-vcredist
Auditing pla-pyscripter4
 OK: Uninstall Key PyScripter_is1 in Windows Registry.
Auditing 4C4C4544-0035-4710-804A-B3C04F434233
OK: No setup.py
Auditing pla-fork
Auditing pla-waptupgrade
The installed version of the WAPT agent and the version of the package are corresponding.
2022-08-12 07:19:44,728 [wapttasks WaptTaskManager 6372] INFO Running task Informer le serveur du statut de cette machine created by SCHEDULER
2022-08-12 07:19:45,466 [wapttasks WaptTaskManager 6372] INFO update_server_status successful (data size 15541)
Done.
2022-08-12 07:20:42,297 [wapttasks waitress-0 5136] INFO Add task Mise à jour de la liste des paquets disponibles to queue
2022-08-12 07:20:42,297 [wapttasks WaptTaskManager 6372] INFO Running task Mise à jour de la liste des paquets disponibles created by None
Get packages index from [<WaptRepo https://waptserver.domaine.local/wapt>, <WaptHostRepo https://waptserver.domaine.local/wapt-host for host_id 4C4C4544-0035-4710-804A-B3C04F434233 >]
2022-08-12 07:21:19,375 [waptws SocketIOClient 6556] WARNING Exception ConnectionError(MaxRetryError("HTTPSConnectionPool(host='waptserver.domaine.local', port=443): Max retries exceeded with url: /get_websocket_auth_token (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x08490D18>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))")), waiting 5.0s before retrying
2022-08-12 07:21:24,508 [wapttasks SocketIOClient 6556] INFO Socketio connection params have changed. Socketio needs reconnect
2022-08-12 07:21:24,509 [wapttasks SocketIOClient 6556] INFO Connecting Socketio to https://waptserver.domaine.local:443
2022-08-12 07:21:24,558 [wapttasks SocketIOClient 6556] INFO WS read loop for 120s
2022-08-12 07:23:25,518 [wapttasks SocketIOClient 6556] INFO WS read loop for 120s
2022-08-12 07:25:26,489 [wapttasks SocketIOClient 6556] INFO WS read loop for 120s
2022-08-12 07:27:27,489 [wapttasks SocketIOClient 6556] INFO WS read loop for 120s

Clearly, the HTTPS connection isn't working properly, even though the server is reachable, can be resolved (nslookup), and pinged by the machine. The server is functional, and the computer is on the same wired network (and even the same site) as another working machine that remains connected. For the record, I should mention that:

This behavior is observed on both user workstations and workstations with the WAPT Console
The certificates are correctly deployed (I can see them in the "Certificates" tab of each affected machine)
A brief connection seems to be established, as I see that the workstations have connected at least once that same day
I'm using a self-signed SSL certificate, and I haven't enabled certificate verification in the agent configuration
I've added the agent configuration to the attachments

Regarding the events, I have taken some screenshots attached, but it translates quite well what we see in the log: there is a start-up, a crash at 07:19 and a restart at 07:21.

alain17 · August 12, 2022 - 09:28

The agent configuration wouldn't upload for editing on the forum, so I'm uploading it here

August 12, 2022 - 3:17 PM

Code: Select all

2022-08-12 07:21:19,375 [waptws SocketIOClient 6556] WARNING Exception ConnectionError(MaxRetryError("HTTPSConnectionPool(host='waptserver.domaine.local', port=443): Max retries exceeded with url: /get_websocket_auth_token (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x08490D18>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))")), waiting 5.0s before retrying

Code: Select all

getaddrinfo failed

That's strange, it seems like a DNS problem. Could you have two DNS servers pushed to the machines, one of which is unable to resolve the address of the WAPT server?

Otherwise, it could apparently be coming from a local http_proxy variable set on the machine?

https://stackoverflow-com.translate.goo ... r_pto=wapp

alain17 · August 15, 2022 - 09:32

Good morning

sfonteneau wrote: ↑August 12, 2022 - 3:17 PM
Code: Select all
2022-08-12 07:21:19,375 [waptws SocketIOClient 6556] WARNING Exception ConnectionError(MaxRetryError("HTTPSConnectionPool(host='waptserver.domaine.local', port=443): Max retries exceeded with url: /get_websocket_auth_token (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x08490D18>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))")), waiting 5.0s before retrying
Code: Select all
getaddrinfo failed
That's strange, it seems like a DNS problem. Could you have two DNS servers pushed to the machines, one of which is unable to resolve the address of the WAPT server?

That's also what seems strange to me. We're using two domain controllers (replicas) that also act as DNS servers (their IP addresses are correctly listed in ipconfig). I ran the following commands to check name resolution on both servers and I get the same (correct) response:

Code: Select all

nslookup waptserver.domaine.local dc01.domaine.local
nslookup waptserver.domaine.local dc02.domaine.local

sfonteneau wrote: ↑August 12, 2022 - 3:17 PM Otherwise, it could apparently come from an http_proxy variable set locally on the machine?

I checked, I don't have that kind of environment variable on my machines, and we don't use a proxy. Strangely, this morning more machines appeared connected, but not mine. I took the opportunity to run a test in Python, and it seems to be working correctly.

: wapt_addrinfo.png (11.98 KB) Viewed 7659 times

That said, I have an interesting lead: my computer shows as "disconnected" when I switch from the wired network to the company's Wi-Fi network. A similar behavior has been observed with other laptops. I replicated my NSLOOKUP and Python tests on both networks, and the results are identical. When the computer switches back to the wired network, the connection is restored.

For some reason I can't figure out, WAPT seems to have trouble switching from a wired to a wireless network. Have you observed this behavior as well?

August 17, 2022 - 10:20

In your network configuration, at the DNS level, is there no fallback to 8.8.8.8, for example?

Whether it's Wi-Fi or cable, it shouldn't be a problem; we're just re-establishing a connection.

The line `/get_websocket_auth_token` contacts the server to re-authenticate for the WebSocket,

but that's where we apparently have a DNS problem.

alain17 · August 19, 2022 - 11:33

sfonteneau wrote: ↑August 17, 2022 - 10:20 In your network configuration, at the DNS level, is there no fallback to 8.8.8.8 for example?

I do have a fallback to an external DNS server, but not for ".local" addresses, which are resolved internally. That said, I migrated to version 2.2.2 this week, and the deployment of the new agents seems to have brought greater stability. This might be thanks to one of the many fixes in this version. I'll keep an eye on it and open a new thread if necessary.

Thank you for your follow-up

August 19, 2022 - 12:11

alain17 wrote: ↑August 19, 2022 - 11:33 I do have a fallback on an external DNS, but not for addresses in ".local", which are resolved internally.

Overall, a fallback to an external DNS is not a good idea (and not just for Wapt)

Indeed, if for some reason the DNS server resolving .local doesn't respond, the request will fall back to the external DNS server if it responds. (And the external DNS server will respond, I don't know, and Windows will cache it.)

This problem has already been encountered in support here; removing the external DNS resolves the issues.