Hacktoberfest 2026 : les issues que les mainteneurs ont marquées pour octobre, ouvertes et accessibles aux débutants. Parcourir les issues Hacktoberfest

Per-task logging costs a third of worker throughput

Fermée
  • Quelque chose ne va pas ?
#68 0 commentaires 0 réactions 0 personnes assignées Voir sur GitHub

Les mainteneurs répondent en général sous 1 jour

Personne n'a encore pris cette issue.

Évaluation

Difficulté
3/5
Temps estimé
1-2 jours
Accessibilité débutants
68/100
Type d'issue
Bug
Clarté
Plutôt claire
Activité
Active
Stack technique
django, python, redis
Domaine
backend, cli, observability, performance

Piste de recherche

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.

Rédigé par le modèle d'indexation à partir du texte de l'issue.

Description

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.

Langage dominant
Python
Étoiles
21
Forks
2
Merge moyen
12 h 39 min
PR mergées (30 j)
27

Préparer son environnement

Par où commencer

  1. Lisez l'issue en entier, puis le guide de contribution du projet.
  2. Signalez en commentaire que vous la prenez — cela évite que deux personnes fassent le même travail.
  3. Forkez le dépôt et travaillez sur une branche.
  4. Ouvrez une pull request qui référence le numéro de l'issue.

Issues similaires

Plus d'issues Python

Recevez les nouvelles issues par e-mail

Un résumé court des issues GitHub adaptées aux débutants.