From 7f4896399da68a2b31cc4ea0e624aec1ff10e880 Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Wed, 17 Jul 2024 22:57:58 -0400 Subject: [PATCH 01/10] Sample use of logging config through a yaml file --- application/__init__.py | 15 +++++++++-- application/logging_default_config.yaml | 34 +++++++++++++++++++++++++ requirements.txt | 1 + 3 files changed, 48 insertions(+), 2 deletions(-) create mode 100644 application/logging_default_config.yaml diff --git a/application/__init__.py b/application/__init__.py index 1392cfa..88123e7 100644 --- a/application/__init__.py +++ b/application/__init__.py @@ -17,13 +17,22 @@ # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS # IN THE SOFTWARE. - +import logging.config +import yaml import os import sys +import logging_utils from flask import Flask, Blueprint from werkzeug.serving import WSGIRequestHandler +with open('logging_default_config.yaml', 'rt') as config_file: + config = yaml.safe_load(config_file.read()) + +logging.config.dictConfig(config) +logger = logging.getLogger(__file__) +logger.debug("successfully set up logger") + from .Profile.Profile import Profile # enable persistent HTTP connections (keep-alive) @@ -54,11 +63,13 @@ profiles: Profile if os.getenv('DBADDR') is not None: from .Profile.DBProfile import DBProfile + profiles = DBProfile(app) else: from .Profile.LocalProfile import LocalProfile + profiles = LocalProfile() api = Blueprint('api', __name__) -from .routes import * +from .routes import * \ No newline at end of file diff --git a/application/logging_default_config.yaml b/application/logging_default_config.yaml new file mode 100644 index 0000000..6fda32a --- /dev/null +++ b/application/logging_default_config.yaml @@ -0,0 +1,34 @@ +version: 1 +disable_existing_loggers: False + +formatters: + default_formatter: + format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s' + datefmt: '%Y-%m-%d %H:%M:%S' + +handlers: + console: + class: logging.StreamHandler + level: DEBUG + formatter: default_formatter + stream: ext://sys.stdout + +loggers: + development: + level: DEBUG + handlers: [console] + propagate: no + + staging: + level: INFO + handlers: [console] + propagate: no + + production: + level: WARNING + handlers: [console] + propagate: no + +root: + level: DEBUG + handlers: [console] diff --git a/requirements.txt b/requirements.txt index b018ee3..0de82e6 100644 --- a/requirements.txt +++ b/requirements.txt @@ -12,4 +12,5 @@ Werkzeug==2.2.2 zipstream-new==1.1.8 paramiko==3.0.0 numpy==1.24.2 +pyyaml==6.0.1 git+https://github.com/junhaoliao/simple-websocket-server#egg=SimpleWebSocketServer From 2881593dbe5d071aac99855b7e25573bdda4fd9a Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Wed, 17 Jul 2024 23:14:41 -0400 Subject: [PATCH 02/10] remove local changes not available to others --- application/__init__.py | 1 - 1 file changed, 1 deletion(-) diff --git a/application/__init__.py b/application/__init__.py index 88123e7..d789ae1 100644 --- a/application/__init__.py +++ b/application/__init__.py @@ -21,7 +21,6 @@ import yaml import os import sys -import logging_utils from flask import Flask, Blueprint from werkzeug.serving import WSGIRequestHandler From f9fb42db47ec5812e7536ab7f91e1470d097c8d7 Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Sat, 20 Jul 2024 10:43:43 -0400 Subject: [PATCH 03/10] Fixed bug to renew password on UG machine due to system upgrade --- application/features/VNC.py | 24 +++++++++++++++++------- application/routes/vnc.py | 7 ++++++- 2 files changed, 23 insertions(+), 8 deletions(-) diff --git a/application/features/VNC.py b/application/features/VNC.py index 20325a2..945f461 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -20,6 +20,7 @@ import os import re +import logging import threading from .Connection import Connection @@ -28,6 +29,8 @@ from ..resources.xstartup import XSTARTUP_STR from ..utils import find_free_port +logger = logging.getLogger(__name__) + def websocket_proxy_thread(local_websocket_port, local_vnc_port): if os.environ.get('SSL_CERT_PATH') is None: @@ -65,8 +68,10 @@ def connect(self, *args, **kwargs): return super().connect(*args, **kwargs) def get_vnc_password(self): - _, _, stdout, _ = self.exec_command_blocking('xxd -p ~/.vnc/passwd') - hexdump = stdout.readline() + # return True, "123456" + _, _, stdout, _ = self.exec_command_blocking("hexdump --format '16/1 \"%02x\"' ~/.vnc/passwd") + hexdump = stdout.readline().rstrip() + logger.info(f"hexdump = {hexdump}") if hexdump == '': return False, '' else: @@ -96,7 +101,7 @@ def remove_vnc_settings(self): return True, '' def reset_vnc_password(self, password): - hexed_passwd = obfuscate_password(password).hex() + # hexed_passwd = obfuscate_password(password).hex() reset_cmd_lst = [ # killall -q: don't complain if no process found @@ -108,16 +113,20 @@ def reset_vnc_password(self, password): "rm -rf ~/.vnc", "mkdir ~/.vnc", - f"printf '{XSTARTUP_STR}' > ~/.vnc/xstartup", - "cp /etc/vnc/xstartup ~/.vnc >& /dev/null", - "chmod 700 ~/.vnc/xstartup", + # FIXME: re-enable xstartup config + # f"printf '{XSTARTUP_STR}' > ~/.vnc/xstartup", + # "cp /etc/vnc/xstartup ~/.vnc >& /dev/null", + # "chmod 700 ~/.vnc/xstartup", - "echo '%s'| xxd -r -p > ~/.vnc/passwd" % hexed_passwd, + "echo '%s'| vncpasswd -f > ~/.vnc/passwd" % password, "chmod 600 ~/.vnc/passwd", ] + logger.debug(f"reset_cmd_lst={reset_cmd_lst}") _, _, _, stderr = self.exec_command_blocking(';'.join(reset_cmd_lst)) error_lines = [] for line in stderr: + logger.error("reset_vnc_password::exec_command_blocking stderr line: %s", line) + if "Disk quota exceeded" in line: return False, 'Disk quota exceeded' else: @@ -128,6 +137,7 @@ def reset_vnc_password(self, password): return True, '' def launch_vnc(self): + logger.debug("launch_vnc") ports_by_me = [] _, _, stdout, _ = self.exec_command_blocking('vncserver -list') for line in stdout: diff --git a/application/routes/vnc.py b/application/routes/vnc.py index 289f014..6d8653a 100644 --- a/application/routes/vnc.py +++ b/application/routes/vnc.py @@ -26,7 +26,8 @@ from .. import api, app, profiles from ..codes import ICtrlStep, ICtrlError, ConnectionType from ..utils import int_to_bytes - +import logging +logger = logging.getLogger(__name__) @api.route('/vnc', methods=['POST']) def start_vnc(): @@ -97,15 +98,19 @@ def generate(): @api.route('/vncpasswd', methods=['POST']) def change_vncpasswd(): + logger.debug("in route /vncpasswd") session_id = request.json.get('session_id') vnc, reason = create_connection(session_id, ConnectionType.VNC) if reason != '': + logger.error("create_connection() failed with status=", status) abort(403, description=reason) passwd = request.json.get('passwd') status, reason = vnc.reset_vnc_password(passwd) + if not status: + logger.error("reset_vnc_password() failed with status=%s", reason) abort(403, description=reason) return 'success' From d15ec58951a99b7586e79ac0af47ef7979beebb9 Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Sat, 20 Jul 2024 17:10:57 -0400 Subject: [PATCH 04/10] Revert "Fixed bug to renew password on UG machine due to system upgrade" This reverts commit f9fb42db47ec5812e7536ab7f91e1470d097c8d7. --- application/features/VNC.py | 24 +++++++----------------- application/routes/vnc.py | 7 +------ 2 files changed, 8 insertions(+), 23 deletions(-) diff --git a/application/features/VNC.py b/application/features/VNC.py index 945f461..20325a2 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -20,7 +20,6 @@ import os import re -import logging import threading from .Connection import Connection @@ -29,8 +28,6 @@ from ..resources.xstartup import XSTARTUP_STR from ..utils import find_free_port -logger = logging.getLogger(__name__) - def websocket_proxy_thread(local_websocket_port, local_vnc_port): if os.environ.get('SSL_CERT_PATH') is None: @@ -68,10 +65,8 @@ def connect(self, *args, **kwargs): return super().connect(*args, **kwargs) def get_vnc_password(self): - # return True, "123456" - _, _, stdout, _ = self.exec_command_blocking("hexdump --format '16/1 \"%02x\"' ~/.vnc/passwd") - hexdump = stdout.readline().rstrip() - logger.info(f"hexdump = {hexdump}") + _, _, stdout, _ = self.exec_command_blocking('xxd -p ~/.vnc/passwd') + hexdump = stdout.readline() if hexdump == '': return False, '' else: @@ -101,7 +96,7 @@ def remove_vnc_settings(self): return True, '' def reset_vnc_password(self, password): - # hexed_passwd = obfuscate_password(password).hex() + hexed_passwd = obfuscate_password(password).hex() reset_cmd_lst = [ # killall -q: don't complain if no process found @@ -113,20 +108,16 @@ def reset_vnc_password(self, password): "rm -rf ~/.vnc", "mkdir ~/.vnc", - # FIXME: re-enable xstartup config - # f"printf '{XSTARTUP_STR}' > ~/.vnc/xstartup", - # "cp /etc/vnc/xstartup ~/.vnc >& /dev/null", - # "chmod 700 ~/.vnc/xstartup", + f"printf '{XSTARTUP_STR}' > ~/.vnc/xstartup", + "cp /etc/vnc/xstartup ~/.vnc >& /dev/null", + "chmod 700 ~/.vnc/xstartup", - "echo '%s'| vncpasswd -f > ~/.vnc/passwd" % password, + "echo '%s'| xxd -r -p > ~/.vnc/passwd" % hexed_passwd, "chmod 600 ~/.vnc/passwd", ] - logger.debug(f"reset_cmd_lst={reset_cmd_lst}") _, _, _, stderr = self.exec_command_blocking(';'.join(reset_cmd_lst)) error_lines = [] for line in stderr: - logger.error("reset_vnc_password::exec_command_blocking stderr line: %s", line) - if "Disk quota exceeded" in line: return False, 'Disk quota exceeded' else: @@ -137,7 +128,6 @@ def reset_vnc_password(self, password): return True, '' def launch_vnc(self): - logger.debug("launch_vnc") ports_by_me = [] _, _, stdout, _ = self.exec_command_blocking('vncserver -list') for line in stdout: diff --git a/application/routes/vnc.py b/application/routes/vnc.py index 6d8653a..289f014 100644 --- a/application/routes/vnc.py +++ b/application/routes/vnc.py @@ -26,8 +26,7 @@ from .. import api, app, profiles from ..codes import ICtrlStep, ICtrlError, ConnectionType from ..utils import int_to_bytes -import logging -logger = logging.getLogger(__name__) + @api.route('/vnc', methods=['POST']) def start_vnc(): @@ -98,19 +97,15 @@ def generate(): @api.route('/vncpasswd', methods=['POST']) def change_vncpasswd(): - logger.debug("in route /vncpasswd") session_id = request.json.get('session_id') vnc, reason = create_connection(session_id, ConnectionType.VNC) if reason != '': - logger.error("create_connection() failed with status=", status) abort(403, description=reason) passwd = request.json.get('passwd') status, reason = vnc.reset_vnc_password(passwd) - if not status: - logger.error("reset_vnc_password() failed with status=%s", reason) abort(403, description=reason) return 'success' From f3d3c36082126db2226072cfc506b7a07a3f1bb0 Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Sun, 21 Jul 2024 10:37:58 -0400 Subject: [PATCH 05/10] Logging setup changes from code review with Junhao --- application/__init__.py | 17 ++++++++----- application/logging_default_config.yaml | 34 ------------------------- log_config.yaml | 18 +++++++++++++ 3 files changed, 28 insertions(+), 41 deletions(-) delete mode 100644 application/logging_default_config.yaml create mode 100644 log_config.yaml diff --git a/application/__init__.py b/application/__init__.py index d789ae1..d1287e7 100644 --- a/application/__init__.py +++ b/application/__init__.py @@ -1,4 +1,4 @@ -# Copyright (c) 2021-2022 iCtrl Developers +# Copyright (c) 2021-2024 iCtrl Developers # # Permission is hereby granted, free of charge, to any person obtaining a copy # of this software and associated documentation files (the "Software"), to @@ -25,12 +25,15 @@ from flask import Flask, Blueprint from werkzeug.serving import WSGIRequestHandler -with open('logging_default_config.yaml', 'rt') as config_file: - config = yaml.safe_load(config_file.read()) +try: + with open('log_config.yaml', 'r') as config_file: + config = yaml.safe_load(config_file.read()) + logging.config.dictConfig(config) +except Exception as ex: + print("Logging setup failed with exception = ", ex) -logging.config.dictConfig(config) -logger = logging.getLogger(__file__) -logger.debug("successfully set up logger") +logger = logging.getLogger(__name__) +logger.warning(f"Logging is set up with config={config}") from .Profile.Profile import Profile @@ -71,4 +74,4 @@ api = Blueprint('api', __name__) -from .routes import * \ No newline at end of file +from .routes import * diff --git a/application/logging_default_config.yaml b/application/logging_default_config.yaml deleted file mode 100644 index 6fda32a..0000000 --- a/application/logging_default_config.yaml +++ /dev/null @@ -1,34 +0,0 @@ -version: 1 -disable_existing_loggers: False - -formatters: - default_formatter: - format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s' - datefmt: '%Y-%m-%d %H:%M:%S' - -handlers: - console: - class: logging.StreamHandler - level: DEBUG - formatter: default_formatter - stream: ext://sys.stdout - -loggers: - development: - level: DEBUG - handlers: [console] - propagate: no - - staging: - level: INFO - handlers: [console] - propagate: no - - production: - level: WARNING - handlers: [console] - propagate: no - -root: - level: DEBUG - handlers: [console] diff --git a/log_config.yaml b/log_config.yaml new file mode 100644 index 0000000..1e6672a --- /dev/null +++ b/log_config.yaml @@ -0,0 +1,18 @@ +version: 1 +disable_existing_loggers: True + +formatters: + default: + format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s' + datefmt: '%Y-%m-%d %H:%M:%S' + +handlers: + console: + class: logging.StreamHandler + level: DEBUG + formatter: default + stream: ext://sys.stderr + +root: + level: DEBUG + handlers: [console] From 992a6141430f787f1b3b09bd18539bccbd38460e Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Sun, 21 Jul 2024 18:51:54 -0400 Subject: [PATCH 06/10] moved yaml import to third party library group in application/__init__.py for better organization --- application/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/application/__init__.py b/application/__init__.py index d1287e7..2040aba 100644 --- a/application/__init__.py +++ b/application/__init__.py @@ -18,10 +18,10 @@ # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS # IN THE SOFTWARE. import logging.config -import yaml import os import sys +import yaml from flask import Flask, Blueprint from werkzeug.serving import WSGIRequestHandler From b46859c60250a959db54ae189ca7fbc819d2c101 Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Tue, 23 Jul 2024 00:27:49 -0400 Subject: [PATCH 07/10] Minor changes from code review with Junhao --- log_config.yaml | 2 +- publish/ictrl_be.spec | 3 ++- 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/log_config.yaml b/log_config.yaml index 1e6672a..672af5a 100644 --- a/log_config.yaml +++ b/log_config.yaml @@ -3,7 +3,7 @@ disable_existing_loggers: True formatters: default: - format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s' + format: '%(asctime)s %(levelname)s [%(name)s:%(lineno)d] %(message)s' datefmt: '%Y-%m-%d %H:%M:%S' handlers: diff --git a/publish/ictrl_be.spec b/publish/ictrl_be.spec index e786bfa..7d8c0b9 100644 --- a/publish/ictrl_be.spec +++ b/publish/ictrl_be.spec @@ -8,7 +8,8 @@ block_cipher = None a = Analysis(['../ictrl_be.py'], pathex=['.'], binaries=[], - datas=[('../client/build', './client')], + datas=[('../client/build', './client'), + ('../log_config.yaml', '..')] hiddenimports=[], hookspath=[], hooksconfig={}, From 91a657b33b757c484321012970007f360c535674 Mon Sep 17 00:00:00 2001 From: Ruihao Li Date: Tue, 23 Jul 2024 22:38:44 -0400 Subject: [PATCH 08/10] Minor change to update ictrl_be.spec for correct syntax and functionality --- publish/ictrl_be.spec | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/publish/ictrl_be.spec b/publish/ictrl_be.spec index 7d8c0b9..7ed1ac2 100644 --- a/publish/ictrl_be.spec +++ b/publish/ictrl_be.spec @@ -9,7 +9,7 @@ a = Analysis(['../ictrl_be.py'], pathex=['.'], binaries=[], datas=[('../client/build', './client'), - ('../log_config.yaml', '..')] + ('../log_config.yaml', '.')], hiddenimports=[], hookspath=[], hooksconfig={}, From 36f5fd416d6b1c7bf8496ab1b77dcf6fec3ddd08 Mon Sep 17 00:00:00 2001 From: IreneLi Date: Wed, 24 Jul 2024 18:44:53 -0400 Subject: [PATCH 09/10] Integrate logging to application/features/ --- application/features/Audio.py | 29 +++++++++++++--- application/features/Connection.py | 51 ++++++++++++++++++++++++---- application/features/SFTP.py | 31 ++++++++++++++--- application/features/Term.py | 22 ++++++++++-- application/features/VNC.py | 28 ++++++++++++--- application/features/mywebsockify.py | 3 +- application/features/vncpasswd.py | 2 ++ 7 files changed, 142 insertions(+), 24 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index 6698c8c..f19aee7 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -31,6 +31,7 @@ from .Connection import Connection from .. import app from ..utils import find_free_port, get_headers_dict_from_str, local_auth +import application AUDIO_CONNECTIONS = {} @@ -57,13 +58,16 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + application.logger.debug("Audio: Establishing Audio connection") return super().connect(*args, **kwargs) def launch_audio(self): try: + application.logger.debug("Audio: Launching Audio connection. Forwarding request to 127.0.0.1, port 0.") self.transport = self.client.get_transport() self.remote_port = self.transport.request_port_forward('127.0.0.1', 0) except Exception as e: + application.logger.warning("Audio: exception raised during launch audio: {}".format(e)) return False, str(e) self.id = uuid.uuid4().hex @@ -83,11 +87,12 @@ def handleConnected(self): headers = get_headers_dict_from_str(headers) if not local_auth(headers=headers, abort_func=self.close): # local auth failure + application.logger.warning("AudioWebSocket: Local Authentication Failure") return audio_id = self.request.path[1:] if audio_id not in AUDIO_CONNECTIONS: - print(f'AudioWebSocket: Requested audio_id={audio_id} does not exist.') + application.logger.warning(f'AudioWebSocket: Requested audio_id={audio_id} does not exist.') self.close() return @@ -103,26 +108,31 @@ def handleConnected(self): f'module-null-sink sink_name={sink_name} ' exit_status, _, stdout, _ = self.audio.exec_command_blocking(load_module_command) if exit_status != 0: - print(f'AudioWebSocket: audio_id={audio_id}: unable to load pactl module-null-sink sink_name={sink_name}') + application.logger.warning(f'AudioWebSocket: audio_id={audio_id}: unable to load pactl module-null-sink sink_name={sink_name}') return load_module_stdout_lines = stdout.readlines() + application.logger.debug("AudioWebSocket: Load Module: {}".format(load_module_stdout_lines)) self.module_id = int(load_module_stdout_lines[0]) keep_launching_ffmpeg = True def ffmpeg_launcher(): + application.logger.debug("AudioWebSocket: ffmpeg_launcher thread started") # TODO: support requesting audio format from the client launch_ffmpeg_command = f'killall ffmpeg; ffmpeg -f pulse -i "{sink_name}.monitor" ' \ f'-ac 2 -acodec pcm_s16le -ar 44100 -f s16le "tcp://127.0.0.1:{self.audio.remote_port}"' # keep launching if the connection is not accepted in the writer() below while keep_launching_ffmpeg: + application.logger.debug(f"AudioWebSocket: Launch ffmpeg: {launch_ffmpeg_command}") _, ffmpeg_stdout, _ = self.audio.client.exec_command(launch_ffmpeg_command) ffmpeg_stdout.channel.recv_exit_status() # if `ffmpeg` launches successfully, `ffmpeg_stdout.channel.recv_exit_status` should not return + application.logger.debug("AudioWebSocket: ffmpeg_launcher thread ended") ffmpeg_launcher_thread = threading.Thread(target=ffmpeg_launcher) def writer(): + application.logger.debug("AudioWebSocket: writer thread started") channel = self.audio.transport.accept(FFMPEG_LOAD_TIME * TRY_FFMPEG_MAX_COUNT) nonlocal keep_launching_ffmpeg @@ -130,22 +140,26 @@ def writer(): if channel is None: ffmpeg_launcher_thread.join() - raise ConnectionError("AudioWebSocket:handleConnected: Unable to launch audio socket on the remote " - "target. ") + application.logger.error("AudioWebSocket:handleConnected: Unable to launch audio socket on the remote target. ") + # raise ConnectionError("AudioWebSocket:handleConnected: Unable to launch audio socket on the remote " + # "target. ") # use a buffer to reduce transfer frequency buffer = b'' while True: data = channel.recv(AUDIO_BUFFER_SIZE) if not data: + application.logger.debug("AudioWebSocket: Close audio socket connection") self.close() break buffer += data if len(buffer) >= AUDIO_BUFFER_SIZE: compressed = zlib.compress(buffer, level=4) + application.logger.debug(f"AudioWebSocket: Send compressed message of size {len(compressed)}") self.sendMessage(compressed) # print(len(compressed) / len(buffer) * 100) buffer = b'' + application.logger.debug("AudioWebSocket: write thread ended") writer_thread = threading.Thread(target=writer) @@ -155,8 +169,10 @@ def writer(): def handleClose(self): if self.module_id is not None: # unload the module before leaving + application.logger.debug(f"AudioWebSocket: Unload module {self.module_id}") self.audio.client.exec_command(f'pactl unload-module {self.module_id}') + application.logger.debug(f"AudioWebSocket: End audio socket {self.audio.id} connection") del AUDIO_CONNECTIONS[self.audio.id] del self.audio @@ -166,13 +182,16 @@ def handleClose(self): # if we are in debug mode, run the server in the second round if not app.debug or os.environ.get("WERKZEUG_RUN_MAIN") == "true": AUDIO_PORT = find_free_port() - print("AUDIO_PORT =", AUDIO_PORT) + # print("AUDIO_PORT =", AUDIO_PORT) + application.logger.debug("Audio: Audio port {}".format(AUDIO_PORT)) if os.environ.get('SSL_CERT_PATH') is None: + application.logger.debug("Audio: SSL Certification Path not set. Generating self-signing certificate") # no certificate provided, generate self-signing certificate audio_server = SimpleSSLWebSocketServer('127.0.0.1', AUDIO_PORT, AudioWebSocket, ssl_context=generate_adhoc_ssl_context()) else: + application.logger.debug("Audio: SSL Certification Path exists") import ssl audio_server = SimpleSSLWebSocketServer('0.0.0.0', AUDIO_PORT, AudioWebSocket, diff --git a/application/features/Connection.py b/application/features/Connection.py index ad0ee0e..b18520b 100644 --- a/application/features/Connection.py +++ b/application/features/Connection.py @@ -27,17 +27,20 @@ import paramiko import select +import application class ForwardServerHandler(socketserver.BaseRequestHandler): def handle(self): self.server: ForwardServer try: + application.logger.debug("Connection: Open forward server channel") chan = self.server.ssh_transport.open_channel( "direct-tcpip", ("127.0.0.1", self.server.chain_port), self.request.getpeername(), ) except Exception as e: + application.logger.warning(f"Connection: Incoming request to 127.0.0.1:{self.server.chain_port} failed: {repr(e)}") return False, "Incoming request to %s:%d failed: %s" % ( "127.0.0.1", self.server.chain_port, repr(e)) @@ -49,6 +52,14 @@ def handle(self): ("127.0.0.1", self.server.chain_port), ) ) + application.logger.debug( + "Connected! Tunnel open %r -> %r -> %r" + % ( + self.request.getpeername(), + chan.getpeername(), + ("127.0.0.1", self.server.chain_port), + ) + ) try: while True: @@ -64,13 +75,16 @@ def handle(self): break self.request.send(data) except Exception as e: - print(e) + application.logger.error(f"Connection: Request transmission failure: {e}") + # print(e) try: + application.logger.debug("Connection: Close forward server channel") chan.close() self.server.shutdown() except Exception as e: - print(e) + application.logger.error(f"Connection: Close forward server channel failed: {e}") + # print(e) class ForwardServer(socketserver.ThreadingTCPServer): @@ -102,6 +116,9 @@ def __del__(self): def _client_connect(self, client: paramiko.SSHClient, host, username, password=None, key_filename=None, private_key_str=None): + if self._jump_channel != None: + application.logger.debug("Connection: Connection initialized through Jump Channel") + application.logger.debug(f"Connection: Connecting to {username}@{host}") if password is not None: client.connect(host, username=username, password=password, timeout=15, sock=self._jump_channel) elif key_filename is not None: @@ -110,7 +127,8 @@ def _client_connect(self, client: paramiko.SSHClient, pkey = paramiko.RSAKey.from_private_key(StringIO(private_key_str)) client.connect(host, username=username, pkey=pkey, timeout=15, sock=self._jump_channel) else: - raise ValueError("Connection: no valid SSH auth given.") + application.logger.error("Connection: no valid SSH auth given.") + # raise ValueError("Connection: no valid SSH auth given.") def _init_jump_channel(self, host, username, **auth_methods): """ @@ -124,27 +142,33 @@ def _init_jump_channel(self, host, username, **auth_methods): """ if (host.endswith('ecf.utoronto.ca') or host.endswith('ecf.toronto.edu')) and not host.startswith('remote'): if self._jump_client is not None: - raise ValueError("API misuse: should not invoke connect twice on the same Connection object") + application.logger.error("Connection: API misuse: should not invoke connect twice on the same Connection object") + # raise ValueError("API misuse: should not invoke connect twice on the same Connection object") self._jump_client = paramiko.SSHClient() self._jump_client.set_missing_host_key_policy(paramiko.AutoAddPolicy()) + application.logger.debug(f"Connection: Initialize Jump Client for connection to {username}@remote.ecf.utoronto.ca") self._client_connect(self._jump_client, 'remote.ecf.utoronto.ca', username, **auth_methods) + application.logger.debug(f"Connection: Open Jump channel connection to {host} at port 22") self._jump_channel = self._jump_client.get_transport().open_channel('direct-tcpip', (host, 22), ('127.0.0.1', 22)) def connect(self, host: str, username: str, **auth_methods): try: + application.logger.debug(f"Connection: Connection attempt to {username}@{host}") self._init_jump_channel(host, username, **auth_methods) self._client_connect(self.client, host, username, **auth_methods) except Exception as e: # raise e # print('Connection::connect() exception:') + application.logger.warning(f"Connection: Connection failed due to {str(e)}") return False, str(e) self.host = host self.username = username + application.logger.debug(f"Connection: Successfully connected to {username}@{host}") return True, '' @staticmethod @@ -160,11 +184,14 @@ def ssh_keygen(key_filename=None, key_file_obj=None, public_key_comment=''): # save the private key if key_filename is not None: + application.logger.debug(f"Connection: RSA SSH private key written to {key_filename}") rsa_key.write_private_key_file(key_filename) elif key_file_obj is not None: rsa_key.write_private_key(key_file_obj) + application.logger.debug(f"Connection: RSA SSH private key written to {key_file_obj}") else: - raise ValueError('Neither key_filename nor key_file_obj is provided.') + application.logger.error("Connection: Neither key_filename nor key_file_obj is provided.") + # raise ValueError('Neither key_filename nor key_file_obj is provided.') # ssh-rsa: key type # rsa_key.get_base64(): key phrase @@ -185,13 +212,16 @@ def save_keys(self, key_filename=None, key_file_obj=None, public_key_comment='') # generate key pairs and save the private key in the key file object pub_key = Connection.ssh_keygen(key_file_obj=key_file_obj, public_key_comment=public_key_comment) else: - raise ValueError('Neither key_filename nor key_file_obj is provided.') + application.logger.error("Connection: Neither key_filename nor key_file_obj is provided.") + # raise ValueError('Neither key_filename nor key_file_obj is provided.') # save the public key onto the remote server exit_status, _, _, _ = self.exec_command_blocking( "mkdir -p ~/.ssh && chmod 700 ~/.ssh && echo '%s' >> ~/.ssh/authorized_keys" % pub_key) if exit_status != 0: + application.logger.warning("Connection: unable to save public key; Check for disk quota and permissions with any conventional SSH clients. ") return False, "Connection::save_keys: unable to save public key; Check for disk quota and permissions with any conventional SSH clients. " + application.logger.debug("Connection: Public ssh key saved to remove server ~/.ssh/authorized_keys") return True, "" @@ -217,6 +247,7 @@ def exec_command_blocking_large(self, command): return '\n'.join(stdout) + '\n' + '\n'.join(stderr) def _port_forward_thread(self, local_port, remote_port): + application.logger.debug("Connection: Port forward thread started") forward_server = ForwardServer(("", local_port), ForwardServerHandler) forward_server.ssh_transport = self.client.get_transport() @@ -224,15 +255,20 @@ def _port_forward_thread(self, local_port, remote_port): forward_server.serve_forever() forward_server.server_close() + application.logger.debug("Connection: Port forward thread ended") def port_forward(self, *args): forwarding_thread = threading.Thread(target=self._port_forward_thread, args=args) forwarding_thread.start() def is_eecg(self): + if 'eecg' in self.host: + application.logger.debug("Connection: Target host is eecg") return 'eecg' in self.host def is_ecf(self): + if 'ecf' in self.host: + application.logger.debug("Connection: Target host is ecf") return 'ecf' in self.host def is_uoft(self): @@ -256,6 +292,9 @@ def is_load_high(self): my_pts_count = len(output) - 1 # -1: excluding the `uptime` output + application.logger.debug(f"Connection: pts count: {pts_count}; my pts count: {my_pts_count}") + application.logger.debug(f"Connection: load sum: {load_sum}") + if pts_count > my_pts_count: # there are more terminals than mine return True elif load_sum > 1.0: diff --git a/application/features/SFTP.py b/application/features/SFTP.py index db0de04..4bf895c 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -26,7 +26,7 @@ from paramiko.sftp_client import SFTPClient from .Connection import Connection - +import application class SFTP(Connection): def __init__(self): @@ -41,14 +41,18 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + application.logger.debug("SFTP: Establishing SFTP connection") status, reason = super().connect(*args, **kwargs) if not status: + application.logger.warning(f"SFTP: connect failed due to {reason}") return status, reason try: + application.logger.debug("SFTP: Open SFTP client connection") self.sftp = self.client.open_sftp() self.sftp.chdir(".") except Exception as e: + application.logger.warning(f"SFTP: Client connect failed due to {e}") return False, str(e) return True, '' @@ -59,6 +63,7 @@ def ls(self, path=""): self.sftp.chdir(path) cwd = self.sftp.getcwd() attrs = self.sftp.listdir_attr(cwd) + application.logger.debug(f"SFTP: ls {cwd}: {attrs}") file_list = [] # TODO: should support uid and gid later @@ -72,6 +77,7 @@ def ls(self, path=""): } file_list.append(file) except Exception as e: + application.logger.warning(f"SFTP: 'ls' failed due to {e}") return False, repr(e), [] return True, cwd, file_list @@ -92,6 +98,7 @@ def dl_generator(self, path): yield chunk chunk = f.read(paramiko.sftp_file.SFTPFile.MAX_REQUEST_SIZE) except PermissionError: + application.logger.warning(f"SFTP: dl_generator Permission denied reading {path}") yield bytes() def _zip_dir_recurse(self, z, parent, file): @@ -100,9 +107,11 @@ def _zip_dir_recurse(self, z, parent, file): mode = self.sftp.stat(fullpath).st_mode if stat.S_ISREG(mode): # print(fullpath, 'is file') + application.logger.debug(f"SFTP: {fullpath} is a file") z.write_iter(fullpath, self.dl_generator(fullpath)) elif stat.S_ISDIR(mode): # print(fullpath, 'is dir') + application.logger.debug(f"SFTP: {fullpath} is a directory") # TODO: support writing an empty directory if len(dir_ls)==0 # That will involve modifying the zipstream library dir_ls = self.sftp.listdir(fullpath) @@ -111,15 +120,19 @@ def _zip_dir_recurse(self, z, parent, file): except FileNotFoundError: # likely due to a symlink that cannot be resolved # do nothing for now + application.logger.warning(f"SFTP: zip_dir_recurse failed on {fullpath} due to FileNotFoundError") return except PermissionError: + application.logger.warning(f"SFTP: zip_dir_recurse failed on {fullpath} due to PermissionError") return def zip_generator(self, cwd, file_list): + application.logger.debug(f"SFTP: zip_generator on directory: {cwd}") self.sftp.chdir(cwd) z = zipstream.ZipFile(compression=zipstream.ZIP_DEFLATED, allowZip64=True) for file in file_list: + application.logger.debug(f"SFTP: zip_generator on file: {file}") self._zip_dir_recurse(z, '', file) return z @@ -128,7 +141,9 @@ def rename(self, cwd, old, new): try: self.sftp.chdir(cwd) self.sftp.rename(old, new) + application.logger.debug(f"SFTP: Rename {old} in directory {cwd} to {new}") except Exception as e: + application.logger.warning(f"SFTP: Rename failed due to {e}") return False, repr(e) return True, '' @@ -136,9 +151,11 @@ def rename(self, cwd, old, new): def chmod(self, path, mode, recursive): _, _, _, stderr = self.exec_command_blocking( f'chmod {"-R" if recursive else ""} {"{0:0{1}o}".format(mode, 3)} "{path}"') + application.logger.debug("SFTP: Change permission on " + path + " to '{0:0{1}o}'".format(mode, 3)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - print(stderr_lines) + application.logger.warning(f"SFTP: chmod failed due to {stderr_lines}") + # print(stderr_lines) return False, 'Some files were not applied with the request mode due to permission issues.' return True, '' @@ -159,20 +176,24 @@ def rm(self, cwd, file_list): counter += 1 if counter == 50: + application.logger.debug(f"SFTP: Execute Command {' '.join(cmd_list)}") _, _, stderr = self.client.exec_command(" ".join(cmd_list)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - print(stderr_lines) + application.logger.warning(f"SFTP: rm file failed due to {stderr_lines}") + # print(stderr_lines) result = 'Some files are not removed due to insufficient permissions' # reset counter counter = 0 cmd_list = [f'cd "{cwd}" && rm -rf'] + application.logger.debug(f"SFTP: Execute Command {' '.join(cmd_list)}") _, _, stderr = self.client.exec_command(" ".join(cmd_list)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - print(stderr_lines) + application.logger.warning(f"SFTP: rm file failed due to {stderr_lines}") + # print(stderr_lines) result = 'Some files are not removed due to insufficient permissions' if result != '': @@ -180,8 +201,10 @@ def rm(self, cwd, file_list): return True, '' def mkdir(self, cwd, name): + application.logger.debug(f"SFTP: Make directory {name} at {cwd}") _, _, _, stderr = self.exec_command_blocking(f'cd "{cwd}"&& mkdir "{name}"') stderr_lines = stderr.readlines() if len(stderr_lines) != 0: + application.logger.warning(f"SFTP: mkdir {name} in {cwd} failed due to {stderr_lines}") return False, stderr_lines[0] return True, '' diff --git a/application/features/Term.py b/application/features/Term.py index daac726..3b1c1a3 100644 --- a/application/features/Term.py +++ b/application/features/Term.py @@ -30,7 +30,7 @@ from .Connection import Connection from .. import app from ..utils import find_free_port, local_auth, get_headers_dict_from_str - +import application TERM_CONNECTIONS = {} @@ -49,12 +49,15 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + application.logger.debug("Term: Establishing Term connection") return super().connect(*args, **kwargs) def launch_shell(self): try: + application.logger.debug("Term: Launching Shell Terminal") self.channel = self.client.invoke_shell('xterm-256color') except Exception as e: + application.logger.warning(f"Term: Launching Shell Terminal failed with error {str(e)}") return False, str(e) self.id = uuid.uuid4().hex @@ -64,8 +67,10 @@ def launch_shell(self): def resize(self, width, height): try: + application.logger.debug(f"Term: Resizing Term to {width}x{height}") self.channel.resize_pty(width, height) except Exception as e: + application.logger.warning(f"Term: Resize Terminal failed with error {str(e)}") return False, str(e) return True, '' @@ -77,6 +82,7 @@ def __init__(self, *args, **kwargs): self.term = None def handleMessage(self): + application.logger.debug(f"TermWebSocket: Send message {self.data}") self.term.channel.send(self.data) def handleConnected(self): @@ -84,30 +90,37 @@ def handleConnected(self): headers = get_headers_dict_from_str(headers) if not local_auth(headers=headers, abort_func=self.close): # local auth failure + application.logger.warning("TermWebSocket: Local Authentication Failure") return + application.logger.debug(f"TermWebSocket: connected to {self.address}") print(self.address, 'connected') terminal_id = self.request.path[1:] if terminal_id not in TERM_CONNECTIONS: - print(f'TermWebSocket: Requested terminal_id={terminal_id} does not exist.') + # print(f'TermWebSocket: Requested terminal_id={terminal_id} does not exist.') + application.logger.warning(f"TermWebSocket: Requested terminal_id={terminal_id} does not exist.") self.close() return self.term = TERM_CONNECTIONS[terminal_id] def writeall(): + application.logger.debug("TermWebSocket: Writeall thread started") while True: data = self.term.channel.recv(1024) if not data: - print(f"\r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") + # print(f"\r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") + application.logger.debug(f"TermWebSocket: \r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") self.close() break self.sendMessage(data) + application.logger.debug("TermWebSocket: Writeall thread ended") writer = threading.Thread(target=writeall) writer.start() def handleClose(self): + application.logger.debug(f"TermWebSocket: Closing terminal {self.term.id} connection") del TERM_CONNECTIONS[self.term.id] del self.term @@ -118,12 +131,15 @@ def handleClose(self): if not app.debug or os.environ.get("WERKZEUG_RUN_MAIN") == "true": TERMINAL_PORT = find_free_port() print("TERMINAL_PORT =", TERMINAL_PORT) + application.logger.debug("Term: Terminal port {}".format(TERMINAL_PORT)) if os.environ.get('SSL_CERT_PATH') is None: + application.logger.debug("Term: SSL Certification Path not set. Generating self-signing certificate") # no certificate provided, generate self-signing certificate terminal_server = SimpleSSLWebSocketServer('127.0.0.1', TERMINAL_PORT, TermWebSocket, ssl_context=generate_adhoc_ssl_context()) else: + application.logger.debug("Term: SSL Certification Path exists") import ssl terminal_server = SimpleSSLWebSocketServer('0.0.0.0', TERMINAL_PORT, TermWebSocket, diff --git a/application/features/VNC.py b/application/features/VNC.py index 6508edb..2dddf3f 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -27,12 +27,12 @@ from .mywebsockify import MyProxyRequestHandler, MySSLProxyServer from .vncpasswd import decrypt_passwd from ..utils import find_free_port - -logger = logging.getLogger(__name__) - +import application def websocket_proxy_thread(local_websocket_port, local_vnc_port): + application.logger.debug("VNC: Start websocket proxy thread") if os.environ.get('SSL_CERT_PATH') is None: + application.logger.debug("VNC: SSL Certification Path not set. Initialize SSL Proxy Server.") proxy_server = MySSLProxyServer(RequestHandlerClass=MyProxyRequestHandler, listen_port=local_websocket_port, target_host='', target_port=local_vnc_port) @@ -41,16 +41,24 @@ def websocket_proxy_thread(local_websocket_port, local_vnc_port): # 1st: first handshake: upgrade the HTTP request # 2nd: actually serve the ws connection for _ in range(2): + if _ == 0: + application.logger.debug("VNC: Handle HTTP request") + else: + application.logger.debug("VNC: Handle WebSocket connection") proxy_server.handle_request() + application.logger.debug("VNC: Close SSL Proxy Server") proxy_server.server_close() else: + application.logger.debug("VNC: SSL Certification Path exists") import subprocess + application.logger.debug(f"VNC: Run websockify on websocket port {local_websocket_port} and vncport {local_vnc_port}") subprocess.run(["/var/www/ictrl/application/websockify-other/c/websockify", f'{local_websocket_port}', f':{local_vnc_port}', '--run-once', '--ssl-only', '--cert', os.environ.get('SSL_CERT_PATH'), '--key', os.environ.get('SSL_KEY_PATH')]) + application.logger.debug("VNC: End websocket proxy thread") class VNC(Connection): @@ -64,12 +72,14 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + application.logger.debug("VNC: Establishing VNC connection") return super().connect(*args, **kwargs) def get_vnc_password(self): _, _, stdout, _ = self.exec_command_blocking("hexdump --format '16/1 \"%02x\"' ~/.vnc/passwd") hexdump = stdout.readline().rstrip() if hexdump == '': + application.logger.warning("VNC: VNC Password is empty") return False, '' else: return True, decrypt_passwd(bytearray.fromhex(hexdump)) @@ -93,6 +103,7 @@ def remove_vnc_settings(self): _, _, _, stderr = self.exec_command_blocking(';'.join(remove_cmd_lst)) stderr_text = "\n".join(stderr) if len(stderr_text): + application.logger.warning(f"VNC: Error removing VNC settings: {stderr_text}") return False, stderr_text return True, '' @@ -119,7 +130,7 @@ def reset_vnc_password(self, password): _, _, _, stderr = self.exec_command_blocking(';'.join(reset_cmd_lst)) error_lines = [] for line in stderr: - logger.error("reset_vnc_password::exec_command_blocking stderr line: %s", line) + application.logger.warning("VNC: Error resetting VNC password: %s", line) if "Disk quota exceeded" in line: return False, 'Disk quota exceeded' @@ -133,12 +144,15 @@ def reset_vnc_password(self, password): def launch_vnc(self): ports_by_me = [] _, _, stdout, _ = self.exec_command_blocking('vncserver -list') + application.logger.debug("VNC: Listing vnc servers") for line in stdout: if 'stale' not in line: # if the server was improperly terminated, the status is 'stale' this_port_by_me = re.findall(r'\d+', line) if len(this_port_by_me) != 0: ports_by_me.append(this_port_by_me[0]) + if line.strip() != "": + application.logger.debug("VNC: VNC server list output: %s", line.strip()) # FIXME: handle disk quota issue when launching vncserver relaunch = False @@ -148,11 +162,13 @@ def launch_vnc(self): 'vncserver' ] if len(ports_by_me) > 1 or len(ports_by_me) == 0: + application.logger.debug("VNC: Relaunch VNC servers") # TODO: might recover the valid ones # more than one VNC servers are listening and therefore all killed above to prevent unexpected results _, _, stdout, stderr = self.exec_command_blocking(';'.join(relaunch_cmd_list)) stderr_lines = "".join(stderr.readlines()) if len(stderr_lines) != 0: + application.logger.warning("VNC: Error relaunching VNC servers: %s", stderr_lines) if 'quota' in stderr_lines: return False, 'QUOTA' else: @@ -169,6 +185,7 @@ def launch_vnc(self): if match: vnc_port = int(match.group(1)) break + application.logger.debug("VNC: VNC port: %s", vnc_port) # FIXME: use a better condition than is_eecg """ @@ -184,7 +201,8 @@ def launch_vnc(self): def create_tunnel(self, remote_port): local_vnc_port = find_free_port() local_websocket_port = find_free_port() - + application.logger.debug(f"VNC: Local VNC Port is {local_vnc_port}") + application.logger.debug(f"VNC: Local Web Socket Port is {local_websocket_port}") self.port_forward(local_vnc_port, remote_port) proxy_thread = threading.Thread(target=websocket_proxy_thread, diff --git a/application/features/mywebsockify.py b/application/features/mywebsockify.py index 1432e1e..88c61d0 100644 --- a/application/features/mywebsockify.py +++ b/application/features/mywebsockify.py @@ -2,7 +2,7 @@ from werkzeug.serving import generate_adhoc_ssl_context from application.utils import local_auth - +import application class MyProxyRequestHandler(websockify.ProxyRequestHandler): def auth_connection(self): @@ -18,6 +18,7 @@ def __init__(self, RequestHandlerClass=websockify.ProxyRequestHandler, ssl_conte super(MySSLProxyServer, self).__init__(RequestHandlerClass=RequestHandlerClass, **kwargs) if ssl_context is None: + application.logger.debug("Generating self-signed SSL certificate") # no certificate provided, generate self-signing certificate ssl_context = generate_adhoc_ssl_context() self.socket = ssl_context.wrap_socket(self.socket, server_side=True) diff --git a/application/features/vncpasswd.py b/application/features/vncpasswd.py index 32b928b..d93e26e 100644 --- a/application/features/vncpasswd.py +++ b/application/features/vncpasswd.py @@ -19,6 +19,7 @@ # IN THE SOFTWARE. import pyDes +import application KEY = [232, 74, 214, 96, 196, 114, 26, 224] CRYPT = pyDes.des(KEY) @@ -42,6 +43,7 @@ def vncpasswd(passwd_path, password=None): with open(passwd_path, "wb") as passwd: passwd.write(obfuscated) + application.logger.debug("Vnc Password: Write obfuscated password to {}".format(passwd_path)) return obfuscated From 58e7582a86b9f46e58b0f73ee5247d3b1438874d Mon Sep 17 00:00:00 2001 From: IreneLi Date: Wed, 24 Jul 2024 21:45:50 -0400 Subject: [PATCH 10/10] Revert "Integrate logging to application/features/" This reverts commit 36f5fd416d6b1c7bf8496ab1b77dcf6fec3ddd08. --- application/features/Audio.py | 29 +++------------- application/features/Connection.py | 51 ++++------------------------ application/features/SFTP.py | 31 +++-------------- application/features/Term.py | 22 ++---------- application/features/VNC.py | 28 +++------------ application/features/mywebsockify.py | 3 +- application/features/vncpasswd.py | 2 -- 7 files changed, 24 insertions(+), 142 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index f19aee7..6698c8c 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -31,7 +31,6 @@ from .Connection import Connection from .. import app from ..utils import find_free_port, get_headers_dict_from_str, local_auth -import application AUDIO_CONNECTIONS = {} @@ -58,16 +57,13 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): - application.logger.debug("Audio: Establishing Audio connection") return super().connect(*args, **kwargs) def launch_audio(self): try: - application.logger.debug("Audio: Launching Audio connection. Forwarding request to 127.0.0.1, port 0.") self.transport = self.client.get_transport() self.remote_port = self.transport.request_port_forward('127.0.0.1', 0) except Exception as e: - application.logger.warning("Audio: exception raised during launch audio: {}".format(e)) return False, str(e) self.id = uuid.uuid4().hex @@ -87,12 +83,11 @@ def handleConnected(self): headers = get_headers_dict_from_str(headers) if not local_auth(headers=headers, abort_func=self.close): # local auth failure - application.logger.warning("AudioWebSocket: Local Authentication Failure") return audio_id = self.request.path[1:] if audio_id not in AUDIO_CONNECTIONS: - application.logger.warning(f'AudioWebSocket: Requested audio_id={audio_id} does not exist.') + print(f'AudioWebSocket: Requested audio_id={audio_id} does not exist.') self.close() return @@ -108,31 +103,26 @@ def handleConnected(self): f'module-null-sink sink_name={sink_name} ' exit_status, _, stdout, _ = self.audio.exec_command_blocking(load_module_command) if exit_status != 0: - application.logger.warning(f'AudioWebSocket: audio_id={audio_id}: unable to load pactl module-null-sink sink_name={sink_name}') + print(f'AudioWebSocket: audio_id={audio_id}: unable to load pactl module-null-sink sink_name={sink_name}') return load_module_stdout_lines = stdout.readlines() - application.logger.debug("AudioWebSocket: Load Module: {}".format(load_module_stdout_lines)) self.module_id = int(load_module_stdout_lines[0]) keep_launching_ffmpeg = True def ffmpeg_launcher(): - application.logger.debug("AudioWebSocket: ffmpeg_launcher thread started") # TODO: support requesting audio format from the client launch_ffmpeg_command = f'killall ffmpeg; ffmpeg -f pulse -i "{sink_name}.monitor" ' \ f'-ac 2 -acodec pcm_s16le -ar 44100 -f s16le "tcp://127.0.0.1:{self.audio.remote_port}"' # keep launching if the connection is not accepted in the writer() below while keep_launching_ffmpeg: - application.logger.debug(f"AudioWebSocket: Launch ffmpeg: {launch_ffmpeg_command}") _, ffmpeg_stdout, _ = self.audio.client.exec_command(launch_ffmpeg_command) ffmpeg_stdout.channel.recv_exit_status() # if `ffmpeg` launches successfully, `ffmpeg_stdout.channel.recv_exit_status` should not return - application.logger.debug("AudioWebSocket: ffmpeg_launcher thread ended") ffmpeg_launcher_thread = threading.Thread(target=ffmpeg_launcher) def writer(): - application.logger.debug("AudioWebSocket: writer thread started") channel = self.audio.transport.accept(FFMPEG_LOAD_TIME * TRY_FFMPEG_MAX_COUNT) nonlocal keep_launching_ffmpeg @@ -140,26 +130,22 @@ def writer(): if channel is None: ffmpeg_launcher_thread.join() - application.logger.error("AudioWebSocket:handleConnected: Unable to launch audio socket on the remote target. ") - # raise ConnectionError("AudioWebSocket:handleConnected: Unable to launch audio socket on the remote " - # "target. ") + raise ConnectionError("AudioWebSocket:handleConnected: Unable to launch audio socket on the remote " + "target. ") # use a buffer to reduce transfer frequency buffer = b'' while True: data = channel.recv(AUDIO_BUFFER_SIZE) if not data: - application.logger.debug("AudioWebSocket: Close audio socket connection") self.close() break buffer += data if len(buffer) >= AUDIO_BUFFER_SIZE: compressed = zlib.compress(buffer, level=4) - application.logger.debug(f"AudioWebSocket: Send compressed message of size {len(compressed)}") self.sendMessage(compressed) # print(len(compressed) / len(buffer) * 100) buffer = b'' - application.logger.debug("AudioWebSocket: write thread ended") writer_thread = threading.Thread(target=writer) @@ -169,10 +155,8 @@ def writer(): def handleClose(self): if self.module_id is not None: # unload the module before leaving - application.logger.debug(f"AudioWebSocket: Unload module {self.module_id}") self.audio.client.exec_command(f'pactl unload-module {self.module_id}') - application.logger.debug(f"AudioWebSocket: End audio socket {self.audio.id} connection") del AUDIO_CONNECTIONS[self.audio.id] del self.audio @@ -182,16 +166,13 @@ def handleClose(self): # if we are in debug mode, run the server in the second round if not app.debug or os.environ.get("WERKZEUG_RUN_MAIN") == "true": AUDIO_PORT = find_free_port() - # print("AUDIO_PORT =", AUDIO_PORT) - application.logger.debug("Audio: Audio port {}".format(AUDIO_PORT)) + print("AUDIO_PORT =", AUDIO_PORT) if os.environ.get('SSL_CERT_PATH') is None: - application.logger.debug("Audio: SSL Certification Path not set. Generating self-signing certificate") # no certificate provided, generate self-signing certificate audio_server = SimpleSSLWebSocketServer('127.0.0.1', AUDIO_PORT, AudioWebSocket, ssl_context=generate_adhoc_ssl_context()) else: - application.logger.debug("Audio: SSL Certification Path exists") import ssl audio_server = SimpleSSLWebSocketServer('0.0.0.0', AUDIO_PORT, AudioWebSocket, diff --git a/application/features/Connection.py b/application/features/Connection.py index b18520b..ad0ee0e 100644 --- a/application/features/Connection.py +++ b/application/features/Connection.py @@ -27,20 +27,17 @@ import paramiko import select -import application class ForwardServerHandler(socketserver.BaseRequestHandler): def handle(self): self.server: ForwardServer try: - application.logger.debug("Connection: Open forward server channel") chan = self.server.ssh_transport.open_channel( "direct-tcpip", ("127.0.0.1", self.server.chain_port), self.request.getpeername(), ) except Exception as e: - application.logger.warning(f"Connection: Incoming request to 127.0.0.1:{self.server.chain_port} failed: {repr(e)}") return False, "Incoming request to %s:%d failed: %s" % ( "127.0.0.1", self.server.chain_port, repr(e)) @@ -52,14 +49,6 @@ def handle(self): ("127.0.0.1", self.server.chain_port), ) ) - application.logger.debug( - "Connected! Tunnel open %r -> %r -> %r" - % ( - self.request.getpeername(), - chan.getpeername(), - ("127.0.0.1", self.server.chain_port), - ) - ) try: while True: @@ -75,16 +64,13 @@ def handle(self): break self.request.send(data) except Exception as e: - application.logger.error(f"Connection: Request transmission failure: {e}") - # print(e) + print(e) try: - application.logger.debug("Connection: Close forward server channel") chan.close() self.server.shutdown() except Exception as e: - application.logger.error(f"Connection: Close forward server channel failed: {e}") - # print(e) + print(e) class ForwardServer(socketserver.ThreadingTCPServer): @@ -116,9 +102,6 @@ def __del__(self): def _client_connect(self, client: paramiko.SSHClient, host, username, password=None, key_filename=None, private_key_str=None): - if self._jump_channel != None: - application.logger.debug("Connection: Connection initialized through Jump Channel") - application.logger.debug(f"Connection: Connecting to {username}@{host}") if password is not None: client.connect(host, username=username, password=password, timeout=15, sock=self._jump_channel) elif key_filename is not None: @@ -127,8 +110,7 @@ def _client_connect(self, client: paramiko.SSHClient, pkey = paramiko.RSAKey.from_private_key(StringIO(private_key_str)) client.connect(host, username=username, pkey=pkey, timeout=15, sock=self._jump_channel) else: - application.logger.error("Connection: no valid SSH auth given.") - # raise ValueError("Connection: no valid SSH auth given.") + raise ValueError("Connection: no valid SSH auth given.") def _init_jump_channel(self, host, username, **auth_methods): """ @@ -142,33 +124,27 @@ def _init_jump_channel(self, host, username, **auth_methods): """ if (host.endswith('ecf.utoronto.ca') or host.endswith('ecf.toronto.edu')) and not host.startswith('remote'): if self._jump_client is not None: - application.logger.error("Connection: API misuse: should not invoke connect twice on the same Connection object") - # raise ValueError("API misuse: should not invoke connect twice on the same Connection object") + raise ValueError("API misuse: should not invoke connect twice on the same Connection object") self._jump_client = paramiko.SSHClient() self._jump_client.set_missing_host_key_policy(paramiko.AutoAddPolicy()) - application.logger.debug(f"Connection: Initialize Jump Client for connection to {username}@remote.ecf.utoronto.ca") self._client_connect(self._jump_client, 'remote.ecf.utoronto.ca', username, **auth_methods) - application.logger.debug(f"Connection: Open Jump channel connection to {host} at port 22") self._jump_channel = self._jump_client.get_transport().open_channel('direct-tcpip', (host, 22), ('127.0.0.1', 22)) def connect(self, host: str, username: str, **auth_methods): try: - application.logger.debug(f"Connection: Connection attempt to {username}@{host}") self._init_jump_channel(host, username, **auth_methods) self._client_connect(self.client, host, username, **auth_methods) except Exception as e: # raise e # print('Connection::connect() exception:') - application.logger.warning(f"Connection: Connection failed due to {str(e)}") return False, str(e) self.host = host self.username = username - application.logger.debug(f"Connection: Successfully connected to {username}@{host}") return True, '' @staticmethod @@ -184,14 +160,11 @@ def ssh_keygen(key_filename=None, key_file_obj=None, public_key_comment=''): # save the private key if key_filename is not None: - application.logger.debug(f"Connection: RSA SSH private key written to {key_filename}") rsa_key.write_private_key_file(key_filename) elif key_file_obj is not None: rsa_key.write_private_key(key_file_obj) - application.logger.debug(f"Connection: RSA SSH private key written to {key_file_obj}") else: - application.logger.error("Connection: Neither key_filename nor key_file_obj is provided.") - # raise ValueError('Neither key_filename nor key_file_obj is provided.') + raise ValueError('Neither key_filename nor key_file_obj is provided.') # ssh-rsa: key type # rsa_key.get_base64(): key phrase @@ -212,16 +185,13 @@ def save_keys(self, key_filename=None, key_file_obj=None, public_key_comment='') # generate key pairs and save the private key in the key file object pub_key = Connection.ssh_keygen(key_file_obj=key_file_obj, public_key_comment=public_key_comment) else: - application.logger.error("Connection: Neither key_filename nor key_file_obj is provided.") - # raise ValueError('Neither key_filename nor key_file_obj is provided.') + raise ValueError('Neither key_filename nor key_file_obj is provided.') # save the public key onto the remote server exit_status, _, _, _ = self.exec_command_blocking( "mkdir -p ~/.ssh && chmod 700 ~/.ssh && echo '%s' >> ~/.ssh/authorized_keys" % pub_key) if exit_status != 0: - application.logger.warning("Connection: unable to save public key; Check for disk quota and permissions with any conventional SSH clients. ") return False, "Connection::save_keys: unable to save public key; Check for disk quota and permissions with any conventional SSH clients. " - application.logger.debug("Connection: Public ssh key saved to remove server ~/.ssh/authorized_keys") return True, "" @@ -247,7 +217,6 @@ def exec_command_blocking_large(self, command): return '\n'.join(stdout) + '\n' + '\n'.join(stderr) def _port_forward_thread(self, local_port, remote_port): - application.logger.debug("Connection: Port forward thread started") forward_server = ForwardServer(("", local_port), ForwardServerHandler) forward_server.ssh_transport = self.client.get_transport() @@ -255,20 +224,15 @@ def _port_forward_thread(self, local_port, remote_port): forward_server.serve_forever() forward_server.server_close() - application.logger.debug("Connection: Port forward thread ended") def port_forward(self, *args): forwarding_thread = threading.Thread(target=self._port_forward_thread, args=args) forwarding_thread.start() def is_eecg(self): - if 'eecg' in self.host: - application.logger.debug("Connection: Target host is eecg") return 'eecg' in self.host def is_ecf(self): - if 'ecf' in self.host: - application.logger.debug("Connection: Target host is ecf") return 'ecf' in self.host def is_uoft(self): @@ -292,9 +256,6 @@ def is_load_high(self): my_pts_count = len(output) - 1 # -1: excluding the `uptime` output - application.logger.debug(f"Connection: pts count: {pts_count}; my pts count: {my_pts_count}") - application.logger.debug(f"Connection: load sum: {load_sum}") - if pts_count > my_pts_count: # there are more terminals than mine return True elif load_sum > 1.0: diff --git a/application/features/SFTP.py b/application/features/SFTP.py index 4bf895c..db0de04 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -26,7 +26,7 @@ from paramiko.sftp_client import SFTPClient from .Connection import Connection -import application + class SFTP(Connection): def __init__(self): @@ -41,18 +41,14 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): - application.logger.debug("SFTP: Establishing SFTP connection") status, reason = super().connect(*args, **kwargs) if not status: - application.logger.warning(f"SFTP: connect failed due to {reason}") return status, reason try: - application.logger.debug("SFTP: Open SFTP client connection") self.sftp = self.client.open_sftp() self.sftp.chdir(".") except Exception as e: - application.logger.warning(f"SFTP: Client connect failed due to {e}") return False, str(e) return True, '' @@ -63,7 +59,6 @@ def ls(self, path=""): self.sftp.chdir(path) cwd = self.sftp.getcwd() attrs = self.sftp.listdir_attr(cwd) - application.logger.debug(f"SFTP: ls {cwd}: {attrs}") file_list = [] # TODO: should support uid and gid later @@ -77,7 +72,6 @@ def ls(self, path=""): } file_list.append(file) except Exception as e: - application.logger.warning(f"SFTP: 'ls' failed due to {e}") return False, repr(e), [] return True, cwd, file_list @@ -98,7 +92,6 @@ def dl_generator(self, path): yield chunk chunk = f.read(paramiko.sftp_file.SFTPFile.MAX_REQUEST_SIZE) except PermissionError: - application.logger.warning(f"SFTP: dl_generator Permission denied reading {path}") yield bytes() def _zip_dir_recurse(self, z, parent, file): @@ -107,11 +100,9 @@ def _zip_dir_recurse(self, z, parent, file): mode = self.sftp.stat(fullpath).st_mode if stat.S_ISREG(mode): # print(fullpath, 'is file') - application.logger.debug(f"SFTP: {fullpath} is a file") z.write_iter(fullpath, self.dl_generator(fullpath)) elif stat.S_ISDIR(mode): # print(fullpath, 'is dir') - application.logger.debug(f"SFTP: {fullpath} is a directory") # TODO: support writing an empty directory if len(dir_ls)==0 # That will involve modifying the zipstream library dir_ls = self.sftp.listdir(fullpath) @@ -120,19 +111,15 @@ def _zip_dir_recurse(self, z, parent, file): except FileNotFoundError: # likely due to a symlink that cannot be resolved # do nothing for now - application.logger.warning(f"SFTP: zip_dir_recurse failed on {fullpath} due to FileNotFoundError") return except PermissionError: - application.logger.warning(f"SFTP: zip_dir_recurse failed on {fullpath} due to PermissionError") return def zip_generator(self, cwd, file_list): - application.logger.debug(f"SFTP: zip_generator on directory: {cwd}") self.sftp.chdir(cwd) z = zipstream.ZipFile(compression=zipstream.ZIP_DEFLATED, allowZip64=True) for file in file_list: - application.logger.debug(f"SFTP: zip_generator on file: {file}") self._zip_dir_recurse(z, '', file) return z @@ -141,9 +128,7 @@ def rename(self, cwd, old, new): try: self.sftp.chdir(cwd) self.sftp.rename(old, new) - application.logger.debug(f"SFTP: Rename {old} in directory {cwd} to {new}") except Exception as e: - application.logger.warning(f"SFTP: Rename failed due to {e}") return False, repr(e) return True, '' @@ -151,11 +136,9 @@ def rename(self, cwd, old, new): def chmod(self, path, mode, recursive): _, _, _, stderr = self.exec_command_blocking( f'chmod {"-R" if recursive else ""} {"{0:0{1}o}".format(mode, 3)} "{path}"') - application.logger.debug("SFTP: Change permission on " + path + " to '{0:0{1}o}'".format(mode, 3)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - application.logger.warning(f"SFTP: chmod failed due to {stderr_lines}") - # print(stderr_lines) + print(stderr_lines) return False, 'Some files were not applied with the request mode due to permission issues.' return True, '' @@ -176,24 +159,20 @@ def rm(self, cwd, file_list): counter += 1 if counter == 50: - application.logger.debug(f"SFTP: Execute Command {' '.join(cmd_list)}") _, _, stderr = self.client.exec_command(" ".join(cmd_list)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - application.logger.warning(f"SFTP: rm file failed due to {stderr_lines}") - # print(stderr_lines) + print(stderr_lines) result = 'Some files are not removed due to insufficient permissions' # reset counter counter = 0 cmd_list = [f'cd "{cwd}" && rm -rf'] - application.logger.debug(f"SFTP: Execute Command {' '.join(cmd_list)}") _, _, stderr = self.client.exec_command(" ".join(cmd_list)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - application.logger.warning(f"SFTP: rm file failed due to {stderr_lines}") - # print(stderr_lines) + print(stderr_lines) result = 'Some files are not removed due to insufficient permissions' if result != '': @@ -201,10 +180,8 @@ def rm(self, cwd, file_list): return True, '' def mkdir(self, cwd, name): - application.logger.debug(f"SFTP: Make directory {name} at {cwd}") _, _, _, stderr = self.exec_command_blocking(f'cd "{cwd}"&& mkdir "{name}"') stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - application.logger.warning(f"SFTP: mkdir {name} in {cwd} failed due to {stderr_lines}") return False, stderr_lines[0] return True, '' diff --git a/application/features/Term.py b/application/features/Term.py index 3b1c1a3..daac726 100644 --- a/application/features/Term.py +++ b/application/features/Term.py @@ -30,7 +30,7 @@ from .Connection import Connection from .. import app from ..utils import find_free_port, local_auth, get_headers_dict_from_str -import application + TERM_CONNECTIONS = {} @@ -49,15 +49,12 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): - application.logger.debug("Term: Establishing Term connection") return super().connect(*args, **kwargs) def launch_shell(self): try: - application.logger.debug("Term: Launching Shell Terminal") self.channel = self.client.invoke_shell('xterm-256color') except Exception as e: - application.logger.warning(f"Term: Launching Shell Terminal failed with error {str(e)}") return False, str(e) self.id = uuid.uuid4().hex @@ -67,10 +64,8 @@ def launch_shell(self): def resize(self, width, height): try: - application.logger.debug(f"Term: Resizing Term to {width}x{height}") self.channel.resize_pty(width, height) except Exception as e: - application.logger.warning(f"Term: Resize Terminal failed with error {str(e)}") return False, str(e) return True, '' @@ -82,7 +77,6 @@ def __init__(self, *args, **kwargs): self.term = None def handleMessage(self): - application.logger.debug(f"TermWebSocket: Send message {self.data}") self.term.channel.send(self.data) def handleConnected(self): @@ -90,37 +84,30 @@ def handleConnected(self): headers = get_headers_dict_from_str(headers) if not local_auth(headers=headers, abort_func=self.close): # local auth failure - application.logger.warning("TermWebSocket: Local Authentication Failure") return - application.logger.debug(f"TermWebSocket: connected to {self.address}") print(self.address, 'connected') terminal_id = self.request.path[1:] if terminal_id not in TERM_CONNECTIONS: - # print(f'TermWebSocket: Requested terminal_id={terminal_id} does not exist.') - application.logger.warning(f"TermWebSocket: Requested terminal_id={terminal_id} does not exist.") + print(f'TermWebSocket: Requested terminal_id={terminal_id} does not exist.') self.close() return self.term = TERM_CONNECTIONS[terminal_id] def writeall(): - application.logger.debug("TermWebSocket: Writeall thread started") while True: data = self.term.channel.recv(1024) if not data: - # print(f"\r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") - application.logger.debug(f"TermWebSocket: \r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") + print(f"\r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") self.close() break self.sendMessage(data) - application.logger.debug("TermWebSocket: Writeall thread ended") writer = threading.Thread(target=writeall) writer.start() def handleClose(self): - application.logger.debug(f"TermWebSocket: Closing terminal {self.term.id} connection") del TERM_CONNECTIONS[self.term.id] del self.term @@ -131,15 +118,12 @@ def handleClose(self): if not app.debug or os.environ.get("WERKZEUG_RUN_MAIN") == "true": TERMINAL_PORT = find_free_port() print("TERMINAL_PORT =", TERMINAL_PORT) - application.logger.debug("Term: Terminal port {}".format(TERMINAL_PORT)) if os.environ.get('SSL_CERT_PATH') is None: - application.logger.debug("Term: SSL Certification Path not set. Generating self-signing certificate") # no certificate provided, generate self-signing certificate terminal_server = SimpleSSLWebSocketServer('127.0.0.1', TERMINAL_PORT, TermWebSocket, ssl_context=generate_adhoc_ssl_context()) else: - application.logger.debug("Term: SSL Certification Path exists") import ssl terminal_server = SimpleSSLWebSocketServer('0.0.0.0', TERMINAL_PORT, TermWebSocket, diff --git a/application/features/VNC.py b/application/features/VNC.py index 2dddf3f..6508edb 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -27,12 +27,12 @@ from .mywebsockify import MyProxyRequestHandler, MySSLProxyServer from .vncpasswd import decrypt_passwd from ..utils import find_free_port -import application + +logger = logging.getLogger(__name__) + def websocket_proxy_thread(local_websocket_port, local_vnc_port): - application.logger.debug("VNC: Start websocket proxy thread") if os.environ.get('SSL_CERT_PATH') is None: - application.logger.debug("VNC: SSL Certification Path not set. Initialize SSL Proxy Server.") proxy_server = MySSLProxyServer(RequestHandlerClass=MyProxyRequestHandler, listen_port=local_websocket_port, target_host='', target_port=local_vnc_port) @@ -41,24 +41,16 @@ def websocket_proxy_thread(local_websocket_port, local_vnc_port): # 1st: first handshake: upgrade the HTTP request # 2nd: actually serve the ws connection for _ in range(2): - if _ == 0: - application.logger.debug("VNC: Handle HTTP request") - else: - application.logger.debug("VNC: Handle WebSocket connection") proxy_server.handle_request() - application.logger.debug("VNC: Close SSL Proxy Server") proxy_server.server_close() else: - application.logger.debug("VNC: SSL Certification Path exists") import subprocess - application.logger.debug(f"VNC: Run websockify on websocket port {local_websocket_port} and vncport {local_vnc_port}") subprocess.run(["/var/www/ictrl/application/websockify-other/c/websockify", f'{local_websocket_port}', f':{local_vnc_port}', '--run-once', '--ssl-only', '--cert', os.environ.get('SSL_CERT_PATH'), '--key', os.environ.get('SSL_KEY_PATH')]) - application.logger.debug("VNC: End websocket proxy thread") class VNC(Connection): @@ -72,14 +64,12 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): - application.logger.debug("VNC: Establishing VNC connection") return super().connect(*args, **kwargs) def get_vnc_password(self): _, _, stdout, _ = self.exec_command_blocking("hexdump --format '16/1 \"%02x\"' ~/.vnc/passwd") hexdump = stdout.readline().rstrip() if hexdump == '': - application.logger.warning("VNC: VNC Password is empty") return False, '' else: return True, decrypt_passwd(bytearray.fromhex(hexdump)) @@ -103,7 +93,6 @@ def remove_vnc_settings(self): _, _, _, stderr = self.exec_command_blocking(';'.join(remove_cmd_lst)) stderr_text = "\n".join(stderr) if len(stderr_text): - application.logger.warning(f"VNC: Error removing VNC settings: {stderr_text}") return False, stderr_text return True, '' @@ -130,7 +119,7 @@ def reset_vnc_password(self, password): _, _, _, stderr = self.exec_command_blocking(';'.join(reset_cmd_lst)) error_lines = [] for line in stderr: - application.logger.warning("VNC: Error resetting VNC password: %s", line) + logger.error("reset_vnc_password::exec_command_blocking stderr line: %s", line) if "Disk quota exceeded" in line: return False, 'Disk quota exceeded' @@ -144,15 +133,12 @@ def reset_vnc_password(self, password): def launch_vnc(self): ports_by_me = [] _, _, stdout, _ = self.exec_command_blocking('vncserver -list') - application.logger.debug("VNC: Listing vnc servers") for line in stdout: if 'stale' not in line: # if the server was improperly terminated, the status is 'stale' this_port_by_me = re.findall(r'\d+', line) if len(this_port_by_me) != 0: ports_by_me.append(this_port_by_me[0]) - if line.strip() != "": - application.logger.debug("VNC: VNC server list output: %s", line.strip()) # FIXME: handle disk quota issue when launching vncserver relaunch = False @@ -162,13 +148,11 @@ def launch_vnc(self): 'vncserver' ] if len(ports_by_me) > 1 or len(ports_by_me) == 0: - application.logger.debug("VNC: Relaunch VNC servers") # TODO: might recover the valid ones # more than one VNC servers are listening and therefore all killed above to prevent unexpected results _, _, stdout, stderr = self.exec_command_blocking(';'.join(relaunch_cmd_list)) stderr_lines = "".join(stderr.readlines()) if len(stderr_lines) != 0: - application.logger.warning("VNC: Error relaunching VNC servers: %s", stderr_lines) if 'quota' in stderr_lines: return False, 'QUOTA' else: @@ -185,7 +169,6 @@ def launch_vnc(self): if match: vnc_port = int(match.group(1)) break - application.logger.debug("VNC: VNC port: %s", vnc_port) # FIXME: use a better condition than is_eecg """ @@ -201,8 +184,7 @@ def launch_vnc(self): def create_tunnel(self, remote_port): local_vnc_port = find_free_port() local_websocket_port = find_free_port() - application.logger.debug(f"VNC: Local VNC Port is {local_vnc_port}") - application.logger.debug(f"VNC: Local Web Socket Port is {local_websocket_port}") + self.port_forward(local_vnc_port, remote_port) proxy_thread = threading.Thread(target=websocket_proxy_thread, diff --git a/application/features/mywebsockify.py b/application/features/mywebsockify.py index 88c61d0..1432e1e 100644 --- a/application/features/mywebsockify.py +++ b/application/features/mywebsockify.py @@ -2,7 +2,7 @@ from werkzeug.serving import generate_adhoc_ssl_context from application.utils import local_auth -import application + class MyProxyRequestHandler(websockify.ProxyRequestHandler): def auth_connection(self): @@ -18,7 +18,6 @@ def __init__(self, RequestHandlerClass=websockify.ProxyRequestHandler, ssl_conte super(MySSLProxyServer, self).__init__(RequestHandlerClass=RequestHandlerClass, **kwargs) if ssl_context is None: - application.logger.debug("Generating self-signed SSL certificate") # no certificate provided, generate self-signing certificate ssl_context = generate_adhoc_ssl_context() self.socket = ssl_context.wrap_socket(self.socket, server_side=True) diff --git a/application/features/vncpasswd.py b/application/features/vncpasswd.py index d93e26e..32b928b 100644 --- a/application/features/vncpasswd.py +++ b/application/features/vncpasswd.py @@ -19,7 +19,6 @@ # IN THE SOFTWARE. import pyDes -import application KEY = [232, 74, 214, 96, 196, 114, 26, 224] CRYPT = pyDes.des(KEY) @@ -43,7 +42,6 @@ def vncpasswd(passwd_path, password=None): with open(passwd_path, "wb") as passwd: passwd.write(obfuscated) - application.logger.debug("Vnc Password: Write obfuscated password to {}".format(passwd_path)) return obfuscated