Files
rengine/shared/logging.py
T
Yogesh OjhaandClaude Sonnet 5 8fac962556 fix(celery): dispatch the canvas one step at a time, not nested
A nested chord canvas put the whole remaining pipeline into every
stage message, duplicated per sibling per level: 33 MB per message,
39 of them filled a 1 GB Redis, and the worker was OOM-killed
deserializing them. Every later launch then failed with "command not
allowed when used memory > 'maxmemory'".

shared/services/orchestrator/canvas.py now builds one step at a time;
a step's chord body is app.tasks.scan.run_scan_step(steps, index+1),
which dispatches the next step once the current one settles. Messages
are ~1 KB now; tests/pipeline/test_canvas_shape.py caps them.

Also, from an end-to-end review of the pipeline:

- The reaper re-queues a PENDING scan with no launch anywhere in the
  queue, so a lost or failed send_task no longer strands it forever.
  api create() now dispatches off the event loop and records a failed
  dispatch the way create_batch already did.
- Cancel no longer revokes queued stage tasks. A cancelled run used to
  walk every remaining step recording one aborted row per stage, and
  whether finalize ran depended on a race with the revoke broadcast.
  The step body now finalizes a cancelled run directly, and the api
  also dispatches finalize so a run with no live canvas still settles.
- The reaper only skips scans that actually have a message queued,
  read off the scans queue, instead of skipping every scan whenever
  the queue holds anything.
- Every beat tick carries expires, so a worker that comes back after
  being down does not replay hours of stacked ticks.
- worker-default and worker-beat restart on their own.
- _run_process kills the tool in a finally; a soft time limit raised
  inside proc.wait used to leave the tool running past the stage.
- on_worker_ready crashed on a missing Consumer attribute, so the
  worker's IP-range and threat-feed warm-up never ran.
- Worker logging now goes through the root logger; it was configured
  on a "rengine.worker" logger nothing writes to, so INFO logs (task
  starts, step hand-overs) never appeared in the container output.
- _normalize_url no longer raises on an unparseable value, which had
  been killing the whole bounty feed sync on one bad scope entry.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0181JfVNatLVWnDbtGWRWPov
2026-09-22 19:31:15 +05:30

99 lines
2.9 KiB
Python

import logging
import sys
from typing import ClassVar
class ColoredFormatter(logging.Formatter):
# ANSI color codes
COLORS: ClassVar[dict[str, str]] = {
"DEBUG": "\033[36m",
"INFO": "\033[32m",
"WARNING": "\033[33m",
"ERROR": "\033[31m",
"CRITICAL": "\033[35m",
"RESET": "\033[0m",
}
def format(self, record: logging.LogRecord) -> str:
plain = record.levelname
color = self.COLORS.get(plain, self.COLORS["RESET"])
record.levelname = f"{color}{plain}{self.COLORS['RESET']}"
try:
return super().format(record)
finally:
record.levelname = plain
QUIET_LOGGERS = ("httpx", "httpcore", "hpack", "urllib3", "asyncio", "kombu", "amqp")
def setup_logging(
name: str = "rengine",
level: str = "INFO",
colored: bool = True,
) -> logging.Logger:
logger = logging.getLogger(name)
logger.setLevel(getattr(logging, level.upper()))
logger.handlers.clear()
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(logging.DEBUG)
if colored:
console_format = ColoredFormatter(
fmt="%(asctime)s | %(levelname)-8s | %(name)s | %(message)s",
datefmt="%Y-%m-%d %H:%M:%S",
)
else:
console_format = logging.Formatter(
fmt="%(asctime)s | %(levelname)-8s | %(name)s | %(message)s",
datefmt="%Y-%m-%d %H:%M:%S",
)
console_handler.setFormatter(console_format)
logger.addHandler(console_handler)
for noisy in QUIET_LOGGERS:
logging.getLogger(noisy).setLevel(logging.WARNING)
return logger
_RESERVED = frozenset({"exc_info", "stack_info", "stacklevel", "extra"})
class _FieldLogger(logging.LoggerAdapter):
"""Accepts structured fields as keywords and appends them to the message."""
def log(self, level, msg, *args, **kwargs):
fields = {k: v for k, v in kwargs.items() if k not in _RESERVED}
for key in fields:
kwargs.pop(key)
if fields:
rendered = " ".join(f"{k}={v}" for k, v in fields.items())
msg = f"{msg} | {rendered}"
super().log(level, msg, *args, **kwargs)
def debug(self, msg, *args, **kwargs):
self.log(logging.DEBUG, msg, *args, **kwargs)
def info(self, msg, *args, **kwargs):
self.log(logging.INFO, msg, *args, **kwargs)
def warning(self, msg, *args, **kwargs):
self.log(logging.WARNING, msg, *args, **kwargs)
def error(self, msg, *args, **kwargs):
self.log(logging.ERROR, msg, *args, **kwargs)
def exception(self, msg, *args, **kwargs):
kwargs.setdefault("exc_info", True)
self.log(logging.ERROR, msg, *args, **kwargs)
def critical(self, msg, *args, **kwargs):
self.log(logging.CRITICAL, msg, *args, **kwargs)
def get_logger(name: str) -> logging.Logger:
return _FieldLogger(logging.getLogger(name), {})