diff --git a/src/Discord.Net/DiscordClient.cs b/src/Discord.Net/DiscordClient.cs index c9ed91a65..e059f3950 100644 --- a/src/Discord.Net/DiscordClient.cs +++ b/src/Discord.Net/DiscordClient.cs @@ -9,6 +9,7 @@ using System.IO; using System.Linq; using System.Threading; using System.Threading.Tasks; +using System.Runtime.InteropServices; namespace Discord { @@ -24,11 +25,12 @@ namespace Discord public event Func LoggedOut { add { _loggedOutEvent.Add(value); } remove { _loggedOutEvent.Remove(value); } } private readonly AsyncEvent> _loggedOutEvent = new AsyncEvent>(); - internal readonly ILogger _discordLogger, _restLogger, _queueLogger; + internal readonly ILogger _clientLogger, _restLogger, _queueLogger; internal readonly SemaphoreSlim _connectionLock; internal readonly RequestQueue _requestQueue; internal bool _isDisposed; internal SelfUser _currentUser; + private bool _isFirstLogSub; public API.DiscordApiClient ApiClient { get; } internal LogManager LogManager { get; } @@ -41,9 +43,10 @@ namespace Discord { LogManager = new LogManager(config.LogLevel); LogManager.Message += async msg => await _logEvent.InvokeAsync(msg).ConfigureAwait(false); - _discordLogger = LogManager.CreateLogger("Discord"); + _clientLogger = LogManager.CreateLogger("Client"); _restLogger = LogManager.CreateLogger("Rest"); _queueLogger = LogManager.CreateLogger("Queue"); + _isFirstLogSub = true; _connectionLock = new SemaphoreSlim(1, 1); @@ -73,6 +76,12 @@ namespace Discord } private async Task LoginInternalAsync(TokenType tokenType, string token, bool validateToken) { + if (_isFirstLogSub) + { + _isFirstLogSub = false; + await WriteInitialLog().ConfigureAwait(false); + } + if (LoginState != LoginState.LoggedOut) await LogoutInternalAsync().ConfigureAwait(false); LoginState = LoginState.LoggingIn; @@ -276,7 +285,28 @@ namespace Discord } /// public void Dispose() => Dispose(true); - + + protected async Task WriteInitialLog() + { + if (this is DiscordSocketClient) + await _clientLogger.InfoAsync($"DiscordSocketClient v{DiscordConfig.Version} (Gateway v{DiscordConfig.GatewayAPIVersion}, {DiscordConfig.GatewayEncoding})").ConfigureAwait(false); + else + await _clientLogger.InfoAsync($"DiscordClient v{DiscordConfig.Version}").ConfigureAwait(false); + await _clientLogger.VerboseAsync($"Runtime: {RuntimeInformation.FrameworkDescription.Trim()} ({ToArchString(RuntimeInformation.ProcessArchitecture)})").ConfigureAwait(false); + await _clientLogger.VerboseAsync($"OS: {RuntimeInformation.OSDescription.Trim()} ({ToArchString(RuntimeInformation.OSArchitecture)})").ConfigureAwait(false); + await _clientLogger.VerboseAsync($"Processors: {Environment.ProcessorCount}").ConfigureAwait(false); + } + + private static string ToArchString(Architecture arch) + { + switch (arch) + { + case Architecture.X64: return "x64"; + case Architecture.X86: return "x86"; + default: return arch.ToString(); + } + } + ConnectionState IDiscordClient.ConnectionState => ConnectionState.Disconnected; ILogManager IDiscordClient.LogManager => LogManager; diff --git a/src/Discord.Net/DiscordSocketClient.cs b/src/Discord.Net/DiscordSocketClient.cs index 5d3194dd8..cc9040cdb 100644 --- a/src/Discord.Net/DiscordSocketClient.cs +++ b/src/Discord.Net/DiscordSocketClient.cs @@ -450,7 +450,7 @@ namespace Discord var data = (payload as JToken).ToObject(_serializer); _heartbeatTime = 0; - _heartbeatTask = RunHeartbeatAsync(data.HeartbeatInterval, _cancelToken.Token); + _heartbeatTask = RunHeartbeatAsync(data.HeartbeatInterval, _cancelToken.Token, _clientLogger); } break; case GatewayOpCode.Heartbeat: @@ -526,7 +526,7 @@ namespace Discord _lastGuildAvailableTime = Environment.TickCount; DataStore = dataStore; - _guildDownloadTask = WaitForGuildsAsync(_cancelToken.Token); + _guildDownloadTask = WaitForGuildsAsync(_cancelToken.Token, _clientLogger); await _readyEvent.InvokeAsync().ConfigureAwait(false); await SyncGuildsAsync().ConfigureAwait(false); @@ -1231,11 +1231,12 @@ namespace Discord #endif } - private async Task RunHeartbeatAsync(int intervalMillis, CancellationToken cancelToken) + private async Task RunHeartbeatAsync(int intervalMillis, CancellationToken cancelToken, ILogger logger) { //Clean this up when Discord's session patch is live try { + await logger.DebugAsync("Heartbeat Started").ConfigureAwait(false); while (!cancelToken.IsCancellationRequested) { await Task.Delay(intervalMillis, cancelToken).ConfigureAwait(false); @@ -1253,13 +1254,19 @@ namespace Discord _heartbeatTime = Environment.TickCount; await ApiClient.SendHeartbeatAsync(_lastSeq).ConfigureAwait(false); } + await logger.DebugAsync("Heartbeat Stopped").ConfigureAwait(false); + } + catch (OperationCanceledException ex) + { + await logger.DebugAsync("Heartbeat Stopped", ex).ConfigureAwait(false); } - catch (OperationCanceledException) { } } - private async Task WaitForGuildsAsync(CancellationToken cancelToken) + private async Task WaitForGuildsAsync(CancellationToken cancelToken, ILogger logger) { + await logger.DebugAsync("GuildDownloader Started").ConfigureAwait(false); while ((_unavailableGuilds != 0) && (Environment.TickCount - _lastGuildAvailableTime < 2000)) await Task.Delay(500, cancelToken).ConfigureAwait(false); + await logger.DebugAsync("GuildDownloader Stopped").ConfigureAwait(false); } private async Task SyncGuildsAsync() { diff --git a/src/Discord.Net/Logging/LogMessage.cs b/src/Discord.Net/Logging/LogMessage.cs index 14bc4e263..938becb29 100644 --- a/src/Discord.Net/Logging/LogMessage.cs +++ b/src/Discord.Net/Logging/LogMessage.cs @@ -20,26 +20,64 @@ namespace Discord public override string ToString() => ToString(null, true); - public string ToString(StringBuilder builder = null, bool fullException = true) + public string ToString(StringBuilder builder = null, bool fullException = true, bool prependTimestamp = true, bool clearBuilder = true, DateTimeKind timestampKind = DateTimeKind.Local, int? padSource = 7) { string sourceName = Source; string message = Message; string exMessage = fullException ? Exception?.ToString() : Exception?.Message; - int maxLength = 1 + (sourceName?.Length ?? 0) + 2 + (message?.Length ?? 0) + 3 + (exMessage?.Length ?? 0); + int maxLength = 1 + + (prependTimestamp ? 8 : 0) + 1 + + (padSource.HasValue ? padSource.Value : sourceName?.Length ?? 0) + 1 + + (message?.Length ?? 0) + + (exMessage?.Length ?? 0) + 3; + if (builder == null) builder = new StringBuilder(maxLength); else { - builder.Clear(); - builder.EnsureCapacity(maxLength); + if (clearBuilder) + { + builder.Clear(); + builder.EnsureCapacity(maxLength); + } } + if (prependTimestamp) + { + DateTime now; + if (timestampKind == DateTimeKind.Utc) + now = DateTime.UtcNow; + else + now = DateTime.Now; + if (now.Hour < 10) + builder.Append('0'); + builder.Append(now.Hour); + builder.Append(':'); + if (now.Minute < 10) + builder.Append('0'); + builder.Append(now.Minute); + builder.Append(':'); + if (now.Second < 10) + builder.Append('0'); + builder.Append(now.Second); + builder.Append(' '); + } if (sourceName != null) { - builder.Append('['); - builder.Append(sourceName); - builder.Append("] "); + if (padSource.HasValue) + { + if (sourceName.Length < padSource.Value) + { + builder.Append(sourceName); + builder.Append(' ', padSource.Value - sourceName.Length); + } + else if (sourceName.Length > padSource.Value) + builder.Append(sourceName.Substring(0, padSource.Value)); + else + builder.Append(sourceName); + } + builder.Append(' '); } if (!string.IsNullOrEmpty(Message)) { @@ -53,7 +91,8 @@ namespace Discord } if (exMessage != null) { - builder.AppendLine(":"); + builder.Append(':'); + builder.AppendLine(); builder.Append(exMessage); } diff --git a/src/Discord.Net/project.json b/src/Discord.Net/project.json index ceac7be0a..a47612f05 100644 --- a/src/Discord.Net/project.json +++ b/src/Discord.Net/project.json @@ -31,6 +31,7 @@ "System.Net.WebSockets.Client": "4.0.0", "System.Reflection.Extensions": "4.0.1", "System.Runtime.InteropServices": "4.1.0", + "System.Runtime.InteropServices.RuntimeInformation": "4.0.0", "System.Runtime.Serialization.Primitives": "4.1.1", "System.Text.RegularExpressions": "4.1.0" },