diff --git a/com.unity.netcode.gameobjects/Editor/NetworkManagerEditor.cs b/com.unity.netcode.gameobjects/Editor/NetworkManagerEditor.cs index 6f3bd006c1..293836d22d 100644 --- a/com.unity.netcode.gameobjects/Editor/NetworkManagerEditor.cs +++ b/com.unity.netcode.gameobjects/Editor/NetworkManagerEditor.cs @@ -298,7 +298,7 @@ private void DisplayNetworkManagerProperties() #else string path = Path.Combine(directory, $"NetworkPrefabs-{m_NetworkManager.GetInstanceID()}.asset"); #endif - Debug.Log("Saving migrated Network Prefabs List to " + path); + m_NetworkManager.Log.Info(new Context(LogLevel.Normal, "Saving migrated Network Prefabs List").With("Path", path)); AssetDatabase.CreateAsset(networkPrefabs, path); EditorUtility.SetDirty(m_NetworkManager); } diff --git a/com.unity.netcode.gameobjects/Editor/NetworkManagerHelper.cs b/com.unity.netcode.gameobjects/Editor/NetworkManagerHelper.cs index cdd4b06186..4352749f5f 100644 --- a/com.unity.netcode.gameobjects/Editor/NetworkManagerHelper.cs +++ b/com.unity.netcode.gameobjects/Editor/NetworkManagerHelper.cs @@ -162,19 +162,17 @@ public void CheckAndNotifyUserNetworkObjectRemoved(NetworkManager networkManager if (!EditorApplication.isPlaying && !editorTest) { - EditorUtility.DisplayDialog($"Removing {nameof(NetworkObject)}", NetworkManagerAndNetworkObjectNotAllowedMessage(), "OK"); + EditorUtility.DisplayDialog($"Removing {nameof(NetworkObject)}", k_NetworkManagerAndNetworkObjectNotAllowedMessage, "OK"); } else { - Debug.LogError(NetworkManagerAndNetworkObjectNotAllowedMessage()); + networkManager.Log.Error(new Context(LogLevel.Error, k_NetworkManagerAndNetworkObjectNotAllowedMessage)); } } } - public string NetworkManagerAndNetworkObjectNotAllowedMessage() - { - return $"A {nameof(GameObject)} cannot have both a {nameof(NetworkManager)} and {nameof(NetworkObject)} assigned to it or any children under it."; - } + private static readonly string k_NetworkManagerAndNetworkObjectNotAllowedMessage = $"A {nameof(GameObject)} cannot have both a {nameof(NetworkManager)} and {nameof(NetworkObject)} assigned to it or any children under it."; + public string NetworkManagerAndNetworkObjectNotAllowedMessage() => k_NetworkManagerAndNetworkObjectNotAllowedMessage; /// /// Handles notifying the user, via display dialog window, that they have nested a NetworkManager. @@ -215,7 +213,7 @@ public bool NotifyUserOfNestedNetworkManager(NetworkManager networkManager, bool } else { - Debug.LogError(message); + networkManager.Log.Error(new Context(LogLevel.Error, message)); } if (!s_LastKnownNetworkManagerParents.ContainsKey(networkManager) && isParented) diff --git a/com.unity.netcode.gameobjects/Runtime/Core/NetworkManager.cs b/com.unity.netcode.gameobjects/Runtime/Core/NetworkManager.cs index d8bcfaffff..14ee04ea0b 100644 --- a/com.unity.netcode.gameobjects/Runtime/Core/NetworkManager.cs +++ b/com.unity.netcode.gameobjects/Runtime/Core/NetworkManager.cs @@ -73,10 +73,7 @@ internal static void LogSerializedTypeNotOptimized() if (!s_SerializedType.Contains(type)) { s_SerializedType.Add(type); - if (NetworkLog.CurrentLogLevel <= LogLevel.Developer) - { - Debug.LogWarning($"[{type.Name}] Serialized type has not been optimized for use with Distributed Authority!"); - } + NetworkLog.LogWarning(new Context(LogLevel.Developer, "Serialized type has not been optimized for use with Distributed Authority!").With(type.Name)); } } #endif @@ -148,7 +145,7 @@ internal GameObject FetchLocalPlayerPrefabToSpawn() { if (!AutoSpawnPlayerPrefabClientSide) { - Debug.LogError($"[{nameof(FetchLocalPlayerPrefabToSpawn)}] Invoked when {nameof(NetworkConfig.AutoSpawnPlayerPrefabClientSide)} was not set! Check call paths!"); + Log.Error(new Context(LogLevel.Error, $"Invoked when {nameof(NetworkConfig.AutoSpawnPlayerPrefabClientSide)} was not set! Check call paths!")); return null; } if (OnFetchLocalPlayerPrefabToSpawn == null && NetworkConfig.PlayerPrefab == null) @@ -244,12 +241,13 @@ internal void PromoteSessionOwner(ulong clientId) { if (!DistributedAuthorityMode) { - NetworkLog.LogErrorServer($"[SceneManagement][NotDA] Invoking promote session owner while not in distributed authority mode!"); + // [Netcode] [PromoteSessionOwner][SceneManagement][NotDA] Invoking promote session owner while not in distributed authority mode! + Log.ErrorServer(new Context(LogLevel.Error, "Invoking promote session owner while not in distributed authority mode!").With("SceneManagement").With("NotDA")); return; } if (!DAHost) { - NetworkLog.LogErrorServer($"[SceneManagement][NotDAHost] Client is attempting to promote another client as the session owner!"); + Log.ErrorServer(new Context(LogLevel.Error, "Client is attempting to promote another client as the session owner!").With("SceneManagement").With("NotDAHost")); return; } SetSessionOwner(clientId); @@ -316,7 +314,8 @@ private void UpdateTopology() var transportTopology = IsListening && IsConnectedClient ? NetworkConfig.NetworkTransport.CurrentTopology() : NetworkConfig.NetworkTopology; if (transportTopology != NetworkConfig.NetworkTopology) { - NetworkLog.LogErrorServer($"[Topology Mismatch][{transportTopology}:{transportTopology.GetType().Name}][NetworkManager.NetworkConfig:{NetworkConfig.NetworkTopology}] Transport detected an issue with the topology usage or setting! Disconnecting from session."); + Log.ErrorServer(new Context(LogLevel.Error, "Transport detected an issue with the topology usage or setting! Disconnecting from session.") + .With("Topology Mismatch").With(transportTopology, transportTopology.GetType().Name).With("NetworkManager.NetworkConfig", NetworkConfig.NetworkTopology)); Shutdown(true); } else @@ -892,6 +891,12 @@ public struct ConnectionApprovalRequest /// public event Action OnClientStarted = null; + /// + /// The callback to invoke once started + /// Invoked on both the server and the client + /// + internal event Action OnStarted = null; + /// /// Subscribe to this event to get notifications before a instance is being destroyed. /// This is useful if you want to use the state of anything the NetworkManager cleans up during its shutdown. @@ -909,6 +914,12 @@ public struct ConnectionApprovalRequest /// The parameter states whether the client was running in host mode public event Action OnClientStopped = null; + /// + /// The callback to invoke once the session stops + /// Invoked on both the server and the client + /// + internal event Action OnStopped = null; + /// /// The instance created after starting the /// @@ -984,6 +995,7 @@ public NetworkPrefabHandler PrefabHandler /// internal IRealTimeProvider RealTimeProvider { get; private set; } + internal ContextualLogger Log; internal INetworkMetrics NetworkMetrics => MetricsManager.NetworkMetrics; internal NetworkMetricsManager MetricsManager = new NetworkMetricsManager(); internal NetworkConnectionManager ConnectionManager = new NetworkConnectionManager(); @@ -1040,6 +1052,11 @@ public void SetSingleton() private void Awake() { + if (Log == null) + { + Log = new ContextualLogger(this, gameObject); + } + NetworkConfig?.InitializePrefabs(); UnityEngine.SceneManagement.SceneManager.sceneUnloaded += OnSceneUnloaded; @@ -1178,19 +1195,12 @@ internal void Initialize(bool server) if (NetworkConfig.NetworkTransport == null) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Error) - { - NetworkLog.LogError("No transport has been selected!"); - } - + Log.Error(new Context(LogLevel.Error, "No transport has been selected!")); return; } // Logging initializes first for any logging during systems initialization - if (NetworkLog.CurrentLogLevel <= LogLevel.Developer) - { - NetworkLog.LogInfo(nameof(Initialize)); - } + Log.CaptureFunctionCall(); this.RegisterNetworkUpdate(NetworkUpdateStage.EarlyUpdate); #if COM_UNITY_MODULES_PHYSICS || COM_UNITY_MODULES_PHYSICS2D @@ -1275,11 +1285,7 @@ private bool CanStart(StartType type) { if (IsListening) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Normal) - { - NetworkLog.LogWarning("Cannot start " + type + " while an instance is already running"); - } - + Log.Warning(new Context(LogLevel.Normal, "Can't start while listening").With("Start", type)); return false; } @@ -1289,10 +1295,7 @@ private bool CanStart(StartType type) { if (ConnectionApprovalCallback == null) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Normal) - { - NetworkLog.LogWarning("No ConnectionApproval callback defined. Connection approval will timeout"); - } + Log.Warning(new Context(LogLevel.Normal, $"No {nameof(ConnectionApprovalCallback)} defined. Connection approval will timeout").With("Start", type)); } } @@ -1300,10 +1303,7 @@ private bool CanStart(StartType type) { if (!NetworkConfig.ConnectionApproval) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Normal) - { - NetworkLog.LogWarning("A ConnectionApproval callback is defined but ConnectionApproval is disabled. In order to use ConnectionApproval it has to be explicitly enabled "); - } + Log.Warning(new Context(LogLevel.Normal, $"{nameof(ConnectionApprovalCallback)} is defined but {nameof(NetworkConfig.ConnectionApproval)} is disabled. In order to use ConnectionApproval it has to be explicitly enabled").With("Start", type)); } } @@ -1313,13 +1313,10 @@ private bool CanStart(StartType type) /// /// Starts a server /// - /// (/) returns true if started in server mode successfully. + /// returns true if started in server mode successfully; otherwise false public bool StartServer() { - if (NetworkLog.CurrentLogLevel <= LogLevel.Developer) - { - NetworkLog.LogInfo(nameof(StartServer)); - } + Log.CaptureFunctionCall(); if (!CanStart(StartType.Server)) { @@ -1338,7 +1335,7 @@ public bool StartServer() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); // Always shutdown to assure everything is cleaned up ShutdownInternal(); return false; @@ -1355,6 +1352,7 @@ public bool StartServer() // Notify the server that everything should be synchronized/spawned at this time. SpawnManager.NotifyNetworkObjectsSynchronized(); OnServerStarted?.Invoke(); + OnStarted?.Invoke(); ConnectionManager.LocalClient.IsApproved = true; return true; } @@ -1363,7 +1361,7 @@ public bool StartServer() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); // Always shutdown to assure everything is cleaned up ShutdownInternal(); IsListening = false; @@ -1378,10 +1376,7 @@ public bool StartServer() /// (/) returns true if started in client mode successfully. public bool StartClient() { - if (NetworkLog.CurrentLogLevel <= LogLevel.Developer) - { - NetworkLog.LogInfo(nameof(StartClient)); - } + Log.CaptureFunctionCall(); if (!CanStart(StartType.Client)) { @@ -1399,7 +1394,7 @@ public bool StartClient() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); ShutdownInternal(); return false; } @@ -1415,11 +1410,12 @@ public bool StartClient() else { OnClientStarted?.Invoke(); + OnStarted?.Invoke(); } } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); ShutdownInternal(); IsListening = false; } @@ -1433,10 +1429,7 @@ public bool StartClient() /// (/) returns true if started in host mode successfully. public bool StartHost() { - if (NetworkLog.CurrentLogLevel <= LogLevel.Developer) - { - NetworkLog.LogInfo(nameof(StartHost)); - } + Log.CaptureFunctionCall(); if (!CanStart(StartType.Host)) { @@ -1454,7 +1447,7 @@ public bool StartHost() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); // Always shutdown to assure everything is cleaned up ShutdownInternal(); return false; @@ -1476,7 +1469,7 @@ public bool StartHost() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); // Always shutdown to assure everything is cleaned up ShutdownInternal(); IsListening = false; @@ -1501,10 +1494,7 @@ private void HostServerInitialize() ConnectionApprovalCallback(new ConnectionApprovalRequest { Payload = NetworkConfig.ConnectionData, ClientNetworkId = ServerClientId }, response); if (!response.Approved) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Normal) - { - NetworkLog.LogWarning("You cannot decline the host connection. The connection was automatically approved."); - } + Log.Warning(new Context(LogLevel.Normal, "You cannot decline the host connection. The connection was automatically approved.")); } ConnectionManager.HandleConnectionApproval(ServerClientId, response.CreatePlayerObject, response.PlayerPrefabHash, response.Position, response.Rotation); @@ -1523,6 +1513,7 @@ private void HostServerInitialize() OnServerStarted?.Invoke(); OnClientStarted?.Invoke(); + OnStarted?.Invoke(); // This assures that any in-scene placed NetworkObject is spawned and // any associated NetworkBehaviours' netcode related properties are @@ -1582,10 +1573,7 @@ public ulong GetClientIdFromTransportId(ulong transportId) /// public void Shutdown(bool discardMessageQueue = false) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Developer) - { - NetworkLog.LogInfo(nameof(Shutdown)); - } + Log.CaptureFunctionCall(); // If we're not running, don't start shutting down, it would only cause an immediate // shutdown the next time the manager is started. @@ -1613,10 +1601,7 @@ internal void ShutdownInternal() #if UNITY_EDITOR EndNetworkSession(); #endif - if (NetworkLog.CurrentLogLevel <= LogLevel.Developer) - { - NetworkLog.LogInfo(nameof(ShutdownInternal)); - } + Log.CaptureFunctionCall(); // Always wrap events that can invoke user script in a // try-catch to assure any proceeding script is still @@ -1632,7 +1617,7 @@ internal void ShutdownInternal() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); } this.UnregisterAllNetworkUpdates(); @@ -1718,6 +1703,8 @@ internal void ShutdownInternal() // or not. (why we pass in "IsClient") OnServerStopped?.Invoke(localClient.IsClient); } + + OnStopped?.Invoke(); } // Ensures that the NetworkManager is cleaned up before OnDestroy is run on NetworkObjects and NetworkBehaviours when quitting the application. @@ -1738,7 +1725,7 @@ private void OnApplicationQuit() #if UNITY_EDITOR if (Singleton != null) { - Debug.LogWarning($"[nameof({nameof(OnApplicationQuit)}][{nameof(NetworkManager)}][{name}] Singleton is not null after invoking OnDestroy. Singleton instance name is {Singleton.name}. Do you have more than one {nameof(NetworkManager)} instance in the DDOL scene?"); + Log.Warning(new Context(LogLevel.Error, $"Singleton is not null after invoking OnDestroy. Do you have more than one {nameof(NetworkManager)} instance in the DDOL scene?").With("SingletonInstance", Singleton.name)); } #endif } @@ -1752,7 +1739,7 @@ private void OnDestroy() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); } UnityEngine.SceneManagement.SceneManager.sceneUnloaded -= OnSceneUnloaded; @@ -1766,7 +1753,7 @@ private void OnDestroy() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); } if (Singleton == this) @@ -1835,15 +1822,17 @@ internal void OnValidate() return; // May occur when the component is added } + if (Log == null) + { + Log = new ContextualLogger(this, gameObject); + } + // Do a validation pass on NetworkConfig properties NetworkConfig.OnValidate(); if (GetComponentInChildren() != null) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Normal) - { - NetworkLog.LogWarning($"{nameof(NetworkManager)} cannot be a {nameof(NetworkObject)}."); - } + Log.Warning(new Context(LogLevel.Normal, $"{nameof(NetworkManager)} cannot be a {nameof(NetworkObject)}.")); } var activeScene = UnityEngine.SceneManagement.SceneManager.GetActiveScene(); @@ -1859,9 +1848,8 @@ internal void OnValidate() var prefabs = NetworkConfig.Prefabs.Prefabs; // Check network prefabs and assign to dictionary for quick look up - for (int i = 0; i < prefabs.Count; i++) + foreach (var networkPrefab in prefabs) { - var networkPrefab = prefabs[i]; var networkPrefabGo = networkPrefab?.Prefab; if (networkPrefabGo == null) { @@ -1871,11 +1859,7 @@ internal void OnValidate() var networkObject = networkPrefabGo.GetComponent(); if (networkObject == null) { - if (NetworkLog.CurrentLogLevel <= LogLevel.Normal) - { - NetworkLog.LogError($"Cannot register {NetworkPrefabHandler.PrefabDebugHelper(networkPrefab)}, it does not have a {nameof(NetworkObject)} component at its root"); - } - + Log.Warning(new Context(LogLevel.Normal, $"Cannot register prefab to {nameof(NetworkManager)}, missing a {nameof(NetworkObject)} component at its root").ForNetworkPrefab(networkPrefab)); continue; } @@ -1884,10 +1868,7 @@ internal void OnValidate() networkPrefabGo.GetComponentsInChildren(true, childNetworkObjects); if (childNetworkObjects.Count > 1) // total count = 1 root NetworkObject + n child NetworkObjects { - if (NetworkLog.CurrentLogLevel <= LogLevel.Normal) - { - NetworkLog.LogWarning($"{NetworkPrefabHandler.PrefabDebugHelper(networkPrefab)} has child {nameof(NetworkObject)}(s) but they will not be spawned across the network (unsupported {nameof(NetworkPrefab)} setup)"); - } + Log.Warning(new Context(LogLevel.Normal, $"Prefab has child {nameof(NetworkObject)}(s) but they will not be spawned across the network (unsupported {nameof(NetworkPrefab)} setup)").ForNetworkPrefab(networkPrefab)); } } } @@ -1898,7 +1879,7 @@ internal void OnValidate() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); } } @@ -1917,7 +1898,7 @@ internal void ModeChanged(PlayModeStateChange playModeState) } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); } } @@ -1933,7 +1914,7 @@ private void BeginNetworkSession() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); } } @@ -1948,7 +1929,7 @@ private void EndNetworkSession() } catch (Exception ex) { - Debug.LogException(ex); + Log.Exception(ex); } } #endif diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/ContextualLogger.cs b/com.unity.netcode.gameobjects/Runtime/Logging/ContextualLogger.cs new file mode 100644 index 0000000000..f5a671ce07 --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/ContextualLogger.cs @@ -0,0 +1,184 @@ +using System; +using System.Diagnostics; +using System.Diagnostics.CodeAnalysis; +using System.Runtime.CompilerServices; +using System.Text; +using UnityEngine; +using Debug = UnityEngine.Debug; +using LogType = UnityEngine.LogType; + +namespace Unity.Netcode +{ + internal class ContextualLogger + { + private const string k_NetcodeHeader = "[Netcode] "; + private bool m_UseCompatibilityMode; + private readonly GameObject m_GameObject; + private readonly ContextBuilder m_Builder = new(); + + private LogContextNetworkManager m_ManagerContext; + private readonly GenericContext m_LoggerContext; + + private const string k_CompilationCondition = "UNITY_ASSERTIONS"; + + public ContextualLogger(bool useCompatibilityMode = false) + { + m_UseCompatibilityMode = useCompatibilityMode; + m_ManagerContext = new LogContextNetworkManager(true); + m_GameObject = null; + m_LoggerContext = GenericContext.Create(); + } + + public ContextualLogger([NotNull] NetworkManager networkManager, GameObject gameObject) + { + m_ManagerContext = new LogContextNetworkManager(networkManager); + m_GameObject = gameObject; + m_LoggerContext = GenericContext.Create(); + } + + [Conditional(k_CompilationCondition)] + internal void UpdateNetworkManagerContext(NetworkManager manager) + { + m_ManagerContext.Dispose(); + m_ManagerContext = new LogContextNetworkManager(manager); + } + + [Conditional(k_CompilationCondition)] + internal void PushContext(string key, object value) + { + m_LoggerContext.StoreInfo(key, value); + } + + [Conditional(k_CompilationCondition)] + internal void PushContext(string key) + { + m_LoggerContext.StoreContext(key); + } + + [Conditional(k_CompilationCondition)] + internal void PopContext(string key) + { + m_LoggerContext.ClearInfo(key); + } + + + [HideInCallstack] + [Conditional(k_CompilationCondition)] + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public void CaptureFunctionCall([CallerMemberName] string memberName = "") + { + Log(LogType.Log, new Context(LogLevel.Developer, memberName, true)); + } + + [HideInCallstack] + [Conditional(k_CompilationCondition)] + public void Info(Context context) => Log(LogType.Log, context); + [HideInCallstack] + [Conditional(k_CompilationCondition)] + public void Warning(Context context) => Log(LogType.Warning, context); + [HideInCallstack] + [Conditional(k_CompilationCondition)] + public void Error(Context context) => Log(LogType.Error, context); + + [HideInCallstack] + [Conditional(k_CompilationCondition)] + public void InfoServer(Context context) => LogServer(LogType.Log, context); + [HideInCallstack] + [Conditional(k_CompilationCondition)] + public void WarningServer(Context context) => LogServer(LogType.Warning, context); + [HideInCallstack] + [Conditional(k_CompilationCondition)] + public void ErrorServer(Context context) => LogServer(LogType.Error, context); + + [HideInCallstack] + public void Exception(Exception exception) + { + Debug.unityLogger.LogException(exception, m_GameObject); + } + + [HideInCallstack] + private void Log(LogType logType, Context context) + { + // Don't act if the LogLevel is higher than the level of this log + if (m_ManagerContext.LogLevel > context.Level) + { + return; + } + + var message = BuildLog(context); + Debug.unityLogger.Log(logType, (object)message, context.GameObjectOverride ?? m_GameObject); + } + + [HideInCallstack] + private void LogServer(LogType logType, Context context) + { + // Don't act if the configured logging level is higher than the level of this log + if (m_ManagerContext.LogLevel <= context.Level) + { + return; + } + + var message = BuildLog(context); + Debug.unityLogger.Log(logType, (object)message, context.GameObjectOverride ?? m_GameObject); + + m_ManagerContext.TrySendMessage(logType, message); + } + + private string BuildLog(Context context) + { + m_Builder.Reset(); + + // Add the Netcode prefix + m_Builder.Append(k_NetcodeHeader); + + if (m_UseCompatibilityMode) + { + m_Builder.Append(context.Message); + } + else + { + // Add the system context + m_ManagerContext.AppendTo(m_Builder); + m_LoggerContext.AppendTo(m_Builder); + + // Add the context for this log + context.AppendTo(m_Builder); + } + + return m_Builder.Build(); + } + } + + internal class ContextBuilder + { + private readonly StringBuilder m_Builder = new(); + private const string k_OpenBracket = "["; + private const string k_CloseBracket = "]"; + private const string k_Separator = ":"; + + public void Reset() + { + m_Builder.Clear(); + } + + public void AppendContext(string context) + { + m_Builder.Append(k_OpenBracket); + m_Builder.Append(context); + m_Builder.Append(k_CloseBracket); + } + + public void AppendContext(object key, object value) + { + m_Builder.Append(k_OpenBracket); + m_Builder.Append(key); + m_Builder.Append(k_Separator); + m_Builder.Append(value); + m_Builder.Append(k_CloseBracket); + } + + public void Append(string value) => m_Builder.Append(value); + + public string Build() => m_Builder.ToString(); + } +} diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/ContextualLogger.cs.meta b/com.unity.netcode.gameobjects/Runtime/Logging/ContextualLogger.cs.meta new file mode 100644 index 0000000000..4cdd3bc881 --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/ContextualLogger.cs.meta @@ -0,0 +1,3 @@ +fileFormatVersion: 2 +guid: bbaa8fb0dd284e21b05ec68dd4e5e911 +timeCreated: 1776366667 \ No newline at end of file diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/GenericContext.cs b/com.unity.netcode.gameobjects/Runtime/Logging/GenericContext.cs new file mode 100644 index 0000000000..042d78e90c --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/GenericContext.cs @@ -0,0 +1,86 @@ +using System; +using System.Collections.Generic; + +namespace Unity.Netcode +{ + internal readonly struct GenericContext : ILogContext, IDisposable + { + private readonly List m_Contexts; + private readonly Dictionary m_Info; + + private GenericContext(List contexts, Dictionary info) + { + m_Contexts = contexts; + m_Info = info; + } + + public readonly void AppendTo(ContextBuilder builder) + { + if (m_Contexts != null) + { + foreach (var ctx in m_Contexts) + { + builder.AppendContext(ctx); + } + } + + if (m_Info != null) + { + foreach (var (key, value) in m_Info) + { + builder.AppendContext(key, value); + } + } + } + + public void StoreContext(string msg) + { + m_Contexts.Add(msg); + } + + public void StoreInfo(object key, object value) + { + m_Info.Add(key, value); + } + + public void ClearInfo(object key) + { + m_Info?.Remove(key); + } + + public void Dispose() + { + PreallocatedStore.Free(this); + } + + public static GenericContext Create() + { + return PreallocatedStore.GetPreallocated(); + } + + private static class PreallocatedStore + { + private static readonly Queue k_Preallocated = new(); + + internal static GenericContext GetPreallocated() + { + if (k_Preallocated.Count > 0) + { + k_Preallocated.Dequeue(); + } + + var contexts = new List(); + var info = new Dictionary(); + return new GenericContext(contexts, info); + } + + internal static void Free(GenericContext ctx) + { + ctx.m_Contexts.Clear(); + ctx.m_Info.Clear(); + k_Preallocated.Enqueue(ctx); + } + } + } + +} diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/GenericContext.cs.meta b/com.unity.netcode.gameobjects/Runtime/Logging/GenericContext.cs.meta new file mode 100644 index 0000000000..ee66b3749f --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/GenericContext.cs.meta @@ -0,0 +1,3 @@ +fileFormatVersion: 2 +guid: 3ed903e3a2894bf1980e589f98e16be9 +timeCreated: 1776401645 \ No newline at end of file diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/LogContext.cs b/com.unity.netcode.gameobjects/Runtime/Logging/LogContext.cs new file mode 100644 index 0000000000..d3a327030c --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/LogContext.cs @@ -0,0 +1,78 @@ +using System.Runtime.CompilerServices; +using UnityEngine; + +namespace Unity.Netcode +{ + internal interface ILogContext + { + public void AppendTo(ContextBuilder builder) + { + } + } + + internal struct Context : ILogContext + { + public readonly LogLevel Level; + private readonly string m_CallingFunction; + internal readonly string Message; + public GameObject GameObjectOverride; + + + private readonly GenericContext m_Other; + + public Context(LogLevel level, string msg, [CallerMemberName] string memberName = "") + { + Level = level; + Message = msg; + m_CallingFunction = memberName; + + m_Other = GenericContext.Create(); + GameObjectOverride = null; + } + + internal Context(LogLevel level, string msg, bool noCaller) + { + Level = level; + Message = msg; + m_CallingFunction = null; + + m_Other = GenericContext.Create(); + GameObjectOverride = null; + } + + public void AppendTo(ContextBuilder builder) + { + // [CallingFunction] + if (!string.IsNullOrEmpty(m_CallingFunction)) + { + builder.AppendContext(m_CallingFunction); + } + + // [SomeContext][SomeName:SomeValue] + m_Other.AppendTo(builder); + + // Human-readable log message + builder.Append(" "); + builder.Append(Message); + } + + public Context With(object key, object value) + { + m_Other.StoreInfo(key, value); + return this; + } + + public Context With(string msg) + { + m_Other.StoreContext(msg); + return this; + } + + public Context ForNetworkPrefab(NetworkPrefab networkPrefab) + { + GameObjectOverride = networkPrefab.Prefab.gameObject; + m_Other.StoreInfo(nameof(NetworkPrefab), networkPrefab.Prefab.name); + return this; + } + } +} diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/LogContext.cs.meta b/com.unity.netcode.gameobjects/Runtime/Logging/LogContext.cs.meta new file mode 100644 index 0000000000..a2a4e87ebd --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/LogContext.cs.meta @@ -0,0 +1,3 @@ +fileFormatVersion: 2 +guid: a0c75597200c497996b677d385e3a8d4 +timeCreated: 1776401476 \ No newline at end of file diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/LogContextNetworkManager.cs b/com.unity.netcode.gameobjects/Runtime/Logging/LogContextNetworkManager.cs new file mode 100644 index 0000000000..57e274417f --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/LogContextNetworkManager.cs @@ -0,0 +1,110 @@ +using System; +using System.Diagnostics.CodeAnalysis; +using UnityEngine; + +namespace Unity.Netcode +{ + internal struct LogContextNetworkManager : ILogContext, IDisposable + { + private NetworkManager m_NetworkManager; + private const string k_ServerString = "[Server]"; + private const string k_SessionOwnerString = "[Session Owner]"; + // This will get appended with the current clientID, doesn't need brackets + private const string k_ClientString = "Client"; + + public LogContextNetworkManager(bool useSingleton) + { + m_NetworkManager = null; + if (!useSingleton) + { + return; + } + + WatchForSingleton(); + } + + public LogContextNetworkManager([NotNull] NetworkManager networkManager) + { + m_NetworkManager = networkManager; + } + + public readonly LogLevel LogLevel => m_NetworkManager?.LogLevel ?? LogLevel.Normal; + + public readonly void TrySendMessage(LogType logType, string message) + { + if (m_NetworkManager != null + && m_NetworkManager.IsListening + && (m_NetworkManager?.NetworkConfig.EnableNetworkLogs ?? false) + && (m_NetworkManager.IsServer || m_NetworkManager.LocalClient.IsSessionOwner)) + { + var messageType = NetworkLog.GetMessageLogType(logType); + NetworkLog.SendLogToAuthority(m_NetworkManager, messageType, m_NetworkManager.LocalClientId, message); + } + } + + private void WatchForSingleton() + { + if (NetworkManager.Singleton != null) + { + m_NetworkManager = NetworkManager.Singleton; + NetworkManager.OnDestroying += OnManagerDestroying; + } + else + { + NetworkManager.OnSingletonReady += OnSingletonReady; + } + } + + private void OnSingletonReady() + { + m_NetworkManager = NetworkManager.Singleton; + NetworkManager.OnSingletonReady -= OnSingletonReady; + } + + private void OnManagerDestroying(NetworkManager manager) + { + if (m_NetworkManager != manager) + { + return; + } + m_NetworkManager = null; + WatchForSingleton(); + } + + public readonly void AppendTo(ContextBuilder builder) + { + if (m_NetworkManager == null) + { + return; + } + + if (!m_NetworkManager.IsListening || !NetworkLog.Config.LogNetworkManagerRole) + { + return; + } + + if (m_NetworkManager.LocalClient.IsSessionOwner) + { + // [Session Owner] + builder.Append(k_SessionOwnerString); + } else if (m_NetworkManager.IsServer) + { + // [Server] + builder.Append(k_ServerString); + } + if (!m_NetworkManager.IsServer) + { + // [Client:1] + builder.AppendContext(k_ClientString, m_NetworkManager.LocalClientId); + } + } + + public void Dispose() + { + NetworkManager.OnDestroying -= OnManagerDestroying; + NetworkManager.OnSingletonReady -= OnSingletonReady; + m_NetworkManager = null; + } + } + +} diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/LogContextNetworkManager.cs.meta b/com.unity.netcode.gameobjects/Runtime/Logging/LogContextNetworkManager.cs.meta new file mode 100644 index 0000000000..f23412129f --- /dev/null +++ b/com.unity.netcode.gameobjects/Runtime/Logging/LogContextNetworkManager.cs.meta @@ -0,0 +1,3 @@ +fileFormatVersion: 2 +guid: ad18865d062a4e80bcf3636e613a631b +timeCreated: 1776379064 \ No newline at end of file diff --git a/com.unity.netcode.gameobjects/Runtime/Logging/NetworkLog.cs b/com.unity.netcode.gameobjects/Runtime/Logging/NetworkLog.cs index 59557cc81a..791045c1fc 100644 --- a/com.unity.netcode.gameobjects/Runtime/Logging/NetworkLog.cs +++ b/com.unity.netcode.gameobjects/Runtime/Logging/NetworkLog.cs @@ -1,139 +1,128 @@ +using System.Diagnostics.CodeAnalysis; +using System.Runtime.CompilerServices; +using System.Text.RegularExpressions; using UnityEngine; namespace Unity.Netcode { + internal struct LogConfiguration + { + internal bool LogNetworkManagerRole; + } + /// /// Helper class for logging /// public static class NetworkLog { + private static readonly ContextualLogger k_Log = new(true); + + internal static void SetNetworkManager(NetworkManager networkManager) + { + k_Log.UpdateNetworkManagerContext(networkManager); + } /// /// Gets the current log level. /// /// The current log level. + // [Obsolete("Use the LogLevel directly on the NetworkManager instead")] public static LogLevel CurrentLogLevel => NetworkManager.Singleton == null ? LogLevel.Normal : NetworkManager.Singleton.LogLevel; + internal static LogConfiguration Config = new LogConfiguration(); + // internal logging /// /// Locally logs a info log with Netcode prefixing. /// /// The message to log - public static void LogInfo(string message) => Debug.Log($"[Netcode] {message}"); + [HideInCallstack] + public static void LogInfo(string message, [CallerMemberName] string memberName = "") => k_Log.Info(new Context(LogLevel.Normal, message, memberName)); + [HideInCallstack] + internal static void LogInfo(Context context) => k_Log.Info(context); /// /// Locally logs a warning log with Netcode prefixing. /// /// The message to log - public static void LogWarning(string message) => Debug.LogWarning($"[Netcode] {message}"); + [HideInCallstack] + public static void LogWarning(string message, [CallerMemberName] string memberName = "") => k_Log.Warning(new Context(LogLevel.Error, message, memberName)); + [HideInCallstack] + internal static void LogWarning(Context context) => k_Log.Warning(context); /// /// Locally logs a error log with Netcode prefixing. /// /// The message to log - public static void LogError(string message) => Debug.LogError($"[Netcode] {message}"); + [HideInCallstack] + public static void LogError(string message, [CallerMemberName] string memberName = "") => k_Log.Error(new Context(LogLevel.Error, message, memberName)); + [HideInCallstack] + internal static void LogError(Context context) => k_Log.Error(context); + + // internal static void Log(LogLevel level, object message, Object gameObject) => Logger.Log($"[Netcode] {message} ({(int)level})"); /// /// Logs an info log locally and on the server if possible. /// /// The message to log - public static void LogInfoServer(string message) => LogServer(message, LogType.Info); + [HideInCallstack] + public static void LogInfoServer(string message, [CallerMemberName] string memberName = "") => k_Log.InfoServer(new Context(LogLevel.Normal, message, memberName)); /// /// Logs an info log locally and on the session owner if possible. /// /// The message to log - public static void LogInfoSessionOwner(string message) => LogServer(message, LogType.Info); + [HideInCallstack] + public static void LogInfoSessionOwner(string message, [CallerMemberName] string memberName = "") => k_Log.InfoServer(new Context(LogLevel.Normal, message, memberName)); /// /// Logs a warning log locally and on the server if possible. /// /// The message to log - public static void LogWarningServer(string message) => LogServer(message, LogType.Warning); + [HideInCallstack] + public static void LogWarningServer(string message, [CallerMemberName] string memberName = "") => k_Log.WarningServer(new Context(LogLevel.Error, message, memberName)); /// /// Logs an error log locally and on the server if possible. /// /// The message to log - public static void LogErrorServer(string message) => LogServer(message, LogType.Error); - - internal static NetworkManager NetworkManagerOverride; + [HideInCallstack] + public static void LogErrorServer(string message, [CallerMemberName] string memberName = "") => k_Log.ErrorServer(new Context(LogLevel.Error, message, memberName)); - private static void LogServer(string message, LogType logType) + internal static LogType GetMessageLogType(UnityEngine.LogType engineLogType) { - var networkManager = NetworkManagerOverride ??= NetworkManager.Singleton; - // Get the sender of the local log - ulong localId = networkManager?.LocalClientId ?? 0; - bool isServer = networkManager && networkManager.DistributedAuthorityMode ? networkManager.LocalClient.IsSessionOwner : - networkManager && !networkManager.DistributedAuthorityMode ? networkManager.IsServer : true; - switch (logType) + return engineLogType switch { - case LogType.Info: - if (isServer) - { - LogInfoServerLocal(message, localId); - } - else - { - LogInfo(message); - } - break; - case LogType.Warning: - if (isServer) - { - LogWarningServerLocal(message, localId); - } - else - { - LogWarning(message); - } - break; - case LogType.Error: - if (isServer) - { - LogErrorServerLocal(message, localId); - } - else - { - LogError(message); - } - break; - } + UnityEngine.LogType.Error => LogType.Error, + UnityEngine.LogType.Warning => LogType.Warning, + UnityEngine.LogType.Log => LogType.Info, + _ => LogType.None + }; + } - if (!isServer && networkManager.NetworkConfig.EnableNetworkLogs) + internal static void SendLogToAuthority(NetworkManager networkManager, LogType logType, ulong senderId, string message) + { + var networkMessage = new ServerLogMessage { - var networkMessage = new ServerLogMessage - { - LogType = logType, - Message = message, - SenderId = localId - }; - var size = networkManager.ConnectionManager.SendMessage(ref networkMessage, MessageDeliveryType.DefaultDelivery, NetworkManager.ServerClientId); - networkManager.NetworkMetrics.TrackServerLogSent(NetworkManager.ServerClientId, (uint)logType, size); - } + LogType = logType, + Message = message, + SenderId = senderId + }; + var size = networkManager.ConnectionManager.SendMessage(ref networkMessage, MessageDeliveryType.DefaultDelivery, NetworkManager.ServerClientId); + networkManager.NetworkMetrics.TrackServerLogSent(NetworkManager.ServerClientId, (uint)logType, size); } - private const string k_HeaderStart = "Netcode"; - private static string Header() + private const string k_SenderId = "SenderId"; + internal static Context ContextWithSenderId([NotNull] NetworkManager networkManager, LogLevel level, ulong senderId, string message) { - var networkManager = NetworkManagerOverride ??= NetworkManager.Singleton; - if (networkManager != null) + var ctx = new Context(level, message, true).With(k_SenderId, senderId); + if (TryGetNetworkObjectName(networkManager, message, out var name)) { - if (networkManager.DistributedAuthorityMode) - { - return $"{k_HeaderStart}-Session-Owner"; - } - return $"{k_HeaderStart}-Server"; + ctx.With(name); } - - // If NetworkManager no longer exists, then return the generic header - return k_HeaderStart; + return ctx; } - internal static void LogInfoServerLocal(string message, ulong sender) => Debug.Log($"[{Header()} Sender={sender}] {message}"); - internal static void LogWarningServerLocal(string message, ulong sender) => Debug.LogWarning($"[{Header()} Sender={sender}] {message}"); - internal static void LogErrorServerLocal(string message, ulong sender) => Debug.LogError($"[{Header()} Sender={sender}] {message}"); - internal enum LogType : byte { Info, @@ -141,5 +130,31 @@ internal enum LogType : byte Error, None } + + private static readonly Regex k_GlobalObjectIdHash = new($@"\[{nameof(NetworkObject.GlobalObjectIdHash)}=(\d+)\]", RegexOptions.Compiled); + [MethodImpl(MethodImplOptions.AggressiveInlining)] + private static bool TryGetNetworkObjectName([NotNull] NetworkManager networkManager, string message, out string name) + { + name = null; + if (!k_GlobalObjectIdHash.IsMatch(message)) + { + return false; + } + + var stringHash = k_GlobalObjectIdHash.Match(message).Groups[1].Value; + if (!ulong.TryParse(stringHash, out var globalObjectIdHash)) + { + return false; + } + + if (!networkManager.SpawnManager.SpawnedObjects.TryGetValue(globalObjectIdHash, out var networkObject)) + { + return false; + } + + name = networkObject.name; + return true; + } + } } diff --git a/com.unity.netcode.gameobjects/Runtime/Messaging/Messages/ServerLogMessage.cs b/com.unity.netcode.gameobjects/Runtime/Messaging/Messages/ServerLogMessage.cs index 23f32a608f..cc6be184ea 100644 --- a/com.unity.netcode.gameobjects/Runtime/Messaging/Messages/ServerLogMessage.cs +++ b/com.unity.netcode.gameobjects/Runtime/Messaging/Messages/ServerLogMessage.cs @@ -46,20 +46,24 @@ public bool Deserialize(FastBufferReader reader, ref NetworkContext context, int public void Handle(ref NetworkContext context) { var networkManager = (NetworkManager)context.SystemOwner; - var senderId = networkManager.DistributedAuthorityMode ? SenderId : context.SenderId; + var senderId = context.SenderId; + if (networkManager.NetworkConfig.UseCMBService && context.SenderId == NetworkManager.ServerClientId) + { + senderId = SenderId; + } networkManager.NetworkMetrics.TrackServerLogReceived(senderId, (uint)LogType, context.MessageSize); switch (LogType) { case NetworkLog.LogType.Info: - NetworkLog.LogInfoServerLocal(Message, senderId); + networkManager.Log.Info(NetworkLog.ContextWithSenderId(networkManager, LogLevel.Normal, senderId, Message)); break; case NetworkLog.LogType.Warning: - NetworkLog.LogWarningServerLocal(Message, senderId); + networkManager.Log.Warning(NetworkLog.ContextWithSenderId(networkManager, LogLevel.Error, senderId, Message)); break; case NetworkLog.LogType.Error: - NetworkLog.LogErrorServerLocal(Message, senderId); + networkManager.Log.Error(NetworkLog.ContextWithSenderId(networkManager, LogLevel.Error, senderId, Message)); break; } } diff --git a/com.unity.netcode.gameobjects/Tests/Editor/NetworkManagerConfigurationTests.cs b/com.unity.netcode.gameobjects/Tests/Editor/NetworkManagerConfigurationTests.cs index d3dd92de2d..d453e1a917 100644 --- a/com.unity.netcode.gameobjects/Tests/Editor/NetworkManagerConfigurationTests.cs +++ b/com.unity.netcode.gameobjects/Tests/Editor/NetworkManagerConfigurationTests.cs @@ -1,6 +1,8 @@ using System.Collections.Generic; +using System.Text.RegularExpressions; using NUnit.Framework; using Unity.Netcode.Editor; +using Unity.Netcode.RuntimeTests; using Unity.Netcode.Transports.UTP; using UnityEditor.SceneManagement; using UnityEngine; @@ -42,7 +44,7 @@ public void NestedNetworkManagerCheck() var messageToCheck = NetworkManager.GenerateNestedNetworkManagerMessage(networkManagerObject.transform); // Trap for the nested NetworkManager exception - LogAssert.Expect(LogType.Error, messageToCheck); + LogAssert.Expect(LogType.Error, new Regex(messageToCheck)); // Since this is an in-editor test, we must force this invocation NetworkManagerHelper.Singleton.NotifyUserOfNestedNetworkManager(networkManager, false, true); @@ -73,7 +75,7 @@ public void NetworkObjectNotAllowed([Values] NetworkObjectPlacement networkObjec var networkManager = gameObject.AddComponent(); // Trap for the error message generated when a NetworkObject is discovered on the same GameObject or any children under it - LogAssert.Expect(LogType.Error, NetworkManagerHelper.Singleton.NetworkManagerAndNetworkObjectNotAllowedMessage()); + LogAssert.Expect(LogType.Error, new Regex(NetworkManagerHelper.Singleton.NetworkManagerAndNetworkObjectNotAllowedMessage())); // Add the NetworkObject var networkObject = targetforNetworkObject.AddComponent(); @@ -119,7 +121,7 @@ public void NestedNetworkObjectPrefabCheck() networkManager.OnValidate(); // Expect a warning - LogAssert.Expect(LogType.Warning, $"[Netcode] {NetworkPrefabHandler.PrefabDebugHelper(networkManager.NetworkConfig.Prefabs.Prefabs[0])} has child {nameof(NetworkObject)}(s) but they will not be spawned across the network (unsupported {nameof(NetworkPrefab)} setup)"); + LogAssert.Expect(LogType.Warning, new Regex($"{parent.name}\\] Prefab has child {nameof(NetworkObject)}\\(s\\) but they will not be spawned across the network \\(unsupported {nameof(NetworkPrefab)} setup\\)")); // Clean up Object.DestroyImmediate(networkManagerObject); diff --git a/com.unity.netcode.gameobjects/Tests/Runtime/NetworkObject/NetworkObjectDestroyTests.cs b/com.unity.netcode.gameobjects/Tests/Runtime/NetworkObject/NetworkObjectDestroyTests.cs index 9f2baa4113..18c5b4554f 100644 --- a/com.unity.netcode.gameobjects/Tests/Runtime/NetworkObject/NetworkObjectDestroyTests.cs +++ b/com.unity.netcode.gameobjects/Tests/Runtime/NetworkObject/NetworkObjectDestroyTests.cs @@ -152,7 +152,7 @@ public IEnumerator TestNetworkObjectClientDestroy([Values] ClientDestroyObject c // The non-authority client is =NOT= allowed to destroy any spawned object it does not // have authority over during runtime. LogAssert.ignoreFailingMessages = true; - NetworkLog.NetworkManagerOverride = nonAuthorityClient; + NetworkLog.SetNetworkManager(nonAuthorityClient); Object.Destroy(clientPlayerClone.gameObject); } @@ -201,12 +201,6 @@ private bool HaveLogsBeenReceived() return true; } - protected override IEnumerator OnTearDown() - { - NetworkLog.NetworkManagerOverride = null; - return base.OnTearDown(); - } - protected override void OnOneTimeTearDown() { // Re-apply the default as the last exiting action diff --git a/com.unity.netcode.gameobjects/Tests/Runtime/TestHelpers/NetcodeIntegrationTest.cs b/com.unity.netcode.gameobjects/Tests/Runtime/TestHelpers/NetcodeIntegrationTest.cs index f747bbbd5d..7da34dc860 100644 --- a/com.unity.netcode.gameobjects/Tests/Runtime/TestHelpers/NetcodeIntegrationTest.cs +++ b/com.unity.netcode.gameobjects/Tests/Runtime/TestHelpers/NetcodeIntegrationTest.cs @@ -594,6 +594,7 @@ private void InternalOnOneTimeSetup() IntegrationTestSceneHandler.VerboseDebugMode = m_EnableVerboseDebug; NetworkManagerHelper.VerboseDebugMode = m_EnableVerboseDebug; VerboseDebug($"Entering {nameof(OneTimeSetup)}"); + // NetworkLog.Config.LogNetworkManagerRole = true; m_NetworkManagerInstatiationMode = OnSetIntegrationTestMode(); @@ -808,7 +809,7 @@ protected void CreateServerAndClients(int numberOfClients) m_NumberOfClients = numberOfClients; m_ClientNetworkManagers = clients; m_ServerNetworkManager = server; - NetworkLog.NetworkManagerOverride = server; + NetworkLog.SetNetworkManager(server); var managers = clients.ToList(); if (!m_UseCmbService)