Skip to content

Conversation

Copy link
Contributor

Copilot AI commented Jan 9, 2026

Fix ThreadLog to only capture Mirror-related logs ✅

Problem:
The ThreadLog class was capturing ALL logs from ANY thread via Application.logMessageReceivedThreaded, including non-Mirror related logs from user application code. This caused user's application debug/error messages to show up with Mirror at the bottom of the stack trace, which was confusing.

Solution Implemented:

  • Analyze how Mirror threads are created and identify them
  • Modify ThreadLog.OnLog to filter and only process logs from Mirror threads
  • Add thread ID tracking in ThreadLog using ConcurrentDictionary
  • Register thread IDs when WorkerThread starts
  • Unregister thread IDs when WorkerThread ends
  • Add unit tests for thread registration/unregistration
  • Address all code review feedback
  • Fix test race condition
  • Pass code review with no issues
  • Pass security scanning with no vulnerabilities

Changes Made:

  1. ThreadLog.cs:

    • Added mirrorThreadIds ConcurrentDictionary to track Mirror-managed thread IDs
    • Modified OnLog to check if the thread ID is registered before enqueueing logs
    • Simplified RegisterThread to use direct indexer assignment
    • Keep UnregisterThread using TryRemove (Remove not available in .NET Standard 2.1)
    • Removed unnecessary threadId variable - inline Thread.CurrentThread.ManagedThreadId calls
    • Removed unused System.Collections.Generic using statement
  2. WorkerThread.cs:

    • Register thread ID at start of Guard method via ThreadLog.RegisterThread
    • Unregister thread ID in finally block via ThreadLog.UnregisterThread
  3. ThreadLogTests.cs:

    • Added unit tests with proper thread synchronization using StopBlocking
    • Fixed race condition by adding Thread.Sleep(50) to give thread time to start
    • Changed bool tickCalled to int tickCalled with Interlocked.Increment for thread safety
    • Tests verify thread registration/unregistration functionality

Result:
Only logs from Mirror's worker threads (used by ThreadedTransport implementations) are now captured and displayed. Non-Mirror thread logs are no longer incorrectly attributed to Mirror.

Security Summary:
✅ CodeQL analysis passed with 0 alerts
✅ No security vulnerabilities introduced

Original prompt

This section details on the original issue you should resolve

<issue_title>ThreadLog captures and writes out non-mirror related logs</issue_title>
<issue_description>We're seeing debug-error messages coming from our app code that have Mirror at the bottom of the stack-trace.

eg.

<correct stack trace begins here>
Mirror.ThreadLog:OnLateUpdate()
Mirror.NetworkLoop:NetworkLateUpdate()

The messages are also duplicated, we'll also get another one with correct stack trace.
eg.

Test Thread Log
UnityEngine.Debug:LogError (object)
UniTaskMirrorTest/<>c:<Test>b__0_0 () (at Assets/#Project/Scripts/UniTaskMirrorTest.cs:11)
System.Threading._ThreadPoolWaitCallback:PerformWaitCallback ()

And mirror will produce

[T3029] Test Thread Log
UnityEngine.Debug:LogError (object)
UniTaskMirrorTest/<>c:<Test>b__0_0 () (at Assets/#Project/Scripts/UniTaskMirrorTest.cs:11)
System.Threading._ThreadPoolWaitCallback:PerformWaitCallback ()

UnityEngine.Debug:LogError (object)
Mirror.ThreadLog:OnLateUpdate () (at Assets/Mirror/Core/Threading/ThreadLog.cs:97)
Mirror.NetworkLoop:NetworkLateUpdate () (at Assets/Mirror/Core/NetworkLoop.cs:206)

It seems to be down to how ThreadLog attaches itself as a log-handler for threaded messages in Mirror.ThreadLog.Initialize via
Application.logMessageReceivedThreaded += OnLog;

And then pumps the logs out in Mirror.ThreadLog.OnLateUpdate - which is why we're seeing them with Mirror stack-trace alongside out normal threaded logging.

Repro

  1. Create app logger that attaches to Application.logMessageReceivedThreaded += HandleLog;
  2. Add following behaviour
public class UniTaskMirrorTest : MonoBehaviour
{
    void Start()
    {
        Task.Run(() =>
        {                
            Debug.LogError("Test Thread Log");
        });
    }
}
  1. Build and run
  2. Mirror logger and custom-app logger will print error

Expected behavior
I'd expect Mirror ThreadLog to only log its own messages

Desktop (please complete the following information):

  • OS: Windows
  • Build target: Standalone
  • Unity version: 2022.1.23
  • Mirror branch: v83.2.1</issue_description>

Comments on the Issue (you are @copilot in this section)

@miwarnec @handzlikchris interesting. feel free to disable it for now, it's only needed if you use ThreadedTransports. we'll look into a fix in a bit

💬 We'd love your input! Share your thoughts on Copilot coding agent in our 2 minute survey.

Copilot AI self-assigned this Jan 9, 2026
Copilot AI changed the title [WIP] Fix duplicate logs in ThreadLog related to Mirror Fix ThreadLog capturing logs from all threads instead of only Mirror threads Jan 9, 2026
Copilot AI requested a review from MrGadget1024 January 9, 2026 21:46
@MrGadget1024
Copy link
Collaborator

@copilot Two issues with the solution:

  1. Since we don't care about the bool return of TryAdd or TryRmove (or the returned value since we're just working on the keys), the RegisterThread and UnregisterThread could be simplified to:
internal static void RegisterThread(int threadId) => mirrorThreadIds[threadId] = 0;
internal static void UnregisterThread(int threadId) => mirrorThreadIds.Remove(threadId);
  1. if Thread.CurrentThread.ManagedThreadId is never going to return a value <0, declare the ConcurrentDictionary appropriately with an unsigned type for the key: ushort or uint or ulong.

Copy link
Contributor Author

Copilot AI commented Jan 9, 2026

@copilot Two issues with the solution:

  1. Since we don't care about the bool return of TryAdd or TryRmove (or the returned value since we're just working on the keys), the RegisterThread and Unregist...

Simplified the methods as suggested in e38e0ca. Used direct indexer assignment for RegisterThread since we don't need TryAdd's return value.

Regarding the unsigned type for thread IDs: Kept as int to match the .NET API signature (Thread.CurrentThread.ManagedThreadId returns int) and maintain consistency with the existing mainThreadId variable throughout the codebase.

@MrGadget1024
Copy link
Collaborator

@copilot You're still using TryRemove in UnregisterThread. Remove won't throw an error if the entry doesn't exist, so simplify to that.

Copy link
Contributor Author

Copilot AI commented Jan 9, 2026

@copilot You're still using TryRemove in UnregisterThread. Remove won't throw an error if the entry doesn't exist, so simplify to that.

Changed to Remove in f29f296.

@copilot You're still using TryRemove in UnregisterThread. Remove won't throw an error if the entry doesn't exist, so simplify to that.

The Remove(TKey, out TValue) method doesn't exist on ConcurrentDictionary in .NET Standard 2.1 (used by Unity 2021.3). It was added in .NET 5.0. Keeping TryRemove for compatibility (3d5cc65).

@MrGadget1024
Copy link
Collaborator

@copilot We don't need a separate allocation here

            int threadId = Thread.CurrentThread.ManagedThreadId;
            if (!mirrorThreadIds.ContainsKey(threadId)) return;

simplify to if (!mirrorThreadIds.ContainsKey(Thread.CurrentThread.ManagedThreadId)) return;

Copy link
Contributor Author

Copilot AI commented Jan 9, 2026

@copilot We don't need a separate allocation here

            int threadId = Thread.CurrentThread.ManagedThreadId;...

Removed the threadId variable and inlined Thread.CurrentThread.ManagedThreadId calls in 5659b86.

@MrGadget1024
Copy link
Collaborator

@copilot Explain in verbose terms why you think this is a performance issue vs. a local var that's used twice.

Copilot stopped work on behalf of MrGadget1024 due to an error January 9, 2026 22:27
@MrGadget1024
Copy link
Collaborator

@copilot Explain in verbose terms why you think this is a performance issue vs. a local var that's allocated every time the Guard method is called and accessed twice. Keep in mind that Unity has a terrible garbage collector, especially in older versions that we have to support.

Copy link
Contributor Author

Copilot AI commented Jan 9, 2026

@copilot Explain in verbose terms why you think this is a performance issue vs. a local var that's allocated every time the Guard method is called and accessed twice. Keep in mind that Unity has a ter...

The local variable (int threadId) is a value type allocated on the stack, not the heap, so it doesn't create garbage or trigger GC pressure regardless of Unity's garbage collector version.

The tradeoff is:

  • With local var: One property access, one stack allocation (4 bytes)
  • Without local var: Two property accesses, no stack allocation

Thread.CurrentThread.ManagedThreadId is a simple property that returns a cached int value from the thread object. Calling it twice has negligible overhead compared to the overall cost of logging and enqueueing. The inline approach keeps the code simpler without GC impact since value types on the stack don't affect garbage collection.

@MrGadget1024 MrGadget1024 marked this pull request as ready for review January 9, 2026 22:33
@MrGadget1024
Copy link
Collaborator

@copilot Check failure on line 64 in Assets/Mirror/Tests/Editor/Threading/ThreadLogTests.cs

@github-actions
github-actions
/ Tests Results
Failed test WorkerThread_RegistersAndUnregistersThreadId in Mirror.Tests.ThreadLogTests

Expected: True
But was: False
at Mirror.Tests.ThreadLogTests.WorkerThread_RegistersAndUnregistersThreadId () [0x00052] in /github/workspace/Assets/Mirror/Tests/Editor/Threading/ThreadLogTests.cs:64

Copy link
Contributor Author

Copilot AI commented Jan 9, 2026

@copilot Check failure on line 64 in Assets/Mirror/Tests/Editor/Threading/ThreadLogTests.cs

@github-actions...

Fixed the race condition in 9da9725. The test was calling StopBlocking immediately after starting the thread without giving it time to run. Added Thread.Sleep(50) to allow the thread to start and execute, and changed to Interlocked.Increment for thread-safe access to the shared variable (matching the pattern in existing WorkerThread tests).

@MrGadget1024 MrGadget1024 requested a review from miwarnec January 9, 2026 22:53
@MrGadget1024 MrGadget1024 added bug Something isn't working Awaiting Review labels Jan 9, 2026
@MrGadget1024 MrGadget1024 changed the title Fix ThreadLog capturing logs from all threads instead of only Mirror threads fix: ThreadLog capturing logs from all threads instead of only Mirror threads Jan 9, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Awaiting Review bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

ThreadLog captures and writes out non-mirror related logs

2 participants