com.unity.netcode.gameobjects icon indicating copy to clipboard operation
com.unity.netcode.gameobjects copied to clipboard

Published 20 hours ago • verified publisher icon Unity-Technologies

Frequent RenderTime before m_StartTimeConsumed error logs

Open jay-tux opened this issue 1 year ago • 4 comments

I'm getting the following error a lot in the console (with different float values, obviously):

[Netcode] renderTime was before m_StartTimeConsumed. This should never happen. renderTime is 12.2774583677451, m_StartTimeConsumed is 12.3562192954915
UnityEngine.Debug:LogError (object)
Unity.Netcode.NetworkLog:LogError (string) (at Library/PackageCache/[email protected]/Runtime/Logging/NetworkLog.cs:34)
Unity.Netcode.BufferedLinearInterpolator`1<single>:Update (single,double,double) (at Library/PackageCache/[email protected]/Components/Interpolator/BufferedLinearInterpolator.cs:207)
Unity.Netcode.Components.NetworkTransform:Update () (at Library/PackageCache/[email protected]/Components/NetworkTransform.cs:1207)

Any idea what could cause this/fix this?

jay-tux avatar Aug 01 '23 08:08 jay-tux

I also see this error in 1.7.1 and I think it is in relation to NetworkTransform.Teleport (and possibly re-parenting? not sure about that bit)

I see it in clusters intermittently using two Unity Editors and Parrel Sync.

[Netcode] renderTime was before m_StartTimeConsumed. This should never happen. renderTime is 1270.11108483368, m_StartTimeConsumed is 1270.16666666667
0x00007ff7320e282d (Unity) StackWalker::GetCurrentCallstack
0x00007ff7320e77d9 (Unity) StackWalker::ShowCallstack
0x00007ff7330b7831 (Unity) GetStacktrace
0x00007ff733775d52 (Unity) DebugStringToFile
0x00007ff731016db6 (Unity) DebugLogHandler_CUSTOM_Internal_Log
0x000001235c667453 (Mono JIT Code) (wrapper managed-to-native) UnityEngine.DebugLogHandler:Internal_Log (UnityEngine.LogType,UnityEngine.LogOption,string,UnityEngine.Object)
0x000001235c66738b (Mono JIT Code) UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])
0x000001235c667110 (Mono JIT Code) UnityEngine.Logger:Log (UnityEngine.LogType,object)
0x00000125a73c3d05 (Mono JIT Code) UnityEngine.Debug:LogError (object)
0x00000125a73c3cab (Mono JIT Code) Unity.Netcode.NetworkLog:LogError (string) (at ./Packages/[email protected]/Runtime/Logging/NetworkLog.cs:34)
0x0000012566fad78b (Mono JIT Code) Unity.Netcode.BufferedLinearInterpolator`1<UnityEngine.Vector3>:Update (single,double,double) (at ./Packages/[email protected]/Components/Interpolator/BufferedLinearInterpolator.cs:209)
0x00000125a6fd0a1b (Mono JIT Code) Unity.Netcode.Components.NetworkTransform:Update () (at ./Packages/[email protected]/Components/NetworkTransform.cs:2808)
0x00000125af9f0088 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007ff8dd7ae274 (mono-2.0-bdwgc) mono_jit_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/mini/mini-runtime.c:3445)
0x00007ff8dd6eeb74 (mono-2.0-bdwgc) do_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3066)
0x00007ff8dd6eed0c (mono-2.0-bdwgc) mono_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3113)
0x00007ff731ff9d14 (Unity) scripting_method_invoke
0x00007ff731fd7e34 (Unity) ScriptingInvocation::Invoke
0x00007ff731fbf4b4 (Unity) MonoBehaviour::CallMethodIfAvailable
0x00007ff731fbf5da (Unity) MonoBehaviour::CallUpdateMethod
0x00007ff731a5bf7b (Unity) BaseBehaviourManager::CommonUpdate<BehaviourManager>
0x00007ff731a6378a (Unity) BehaviourManager::Update
0x00007ff731c9464d (Unity) `InitPlayerLoopCallbacks'::`2'::UpdateScriptRunBehaviourUpdateRegistrator::Forward
0x00007ff731c735cc (Unity) ExecutePlayerLoop
0x00007ff731c73748 (Unity) ExecutePlayerLoop
0x00007ff731c7a025 (Unity) PlayerLoop
0x00007ff732c3c16f (Unity) PlayerLoopController::InternalUpdateScene
0x00007ff732c48d9d (Unity) PlayerLoopController::UpdateSceneIfNeededFromMainLoop
0x00007ff732c470a1 (Unity) Application::TickTimer
0x00007ff7330be16a (Unity) MainMessageLoop
0x00007ff7330c39d0 (Unity) WinMain
0x00007ff7344a7dbe (Unity) __scrt_common_main_seh
0x00007ff98b17257d (KERNEL32) BaseThreadInitThunk
0x00007ff98b86aa58 (ntdll) RtlUserThreadStart

[Netcode] renderTime was before m_StartTimeConsumed. This should never happen. renderTime is 1270.12417936535, m_StartTimeConsumed is 1270.16666666667
0x00007ff7320e282d (Unity) StackWalker::GetCurrentCallstack
0x00007ff7320e77d9 (Unity) StackWalker::ShowCallstack
0x00007ff7330b7831 (Unity) GetStacktrace
0x00007ff733775d52 (Unity) DebugStringToFile
0x00007ff731016db6 (Unity) DebugLogHandler_CUSTOM_Internal_Log
0x000001235c667453 (Mono JIT Code) (wrapper managed-to-native) UnityEngine.DebugLogHandler:Internal_Log (UnityEngine.LogType,UnityEngine.LogOption,string,UnityEngine.Object)
0x000001235c66738b (Mono JIT Code) UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])
0x000001235c667110 (Mono JIT Code) UnityEngine.Logger:Log (UnityEngine.LogType,object)
0x00000125a73c3d05 (Mono JIT Code) UnityEngine.Debug:LogError (object)
0x00000125a73c3cab (Mono JIT Code) Unity.Netcode.NetworkLog:LogError (string) (at ./Packages/[email protected]/Runtime/Logging/NetworkLog.cs:34)
0x0000012566fad78b (Mono JIT Code) Unity.Netcode.BufferedLinearInterpolator`1<UnityEngine.Vector3>:Update (single,double,double) (at ./Packages/[email protected]/Components/Interpolator/BufferedLinearInterpolator.cs:209)
0x00000125a6fd0a1b (Mono JIT Code) Unity.Netcode.Components.NetworkTransform:Update () (at ./Packages/[email protected]/Components/NetworkTransform.cs:2808)
0x00000125af9f0088 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007ff8dd7ae274 (mono-2.0-bdwgc) mono_jit_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/mini/mini-runtime.c:3445)
0x00007ff8dd6eeb74 (mono-2.0-bdwgc) do_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3066)
0x00007ff8dd6eed0c (mono-2.0-bdwgc) mono_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3113)
0x00007ff731ff9d14 (Unity) scripting_method_invoke
0x00007ff731fd7e34 (Unity) ScriptingInvocation::Invoke
0x00007ff731fbf4b4 (Unity) MonoBehaviour::CallMethodIfAvailable
0x00007ff731fbf5da (Unity) MonoBehaviour::CallUpdateMethod
0x00007ff731a5bf7b (Unity) BaseBehaviourManager::CommonUpdate<BehaviourManager>
0x00007ff731a6378a (Unity) BehaviourManager::Update
0x00007ff731c9464d (Unity) `InitPlayerLoopCallbacks'::`2'::UpdateScriptRunBehaviourUpdateRegistrator::Forward
0x00007ff731c735cc (Unity) ExecutePlayerLoop
0x00007ff731c73748 (Unity) ExecutePlayerLoop
0x00007ff731c7a025 (Unity) PlayerLoop
0x00007ff732c3c16f (Unity) PlayerLoopController::InternalUpdateScene
0x00007ff732c48d9d (Unity) PlayerLoopController::UpdateSceneIfNeededFromMainLoop
0x00007ff732c470a1 (Unity) Application::TickTimer
0x00007ff7330be16a (Unity) MainMessageLoop
0x00007ff7330c39d0 (Unity) WinMain
0x00007ff7344a7dbe (Unity) __scrt_common_main_seh
0x00007ff98b17257d (KERNEL32) BaseThreadInitThunk
0x00007ff98b86aa58 (ntdll) RtlUserThreadStart

[Netcode] renderTime was before m_StartTimeConsumed. This should never happen. renderTime is 1270.13623644256, m_StartTimeConsumed is 1270.16666666667
0x00007ff7320e282d (Unity) StackWalker::GetCurrentCallstack
0x00007ff7320e77d9 (Unity) StackWalker::ShowCallstack
0x00007ff7330b7831 (Unity) GetStacktrace
0x00007ff733775d52 (Unity) DebugStringToFile
0x00007ff731016db6 (Unity) DebugLogHandler_CUSTOM_Internal_Log
0x000001235c667453 (Mono JIT Code) (wrapper managed-to-native) UnityEngine.DebugLogHandler:Internal_Log (UnityEngine.LogType,UnityEngine.LogOption,string,UnityEngine.Object)
0x000001235c66738b (Mono JIT Code) UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])
0x000001235c667110 (Mono JIT Code) UnityEngine.Logger:Log (UnityEngine.LogType,object)
0x00000125a73c3d05 (Mono JIT Code) UnityEngine.Debug:LogError (object)
0x00000125a73c3cab (Mono JIT Code) Unity.Netcode.NetworkLog:LogError (string) (at ./Packages/[email protected]/Runtime/Logging/NetworkLog.cs:34)
0x0000012566fad78b (Mono JIT Code) Unity.Netcode.BufferedLinearInterpolator`1<UnityEngine.Vector3>:Update (single,double,double) (at ./Packages/[email protected]/Components/Interpolator/BufferedLinearInterpolator.cs:209)
0x00000125a6fd0a1b (Mono JIT Code) Unity.Netcode.Components.NetworkTransform:Update () (at ./Packages/[email protected]/Components/NetworkTransform.cs:2808)
0x00000125af9f0088 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007ff8dd7ae274 (mono-2.0-bdwgc) mono_jit_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/mini/mini-runtime.c:3445)
0x00007ff8dd6eeb74 (mono-2.0-bdwgc) do_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3066)
0x00007ff8dd6eed0c (mono-2.0-bdwgc) mono_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3113)
0x00007ff731ff9d14 (Unity) scripting_method_invoke
0x00007ff731fd7e34 (Unity) ScriptingInvocation::Invoke
0x00007ff731fbf4b4 (Unity) MonoBehaviour::CallMethodIfAvailable
0x00007ff731fbf5da (Unity) MonoBehaviour::CallUpdateMethod
0x00007ff731a5bf7b (Unity) BaseBehaviourManager::CommonUpdate<BehaviourManager>
0x00007ff731a6378a (Unity) BehaviourManager::Update
0x00007ff731c9464d (Unity) `InitPlayerLoopCallbacks'::`2'::UpdateScriptRunBehaviourUpdateRegistrator::Forward
0x00007ff731c735cc (Unity) ExecutePlayerLoop
0x00007ff731c73748 (Unity) ExecutePlayerLoop
0x00007ff731c7a025 (Unity) PlayerLoop
0x00007ff732c3c16f (Unity) PlayerLoopController::InternalUpdateScene
0x00007ff732c48d9d (Unity) PlayerLoopController::UpdateSceneIfNeededFromMainLoop
0x00007ff732c470a1 (Unity) Application::TickTimer
0x00007ff7330be16a (Unity) MainMessageLoop
0x00007ff7330c39d0 (Unity) WinMain
0x00007ff7344a7dbe (Unity) __scrt_common_main_seh
0x00007ff98b17257d (KERNEL32) BaseThreadInitThunk
0x00007ff98b86aa58 (ntdll) RtlUserThreadStart

[Netcode] renderTime was before m_StartTimeConsumed. This should never happen. renderTime is 1270.1486973178, m_StartTimeConsumed is 1270.16666666667
0x00007ff7320e282d (Unity) StackWalker::GetCurrentCallstack
0x00007ff7320e77d9 (Unity) StackWalker::ShowCallstack
0x00007ff7330b7831 (Unity) GetStacktrace
0x00007ff733775d52 (Unity) DebugStringToFile
0x00007ff731016db6 (Unity) DebugLogHandler_CUSTOM_Internal_Log
0x000001235c667453 (Mono JIT Code) (wrapper managed-to-native) UnityEngine.DebugLogHandler:Internal_Log (UnityEngine.LogType,UnityEngine.LogOption,string,UnityEngine.Object)
0x000001235c66738b (Mono JIT Code) UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])
0x000001235c667110 (Mono JIT Code) UnityEngine.Logger:Log (UnityEngine.LogType,object)
0x00000125a73c3d05 (Mono JIT Code) UnityEngine.Debug:LogError (object)
0x00000125a73c3cab (Mono JIT Code) Unity.Netcode.NetworkLog:LogError (string) (at ./Packages/[email protected]/Runtime/Logging/NetworkLog.cs:34)
0x0000012566fad78b (Mono JIT Code) Unity.Netcode.BufferedLinearInterpolator`1<UnityEngine.Vector3>:Update (single,double,double) (at ./Packages/[email protected]/Components/Interpolator/BufferedLinearInterpolator.cs:209)
0x00000125a6fd0a1b (Mono JIT Code) Unity.Netcode.Components.NetworkTransform:Update () (at ./Packages/[email protected]/Components/NetworkTransform.cs:2808)
0x00000125af9f0088 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007ff8dd7ae274 (mono-2.0-bdwgc) mono_jit_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/mini/mini-runtime.c:3445)
0x00007ff8dd6eeb74 (mono-2.0-bdwgc) do_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3066)
0x00007ff8dd6eed0c (mono-2.0-bdwgc) mono_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3113)
0x00007ff731ff9d14 (Unity) scripting_method_invoke
0x00007ff731fd7e34 (Unity) ScriptingInvocation::Invoke
0x00007ff731fbf4b4 (Unity) MonoBehaviour::CallMethodIfAvailable
0x00007ff731fbf5da (Unity) MonoBehaviour::CallUpdateMethod
0x00007ff731a5bf7b (Unity) BaseBehaviourManager::CommonUpdate<BehaviourManager>
0x00007ff731a6378a (Unity) BehaviourManager::Update
0x00007ff731c9464d (Unity) `InitPlayerLoopCallbacks'::`2'::UpdateScriptRunBehaviourUpdateRegistrator::Forward
0x00007ff731c735cc (Unity) ExecutePlayerLoop
0x00007ff731c73748 (Unity) ExecutePlayerLoop
0x00007ff731c7a025 (Unity) PlayerLoop
0x00007ff732c3c16f (Unity) PlayerLoopController::InternalUpdateScene
0x00007ff732c48d9d (Unity) PlayerLoopController::UpdateSceneIfNeededFromMainLoop
0x00007ff732c470a1 (Unity) Application::TickTimer
0x00007ff7330be16a (Unity) MainMessageLoop
0x00007ff7330c39d0 (Unity) WinMain
0x00007ff7344a7dbe (Unity) __scrt_common_main_seh
0x00007ff98b17257d (KERNEL32) BaseThreadInitThunk
0x00007ff98b86aa58 (ntdll) RtlUserThreadStart

[Netcode] renderTime was before m_StartTimeConsumed. This should never happen. renderTime is 1270.16080491867, m_StartTimeConsumed is 1270.16666666667
0x00007ff7320e282d (Unity) StackWalker::GetCurrentCallstack
0x00007ff7320e77d9 (Unity) StackWalker::ShowCallstack
0x00007ff7330b7831 (Unity) GetStacktrace
0x00007ff733775d52 (Unity) DebugStringToFile
0x00007ff731016db6 (Unity) DebugLogHandler_CUSTOM_Internal_Log
0x000001235c667453 (Mono JIT Code) (wrapper managed-to-native) UnityEngine.DebugLogHandler:Internal_Log (UnityEngine.LogType,UnityEngine.LogOption,string,UnityEngine.Object)
0x000001235c66738b (Mono JIT Code) UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])
0x000001235c667110 (Mono JIT Code) UnityEngine.Logger:Log (UnityEngine.LogType,object)
0x00000125a73c3d05 (Mono JIT Code) UnityEngine.Debug:LogError (object)
0x00000125a73c3cab (Mono JIT Code) Unity.Netcode.NetworkLog:LogError (string) (at ./Packages/[email protected]/Runtime/Logging/NetworkLog.cs:34)
0x0000012566fad78b (Mono JIT Code) Unity.Netcode.BufferedLinearInterpolator`1<UnityEngine.Vector3>:Update (single,double,double) (at ./Packages/[email protected]/Components/Interpolator/BufferedLinearInterpolator.cs:209)
0x00000125a6fd0a1b (Mono JIT Code) Unity.Netcode.Components.NetworkTransform:Update () (at ./Packages/[email protected]/Components/NetworkTransform.cs:2808)
0x00000125af9f0088 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007ff8dd7ae274 (mono-2.0-bdwgc) mono_jit_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/mini/mini-runtime.c:3445)
0x00007ff8dd6eeb74 (mono-2.0-bdwgc) do_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3066)
0x00007ff8dd6eed0c (mono-2.0-bdwgc) mono_runtime_invoke (at C:/build/output/Unity-Technologies/mono/mono/metadata/object.c:3113)
0x00007ff731ff9d14 (Unity) scripting_method_invoke
0x00007ff731fd7e34 (Unity) ScriptingInvocation::Invoke
0x00007ff731fbf4b4 (Unity) MonoBehaviour::CallMethodIfAvailable
0x00007ff731fbf5da (Unity) MonoBehaviour::CallUpdateMethod
0x00007ff731a5bf7b (Unity) BaseBehaviourManager::CommonUpdate<BehaviourManager>
0x00007ff731a6378a (Unity) BehaviourManager::Update
0x00007ff731c9464d (Unity) `InitPlayerLoopCallbacks'::`2'::UpdateScriptRunBehaviourUpdateRegistrator::Forward
0x00007ff731c735cc (Unity) ExecutePlayerLoop
0x00007ff731c73748 (Unity) ExecutePlayerLoop
0x00007ff731c7a025 (Unity) PlayerLoop
0x00007ff732c3c16f (Unity) PlayerLoopController::InternalUpdateScene
0x00007ff732c48d9d (Unity) PlayerLoopController::UpdateSceneIfNeededFromMainLoop
0x00007ff732c470a1 (Unity) Application::TickTimer
0x00007ff7330be16a (Unity) MainMessageLoop
0x00007ff7330c39d0 (Unity) WinMain
0x00007ff7344a7dbe (Unity) __scrt_common_main_seh
0x00007ff98b17257d (KERNEL32) BaseThreadInitThunk
0x00007ff98b86aa58 (ntdll) RtlUserThreadStart

zachstronaut avatar Dec 13 '23 21:12 zachstronaut

Did you two find a solution to this? I am seeing that it might be coming from the BufferedLinearInterpolator class from Netcode. Maybe there might be a fix in adjusting the interpolation settings? Will investigate

hwedwards avatar Apr 07 '24 03:04 hwedwards

Im getting the same [Netcode] renderTime was before m_StartTimeConsumed. This should never happen. renderTime is 92.9532505752984, m_StartTimeConsumed is 92.9666715152562 UnityEngine.DebugLogHandler:LogFormat(LogType, Object, String, Object[]) UnityEngine.Logger:Log(LogType, Object) UnityEngine.Debug:LogError(Object) Unity.Netcode.NetworkLog:LogError(String) (at .\Library\PackageCache\[email protected]\Runtime\Logging\NetworkLog.cs:34) Unity.Netcode.BufferedLinearInterpolator`1:Update(Single, Double, Double) (at .\Library\PackageCache\[email protected]\Components\Interpolator\BufferedLinearInterpolator.cs:207) Unity.Netcode.Components.NetworkTransform:Update() (at .\Library\PackageCache\[email protected]\Components\NetworkTransform.cs:2814)

This only happens in the build for me tho

Buwubi avatar May 12 '24 23:05 Buwubi

Having this issue as well. I'm also using ParallelSync and Relay and kinda pulling my hair out.

It happens when changing scenes from a basically empty scene with a network manager to another scene. After x amount of time, this crash happens. If I host the relay and join the relay from the other direction, it will not crash, but after 2 or 3 runs it'll crash and I reverse order again.

Really flaky and difficult to deal with crash. Unbelievably bad error message as well that doesn't help at all. Sometimes i'll be fine 10 runs in a row, sometimes it takes 10 trys to work once.

alexboisselle-rd avatar May 20 '24 01:05 alexboisselle-rd