Added system info and background task start/stop to logs

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<Task> LoggedOut { add { _loggedOutEvent.Add(value); } remove { _loggedOutEvent.Remove(value); } }
         private readonly AsyncEvent<Func<Task>> _loggedOutEvent = new AsyncEvent<Func<Task>>();
 
-        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
         }
         /// <inheritdoc />
         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;
 

src/Discord.Net/DiscordSocketClient.cs

@@ -450,7 +450,7 @@ namespace Discord
                             var data = (payload as JToken).ToObject<HelloEvent>(_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()
         {

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();
+                if (clearBuilder)
-                builder.EnsureCapacity(maxLength);
+                {
+                    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('[');
+                if (padSource.HasValue)
-                builder.Append(sourceName);
+                {
-                builder.Append("] ");
+                    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);
             }
 

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"
   },