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 3 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
9 changes: 7 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,22 +35,27 @@
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 != '':
logger.warning("Audio: Failed to create audio connection: %s", reason)
abort(403, description=reason)

status, reason = audio.launch_audio()
if status is False:
logger.error("Audio: Audio launch failed: %s", reason)
abort(403, description=reason)

result = {
'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)
34 changes: 29 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,11 +31,14 @@
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:
logger.warning("Common: Session not found: %s", session_id)
abort(403, f'Fail: session {session_id} does not exist')

if conn_type == ConnectionType.GENERAL:
Expand All @@ -49,11 +52,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 +69,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,18 +99,20 @@ 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)
if status is False:
logger.warning("Common: Failed to create session: %s", reason)
abort(403, reason)

# FIXME: password should be optional: only pass 'conn' if password is given
status, reason = profiles.add_session(host, username, conn)
if status is False:
logger.error("Common: Failed to save session info")
abort(500, reason)

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

elif request.method == 'PATCH':
Expand All @@ -112,10 +123,13 @@ 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:
logger.warning("Common: Failed to update nickname for session %s: %s", session_id, reason)
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 @@ -132,26 +146,32 @@ def handle_session():
# find the domain when the domain is not specified
full_host_name, _, _, _, _ = profiles.get_session_info(session_id)
if full_host_name is None:
logger.error("Common: Failed to resolve full host name for session_id=%s. Session does not exist.", session_id)
abort(400, f'failed: session {session_id} does not exist')
domain = full_host_name[full_host_name.find('.'):]

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:
logger.warning("Common: Failed to change host for session %s: %s", session_id, reason)
abort(403, reason)

return 'success'

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:
logger.warning("Common: Failed to delete session %s: %s", session_id, reason)
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,17 +180,21 @@ 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 != '':
logger.warning("Common: Failed to establish connection for blocking command: %s", 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:
logger.error("Common: Command execution failed")
abort(500, 'exec failed')
result = '\n'.join(stdout) + '\n' + '\n'.join(stderr)

Expand Down
41 changes: 30 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,42 +22,45 @@
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 != '':
logger.error("Sftp: SFTP connection failed: %s", reason)
abort(403, description=reason)

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

result = {
'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 != '':
logger.error("Sftp: SFTP connection failed: %s", reason)
abort(403, description=reason)

files = json.loads(args_files)
Expand All @@ -75,11 +78,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 +92,17 @@ 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 != '':
logger.error("Sftp: SFTP connection failed: %s", reason)
abort(403, description=reason)

status, reason = sftp.rename(cwd, old, new)
if not status:
logger.error("Sftp: Rename failed: %s", reason)
abort(400, reason)

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


Expand All @@ -105,31 +111,38 @@ 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 != '':
logger.error("Sftp: SFTP connection failed: %s", reason)
abort(403, description=reason)

status, reason = sftp.chmod(path, mode, recursive)
if not status:
logger.error("Sftp: CHMOD failed: %s", reason)
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 != '':
logger.error("Sftp: SFTP connection failed: %s", reason)
abort(403, description=reason)

status, reason = sftp.mkdir(cwd, name)
if status is False:
logger.error("Sftp: Directory creation failed: %s", reason)
abort(400, description=reason)

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


Expand All @@ -139,9 +152,11 @@ 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 != '':
logger.error("Sftp: SFTP connection failed: %s", reason)
abort(403, description=reason)

p = Path(relative_path)
Expand All @@ -151,6 +166,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,21 +178,24 @@ 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 != '':
logger.error("Sftp: SFTP connection failed: %s", reason)
abort(403, description=reason)

status, reason = sftp.rm(cwd, files)
if not status:
logger.error("Sftp: File removal failed: %s", reason)
abort(400, description=reason)

logger.info("Sftp: Files removed successfully from %s", cwd)
return 'success'
Loading
Loading