tommy/tbd-station-14
2
1
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Cache the last 3 rounds of admin logs in memory

Browse Source 
Reduces send logs time from 2/10/45 seconds to 2 milliseconds
Not thread safe
Removes LogRecord
This commit is contained in:
DrSmugleaf
2021-12-25 02:07:12 +01:00
parent cdc1a70c03
commit 1f8152cb02
13 changed files with 233 additions and 109 deletions
Download Patch File Download Diff File Expand all files Collapse all files

10
Content.Client/Administration/UI/Logs/AdminLogsControl.xaml.cs
View File

@@ -1,6 +1,7 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Runtime.InteropServices;
using Content.Client.Administration.UI.CustomControls;
using Content.Shared.Administration.Logs;
using Content.Shared.Database;
@@ -390,11 +391,12 @@ public partial class AdminLogsControl : Control
UpdateLogs();
}
public void AddLogs(SharedAdminLog[] logs)
public void AddLogs(List<SharedAdminLog> logs)
{
for (var i = 0; i < logs.Length; i++)
var span = CollectionsMarshal.AsSpan(logs);
for (var i = 0; i < span.Length; i++)
{
ref var log = ref logs[i];
ref var log = ref span[i];
var separator = new HSeparator();
var label = new AdminLogLabel(ref log, separator);
label.Visible = ShouldShowLog(label);
@@ -404,7 +406,7 @@ public partial class AdminLogsControl : Control
}
}
public void SetLogs(SharedAdminLog[] logs)
public void SetLogs(List<SharedAdminLog> logs)
{
LogsContainer.RemoveAllChildren();
AddLogs(logs);

67
Content.IntegrationTests/Tests/Administration/Logs/AddTests.cs
View File

@@ -5,6 +5,7 @@ using System.Threading.Tasks;
using Content.Server.Administration.Logs;
using Content.Server.Database;
using Content.Server.GameTicking;
using Content.Shared.Administration.Logs;
using Content.Shared.CCVar;
using Content.Shared.Database;
using NUnit.Framework;
@@ -89,6 +90,7 @@ public class AddTests : ContentIntegrationTest
var sSystems = server.ResolveDependency<IEntitySystemManager>();
var sAdminLogSystem = sSystems.GetEntitySystem<AdminLogSystem>();
var sGamerTicker = sSystems.GetEntitySystem<GameTicker>();
var guid = Guid.NewGuid();
@@ -100,27 +102,27 @@ public class AddTests : ContentIntegrationTest
sAdminLogSystem.Add(LogType.Unknown, $"{entity} test log: {guid}");
});
LogRecord log = null;
SharedAdminLog log = default;
await WaitUntil(server, async () =>
{
var logs = sAdminLogSystem.CurrentRoundLogs(new LogFilter
var logs = await sAdminLogSystem.CurrentRoundLogs(new LogFilter
{
Search = guid.ToString()
});
await foreach (var found in logs)
if (logs.Count == 0)
{
log = found;
return true;
return false;
}
return false;
log = logs.First();
return true;
});
var filter = new LogFilter
{
Round = log.RoundId,
Round = sGamerTicker.RoundId,
Search = log.Message,
Types = new HashSet<LogType> {log.Type},
};
@@ -137,9 +139,8 @@ public class AddTests : ContentIntegrationTest
}
[Test]
[TestCase(500, false)]
[TestCase(500, true)]
public async Task BulkAddLogs(int amount, bool parallel)
[TestCase(500)]
public async Task BulkAddLogs(int amount)
{
var server = StartServer(new ServerContentIntegrationOption
{
@@ -162,33 +163,16 @@ public class AddTests : ContentIntegrationTest
var coordinates = GetMainEntityCoordinates(sMaps);
var entity = sEntities.SpawnEntity(null, coordinates);
if (parallel)
{
Parallel.For(0, amount, _ =>
{
sAdminLogSystem.Add(LogType.Unknown, $"{entity:Entity} test log.");
});
}
else
{
for (var i = 0; i < amount; i++)
{
sAdminLogSystem.Add(LogType.Unknown, $"{entity:Entity} test log.");
}
}
});
await WaitUntil(server, async () =>
{
var messages = sAdminLogSystem.CurrentRoundLogs();
var count = 0;
await foreach (var _ in messages)
{
count++;
}
return count >= amount;
var messages = await sAdminLogSystem.CurrentRoundLogs();
return messages.Count >= amount;
});
}
@@ -225,15 +209,14 @@ public class AddTests : ContentIntegrationTest
await WaitUntil(server, async () =>
{
var logs = sAdminLogSystem.CurrentRoundLogs();
await foreach (var log in logs)
var logs = await sAdminLogSystem.CurrentRoundLogs();
if (logs.Count == 0)
{
Assert.That(log.Players, Does.Contain(playerGuid));
return true;
return false;
}
return false;
Assert.That(logs.First().Players, Does.Contain(playerGuid));
return true;
});
}
@@ -273,27 +256,27 @@ public class AddTests : ContentIntegrationTest
sGamerTicker.StartRound(true);
});
LogRecord log = null;
SharedAdminLog log = default;
await WaitUntil(server, async () =>
{
var logs = sAdminLogSystem.CurrentRoundLogs(new LogFilter
var logs = await sAdminLogSystem.CurrentRoundLogs(new LogFilter
{
Search = guid.ToString()
});
await foreach (var found in logs)
if (logs.Count == 0)
{
log = found;
return true;
return false;
}
return false;
log = logs.First();
return true;
});
var filter = new LogFilter
{
Round = log.RoundId,
Round = sGamerTicker.RoundId,
Search = log.Message,
Types = new HashSet<LogType> {log.Type},
};

5
Content.IntegrationTests/Tests/Administration/Logs/FilterTests.cs
View File

@@ -1,5 +1,4 @@
using System;
using System.Threading;
using System.Threading.Tasks;
using Content.Server.Administration.Logs;
using Content.Shared.Administration.Logs;
@@ -84,13 +83,13 @@ public class FilterTests : ContentIntegrationTest
var firstFound = false;
var secondFound = false;
var both = sAdminLogSystem.CurrentRoundLogs(new LogFilter
var both = await sAdminLogSystem.CurrentRoundLogs(new LogFilter
{
Search = commonGuidStr,
DateOrder = order
});
await foreach (var log in both)
foreach (var log in both)
{
if (!log.Message.Contains(commonGuidStr))
{

2
Content.IntegrationTests/Tests/Administration/Logs/QueryTests.cs
View File

@@ -59,7 +59,7 @@ public class QueryTests : ContentIntegrationTest
await WaitUntil(server, async () =>
{
await foreach (var _ in sAdminLogSystem.All(filter))
foreach (var _ in await sAdminLogSystem.All(filter))
{
return true;
}

151
Content.Server/Administration/Logs/AdminLogSystem.Cache.cs Normal file
View File

@@ -0,0 +1,151 @@
using System;
using System.Collections.Generic;
using System.Diagnostics.CodeAnalysis;
using System.Linq;
using Content.Server.Database;
using Content.Shared.Administration.Logs;
using Content.Shared.Database;
using Prometheus;
namespace Content.Server.Administration.Logs;
public partial class AdminLogSystem
{
private const int MaxRoundsCached = 3;
private const int LogListInitialSize = 30_000;
private readonly int _logTypes = Enum.GetValues<LogType>().Length;
// TODO ADMIN LOGS make this thread safe or remove thread safety from the main partial class
private readonly Dictionary<int, List<SharedAdminLog>> _roundsLogCache = new(MaxRoundsCached);
private static readonly Gauge CacheRoundCount = Metrics.CreateGauge(
"admin_logs_cache_round_count",
"How many rounds are in cache.");
private static readonly Gauge CacheLogCount = Metrics.CreateGauge(
"admin_logs_cache_log_count",
"How many logs are in cache.");
// TODO ADMIN LOGS cache previous {MaxRoundsCached} rounds on startup
private void CacheNewRound()
{
List<SharedAdminLog> list;
var oldestRound = CurrentRoundId - MaxRoundsCached;
if (_roundsLogCache.Remove(oldestRound, out var oldestList))
{
list = oldestList;
list.Clear();
}
else
{
list = new List<SharedAdminLog>(LogListInitialSize);
}
_roundsLogCache.Add(CurrentRoundId, list);
CacheRoundCount.Set(_roundsLogCache.Count);
}
private void CacheLog(AdminLog log)
{
var players = log.Players.Select(player => player.PlayerUserId).ToArray();
var record = new SharedAdminLog(log.Id, log.Type, log.Impact, log.Date, log.Message, players);
CacheLog(record);
}
private void CacheLog(QueuedLog log)
{
CacheLog(log.Log);
}
private void CacheLog(SharedAdminLog log)
{
// TODO ADMIN LOGS remove redundant data and don't do a dictionary lookup per log
var cache = _roundsLogCache[CurrentRoundId];
cache.Add(log);
CacheLogCount.Set(cache.Count);
}
private void CacheLogs(IEnumerable<SharedAdminLog> logs)
{
var cache = _roundsLogCache[CurrentRoundId];
cache.AddRange(logs);
CacheLogCount.Set(cache.Count);
}
private bool TryGetCache(int roundId, [NotNullWhen(true)] out List<SharedAdminLog>? cache)
{
return _roundsLogCache.TryGetValue(roundId, out cache);
}
private bool TrySearchCache(LogFilter? filter, [NotNullWhen(true)] out List<SharedAdminLog>? results)
{
if (filter?.Round == null || !TryGetCache(filter.Round.Value, out var cache))
{
results = null;
return false;
}
// TODO ADMIN LOGS a better heuristic than linq spaghetti
var query = cache.AsEnumerable();
query = filter.DateOrder switch
{
DateOrder.Ascending => query,
DateOrder.Descending => query.Reverse(),
_ => throw new ArgumentOutOfRangeException(nameof(filter),
$"Unknown {nameof(DateOrder)} value {filter.DateOrder}")
};
if (filter.LogsSent != 0)
{
query = query.Skip(filter.LogsSent);
}
if (filter.Search != null)
{
query = query.Where(log => log.Message.Contains(filter.Search, StringComparison.OrdinalIgnoreCase));
}
if (filter.Types != null && filter.Types.Count != _logTypes)
{
query = query.Where(log => filter.Types.Contains(log.Type));
}
if (filter.Impacts != null)
{
query = query.Where(log => filter.Impacts.Contains(log.Impact));
}
if (filter.Before != null)
{
query = query.Where(log => log.Date < filter.Before);
}
if (filter.After != null)
{
query = query.Where(log => log.Date > filter.After);
}
if (filter.AnyPlayers != null)
{
query = query.Where(log => filter.AnyPlayers.Any(filterPlayer => log.Players.Contains(filterPlayer)));
}
if (filter.AllPlayers != null)
{
query = query.Where(log => filter.AllPlayers.All(filterPlayer => log.Players.Contains(filterPlayer)));
}
if (filter.Limit != null)
{
query = query.Take(filter.Limit.Value);
}
// TODO ADMIN LOGS array pool
results = query.ToList();
return true;
}
}

35
Content.Server/Administration/Logs/AdminLogSystem.cs
View File

@@ -2,6 +2,7 @@
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Text.Json;
using System.Threading;
using System.Threading.Tasks;
using Content.Server.Database;
using Content.Server.GameTicking;
@@ -75,7 +76,10 @@ public partial class AdminLogSystem : SharedAdminLogSystem
private readonly ConcurrentQueue<QueuedLog> _logQueue = new();
private readonly ConcurrentQueue<QueuedLog> _preRoundLogQueue = new();
// Per round
private int CurrentRoundId => _gameTicker.RoundId;
private int _currentLogId;
private int NextLogId => Interlocked.Increment(ref _currentLogId);
public override void Initialize()
{
@@ -195,6 +199,7 @@ public partial class AdminLogSystem : SharedAdminLogSystem
foreach (var queued in _preRoundLogQueue)
{
queued.Log.RoundId = _gameTicker.RoundId;
CacheLog(queued);
}
copy.AddRange(_preRoundLogQueue);
@@ -227,6 +232,9 @@ public partial class AdminLogSystem : SharedAdminLogSystem
private void RoundStarting(RoundStartingEvent ev)
{
Interlocked.Exchange(ref _currentLogId, 0);
CacheNewRound();
if (_metricsEnabled)
{
PreRoundQueueCapReached.Set(0);
@@ -237,12 +245,16 @@ public partial class AdminLogSystem : SharedAdminLogSystem
private async void Add(LogType type, LogImpact impact, string message, JsonDocument json, List<Guid> players, List<(int id, string? name)> entities)
{
var logId = NextLogId;
var date = DateTime.UtcNow;
var log = new AdminLog
{
Id = logId,
RoundId = CurrentRoundId,
Type = type,
Impact = impact,
Date = DateTime.UtcNow,
Date = date,
Message = message,
Json = json,
Players = new List<AdminLogPlayer>(players.Count)
@@ -254,6 +266,7 @@ public partial class AdminLogSystem : SharedAdminLogSystem
{
var player = new AdminLogPlayer
{
LogId = logId,
PlayerUserId = id
};
@@ -267,6 +280,7 @@ public partial class AdminLogSystem : SharedAdminLogSystem
else
{
_logQueue.Enqueue(queued);
CacheLog(log);
}
}
@@ -289,9 +303,22 @@ public partial class AdminLogSystem : SharedAdminLogSystem
Add(type, LogImpact.Medium, ref handler);
}
public IAsyncEnumerable<LogRecord> All(LogFilter? filter = null)
public async Task<List<SharedAdminLog>> All(LogFilter? filter = null)
{
return _db.GetAdminLogs(filter);
if (TrySearchCache(filter, out var results))
{
return results;
}
var initialSize = Math.Min(filter?.Limit ?? 0, 1000);
var list = new List<SharedAdminLog>(initialSize);
await foreach (var log in _db.GetAdminLogs(filter).WithCancellation(filter?.CancellationToken ?? default))
{
list.Add(log);
}
return list;
}
public IAsyncEnumerable<string> AllMessages(LogFilter? filter = null)
@@ -309,7 +336,7 @@ public partial class AdminLogSystem : SharedAdminLogSystem
return _db.GetRound(roundId);
}
public IAsyncEnumerable<LogRecord> CurrentRoundLogs(LogFilter? filter = null)
public Task<List<SharedAdminLog>> CurrentRoundLogs(LogFilter? filter = null)
{
filter ??= new LogFilter();
filter.Round = CurrentRoundId;

14
Content.Server/Administration/Logs/AdminLogsEui.cs
View File

@@ -147,21 +147,17 @@ public sealed class AdminLogsEui : BaseEui
stopwatch.Start();
// TODO ADMIN LOGS array pool
var logs = new List<SharedAdminLog>(_clientBatchSize);
List<SharedAdminLog> logs = default!;
await Task.Run(async () =>
{
var results = await Task.Run(() => _logSystem.All(_filter));
await foreach (var record in results.WithCancellation(_logSendCancellation.Token))
{
var log = new SharedAdminLog(record.Id, record.Type, record.Impact, record.Date, record.Message, record.Players);
logs.Add(log);
}
logs = await _logSystem.All(_filter);
}, _filter.CancellationToken);
if (logs.Count > 0)
{
_filter.LogsSent += logs.Count;
var largestId = _filter.DateOrder switch
{
DateOrder.Ascending => ^1,
@@ -172,7 +168,7 @@ public sealed class AdminLogsEui : BaseEui
_filter.LastLogId = logs[largestId].Id;
}
var message = new NewLogs(logs.ToArray(), replace);
var message = new NewLogs(logs, replace);
SendMessage(message);

2
Content.Server/Administration/Logs/LogFilter.cs
View File

@@ -28,6 +28,8 @@ public sealed class LogFilter
public int? LastLogId { get; set; }
public int LogsSent { get; set; }
public int? Limit { get; set; }
public DateOrder DateOrder { get; set; } = DateOrder.Descending;

36
Content.Server/Administration/Logs/LogRecord.cs
View File

@@ -1,36 +0,0 @@
using System;
using System.Collections.Generic;
using Content.Server.Database;
using Content.Shared.Administration.Logs;
using Content.Shared.Database;
namespace Content.Server.Administration.Logs;
public class LogRecord
{
public LogRecord(
int id,
int roundId,
LogType type,
LogImpact impact,
DateTime date,
string message,
Guid[] players)
{
Id = id;
RoundId = roundId;
Type = type;
Impact = impact;
Date = date;
Message = message;
Players = players;
}
public int Id { get; }
public int RoundId { get; }
public LogType Type { get; }
public LogImpact Impact { get; }
public DateTime Date { get; }
public string Message { get; }
public Guid[] Players { get; }
}

4
Content.Server/Database/ServerDbBase.cs
View File

@@ -640,7 +640,7 @@ namespace Content.Server.Database
}
}
public async IAsyncEnumerable<LogRecord> GetAdminLogs(LogFilter? filter = null)
public async IAsyncEnumerable<SharedAdminLog> GetAdminLogs(LogFilter? filter = null)
{
await using var db = await GetDb();
var query = await GetAdminLogsQuery(db.DbContext, filter);
@@ -654,7 +654,7 @@ namespace Content.Server.Database
players[i] = log.Players[i].PlayerUserId;
}
yield return new LogRecord(log.Id, log.RoundId, log.Type, log.Impact, log.Date, log.Message, players);
yield return new SharedAdminLog(log.Id, log.Type, log.Impact, log.Date, log.Message, players);
}
}

6
Content.Server/Database/ServerDbManager.cs
View File

@@ -7,6 +7,7 @@ using System.Text.Json;
using System.Threading;
using System.Threading.Tasks;
using Content.Server.Administration.Logs;
using Content.Shared.Administration.Logs;
using Content.Shared.CCVar;
using Content.Shared.Preferences;
using Microsoft.Data.Sqlite;
@@ -19,7 +20,6 @@ using Robust.Shared.IoC;
using Robust.Shared.Log;
using Robust.Shared.Maths;
using Robust.Shared.Network;
using Logger = Robust.Shared.Log.Logger;
using LogLevel = Robust.Shared.Log.LogLevel;
using MSLogLevel = Microsoft.Extensions.Logging.LogLevel;
@@ -135,7 +135,7 @@ namespace Content.Server.Database
Task AddAdminLogs(List<QueuedLog> logs);
IAsyncEnumerable<string> GetAdminLogMessages(LogFilter? filter = null);
IAsyncEnumerable<LogRecord> GetAdminLogs(LogFilter? filter = null);
IAsyncEnumerable<SharedAdminLog> GetAdminLogs(LogFilter? filter = null);
IAsyncEnumerable<JsonDocument> GetAdminLogsJson(LogFilter? filter = null);
#endregion
@@ -346,7 +346,7 @@ namespace Content.Server.Database
return _db.GetAdminLogMessages(filter);
}
public IAsyncEnumerable<LogRecord> GetAdminLogs(LogFilter? filter = null)
public IAsyncEnumerable<SharedAdminLog> GetAdminLogs(LogFilter? filter = null)
{
return _db.GetAdminLogs(filter);
}

2
Content.Server/GameTicking/Events/RoundStartingEvent.cs
View File

@@ -3,7 +3,7 @@
namespace Content.Server.GameTicking.Events;
/// <summary>
/// Raised at the start of <see cref="GameTicker.StartRound"/>
/// Raised at the start of <see cref="GameTicker.StartRound"/>, after round id has been incremented
/// </summary>
public class RoundStartingEvent : EntityEventArgs
{

4
Content.Shared/Administration/AdminLogsEuiState.cs
View File

@@ -33,13 +33,13 @@ public static class AdminLogsEuiMsg
[Serializable, NetSerializable]
public sealed class NewLogs : EuiMessageBase
{
public NewLogs(SharedAdminLog[] logs, bool replace)
public NewLogs(List<SharedAdminLog> logs, bool replace)
{
Logs = logs;
Replace = replace;
}
public SharedAdminLog[] Logs { get; set; }
public List<SharedAdminLog> Logs { get; set; }
public bool Replace { get; set; }
}