Merge pull request #559 from sunbeam-labs/558-rollback-logging

Rollback logging

Author: Ulthran

.github/workflows/integration-tests.yml

@@ -56,4 +56,4 @@ jobs:
               run: |
                 sunbeam init --data_fp tests/data/reads/ --profile slurm test/
                 cat test/config.yaml
-                sunbeam run test --default-resources slurm_account=runner --profile test/
+                sunbeam run test --default-resources slurm_account=runner --profile test/ --show-failed-logs

sunbeam/logging.py

@@ -2,68 +2,19 @@
 from pathlib import Path
 
 
-class ConditionalLevelFormatter(logging.Formatter):
-    def format(self, record):
-        # For WARNING and above, include "LEVELNAME: message"
-        if record.levelno >= logging.WARNING:
-            return f"{record.levelname}: {record.getMessage()}"
-        # For lower levels like INFO, just return the message
-        return record.getMessage()
+logging.basicConfig(
+    level=logging.INFO,
+    format="%(message)s",
+)
 
 
 def get_sunbeam_logger() -> logging.Logger:
-    """Basic logger for general library output."""
-    logger = logging.getLogger("sunbeam")
-    logger.setLevel(logging.INFO)
+    return logging.getLogger()
 
-    if not logger.handlers:
-        ch = logging.StreamHandler()
-        ch.setLevel(logging.INFO)
-        ch.setFormatter(ConditionalLevelFormatter())
-        logger.addHandler(ch)
 
-    return logger
-
-
-def get_pipeline_logger(log_fp: Path = None) -> logging.Logger:
-    """Sets up logging for the main pipeline entry point."""
-    logger = logging.getLogger("sunbeam.pipeline")
-    logger.setLevel(logging.DEBUG)
-    logger.propagate = False
-
-    if not logger.handlers:
-        # Console handler
-        ch = logging.StreamHandler()
-        ch.setLevel(logging.INFO)
-        ch.setFormatter(ConditionalLevelFormatter())
-
-        # File handler
-        if log_fp is None:
-            raise ValueError(
-                "log_fp is None but the logger hasn't been initialized with a file handler yet"
-            )
-        fh = logging.FileHandler(log_fp, mode="w")
-        fh.setLevel(logging.DEBUG)
-        fh.setFormatter(logging.Formatter("[%(asctime)s] %(levelname)s: %(message)s"))
-
-        logger.addHandler(ch)
-        logger.addHandler(fh)
-
-    return logger
-
-
-class ExtensionLoggerAdapter(logging.LoggerAdapter):
-    def process(self, msg, kwargs):
-        return f"[{self.extra['ext'].upper()}] {msg}", kwargs
+def get_pipeline_logger(log_fp: Path | None = None) -> logging.Logger:
+    return logging.getLogger()
 
 
 def get_extension_logger(name: str) -> logging.Logger:
-    """Returns a logger for a specific extension under the pipeline."""
-    logger = logging.getLogger(f"sunbeam.pipeline.extensions.{name}")
-    logger.setLevel(logging.DEBUG)
-
-    # Remove any direct handlers — let it propagate to sunbeam.pipeline
-    logger.handlers.clear()
-    logger.propagate = True
-
-    return ExtensionLoggerAdapter(logger, {"ext": name})
+    return logging.getLogger()

sunbeam/scripts/run.py

@@ -18,13 +18,12 @@ def main(argv: list[str] = sys.argv):
 
     sc = SunbeamConfig.from_file(configfile)
     Cfg = sc.resolved_paths()
-    log_fp = Cfg["all"]["log_fp"]
 
     # From here on everything is considered part of the "pipeline"
     # This means all logs are handled by the pipeline logger (or pipeline extension loggers)
     # You could argue it would make more sense to start this at the actual snakemake call
     # but this way we can log some relevant setup information that might be useful on post-mortem analysis
-    logger = get_pipeline_logger(log_fp)
+    logger = get_pipeline_logger()
 
     snakefile = Path(__file__).parent.parent / "workflow" / "Snakefile"
     if not snakefile.exists():

sunbeam/workflow/Snakefile

@@ -20,7 +20,7 @@ MIN_RUNTIME = int(os.getenv("SUNBEAM_MIN_RUNTIME", 15))
 
 sc = SunbeamConfig(config)
 Cfg = sc.resolved_paths()
-logger = get_pipeline_logger(Cfg["all"]["log_fp"])
+logger = get_pipeline_logger()
 logger.debug(f"Sunbeam configuration: {Cfg}")
 
 # Load extensions
@@ -144,49 +144,39 @@ for sbx_name, sbx_fp in sbxs.items():
         include: rule_fp
 
 
-# ---- Add standard features to rules
-### NOT FUNCTIONAL ###
-# This is here for future reference but as-is does not do anything
-# Effectful lines are commented out to avoid errors/unintended behavior
-for rule_obj in workflow.rules:
-    # Determine wildcard string
-    wildcards_str = ""
-    if rule_obj.wildcard_names:
-        wildcards_str = "_".join(f"{{{w}}}" for w in rule_obj.wildcard_names)
-
-    # Add sunbeam log file
-    log_name = (
-        f"{rule_obj.name}_{wildcards_str}.log" if wildcards_str else f"{rule_obj.name}.log"
-    )
-    # rule_obj.log.update({"main": str(LOG_FP / log_name)})
-
-    # Add benchmarks
-    wildcards_str = "_".join(f"{{{w}}}" for w in rule_obj.wildcard_names)
-    benchmark_name = (
-        f"{rule_obj.name}_{wildcards_str}.tsv" if wildcards_str else f"{rule_obj.name}.tsv"
-    )
-
-    # try:
-    # rule_obj.benchmark = str(BENCHMARK_FP / benchmark_name)
-    # except AssertionError:
-    # logger.warning(f"Skipping benchmark assignment for rule '{rule_obj.name}' (unsupported)")
-    # logger.debug(rule_obj.benchmark)
-### END NOT FUNCTIONAL ###
-
-
 # ---- Rule all: run all targets
 rule all:
     input:
         TARGET_ALL,
 
 
+rule _test_shell:
+    output:
+        QC_FP / ".test_shell",
+    shell:
+        """
+        echo "Test shell rule executed successfully." > {output}
+        """
+
+
+rule _test_script:
+    output:
+        QC_FP / ".test_script",
+    log:
+        QC_FP / ".test_script.log",
+    script:
+        "scripts/_test_script.py"
+
+
 rule test:
     input:
         samples=expand(
             QC_FP / "00_samples" / "{sample}_{rp}.fastq.gz",
             sample=Samples.keys(),
             rp=Pairs,
         ),
+        test_shell=QC_FP / ".test_shell",
+        test_script=QC_FP / ".test_script",
     run:
         logger.info([x for x in input.samples])
 

sunbeam/workflow/scripts/_test_script.py

@@ -0,0 +1,18 @@
+from pathlib import Path
+
+
+l = snakemake.log[0]
+o = Path(snakemake.output[0])
+
+with open(l, "w") as log:
+    log.write("HERE\n")
+
+    from sunbeam.logging import get_pipeline_logger, get_extension_logger
+    from sunbeam.project import SampleList, SunbeamConfig, output_subdir
+
+    logger = get_pipeline_logger()
+    logger.info("This works!")
+
+    SampleList()
+
+    o.write_text("This is a test output file.\n")