Forkserver child processes start with no logging configured (embed/ingest logs lost)

[bygadd]

When the backend uses the forkserver start method, log records from child processes — the embedding/ingest path (ccb.injest, doc_loader, models, vectordb, network_em) — never reach the configured handlers; only the parent process logs. Per-request indexing/embedding activity is effectively invisible, which makes indexing problems hard to diagnose.

Cause: setup_logging() runs inside if __name__ == '__main__' in main.py (~L50–53), and the start method is set to forkserver just after. Forkserver children are re-imported without __main__, so they never run setup_logging() and start with default/unconfigured logging.

Suggested fix: relay child records to the parent's handlers — a multiprocessing.Queue + logging.handlers.QueueListener on the parent, and a QueueHandler installed in each child (wired in the child entrypoint / exception wrapper, with the queue passed into the spawned process). After wiring this on our 5.3.x deployment, child PIDs and ccb.injest lines appeared in the log.

(Disclosure: investigated with AI assistance; verified on a live deployment.)

[kyteinsky]

hello,
thanks for the report.
I would not yet consider this a bug since the warnings and errors from the subprocesses are still captured from the stdout/err but a feature request, and would be quite nice to have the queue system for the logs.

[bygadd]

hey — I can still reproduce this on 5.4.0.

From what I see, setup_logging() is still only called under if __name__ == "__main__" in main.py, and the forkserver start method is set right after that. Because of this, the forkserver children re-import the package without going through __main__, so they never run the logging setup.

The result is that the ccb.* child loggers — for example ccb.injest, network_em, doc_loader, models, vectordb — end up without handlers. The new stdconn pipe in exception_wrap is useful, and it does relay the child’s raw stdout/stderr, plus the faulthandler dump on crash. But it doesn’t relay normal logging records, so per-request embed/ingest logs from the child processes are still missing.

On our 5.4.0 instance, ccb.log only contained the main pid until we added a logging relay.

We re-applied the approach from the original issue, adjusted for the rewritten exception_wrap / exec_in_proc flow:

• one multiprocessing.Queue
• a QueueListener in the parent, using the real parent ccb handlers
• a QueueHandler installed on the child’s ccb logger from inside exception_wrap
• the queue is passed in as a kwarg from exec_in_proc

That keeps file writing in the parent process, so there is only one writer and no RotatingFileHandler rotation race. We also scoped it to ccb.*, so it doesn’t start relaying unrelated library logs.

After that change, log records from forkserver children like ccb.chain, ccb.nextwork_em, and ccb.utils show up in ccb.log with the child pid. Before the change, we only saw the main pid there.

This is the patch we’re currently running:

https://github.com/bygadd/context_chat-community-fixes/blob/a2a9db864f296baa9fee3c9b2989fe2a5f37a0ec/context_chat_backend/apply_patch_childlog_540.sh

Happy to open a PR if you’d like to take this upstream.

(Disclosure: investigated and verified on a live deployment, with AI assistance.)

[kyteinsky]

the method sounds good, would appreciate a PR!