diff --git a/osu.Server.Spectator.Tests/BuildUserCountUpdaterTest.cs b/osu.Server.Spectator.Tests/BuildUserCountUpdaterTest.cs index 7b7771ed..ea3a78a6 100644 --- a/osu.Server.Spectator.Tests/BuildUserCountUpdaterTest.cs +++ b/osu.Server.Spectator.Tests/BuildUserCountUpdaterTest.cs @@ -3,6 +3,7 @@ using System; using System.Threading.Tasks; +using Microsoft.Extensions.Logging; using Moq; using osu.Server.Spectator.Database; using osu.Server.Spectator.Database.Models; @@ -17,6 +18,7 @@ public class BuildUserCountUpdaterTest private readonly EntityStore clientStates; private readonly Mock databaseFactoryMock; private readonly Mock databaseAccessMock; + private readonly Mock loggerFactoryMock; public BuildUserCountUpdaterTest() { @@ -24,6 +26,9 @@ public BuildUserCountUpdaterTest() databaseFactoryMock = new Mock(); databaseAccessMock = new Mock(); + loggerFactoryMock = new Mock(); + loggerFactoryMock.Setup(factory => factory.CreateLogger(It.IsAny())) + .Returns(new Mock().Object); databaseFactoryMock.Setup(df => df.GetInstance()).Returns(databaseAccessMock.Object); } @@ -53,7 +58,7 @@ public async Task TestPeriodicUpdates() await trackUser(6, "unknown"); AppSettings.TrackBuildUserCounts = true; - var updater = new BuildUserCountUpdater(clientStates, databaseFactoryMock.Object) + var updater = new BuildUserCountUpdater(clientStates, databaseFactoryMock.Object, loggerFactoryMock.Object) { UpdateInterval = 50 }; diff --git a/osu.Server.Spectator.Tests/ConcurrentConnectionLimiterTests.cs b/osu.Server.Spectator.Tests/ConcurrentConnectionLimiterTests.cs index bd853023..c5c37e4d 100644 --- a/osu.Server.Spectator.Tests/ConcurrentConnectionLimiterTests.cs +++ b/osu.Server.Spectator.Tests/ConcurrentConnectionLimiterTests.cs @@ -6,6 +6,7 @@ using System.Security.Claims; using System.Threading.Tasks; using Microsoft.AspNetCore.SignalR; +using Microsoft.Extensions.Logging; using Moq; using osu.Server.Spectator.Entities; using osu.Server.Spectator.Hubs.Spectator; @@ -17,6 +18,7 @@ public class ConcurrentConnectionLimiterTests { private readonly EntityStore connectionStates; private readonly Mock serviceProviderMock; + private readonly Mock loggerFactoryMock; private readonly Mock hubMock; public ConcurrentConnectionLimiterTests() @@ -28,6 +30,10 @@ public ConcurrentConnectionLimiterTests() serviceProviderMock.Setup(sp => sp.GetService(It.IsAny())) .Returns(hubContextMock.Object); + loggerFactoryMock = new Mock(); + loggerFactoryMock.Setup(factory => factory.CreateLogger(It.IsAny())) + .Returns(new Mock().Object); + hubMock = new Mock(); } @@ -44,7 +50,7 @@ public async Task TestNormalOperation() }) })); - var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object); + var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object, loggerFactoryMock.Object); var lifetimeContext = new HubLifetimeContext(hubCallerContextMock.Object, serviceProviderMock.Object, hubMock.Object); bool connected = false; @@ -103,7 +109,7 @@ public async Task TestConcurrencyBlocked() }) })); - var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object); + var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object, loggerFactoryMock.Object); var firstLifetimeContext = new HubLifetimeContext(firstContextMock.Object, serviceProviderMock.Object, hubMock.Object); await filter.OnConnectedAsync(firstLifetimeContext, _ => Task.CompletedTask); @@ -149,7 +155,7 @@ public async Task TestStaleDisconnectIsANoOp() }) })); - var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object); + var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object, loggerFactoryMock.Object); var firstLifetimeContext = new HubLifetimeContext(firstContextMock.Object, serviceProviderMock.Object, hubMock.Object); await filter.OnConnectedAsync(firstLifetimeContext, _ => Task.CompletedTask); @@ -189,7 +195,7 @@ public async Task TestHubDisconnectsTrackedSeparately() }) })); - var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object); + var filter = new ConcurrentConnectionLimiter(connectionStates, serviceProviderMock.Object, loggerFactoryMock.Object); var firstLifetimeContext = new HubLifetimeContext(firstContextMock.Object, serviceProviderMock.Object, new FirstHub()); await filter.OnConnectedAsync(firstLifetimeContext, _ => Task.CompletedTask); diff --git a/osu.Server.Spectator.Tests/MetadataHubTest.cs b/osu.Server.Spectator.Tests/MetadataHubTest.cs index b18282ec..158824fb 100644 --- a/osu.Server.Spectator.Tests/MetadataHubTest.cs +++ b/osu.Server.Spectator.Tests/MetadataHubTest.cs @@ -8,6 +8,7 @@ using Microsoft.Extensions.Caching.Distributed; using Microsoft.Extensions.Caching.Memory; using Microsoft.Extensions.Options; +using Microsoft.Extensions.Logging; using Moq; using osu.Game.Online.Metadata; using osu.Game.Users; @@ -36,8 +37,11 @@ public MetadataHubTest() var mockDatabase = new Mock(); var databaseFactory = new Mock(); databaseFactory.Setup(factory => factory.GetInstance()).Returns(mockDatabase.Object); + var loggerFactoryMock = new Mock(); + loggerFactoryMock.Setup(factory => factory.CreateLogger(It.IsAny())) + .Returns(new Mock().Object); - hub = new MetadataHub(cache, userStates, databaseFactory.Object, new Mock().Object); + hub = new MetadataHub(loggerFactoryMock.Object, cache, userStates, databaseFactory.Object, new Mock().Object); var mockContext = new Mock(); mockContext.Setup(ctx => ctx.UserIdentifier).Returns(user_id.ToString()); diff --git a/osu.Server.Spectator.Tests/Multiplayer/MultiplayerTest.cs b/osu.Server.Spectator.Tests/Multiplayer/MultiplayerTest.cs index 89798ed1..384e5bb1 100644 --- a/osu.Server.Spectator.Tests/Multiplayer/MultiplayerTest.cs +++ b/osu.Server.Spectator.Tests/Multiplayer/MultiplayerTest.cs @@ -10,6 +10,7 @@ using Microsoft.Extensions.Caching.Distributed; using Microsoft.Extensions.Caching.Memory; using Microsoft.Extensions.Options; +using Microsoft.Extensions.Logging; using Moq; using osu.Game.Beatmaps; using osu.Game.Online.Multiplayer; @@ -128,7 +129,12 @@ protected MultiplayerTest() Clients.Setup(clients => clients.Group(MultiplayerHub.GetGroupId(ROOM_ID_2))).Returns(Receiver2.Object); Clients.Setup(client => client.Caller).Returns(Caller.Object); + var loggerFactoryMock = new Mock(); + loggerFactoryMock.Setup(factory => factory.CreateLogger(It.IsAny())) + .Returns(new Mock().Object); + Hub = new TestMultiplayerHub( + loggerFactoryMock.Object, new MemoryDistributedCache(Options.Create(new MemoryDistributedCacheOptions())), Rooms, UserStates, diff --git a/osu.Server.Spectator.Tests/Multiplayer/TestMultiplayerHub.cs b/osu.Server.Spectator.Tests/Multiplayer/TestMultiplayerHub.cs index 6da6e750..cacf4d84 100644 --- a/osu.Server.Spectator.Tests/Multiplayer/TestMultiplayerHub.cs +++ b/osu.Server.Spectator.Tests/Multiplayer/TestMultiplayerHub.cs @@ -3,6 +3,7 @@ using Microsoft.AspNetCore.SignalR; using Microsoft.Extensions.Caching.Distributed; +using Microsoft.Extensions.Logging; using osu.Server.Spectator.Database; using osu.Server.Spectator.Entities; using osu.Server.Spectator.Hubs.Multiplayer; @@ -13,13 +14,15 @@ public class TestMultiplayerHub : MultiplayerHub { public new MultiplayerHubContext HubContext => base.HubContext; - public TestMultiplayerHub(IDistributedCache cache, - EntityStore rooms, - EntityStore users, - IDatabaseFactory databaseFactory, - ChatFilters chatFilters, - IHubContext hubContext) - : base(cache, rooms, users, databaseFactory, chatFilters, hubContext) + public TestMultiplayerHub( + ILoggerFactory loggerFactory, + IDistributedCache cache, + EntityStore rooms, + EntityStore users, + IDatabaseFactory databaseFactory, + ChatFilters chatFilters, + IHubContext hubContext) + : base(loggerFactory, cache, rooms, users, databaseFactory, chatFilters, hubContext) { } diff --git a/osu.Server.Spectator.Tests/SpectatorHubTest.cs b/osu.Server.Spectator.Tests/SpectatorHubTest.cs index b7d33049..c0037b71 100644 --- a/osu.Server.Spectator.Tests/SpectatorHubTest.cs +++ b/osu.Server.Spectator.Tests/SpectatorHubTest.cs @@ -68,7 +68,7 @@ public SpectatorHubTest() var mockScoreProcessedSubscriber = new Mock(); - hub = new SpectatorHub(cache, clientStates, databaseFactory.Object, scoreUploader, mockScoreProcessedSubscriber.Object); + hub = new SpectatorHub(loggerFactory.Object, cache, clientStates, databaseFactory.Object, scoreUploader, mockScoreProcessedSubscriber.Object); } [Fact] diff --git a/osu.Server.Spectator.Tests/StatefulUserHubTest.cs b/osu.Server.Spectator.Tests/StatefulUserHubTest.cs index dd720d1a..0546446a 100644 --- a/osu.Server.Spectator.Tests/StatefulUserHubTest.cs +++ b/osu.Server.Spectator.Tests/StatefulUserHubTest.cs @@ -7,6 +7,7 @@ using Microsoft.AspNetCore.SignalR; using Microsoft.Extensions.Caching.Distributed; using Microsoft.Extensions.Caching.Memory; +using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; using Moq; using osu.Game.Online; @@ -29,10 +30,14 @@ public class StatefulUserHubTest public StatefulUserHubTest() { + var loggerFactoryMock = new Mock(); + loggerFactoryMock.Setup(factory => factory.CreateLogger(It.IsAny())) + .Returns(new Mock().Object); + MemoryDistributedCache cache = new MemoryDistributedCache(Options.Create(new MemoryDistributedCacheOptions())); userStates = new EntityStore(); - hub = new TestStatefulHub(cache, userStates); + hub = new TestStatefulHub(loggerFactoryMock.Object, cache, userStates); mockContext = new Mock(); mockContext.Setup(context => context.UserIdentifier).Returns(user_id.ToString()); @@ -108,8 +113,8 @@ private void setNewConnectionId(string? connectionId = null) => private class TestStatefulHub : StatefulUserHub { - public TestStatefulHub(IDistributedCache cache, EntityStore userStates) - : base(cache, userStates) + public TestStatefulHub(ILoggerFactory loggerFactory, IDistributedCache cache, EntityStore userStates) + : base(loggerFactory, cache, userStates) { } diff --git a/osu.Server.Spectator/Authentication/ConfigureJwtBearerOptions.cs b/osu.Server.Spectator/Authentication/ConfigureJwtBearerOptions.cs index 6dcdc5c2..e14214f5 100644 --- a/osu.Server.Spectator/Authentication/ConfigureJwtBearerOptions.cs +++ b/osu.Server.Spectator/Authentication/ConfigureJwtBearerOptions.cs @@ -6,6 +6,7 @@ using System.Security.Cryptography; using Microsoft.AspNetCore.Authentication.JwtBearer; using Microsoft.Extensions.Options; +using Microsoft.Extensions.Logging; using Microsoft.IdentityModel.JsonWebTokens; using Microsoft.IdentityModel.Tokens; using Org.BouncyCastle.Crypto.Parameters; @@ -17,10 +18,12 @@ namespace osu.Server.Spectator.Authentication public class ConfigureJwtBearerOptions : IConfigureNamedOptions { private readonly IDatabaseFactory databaseFactory; + private readonly ILoggerFactory loggerFactory; - public ConfigureJwtBearerOptions(IDatabaseFactory databaseFactory) + public ConfigureJwtBearerOptions(IDatabaseFactory databaseFactory, ILoggerFactory loggerFactory) { this.databaseFactory = databaseFactory; + this.loggerFactory = loggerFactory; } public void Configure(JwtBearerOptions options) @@ -50,7 +53,7 @@ public void Configure(JwtBearerOptions options) if (userId != tokenUserId) { - Console.WriteLine("Token revoked or expired"); + loggerFactory.CreateLogger("JsonWebToken").LogInformation("Token revoked or expired"); context.Fail("Token has expired or been revoked"); } } diff --git a/osu.Server.Spectator/CodeAnalysis/BannedSymbols.txt b/osu.Server.Spectator/CodeAnalysis/BannedSymbols.txt new file mode 100644 index 00000000..78cd1816 --- /dev/null +++ b/osu.Server.Spectator/CodeAnalysis/BannedSymbols.txt @@ -0,0 +1,2 @@ +T:osu.Framework.Logging.Logger;Don't use osu!framework logger. Use Microsoft.Extensions.Logging.ILogger instead through DI. +T:System.Console;Don't use Console for logging. Use Microsoft.Extensions.Logging.ILogger instead through DI. diff --git a/osu.Server.Spectator/ConcurrentConnectionLimiter.cs b/osu.Server.Spectator/ConcurrentConnectionLimiter.cs index d6bd28e4..2fa99fb8 100644 --- a/osu.Server.Spectator/ConcurrentConnectionLimiter.cs +++ b/osu.Server.Spectator/ConcurrentConnectionLimiter.cs @@ -7,8 +7,8 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.SignalR; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; using osu.Framework.Extensions.TypeExtensions; -using osu.Framework.Logging; using osu.Game.Online; using osu.Server.Spectator.Entities; using osu.Server.Spectator.Extensions; @@ -21,16 +21,19 @@ public class ConcurrentConnectionLimiter : IHubFilter private readonly EntityStore connectionStates; private readonly IServiceProvider serviceProvider; + private readonly ILogger logger; private static readonly IEnumerable stateful_user_hubs = typeof(IStatefulUserHub).Assembly.GetTypes().Where(type => typeof(IStatefulUserHub).IsAssignableFrom(type) && typeof(Hub).IsAssignableFrom(type) && !type.IsInterface && !type.IsAbstract).ToArray(); public ConcurrentConnectionLimiter( EntityStore connectionStates, - IServiceProvider serviceProvider) + IServiceProvider serviceProvider, + ILoggerFactory loggerFactory) { this.connectionStates = connectionStates; this.serviceProvider = serviceProvider; + logger = loggerFactory.CreateLogger(nameof(ConcurrentConnectionLimiter)); } public async Task OnConnectedAsync(HubLifetimeContext context, Func next) @@ -83,8 +86,12 @@ private async Task registerConnection(HubLifetimeContext context) } } - private static void log(HubLifetimeContext context, string message) - => Logger.Log($"[user:{context.Context.GetUserId()}] [connection:{context.Context.ConnectionId}] [hub:{context.Hub.GetType().ReadableName()}] {message}"); + private void log(HubLifetimeContext context, string message) + => logger.LogInformation("[user:{user}] [connection:{connection}] [hub:{hub}] {message}", + context.Context.GetUserId(), + context.Context.ConnectionId, + context.Hub.GetType().ReadableName(), + message); public async ValueTask InvokeMethodAsync(HubInvocationContext invocationContext, Func> next) { diff --git a/osu.Server.Spectator/GracefulShutdownManager.cs b/osu.Server.Spectator/GracefulShutdownManager.cs index f75323c4..a943d232 100644 --- a/osu.Server.Spectator/GracefulShutdownManager.cs +++ b/osu.Server.Spectator/GracefulShutdownManager.cs @@ -4,10 +4,11 @@ using System; using System.Collections.Generic; using System.Linq; +using System.Text; using System.Threading; using System.Threading.Tasks; using Microsoft.Extensions.Hosting; -using osu.Framework.Logging; +using Microsoft.Extensions.Logging; using osu.Game.Online.Multiplayer; using osu.Server.Spectator.Entities; using osu.Server.Spectator.Hubs; @@ -30,6 +31,7 @@ public class GracefulShutdownManager private readonly List dependentStores = new List(); private readonly EntityStore roomStore; private readonly BuildUserCountUpdater buildUserCountUpdater; + private readonly ILogger logger; public GracefulShutdownManager( EntityStore roomStore, @@ -38,10 +40,12 @@ public GracefulShutdownManager( ScoreUploader scoreUploader, EntityStore connectionStateStore, EntityStore metadataClientStore, - BuildUserCountUpdater buildUserCountUpdater) + BuildUserCountUpdater buildUserCountUpdater, + ILoggerFactory loggerFactory) { this.roomStore = roomStore; this.buildUserCountUpdater = buildUserCountUpdater; + logger = loggerFactory.CreateLogger(nameof(GracefulShutdownManager)); dependentStores.Add(roomStore); dependentStores.Add(clientStateStore); @@ -58,7 +62,7 @@ public GracefulShutdownManager( private void shutdownSafely() { - Logger.Log("Server shutdown triggered"); + logger.LogInformation("Server shutdown triggered"); // stop tracking user counts. // it is presumed that another instance will take over doing so. @@ -78,6 +82,8 @@ await r.StartCountdown(new ServerShuttingDownCountdown TimeSpan timeWaited = new TimeSpan(); TimeSpan timeBetweenChecks = TimeSpan.FromSeconds(10); + var stringBuilder = new StringBuilder(); + while (timeWaited < TIME_BEFORE_FORCEFUL_SHUTDOWN) { var remaining = dependentStores.Select(store => (store.EntityName, store.RemainingUsages)); @@ -85,15 +91,17 @@ await r.StartCountdown(new ServerShuttingDownCountdown if (remaining.Sum(s => s.RemainingUsages) == 0) break; - Logger.Log("Waiting for usages of existing entities to finish..."); + stringBuilder.Clear(); + stringBuilder.AppendLine("Waiting for usages of existing entities to finish..."); foreach (var r in remaining) - Logger.Log($"{r.EntityName,10}: {r.RemainingUsages}"); + stringBuilder.AppendLine($"{r.EntityName,10}: {r.RemainingUsages}"); + logger.LogInformation(stringBuilder.ToString()); Thread.Sleep(timeBetweenChecks); timeWaited = timeWaited.Add(timeBetweenChecks); } - Logger.Log("All entities cleaned up. Server shutdown unblocking."); + logger.LogInformation("All entities cleaned up. Server shutdown unblocking."); } private async Task performOnAllRooms(Func action) diff --git a/osu.Server.Spectator/Hubs/ILogTarget.cs b/osu.Server.Spectator/Hubs/ILogTarget.cs index 978fb5d7..8021ac59 100644 --- a/osu.Server.Spectator/Hubs/ILogTarget.cs +++ b/osu.Server.Spectator/Hubs/ILogTarget.cs @@ -2,13 +2,13 @@ // See the LICENCE file in the repository root for full licence text. using System; -using osu.Framework.Logging; +using Microsoft.Extensions.Logging; namespace osu.Server.Spectator.Hubs { internal interface ILogTarget { - void Log(string message, LogLevel logLevel = LogLevel.Verbose); + void Log(string message, LogLevel logLevel = LogLevel.Information); void Error(string message, Exception exception); } diff --git a/osu.Server.Spectator/Hubs/LoggingHub.cs b/osu.Server.Spectator/Hubs/LoggingHub.cs index 2714e76b..16562175 100644 --- a/osu.Server.Spectator/Hubs/LoggingHub.cs +++ b/osu.Server.Spectator/Hubs/LoggingHub.cs @@ -5,7 +5,7 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.SignalR; -using osu.Framework.Logging; +using Microsoft.Extensions.Logging; using Sentry; using StatsdClient; @@ -16,16 +16,16 @@ public class LoggingHub : Hub, ILogTarget { protected string Name; - private readonly Logger logger; + private readonly ILogger logger; // ReSharper disable once StaticMemberInGenericType private static int totalConnected; - public LoggingHub() + public LoggingHub(ILoggerFactory loggerFactory) { Name = GetType().Name.Replace("Hub", string.Empty); - logger = Logger.GetLogger(Name); + logger = loggerFactory.CreateLogger(Name); } public override async Task OnConnectedAsync() @@ -43,9 +43,13 @@ public override async Task OnDisconnectedAsync(Exception? exception) await base.OnDisconnectedAsync(exception); } - protected void Log(string message, LogLevel logLevel = LogLevel.Verbose) => logger.Add($"[user:{getLoggableUserIdentifier()}] {message.Trim()}", logLevel); + protected void Log(string message, LogLevel logLevel = LogLevel.Information) => logger.Log(logLevel, "[user:{userId}] {message}", + getLoggableUserIdentifier(), + message.Trim()); - protected void Error(string message, Exception exception) => logger.Add($"[user:{getLoggableUserIdentifier()}] {message.Trim()}", LogLevel.Error, exception); + protected void Error(string message, Exception exception) => logger.LogError(exception, "[user:{userId}] {message)}", + getLoggableUserIdentifier(), + message.Trim()); private string getLoggableUserIdentifier() => Context.UserIdentifier ?? "???"; diff --git a/osu.Server.Spectator/Hubs/Metadata/BuildUserCountUpdater.cs b/osu.Server.Spectator/Hubs/Metadata/BuildUserCountUpdater.cs index e19bda63..f92aff11 100644 --- a/osu.Server.Spectator/Hubs/Metadata/BuildUserCountUpdater.cs +++ b/osu.Server.Spectator/Hubs/Metadata/BuildUserCountUpdater.cs @@ -7,7 +7,7 @@ using System.Text.RegularExpressions; using System.Threading; using System.Threading.Tasks; -using osu.Framework.Logging; +using Microsoft.Extensions.Logging; using osu.Server.Spectator.Database; using osu.Server.Spectator.Database.Models; using osu.Server.Spectator.Entities; @@ -23,19 +23,20 @@ public class BuildUserCountUpdater : IDisposable private readonly EntityStore clientStates; private readonly IDatabaseFactory databaseFactory; - private readonly Logger logger; + private readonly ILogger logger; private CancellationTokenSource? cancellationSource; public BuildUserCountUpdater( EntityStore clientStates, - IDatabaseFactory databaseFactory) + IDatabaseFactory databaseFactory, + ILoggerFactory loggerFactory) { this.clientStates = clientStates; this.databaseFactory = databaseFactory; cancellationSource = new CancellationTokenSource(); - logger = Logger.GetLogger(nameof(BuildUserCountUpdater)); + logger = loggerFactory.CreateLogger(nameof(BuildUserCountUpdater)); Task.Factory.StartNew(runUpdateLoop, TaskCreationOptions.LongRunning); } @@ -50,7 +51,7 @@ private void runUpdateLoop() } catch (Exception ex) { - logger.Add("Failed to update build user counts", LogLevel.Error, ex); + logger.LogError(ex, "Failed to update build user counts"); } Thread.Sleep(UpdateInterval); @@ -82,7 +83,7 @@ private async Task updateBuildUserCounts() if (buildsByHash.TryGetValue(versionHash, out var build)) newUserCounts[build] += userCount; else - logger.Add($"Unrecognised version hash {versionHash} reported by {userCount} clients. Skipping update."); + logger.LogInformation("Unrecognised version hash {versionHash} reported by {userCount} clients. Skipping update.", versionHash, userCount); } foreach (var (build, newUserCount) in newUserCounts) @@ -107,13 +108,13 @@ private Dictionary constructHashToBuildMapping(IEnumerable constructHashToBuildMapping(IEnumerable constructHashToBuildMapping(IEnumerable metadataHubContext) + public MetadataBroadcaster( + ILoggerFactory loggerFactory, + IDatabaseFactory databaseFactory, + IHubContext metadataHubContext) { this.databaseFactory = databaseFactory; this.metadataHubContext = metadataHubContext; + this.logger = loggerFactory.CreateLogger(nameof(MetadataBroadcaster)); timerCancellationSource = new CancellationTokenSource(); timerCancellationToken = timerCancellationSource.Token; @@ -50,18 +56,18 @@ private async void pollForChanges(object? sender, ElapsedEventArgs args) var updates = await db.GetUpdatedBeatmapSets(lastQueueId); lastQueueId = updates.LastProcessedQueueID; - Console.WriteLine($"Polled beatmap changes up to last queue id {updates.LastProcessedQueueID}"); + logger.LogInformation("Polled beatmap changes up to last queue id {lastProcessedQueueID}", updates.LastProcessedQueueID); if (updates.BeatmapSetIDs.Any()) { - Console.WriteLine($"Broadcasting new beatmaps to client: {string.Join(',', updates.BeatmapSetIDs.Select(i => i.ToString()))}"); + logger.LogInformation("Broadcasting new beatmaps to client: {beatmapIds}", string.Join(',', updates.BeatmapSetIDs.Select(i => i.ToString()))); await metadataHubContext.Clients.All.SendAsync(nameof(IMetadataClient.BeatmapSetsUpdated), updates, cancellationToken: timerCancellationToken); } } } catch (Exception e) { - Console.WriteLine($"Error during beatmap update polling: {e}"); + logger.LogError(e, $"Error during beatmap update polling"); } finally { diff --git a/osu.Server.Spectator/Hubs/Metadata/MetadataHub.cs b/osu.Server.Spectator/Hubs/Metadata/MetadataHub.cs index 30834e63..2b8db05b 100644 --- a/osu.Server.Spectator/Hubs/Metadata/MetadataHub.cs +++ b/osu.Server.Spectator/Hubs/Metadata/MetadataHub.cs @@ -6,6 +6,7 @@ using Microsoft.AspNetCore.SignalR; using Microsoft.Extensions.Caching.Distributed; using Microsoft.Extensions.Primitives; +using Microsoft.Extensions.Logging; using osu.Game.Online.Metadata; using osu.Game.Users; using osu.Server.Spectator.Database; @@ -22,11 +23,12 @@ public class MetadataHub : StatefulUserHub internal const string ONLINE_PRESENCE_WATCHERS_GROUP = "metadata:online-presence-watchers"; public MetadataHub( + ILoggerFactory loggerFactory, IDistributedCache cache, EntityStore userStates, IDatabaseFactory databaseFactory, IDailyChallengeUpdater dailyChallengeUpdater) - : base(cache, userStates) + : base(loggerFactory, cache, userStates) { this.databaseFactory = databaseFactory; this.dailyChallengeUpdater = dailyChallengeUpdater; diff --git a/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHub.cs b/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHub.cs index 8c3104e6..d9dfdf95 100644 --- a/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHub.cs +++ b/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHub.cs @@ -7,8 +7,8 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.SignalR; using Microsoft.Extensions.Caching.Distributed; +using Microsoft.Extensions.Logging; using Newtonsoft.Json; -using osu.Framework.Logging; using osu.Game.Online.API; using osu.Game.Online.Multiplayer; using osu.Game.Online.Multiplayer.Countdown; @@ -27,18 +27,20 @@ public class MultiplayerHub : StatefulUserHub rooms, - EntityStore users, - IDatabaseFactory databaseFactory, - ChatFilters chatFilters, - IHubContext hubContext) - : base(cache, users) + public MultiplayerHub( + ILoggerFactory loggerFactory, + IDistributedCache cache, + EntityStore rooms, + EntityStore users, + IDatabaseFactory databaseFactory, + ChatFilters chatFilters, + IHubContext hubContext) + : base(loggerFactory, cache, users) { Rooms = rooms; this.databaseFactory = databaseFactory; this.chatFilters = chatFilters; - HubContext = new MultiplayerHubContext(hubContext, rooms, users); + HubContext = new MultiplayerHubContext(hubContext, rooms, users, loggerFactory); } public Task JoinRoom(long roomId) => JoinRoomWithPassword(roomId, string.Empty); @@ -940,6 +942,6 @@ private async Task leaveRoom(MultiplayerClientState state, ItemUsage> GetRoom(long roomId) => Rooms.GetForUse(roomId); - protected void Log(ServerMultiplayerRoom room, string message, LogLevel logLevel = LogLevel.Verbose) => base.Log($"[room:{room.RoomID}] {message}", logLevel); + protected void Log(ServerMultiplayerRoom room, string message, LogLevel logLevel = LogLevel.Information) => base.Log($"[room:{room.RoomID}] {message}", logLevel); } } diff --git a/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHubContext.cs b/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHubContext.cs index 13f2d400..d9bf0be2 100644 --- a/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHubContext.cs +++ b/osu.Server.Spectator/Hubs/Multiplayer/MultiplayerHubContext.cs @@ -7,7 +7,7 @@ using System.Linq; using System.Threading.Tasks; using Microsoft.AspNetCore.SignalR; -using osu.Framework.Logging; +using Microsoft.Extensions.Logging; using osu.Game.Online; using osu.Game.Online.API; using osu.Game.Online.Multiplayer; @@ -30,15 +30,19 @@ public class MultiplayerHubContext : IMultiplayerHubContext private readonly IHubContext context; private readonly EntityStore rooms; private readonly EntityStore users; - private readonly Logger logger; + private readonly ILogger logger; - public MultiplayerHubContext(IHubContext context, EntityStore rooms, EntityStore users) + public MultiplayerHubContext( + IHubContext context, + EntityStore rooms, + EntityStore users, + ILoggerFactory loggerFactory) { this.context = context; this.rooms = rooms; this.users = users; - logger = Logger.GetLogger(nameof(MultiplayerHub).Replace("Hub", string.Empty)); + logger = loggerFactory.CreateLogger(nameof(MultiplayerHub).Replace("Hub", string.Empty)); } public Task NotifyNewMatchEvent(ServerMultiplayerRoom room, MatchServerEvent e) @@ -228,14 +232,19 @@ public async Task StartOrStopGameplay(ServerMultiplayerRoom room) await ChangeRoomState(room, anyUserPlaying ? MultiplayerRoomState.Playing : MultiplayerRoomState.Open); } - private void log(ServerMultiplayerRoom room, MultiplayerRoomUser? user, string message, LogLevel logLevel = LogLevel.Verbose) + private void log(ServerMultiplayerRoom room, MultiplayerRoomUser? user, string message, LogLevel logLevel = LogLevel.Information) { - logger.Add($"[user:{getLoggableUserIdentifier(user)}] [room:{room.RoomID}] {message.Trim()}", logLevel); + logger.Log(logLevel, "[user:{userId}] [room:{roomID}] {message}", + getLoggableUserIdentifier(user), + room.RoomID, + message.Trim()); } private void error(MultiplayerRoomUser? user, string message, Exception exception) { - logger.Add($"[user:{getLoggableUserIdentifier(user)}] {message.Trim()}", LogLevel.Error, exception); + logger.LogError(exception, "[user:{userId}] {message}", + getLoggableUserIdentifier(user), + message.Trim()); } private string getLoggableUserIdentifier(MultiplayerRoomUser? user) diff --git a/osu.Server.Spectator/Hubs/Spectator/ScoreProcessedSubscriber.cs b/osu.Server.Spectator/Hubs/Spectator/ScoreProcessedSubscriber.cs index 32faf5c2..c89bfe49 100644 --- a/osu.Server.Spectator/Hubs/Spectator/ScoreProcessedSubscriber.cs +++ b/osu.Server.Spectator/Hubs/Spectator/ScoreProcessedSubscriber.cs @@ -7,8 +7,8 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.SignalR; +using Microsoft.Extensions.Logging; using Newtonsoft.Json; -using osu.Framework.Logging; using osu.Game.Online.Spectator; using osu.Server.Spectator.Database; using osu.Server.Spectator.Database.Models; @@ -32,13 +32,14 @@ public sealed class ScoreProcessedSubscriber : IScoreProcessedSubscriber, IDispo private readonly ConcurrentDictionary subscriptions = new ConcurrentDictionary(); private readonly Timer timer; - private readonly Logger logger; + private readonly ILogger logger; private readonly IHubContext spectatorHubContext; public ScoreProcessedSubscriber( IDatabaseFactory databaseFactory, IConnectionMultiplexer redis, - IHubContext spectatorHubContext) + IHubContext spectatorHubContext, + ILoggerFactory loggerFactory) { this.databaseFactory = databaseFactory; this.spectatorHubContext = spectatorHubContext; @@ -51,7 +52,7 @@ public ScoreProcessedSubscriber( subscriber = redis.GetSubscriber(); subscriber.Subscribe(new RedisChannel("osu-channel:score:processed", RedisChannel.PatternMode.Literal), (_, message) => onMessageReceived(message)); - logger = Logger.GetLogger(nameof(ScoreProcessedSubscriber)); + logger = loggerFactory.CreateLogger(nameof(ScoreProcessedSubscriber)); } private void onMessageReceived(string? message) @@ -76,7 +77,7 @@ private void onMessageReceived(string? message) } catch (Exception ex) { - logger.Add($"Failed to process message {message}", LogLevel.Error, ex); + logger.LogError(ex, "Failed to process message"); DogStatsd.Increment($"{statsd_prefix}.messages.dropped"); } } @@ -113,7 +114,10 @@ public async Task RegisterForNotificationAsync(string receiverConnectionId, int } catch (Exception ex) { - logger.Add($"Failed to register connection {receiverConnectionId} for info about score {userId}:{scoreToken}", LogLevel.Error, ex); + logger.LogError(ex, "Failed to register connection {receiverConnectionId} for info about score {userId}:{scoreToken}", + receiverConnectionId, + userId, + scoreToken); DogStatsd.Increment($"{statsd_prefix}.subscriptions.failed"); } } diff --git a/osu.Server.Spectator/Hubs/Spectator/SpectatorHub.cs b/osu.Server.Spectator/Hubs/Spectator/SpectatorHub.cs index 60eddf6d..f58442a8 100644 --- a/osu.Server.Spectator/Hubs/Spectator/SpectatorHub.cs +++ b/osu.Server.Spectator/Hubs/Spectator/SpectatorHub.cs @@ -6,6 +6,7 @@ using System.Linq; using System.Threading.Tasks; using Microsoft.Extensions.Caching.Distributed; +using Microsoft.Extensions.Logging; using osu.Game.Beatmaps; using osu.Game.Online.API.Requests.Responses; using osu.Game.Database; @@ -36,12 +37,13 @@ public class SpectatorHub : StatefulUserHub users, IDatabaseFactory databaseFactory, ScoreUploader scoreUploader, IScoreProcessedSubscriber scoreProcessedSubscriber) - : base(cache, users) + : base(loggerFactory, cache, users) { this.databaseFactory = databaseFactory; this.scoreUploader = scoreUploader; diff --git a/osu.Server.Spectator/Hubs/StatefulUserHub.cs b/osu.Server.Spectator/Hubs/StatefulUserHub.cs index eb166197..699ef4af 100644 --- a/osu.Server.Spectator/Hubs/StatefulUserHub.cs +++ b/osu.Server.Spectator/Hubs/StatefulUserHub.cs @@ -7,6 +7,7 @@ using JetBrains.Annotations; using Microsoft.AspNetCore.Authorization; using Microsoft.Extensions.Caching.Distributed; +using Microsoft.Extensions.Logging; using osu.Game.Online; using osu.Server.Spectator.Entities; using osu.Server.Spectator.Extensions; @@ -21,7 +22,11 @@ public abstract class StatefulUserHub : LoggingHub { protected readonly EntityStore UserStates; - protected StatefulUserHub(IDistributedCache cache, EntityStore userStates) + protected StatefulUserHub( + ILoggerFactory loggerFactory, + IDistributedCache cache, + EntityStore userStates) + : base(loggerFactory) { UserStates = userStates; } diff --git a/osu.Server.Spectator/LoggingHubFilter.cs b/osu.Server.Spectator/LoggingHubFilter.cs index 14f8dc0e..c8739d0c 100644 --- a/osu.Server.Spectator/LoggingHubFilter.cs +++ b/osu.Server.Spectator/LoggingHubFilter.cs @@ -6,8 +6,8 @@ using System.Linq; using System.Threading.Tasks; using Microsoft.AspNetCore.SignalR; +using Microsoft.Extensions.Logging; using osu.Framework.Development; -using osu.Framework.Logging; using osu.Server.Spectator.Hubs; namespace osu.Server.Spectator diff --git a/osu.Server.Spectator/Program.cs b/osu.Server.Spectator/Program.cs index cd7e779b..cabbad98 100644 --- a/osu.Server.Spectator/Program.cs +++ b/osu.Server.Spectator/Program.cs @@ -2,15 +2,12 @@ // See the LICENCE file in the repository root for full licence text. using System; -using System.IO; using System.Net; using Microsoft.AspNetCore.Hosting; #if !DEBUG using Microsoft.AspNetCore.SignalR; #endif using Microsoft.Extensions.Hosting; -using osu.Framework.Logging; -using osu.Framework.Platform; using StatsdClient; namespace osu.Server.Spectator @@ -19,9 +16,6 @@ public static class Program { public static void Main(string[] args) { - Logger.GameIdentifier = "osu-server-spectator"; - Logger.Storage = new NativeStorage(Path.Combine(Environment.CurrentDirectory, "Logs")); - DogStatsd.Configure(new StatsdConfig { StatsdServerName = AppSettings.DataDogAgentHost, diff --git a/osu.Server.Spectator/Storage/FileScoreStorage.cs b/osu.Server.Spectator/Storage/FileScoreStorage.cs index 322c3097..d0cec652 100644 --- a/osu.Server.Spectator/Storage/FileScoreStorage.cs +++ b/osu.Server.Spectator/Storage/FileScoreStorage.cs @@ -1,9 +1,9 @@ // Copyright (c) ppy Pty Ltd . Licensed under the MIT Licence. // See the LICENCE file in the repository root for full licence text. -using System; using System.IO; using System.Threading.Tasks; +using Microsoft.Extensions.Logging; using osu.Game.Scoring; using osu.Game.Scoring.Legacy; @@ -11,13 +11,22 @@ namespace osu.Server.Spectator.Storage { public class FileScoreStorage : IScoreStorage { + private readonly ILogger logger; + + public FileScoreStorage(ILoggerFactory loggerFactory) + { + logger = loggerFactory.CreateLogger(nameof(FileScoreStorage)); + } + public Task WriteAsync(Score score) { var legacyEncoder = new LegacyScoreEncoder(score, null); string filename = score.ScoreInfo.OnlineID.ToString(); - Console.WriteLine($"Writing replay for score {score.ScoreInfo.OnlineID} to {filename}"); + logger.LogInformation("Writing replay for score {scoreId} to {filename}", + score.ScoreInfo.OnlineID, + filename); using (var outStream = File.Create(Path.Combine(AppSettings.ReplaysPath, filename))) legacyEncoder.Encode(outStream); diff --git a/osu.Server.Spectator/Storage/S3ScoreStorage.cs b/osu.Server.Spectator/Storage/S3ScoreStorage.cs index 077eaf6d..4d034ee8 100644 --- a/osu.Server.Spectator/Storage/S3ScoreStorage.cs +++ b/osu.Server.Spectator/Storage/S3ScoreStorage.cs @@ -1,10 +1,10 @@ // Copyright (c) ppy Pty Ltd . Licensed under the MIT Licence. // See the LICENCE file in the repository root for full licence text. -using System; using System.Globalization; using System.IO; using System.Threading.Tasks; +using Microsoft.Extensions.Logging; using osu.Game.Scoring; using osu.Game.Scoring.Legacy; @@ -12,6 +12,13 @@ namespace osu.Server.Spectator.Storage { public class S3ScoreStorage : IScoreStorage { + private readonly ILogger logger; + + public S3ScoreStorage(ILoggerFactory loggerFactory) + { + logger = loggerFactory.CreateLogger(nameof(S3ScoreStorage)); + } + public async Task WriteAsync(Score score) { using (var outStream = new MemoryStream()) @@ -20,7 +27,7 @@ public async Task WriteAsync(Score score) outStream.Seek(0, SeekOrigin.Begin); - Console.WriteLine($"Uploading replay for score {score.ScoreInfo.OnlineID}"); + logger.LogInformation($"Uploading replay for score {score.ScoreInfo.OnlineID}"); await S3.Upload(AppSettings.ReplaysBucket, score.ScoreInfo.OnlineID.ToString(CultureInfo.InvariantCulture), outStream, outStream.Length); } diff --git a/osu.Server.Spectator/osu.Server.Spectator.csproj b/osu.Server.Spectator/osu.Server.Spectator.csproj index fc168c15..114bdf5d 100644 --- a/osu.Server.Spectator/osu.Server.Spectator.csproj +++ b/osu.Server.Spectator/osu.Server.Spectator.csproj @@ -31,5 +31,9 @@ + + + +