Implements #11 - JSONL logging instead of printing to stdout

pyproject.toml

@@ -29,7 +29,8 @@ dependencies = [
     "pandas==2.2.2",
     "numpy==2.0.0",
     "nska-deserialize==1.5.1",
-    "yara-python==4.5.1"
+    "yara-python==4.5.1",
+    "python-json-logger==2.0.7"
 ]
 
 [project.scripts]

requirements.txt

@@ -7,4 +7,5 @@ pandas==2.2.2
 numpy==2.0.0
 nska-deserialize==1.5.1
 yara-python==4.5.1
-# pycrashreport==1.2.4
+# pycrashreport==1.2.4
+python-json-logger==2.0.7

src/sysdiagnose/analysers/apps.py

@@ -4,12 +4,15 @@
 # Author: Emiliern Le Jamtel
 
 import re
+import logging
 from sysdiagnose.utils.base import BaseAnalyserInterface
 from sysdiagnose.parsers.accessibility_tcc import AccessibilityTccParser
 from sysdiagnose.parsers.brctl import BrctlParser
 from sysdiagnose.parsers.itunesstore import iTunesStoreParser
 from sysdiagnose.parsers.logarchive import LogarchiveParser
 
+logger = logging.getLogger('sysdiagnose')
+
 
 class AppsAnalyser(BaseAnalyserInterface):
     description = 'Get list of Apps installed on the device'
@@ -88,9 +91,9 @@ def execute(self):
                         if matches:
                             new_term = matches[0]
                         else:
-                            # print(f"Skipping entry: {entry['subsystem']}")
+                            logger.debug(f"Skipping entry: {entry['subsystem']}")
                             continue
-                # print(f"New entry: {new_term} - was: {entry['subsystem']}")
+                logger.debug(f"New entry: {new_term} - was: {entry['subsystem']}")
                 entry['subsystem'] = new_term
             # add it to the list
             try:

src/sysdiagnose/analysers/demo_analyser.py

@@ -3,7 +3,7 @@
 # For Python3
 # DEMO - Skeleton
 
-from sysdiagnose.utils.base import BaseAnalyserInterface
+from sysdiagnose.utils.base import BaseAnalyserInterface, logger
 
 
 class DemoAnalyser(BaseAnalyserInterface):
@@ -21,6 +21,7 @@ def execute(self):
         By doing so you will get the parser output even if it never ran before.
         """
         print("DO SOMETHING HERE")
+        logger.info("log something here", extra={'analyser': __name__})
 
         # json_data = p_fooparser.get_result()
 

src/sysdiagnose/analysers/timesketch.py

@@ -17,6 +17,9 @@
 from sysdiagnose.parsers.crashlogs import CrashLogsParser
 from collections.abc import Generator
 from sysdiagnose.utils.base import BaseAnalyserInterface
+import logging
+
+logger = logging.getLogger('sysdiagnose')
 
 
 class TimesketchAnalyser(BaseAnalyserInterface):
@@ -50,7 +53,7 @@ def __extract_ts_mobileactivation(self) -> Generator[dict, None, None]:
                     pass
                 yield ts_event
         except Exception as e:
-            print(f"ERROR while extracting timestamp from mobileactivation file. Reason: {str(e)}")
+            logger.exception("ERROR while extracting timestamp from mobileactivation file.")
 
     def __extract_ts_powerlogs(self) -> Generator[dict, None, None]:
         try:
@@ -91,7 +94,7 @@ def __extract_ts_powerlogs(self) -> Generator[dict, None, None]:
                     pass
 
         except Exception as e:
-            print(f"ERROR while extracting timestamp from powerlogs. Reason: {str(e)}")
+            logger.exception("ERROR while extracting timestamp from powerlogs.")
 
     def __extract_ts_swcutil(self) -> Generator[dict, None, None]:
         try:
@@ -111,10 +114,10 @@ def __extract_ts_swcutil(self) -> Generator[dict, None, None]:
                         yield ts_event
                     except KeyError:
                         # some entries do not have a Last Checked or timestamp field
-                        # print(f"WARNING {filename} while extracting timestamp from {(service['Service'])} - {(service['App ID'])}. Record not inserted.")
+                        logger.warning(f"Error while extracting timestamp from {(service['Service'])} - {(service['App ID'])}. Record not inserted.")
                         pass
         except Exception as e:
-            print(f"ERROR while extracting timestamp from swcutil. Reason {str(e)}")
+            logger.exception("ERROR while extracting timestamp from swcutil.")
 
     def __extract_ts_accessibility_tcc(self) -> Generator[dict, None, None]:
         try:
@@ -135,7 +138,7 @@ def __extract_ts_accessibility_tcc(self) -> Generator[dict, None, None]:
                 }
                 yield ts_event
         except Exception as e:
-            print(f"ERROR while extracting timestamp from accessibility_tcc. Reason {str(e)}")
+            logger.exception("ERROR while extracting timestamp from accessibility_tcc.")
 
     def __extract_ts_shutdownlogs(self) -> Generator[dict, None, None]:
         try:
@@ -153,9 +156,9 @@ def __extract_ts_shutdownlogs(self) -> Generator[dict, None, None]:
                     }
                     yield ts_event
                 except Exception as e:
-                    print(f"WARNING: shutdownlog entry not parsed: {event}. Reason: {str(e)}")
+                    logger.warning(f"WARNING: shutdownlog entry not parsed: {event}", exc_info=True)
         except Exception as e:
-            print(f"ERROR while extracting timestamp from shutdownlog. Reason: {str(e)}")
+            logger.exception("ERROR while extracting timestamp from shutdownlog.")
 
     def __extract_ts_logarchive(self) -> Generator[dict, None, None]:
         try:
@@ -173,9 +176,9 @@ def __extract_ts_logarchive(self) -> Generator[dict, None, None]:
                     }
                     yield ts_event
                 except KeyError as e:
-                    print(f"WARNING: trace not parsed: {event}. Error {e}")
+                    logger.warning(f"WARNING: trace not parsed: {event}.", exc_info=True)
         except Exception as e:
-            print(f"ERROR while extracting timestamp from logarchive. Reason: {str(e)}")
+            logger.exception(f"ERROR while extracting timestamp from logarchive.")
 
     def __extract_ts_wifisecurity(self) -> Generator[dict, None, None]:
         try:
@@ -206,7 +209,7 @@ def __extract_ts_wifisecurity(self) -> Generator[dict, None, None]:
                 }
                 yield ts_event
         except Exception as e:
-            print(f"ERROR while extracting timestamp from wifisecurity. Reason {str(e)}")
+            logger.exception("ERROR while extracting timestamp from wifisecurity.")
 
     def __extract_ts_wifi_known_networks(self) -> Generator[dict, None, None]:
         try:
@@ -228,7 +231,7 @@ def __extract_ts_wifi_known_networks(self) -> Generator[dict, None, None]:
                     yield ts_event
                 except KeyError:
                     # some wifi networks do not have an AddedAt field
-                    # print(f"ERROR {filename} while extracting timestamp from {ssid}. Reason: {str(e)}. Record not inserted.")
+                    logger.warning(f"Error while extracting timestamp from {ssid}. Record not inserted.", exc_info=True)
                     pass
 
                 # WIFI modified
@@ -245,7 +248,7 @@ def __extract_ts_wifi_known_networks(self) -> Generator[dict, None, None]:
                     yield ts_event
                 except KeyError:
                     # some wifi networks do not have an UpdatedAt field
-                    # print(f"ERROR {filename} while extracting timestamp from {ssid}. Reason: {str(e)}. Record not inserted.")
+                    logger.warning(f"Error while extracting timestamp from {ssid}.Record not inserted.", exc_info=True)
                     pass
 
                 # Password for wifi modified
@@ -262,10 +265,10 @@ def __extract_ts_wifi_known_networks(self) -> Generator[dict, None, None]:
                     yield ts_event
                 except KeyError:
                     # some wifi networks do not have a password modification date
-                    # print(f"ERROR {filename} while extracting timestamp from {ssid}. Reason: {str(e)}. Record not inserted.")
+                    logger.warning(f"Error while extracting timestamp from {ssid}. Record not inserted.", exc_info=True)
                     pass
         except Exception as e:
-            print(f"ERROR while extracting timestamp from wifi_known_networks. Reason {str(e)}")
+            logger.exception("ERROR while extracting timestamp from wifi_known_networks.")
 
     def __extract_ts_crashlogs(self) -> Generator[dict, None, None]:
         try:
@@ -288,7 +291,7 @@ def __extract_ts_crashlogs(self) -> Generator[dict, None, None]:
                     # skip bug_type fields
                     pass
         except Exception as e:
-            print(f"ERROR while extracting timestamp from crashlog. Reason {str(e)}")
+            logger.exception("ERROR while extracting timestamp from crashlog.")
 
     def execute(self):
         # Get all the functions that start with '__extract_ts_'

src/sysdiagnose/analysers/yarascan.py

@@ -3,8 +3,11 @@
 import glob
 import threading
 import queue
+import logging
 from sysdiagnose.utils.base import BaseAnalyserInterface
 
+logger = logging.getLogger('sysdiagnose')
+
 
 # These are the commonly used external variables that can be used in the YARA rules
 externals = {
@@ -69,7 +72,7 @@ def execute(self):
             results['matches'] = matches
 
         if len(results['errors']) > 0:
-            print("Scan finished with errors. Review the results")
+            logger.error("Scan finished with errors. Review the results")
 
         return results
 
@@ -80,17 +83,17 @@ def get_valid_yara_rule_files(self) -> tuple[list, list]:
         for rule_file in rule_files_to_test:
             if not os.path.isfile(rule_file):
                 continue
-            print(f"Loading YARA rule: {rule_file}")
+            logger.info(f"Loading YARA rule: {rule_file}")
             try:
                 yara.compile(filepath=rule_file, externals=externals)
                 # if we reach this point, the rule is valid
                 rule_files_validated.append(rule_file)
             except yara.SyntaxError as e:
-                print(f"Error compiling rule {rule_file}: {str(e)}")
+                logger.exception(f"Error compiling rule {rule_file}")
                 errors.append(f"Error compiling rule {rule_file}: {str(e)}")
                 continue
             except yara.Error as e:
-                print(f"Error compiling rule {rule_file}: {str(e)}")
+                logger.exception(f"Error compiling rule {rule_file}")
                 errors.append(f"Error loading rule {rule_file}: {str(e)}")
                 continue
 
@@ -111,7 +114,7 @@ def scan_directory(directories: list, rule_filepaths: dict, ignore_files: list,
                 for ignore_folder in ignore_folders:
                     if root.startswith(ignore_folder):
                         stop = True
-                        print(f"Skipping folder: {root}")
+                        logger.info(f"Skipping folder: {root}")
                         continue
                 if stop:
                     continue
@@ -121,7 +124,7 @@ def scan_directory(directories: list, rule_filepaths: dict, ignore_files: list,
                     for ignore_file in ignore_files:
                         if file_full_path.startswith(ignore_file):
                             stop = True
-                            print(f"Skipping file: {file_full_path}")
+                            logger.info(f"Skipping file: {file_full_path}")
                             continue
                     if stop:
                         continue
@@ -133,13 +136,13 @@ def consumer():
             rules = yara.compile(filepaths=rule_filepaths, externals=externals)
 
             while True:
-                print(f"Consumer thread seeing {file_queue.qsize()} files in queue, and taking one")
+                logger.info(f"Consumer thread seeing {file_queue.qsize()} files in queue, and taking one")
                 file_path = file_queue.get()
                 if file_path is None:
-                    print("Consumer thread exiting")
+                    logger.info("Consumer thread exiting")
                     break
 
-                print(f"Scanning file: {file_path}")
+                logger.info(f"Scanning file: {file_path}")
                 # set the externals for this file - massive slowdown
                 # externals_local = externals.copy()
                 # externals_local['filename'] = file

src/sysdiagnose/main.py

@@ -3,6 +3,8 @@
 import sys
 from sysdiagnose import Sysdiagnose
 import os
+import time
+from sysdiagnose.utils.logger import logger, get_console_handler, get_json_handler
 
 
 def parse_parser_error(message):
@@ -41,11 +43,13 @@ def main():
     # parse mode
     parse_parser = subparsers.add_parser('parse', help='Parse a case')
     parse_parser.add_argument('parser', help='Name of the parser, "all" for running all parsers, or "list" for a listing of all parsers')
+    parse_parser.add_argument('--log', default='WARNING', choices=['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'], help='Enables logging level (DEBUG, INFO, WARNING, ERROR, CRITICAL)')
     parse_parser.error = parse_parser_error
 
     # analyse mode
     analyse_parser = subparsers.add_parser('analyse', help='Analyse a case')
     analyse_parser.add_argument('analyser', help='Name of the analyser, "all" for running all analysers, or "list" for a listing of all analysers')
+    analyse_parser.add_argument('--log', default='WARNING', choices=['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'], help='Enables logging level (DEBUG, INFO, WARNING, ERROR, CRITICAL)')
     analyse_parser.error = analyse_parser_error
 
     # list mode
@@ -123,14 +127,37 @@ def main():
         else:
             case_ids = [args.case_id]
 
+        # Handle console logging
+        log_level = args.log.upper()
+        logger.addHandler(get_console_handler(log_level))
+
+        logger2file = None
         for case_id in case_ids:
+            # Handle file logging
+            time_str = time.strftime("%Y%m%dT%H%M%S")
+            filename = f"{time_str}-parse-{case_id}.jsonl"
+            folder = sd.config.get_case_parsed_data_folder(case_id)
+            # https://stackoverflow.com/questions/13839554/how-to-change-filehandle-with-python-logging-on-the-fly-with-different-classes-a
+            if logger2file is None:
+                logger2file = get_json_handler(os.path.join(folder, filename))
+                logger.addHandler(logger2file)
+            else:
+                logger2file.close()
+                logger2file.setStream(open(os.path.join(folder, filename), 'a'))
+
             print(f"Case ID: {case_id}")
             for parser in parsers_list:
                 print(f"Parser '{parser}' for case ID '{case_id}'")
+                logger.info(f"Parser '{parser}' started", extra={'parser': parser})
                 try:
-                    sd.parse(parser, case_id)
+                    result = sd.parse(parser, case_id)
+                    result_str = "successfully" if result == 0 else "with errors"
+                    logger.info(f"Parser '{parser}' finished {result_str}", extra={'parser': parser, 'result': result})
                 except NotImplementedError:
-                    print(f"Parser '{parser}' is not implemented yet, skipping")
+                    logger.warning(f"Parser '{parser}' is not implemented yet, skipping", extra={'parser': parser})
+
+        if logger2file is not None:
+            logger2file.close()
 
     elif args.mode == 'analyse':
         # Handle analyse mode
@@ -155,14 +182,38 @@ def main():
         else:
             case_ids = [args.case_id]
 
+        # Handle console logging
+        log_level = args.log.upper()
+        logger.addHandler(get_console_handler(log_level))
+
+        logger2file = None
         for case_id in case_ids:
+            # Handle file logging
+            time_str = time.strftime("%Y%m%dT%H%M%S")
+            filename = f"{time_str}-analyse-{case_id}.jsonl"
+            folder = sd.config.get_case_parsed_data_folder(case_id)
+            # https://stackoverflow.com/questions/13839554/how-to-change-filehandle-with-python-logging-on-the-fly-with-different-classes-a
+            if logger2file is None:
+                logger2file = get_json_handler(os.path.join(folder, filename))
+                logger.addHandler(logger2file)
+            else:
+                logger2file.close()
+                logger2file.setStream(open(os.path.join(folder, filename), 'a'))
+
             print(f"Case ID: {case_id}")
             for analyser in analysers_list:
                 print(f"  Analyser '{analyser}' for case ID '{case_id}'")
+                logger.info(f"Analyser '{analyser}' started", extra={'analyser': analyser})
                 try:
-                    sd.analyse(analyser, case_id)
+                    result = sd.analyse(analyser, case_id)
+                    result_str = "successfully" if result == 0 else "with errors"
+                    logger.info(f"Analyser '{analyser}' finished {result_str}", extra={'analyser': analyser, 'result': result})
                 except NotImplementedError:
-                    print(f"Analyser '{analyser}' is not implemented yet, skipping")
+                    logger.warning(f"Analyser '{analyser}' is not implemented yet, skipping", extra={'analyser': analyser})
+
+        if logger2file is not None:
+            logger2file.close()
+
     else:
         parser.print_help()