Search Unity

Bug [TestRunner] Might be stuck when print debug log in other thread when teardown

Discussion in 'Testing & Automation' started by tianzhizhi, Jan 16, 2023.

  1. tianzhizhi

    tianzhizhi

    Joined:
    Jul 21, 2021
    Posts:
    3
    sample code:

    Code (CSharp):
    1. public class TestSample{
    2.  
    3.   [UnityTest]
    4.   public IEnumerator TearDown{
    5.     Debug.Log("Log...");
    6.  
    7.     var thread = new Thread(() =>{
    8.       Thread.Sleep(1);
    9.       Debug.Log("I am a log...")
    10.     });
    11.  
    12.     thread.IsBackground = true;
    13.     thread.Start();
    14.   }
    15. }
    (Of course, it's just a simple one, in my test unit it's more complicated than this)

    Then, sometimes I would get following error and be stuck forever in Unity Editor or Jenkins:

    Code (txt):
    1.  
    2. ArgumentOutOfRangeException: Index was out of range. Must be non-negative and less than the size of the collection.
    3. Parameter name: chunkLength
    4. at System.Text.StringBuilder.ToString () [0x000a6] in <695d1cc93cca45069c528c15c9fdd749>:0
    5. at NUnit.Framework.Internal.TestResult.get_Output () [0x00001] in <10b6135e63434fdba4fc6c109928ab3b>:0
    6. at UnityEditor.TestTools.TestRunner.Api.TestResultAdaptor..ctor (NUnit.Framework.Interfaces.ITestResult result, UnityEditor.TestTools.TestRunner.Api.ITestAdaptor test, UnityEditor.TestTools.TestRunner.Api.ITestResultAdaptor[] children) [0x000e2] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEditor.TestRunner/Api/TestResultAdaptor.cs:32
    7. at UnityEditor.TestTools.TestRunner.Api.TestAdaptorFactory.Create (NUnit.Framework.Interfaces.ITestResult testResult) [0x0002d] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEditor.TestRunner/Api/TestAdaptorFactory.cs:42
    8. at UnityEditor.TestTools.TestRunner.Api.CallbacksDelegator.TestFinished (NUnit.Framework.Interfaces.ITestResult result) [0x00007] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEditor.TestRunner/Api/CallbacksDelegator.cs:91
    9. at UnityEditor.TestTools.TestRunner.Api.CallbacksDelegatorListener.TestFinished (NUnit.Framework.Interfaces.ITestResult result) [0x00001] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEditor.TestRunner/Api/CallbacksDelegatorListener.cs:25
    10. at UnityEngine.Events.InvokableCall`1[T1].Invoke (T1 args0) [0x00010] in /Users/bokken/buildslave/unity/build/Runtime/Export/UnityEvent/UnityEvent.cs:221
    11. at UnityEngine.Events.UnityEvent`1[T0].Invoke (T0 arg0) [0x00025] in /Users/bokken/buildslave/unity/build/Runtime/Export/UnityEvent/UnityEvent/UnityEvent_1.cs:58
    12. at UnityEngine.TestTools.TestRunner.TestListenerWrapper.TestFinished (NUnit.Framework.Interfaces.ITestResult result) [0x00001] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/TestRunner/TestListenerWrapper.cs:23
    13. at UnityEngine.TestRunner.NUnitExtensions.Runner.UnityWorkItem.WorkItemComplete () [0x0005a] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/UnityWorkItem.cs:102
    14. at UnityEngine.TestRunner.NUnitExtensions.Runner.CoroutineTestWorkItem+<PerformWork>d__6.<>m__Finally1 () [0x00008] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CoroutineTestWorkItem.cs:72
    15. at UnityEngine.TestRunner.NUnitExtensions.Runner.CoroutineTestWorkItem+<PerformWork>d__6.MoveNext () [0x001ef] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CoroutineTestWorkItem.cs:69
    16. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<RunChildren>d__16.MoveNext () [0x000fa] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:201
    17. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<PerformWork>d__12.MoveNext () [0x0026d] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:77
    18. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<RunChildren>d__16.MoveNext () [0x000fa] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:201
    19. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<PerformWork>d__12.MoveNext () [0x0026d] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:77
    20. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<RunChildren>d__16.MoveNext () [0x000fa] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:201
    21. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<PerformWork>d__12.MoveNext () [0x0026d] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:77
    22. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<RunChildren>d__16.MoveNext () [0x000fa] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:201
    23. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<PerformWork>d__12.MoveNext () [0x0026d] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:77
    24. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<RunChildren>d__16.MoveNext () [0x000fa] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:201
    25. at UnityEngine.TestRunner.NUnitExtensions.Runner.CompositeWorkItem+<PerformWork>d__12.MoveNext () [0x0026d] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/NUnitExtensions/Runner/CompositeWorkItem.cs:77
    26. at UnityEngine.TestTools.TestRunner.PlaymodeTestsController+<TestRunnerCoroutine>d__15.MoveNext () [0x00058] in /Users/c4games/.jenkins/workspace/LoveEngine-Full-Test-GirlHD-Online/Library/PackageCache/com.unity.test-framework@1.1.31/UnityEngine.TestRunner/TestRunner/PlaymodeTestsController.cs:69
    27. at UnityEngine.SetupCoroutine.InvokeMoveNext (System.Collections.IEnumerator enumerator, System.IntPtr returnValueAddress) [0x00020] in /Users/bokken/buildslave/unity/build/Runtime/Export/Scripting/Coroutines.cs:17
    28.  
    I checked this in source code of test framework and guess that it might be caused by a StringBuilder has been writen by other backgorund thread and read by main thread at same time.

    Of couse it happened in a small probability.
     
    tianzhizhi, Jan 16, 2023
    #1
    sandolkakos likes this.

  2. Warnecke

    Warnecke

    Unity Technologies

    Joined:
    Nov 28, 2017
    Posts:
    92
    Hey. Thanks for reporting this. We have recently applied a fix for this and are testing it internally. Once we have confirmed that it no longer happens, we will include the fix in one of the next 1.3 UTF releases.
     
    Warnecke, Jan 16, 2023
    #2
    sandolkakos likes this.

  3. tianzhizhi

    tianzhizhi

    Joined:
    Jul 21, 2021
    Posts:
    3
    Great! Thanks for your fix and reply.
     
    tianzhizhi, Jan 16, 2023
    #3