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

RPC send/receive logging as an additional verbose logging level for developer debugging

Open zachstronaut opened this issue 2 years ago • 1 comments

It's excellent that RPCs appear in the Profiler. However, sometimes it's still nice to have logging of your RPCs that are being sent or received. You could include this in LogLevel.Developer or have a new LogLevel.Verbose

In RpcMessage.cs I would modify Deserialize:

        public static unsafe bool Deserialize(ref FastBufferReader reader, ref NetworkContext context, ref RpcMetadata metadata, ref FastBufferReader payload)
        {
            ByteUnpacker.ReadValueBitPacked(reader, out metadata.NetworkObjectId);
            ByteUnpacker.ReadValueBitPacked(reader, out metadata.NetworkBehaviourId);
            ByteUnpacker.ReadValueBitPacked(reader, out metadata.NetworkRpcMethodId);

            var networkManager = (NetworkManager)context.SystemOwner;
            if (!networkManager.SpawnManager.SpawnedObjects.ContainsKey(metadata.NetworkObjectId))
            {
                networkManager.DeferredMessageManager.DeferMessage(IDeferredNetworkMessageManager.TriggerType.OnSpawn, metadata.NetworkObjectId, reader, ref context);
                return false;
            }

            var networkObject = networkManager.SpawnManager.SpawnedObjects[metadata.NetworkObjectId];
            var networkBehaviour = networkManager.SpawnManager.SpawnedObjects[metadata.NetworkObjectId].GetNetworkBehaviourAtOrderIndex(metadata.NetworkBehaviourId);
            if (networkBehaviour == null)
            {
                return false;
            }

            if (!NetworkManager.__rpc_func_table.ContainsKey(metadata.NetworkRpcMethodId))
            {
                return false;
            }

            payload = new FastBufferReader(reader.GetUnsafePtrAtCurrentPosition(), Allocator.None, reader.Length - reader.Position);

#if DEVELOPMENT_BUILD || UNITY_EDITOR
            if (NetworkManager.__rpc_name_table.TryGetValue(metadata.NetworkRpcMethodId, out var rpcMethodName))
            {
                if (NetworkLog.CurrentLogLevel == LogLevel.Developer) NetworkLog.LogInfo("RPC Received: " + rpcMethodName);
                networkManager.NetworkMetrics.TrackRpcReceived(
                    context.SenderId,
                    networkObject,
                    rpcMethodName,
                    networkBehaviour.__getTypeName(),
                    reader.Length);
            }
#endif

            return true;
        }

And in NetworkBehaviour.cs I would modify __beginSendServerRpc and __beginSendClientRpc:

#pragma warning disable IDE1006 // disable naming rule violation check
        // RuntimeAccessModifiersILPP will make this `protected`
        internal FastBufferWriter __beginSendServerRpc(uint rpcMethodId, ServerRpcParams serverRpcParams, RpcDelivery rpcDelivery)
#pragma warning restore IDE1006 // restore naming rule violation check
        {
#if DEVELOPMENT_BUILD || UNITY_EDITOR
            if (NetworkManager.__rpc_name_table.TryGetValue(rpcMethodId, out var rpcMethodName))
            {
                if (NetworkLog.CurrentLogLevel == LogLevel.Developer) NetworkLog.LogInfo("RPC Sent " + rpcMethodName);
            }
#endif
            return new FastBufferWriter(k_RpcMessageDefaultSize, Allocator.Temp, k_RpcMessageMaximumSize);
        }

#pragma warning disable IDE1006 // disable naming rule violation check
        // RuntimeAccessModifiersILPP will make this `protected`
        internal FastBufferWriter __beginSendClientRpc(uint rpcMethodId, ClientRpcParams clientRpcParams, RpcDelivery rpcDelivery)
#pragma warning restore IDE1006 // restore naming rule violation check
        {
#if DEVELOPMENT_BUILD || UNITY_EDITOR
            if (NetworkManager.__rpc_name_table.TryGetValue(rpcMethodId, out var rpcMethodName))
            {
                if (NetworkLog.CurrentLogLevel == LogLevel.Developer) NetworkLog.LogInfo("RPC Sent " + rpcMethodName);
            }
#endif
            return new FastBufferWriter(k_RpcMessageDefaultSize, Allocator.Temp, k_RpcMessageMaximumSize);
        }

zachstronaut avatar Sep 13 '23 17:09 zachstronaut

I'm actually not sure why I didn't propose adding this logging to NetworkMetrics.cs track methods which is a lot cleaner?

Although, it seems like TrackRpcReceived isn't called 100% accurately after the big RPC overhaul y'all did.

zachstronaut avatar Nov 29 '23 15:11 zachstronaut