Bug 7552 - Web Access is still written in Python 2
Summary: Web Access is still written in Python 2
Status: CLOSED FIXED
Alias: None
Product: ThinLinc
Classification: Unclassified
Component: Web Access (show other bugs)
Version: trunk
Hardware: PC All
: P2 Normal
Target Milestone: 4.13.0
Assignee: Pierre Ossman
URL:
Keywords: frifl_tester, linma_tester, prosaic
Depends on: 7551 7553
Blocks: 4586
  Show dependency treegraph
 
Reported: 2020-09-09 10:05 CEST by Niko Lehto
Modified: 2021-07-14 09:32 CEST (History)
3 users (show)

See Also:
Acceptance Criteria:


Attachments

Description Niko Lehto cendio 2020-09-09 10:05:55 CEST
Python 2 is getting old and unsupported so we should rewrite the parts of Web Access that uses Python 2 to python 3.
Comment 49 Pierre Ossman cendio 2020-10-26 09:42:11 CET
We're not handling encoding properly in server.py:

> 2020-10-26 09:26:52 INFO tlwebaccess[25901]: [::ffff:10.47.1.240] 'GET /?submitbutton=Go+to+the+login+page HTTP/1.1' 200 -
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240] ----------------------------------------
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240] Exception happened during processing of request from ('::ffff:10.47.1.240', 49664, 0, 0)
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240] Traceback (most recent call last):
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/forkingserver.py", line 61, in process_request
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self . finish_request ( request , client_address )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 464, in finish_request
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     HTTPSServer . finish_request ( self , request , client_address )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 311, in finish_request
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     TLSServer . finish_request ( self , request , client_address )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/tlstunnel.py", line 95, in finish_request
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self . TLSRequestHandlerClass ( request , client_address , self )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 85, in __init__
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     client_address , server )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/usr/lib/python3.6/socketserver.py", line 724, in __init__
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self.handle()
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 285, in handle
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     RequestHandlerClass . handle ( self )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/usr/lib/python3.6/http/server.py", line 418, in handle
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self.handle_one_request()
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/websocketserver.py", line 47, in handle_one_request
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     super(WebSocketRequestHandlerMixIn, self).handle_one_request()
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 113, in handle_one_request
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     BaseHTTPRequestHandler . handle_one_request ( self )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/usr/lib/python3.6/http/server.py", line 406, in handle_one_request
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     method()
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/websocketserver.py", line 62, in _websocket_do_GET
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self.do_GET()
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 79, in do_GET
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self . post_or_get ( "do_GET" , I1i1Ii )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 129, in post_or_get
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self . _write ( 200 , i1IIiII11 , OooOoo0OO0OO0 )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 168, in _write
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self . wfile . write ( body )
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]   File "/usr/lib/python3.6/socketserver.py", line 803, in write
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240]     self._sock.sendall(b)
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240] TypeError: a bytes-like object is required, not 'str'
> 2020-10-26 09:26:52 ERROR tlwebaccess[25901]: [::ffff:10.47.1.240] ----------------------------------------
Comment 50 Samuel Mannehed cendio 2020-10-27 09:25:05 CET
I get this traceback in the session log when starting a new session:

> Traceback (most recent call last):
>   File "libexec/tl-set-sso-helper", line 68, in <module>
>     I1IiI ( )
>   File "libexec/tl-set-sso-helper", line 53, in I1IiI
>     OoOooOOOO = sso . set_password ( O0o )
>   File "/opt/thinlinc/modules/thinlinc/sso.py", line 161, in set_password
>     return _set_sso_attribute("TL_SSO_PASSWORD", new_passwd)
>   File "/opt/thinlinc/modules/thinlinc/sso.py", line 129, in _set_sso_attribute
>     key = _encryption_key()
>   File "/opt/thinlinc/modules/thinlinc/sso.py", line 84, in _encryption_key
>     return ctccommon.derive_from_sessionkey("sso", 256)
> AttributeError: 'module' object has no attribute 'derive_from_sessionkey'
Comment 60 Niko Lehto cendio 2020-10-27 15:09:35 CET
Tested the following for r35575:
- Standard session handling, reconnect
- Sound redirection
- Graphical updates
- Normal usage Native client and Webclient (Firefox 81)
- tlwebadm
- thinlocal printing

Scripts:
- tl-notify
- tl-unmount-localdrives
- tl-mount-localdrives
- tl-session-param
- tl-wait-smartcard
- tl-serial-redir
Comment 65 Niko Lehto cendio 2020-11-02 13:07:49 CET
After changes done in r35587, we can no longer log in via webaccess. We get the following message in tlwebaccess.log:
> 2020-11-02 11:27:39 ERROR tlwebaccess[3391]: [::ffff:10.47.1.20] Failed authorization for user 'test': Invalid authorization cookie.
> 2020-11-02 11:27:39 ERROR tlwebaccess[3391]: [::ffff:10.47.1.20] code 401, message Unauthorized
> 2020-11-02 11:27:39 INFO tlwebaccess[3391]: [::ffff:10.47.1.20] 'GET /websocket/test/10/YTRhNzM2NzA2NTYwNGQwMWY1ODE5ZTRhMDg2YmQyZjIzMDQzMjc0ZDdmMWRiMWI2NzdmYjkxYWEzMmFiMjRlNWQwMmY5NzEyMzk1OGE5YTA3ZGIwODc3ODYxZjVhMTJkYTk4NTI5ZTcyNGI0MjU0YzY2YTZiNzEwODU1MDBkYjAzMTM2MzAzNDMzMzEzMjM4MzUzOCQxNjA0MzEyODU4JDYxZTUwNGFmZjg1ZTE2NWMyODRiOWRjYjgyNTNmNTdhMmQ2NDI3ZTY1NDg1ZWIzY2QyOGEwNzZjMjhjYTI0MTQ4MDY3Y2M3NWZhYzI1NmJjMGVjNzg0NWZlMWNkOGUzZDBkNGI2ZGZiZTkxMjM1OTBkYTViMDY2YTE5MGU4NmY4 HTTP/1.1' 401 -
Comment 68 Niko Lehto cendio 2020-11-09 15:16:43 CET
Re-tested webaccess, this works good now after r35642. Tested connecting, reconnecting and standard usage in Firefox 81.
Tlwebaccess works good too.
Comment 69 Niko Lehto cendio 2020-11-09 15:17:27 CET
(In reply to Niko Lehto from comment #68)
> Tlwebaccess* works good too.
*tlwebadm
Comment 71 Niko Lehto cendio 2020-11-10 09:26:23 CET
Tested with a build containing r35646 changes, tested:
Webaccess
  - Standard login/reconnect
  - Standard usage
  - Graphical updates

Native 4.12
  - Login/reconnect/end existing
  - Sound
  - Standard usage

Webadmin
  - Sessioninfo
  - Terminating session
  - System health checks

Scripts
  - tl-mount-local-drives
  - tl-umount-local-drives
  - tl-session-param

Looks good.
Comment 81 Pierre Ossman cendio 2020-11-11 13:28:28 CET
Should be all done now.

Things we've changed and need testing:

tlwebaccess:

 * Everything

tlwebadm:

 * Status page (calls to vsmserver)¹
 * stdio redirection (/dev/null and log)
 * pid file creation
 * Authentication

vsmserver:

 * stdio redirection (/dev/null and log)
 * pid file creation

vsmagent:

 * stdio redirection (/dev/null and log)
 * pid file creation
 * vncpasswd (normal login, shadowing)
 * cookie generation
 * port and display allocation
 * port freeing
 * session polling
 * port redirection limiting

sso:

 * storing and reading (e.g. across an upgrade)

local drives:

 * mounting/unmounting¹

printing:

 * thinlocal¹
 * nearest

misc:

 * tl-notify¹
 * tl-session-param¹
 * tl-wait-smartcard¹
 * tl-serial-redir¹


¹ Already tested
Comment 83 Pierre Ossman cendio 2020-11-12 13:37:56 CET
Testing on SLES 12:

tlwebadm:

 ✓ stdio redirection (/dev/null and log)
 ✓ pid file creation
 ✓ Authentication (checked conf, bad pass, good pass, new pass with tl-gen-auth)

vsmserver:

 ✓ stdio redirection (/dev/null and log)
 ✓ pid file creation

vsmagent:

 ✓ stdio redirection (/dev/null and log)
 ✓ pid file creation
 ✓ vncpasswd (normal login, shadowing)
 ✓ cookie generation (look random, and work)
 ✓ port and display allocation
 ✓ port freeing
 ✓ session polling
 ✓ port redirection limiting
Comment 86 Niko Lehto cendio 2020-11-17 13:39:19 CET
tlwebaccess/main.py cointains an errcode, ETIMEDOUT, this is an undeclared variable at the moment and will give a trace back when user login is timed out for the in webaccess.
Comment 88 Pierre Ossman cendio 2020-11-18 13:12:47 CET
More testing on SLES 12:

printing:

 ✓ nearest

That should be all testing for non-tlwebaccess stuff.
Comment 91 Pierre Ossman cendio 2020-11-18 14:57:14 CET
Tested on SLES 12:

Authentication:

 ✓ Normal password (OK/FAIL)
 ✓ Password expiration warning
 ✓ Password change
 ✓ Expired account
 ✓ Locked account

Sessions:

 ✓ New session
 ✓ Reconnect session
 ✓ Session unreachable
Comment 92 Niko Lehto cendio 2020-11-18 16:21:48 CET
Tested on RHEL8:

✓ Normal login
✓ Basic functions
✓ Session handling
   ✓ New session
   ✓ Reconnect session
✓ Clipboard redirection

OTP still needs testing. Could not test this on RHEL8, see Bug 7591.
Comment 93 Niko Lehto cendio 2020-11-19 08:45:04 CET
Tested OTP with google-authenticator on nightly build in Ubuntu 20.04, and it works well.
Comment 94 Pierre Ossman cendio 2020-11-19 11:27:11 CET
Tested on SLES 12:

 ✓ Unicode username/password/homedir on UTF-8 system (båss€/l€nux99)

Had to patch around a bug in the profile chooser for non-ASCII in $PATH though. Not filing a bugzilla bug for it as it will resolve itself when switching to Python 3.
Comment 95 Pierre Ossman cendio 2020-11-19 12:56:30 CET
Tested on SLES 12:

 ✓ Login timeout
 ✓ Not allowed to create more sessions
 ✓ Correct session handling with multiple sessions
Comment 96 Niko Lehto cendio 2020-11-20 10:35:50 CET
Tested on Latin-9 RHEL8 system:

  ✓ Unicode username/password/homedir (Username: böngt Passwd: böngt)

Also had to patch the bug described in #94. Found Bug 7593 (Not related to web access testing).

Log in / session handling works well.
Comment 97 Pierre Ossman cendio 2020-11-20 10:38:02 CET
Everything seems to be working fine. Tester can see the last few comments for areas interesting for testing.
Comment 101 Pierre Ossman cendio 2020-12-01 13:45:17 CET
We're not closing some files and process like we should:

> /usr/lib64/python3.8/subprocess.py:942: ResourceWarning: subprocess 1833438 is still running
>   _warn("subprocess %s is still running" % self.pid,
> ...
>   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/pamconversation.py", lineno 120
>     self . p = subprocess . Popen ( I111II111I1I ,

and:

> /opt/thinlinc/modules/thinlinc/tlwebaccess/session.py:27: ResourceWarning: unclosed <socket.socket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 42678), raddr=('127.0.0.1', 9000)>
>   self . _vsmconnect ( )

and:

> /opt/thinlinc/modules/thinlinc/tlwebaccess/server.py:91: ResourceWarning: unclosed <socket.socket fd=5, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, raddr=/var/run/thinlinc/master/1000>
>   OooOoo0OO0OO0 = main . handle_request ( self . server . hive ,

and:

> /opt/thinlinc/modules/thinlinc/sessioninfo.py:121: ResourceWarning: unclosed file <_io.TextIOWrapper name='/proc/1833520/cmdline' mode='r' encoding='UTF-8'>
>   for II1iiii in open ( "/proc/%s/cmdline" % oooOOOooo ) . read ( ) . split ( '\0' ) :

and:

> /opt/thinlinc/modules/thinlinc/sessioninfo.py:134: ResourceWarning: unclosed file <_io.TextIOWrapper name='/proc/1833520/status' mode='r' encoding='UTF-8'>
>   for II1iiii in open ( "/proc/%s/status" % oooOOOooo ) . readlines ( ) :
Comment 103 Pierre Ossman cendio 2020-12-03 10:46:35 CET
We also have this deprecation warning that we should examine:

> /opt/thinlinc/modules/thinlinc/unixxmlrpc.py:59: DeprecationWarning: urllib.parse.splittype() is deprecated as of 3.8, use urllib.parse.urlparse() instead
Comment 105 Niko Lehto cendio 2020-12-03 14:11:10 CET
Could reproduce these warnings on Ubuntu 20.04 that uses Python 3.8. Could not reproduce on RHEL8 using Python 3.6 nor 3.8.

Left to do:
Unclosed subprocess: 
> /usr/lib64/python3.8/subprocess.py:942: ResourceWarning: subprocess 1833438 is still running
>   _warn("subprocess %s is still running" % self.pid,
> ...
>   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/pamconversation.py", lineno 120
>     self . p = subprocess . Popen ( I111II111I1I ,
Unclosed sockets:
> /opt/thinlinc/modules/thinlinc/tlwebaccess/session.py:27: ResourceWarning: unclosed <socket.socket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 42678), raddr=('127.0.0.1', 9000)>
>   self . _vsmconnect ( )
and
> /opt/thinlinc/modules/thinlinc/tlwebaccess/server.py:91: ResourceWarning: unclosed <socket.socket fd=5, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, raddr=/var/run/thinlinc/master/1000>
>   OooOoo0OO0OO0 = main . handle_request ( self . server . hive ,
Deprecation warning:
> > /opt/thinlinc/modules/thinlinc/unixxmlrpc.py:59: DeprecationWarning: urllib.parse.splittype() is deprecated as of 3.8, use urllib.parse.urlparse() instead
Comment 110 Niko Lehto cendio 2020-12-08 10:02:48 CET
Tested on Ubuntu 20.04 with python 3.8:
 - Login
 - Reconnect to session

Works well and I saw no warnings in tlwebaccess.log

As a side note:
"UnixServerProxy" can be used as context manager from Python 3.5 and onwards, but since we need to support Python 3.4 we must close this socket manually. (Done in r35852)
Comment 111 Niko Lehto cendio 2020-12-09 15:12:19 CET
The subprocess that is warned about is the subprocess starting tl-pamapp located in new_session() of pamconversation.py.

For us to see that this subprocess closes correctly we need to retain reference to the subprocess, which in the current state will be hard. And probably require restructuring of code.

The reference will be retained in the object which is used to start a new pam-session, but will be lost if the login is suspended to facilitate for e.g. password change or OTP. This is because a new pamconversation obj. is created with just the session id for reconnect.

Another solution is to ignore this warning, because to my understanding the tl-pamapp process will be closed automatically if left alone. But we should to do it correctly if possible (The former solution.).
Comment 112 Pierre Ossman cendio 2020-12-10 12:47:43 CET
It seems upstream doesn't seem to care for our use case here:

https://bugs.python.org/issue27068

Long term we should probably move to doing a fork() and exec() manually. However that is a lot of work, and subprocess seems to work well enough for us for now. So let's silence the warning from subprocess the same way Python's own asyncio module does.
Comment 114 Pierre Ossman cendio 2020-12-10 12:55:02 CET
Every warning is now resolved as far as I can test on Python 3.8 (on Fedora 32). Should be ready for testing again.
Comment 115 Frida Flodin cendio 2020-12-11 14:13:44 CET
Got a DeprecationWarning with Python 3.8.2 on Ubuntu20.04. These methods seems to be removed in 3.9.

> /opt/thinlinc/modules/thinlinc/websocket.py:899: DeprecationWarning: fromstring() is deprecated. Use frombytes() instead.
>  f['payload'] = self._unmask(buf[hlen:(hlen+length)], mask_key)
> /opt/thinlinc/modules/thinlinc/websocket.py:899: DeprecationWarning: tostring() is deprecated. Use tobytes() instead.
>  f['payload'] = self._unmask(buf[hlen:(hlen+length)], mask_key)



Got the following traceback when logging in when running webaccess with Python 3.9:

> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30] ----------------------------------------
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30] Exception happened during processing of request from ('::ffff:10.47.1.30', 51152, 0, 0)
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30] Traceback (most recent call last):
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/forkingserver.py", line 61, in process_request
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     self . finish_request ( request , client_address )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 451, in finish_request
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     super ( ) . finish_request ( request , client_address )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 300, in finish_request
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     super ( ) . finish_request ( request , client_address )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/tlstunnel.py", line 71, in finish_request
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     self . TLSRequestHandlerClass ( request , client_address , self )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 75, in __init__
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     super ( ) . __init__ ( request , client_address , server )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/usr/lib/python3.9/socketserver.py", line 720, in __init__
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     self.handle()
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 275, in handle
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     super ( ) . handle ( )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/usr/lib/python3.9/http/server.py", line 427, in handle
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     self.handle_one_request()
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocketserver.py", line 47, in handle_one_request
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     super(WebSocketRequestHandlerMixIn, self).handle_one_request()
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/httpserver.py", line 103, in handle_one_request
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     super ( ) . handle_one_request ( )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/usr/lib/python3.9/http/server.py", line 415, in handle_one_request
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     method()
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocketserver.py", line 60, in _websocket_do_GET
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     self.handle_upgrade()
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 228, in handle_upgrade
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     super ( ) . handle_upgrade ( oOoo0OOOOOoo , self . path )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocketserver.py", line 87, in handle_upgrade
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     self.handle_websocket()
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 310, in handle_websocket
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     self . _do_proxy ( O0o )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", line 378, in _do_proxy
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     o0oOoOoO = self . request . recv ( )
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocket.py", line 371, in recv
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     return self.recvmsg()
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocket.py", line 403, in recvmsg
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     if not self._recv_frames():
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocket.py", line 619, in _recv_frames
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     frame = self._decode_hybi(self._recv_buffer)
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocket.py", line 899, in _decode_hybi
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     f['payload'] = self._unmask(buf[hlen:(hlen+length)], mask_key)
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]   File "/opt/thinlinc/modules/thinlinc/websocket.py", line 808, in _unmask
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30]     data.fromstring(buf)
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30] AttributeError: 'array.array' object has no attribute 'fromstring'
> 2020-12-11 13:07:13 ERROR tlwebaccess[10627]: [::ffff:10.47.1.30] ----------------------------------------
>
Comment 117 Pierre Ossman cendio 2020-12-14 16:39:53 CET
For some odd reason I'm not getting that DeprecationWarning with Fedora 32's Python 3.8.6.

Still, I've swapped out those calls now to something current.
Comment 118 Pierre Ossman cendio 2020-12-15 09:24:58 CET
We're still using the deprecated socket.error in these modules. Let's try to avoid that since it might be removed in future Python versions.
Comment 122 Pierre Ossman cendio 2020-12-15 12:55:19 CET
All fixed. Tester needs to check:

 * Simple login

 * Login timeout (e.g. waiting for OTP, or password change)

 * WebSocket traffic (graphics updates and mouse/keyboard input)
Comment 123 Frida Flodin cendio 2020-12-18 13:54:04 CET
I have now tested running webaccess with Python 3.9.0 on Ubuntu20.04 from Firefox 78.0. Seems to work fine. What I have tested:

  - [X] Login
    - [X] Normal login
    - [X] Login timeout during password change
  - [X] Basic functions/Standard usage
  - [X] Graphical updates
  - [X] Session handling
    - [X] New session
    - [X] Reconnect session
    - [X] Not allowed to create more sessions
    - [X] Session unreachable
    - [X] Correct session handling with multiple sessions
  - [X] Clipboard redirection
  - [X] Authentication
    - [X] Normal password (OK/FAIL)
    - [X] Password expiration warning
    - [X] Password change
    - [X] Expired account
    - [X] Locked account
    - [X] OTP with google-authenticator
    - [X] Unicode username/password/homedir on UTF-8 system (test€r/€)
    - [ ] Unicode on Latin-9 system (Found bug 7613, so not tested)

Also need to test all dependencies that is affected by this bug before closing.
Comment 124 Frida Flodin cendio 2020-12-18 14:58:48 CET
Finished testing affected parts of the product. Only two scripts are not tested; tl-wait-smartcard and tl-serial-redir. A complete list of what I have tested follows bellow. All was tested with server on Ubuntu20.04. 

  - [X] Native client 4.12 
    - [X] Login/reconnect/end existing
    - [X] Sound
    - [X] Standard usage
  - [X] Printing (Tested on bug 7554)
    - [X] thinlocal
    - [X] nearest
    - [X] Respooling
  - [X] tlwebadm (With Python 3.9)
    - [X] stdio redirection (/dev/null and log)
    - [X] pid file creation
    - [X] Authentication (checked conf, bad pass, good pass, new pass with tl-gen-auth, '€' password on server with Latin-9)
    - [X] Status page (calls to vsmserver)
    - [X] Sessioninfo
    - [X] Terminating session
    - [X] System health checks
  - [X] vsmserver
    - [X] stdio redirection (/dev/null and log)
    - [X] pid file creation
  - [X] vsmagent
    - [X] stdio redirection (/dev/null and log)
    - [X] pid file creation
    - [X] vncpasswd (normal login, shadowing)
    - [X] cookie generation (look random, and work)
    - [X] port and display allocation
    - [X] port freeing
    - [X] session polling
    - [X] port redirection limiting
  - [X] sso (Tested on bug 7554)
    - [X] storing and reading (e.g. across an upgrade)
  - [X] local drives
    - [X] mounting/unmounting
  - [-] scripts
    - [X] tl-notify
    - [X] tl-session-param
    - [ ] tl-wait-smartcard
    - [ ] tl-serial-redir
    - [X] tl-unmount-localdrives
    - [X] tl-mount-localdrives
Comment 125 Linn cendio 2020-12-21 14:09:26 CET
- [X] tl-wait-smartcard (Tested on Ubuntu 20.04, and the script is executed when
                         logging in)
- [-] tl-serial-redir (Doesn't work, and should not be tested. Ignoring)

With that, everything is tested. Closing!
Comment 126 Frida Flodin cendio 2021-01-21 15:36:37 CET
Found a ResourceWarning that happens very rarely. One way I could reproduce it was when logging in with 3 different users and running glxgears in all sessions. Then doing a hard kill on the browser (killall -9). I could not reproduce it every time.


This is the warning I got when running with tracemalloc:


> 2021-01-21 13:41:26 ERROR tlwebaccess[17578]: [::ffff:10.47.1.30] gnutls_record_recv: The TLS connection was non-properly terminated.
> 2021-01-21 13:41:26 ERROR tlwebaccess[17244]: [::ffff:10.47.1.30] gnutls_record_recv: The TLS connection was non-properly terminated.
> 2021-01-21 13:41:26 ERROR tlwebaccess[17244]: [::ffff:10.47.1.30] gnutls_bye: The specified session has been invalidated for some reason.
> 2021-01-21 13:41:26 ERROR tlwebaccess[17578]: [::ffff:10.47.1.30] gnutls_bye: The specified session has been invalidated for some reason.
> 2021-01-21 13:41:26 ERROR tlwebaccess[18030]: [::ffff:10.47.1.30] gnutls_record_recv: The TLS connection was non-properly terminated.
> /opt/thinlinc/modules/thinlinc/httpserver.py:81: ResourceWarning: unclosed <socket.socket fd=3, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 43508), raddr=('127.0.0.1', 5912)>
>   if 29 - 29: IiIIii11Ii - oOo0O00
> Object allocated at (most recent call last):
>   File "/opt/thinlinc/modules/thinlinc/websocketserver.py", lineno 50
>     self.handle_upgrade()
>   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", lineno 228
>     super ( ) . handle_upgrade ( oOoo0OOOOOoo , self . path )
>   File "/opt/thinlinc/modules/thinlinc/websocketserver.py", lineno 77
>     self.handle_websocket()
>   File "/opt/thinlinc/modules/thinlinc/tlwebaccess/server.py", lineno 304
>     O0o = socket . create_connection ( ( self . target_host , self . target_port ) )
>   File "/usr/lib/python3.8/socket.py", lineno 791
>     sock = socket(af, socktype, proto)
Comment 130 Niko Lehto cendio 2021-02-02 10:25:24 CET
After the latest commit we should now at least close the socket whenever we encounter errors.
We don't have to see that shutdown() is called before close() because at that point we have already encountered an error and just want to close the socket.

Because I can't at this point reproduce the original error, tester can throw manual errors in the code and see if we get a resource warning of unclosed socket.
Comment 131 Niko Lehto cendio 2021-02-02 15:08:30 CET
(In reply to Frida from comment #126)
I cannot reproduce this resource warning. I have tried the same way described here.
Ubuntu 20.04 server were used for all my testing.
The Webaccess used was mostly on Chrome, but also a few times on Firefox.

Tried if desktop environment could impact this, so I have tried using gnome and xfce.

The testing scenarios I tried to try to reproduce this warning with were:
  - Multiple tabs with logged in users (3-4)
  - Multiple windows with logged in user (3-4)
In both scenarios all users were running glxgears and the browser were killed by using 'killall -9 <browser>'

Also tried IE and Firefox on Windows 10.

As of commit r36091 we now close socket if errors are raised. This doesn't solve the error that caused our resource warning, but will close our socket correctly when it occurs. Our current theory is that it is an 'ConnectionError' that is raised at some point and this is handled higher up in httpserver.py and silenced there, see bug 7633.

Marking this bug as resolved as I can't reproduce the error.
Comment 132 Frida Flodin cendio 2021-02-08 14:10:30 CET
(In reply to Niko Lehto from comment #131)
I also have problem reproducing this now. But I can verify by manually raising ConnectionError that the socket now is closed in that scenario. Also tested normal behavior of Web Access and it works fine. Tested on RHEL 8 with Python 3.8.

Note You need to log in before you can comment on or make changes to this bug.