Fix process log

utils/process.py

@@ -109,7 +109,7 @@ def process(
         main_task_id = get_options(task_dict["options"]).get("main_task_id", 0)
 
     # ToDo new logger here
-    handlers = init_logging(tid=str(task_id), debug=debug)
+    per_analysis_handler = init_per_analysis_logging(tid=str(task_id), debug=debug)
     set_formatter_fmt(task_id, main_task_id)
     setproctitle(f"{original_proctitle} [Task {task_id}]")
     results = {"statistics": {"processing": [], "signatures": [], "reporting": []}}
@@ -154,10 +154,7 @@ def process(
         for i, obj in enumerate(gc.garbage):
             log.info("(garbage) GC object #%d: type=%s", i, type(obj).__name__)
 
-    for handler in handlers:
-        if not handler:
-            continue
-        log.removeHandler(handler)
+    log.removeHandler(per_analysis_handler)
 
 
 def init_worker():
@@ -180,7 +177,7 @@ def set_formatter_fmt(task_id=None, main_task_id=None):
     FORMATTER._style._fmt = get_formatter_fmt(task_id, main_task_id)
 
 
-def init_logging(tid=0, debug=False):
+def init_logging(debug=False):
 
     # Pyattck creates root logger which we don't want. So we must use this dirty hack to remove it
     # If basicConfig was already called by something and had a StreamHandler added,
@@ -195,15 +192,13 @@ def init_logging(tid=0, debug=False):
         - ch - console handler
         - slh - syslog handler
         - fh - file handle -> process.log
-        - fhpa - file handler per analysis
     """
 
     ch = ConsoleHandler()
     ch.setFormatter(FORMATTER)
     log.addHandler(ch)
 
     slh = False
-    fhpa = False
 
     if logconf.logger.syslog_process:
         slh = logging.handlers.SysLogHandler(address=logconf.logger.syslog_dev)
@@ -223,6 +218,30 @@ def init_logging(tid=0, debug=False):
 
         fh.setFormatter(FORMATTER)
         log.addHandler(fh)
+    except PermissionError:
+        sys.exit("Probably executed with wrong user, PermissionError to create/access log")
+
+    if debug:
+        log.setLevel(logging.DEBUG)
+    else:
+        log.setLevel(logging.INFO)
+
+    logging.getLogger("urllib3").setLevel(logging.WARNING)
+    return ch, fh, slh
+
+
+def init_per_analysis_logging(tid=0, debug=False):
+
+    """
+    Handlers:
+        - fhpa - file handler per analysis
+    """
+
+    fhpa = False
+
+    try:
+        if not path_exists(os.path.join(CUCKOO_ROOT, "log")):
+            path_mkdir(os.path.join(CUCKOO_ROOT, "log"))
 
         if logconf.logger.process_analysis_folder:
             path = os.path.join(CUCKOO_ROOT, "storage", "analyses", str(tid), "process.log")
@@ -242,15 +261,14 @@ def init_logging(tid=0, debug=False):
     else:
         log.setLevel(logging.INFO)
 
-    logging.getLogger("urllib3").setLevel(logging.WARNING)
-    return ch, fh, slh, fhpa
+    return fhpa
 
 
 def processing_finished(future):
     task_id = pending_future_map.get(future)
     try:
         _ = future.result()
-        log.info("Reports generation completed")
+        log.info("Reports generation completed for Task #%d", task_id)
     except TimeoutError as error:
         log.error("Processing Timeout %s. Function: %s", error, error.args[1])
         Database().set_status(task_id, TASK_FAILED_PROCESSING)
@@ -459,6 +477,8 @@ def main():
     )
     args = parser.parse_args()
 
+    handlers = init_logging(debug=args.debug)
+
     init_modules()
     if args.id == "auto":
         autoprocess(
@@ -525,6 +545,11 @@ def main():
                 log.debug("Finished processing task")
                 set_formatter_fmt()
 
+    for handler in handlers:
+        if not handler:
+            continue
+        log.removeHandler(handler)
+
 
 if __name__ == "__main__":
     with suppress(KeyboardInterrupt):