Skip to content

add routes logging message #37

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 4 commits into
base: main
Choose a base branch
from
Open

add routes logging message #37

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
2dd13d6
add routes logging message
Nuovaxu Aug 10, 2024
7a5bda9
remove unncessary log messages from exception
Nuovaxu Sep 22, 2024
4e527fe
chore: switch to % formatting in logs for deferred computation
Jan 5, 2025
fab002c
Removed logs preceding abort() calls as they are now handled by the g…
Jan 5, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 5 additions & 2 deletions application/routes/audio.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,10 +35,13 @@
from .. import api
from ..codes import ConnectionType
from ..features.Audio import AUDIO_PORT

import logging
logger = logging.getLogger(__name__)

@api.route('/audio', methods=['POST'])
def start_audio():
#TODO: Request recieved with body
logger.debug("Audio: Received request to start audio with data: %s", request.json)
Comment on lines +43 to +44
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick (assertive)

Remove TODO comment and fix typo.

The TODO comment contains a typo ("recieved" should be "received") and appears to be a placeholder that can be removed since the logging has been implemented.

Apply this diff:

-    #TODO: Request recieved with body
📝 Committable suggestion

‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.

Suggested change
#TODO: Request recieved with body
logger.debug("Audio: Received request to start audio with data: %s", request.json)
logger.debug("Audio: Received request to start audio with data: %s", request.json)

session_id = request.json.get('session_id')
audio, reason = create_connection(session_id, ConnectionType.AUDIO)
if reason != '':
Expand All @@ -52,5 +55,5 @@ def start_audio():
'port': AUDIO_PORT,
'audio_id': audio.id
}

logger.info("Audio: Audio launched successfully with ID %s on port %s", audio.id, AUDIO_PORT)
return json.dumps(result)
25 changes: 20 additions & 5 deletions application/routes/common.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -31,9 +31,11 @@
from ..features.Term import Term
from ..features.VNC import VNC
from ..utils import int_to_bytes

import logging
logger = logging.getLogger(__name__)

def create_connection(session_id, conn_type):
logger.debug("Common: Attempting to create connection: session_id=%s, conn_type=%s", session_id, conn_type)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick (assertive)

Consider enhancing error handling with specific error codes.

While the logging is comprehensive, consider mapping specific error codes to more descriptive log messages.

         if reason.startswith('[Errno 60]') \
                 or reason.startswith('[Errno 64]') \
                 or reason.startswith('[Errno 51]') \
                 or reason == 'timed out':
+            logger.error("Common: Host unreachable error encountered")
             reason = int_to_bytes(ICtrlError.SSH.HOST_UNREACHABLE)
         elif "encountered RSA key, expected OPENSSH key" in reason:
+            logger.error("Common: Authentication error - incorrect key format")
             reason = int_to_bytes(ICtrlError.SSH.AUTH_WRONG)

Also applies to: 54-54, 60-60, 71-71

host, username, this_private_key_path, this_private_key_str, _ = profiles.get_session_info(session_id)
if host is None:
abort(403, f'Fail: session {session_id} does not exist')
Expand All @@ -49,11 +51,13 @@ def create_connection(session_id, conn_type):
elif conn_type == ConnectionType.AUDIO:
conn = Audio()
else:
logger.error("Common: Invalid connection type requested: %s", conn_type)
raise TypeError(f'Invalid type: {conn_type}')

status, reason = conn.connect(host, username,
key_filename=this_private_key_path, private_key_str=this_private_key_str)
if status is False:
logger.error("Common: Connection failed: %s", reason)
if reason.startswith('[Errno 60]') \
or reason.startswith('[Errno 64]') \
or reason.startswith('[Errno 51]') \
Expand All @@ -64,20 +68,24 @@ def create_connection(session_id, conn_type):
else:
print(reason)
# TODO: return the other specific codes
logger.error("Common: Unhandled connection failure reason: %s", reason)
reason = int_to_bytes(ICtrlError.SSH.GENERAL)

return conn, reason


@api.route('/profiles')
def get_profiles():
logger.info("Common: Fetching all profiles")
return profiles.query()


@api.route('/session', methods=['GET', 'POST', 'PATCH', 'DELETE'])
def handle_session():
logger.debug("Common: Session operation: %s", request.method)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🛠️ Refactor suggestion

Consider breaking down the complex handle_session function.

While the logging implementation is good, the function's complexity (14 > 10) suggests it should be broken down into smaller, more focused functions.

Consider extracting each HTTP method handler into its own function:

def _handle_get_session(session_id: str) -> dict:
    logger.debug("Common: Retrieving session with ID: %s", session_id)
    # ... GET logic ...

def _handle_post_session(host: str, username: str, password: str) -> str:
    logger.debug("Common: Creating new session with host=%s, username=%s", host, username)
    # ... POST logic ...

Also applies to: 88-88, 101-101, 112-112

if request.method == 'GET':
session_id = request.args.get('id')
logger.debug("Common: Retrieving session with ID: %s", session_id)
host, username, _, _, nickname = profiles.get_session_info(session_id)

return json.dumps({
Expand All @@ -90,7 +98,7 @@ def handle_session():
username = request.json.get('username')
# FIXME: password should be optional
password = request.json.get("password")

logger.debug("Common: Creating new session with host=%s, username=%s", host, username)
conn = Connection()

status, reason = conn.connect(host, username, password=password)
Expand All @@ -101,7 +109,7 @@ def handle_session():
status, reason = profiles.add_session(host, username, conn)
if status is False:
abort(500, reason)

logger.info("Common: Session created successfully for host=%s", host)
return 'success'

elif request.method == 'PATCH':
Expand All @@ -112,10 +120,12 @@ def handle_session():

if nickname is not None:
# only update nickname
logger.info("Common: Updating nickname for session %s", session_id)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick (assertive)

Consider adding error logging for PATCH operations.

While the success path logging is good, consider adding error logging for failed operations.

     if not status:
+        logger.error("Common: Failed to update nickname for session %s: %s", session_id, reason)
         abort(400, reason)

Also applies to: 128-128, 150-150

status, reason = profiles.set_session_nickname(session_id, nickname)
if not status:
abort(400, reason)
else:
logger.info("Common: Terminating old session with ID %s", session_id)
# terminate old sessions with best efforts
# noinspection PyBroadException
try:
Expand All @@ -137,6 +147,7 @@ def handle_session():

host += domain

logger.info("Common: Changing host for session %s to %s", session_id, host)
status, reason = profiles.change_host(session_id, host)
if not status:
abort(403, reason)
Expand All @@ -145,13 +156,15 @@ def handle_session():

elif request.method == 'DELETE':
session_id = request.args.get('session_id')

logger.info("Common: Deleting session with ID: %s", session_id)
status, reason = profiles.delete_session(session_id)
if not status:
abort(403, reason)

logger.info("Common: Session %s deleted successfully", session_id)
return 'success'
else:
logger.error("Common: Unsupported HTTP method %s for session endpoint", request.method)
abort(405)


Expand All @@ -160,15 +173,17 @@ def exec_blocking():
session_id = request.json.get('session_id')
cmd = request.json.get('cmd')
large = request.json.get('large', False)

logger.debug("Common: Executing blocking command for session_id=%s", session_id)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick (assertive)

Add error logging for failed command execution.

Consider adding error logging when command execution fails.

         status, _, stdout, stderr = conn.exec_command_blocking(cmd)
         if status is False:
+            logger.error("Common: Command execution failed: %s", stderr)
             abort(500, 'exec failed')

Also applies to: 183-183, 186-186

conn, reason = create_connection(session_id, ConnectionType.GENERAL)
if reason != '':
abort(403, reason)

result: str
if large:
logger.debug("Common: Executing large blocking command")
result = conn.exec_command_blocking_large(cmd)
else:
logger.debug("Common: Executing standard blocking command")
status, _, stdout, stderr = conn.exec_command_blocking(cmd)
if status is False:
abort(500, 'exec failed')
Expand Down
29 changes: 18 additions & 11 deletions application/routes/sftp.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,20 +22,19 @@
import posixpath
from datetime import datetime
from pathlib import Path

from flask import request, abort, stream_with_context

from .common import create_connection
from .. import api, app
from ..codes import ConnectionType

import logging
logger = logging.getLogger(__name__)
UPLOAD_CHUNK_SIZE = 1024 * 1024


@api.route('/sftp_ls/<session_id>')
def sftp_ls(session_id):
path = request.args.get('path')

logger.debug("Sftp: Listing SFTP directory: %s for session %s", path, session_id)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick (assertive)

LGTM: Logging added to sftp_ls function.

The logging statements provide good coverage of the function's execution flow. Consider using logger.exception() when logging errors in the error path.

     status, cwd, file_list = sftp.ls(path)
     if status is False:
+        logger.exception("Sftp: Failed to list directory: %s", path)
         abort(400, description=cwd)

Also applies to: 50-50

sftp, reason = create_connection(session_id, ConnectionType.SFTP)
if reason != '':
abort(403, description=reason)
Expand All @@ -48,14 +47,15 @@ def sftp_ls(session_id):
'cwd': cwd,
'files': file_list
}
logger.info("Sftp: Directory listed successfully: %s", cwd)
return json.dumps(result)


@api.route('/sftp_dl/<session_id>')
def sftp_dl(session_id):
cwd = request.args.get('cwd')
args_files = request.args.get('files')

logger.debug("Sftp: Downloading files: %s from %s for session %s", args_files, cwd, session_id)
sftp, reason = create_connection(session_id, ConnectionType.SFTP)
if reason != '':
abort(403, description=reason)
Expand All @@ -75,11 +75,12 @@ def sftp_dl(session_id):
dt_str = datetime.now().strftime('_%Y%m%d_%H%M%S')
zip_name = posixpath.basename(cwd) + dt_str + '.zip'
r.headers.set('Content-Disposition', 'attachment', filename=zip_name)
logger.info("Sftp: Sending zip file: %s", zip_name)
else:
r = app.response_class(stream_with_context(sftp.dl_generator(files[0])), mimetype='application/octet-stream')
r.headers.set('Content-Disposition', 'attachment', filename=files[0])
r.headers.set('Content-Length', size)

logger.info("Sftp: Sending file: %s", files[0])
return r


Expand All @@ -88,15 +89,15 @@ def sftp_rename(session_id):
cwd = request.json.get('cwd')
old = request.json.get('old')
new = request.json.get('new')

logger.debug("Sftp: Renaming file from %s to %s in %s for session %s", old, new, cwd, session_id)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick (assertive)

Consider enhancing error logging in sftp_rename.

While the logging is good, consider adding exception logging in the error path.

     status, reason = sftp.rename(cwd, old, new)
     if not status:
+        logger.exception("Sftp: Failed to rename file from %s to %s: %s", old, new, reason)
         abort(400, reason)

Also applies to: 100-100

sftp, reason = create_connection(session_id, ConnectionType.SFTP)
if reason != '':
abort(403, description=reason)

status, reason = sftp.rename(cwd, old, new)
if not status:
abort(400, reason)

logger.info("Sftp: Rename successful from %s to %s", old, new)
return 'success'


Expand All @@ -105,6 +106,7 @@ def sftp_chmod(session_id):
path = request.json.get('path')
mode = request.json.get('mode')
recursive = request.json.get('recursive')
logger.debug("Sftp: Changing file mode for %s to %s, recursive: %s in session %s", path, mode, recursive, session_id)

sftp, reason = create_connection(session_id, ConnectionType.SFTP)
if reason != '':
Expand All @@ -114,14 +116,15 @@ def sftp_chmod(session_id):
if not status:
abort(400, reason)

logger.info("Sftp: CHMOD successful for %s", path)
return 'success'


@api.route('/sftp_mkdir/<session_id>', methods=['PUT'])
def sftp_mkdir(session_id):
cwd = request.json.get('cwd')
name = request.json.get('name')

logger.debug("Sftp: Creating directory %s in %s for session %s", name, cwd, session_id)
sftp, reason = create_connection(session_id, ConnectionType.SFTP)
if reason != '':
abort(403, description=reason)
Expand All @@ -130,6 +133,7 @@ def sftp_mkdir(session_id):
if status is False:
abort(400, description=reason)

logger.info("Sftp: Directory created successfully: %s", name)
return 'success'


Expand All @@ -139,6 +143,7 @@ def sftp_ul(session_id):
# no need to use secure_filename because the user should be responsible for her/his input
# when not using the client
relative_path = request.headers.get('Path')
logger.debug("Sftp: Uploading file %s to %s for session %s", relative_path, cwd, session_id)

sftp, reason = create_connection(session_id, ConnectionType.SFTP)
if reason != '':
Expand All @@ -151,6 +156,7 @@ def sftp_ul(session_id):
if str(relative_dir_path) != '.':
cwd = posixpath.join(cwd, relative_dir_path)
# TODO: check: will this ever fail?
logger.debug("Sftp: Creating directories recursively for %s", cwd)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codebase verification

The TODO comment should be replaced with proper error handling

The verification reveals that exec_command_blocking returns an exit status that's not being checked in the SFTP upload route, unlike other places in the codebase where directory operations are properly validated (e.g., the sftp_mkdir endpoint). The recursive directory creation through mkdir -p could fail due to:

  • Permission issues
  • Disk space constraints
  • Invalid path characters
  • Network issues during SFTP command execution

Specific locations needing attention:

  • application/routes/sftp.py: Add error handling for the mkdir -p command by checking the exit status returned by exec_command_blocking
  • Consider using the same error handling pattern as seen in the sftp_mkdir endpoint where errors are properly logged and propagated to the client
🔗 Analysis chain

Consider removing TODO comment.

The TODO comment questions whether directory creation could fail. Since this is a critical operation, we should either:

  1. Handle the potential failure case, or
  2. Document why it's safe to assume it won't fail

Let me gather more context about the error handling in this SFTP implementation.

Let me check how the SFTP connection and command execution is implemented.

🏁 Scripts executed

The following scripts were executed for the analysis:

Script:

#!/bin/bash
# Search for similar mkdir -p usage and error handling patterns
rg -A 5 'mkdir -p'

Length of output: 894

Script:

#!/bin/bash
# Look for the surrounding context of the directory creation
rg -B 10 -A 10 'mkdir.*cwd' application/routes/sftp.py

# Search for error handling patterns in the SFTP implementation
ast-grep --pattern 'try {
  $$$
  sftp.$$$
  $$$
} catch ($$$) {
  $$$
}'

Length of output: 1590

Script:

#!/bin/bash
# Check the SFTP connection implementation and exec_command_blocking
rg -B 5 -A 10 'class.*SFTP' 

# Look for exec_command_blocking implementation
rg -B 5 -A 10 'def exec_command_blocking'

Length of output: 3032

sftp.exec_command_blocking(f'mkdir -p "{cwd}"')

sftp.sftp.chdir(path=cwd)
Expand All @@ -162,15 +168,15 @@ def sftp_ul(session_id):
chunk = request.stream.read(UPLOAD_CHUNK_SIZE)

sftp_file.close()

logger.info("Sftp: File uploaded successfully: %s", request_filename)
return 'success'


@api.route('/sftp_rm/<session_id>', methods=['POST'])
def sftp_rm(session_id):
cwd = request.json.get('cwd')
files = request.json.get('files')

logger.debug("Sftp: Removing files %s from %s for session %s", files, cwd, session_id)
sftp, reason = create_connection(session_id, ConnectionType.SFTP)
if reason != '':
abort(403, description=reason)
Expand All @@ -179,4 +185,5 @@ def sftp_rm(session_id):
if not status:
abort(400, description=reason)

logger.info("Sftp: Files removed successfully from %s", cwd)
return 'success'
10 changes: 8 additions & 2 deletions application/routes/term.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,8 @@
from ..codes import ICtrlStep, ConnectionType, ICtrlError
from ..features.Term import TERM_CONNECTIONS, TERMINAL_PORT
from ..utils import int_to_bytes
import logging
logger = logging.getLogger(__name__)


# FIXME: store term_id is cookie-based Flask 'session'
Expand All @@ -35,17 +37,19 @@
def start_terminal():
session_id = request.json.get('sessionID')
load_check = request.json.get('loadCheck', True)

logger.debug("Term: Starting terminal session: %s", session_id)
def generate():
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick (assertive)

Consider adding a return type annotation to generate().
Since this function yields data to the client, specifying a -> Generator[bytes, None, None] or similar can improve readability and tooling support.

 def generate():
+    # type: (...) -> Generator[bytes, None, None]
     ...

Committable suggestion skipped: line range outside the PR's diff.

🧰 Tools
🪛 Ruff (0.8.2)

41-41: Missing return type annotation for private function generate

(ANN202)

yield int_to_bytes(ICtrlStep.Term.SSH_AUTH)

term, reason = create_connection(session_id, ConnectionType.TERM)
if reason != '':
logger.error("Term: Terminal connection failed: %s", reason)
yield reason
return

yield int_to_bytes(ICtrlStep.Term.CHECK_LOAD)
if term.is_uoft() and load_check and term.is_load_high():
logger.warning("Term: Load too high to start terminal session: %s", session_id)
yield int_to_bytes(ICtrlError.SSH.OVER_LOADED)
return

Expand All @@ -59,6 +63,7 @@ def generate():
'port': TERMINAL_PORT,
'term_id': term.id
}
logger.info("Term: Terminal session started successfully: %s on port %s", term.id, TERMINAL_PORT)
yield json.dumps(result)

return app.response_class(stream_with_context(generate()), mimetype='application/octet-stream')
Expand All @@ -72,10 +77,11 @@ def resize_terminal():

width = request.json.get('w')
height = request.json.get('h')

logger.debug("Term: Resizing terminal %s: width %s, height %s", term_id, width, height)
term = TERM_CONNECTIONS[term_id]
status, reason = term.resize(width, height)
if status is False:
abort(403, description=reason)

logger.info("Term: Terminal %s resized successfully", term_id)
return 'success'
Loading