diff --git a/moonraker/app.py b/moonraker/app.py index eef77eac5..9a6862e8e 100644 --- a/moonraker/app.py +++ b/moonraker/app.py @@ -881,6 +881,7 @@ def initialize(self, def prepare(self) -> None: super(FileUploadHandler, self).prepare() + logging.info(f"Upload Request Received from {self.request.remote_ip}") fm: FileManager = self.server.lookup_component("file_manager") fm.check_write_enabled() if self.request.method == "POST": @@ -932,6 +933,7 @@ async def post(self) -> None: debug_msg += f"\n{name}: {value}" debug_msg += f"\nChecksum: {calc_chksum}" logging.debug(debug_msg) + logging.info(f"Processing Uploaded File: {self._file.multipart_filename}") try: result = await self.file_manager.finalize_upload(form_args) except ServerError as e: diff --git a/moonraker/common.py b/moonraker/common.py index b84ebc52b..c097cd6ca 100644 --- a/moonraker/common.py +++ b/moonraker/common.py @@ -581,8 +581,8 @@ def build_error( ) -> Dict[str, Any]: if method_name: method_name = f"Requested Method: {method_name}, " - log_msg = f"JSON-RPC Request Error - {method_name}Code: {code}\n{msg}" - if is_exc: + log_msg = f"JSON-RPC Request Error - {method_name}Code: {code}, Message: {msg}" + if is_exc and self.verbose: logging.exception(log_msg) else: logging.info(log_msg) diff --git a/moonraker/components/file_manager/file_manager.py b/moonraker/components/file_manager/file_manager.py index 77a0d6b72..edae73f26 100644 --- a/moonraker/components/file_manager/file_manager.py +++ b/moonraker/components/file_manager/file_manager.py @@ -2468,9 +2468,11 @@ async def _run_extract_metadata(self, if self.enable_object_proc: timeout = 300. cmd += " --check-objects" - shell_cmd: SCMDComp = self.server.lookup_component('shell_command') - scmd = shell_cmd.build_shell_command(cmd, log_stderr=True) - result = await scmd.run_with_response(timeout=timeout) + result = bytearray() + sc: SCMDComp = self.server.lookup_component('shell_command') + scmd = sc.build_shell_command(cmd, callback=result.extend, log_stderr=True) + if not await scmd.run(timeout=timeout): + raise self.server.error("Extract Metadata returned with error") try: decoded_resp: Dict[str, Any] = json.loads(result.strip()) except Exception: diff --git a/moonraker/components/file_manager/metadata.py b/moonraker/components/file_manager/metadata.py index 411ec8b80..587d6f1d6 100644 --- a/moonraker/components/file_manager/metadata.py +++ b/moonraker/components/file_manager/metadata.py @@ -17,6 +17,7 @@ import zipfile import shutil import uuid +import logging from PIL import Image # Annotation imports @@ -35,9 +36,8 @@ UFP_MODEL_PATH = "/3D/model.gcode" UFP_THUMB_PATH = "/Metadata/thumbnail.png" -def log_to_stderr(msg: str) -> None: - sys.stderr.write(f"{msg}\n") - sys.stderr.flush() +logging.basicConfig(stream=sys.stderr, level=logging.INFO) +logger = logging.getLogger("metadata") # regex helpers def _regex_find_floats(pattern: str, @@ -144,12 +144,12 @@ def _check_has_objects(self, if match is not None: # Objects already processed fname = os.path.basename(self.path) - log_to_stderr( + logger.info( f"File '{fname}' currently supports cancellation, " "processing aborted" ) if match.group(1).startswith("DEFINE_OBJECT"): - log_to_stderr( + logger.info( "Legacy object processing detected. This is not " "compatible with official versions of Klipper." ) @@ -229,7 +229,7 @@ def parse_thumbnails(self) -> Optional[List[Dict[str, Any]]]: try: os.mkdir(thumb_dir) except Exception: - log_to_stderr(f"Unable to create thumb dir: {thumb_dir}") + logger.info(f"Unable to create thumb dir: {thumb_dir}") return None thumb_base = os.path.splitext(os.path.basename(self.path))[0] parsed_matches: List[Dict[str, Any]] = [] @@ -239,12 +239,12 @@ def parse_thumbnails(self) -> Optional[List[Dict[str, Any]]]: info = _regex_find_ints(r".*", lines[0]) data = "".join(lines[1:-1]) if len(info) != 3: - log_to_stderr( + logger.info( f"MetadataError: Error parsing thumbnail" f" header: {lines[0]}") continue if len(data) != info[2]: - log_to_stderr( + logger.info( f"MetadataError: Thumbnail Size Mismatch: " f"detected {info[2]}, actual {len(data)}") continue @@ -283,7 +283,7 @@ def parse_thumbnails(self) -> Optional[List[Dict[str, Any]]]: 'relative_path': rel_path_small }) except Exception as e: - log_to_stderr(str(e)) + logger.info(str(e)) return parsed_matches def parse_layer_count(self) -> Optional[int]: @@ -564,7 +564,7 @@ def parse_thumbnails(self) -> Optional[List[Dict[str, Any]]]: 'relative_path': rel_path_small }) except Exception as e: - log_to_stderr(str(e)) + logger.info(str(e)) return None return thumbs @@ -978,10 +978,10 @@ def process_objects(file_path: str, slicer: BaseSlicer, name: str) -> bool: preprocess_m486 ) except ImportError: - log_to_stderr("Module 'preprocess-cancellation' failed to load") + logger.info("Module 'preprocess-cancellation' failed to load") return False fname = os.path.basename(file_path) - log_to_stderr( + logger.info( f"Performing Object Processing on file: {fname}, " f"sliced by {name}" ) @@ -999,7 +999,7 @@ def process_objects(file_path: str, slicer: BaseSlicer, name: str) -> bool: elif isinstance(slicer, IdeaMaker): processor = preprocess_ideamaker else: - log_to_stderr( + logger.info( f"Object Processing Failed, slicer {name}" "not supported" ) @@ -1007,7 +1007,7 @@ def process_objects(file_path: str, slicer: BaseSlicer, name: str) -> bool: for line in processor(in_file): out_file.write(line) except Exception as e: - log_to_stderr(f"Object processing failed: {e}") + logger.info(f"Object processing failed: {e}") return False if os.path.islink(file_path): file_path = os.path.realpath(file_path) @@ -1065,7 +1065,7 @@ def extract_metadata( def extract_ufp(ufp_path: str, dest_path: str) -> None: if not os.path.isfile(ufp_path): - log_to_stderr(f"UFP file Not Found: {ufp_path}") + logger.info(f"UFP file Not Found: {ufp_path}") sys.exit(-1) thumb_name = os.path.splitext( os.path.basename(dest_path))[0] + ".png" @@ -1088,12 +1088,12 @@ def extract_ufp(ufp_path: str, dest_path: str) -> None: os.mkdir(dest_thumb_dir) shutil.move(tmp_thumb_path, dest_thumb_path) except Exception: - log_to_stderr(traceback.format_exc()) + logger.info(traceback.format_exc()) sys.exit(-1) try: os.remove(ufp_path) except Exception: - log_to_stderr(f"Error removing ufp file: {ufp_path}") + logger.info(f"Error removing ufp file: {ufp_path}") def main(path: str, filename: str, @@ -1105,12 +1105,12 @@ def main(path: str, extract_ufp(ufp, file_path) metadata: Dict[str, Any] = {} if not os.path.isfile(file_path): - log_to_stderr(f"File Not Found: {file_path}") + logger.info(f"File Not Found: {file_path}") sys.exit(-1) try: metadata = extract_metadata(file_path, check_objects) except Exception: - log_to_stderr(traceback.format_exc()) + logger.info(traceback.format_exc()) sys.exit(-1) fd = sys.stdout.fileno() data = json.dumps( @@ -1145,5 +1145,5 @@ def main(path: str, args = parser.parse_args() check_objects = args.check_objects enabled_msg = "enabled" if check_objects else "disabled" - log_to_stderr(f"Object Processing is {enabled_msg}") + logger.info(f"Object Processing is {enabled_msg}") main(args.path, args.filename, args.ufp, check_objects) diff --git a/moonraker/components/shell_command.py b/moonraker/components/shell_command.py index 26b9315e4..abeaf6a68 100644 --- a/moonraker/components/shell_command.py +++ b/moonraker/components/shell_command.py @@ -46,7 +46,6 @@ def __init__( self, limit: int, loop: asyncio.events.AbstractEventLoop, - program_name: str = "", std_out_cb: OutputCallback = None, std_err_cb: OutputCallback = None, log_stderr: bool = False @@ -54,7 +53,6 @@ def __init__( self._loop = loop self._pipe_fds: List[int] = [] super().__init__(limit, loop) - self.program_name = program_name self.std_out_cb = std_out_cb self.std_err_cb = std_err_cb self.log_stderr = log_stderr @@ -94,7 +92,7 @@ def pipe_data_received(self, fd: int, data: bytes | str) -> None: msg = data.decode(errors='ignore') else: msg = data - logging.info(f"{self.program_name}: {msg}") + logging.info(msg) if cb is not None: if isinstance(data, str): data = data.encode() @@ -288,9 +286,9 @@ async def _create_subprocess( def protocol_factory(): return ShellCommandProtocol( - limit=2**20, loop=loop, program_name=self.command[0], - std_out_cb=self.std_out_cb, std_err_cb=self.std_err_cb, - log_stderr=self.log_stderr) + limit=2**20, loop=loop, std_out_cb=self.std_out_cb, + std_err_cb=self.std_err_cb, log_stderr=self.log_stderr + ) try: stdpipe: Optional[int] = None if has_input: