Hacktoberfest 2026: los issues que los mantenedores marcaron para octubre, abiertos y aptos para principiantes. Explorar issues de Hacktoberfest

Per-task logging costs a third of worker throughput

Cerrado
  • ¿Algo no está bien?
#68 0 comentarios 0 reacciones 0 asignados Ver en GitHub

Los mantenedores suelen responder en 1 día

Nadie ha tomado este issue todavía.

Evaluación

Dificultad
3/5
Tiempo estimado
1-2 días
Aptitud para principiantes
68/100
Tipo de issue
Error
Claridad
Bastante claro
Estado de actividad
Activo
Stack tecnológico
django, python, redis
Área
backend, cli, observability, performance

Línea de trabajo

Start with threadmill/executor.py, especially configure_logging, the worker command options, and the per-task executor log calls. Trace how TaskExecutor receives logging configuration and how Django's task signal receivers inherit the root level. Done means the worker exposes a configurable level, avoids forcing INFO, and treats per-task executor messages as debug detail while preserving operator control of django.tasks.

Escrito por el modelo de indexación a partir del texto del issue.

Descripción

Profiling a drain (20,000 echo tasks, one process, one thread, prefetch 128) puts logging at roughly 70 µs of client CPU per task, against a recorded per-task wall of 184 µs. That is about 38% of the worker's throughput, and it is the single largest Python cost in the loop - larger than the Redis round trips it sits next to.

What emits four JSON records per task

  • threadmill/executor.py logs Executing task ... and then Task ... succeeded (or failed) at INFO for every task.
  • Django's own django.tasks.signals receivers (log_task_started, log_task_finished) log once more each. They are registered at import and sit at NOTSET, so they inherit the root logger's level.
  • threadmill/executor.py's configure_logging sets the root logger to INFO unconditionally, so all four records are formatted and written.
  • The worker's default formatter is JsonFormatter, which builds a payload dict and json.dumpses it per record, then writes to stdout and flushes.

Measured inside that 70 µs: 51 µs in StreamHandler.emit and 36 µs in JsonFormatter.format/json.dumps - the formatting, not the log call itself. record_task's lock, by contrast, costs 0.35 µs, and normalize_json 0.5 µs.

Why this is a defect and not just a tuning knob

There is no way to quieten a production worker: configure_logging hardcodes root_logger.setLevel(logging.INFO), and the command exposes --log-format but no --log-level. A deployment that wants WARNING output cannot get it, and it pays a JSON encode and a stdout flush per task for the privilege.

Suggested fix

  • Add a level option to the worker command (and to TaskExecutor), defaulting to something quiet.
  • Demote the two per-task executor records to DEBUG; "task started/succeeded" is trace-level detail, and the task itself is the interesting signal.
  • Leave the level of django.tasks to the operator rather than forcing the root logger to INFO.

Benchmark fairness

The comparison harness runs celery and dramatiq with --loglevel=WARNING, while threadmill currently cannot run below INFO, so part of the chart gap is threadmill logging its own benchmark. Fixing this makes the comparison apples-to-apples as well as making production faster.

Discovered while validating per-task performance claims; the profiling numbers are from a loaded machine, so treat the shares as the durable result and the absolute microseconds as this box's.

Lenguaje dominante
Python
Estrellas
21
Forks
2
Merge medio
12 h 39 min
PR fusionados (30 d)
27

Preparar el entorno

Primeros pasos

  1. Lee el issue completo y luego la guía de contribución del proyecto.
  2. Comenta en el issue que vas a ocuparte — evita que dos personas hagan lo mismo.
  3. Haz un fork del repositorio y trabaja en una rama.
  4. Abre un pull request que haga referencia al número del issue.

Issues similares

Más issues de Python

Recibe los nuevos issues en tu correo

Un resumen breve de issues de GitHub para principiantes.