From 49c74e17722538fb992dfacc428a339bfb147dac Mon Sep 17 00:00:00 2001 From: IreneLi Date: Thu, 26 Sep 2024 23:04:54 -0400 Subject: [PATCH 1/8] Integrate logging to application/features/. --- application/features/Audio.py | 28 +++++++++++++++++++---- application/features/Connection.py | 34 +++++++++++++++++++++++++++- application/features/SFTP.py | 19 ++++++++++++++-- application/features/Term.py | 22 +++++++++++++++--- application/features/VNC.py | 28 +++++++++++++++++++---- application/features/mywebsockify.py | 5 +++- application/features/vncpasswd.py | 6 ++++- 7 files changed, 126 insertions(+), 16 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index 6698c8c7..db4b71ad 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -31,6 +31,9 @@ from .Connection import Connection from .. import app from ..utils import find_free_port, get_headers_dict_from_str, local_auth +import logging.config + +logger = logging.getLogger(__name__) AUDIO_CONNECTIONS = {} @@ -57,13 +60,16 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + logger.debug("Audio: Establishing Audio connection") return super().connect(*args, **kwargs) def launch_audio(self): try: + 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: + logger.warning("Audio: exception raised during launch audio: {}".format(e)) return False, str(e) self.id = uuid.uuid4().hex @@ -83,11 +89,12 @@ def handleConnected(self): headers = get_headers_dict_from_str(headers) if not local_auth(headers=headers, abort_func=self.close): # local auth failure + 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.') + logger.warning(f'AudioWebSocket: Requested audio_id={audio_id} does not exist.') self.close() return @@ -103,26 +110,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}') + 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() + 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(): + 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: + 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 + logger.debug("AudioWebSocket: ffmpeg_launcher thread ended") ffmpeg_launcher_thread = threading.Thread(target=ffmpeg_launcher) def writer(): + logger.debug("AudioWebSocket: writer thread started") channel = self.audio.transport.accept(FFMPEG_LOAD_TIME * TRY_FFMPEG_MAX_COUNT) nonlocal keep_launching_ffmpeg @@ -138,14 +150,17 @@ def writer(): while True: data = channel.recv(AUDIO_BUFFER_SIZE) if not data: + logger.debug("AudioWebSocket: Close audio socket connection") self.close() break buffer += data if len(buffer) >= AUDIO_BUFFER_SIZE: compressed = zlib.compress(buffer, level=4) + logger.debug(f"AudioWebSocket: Send compressed message of size {len(compressed)}") self.sendMessage(compressed) # print(len(compressed) / len(buffer) * 100) buffer = b'' + logger.debug("AudioWebSocket: write thread ended") writer_thread = threading.Thread(target=writer) @@ -155,8 +170,10 @@ def writer(): def handleClose(self): if self.module_id is not None: # unload the module before leaving + logger.debug(f"AudioWebSocket: Unload module {self.module_id}") self.audio.client.exec_command(f'pactl unload-module {self.module_id}') + logger.debug(f"AudioWebSocket: End audio socket {self.audio.id} connection") del AUDIO_CONNECTIONS[self.audio.id] del self.audio @@ -166,13 +183,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) + logger.debug("Audio: Audio port {}".format(AUDIO_PORT)) if os.environ.get('SSL_CERT_PATH') is None: + 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: + logger.debug("Audio: SSL Certification Path exists") import ssl audio_server = SimpleSSLWebSocketServer('0.0.0.0', AUDIO_PORT, AudioWebSocket, @@ -180,4 +200,4 @@ def handleClose(self): keyfile=os.environ.get('SSL_KEY_PATH'), version=ssl.PROTOCOL_TLS) - threading.Thread(target=audio_server.serveforever, daemon=True).start() + threading.Thread(target=audio_server.serveforever, daemon=True).start() \ No newline at end of file diff --git a/application/features/Connection.py b/application/features/Connection.py index ad0ee0e0..95fad771 100644 --- a/application/features/Connection.py +++ b/application/features/Connection.py @@ -27,11 +27,15 @@ import paramiko import select +import logging.config + +logger = logging.getLogger(__name__) class ForwardServerHandler(socketserver.BaseRequestHandler): def handle(self): self.server: ForwardServer try: + logger.debug("Connection: Open forward server channel") chan = self.server.ssh_transport.open_channel( "direct-tcpip", ("127.0.0.1", self.server.chain_port), @@ -49,6 +53,14 @@ def handle(self): ("127.0.0.1", self.server.chain_port), ) ) + logger.debug( + "Connected! Tunnel open %r -> %r -> %r" + % ( + self.request.getpeername(), + chan.getpeername(), + ("127.0.0.1", self.server.chain_port), + ) + ) try: while True: @@ -67,6 +79,7 @@ def handle(self): print(e) try: + logger.debug("Connection: Close forward server channel") chan.close() self.server.shutdown() except Exception as e: @@ -102,6 +115,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: + logger.debug("Connection: Connection initialized through Jump Channel") + 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: @@ -128,13 +144,16 @@ def _init_jump_channel(self, host, username, **auth_methods): self._jump_client = paramiko.SSHClient() self._jump_client.set_missing_host_key_policy(paramiko.AutoAddPolicy()) + 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) + 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: + 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: @@ -145,6 +164,7 @@ def connect(self, host: str, username: str, **auth_methods): self.host = host self.username = username + logger.debug(f"Connection: Successfully connected to {username}@{host}") return True, '' @staticmethod @@ -160,9 +180,11 @@ def ssh_keygen(key_filename=None, key_file_obj=None, public_key_comment=''): # save the private key if key_filename is not None: + 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) + 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.') @@ -192,6 +214,7 @@ def save_keys(self, key_filename=None, key_file_obj=None, public_key_comment='') "mkdir -p ~/.ssh && chmod 700 ~/.ssh && echo '%s' >> ~/.ssh/authorized_keys" % pub_key) if exit_status != 0: return False, "Connection::save_keys: unable to save public key; Check for disk quota and permissions with any conventional SSH clients. " + logger.debug("Connection: Public ssh key saved to remove server ~/.ssh/authorized_keys") return True, "" @@ -217,6 +240,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): + logger.debug("Connection: Port forward thread started") forward_server = ForwardServer(("", local_port), ForwardServerHandler) forward_server.ssh_transport = self.client.get_transport() @@ -224,15 +248,20 @@ def _port_forward_thread(self, local_port, remote_port): forward_server.serve_forever() forward_server.server_close() + 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: + logger.debug("Connection: Target host is eecg") return 'eecg' in self.host def is_ecf(self): + if 'ecf' in self.host: + logger.debug("Connection: Target host is ecf") return 'ecf' in self.host def is_uoft(self): @@ -256,6 +285,9 @@ def is_load_high(self): my_pts_count = len(output) - 1 # -1: excluding the `uptime` output + logger.debug(f"Connection: pts count: {pts_count}; my pts count: {my_pts_count}") + 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: @@ -265,4 +297,4 @@ def is_load_high(self): # it is considered a high load return True - return False + return False \ No newline at end of file diff --git a/application/features/SFTP.py b/application/features/SFTP.py index db0de048..387deeae 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -26,7 +26,9 @@ from paramiko.sftp_client import SFTPClient from .Connection import Connection +import logging.config +logger = logging.getLogger(__name__) class SFTP(Connection): def __init__(self): @@ -41,11 +43,13 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + logger.debug("SFTP: Establishing SFTP connection") status, reason = super().connect(*args, **kwargs) if not status: return status, reason try: + logger.debug("SFTP: Open SFTP client connection") self.sftp = self.client.open_sftp() self.sftp.chdir(".") except Exception as e: @@ -59,6 +63,7 @@ def ls(self, path=""): self.sftp.chdir(path) cwd = self.sftp.getcwd() attrs = self.sftp.listdir_attr(cwd) + logger.debug(f"SFTP: ls {cwd}: {attrs}") file_list = [] # TODO: should support uid and gid later @@ -100,9 +105,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') + 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') + 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) @@ -116,10 +123,12 @@ def _zip_dir_recurse(self, z, parent, file): return def zip_generator(self, cwd, file_list): + 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: + logger.debug(f"SFTP: zip_generator on file: {file}") self._zip_dir_recurse(z, '', file) return z @@ -128,6 +137,7 @@ def rename(self, cwd, old, new): try: self.sftp.chdir(cwd) self.sftp.rename(old, new) + logger.debug(f"SFTP: Rename {old} in directory {cwd} to {new}") except Exception as e: return False, repr(e) @@ -136,9 +146,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}"') + 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) + 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,6 +171,7 @@ def rm(self, cwd, file_list): counter += 1 if counter == 50: + 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: @@ -169,6 +182,7 @@ def rm(self, cwd, file_list): counter = 0 cmd_list = [f'cd "{cwd}" && rm -rf'] + 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: @@ -180,8 +194,9 @@ def rm(self, cwd, file_list): return True, '' def mkdir(self, cwd, name): + 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: return False, stderr_lines[0] - return True, '' + return True, '' \ No newline at end of file diff --git a/application/features/Term.py b/application/features/Term.py index daac726d..829ca550 100644 --- a/application/features/Term.py +++ b/application/features/Term.py @@ -30,7 +30,9 @@ from .Connection import Connection from .. import app from ..utils import find_free_port, local_auth, get_headers_dict_from_str +import logging.config +logger = logging.getLogger(__name__) TERM_CONNECTIONS = {} @@ -49,10 +51,12 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + logger.debug("Term: Establishing Term connection") return super().connect(*args, **kwargs) def launch_shell(self): try: + logger.debug("Term: Launching Shell Terminal") self.channel = self.client.invoke_shell('xterm-256color') except Exception as e: return False, str(e) @@ -64,6 +68,7 @@ def launch_shell(self): def resize(self, width, height): try: + logger.debug(f"Term: Resizing Term to {width}x{height}") self.channel.resize_pty(width, height) except Exception as e: return False, str(e) @@ -77,6 +82,7 @@ def __init__(self, *args, **kwargs): self.term = None def handleMessage(self): + 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 + logger.warning("TermWebSocket: Local Authentication Failure") return + 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.') + logger.warning(f"TermWebSocket: Requested terminal_id={terminal_id} does not exist.") self.close() return self.term = TERM_CONNECTIONS[terminal_id] def writeall(): + 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") + logger.debug(f"TermWebSocket: \r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") self.close() break self.sendMessage(data) + logger.debug("TermWebSocket: Writeall thread ended") writer = threading.Thread(target=writeall) writer.start() def handleClose(self): + 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) + logger.debug("Term: Terminal port {}".format(TERMINAL_PORT)) if os.environ.get('SSL_CERT_PATH') is None: + 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: + logger.debug("Term: SSL Certification Path exists") import ssl terminal_server = SimpleSSLWebSocketServer('0.0.0.0', TERMINAL_PORT, TermWebSocket, @@ -131,4 +147,4 @@ def handleClose(self): keyfile=os.environ.get('SSL_KEY_PATH'), version=ssl.PROTOCOL_TLS) - threading.Thread(target=terminal_server.serveforever, daemon=True).start() + threading.Thread(target=terminal_server.serveforever, daemon=True).start() \ No newline at end of file diff --git a/application/features/VNC.py b/application/features/VNC.py index 6508edbb..29442cf4 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -27,12 +27,14 @@ from .mywebsockify import MyProxyRequestHandler, MySSLProxyServer from .vncpasswd import decrypt_passwd from ..utils import find_free_port +import logging.config logger = logging.getLogger(__name__) - def websocket_proxy_thread(local_websocket_port, local_vnc_port): + logger.debug("VNC: Start websocket proxy thread") if os.environ.get('SSL_CERT_PATH') is None: + 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 +43,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: + logger.debug("VNC: Handle HTTP request") + else: + logger.debug("VNC: Handle WebSocket connection") proxy_server.handle_request() + logger.debug("VNC: Close SSL Proxy Server") proxy_server.server_close() else: + logger.debug("VNC: SSL Certification Path exists") import subprocess + 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')]) + logger.debug("VNC: End websocket proxy thread") class VNC(Connection): @@ -64,12 +74,14 @@ def __del__(self): super().__del__() def connect(self, *args, **kwargs): + 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 == '': + logger.warning("VNC: VNC Password is empty") return False, '' else: return True, decrypt_passwd(bytearray.fromhex(hexdump)) @@ -93,6 +105,7 @@ def remove_vnc_settings(self): _, _, _, stderr = self.exec_command_blocking(';'.join(remove_cmd_lst)) stderr_text = "\n".join(stderr) if len(stderr_text): + logger.warning(f"VNC: Error removing VNC settings: {stderr_text}") return False, stderr_text return True, '' @@ -119,7 +132,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) + logger.warning("VNC: Error resetting VNC password: %s", line) if "Disk quota exceeded" in line: return False, 'Disk quota exceeded' @@ -133,12 +146,15 @@ def reset_vnc_password(self, password): def launch_vnc(self): ports_by_me = [] _, _, stdout, _ = self.exec_command_blocking('vncserver -list') + 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() != "": + logger.debug("VNC: VNC server list output: %s", line.strip()) # FIXME: handle disk quota issue when launching vncserver relaunch = False @@ -148,11 +164,13 @@ def launch_vnc(self): 'vncserver' ] if len(ports_by_me) > 1 or len(ports_by_me) == 0: + 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: + logger.warning("VNC: Error relaunching VNC servers: %s", stderr_lines) if 'quota' in stderr_lines: return False, 'QUOTA' else: @@ -169,6 +187,7 @@ def launch_vnc(self): if match: vnc_port = int(match.group(1)) break + logger.debug("VNC: VNC port: %s", vnc_port) # FIXME: use a better condition than is_eecg """ @@ -184,11 +203,12 @@ def launch_vnc(self): def create_tunnel(self, remote_port): local_vnc_port = find_free_port() local_websocket_port = find_free_port() - + logger.debug(f"VNC: Local VNC Port is {local_vnc_port}") + 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, args=[local_websocket_port, local_vnc_port]) proxy_thread.start() - return local_websocket_port + return local_websocket_port \ No newline at end of file diff --git a/application/features/mywebsockify.py b/application/features/mywebsockify.py index 1432e1e4..7e86fd27 100644 --- a/application/features/mywebsockify.py +++ b/application/features/mywebsockify.py @@ -2,7 +2,9 @@ from werkzeug.serving import generate_adhoc_ssl_context from application.utils import local_auth +import logging.config +logger = logging.getLogger(__name__) class MyProxyRequestHandler(websockify.ProxyRequestHandler): def auth_connection(self): @@ -18,6 +20,7 @@ def __init__(self, RequestHandlerClass=websockify.ProxyRequestHandler, ssl_conte super(MySSLProxyServer, self).__init__(RequestHandlerClass=RequestHandlerClass, **kwargs) if ssl_context is None: + 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) + self.socket = ssl_context.wrap_socket(self.socket, server_side=True) \ No newline at end of file diff --git a/application/features/vncpasswd.py b/application/features/vncpasswd.py index 32b928b6..e6951901 100644 --- a/application/features/vncpasswd.py +++ b/application/features/vncpasswd.py @@ -19,6 +19,9 @@ # IN THE SOFTWARE. import pyDes +import logging.config + +logger = logging.getLogger(__name__) KEY = [232, 74, 214, 96, 196, 114, 26, 224] CRYPT = pyDes.des(KEY) @@ -42,6 +45,7 @@ def vncpasswd(passwd_path, password=None): with open(passwd_path, "wb") as passwd: passwd.write(obfuscated) + logger.debug("Vnc Password: Write obfuscated password to {}".format(passwd_path)) return obfuscated @@ -66,4 +70,4 @@ def read_password(): if passwd != passwd2: print("Passwords don't match - try again") continue - return obfuscate_password(passwd) + return obfuscate_password(passwd) \ No newline at end of file From a4e548a85f2b3a37718b025847f121a12e72910a Mon Sep 17 00:00:00 2001 From: IreneLi Date: Sun, 5 Jan 2025 01:30:05 -0500 Subject: [PATCH 2/8] Change string formatting to replace f-strings --- application/features/Audio.py | 23 +++++++++++++---------- application/features/Connection.py | 30 ++++++++++++++---------------- application/features/SFTP.py | 25 +++++++++++-------------- application/features/Term.py | 16 +++++++--------- application/features/VNC.py | 8 ++++---- application/features/vncpasswd.py | 2 +- 6 files changed, 50 insertions(+), 54 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index db4b71ad..500efb5c 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -69,7 +69,7 @@ def launch_audio(self): self.transport = self.client.get_transport() self.remote_port = self.transport.request_port_forward('127.0.0.1', 0) except Exception as e: - logger.warning("Audio: exception raised during launch audio: {}".format(e)) + logger.warning("Audio: exception raised during launch audio: %s", e) return False, str(e) self.id = uuid.uuid4().hex @@ -94,7 +94,7 @@ def handleConnected(self): audio_id = self.request.path[1:] if audio_id not in AUDIO_CONNECTIONS: - logger.warning(f'AudioWebSocket: Requested audio_id={audio_id} does not exist.') + logger.warning("AudioWebSocket: Requested audio_id=%s does not exist.", audio_id) self.close() return @@ -110,10 +110,14 @@ 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: - logger.warning(f'AudioWebSocket: audio_id={audio_id}: unable to load pactl module-null-sink sink_name={sink_name}') + logger.warning( + "AudioWebSocket: audio_id=%s: unable to load pactl module-null-sink sink_name=%s", + audio_id, + sink_name + ) return load_module_stdout_lines = stdout.readlines() - logger.debug("AudioWebSocket: Load Module: {}".format(load_module_stdout_lines)) + logger.debug("AudioWebSocket: Load Module: %s", load_module_stdout_lines) self.module_id = int(load_module_stdout_lines[0]) keep_launching_ffmpeg = True @@ -125,7 +129,7 @@ def ffmpeg_launcher(): 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: - logger.debug(f"AudioWebSocket: Launch ffmpeg: {launch_ffmpeg_command}") + logger.debug("AudioWebSocket: Launch ffmpeg: %s", 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 @@ -156,7 +160,7 @@ def writer(): buffer += data if len(buffer) >= AUDIO_BUFFER_SIZE: compressed = zlib.compress(buffer, level=4) - logger.debug(f"AudioWebSocket: Send compressed message of size {len(compressed)}") + logger.debug("AudioWebSocket: Send compressed message of size %s", len(compressed)) self.sendMessage(compressed) # print(len(compressed) / len(buffer) * 100) buffer = b'' @@ -170,10 +174,10 @@ def writer(): def handleClose(self): if self.module_id is not None: # unload the module before leaving - logger.debug(f"AudioWebSocket: Unload module {self.module_id}") + logger.debug("AudioWebSocket: Unload module %s", self.module_id) self.audio.client.exec_command(f'pactl unload-module {self.module_id}') - logger.debug(f"AudioWebSocket: End audio socket {self.audio.id} connection") + logger.debug("AudioWebSocket: End audio socket %s connection", self.audio.id) del AUDIO_CONNECTIONS[self.audio.id] del self.audio @@ -183,8 +187,7 @@ 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) - logger.debug("Audio: Audio port {}".format(AUDIO_PORT)) + logger.debug("Audio: Audio port %s", AUDIO_PORT) if os.environ.get('SSL_CERT_PATH') is None: logger.debug("Audio: SSL Certification Path not set. Generating self-signing certificate") diff --git a/application/features/Connection.py b/application/features/Connection.py index 95fad771..e8154c08 100644 --- a/application/features/Connection.py +++ b/application/features/Connection.py @@ -54,12 +54,10 @@ def handle(self): ) ) logger.debug( - "Connected! Tunnel open %r -> %r -> %r" - % ( - self.request.getpeername(), - chan.getpeername(), - ("127.0.0.1", self.server.chain_port), - ) + "Connected! Tunnel open %r -> %r -> %r", + self.request.getpeername(), + chan.getpeername(), + ("127.0.0.1", self.server.chain_port), ) try: @@ -115,9 +113,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: + if self._jump_channel is not None: logger.debug("Connection: Connection initialized through Jump Channel") - logger.debug(f"Connection: Connecting to {username}@{host}") + logger.debug("Connection: Connecting to %s@%s", 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: @@ -144,16 +142,16 @@ def _init_jump_channel(self, host, username, **auth_methods): self._jump_client = paramiko.SSHClient() self._jump_client.set_missing_host_key_policy(paramiko.AutoAddPolicy()) - logger.debug(f"Connection: Initialize Jump Client for connection to {username}@remote.ecf.utoronto.ca") + logger.debug("Connection: Initialize Jump Client for connection to %s@remote.ecf.utoronto.ca", username) self._client_connect(self._jump_client, 'remote.ecf.utoronto.ca', username, **auth_methods) - logger.debug(f"Connection: Open Jump channel connection to {host} at port 22") + logger.debug("Connection: Open Jump channel connection to %s at port 22", host) 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: - logger.debug(f"Connection: Connection attempt to {username}@{host}") + logger.debug("Connection: Connection attempt to %s@%s", username, host) self._init_jump_channel(host, username, **auth_methods) self._client_connect(self.client, host, username, **auth_methods) except Exception as e: @@ -164,7 +162,7 @@ def connect(self, host: str, username: str, **auth_methods): self.host = host self.username = username - logger.debug(f"Connection: Successfully connected to {username}@{host}") + logger.debug("Connection: Successfully connected to %s@%s", username, host) return True, '' @staticmethod @@ -180,11 +178,11 @@ def ssh_keygen(key_filename=None, key_file_obj=None, public_key_comment=''): # save the private key if key_filename is not None: - logger.debug(f"Connection: RSA SSH private key written to {key_filename}") + logger.debug("Connection: RSA SSH private key written to %s", 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) - logger.debug(f"Connection: RSA SSH private key written to {key_file_obj}") + logger.debug("Connection: RSA SSH private key written to %s", key_file_obj) else: raise ValueError('Neither key_filename nor key_file_obj is provided.') @@ -285,8 +283,8 @@ def is_load_high(self): my_pts_count = len(output) - 1 # -1: excluding the `uptime` output - logger.debug(f"Connection: pts count: {pts_count}; my pts count: {my_pts_count}") - logger.debug(f"Connection: load sum: {load_sum}") + logger.debug("Connection: pts count: %s; my pts count: %s", pts_count, my_pts_count) + logger.debug("Connection: load sum: %s", load_sum) if pts_count > my_pts_count: # there are more terminals than mine return True diff --git a/application/features/SFTP.py b/application/features/SFTP.py index 387deeae..64ee32ea 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -63,7 +63,7 @@ def ls(self, path=""): self.sftp.chdir(path) cwd = self.sftp.getcwd() attrs = self.sftp.listdir_attr(cwd) - logger.debug(f"SFTP: ls {cwd}: {attrs}") + logger.debug("SFTP: ls %s: %s", cwd, attrs) file_list = [] # TODO: should support uid and gid later @@ -104,12 +104,10 @@ def _zip_dir_recurse(self, z, parent, file): try: mode = self.sftp.stat(fullpath).st_mode if stat.S_ISREG(mode): - # print(fullpath, 'is file') - logger.debug(f"SFTP: {fullpath} is a file") + logger.debug("SFTP: %s is a file", fullpath) z.write_iter(fullpath, self.dl_generator(fullpath)) elif stat.S_ISDIR(mode): - # print(fullpath, 'is dir') - logger.debug(f"SFTP: {fullpath} is a directory") + logger.debug("SFTP: %s is a directory", fullpath) # TODO: support writing an empty directory if len(dir_ls)==0 # That will involve modifying the zipstream library dir_ls = self.sftp.listdir(fullpath) @@ -123,12 +121,12 @@ def _zip_dir_recurse(self, z, parent, file): return def zip_generator(self, cwd, file_list): - logger.debug(f"SFTP: zip_generator on directory: {cwd}") + logger.debug("SFTP: zip_generator on directory: %s", cwd) self.sftp.chdir(cwd) z = zipstream.ZipFile(compression=zipstream.ZIP_DEFLATED, allowZip64=True) for file in file_list: - logger.debug(f"SFTP: zip_generator on file: {file}") + logger.debug("SFTP: zip_generator on file: %s", file) self._zip_dir_recurse(z, '', file) return z @@ -137,7 +135,7 @@ def rename(self, cwd, old, new): try: self.sftp.chdir(cwd) self.sftp.rename(old, new) - logger.debug(f"SFTP: Rename {old} in directory {cwd} to {new}") + logger.debug("SFTP: Rename %s in directory %s to %s", old, cwd, new) except Exception as e: return False, repr(e) @@ -146,11 +144,10 @@ 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}"') - logger.debug("SFTP: Change permission on " + path + " to '{0:0{1}o}'".format(mode, 3)) + logger.debug("SFTP: Change permission on %s to '%s'", path, "{0:0{1}o}".format(mode, 3)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - logger.warning(f"SFTP: chmod failed due to {stderr_lines}") - # print(stderr_lines) + logger.warning("SFTP: chmod failed due to %s", stderr_lines) return False, 'Some files were not applied with the request mode due to permission issues.' return True, '' @@ -171,7 +168,7 @@ def rm(self, cwd, file_list): counter += 1 if counter == 50: - logger.debug(f"SFTP: Execute Command {' '.join(cmd_list)}") + logger.debug("SFTP: Execute Command %s", ' '.join(cmd_list)) _, _, stderr = self.client.exec_command(" ".join(cmd_list)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: @@ -182,7 +179,7 @@ def rm(self, cwd, file_list): counter = 0 cmd_list = [f'cd "{cwd}" && rm -rf'] - logger.debug(f"SFTP: Execute Command {' '.join(cmd_list)}") + logger.debug("SFTP: Execute Command %s", ' '.join(cmd_list)) _, _, stderr = self.client.exec_command(" ".join(cmd_list)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: @@ -194,7 +191,7 @@ def rm(self, cwd, file_list): return True, '' def mkdir(self, cwd, name): - logger.debug(f"SFTP: Make directory {name} at {cwd}") + logger.debug("SFTP: Make directory %s at %s", name, cwd) _, _, _, stderr = self.exec_command_blocking(f'cd "{cwd}"&& mkdir "{name}"') stderr_lines = stderr.readlines() if len(stderr_lines) != 0: diff --git a/application/features/Term.py b/application/features/Term.py index 829ca550..c4800750 100644 --- a/application/features/Term.py +++ b/application/features/Term.py @@ -68,7 +68,7 @@ def launch_shell(self): def resize(self, width, height): try: - logger.debug(f"Term: Resizing Term to {width}x{height}") + logger.debug("Term: Resizing Term to %sx%s", width, height) self.channel.resize_pty(width, height) except Exception as e: return False, str(e) @@ -82,7 +82,7 @@ def __init__(self, *args, **kwargs): self.term = None def handleMessage(self): - logger.debug(f"TermWebSocket: Send message {self.data}") + logger.debug("TermWebSocket: Send message %s", self.data) self.term.channel.send(self.data) def handleConnected(self): @@ -93,12 +93,11 @@ def handleConnected(self): logger.warning("TermWebSocket: Local Authentication Failure") return - logger.debug(f"TermWebSocket: connected to {self.address}") + logger.debug("TermWebSocket: connected to %s", 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.') - logger.warning(f"TermWebSocket: Requested terminal_id={terminal_id} does not exist.") + logger.warning("TermWebSocket: Requested terminal_id=%s does not exist.", terminal_id) self.close() return @@ -109,8 +108,7 @@ def writeall(): while True: data = self.term.channel.recv(1024) if not data: - # print(f"\r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") - logger.debug(f"TermWebSocket: \r\n*** {terminal_id}: Shell EOF ***\r\n\r\n") + logger.debug("TermWebSocket: \r\n*** %s: Shell EOF ***\r\n\r\n", terminal_id) self.close() break self.sendMessage(data) @@ -120,7 +118,7 @@ def writeall(): writer.start() def handleClose(self): - logger.debug(f"TermWebSocket: Closing terminal {self.term.id} connection") + logger.debug("TermWebSocket: Closing terminal %s connection", self.term.id) del TERM_CONNECTIONS[self.term.id] del self.term @@ -131,7 +129,7 @@ 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) - logger.debug("Term: Terminal port {}".format(TERMINAL_PORT)) + logger.debug("Term: Terminal port %s", TERMINAL_PORT) if os.environ.get('SSL_CERT_PATH') is None: logger.debug("Term: SSL Certification Path not set. Generating self-signing certificate") diff --git a/application/features/VNC.py b/application/features/VNC.py index 29442cf4..39425688 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -54,7 +54,7 @@ def websocket_proxy_thread(local_websocket_port, local_vnc_port): logger.debug("VNC: SSL Certification Path exists") import subprocess - logger.debug(f"VNC: Run websockify on websocket port {local_websocket_port} and vncport {local_vnc_port}") + logger.debug("VNC: Run websockify on websocket port %d and vncport %d", local_websocket_port, 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', @@ -105,7 +105,7 @@ def remove_vnc_settings(self): _, _, _, stderr = self.exec_command_blocking(';'.join(remove_cmd_lst)) stderr_text = "\n".join(stderr) if len(stderr_text): - logger.warning(f"VNC: Error removing VNC settings: {stderr_text}") + logger.warning("VNC: Error removing VNC settings: %s", stderr_text) return False, stderr_text return True, '' @@ -203,8 +203,8 @@ def launch_vnc(self): def create_tunnel(self, remote_port): local_vnc_port = find_free_port() local_websocket_port = find_free_port() - logger.debug(f"VNC: Local VNC Port is {local_vnc_port}") - logger.debug(f"VNC: Local Web Socket Port is {local_websocket_port}") + logger.debug("VNC: Local VNC Port is %s", local_vnc_port) + logger.debug("VNC: Local Web Socket Port is %s", local_websocket_port) self.port_forward(local_vnc_port, remote_port) proxy_thread = threading.Thread(target=websocket_proxy_thread, diff --git a/application/features/vncpasswd.py b/application/features/vncpasswd.py index e6951901..f477954d 100644 --- a/application/features/vncpasswd.py +++ b/application/features/vncpasswd.py @@ -45,7 +45,7 @@ def vncpasswd(passwd_path, password=None): with open(passwd_path, "wb") as passwd: passwd.write(obfuscated) - logger.debug("Vnc Password: Write obfuscated password to {}".format(passwd_path)) + logger.debug("Vnc Password: Write obfuscated password to %s", passwd_path) return obfuscated From 1a2c832551bcfa23a51c7f7a5ffef84d0ef5f32c Mon Sep 17 00:00:00 2001 From: IreneLi Date: Tue, 7 Jan 2025 17:44:01 -0500 Subject: [PATCH 3/8] Log exceptions --- application/features/Audio.py | 2 +- application/features/Connection.py | 6 ++++-- application/features/SFTP.py | 3 +++ application/features/Term.py | 2 ++ 4 files changed, 10 insertions(+), 3 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index 500efb5c..2a428272 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -69,7 +69,7 @@ def launch_audio(self): self.transport = self.client.get_transport() self.remote_port = self.transport.request_port_forward('127.0.0.1', 0) except Exception as e: - logger.warning("Audio: exception raised during launch audio: %s", e) + logger.exception("Audio: exception raised during launch audio") return False, str(e) self.id = uuid.uuid4().hex diff --git a/application/features/Connection.py b/application/features/Connection.py index e8154c08..7c3bfd2f 100644 --- a/application/features/Connection.py +++ b/application/features/Connection.py @@ -42,6 +42,7 @@ def handle(self): self.request.getpeername(), ) except Exception as e: + logger.exception("Connection: Incoming request to 127.0.0.1:%d failed", self.server.chain_port) return False, "Incoming request to %s:%d failed: %s" % ( "127.0.0.1", self.server.chain_port, repr(e)) @@ -75,6 +76,7 @@ def handle(self): self.request.send(data) except Exception as e: print(e) + logger.exception("Connection: Error occurred during data transfer") try: logger.debug("Connection: Close forward server channel") @@ -82,6 +84,7 @@ def handle(self): self.server.shutdown() except Exception as e: print(e) + logger.exception("Connection: Close forward server channel failed") class ForwardServer(socketserver.ThreadingTCPServer): @@ -155,8 +158,7 @@ def connect(self, host: str, username: str, **auth_methods): 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:') + logger.exception("Connection: Connection attempt to %s@%s failed", username, host) return False, str(e) self.host = host diff --git a/application/features/SFTP.py b/application/features/SFTP.py index 64ee32ea..db6a51e5 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -53,6 +53,7 @@ def connect(self, *args, **kwargs): self.sftp = self.client.open_sftp() self.sftp.chdir(".") except Exception as e: + logger.exception("SFTP: Open SFTP client connection failed") return False, str(e) return True, '' @@ -77,6 +78,7 @@ def ls(self, path=""): } file_list.append(file) except Exception as e: + logger.exception("SFTP: ls failed") return False, repr(e), [] return True, cwd, file_list @@ -137,6 +139,7 @@ def rename(self, cwd, old, new): self.sftp.rename(old, new) logger.debug("SFTP: Rename %s in directory %s to %s", old, cwd, new) except Exception as e: + logger.exception("SFTP: Rename failed") return False, repr(e) return True, '' diff --git a/application/features/Term.py b/application/features/Term.py index c4800750..e7ad8e70 100644 --- a/application/features/Term.py +++ b/application/features/Term.py @@ -59,6 +59,7 @@ def launch_shell(self): logger.debug("Term: Launching Shell Terminal") self.channel = self.client.invoke_shell('xterm-256color') except Exception as e: + logger.exception("Term: Launch Shell Terminal failed") return False, str(e) self.id = uuid.uuid4().hex @@ -71,6 +72,7 @@ def resize(self, width, height): logger.debug("Term: Resizing Term to %sx%s", width, height) self.channel.resize_pty(width, height) except Exception as e: + logger.exception("Term: Resize Term failed") return False, str(e) return True, '' From 28179e8d37a5314240438e6b82b06043285d030a Mon Sep 17 00:00:00 2001 From: IreneLi Date: Tue, 7 Jan 2025 17:47:13 -0500 Subject: [PATCH 4/8] Add new line after each file --- application/features/Audio.py | 2 +- application/features/Connection.py | 2 +- application/features/SFTP.py | 2 +- application/features/Term.py | 2 +- application/features/VNC.py | 2 +- application/features/vncpasswd.py | 2 +- 6 files changed, 6 insertions(+), 6 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index 2a428272..27d21d38 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -203,4 +203,4 @@ def handleClose(self): keyfile=os.environ.get('SSL_KEY_PATH'), version=ssl.PROTOCOL_TLS) - threading.Thread(target=audio_server.serveforever, daemon=True).start() \ No newline at end of file + threading.Thread(target=audio_server.serveforever, daemon=True).start() diff --git a/application/features/Connection.py b/application/features/Connection.py index 7c3bfd2f..9f1f059c 100644 --- a/application/features/Connection.py +++ b/application/features/Connection.py @@ -297,4 +297,4 @@ def is_load_high(self): # it is considered a high load return True - return False \ No newline at end of file + return False diff --git a/application/features/SFTP.py b/application/features/SFTP.py index db6a51e5..1f9e58fa 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -199,4 +199,4 @@ def mkdir(self, cwd, name): stderr_lines = stderr.readlines() if len(stderr_lines) != 0: return False, stderr_lines[0] - return True, '' \ No newline at end of file + return True, '' diff --git a/application/features/Term.py b/application/features/Term.py index e7ad8e70..7d9ca87c 100644 --- a/application/features/Term.py +++ b/application/features/Term.py @@ -147,4 +147,4 @@ def handleClose(self): keyfile=os.environ.get('SSL_KEY_PATH'), version=ssl.PROTOCOL_TLS) - threading.Thread(target=terminal_server.serveforever, daemon=True).start() \ No newline at end of file + threading.Thread(target=terminal_server.serveforever, daemon=True).start() diff --git a/application/features/VNC.py b/application/features/VNC.py index 39425688..43dc8144 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -211,4 +211,4 @@ def create_tunnel(self, remote_port): args=[local_websocket_port, local_vnc_port]) proxy_thread.start() - return local_websocket_port \ No newline at end of file + return local_websocket_port diff --git a/application/features/vncpasswd.py b/application/features/vncpasswd.py index f477954d..e538c919 100644 --- a/application/features/vncpasswd.py +++ b/application/features/vncpasswd.py @@ -70,4 +70,4 @@ def read_password(): if passwd != passwd2: print("Passwords don't match - try again") continue - return obfuscate_password(passwd) \ No newline at end of file + return obfuscate_password(passwd) From ec6cf5847ebae567ac0c89bc0f4813ea958ee303 Mon Sep 17 00:00:00 2001 From: IreneLi Date: Tue, 7 Jan 2025 18:17:44 -0500 Subject: [PATCH 5/8] Enhancing logging messages to be more specific. --- application/features/SFTP.py | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/application/features/SFTP.py b/application/features/SFTP.py index 1f9e58fa..6b5cf591 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -61,10 +61,12 @@ def connect(self, *args, **kwargs): def ls(self, path=""): try: if path != "": + logger.debug("SFTP: Execute ls on path %s", path) self.sftp.chdir(path) + else: + logger.debug("SFTP: Execute ls on the current working directory") cwd = self.sftp.getcwd() attrs = self.sftp.listdir_attr(cwd) - logger.debug("SFTP: ls %s: %s", cwd, attrs) file_list = [] # TODO: should support uid and gid later @@ -77,6 +79,7 @@ def ls(self, path=""): "mtime": file_attr.st_mtime } file_list.append(file) + logger.debug("SFTP: ls completed successfully") except Exception as e: logger.exception("SFTP: ls failed") return False, repr(e), [] @@ -171,7 +174,7 @@ def rm(self, cwd, file_list): counter += 1 if counter == 50: - logger.debug("SFTP: Execute Command %s", ' '.join(cmd_list)) + logger.debug("SFTP: Execute Command %s with file counter of 50", ' '.join(cmd_list)) _, _, stderr = self.client.exec_command(" ".join(cmd_list)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: From 8c1a1d82d4a9d1452fea1e717d416f40c28f6c5b Mon Sep 17 00:00:00 2001 From: IreneLi Date: Tue, 7 Jan 2025 18:38:52 -0500 Subject: [PATCH 6/8] Remove potentially sensitive information --- application/features/SFTP.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/application/features/SFTP.py b/application/features/SFTP.py index 6b5cf591..0f2bf632 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -140,7 +140,7 @@ def rename(self, cwd, old, new): try: self.sftp.chdir(cwd) self.sftp.rename(old, new) - logger.debug("SFTP: Rename %s in directory %s to %s", old, cwd, new) + logger.debug("SFTP: File rename operation completed") except Exception as e: logger.exception("SFTP: Rename failed") return False, repr(e) @@ -150,10 +150,10 @@ 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}"') - logger.debug("SFTP: Change permission on %s to '%s'", path, "{0:0{1}o}".format(mode, 3)) + logger.debug("SFTP: Change permission to '%s'", "{0:0{1}o}".format(mode, 3)) stderr_lines = stderr.readlines() if len(stderr_lines) != 0: - logger.warning("SFTP: chmod failed due to %s", stderr_lines) + logger.warning(f"SFTP: chmod operation failed") return False, 'Some files were not applied with the request mode due to permission issues.' return True, '' @@ -197,7 +197,7 @@ def rm(self, cwd, file_list): return True, '' def mkdir(self, cwd, name): - logger.debug("SFTP: Make directory %s at %s", name, cwd) + logger.debug("SFTP: Creating new directory") _, _, _, stderr = self.exec_command_blocking(f'cd "{cwd}"&& mkdir "{name}"') stderr_lines = stderr.readlines() if len(stderr_lines) != 0: From 3d0469b44266a662b033e9d5c791e52722bf783c Mon Sep 17 00:00:00 2001 From: IreneLi Date: Wed, 8 Jan 2025 16:47:00 -0500 Subject: [PATCH 7/8] Update import libraries for consistency --- application/features/Audio.py | 2 +- application/features/Connection.py | 2 +- application/features/SFTP.py | 2 +- application/features/Term.py | 2 +- application/features/VNC.py | 1 - application/features/mywebsockify.py | 6 +++--- application/features/vncpasswd.py | 2 +- 7 files changed, 8 insertions(+), 9 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index 27d21d38..4cc3c8b5 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -31,7 +31,7 @@ from .Connection import Connection from .. import app from ..utils import find_free_port, get_headers_dict_from_str, local_auth -import logging.config +import logging logger = logging.getLogger(__name__) diff --git a/application/features/Connection.py b/application/features/Connection.py index 9f1f059c..2858e749 100644 --- a/application/features/Connection.py +++ b/application/features/Connection.py @@ -27,7 +27,7 @@ import paramiko import select -import logging.config +import logging logger = logging.getLogger(__name__) diff --git a/application/features/SFTP.py b/application/features/SFTP.py index 0f2bf632..5d9a421d 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 logging.config +import logging logger = logging.getLogger(__name__) diff --git a/application/features/Term.py b/application/features/Term.py index 7d9ca87c..400a79bf 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 logging.config +import logging logger = logging.getLogger(__name__) TERM_CONNECTIONS = {} diff --git a/application/features/VNC.py b/application/features/VNC.py index 43dc8144..71f30881 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -27,7 +27,6 @@ from .mywebsockify import MyProxyRequestHandler, MySSLProxyServer from .vncpasswd import decrypt_passwd from ..utils import find_free_port -import logging.config logger = logging.getLogger(__name__) diff --git a/application/features/mywebsockify.py b/application/features/mywebsockify.py index 7e86fd27..8255a352 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 logging.config +import logging logger = logging.getLogger(__name__) @@ -20,7 +20,7 @@ def __init__(self, RequestHandlerClass=websockify.ProxyRequestHandler, ssl_conte super(MySSLProxyServer, self).__init__(RequestHandlerClass=RequestHandlerClass, **kwargs) if ssl_context is None: - logger.debug("Generating self-signed SSL certificate") + logger.debug("No SSL context provided. 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) \ No newline at end of file + self.socket = ssl_context.wrap_socket(self.socket, server_side=True) diff --git a/application/features/vncpasswd.py b/application/features/vncpasswd.py index e538c919..05b177d1 100644 --- a/application/features/vncpasswd.py +++ b/application/features/vncpasswd.py @@ -19,7 +19,7 @@ # IN THE SOFTWARE. import pyDes -import logging.config +import logging logger = logging.getLogger(__name__) From 269fd83fe9c38d555db9fbc52e39a55668c1da44 Mon Sep 17 00:00:00 2001 From: IreneLi Date: Wed, 8 Jan 2025 17:02:04 -0500 Subject: [PATCH 8/8] Ensure consistency among format of logs --- application/features/Audio.py | 4 ++-- application/features/SFTP.py | 4 ++-- application/features/VNC.py | 2 +- 3 files changed, 5 insertions(+), 5 deletions(-) diff --git a/application/features/Audio.py b/application/features/Audio.py index 4cc3c8b5..32ed28d6 100644 --- a/application/features/Audio.py +++ b/application/features/Audio.py @@ -65,7 +65,7 @@ def connect(self, *args, **kwargs): def launch_audio(self): try: - logger.debug("Audio: Launching Audio connection. Forwarding request to 127.0.0.1, port 0.") + 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: @@ -94,7 +94,7 @@ def handleConnected(self): audio_id = self.request.path[1:] if audio_id not in AUDIO_CONNECTIONS: - logger.warning("AudioWebSocket: Requested audio_id=%s does not exist.", audio_id) + logger.warning("AudioWebSocket: Requested audio_id=%s does not exist", audio_id) self.close() return diff --git a/application/features/SFTP.py b/application/features/SFTP.py index 5d9a421d..95b18a99 100644 --- a/application/features/SFTP.py +++ b/application/features/SFTP.py @@ -109,10 +109,10 @@ def _zip_dir_recurse(self, z, parent, file): try: mode = self.sftp.stat(fullpath).st_mode if stat.S_ISREG(mode): - logger.debug("SFTP: %s is a file", fullpath) + logger.debug("SFTP: The given path is a file") z.write_iter(fullpath, self.dl_generator(fullpath)) elif stat.S_ISDIR(mode): - logger.debug("SFTP: %s is a directory", fullpath) + logger.debug("SFTP: The given path 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) diff --git a/application/features/VNC.py b/application/features/VNC.py index 71f30881..b5858f0c 100644 --- a/application/features/VNC.py +++ b/application/features/VNC.py @@ -53,7 +53,7 @@ def websocket_proxy_thread(local_websocket_port, local_vnc_port): logger.debug("VNC: SSL Certification Path exists") import subprocess - logger.debug("VNC: Run websockify on websocket port %d and vncport %d", local_websocket_port, local_vnc_port) + logger.debug("VNC: Run websockify on websocket port %s and vncport %s", local_websocket_port, 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',