Broken out from bug 7636. See that bug for details. There are numerous circumstances where we, for different reasons, want to delay calls. We should make sure that all of them use asyncio's functionality for this.
All places that needed to be changed should now be fixed and tested, see below for my testing details. - extproc To test the timeout handling in extproc AsyncProcess I put two scripts in /opt/thinlinc/etc/sessionstartup.d/ , one that sleeps for 50 seconds and one that sleeps for 1 second. I can see in vsmserver.log that the first script hits timeout after 40 seconds and that the other script finishes. This to make sure that the timeout handling works correct and that the timeout is canceled when a script exits. - hander_reqsession Turned on debug level DEBUG3 and started a session. I can see the log message > 2023-09-13 09:42:15 DEBUG3 vsmagent.session: wait_on_vnc_port: Adding delayed call run at Wed Sep 13 09:42:15 2023 and then a new check within a second > 2023-09-13 09:58:03 DEBUG3 vsmagent.session: wait_on_vnc_port: Starting CheckTCPPortOpen on 5910 with timeout at Wed Sep 13 09:58:28 2023 This is repeated 4 times until we are connected and the session works as expected. - handler_vsmagent_terminatesession Tested by terminating a session with tlctl. We wait for the process to be killed with ´waitpid´ WNOHANG, so if the session is not immediately shut down we wait half a second before checking again. You can somewhat feel the little delay after you press 'y', can it be 0.5 second? I verified that the delayed call was actually scheduled by putting a log message in the code. - loadbalancer I can see in vsmserver.log that the load is updated with 40 seconds interval. I needed to put debug level DEBUG for this. - portopencheck I tested that the call_soon call works as expected, the same way as for handler_reqsession I did not find an easy way to test the timeout handling in portopencheck. Tested to netcat the next free vnc port and then ctrl-z it. The theory was that a connect to this socket should freeze portopen connect. But it didn't. I just got IN_USE and we tried the next display. bug 7930. - sessionstore Checked vsmserver.log that active session are written to disk when the sessionstore has changed. This is checked every with 30 second interval. Also checked that sessions are verified every 10 minutes. It can be seen in vsmserver.log. Checked that HA tries to transfer session update every second if it fails. This by enabling HA with a node that does not run a vsmserver. - usersocketserver I can see in vnmserver.log that the usersocketserver is removed after 3*40 seconds. - vsmagent I can see that housekeeping is done every 10th second. - vsmserver Updates the license data from disk twice a day, with 12 hour interval. Luckily I had my server on over the weekend, so I could see in the log that the licenses had been updated as expected. - xmlrpc just added a fake agent and the getloadcall will timeout.
I verified build 3385 on RHEL 9: After changing all log levels in vsmagent.hconf and vsmserver.hconf to DEBUG3, I then tailed vsmserver.log and vsmagent.log. In the logs, I could verify that: * Periodic load updates come regularly at the configured timeout. 40 seconds by default, and with "load_update_cycle=10", each 10 seconds: > 2023-09-20 16:45:08 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Wed Sep 20 16:45:18 2023 > 2023-09-20 16:45:18 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Wed Sep 20 16:45:28 2023 * Periodic load updates time out when the agent can't be reached: > 2023-09-20 16:45:48 WARNING vsmserver.loadinfo: Error talking to VSM agent asfaf:904 in request for loadinfo. Marking as down.: [Errno -2] Name or service not known > 2023-09-20 16:45:48 DEBUG3 vsmserver: loadstatus marking agent asfaf as down > 2023-09-20 16:45:48 DEBUG vsmserver: Scheduled load update of asfaf at Wed Sep 20 16:45:58 2023 * Sessionstore updates session info periodically: > 2023-09-20 16:54:48 DEBUG vsmserver.session: Doing periodic session verification > 2023-09-20 16:54:48 DEBUG2 vsmserver.session: Verifying sessions for 0 users * User sockets are removed on timeout as intended: > 2023-09-20 16:45:23 DEBUG2 vsmserver: Handling method create_user_socket > 2023-09-20 16:45:23 DEBUG vsmserver.session: User with uid 0 requested a socket > 2023-09-20 16:45:23 DEBUG2 vsmserver: Setting up removal of /var/run/thinlinc/master/0 at Wed Sep 20 16:47:23 2023 > 2023-09-20 16:47:23 DEBUG2 vsmserver: Removing /var/run/thinlinc/master/0 due to timeout * Terminate session works well: > 2023-09-20 17:16:01 DEBUG2 vsmserver: Handling method kill_session on socket owned by uid 0 > 2023-09-20 17:16:01 INFO vsmserver.session: User with uid 0 requested termination of 127.0.0.1:10 > 2023-09-20 17:16:01 DEBUG2 vsmagent: Handling method terminate_session > 2023-09-20 17:16:02 DEBUG3 vsmserver.session: Removing session for cendio * Port check on agent works well: > 2023-09-20 17:09:37 DEBUG3 vsmagent.session: wait_on_vnc_port: Starting CheckTCPPortOpen on 5910 with timeout at Wed Sep 20 17:10:02 2023 > 2023-09-20 17:09:37 DEBUG3 vsmagent.session: wait_on_vnc_port: Adding delayed call run at Wed Sep 20 17:09:37 2023 > 2023-09-20 17:09:37 DEBUG3 vsmagent.session: wait_on_vnc_port: Starting CheckTCPPortOpen on 5910 with timeout at Wed Sep 20 17:10:02 2023 * vsmagent housekeeping is done each 10 seconds: > 2023-09-20 16:45:36 DEBUG2 vsmagent: Waiting for children > 2023-09-20 16:45:36 DEBUG2 vsmagent: Updating dynamic load information > 2023-09-20 16:45:36 DEBUG2 vsmagent: Scheduling next housekeeping at Wed Sep 20 16:45:46 2023 > 2023-09-20 16:45:46 DEBUG2 vsmagent: Waiting for children > 2023-09-20 16:45:46 DEBUG2 vsmagent: Updating dynamic load information > 2023-09-20 16:45:46 DEBUG2 vsmagent: Scheduling next housekeeping at Wed Sep 20 16:45:56 2023 Also checked the commits and the code looks good. Closing.
