Unity's logging system, in depth ① — four pitfalls of the log callback

Unity logging, part 1 of 3 — ① Callback pitfalls · ② A GC-free ring buffer · ③ What changes in builds (②·③ coming next)

The minimal bug capture setup covered hooking the log callback in a single paragraph. This series unpacks that paragraph properly — the material is the set of traps we actually hit while building our SDK's log collector.

Pitfall 1. logMessageReceived vs logMessageReceivedThreaded — the overlap problem

The difference is usually described as "main-thread logs only, or everything," but the precise behavior is this:

• logMessageReceived: only logs raised on the main thread, invoked on the main thread
• logMessageReceivedThreaded: logs from all threads, invoked on whichever thread raised them

The important part is that Threaded includes main-thread logs too. Subscribe to both and every main-thread log arrives twice. If you want worker-thread exceptions, subscribe to Threaded — and only Threaded.

Pitfall 2. Unity APIs inside the callback — the exception you tried to catch spawns a new one

The Threaded callback runs on the thread that raised the log. But many Unity APIs, Time.realtimeSinceStartup among them, are main-thread only — call them from a worker thread and you get a UnityException.

What makes this one vicious is the failure condition. It breaks only in the exact situation you chose Threaded for. During development, with main-thread logs only, everything runs fine — then after you ship, the first time a background thread throws, the log collector itself dies.

The fix combines two things — fall back to a value refreshed from the main thread, and defend the whole callback.

void OnLog(string condition, string stackTrace, LogType type)
{
    double time;
    try { time = Time.realtimeSinceStartupAsDouble; _lastMainThreadTime = time; }
    catch { time = _lastMainThreadTime; }   // worker thread — substitute the last known value
    // ... write to the buffer (lock required)
}

Pitfall 3. Logging from inside the callback — recursion

Call Debug.Log (or Debug.LogWarning, etc.) inside the callback and that log invokes the callback again. Unconditional logging means infinite recursion; even conditional logging can run away in edge cases.

The danger is that error-handling code is the most tempting place to violate this. "If the buffer write fails, at least log a warning" is exactly this trap. Failures inside the callback should go to some other channel — a counter, a flag — and be reported from the main loop.

Pitfall 4. Leaked subscriptions — a ghost you only meet in the editor

Forgetting -= in OnDisable is a plain leak in a build, but in the editor it becomes something stranger. In a project with domain reload disabled (Enter Play Mode Settings), static event subscriptions survive across play sessions, so a callback referencing a destroyed object gets invoked on the next play. It's a regular cause of the "weird exceptions from the second play session onward" mystery.

Enforce the subscribe/unsubscribe pair in OnEnable/OnDisable, and have the callback validate its own state on the first line.

Summary — the callback is a border crossing

What the four pitfalls share is this: the log callback looks like an ordinary C# event but is actually a thread boundary and a lifecycle boundary. The rule at a border is to do as little as possible — grab the timestamp and the data, put them in the buffer, and leave all judgment and processing to the main loop.

That "put them in the buffer" part is the next problem. If the collector allocates on every frame, the cause of your performance bugs becomes the collector itself. The next post covers designing a ring buffer with zero GC allocation.