From a3ca36cb54a3e6e743fbcf90f19f0d76ba71aebc Mon Sep 17 00:00:00 2001 From: Ionut Andrei Oanca Date: Mon, 16 Nov 2020 17:40:19 +0100 Subject: Review logging and minor changes in SyncPlay --- .../SyncPlay/GroupController.cs | 83 ++++++++++++---------- .../SyncPlay/SyncPlayManager.cs | 28 +++++--- 2 files changed, 62 insertions(+), 49 deletions(-) (limited to 'Emby.Server.Implementations') diff --git a/Emby.Server.Implementations/SyncPlay/GroupController.cs b/Emby.Server.Implementations/SyncPlay/GroupController.cs index 48596bb42..4efc671ff 100644 --- a/Emby.Server.Implementations/SyncPlay/GroupController.cs +++ b/Emby.Server.Implementations/SyncPlay/GroupController.cs @@ -28,7 +28,12 @@ namespace Emby.Server.Implementations.SyncPlay /// /// The logger. /// - private readonly ILogger _logger; + private readonly ILogger _logger; + + /// + /// The logger factory. + /// + private readonly ILoggerFactory _loggerFactory; /// /// The user manager. @@ -45,6 +50,12 @@ namespace Emby.Server.Implementations.SyncPlay /// private readonly ILibraryManager _libraryManager; + /// + /// The participants, or members of the group. + /// + private readonly Dictionary _participants = + new Dictionary(StringComparer.OrdinalIgnoreCase); + /// /// Internal group state. /// @@ -54,37 +65,41 @@ namespace Emby.Server.Implementations.SyncPlay /// /// Initializes a new instance of the class. /// - /// The logger. + /// The logger factory. /// The user manager. /// The session manager. /// The library manager. public GroupController( - ILogger logger, + ILoggerFactory loggerFactory, IUserManager userManager, ISessionManager sessionManager, ILibraryManager libraryManager) { - _logger = logger; + _loggerFactory = loggerFactory; _userManager = userManager; _sessionManager = sessionManager; _libraryManager = libraryManager; + _logger = loggerFactory.CreateLogger(); - _state = new IdleGroupState(_logger); + _state = new IdleGroupState(loggerFactory); } /// /// Gets the default ping value used for sessions. /// + /// The default ping. public long DefaultPing { get; } = 500; /// /// Gets the maximum time offset error accepted for dates reported by clients, in milliseconds. /// + /// The maximum time offset error. public long TimeSyncOffset { get; } = 2000; /// /// Gets the maximum offset error accepted for position reported by clients, in milliseconds. /// + /// The maximum offset error. public long MaxPlaybackOffset { get; } = 500; /// @@ -123,24 +138,16 @@ namespace Emby.Server.Implementations.SyncPlay /// The last activity. public DateTime LastActivity { get; set; } - /// - /// Gets the participants. - /// - /// The participants, or members of the group. - public Dictionary Participants { get; } = - new Dictionary(StringComparer.OrdinalIgnoreCase); - /// /// Adds the session to the group. /// /// The session. private void AddSession(SessionInfo session) { - Participants.TryAdd( + _participants.TryAdd( session.Id, - new GroupMember + new GroupMember(session) { - Session = session, Ping = DefaultPing, IsBuffering = false }); @@ -152,7 +159,7 @@ namespace Emby.Server.Implementations.SyncPlay /// The session. private void RemoveSession(SessionInfo session) { - Participants.Remove(session.Id); + _participants.Remove(session.Id); } /// @@ -166,14 +173,14 @@ namespace Emby.Server.Implementations.SyncPlay return type switch { SyncPlayBroadcastType.CurrentSession => new SessionInfo[] { from }, - SyncPlayBroadcastType.AllGroup => Participants + SyncPlayBroadcastType.AllGroup => _participants .Values .Select(session => session.Session), - SyncPlayBroadcastType.AllExceptCurrentSession => Participants + SyncPlayBroadcastType.AllExceptCurrentSession => _participants .Values .Select(session => session.Session) .Where(session => !session.Id.Equals(from.Id, StringComparison.OrdinalIgnoreCase)), - SyncPlayBroadcastType.AllReady => Participants + SyncPlayBroadcastType.AllReady => _participants .Values .Where(session => !session.IsBuffering) .Select(session => session.Session), @@ -204,7 +211,7 @@ namespace Emby.Server.Implementations.SyncPlay private bool HasAccessToQueue(User user, IReadOnlyList queue) { // Check if queue is empty. - if (!queue?.Any() ?? true) + if (queue == null || queue.Count == 0) { return true; } @@ -229,13 +236,13 @@ namespace Emby.Server.Implementations.SyncPlay private bool AllUsersHaveAccessToQueue(IReadOnlyList queue) { // Check if queue is empty. - if (!queue?.Any() ?? true) + if (queue == null || queue.Count == 0) { return true; } // Get list of users. - var users = Participants + var users = _participants .Values .Select(participant => _userManager.GetUserById(participant.Session.UserId)); @@ -247,7 +254,7 @@ namespace Emby.Server.Implementations.SyncPlay } /// - public bool IsGroupEmpty() => Participants.Count == 0; + public bool IsGroupEmpty() => _participants.Count == 0; /// public void CreateGroup(SessionInfo session, NewGroupRequest request, CancellationToken cancellationToken) @@ -268,8 +275,8 @@ namespace Emby.Server.Implementations.SyncPlay RunTimeTicks = session.FullNowPlayingItem.RunTimeTicks ?? 0; PositionTicks = session.PlayState.PositionTicks ?? 0; - // Mantain playstate. - var waitingState = new WaitingGroupState(_logger) + // Maintain playstate. + var waitingState = new WaitingGroupState(_loggerFactory) { ResumePlaying = !session.PlayState.IsPaused }; @@ -281,7 +288,7 @@ namespace Emby.Server.Implementations.SyncPlay _state.SessionJoined(this, _state.Type, session, cancellationToken); - _logger.LogInformation("InitGroup: {SessionId} created group {GroupId}.", session.Id, GroupId.ToString()); + _logger.LogInformation("Session {SessionId} created group {GroupId}.", session.Id, GroupId.ToString()); } /// @@ -297,7 +304,7 @@ namespace Emby.Server.Implementations.SyncPlay _state.SessionJoined(this, _state.Type, session, cancellationToken); - _logger.LogInformation("SessionJoin: {SessionId} joined group {GroupId}.", session.Id, GroupId.ToString()); + _logger.LogInformation("Session {SessionId} joined group {GroupId}.", session.Id, GroupId.ToString()); } /// @@ -311,7 +318,7 @@ namespace Emby.Server.Implementations.SyncPlay _state.SessionJoined(this, _state.Type, session, cancellationToken); - _logger.LogInformation("SessionRestore: {SessionId} re-joined group {GroupId}.", session.Id, GroupId.ToString()); + _logger.LogInformation("Session {SessionId} re-joined group {GroupId}.", session.Id, GroupId.ToString()); } /// @@ -327,7 +334,7 @@ namespace Emby.Server.Implementations.SyncPlay var updateOthers = NewSyncPlayGroupUpdate(GroupUpdateType.UserLeft, session.UserName); SendGroupUpdate(session, SyncPlayBroadcastType.AllExceptCurrentSession, updateOthers, cancellationToken); - _logger.LogInformation("SessionLeave: {SessionId} left group {GroupId}.", session.Id, GroupId.ToString()); + _logger.LogInformation("Session {SessionId} left group {GroupId}.", session.Id, GroupId.ToString()); } /// @@ -336,14 +343,14 @@ namespace Emby.Server.Implementations.SyncPlay // The server's job is to maintain a consistent state for clients to reference // and notify clients of state changes. The actual syncing of media playback // happens client side. Clients are aware of the server's time and use it to sync. - _logger.LogInformation("HandleRequest: {SessionId} requested {RequestType}, group {GroupId} is {StateType}.", session.Id, request.Type, GroupId.ToString(), _state.Type); + _logger.LogInformation("Session {SessionId} requested {RequestType} in group {GroupId} that is {StateType}.", session.Id, request.Type, GroupId.ToString(), _state.Type); request.Apply(this, _state, session, cancellationToken); } /// public GroupInfoDto GetInfo() { - var participants = Participants.Values.Select(session => session.Session.UserName).Distinct().ToList(); + var participants = _participants.Values.Select(session => session.Session.UserName).Distinct().ToList(); return new GroupInfoDto(GroupId, GroupName, _state.Type, participants, DateTime.UtcNow); } @@ -357,7 +364,7 @@ namespace Emby.Server.Implementations.SyncPlay /// public void SetIgnoreGroupWait(SessionInfo session, bool ignoreGroupWait) { - if (Participants.TryGetValue(session.Id, out GroupMember value)) + if (_participants.TryGetValue(session.Id, out GroupMember value)) { value.IgnoreGroupWait = ignoreGroupWait; } @@ -366,7 +373,7 @@ namespace Emby.Server.Implementations.SyncPlay /// public void SetState(IGroupState state) { - _logger.LogInformation("SetState: {GroupId} switching from {FromStateType} to {ToStateType}.", GroupId.ToString(), _state.Type, state.Type); + _logger.LogInformation("Group {GroupId} switching from {FromStateType} to {ToStateType}.", GroupId.ToString(), _state.Type, state.Type); this._state = state; } @@ -426,7 +433,7 @@ namespace Emby.Server.Implementations.SyncPlay /// public void UpdatePing(SessionInfo session, long ping) { - if (Participants.TryGetValue(session.Id, out GroupMember value)) + if (_participants.TryGetValue(session.Id, out GroupMember value)) { value.Ping = ping; } @@ -436,7 +443,7 @@ namespace Emby.Server.Implementations.SyncPlay public long GetHighestPing() { long max = long.MinValue; - foreach (var session in Participants.Values) + foreach (var session in _participants.Values) { max = Math.Max(max, session.Ping); } @@ -447,7 +454,7 @@ namespace Emby.Server.Implementations.SyncPlay /// public void SetBuffering(SessionInfo session, bool isBuffering) { - if (Participants.TryGetValue(session.Id, out GroupMember value)) + if (_participants.TryGetValue(session.Id, out GroupMember value)) { value.IsBuffering = isBuffering; } @@ -456,7 +463,7 @@ namespace Emby.Server.Implementations.SyncPlay /// public void SetAllBuffering(bool isBuffering) { - foreach (var session in Participants.Values) + foreach (var session in _participants.Values) { session.IsBuffering = isBuffering; } @@ -465,7 +472,7 @@ namespace Emby.Server.Implementations.SyncPlay /// public bool IsBuffering() { - foreach (var session in Participants.Values) + foreach (var session in _participants.Values) { if (session.IsBuffering && !session.IgnoreGroupWait) { diff --git a/Emby.Server.Implementations/SyncPlay/SyncPlayManager.cs b/Emby.Server.Implementations/SyncPlay/SyncPlayManager.cs index ee75580cc..fdaa12a04 100644 --- a/Emby.Server.Implementations/SyncPlay/SyncPlayManager.cs +++ b/Emby.Server.Implementations/SyncPlay/SyncPlayManager.cs @@ -21,6 +21,11 @@ namespace Emby.Server.Implementations.SyncPlay /// private readonly ILogger _logger; + /// + /// The logger factory. + /// + private readonly ILoggerFactory _loggerFactory; + /// /// The user manager. /// @@ -58,20 +63,21 @@ namespace Emby.Server.Implementations.SyncPlay /// /// Initializes a new instance of the class. /// - /// The logger. + /// The logger factory. /// The user manager. /// The session manager. /// The library manager. public SyncPlayManager( - ILogger logger, + ILoggerFactory loggerFactory, IUserManager userManager, ISessionManager sessionManager, ILibraryManager libraryManager) { - _logger = logger; + _loggerFactory = loggerFactory; _userManager = userManager; _sessionManager = sessionManager; _libraryManager = libraryManager; + _logger = loggerFactory.CreateLogger(); _sessionManager.SessionStarted += OnSessionManagerSessionStarted; } @@ -98,7 +104,7 @@ namespace Emby.Server.Implementations.SyncPlay LeaveGroup(session, cancellationToken); } - var group = new GroupController(_logger, _userManager, _sessionManager, _libraryManager); + var group = new GroupController(_loggerFactory, _userManager, _sessionManager, _libraryManager); _groups[group.GroupId] = group; AddSessionToGroup(session, group); @@ -123,7 +129,7 @@ namespace Emby.Server.Implementations.SyncPlay if (group == null) { - _logger.LogWarning("JoinGroup: {SessionId} tried to join group {GroupId} that does not exist.", session.Id, groupId); + _logger.LogWarning("Session {SessionId} tried to join group {GroupId} that does not exist.", session.Id, groupId); var error = new GroupUpdate(Guid.Empty, GroupUpdateType.GroupDoesNotExist, string.Empty); _sessionManager.SendSyncPlayGroupUpdate(session, error, CancellationToken.None); @@ -132,7 +138,7 @@ namespace Emby.Server.Implementations.SyncPlay if (!group.HasAccessToPlayQueue(user)) { - _logger.LogWarning("JoinGroup: {SessionId} does not have access to some content from the playing queue of group {GroupId}.", session.Id, group.GroupId.ToString()); + _logger.LogWarning("Session {SessionId} tried to join group {GroupId} but does not have access to some content of the playing queue.", session.Id, group.GroupId.ToString()); var error = new GroupUpdate(group.GroupId, GroupUpdateType.LibraryAccessDenied, string.Empty); _sessionManager.SendSyncPlayGroupUpdate(session, error, CancellationToken.None); @@ -171,7 +177,7 @@ namespace Emby.Server.Implementations.SyncPlay if (group == null) { - _logger.LogWarning("LeaveGroup: {SessionId} does not belong to any group.", session.Id); + _logger.LogWarning("Session {SessionId} does not belong to any group.", session.Id); var error = new GroupUpdate(Guid.Empty, GroupUpdateType.NotInGroup, string.Empty); _sessionManager.SendSyncPlayGroupUpdate(session, error, CancellationToken.None); @@ -183,7 +189,7 @@ namespace Emby.Server.Implementations.SyncPlay if (group.IsGroupEmpty()) { - _logger.LogInformation("LeaveGroup: removing empty group {GroupId}.", group.GroupId); + _logger.LogInformation("Group {GroupId} is empty, removing it.", group.GroupId); _groups.Remove(group.GroupId, out _); } } @@ -225,7 +231,7 @@ namespace Emby.Server.Implementations.SyncPlay if (group == null) { - _logger.LogWarning("HandleRequest: {SessionId} does not belong to any group.", session.Id); + _logger.LogWarning("Session {SessionId} does not belong to any group.", session.Id); var error = new GroupUpdate(Guid.Empty, GroupUpdateType.NotInGroup, string.Empty); _sessionManager.SendSyncPlayGroupUpdate(session, error, CancellationToken.None); @@ -370,7 +376,7 @@ namespace Emby.Server.Implementations.SyncPlay if (user.SyncPlayAccess == SyncPlayAccess.None) { - _logger.LogWarning("IsRequestValid: {SessionId} does not have access to SyncPlay. Requested {RequestType}.", session.Id, requestType); + _logger.LogWarning("Session {SessionId} requested {RequestType} but does not have access to SyncPlay.", session.Id, requestType); // TODO: rename to a more generic error. Next PR will fix this. var error = new GroupUpdate(Guid.Empty, GroupUpdateType.JoinGroupDenied, string.Empty); @@ -380,7 +386,7 @@ namespace Emby.Server.Implementations.SyncPlay if (requestType.Equals(GroupRequestType.NewGroup) && user.SyncPlayAccess != SyncPlayAccess.CreateAndJoinGroups) { - _logger.LogWarning("IsRequestValid: {SessionId} does not have permission to create groups.", session.Id); + _logger.LogWarning("Session {SessionId} does not have permission to create groups.", session.Id); var error = new GroupUpdate(Guid.Empty, GroupUpdateType.CreateGroupDenied, string.Empty); _sessionManager.SendSyncPlayGroupUpdate(session, error, CancellationToken.None); -- cgit v1.2.3