First commit of LoggingService

Kerobot/InstanceConfig.cs

@@ -30,7 +30,15 @@ namespace Kerobot
         /// </remarks>
         internal string PostgresConnString => _pgSqlConnectionString;
 
-        // TODO add fields for services to be configurable: DMRelay, InstanceLog
+        const string JInstanceLogReportTarget = "LogTarget";
+        readonly ulong _ilReptGuild, _ilReptChannel;
+        /// <summary>
+        /// Guild and channel ID, respectively, for instance log reporting.
+        /// Specified as "(guild ID)/(channel ID)".
+        /// </summary>
+        internal (ulong, ulong) InstanceLogReportTarget => (_ilReptGuild, _ilReptChannel);
+
+        // TODO add fields for services to be configurable: DMRelay
 
         /// <summary>
         /// Sets up instance configuration object from file and command line parameters.
@@ -63,10 +71,32 @@ namespace Kerobot
             // Input validation - throw exception on errors. Exception messages printed as-is.
             _botToken = conf[JBotToken]?.Value<string>();
             if (string.IsNullOrEmpty(_botToken))
-                throw new Exception($"'{JBotToken}' was not properly specified in configuration.");
+                throw new Exception($"'{JBotToken}' is not properly specified in configuration.");
             _pgSqlConnectionString = conf[JPgSqlConnectionString]?.Value<string>();
             if (string.IsNullOrEmpty(_pgSqlConnectionString))
-                throw new Exception($"'{JPgSqlConnectionString}' was not properly specified in configuration.");
+                throw new Exception($"'{JPgSqlConnectionString}' is not properly specified in configuration.");
+
+            var ilInput = conf[JInstanceLogReportTarget]?.Value<string>();
+            if (!string.IsNullOrWhiteSpace(ilInput))
+            {
+                int idx = ilInput.IndexOf('/');
+                if (idx < 0) throw new Exception($"'{JInstanceLogReportTarget}' is not properly specified in configuration.");
+                try
+                {
+                    _ilReptGuild = ulong.Parse(ilInput.Substring(0, idx));
+                    _ilReptChannel = ulong.Parse(ilInput.Substring(idx + 1, ilInput.Length - (idx + 1)));
+                }
+                catch (FormatException)
+                {
+                    throw new Exception($"'{JInstanceLogReportTarget}' is not properly specified in configuration.");
+                }
+            }
+            else
+            {
+                // Feature is disabled
+                _ilReptGuild = 0;
+                _ilReptChannel = 0;
+            }
         }
     }
 }

Kerobot/Kerobot.cs

@@ -1,8 +1,6 @@
-using Discord;
-using Discord.WebSocket;
+using Discord.WebSocket;
 using Kerobot.Services;
 using Npgsql;
-using System;
 using System.Collections.Generic;
 using System.Threading.Tasks;
 
@@ -15,10 +13,11 @@ namespace Kerobot
     public partial class Kerobot
     {
         // Partial class: Services are able to add their own methods and properties to this class.
-        // This is to prevent this file from having too many references to many different and unrelated features.
+        // This is to prevent this file from having too many references to different and unrelated features.
 
         private readonly InstanceConfig _icfg;
         private readonly DiscordSocketClient _client;
+        private IReadOnlyCollection<Service> _services; // all services in an iterable format
 
         /// <summary>
         /// Gets application instance configuration.
@@ -34,14 +33,31 @@ namespace Kerobot
             _icfg = conf;
             _client = client;
 
+            // 'Ready' event handler. Because there's no other place for it.
+            _client.Ready += async delegate
+            {
+                await InstanceLogAsync(true, "Kerobot", "Connected and ready.");
+            };
+
             InitializeServices();
-            
-            // and prepare modules here
+
+            // TODO prepare modules here
+
+            // Everything's ready to go by now. Print the welcome message here.
+            var ver = System.Reflection.Assembly.GetExecutingAssembly().GetName().Version;
+            InstanceLogAsync(false, "Kerobot",
+                $"This is Kerobot v{ver.ToString(3)}. https://github.com/Noikoio/Kerobot").Wait();
         }
 
         private void InitializeServices()
         {
-            throw new NotImplementedException();
+            var svcList = new List<Service>();
+
+            // Put services here as they become usable.
+            _svcLogging = new Services.Logging.LoggingService(this);
+            svcList.Add(_svcLogging);
+
+            _services = svcList.AsReadOnly();
         }
 
         /// <summary>

Kerobot/Program.cs

@@ -6,7 +6,7 @@ using System.Threading.Tasks;
 namespace Kerobot
 {
     /// <summary>
-    /// Program startup class. Does initialization before starting the Discord client.
+    /// Program startup class.
     /// </summary>
     class Program
     {
@@ -18,12 +18,15 @@ namespace Kerobot
         
         static Kerobot _main;
         
+        /// <summary>
+        /// Entry point. Loads options, initializes all components, then connects to Discord.
+        /// </summary>
         static async Task Main(string[] args)
         {
             _startTime = DateTimeOffset.UtcNow;
             Console.WriteLine("Bot start time: " + _startTime.ToString("u"));
 
-            // Get instance config figured out
+            // Get instance configuration from file and parameters
             var opts = Options.ParseOptions(args); // Program can exit here.
             InstanceConfig cfg;
             try
@@ -37,7 +40,7 @@ namespace Kerobot
                 return;
             }
 
-            // Quick test if database configuration works
+            // Quick test of database configuration
             try
             {
                 using (var d = new Npgsql.NpgsqlConnection(cfg.PostgresConnString))
@@ -77,13 +80,21 @@ namespace Kerobot
 
         private static void Console_CancelKeyPress(object sender, ConsoleCancelEventArgs e)
         {
-            // TODO finish implementation when logging is set up
             e.Cancel = true;
-            // _main.Log("Received Cancel event. Application will shut down...");
-            // stop periodic task processing - wait for current run to finish if executing (handled by service?)
-            // notify services of shutdown
-            bool success = _main.DiscordClient.LogoutAsync().Wait(10000);
-            // if (!success) _main.Log("Failed to disconnect cleanly from Discord. Will force shut down.");
+
+            _main.InstanceLogAsync(true, "Kerobot", "Shutting down. Reason: Interrupt signal.");
+
+            // 5 seconds of leeway - any currently running tasks will need time to finish executing
+            var leeway = Task.Delay(5000);
+
+            // TODO periodic task service: stop processing, wait for all tasks to finish
+            // TODO notify services of shutdown
+
+            leeway.Wait();
+            
+            bool success = _main.DiscordClient.StopAsync().Wait(1000);
+            if (!success) _main.InstanceLogAsync(false, "Kerobot",
+                "Failed to disconnect cleanly from Discord. Will force shut down.").Wait();
             Environment.Exit(0);
         }
     }

Kerobot/Services/Logging/Kerobot_hooks.cs

@@ -0,0 +1,28 @@
+using Kerobot.Services.Logging;
+using System.Threading.Tasks;
+
+namespace Kerobot
+{
+    partial class Kerobot
+    {
+        LoggingService _svcLogging;
+
+        /// <summary>
+        /// Appends a log message to the instance log.
+        /// </summary>
+        /// <param name="report">Specifies if the message should be sent to the dedicated logging channel on Discord.</param>
+        /// <param name="source">Name of the subsystem from which the log message originated.</param>
+        /// <param name="message">The log message to append. Multi-line messages are acceptable.</param>
+        public Task InstanceLogAsync(bool report, string source, string message)
+            => _svcLogging.DoInstanceLogAsync(report, source, message);
+
+        /// <summary>
+        /// Appends a log message to the guild-specific log.
+        /// </summary>
+        /// <param name="guild">The guild ID associated with this message.</param>
+        /// <param name="source">Name of the subsystem from which the log message originated.</param>
+        /// <param name="message">The log message to append. Multi-line messages are acceptable.</param>
+        public Task GuildLogAsync(ulong guild, string source, string message)
+            => _svcLogging.DoGuildLogAsync(guild, source, message);
+    }
+}

Kerobot/Services/Logging/LoggingService.cs

@@ -0,0 +1,188 @@
+using Discord;
+using Npgsql;
+using NpgsqlTypes;
+using System;
+using System.Threading.Tasks;
+
+namespace Kerobot.Services.Logging
+{
+    /// <summary>
+    /// Implements logging for the whole program.
+    /// </summary>
+    class LoggingService : Service
+    {
+        // Note: Service.Log's functionality is implemented here. Don't use it within this class.
+        // If necessary, use DoInstanceLogAsync instead.
+
+        internal LoggingService(Kerobot kb) : base(kb)
+        {
+            // Create global instance log table
+            async Task CreateGlobalTable()
+            {
+                using (var db = await Kerobot.GetOpenNpgsqlConnectionAsync(null))
+                    await CreateDatabaseTablesAsync(db);
+            }
+            CreateGlobalTable().Wait();
+
+            // Discord.Net log handling (client logging option is specified in Program.cs)
+            kb.DiscordClient.Log += DiscordClient_Log;
+        }
+
+        /// <summary>
+        /// Discord.Net logging events handled here.
+        /// Only events with high severity are placed in the log. Others are just printed to console.
+        /// </summary>
+        private async Task DiscordClient_Log(LogMessage arg)
+        {
+            var ts = DateTimeOffset.UtcNow;
+            bool important = arg.Severity > LogSeverity.Info;
+            string msg = $"[{Enum.GetName(typeof(LogSeverity), arg.Severity)}] {arg.Message}";
+            const string logSource = "Discord.Net";
+
+            if (important)
+            {
+                // Note: Using external method here!
+                await Kerobot.InstanceLogAsync(true, logSource, msg);
+            }
+            else
+            {
+                FormatToConsole(DateTimeOffset.UtcNow, logSource, msg);
+            }
+        }
+
+        const string TableLog = "logging";
+        public override async Task CreateDatabaseTablesAsync(NpgsqlConnection db)
+        {
+            using (var c = db.CreateCommand())
+            {
+                c.CommandText = $"create table if not exists {TableLog} ("
+                    + "log_id serial primary key, "
+                    + "log_timestamp timestamptz not null, "
+                    + "log_source text not null, "
+                    + "message text not null"
+                    + ")";
+                await c.ExecuteNonQueryAsync();
+            }
+        }
+        private async Task TableInsertAsync(NpgsqlConnection db, DateTimeOffset timestamp, string source, string message)
+        {
+            using (var c = db.CreateCommand())
+            {
+                c.CommandText = $"insert into {TableLog} (log_timestamp, log_source, message) values"
+                    + "(@Ts, @Src, @Msg)";
+                c.Parameters.Add("@Ts", NpgsqlDbType.TimestampTZ).Value = timestamp;
+                c.Parameters.Add("@Src", NpgsqlDbType.Text).Value = source;
+                c.Parameters.Add("@Msg", NpgsqlDbType.Text).Value = message;
+                c.Prepare();
+                await c.ExecuteNonQueryAsync();
+            }
+        }
+
+        /// <summary>
+        /// All console writes originate here.
+        /// Takes incoming details of a log message. Formats the incoming information in a
+        /// consistent format before writing out the result to console.
+        /// </summary>
+        private void FormatToConsole(DateTimeOffset timestamp, string source, string message)
+        {
+            var prefix = $"[{timestamp:u}] [{source}] ";
+            foreach (var line in message.Split(new string[] { "\r\n", "\n" }, StringSplitOptions.None))
+            {
+                Console.WriteLine(prefix + line);
+            }
+        }
+
+        /// <summary>
+        /// See <see cref="Kerobot.InstanceLogAsync(bool, string, string)"/>
+        /// </summary>
+        public async Task DoInstanceLogAsync(bool report, string source, string message)
+        {
+            FormatToConsole(DateTimeOffset.UtcNow, source, message);
+
+            Exception insertException = null;
+            try
+            {
+                using (var db = await Kerobot.GetOpenNpgsqlConnectionAsync(null))
+                {
+                    await TableInsertAsync(db, DateTimeOffset.UtcNow, source, message);
+                }
+            }
+            catch (Exception ex)
+            {
+                // This is not good. Resorting to plain console write to report the issue.
+                // Let's hope a warning reaches the reporting channel.
+                Console.WriteLine("!!! Error during recording to instance log: " + ex.Message);
+                Console.WriteLine(ex.StackTrace);
+                insertException = ex;
+            }
+
+            // Report to logging channel if necessary and possible
+            var (g, c) = Kerobot.Config.InstanceLogReportTarget;
+            if ((insertException != null || report) &&
+                g != 0 && c != 0 && Kerobot.DiscordClient.ConnectionState == ConnectionState.Connected)
+            {
+                var ch = Kerobot.DiscordClient.GetGuild(g)?.GetTextChannel(c);
+                if (ch == null) return; // not connected, or channel doesn't exist.
+
+                if (insertException != null)
+                {
+                    // Attempt to report instance logging failure to the reporting channel
+                    try
+                    {
+                        EmbedBuilder e = new EmbedBuilder()
+                        {
+                            Footer = new EmbedFooterBuilder() { Text = Name },
+                            Timestamp = DateTimeOffset.UtcNow,
+                            Description = "Error during recording to instance log.\nCheck the console.",
+                            Color = Color.DarkRed
+                        };
+                        await ch.SendMessageAsync("", embed: e.Build());
+                    }
+                    catch
+                    {
+                        return; // Give up
+                    }
+                }
+
+                if (report)
+                {
+                    try
+                    {
+                        EmbedBuilder e = new EmbedBuilder()
+                        {
+                            Footer = new EmbedFooterBuilder() { Text = source },
+                            Timestamp = DateTimeOffset.UtcNow,
+                            Description = message
+                        };
+                        await ch.SendMessageAsync("", embed: e.Build());
+                    }
+                    catch (Discord.Net.HttpException ex)
+                    {
+                        await DoInstanceLogAsync(false, Name, "Failed to send message to reporting channel: " + ex.Message);
+                    }
+                }
+            }
+        }
+
+        /// <summary>
+        /// See <see cref="Kerobot.GuildLogAsync(ulong, string, string)"/>
+        /// </summary>
+        public async Task DoGuildLogAsync(ulong guild, string source, string message)
+        {
+            try
+            {
+                using (var db = await Kerobot.GetOpenNpgsqlConnectionAsync(guild))
+                {
+                    await TableInsertAsync(db, DateTimeOffset.UtcNow, source, message);
+                }
+            }
+            catch (Exception ex)
+            {
+                // Probably a bad idea, but...
+                await DoInstanceLogAsync(true, this.Name, "Failed to store guild log item: " + ex.Message);
+                // Stack trace goes to console only.
+                FormatToConsole(DateTime.UtcNow, this.Name, ex.StackTrace);
+            }
+        }
+    }
+}

Kerobot/Services/Service.cs

@@ -1,6 +1,4 @@
-using System;
-using System.Collections.Generic;
-using System.Text;
+using System.Threading.Tasks;
 
 namespace Kerobot.Services
 {
@@ -11,15 +9,31 @@ namespace Kerobot.Services
     /// Services provide the core functionality of this program. Modules are expected to call into methods
     /// provided by services for the times when processor-intensive or shared functionality needs to be utilized.
     /// </remarks>
-    internal class Service
+    internal abstract class Service
     {
         private readonly Kerobot _kb;
-
         public Kerobot Kerobot => _kb;
 
-        protected internal Service(Kerobot kb)
+        public string Name => this.GetType().Name;
+
+        public Service(Kerobot kb)
         {
             _kb = kb;
         }
+
+        /// <summary>
+        /// Initializes database tables per-guild. Called when entering a guild.
+        /// </summary>
+        /// <param name="db">An opened database connection with the appropriate schema option set.</param>
+        /// <remarks>If overriding, calling the base method is not necessary.</remarks>
+        public virtual Task CreateDatabaseTablesAsync(Npgsql.NpgsqlConnection db) => Task.CompletedTask;
+
+        /// <summary>
+        /// Creates a log message.
+        /// </summary>
+        /// <param name="message">Logging message contents.</param>
+        /// <param name="report">Determines if the log message should be sent to a reporting channel.</param>
+        /// <returns></returns>
+        protected Task Log(string message, bool report = false) => Kerobot.InstanceLogAsync(report, Name, message);
     }
 }