using Barotrauma.Extensions; using Microsoft.Xna.Framework; using System; using System.Collections.Concurrent; using System.Collections.Generic; using System.Linq; using System.Threading; using System.Threading.Tasks; using static Barotrauma.EosInterface.Ownership; // DO NOT TOUCH ANYTHING HERE // OR EVERYTHING WILL FAIL namespace Barotrauma.Networking { class ServerEntityEvent : NetEntityEvent { private IServerSerializable serializable; #if DEBUG public string StackTrace; #endif private double createTime; public double CreateTime { get { return createTime; } } public void ResetCreateTime() { createTime = Timing.TotalTime; } public ServerEntityEvent(IServerSerializable serializableEntity, UInt16 id) : base(serializableEntity, id) { serializable = serializableEntity; createTime = Timing.TotalTime; #if DEBUG StackTrace = Environment.StackTrace.CleanupStackTrace(); #endif } public void Write(IWriteMessage msg, Client recipient) { serializable.ServerEventWrite(msg, recipient, Data); } } class ServerEntityEventManager : NetEntityEventManager { static public ServerEntityEventManager SEM; private readonly List events; //list of unique events (i.e. !IsDuplicate) created during the round //used for syncing clients who join mid-round private readonly List uniqueEvents; private UInt16 lastSentToAll; private UInt16 lastSentToAnyone; private double lastSentToAnyoneTime; private double lastWarningTime; public List Events { get { return events; } } public List UniqueEvents { get { return uniqueEvents; } } private class BufferedEvent { public readonly Client Sender; public readonly UInt16 CharacterStateID; public readonly ReadWriteMessage Data; public readonly Character Character; public readonly IClientSerializable TargetEntity; public bool IsProcessed; /// /// Does the client need to be controlling a character for the server to consider the event valid? /// public bool RequireCharacter = true; public BufferedEvent(Client sender, Character senderCharacter, UInt16 characterStateID, IClientSerializable targetEntity, ReadWriteMessage data) { this.Sender = sender; this.Character = senderCharacter; this.CharacterStateID = characterStateID; this.TargetEntity = targetEntity; this.Data = data; } } private readonly List bufferedEvents; private UInt16 ID; private readonly GameServer server; private double lastEventCountHighWarning; private class PendingCreateEvent { public IServerSerializable Entity; public NetEntityEvent.IData Data; public PendingCreateEvent(IServerSerializable entity, NetEntityEvent.IData data) { Entity = entity; Data = data; } } private readonly ConcurrentQueue pendingCreateQueue; private readonly Task createEventTask; private readonly CancellationTokenSource cancellationTokenSource = new CancellationTokenSource(); private readonly SemaphoreSlim eventSignal = new SemaphoreSlim(0); public ServerEntityEventManager(GameServer server) { events = new List(); this.server = server; bufferedEvents = new List(); uniqueEvents = new List(); pendingCreateQueue = new ConcurrentQueue(); lastWarningTime = -10.0; SEM = this; createEventTask = Task.Run(() => CreateEventProcessorLoop(cancellationTokenSource.Token)); } private async Task CreateEventProcessorLoop(CancellationToken token) { while (!token.IsCancellationRequested) { try { await eventSignal.WaitAsync(100, token); ProcessPendingCreateEvents(); } catch (OperationCanceledException) { break; } } } private void ProcessPendingCreateEvents() { // Dequeue and process all pending events currently in the queue. // Use a lock to synchronize modifications to shared lists / ID. while (pendingCreateQueue.TryDequeue(out PendingCreateEvent pending)) { // The original CreateEvent logic (mostly unchanged) but executed under a lock if (pending == null || pending.Entity == null) { continue; } var entity = pending.Entity; var extraData = pending.Data; var newEvent = new ServerEntityEvent(entity, (UInt16)(ID + 1)); if (extraData != null) newEvent.SetData(extraData); bool inGameClientsPresent = server.ConnectedClients.Count(c => c.InGame) > 0; //remove old events that have been sent to all clients, they are redundant now // keep at least one event in the list (lastSentToAll == e.ID) so we can use it to keep track of the latest ID // and events less than 15 seconds old to give disconnected clients a bit of time to reconnect without getting desynced if (GameMain.GameSession.RoundDuration > server.ServerSettings.RoundStartSyncDuration) { events.RemoveAll(e => (NetIdUtils.IdMoreRecent(lastSentToAll, e.ID) || !inGameClientsPresent) && e.CreateTime < Timing.TotalTime - server.ServerSettings.EventRemovalTime); } bool duplicateFound = false; for (int i = events.Count - 1; i >= 0; i--) { //we already have an identical event that's waiting to be sent // -> no need to add a new one if (events[i].IsDuplicate(newEvent) && !events[i].Sent) { duplicateFound = true; break; } } if (duplicateFound) { continue; } ID++; events.Add(newEvent); if (!uniqueEvents.Any(e => e.IsDuplicate(newEvent))) { //create a copy of the event and give it a new ID var uniqueEvent = new ServerEntityEvent(entity, (UInt16)(uniqueEvents.Count + 1)); uniqueEvent.SetData(extraData); uniqueEvents.Add(uniqueEvent); } } } public void CreateEvent(IServerSerializable entity, NetEntityEvent.IData extraData = null) { if (!ValidateEntity(entity)) { return; } // enqueue and let background task handle the rest pendingCreateQueue.Enqueue(new PendingCreateEvent(entity, extraData)); if (eventSignal.CurrentCount == 0) { eventSignal.Release(); } } public void Dispose() { cancellationTokenSource.Cancel(); eventSignal.Release(); try { createEventTask?.Wait(2000); } catch (AggregateException) { } finally { cancellationTokenSource.Dispose(); eventSignal.Dispose(); } } // Due to intensive access demend and time it takes to refactor, we use try-catch when facing thread-safety issue to skip to next update :( public void Update(List clients) { foreach (BufferedEvent bufferedEvent in bufferedEvents) { if (bufferedEvent.Character == null || bufferedEvent.Character.IsDead) { if (bufferedEvent.RequireCharacter) { bufferedEvent.IsProcessed = true; continue; } } //delay reading the events until the inputs for the corresponding frame have been processed //UNLESS the character is unconscious, in which case we'll read the messages immediately (because further inputs will be ignored) //atm the "give in" command is the only thing unconscious characters can do, other types of events are ignored if (bufferedEvent.Character != null && !bufferedEvent.Character.IsIncapacitated && NetIdUtils.IdMoreRecent(bufferedEvent.CharacterStateID, bufferedEvent.Character.LastProcessedID)) { DebugConsole.Log($"Delaying reading entity event sent by a client until the character state has been processed. Event's character state: {bufferedEvent.CharacterStateID}, last processed character state: {bufferedEvent.Character.LastProcessedID}"); continue; } try { ReadEvent(bufferedEvent.Data, bufferedEvent.TargetEntity, bufferedEvent.Sender); } catch (Exception e) { string entityName = bufferedEvent.TargetEntity == null ? "null" : bufferedEvent.TargetEntity.ToString(); if (GameSettings.CurrentConfig.VerboseLogging) { string errorMsg = "Failed to read server event for entity \"" + entityName + "\"!"; GameServer.Log(errorMsg + "\n" + e.StackTrace.CleanupStackTrace(), ServerLog.MessageType.Error); DebugConsole.ThrowError(errorMsg, e); } GameAnalyticsManager.AddErrorEventOnce("ServerEntityEventManager.Read:ReadFailed" + entityName, GameAnalyticsManager.ErrorSeverity.Error, "Failed to read server event for entity \"" + entityName + "\"!\n" + e.StackTrace.CleanupStackTrace()); } bufferedEvent.IsProcessed = true; } List inGameClients = null; List midRoundSyncClients = null; Client ownerClient = null; foreach (var c in clients) { if (c.InGame) { if (c.NeedsMidRoundSync) { (midRoundSyncClients ??= new List()).Add(c); } else { (inGameClients ??= new List()).Add(c); } } if (server.OwnerConnection != null && c.Connection == server.OwnerConnection) { ownerClient = c; } } if (inGameClients != null && inGameClients.Count > 0) { lastSentToAnyone = inGameClients[0].LastRecvEntityEventID; lastSentToAll = ownerClient?.LastRecvEntityEventID ?? inGameClients[0].LastRecvEntityEventID; foreach (var c in inGameClients) { if (NetIdUtils.IdMoreRecent(lastSentToAll, c.LastRecvEntityEventID)) { lastSentToAll = c.LastRecvEntityEventID; } if (NetIdUtils.IdMoreRecent(c.LastRecvEntityEventID, lastSentToAnyone)) { lastSentToAnyone = c.LastRecvEntityEventID; } } try { lastSentToAnyoneTime = events.ToList().Find(e => e.ID == lastSentToAnyone)?.CreateTime ?? Timing.TotalTime; } catch { lastSentToAnyoneTime = Timing.TotalTime; } if (Timing.TotalTime - lastWarningTime > 5.0 && Timing.TotalTime - lastSentToAnyoneTime > 10.0 && GameMain.GameSession.RoundDuration > server.ServerSettings.RoundStartSyncDuration) { lastWarningTime = Timing.TotalTime; string warningMsg = $"WARNING: ServerEntityEventManager is lagging behind! Last sent id: {lastSentToAnyone}, latest create id: {ID}"; warningMsg += "\n" + GetHighEventCountsWarning(events, maxEventsToList: 3); GameServer.Log(warningMsg, ServerLog.MessageType.ServerMessage); events.ForEach(e => e.ResetCreateTime()); //TODO: reset clients if this happens, maybe do it if a majority are behind rather than all of them? } clients.Where(c => c.NeedsMidRoundSync).ForEach(c => { if (NetIdUtils.IdMoreRecent(lastSentToAll, c.FirstNewEventID)) lastSentToAll = (ushort)(c.FirstNewEventID - 1); }); ServerEntityEvent firstEventToResend; try { firstEventToResend = events.Find(e => e.ID == (ushort)(lastSentToAll + 1)); } catch { firstEventToResend = null; } if (firstEventToResend != null && GameMain.GameSession.RoundDuration > server.ServerSettings.RoundStartSyncDuration && ((lastSentToAnyoneTime - firstEventToResend.CreateTime) > server.ServerSettings.OldReceivedEventKickTime || (Timing.TotalTime - firstEventToResend.CreateTime) > server.ServerSettings.OldEventKickTime)) { // This event is 10 seconds older than the last one we've successfully sent, // kick everyone that hasn't received it yet, this is way too old // UNLESS the event was created when the client was still midround syncing, // in which case we'll wait until the timeout runs out before kicking the client List toKick = inGameClients.FindAll(c => NetIdUtils.IdMoreRecent((UInt16)(lastSentToAll + 1), c.LastRecvEntityEventID) && (firstEventToResend.CreateTime > c.MidRoundSyncTimeOut || lastSentToAnyoneTime > c.MidRoundSyncTimeOut || Timing.TotalTime > c.MidRoundSyncTimeOut + 10.0)); toKick.ForEach(c => { DebugConsole.NewMessage(c.Name + " was kicked because they were expecting a very old network event (" + (c.LastRecvEntityEventID + 1).ToString() + ")", Color.Red); GameServer.Log(GameServer.ClientLogName(c) + " was kicked because they were expecting a very old network event (" + (c.LastRecvEntityEventID + 1).ToString() + " (created " + (Timing.TotalTime - firstEventToResend.CreateTime).ToString("0.##") + " s ago, " + (lastSentToAnyoneTime - firstEventToResend.CreateTime).ToString("0.##") + " s older than last event sent to anyone)" + " Events queued: " + events.Count + ", last sent to all: " + lastSentToAll, ServerLog.MessageType.Error); server.DisconnectClient(c, PeerDisconnectPacket.WithReason(DisconnectReason.ExcessiveDesyncOldEvent)); } ); } if (events.Count > 0) { //the client is waiting for an event that we don't have anymore //(the ID they're expecting is smaller than the ID of the first event in our list) List toKick = inGameClients.FindAll(c => NetIdUtils.IdMoreRecent(events[0].ID, (UInt16)(c.LastRecvEntityEventID + 1))); toKick.ForEach(c => { DebugConsole.NewMessage(c.Name + " was kicked because they were expecting a removed network event (" + (c.LastRecvEntityEventID + 1).ToString() + ", last available is " + events[0].ID.ToString() + ")", Color.Red); GameServer.Log(GameServer.ClientLogName(c) + " was kicked because they were expecting a removed network event (" + (c.LastRecvEntityEventID + 1).ToString() + ", last available is " + events[0].ID.ToString() + ")", ServerLog.MessageType.Error); server.DisconnectClient(c, PeerDisconnectPacket.WithReason(DisconnectReason.ExcessiveDesyncRemovedEvent)); }); } } if (midRoundSyncClients != null) { foreach (var c in midRoundSyncClients) { if (NetIdUtils.IdMoreRecent(lastSentToAll, c.FirstNewEventID)) { lastSentToAll = (ushort)(c.FirstNewEventID - 1); } if (c.Connection != GameMain.Server.OwnerConnection && Timing.TotalTime > c.MidRoundSyncTimeOut) { GameServer.Log("Disconnecting client " + GameServer.ClientLogName(c) + ". Syncing took too long.", ServerLog.MessageType.Error); GameMain.Server.DisconnectClient(c, PeerDisconnectPacket.WithReason(DisconnectReason.SyncTimeout)); } } } bufferedEvents.RemoveAll(b => b.IsProcessed); } private void BufferEvent(BufferedEvent bufferedEvent) { if (bufferedEvents.Count > 512) { //should normally never happen //a client could potentially spam events with a much higher character state ID //than the state of their character and/or stop sending character inputs, //so we'll drop some events to make sure no-one blows up our buffer DebugConsole.Log("Excessive amount of events in a client's event buffer. The client may be spamming events or their event IDs might be out of sync. Dropping events..."); bufferedEvents.RemoveRange(0, 256); } bufferedEvents.Add(bufferedEvent); } /// /// Writes all the events that the client hasn't received yet into the outgoing message /// public void Write(in SegmentTableWriter segmentTable, Client client, IWriteMessage msg) { Write(segmentTable, client, msg, out _); } /// /// Writes all the events that the client hasn't received yet into the outgoing message /// public void Write(in SegmentTableWriter segmentTable, Client client, IWriteMessage msg, out List sentEvents) { List eventsToSync = GetEventsToSync(client); if (eventsToSync.Count == 0) { sentEvents = eventsToSync; return; } //too many events for one packet //(normal right after a round has just started, don't show a warning if it's been less than 30 seconds) if (eventsToSync.Count > 200 && GameMain.GameSession != null && GameMain.GameSession.RoundDuration > 30.0) { if (eventsToSync.Count > 200 && !client.NeedsMidRoundSync && Timing.TotalTime > lastEventCountHighWarning + 2.0) { Color color = eventsToSync.Count > 500 ? Color.Red : Color.Orange; if (eventsToSync.Count < 300) { color = Color.Yellow; } string warningMsg = "WARNING: event count very high: " + eventsToSync.Count; warningMsg += "\n" + GetHighEventCountsWarning(eventsToSync, maxEventsToList: 3); if (GameSettings.CurrentConfig.VerboseLogging) { GameServer.Log(warningMsg, ServerLog.MessageType.Error); } server.SendConsoleMessage(warningMsg, client, color); DebugConsole.NewMessage(warningMsg, color); lastEventCountHighWarning = Timing.TotalTime; } } if (client.NeedsMidRoundSync) { segmentTable.StartNewSegment(ServerNetSegment.EntityEventInitial); msg.WriteUInt16(client.UnreceivedEntityEventCount); msg.WriteUInt16(client.FirstNewEventID); Write(msg, eventsToSync, out sentEvents, client); } else { segmentTable.StartNewSegment(ServerNetSegment.EntityEvent); Write(msg, eventsToSync, out sentEvents, client); } foreach (NetEntityEvent entityEvent in sentEvents) { (entityEvent as ServerEntityEvent).Sent = true; client.EntityEventLastSent[entityEvent.ID] = Lidgren.Network.NetTime.Now; } } private string GetHighEventCountsWarning(IEnumerable events, int maxEventsToList) { string warningMsg = string.Empty; var sortedEvents = events.GroupBy(e => e.Entity.ToString()) .Select(e => new { Value = e.First(), Count = e.Count() }) .OrderByDescending(e => e.Count); int count = 1; foreach (var sortedEvent in sortedEvents) { Entity targetEntity = sortedEvent.Value.Entity; if (!warningMsg.IsNullOrEmpty()) { warningMsg += "\n"; } warningMsg += count + ". " + (targetEntity?.ToString() ?? "null") + " x" + sortedEvent.Count; if (targetEntity != null && targetEntity.ContentPackage != ContentPackageManager.VanillaCorePackage) { warningMsg += $" (content package: {targetEntity.ContentPackage.Name})"; } count++; if (count > maxEventsToList) { break; } } return warningMsg; } /// /// Returns a list of events that should be sent to the client from the eventList /// private List GetEventsToSync(Client client) { List eventsToSync = new List(); var eventList = client.NeedsMidRoundSync ? uniqueEvents : events; if (eventList.Count == 0) { return eventsToSync; } //find the index of the first event the client hasn't received int startIndex = eventList.Count; while (startIndex > 0 && NetIdUtils.IdMoreRecent(eventList[startIndex - 1].ID, client.LastRecvEntityEventID)) { startIndex--; } for (int i = startIndex; i < eventList.Count; i++) { //find the first event that hasn't been sent in roundtriptime or at all client.EntityEventLastSent.TryGetValue(eventList[i].ID, out double lastSent); float avgRoundtripTime = 0.01f; //TODO: reimplement client.Connection.AverageRoundtripTime float minInterval = Math.Max(avgRoundtripTime, (float)server.UpdateInterval.TotalSeconds * 2); if (lastSent > Lidgren.Network.NetTime.Now - Math.Min(minInterval, 0.5f)) { continue; } if (client.NeedsMidRoundSync) { if (i <= client.UnreceivedEntityEventCount) { eventsToSync.AddRange(eventList.GetRange(i, client.UnreceivedEntityEventCount - i)); } } else { eventsToSync.AddRange(eventList.GetRange(i, eventList.Count - i)); } break; } return eventsToSync; } public void InitClientMidRoundSync(Client client) { //no need for midround syncing if no events have been created, //or if the first created unique event is still in the event list if (uniqueEvents.Count == 0 || (events.Count > 0 && events[0].ID == uniqueEvents[0].ID)) { client.UnreceivedEntityEventCount = 0; client.FirstNewEventID = 0; client.NeedsMidRoundSync = false; } else { //assume we can get at least 10 events per second through double midRoundSyncTimeOut = uniqueEvents.Count / 10 * server.UpdateInterval.TotalSeconds; midRoundSyncTimeOut = Math.Max(midRoundSyncTimeOut, server.ServerSettings.MinimumMidRoundSyncTimeout); client.UnreceivedEntityEventCount = (UInt16)uniqueEvents.Count; client.NeedsMidRoundSync = true; client.MidRoundSyncTimeOut = Timing.TotalTime + midRoundSyncTimeOut; //how many (unique) events the clients had missed before joining client.UnreceivedEntityEventCount = (UInt16)uniqueEvents.Count; //ID of the first event sent after the client joined //(after the client has been synced they'll switch their lastReceivedID //to the one before this, and the eventmanagers will start to function "normally") client.FirstNewEventID = events.Count == 0 ? (UInt16)0 : events[events.Count - 1].ID; } } /// /// Read the events from the message, ignoring ones we've already received /// public void Read(IReadMessage msg, Client sender = null) { msg.ReadPadBits(); UInt16 firstEventID = msg.ReadUInt16(); int eventCount = msg.ReadByte(); for (int i = 0; i < eventCount; i++) { UInt16 thisEventID = (UInt16)(firstEventID + (UInt16)i); UInt16 entityID = msg.ReadUInt16(); if (entityID == Entity.NullEntityID) { if (thisEventID == (UInt16)(sender.LastSentEntityEventID + 1)) sender.LastSentEntityEventID++; continue; } int msgLength = (int)msg.ReadVariableUInt32(); IClientSerializable entity = Entity.FindEntityByID(entityID) as IClientSerializable; //skip the event if we've already received it if (thisEventID != (UInt16)(sender.LastSentEntityEventID + 1)) { if (GameSettings.CurrentConfig.VerboseLogging) { DebugConsole.NewMessage("Received msg " + thisEventID + ", expecting " + sender.LastSentEntityEventID, Color.Red); } msg.BitPosition += msgLength * 8; } else if (entity == null) { //entity not found -> consider the event read and skip over it //(can happen, for example, when a client uses a medical item repeatedly //and creates an event for it before receiving the event about it being removed) if (GameSettings.CurrentConfig.VerboseLogging) { DebugConsole.NewMessage( "Received msg " + thisEventID + ", entity " + entityID + " not found", Microsoft.Xna.Framework.Color.Orange); } sender.LastSentEntityEventID++; msg.BitPosition += msgLength * 8; } else { if (GameSettings.CurrentConfig.VerboseLogging) { DebugConsole.NewMessage("Received msg " + thisEventID, Microsoft.Xna.Framework.Color.Green); } UInt16 characterStateID = msg.ReadUInt16(); ReadWriteMessage buffer = new ReadWriteMessage(); byte[] temp = msg.ReadBytes(msgLength - 2); buffer.WriteBytes(temp, 0, msgLength - 2); buffer.BitPosition = 0; BufferEvent( new BufferedEvent(sender, sender.Character, characterStateID, entity, buffer) { //hull updates can be sent without a character to allow editing water and fire in spectator mode RequireCharacter = entity is not Hull }); sender.LastSentEntityEventID++; } } } protected override void WriteEvent(IWriteMessage buffer, NetEntityEvent entityEvent, Client recipient = null) { var serverEvent = entityEvent as ServerEntityEvent; if (serverEvent == null) return; serverEvent.Write(buffer, recipient); } protected void ReadEvent(IReadMessage buffer, INetSerializable entity, Client sender = null) { var clientEntity = entity as IClientSerializable; if (clientEntity == null) return; clientEntity.ServerEventRead(buffer, sender); } public void Clear() { ID = 0; events.Clear(); bufferedEvents.Clear(); lastSentToAll = 0; uniqueEvents.Clear(); foreach (Client c in server.ConnectedClients) { c.EntityEventLastSent.Clear(); c.LastRecvEntityEventID = 0; c.LastSentEntityEventID = 0; } } } }