Expanded logging

Artemis/Artemis/App.config

@@ -280,7 +280,7 @@
     </Artemis.Modules.Effects.Bubbles.Bubbles>
     <Artemis.Settings.General>
       <setting name="LastEffect" serializeAs="String">
-        <value>TypeWave</value>
+        <value>WindowsProfile</value>
       </setting>
       <setting name="LastKeyboard" serializeAs="String">
         <value />
@@ -306,6 +306,9 @@
       <setting name="Theme" serializeAs="String">
         <value>Light</value>
       </setting>
+      <setting name="LogLevel" serializeAs="String">
+        <value>Info</value>
+      </setting>
     </Artemis.Settings.General>
   </userSettings>
   <runtime>

Artemis/Artemis/Artemis.csproj

@@ -38,8 +38,8 @@
     <SupportUrl>https://github.com/SpoinkyNL/Artemis/wiki/Frequently-Asked-Questions-%28FAQ%29</SupportUrl>
     <ProductName>Artemis</ProductName>
     <PublisherName>Artemis</PublisherName>
-    <ApplicationRevision>0</ApplicationRevision>
+    <ApplicationRevision>2</ApplicationRevision>
-    <ApplicationVersion>1.1.3.0</ApplicationVersion>
+    <ApplicationVersion>1.1.3.2</ApplicationVersion>
     <UseApplicationTrust>false</UseApplicationTrust>
     <CreateDesktopShortcut>true</CreateDesktopShortcut>
     <PublishWizardCompleted>true</PublishWizardCompleted>
@@ -452,6 +452,7 @@
     <Compile Include="Utilities\Keyboard\KeyboardHook.cs" />
     <Compile Include="Utilities\Layers\AnimationUpdater.cs" />
     <Compile Include="Utilities\Layers\Drawer.cs" />
+    <Compile Include="Utilities\Logging.cs" />
     <Compile Include="Utilities\LogitechDll\DllManager.cs" />
     <Compile Include="Utilities\LogitechDll\NamedPipeServer.cs" />
     <Compile Include="Utilities\LogitechDll\PipeServer.cs" />
@@ -616,9 +617,6 @@
       <Generator>SettingsSingleFileGenerator</Generator>
       <LastGenOutput>VolumeDisplay.Designer.cs</LastGenOutput>
     </None>
-    <Content Include="NLog.config">
-      <CopyToOutputDirectory>Always</CopyToOutputDirectory>
-    </Content>
     <None Include="NLog.xsd">
       <SubType>Designer</SubType>
     </None>

Artemis/Artemis/ArtemisBootstrapper.cs

@@ -5,6 +5,7 @@ using System.Windows;
 using System.Windows.Controls;
 using System.Windows.Forms;
 using Artemis.InjectionModules;
+using Artemis.Utilities;
 using Artemis.ViewModels;
 using Caliburn.Micro;
 using Ninject;
@@ -20,6 +21,9 @@ namespace Artemis
 
         public ArtemisBootstrapper()
         {
+            // Start logging before anything else
+            Logging.SetupLogging(Settings.General.Default.LogLevel);
+
             CheckDuplicateInstances();
             Initialize();
             BindSpecialValues();

Artemis/Artemis/Managers/DeviceManager.cs

@@ -25,8 +25,6 @@ namespace Artemis.Managers
         public DeviceManager(IEventAggregator events, ILogger logger, List<DeviceProvider> deviceProviders)
         {
             _logger = logger;
-            _logger.Info("Intializing DeviceManager");
-
             _events = events;
 
             KeyboardProviders = deviceProviders.Where(d => d.Type == DeviceType.Keyboard)
@@ -34,7 +32,7 @@ namespace Artemis.Managers
             MiceProviders = deviceProviders.Where(d => d.Type == DeviceType.Mouse).ToList();
             HeadsetProviders = deviceProviders.Where(d => d.Type == DeviceType.Headset).ToList();
 
-            _logger.Info("Intialized DeviceManager");
+            _logger.Info("Intialized DeviceManager with {0} device providers", deviceProviders.Count);
         }
 
         public List<DeviceProvider> HeadsetProviders { get; set; }

Artemis/Artemis/Managers/EffectManager.cs

@@ -23,8 +23,6 @@ namespace Artemis.Managers
         public EffectManager(ILogger logger, IEventAggregator events, DeviceManager deviceManager)
         {
             _logger = logger;
-            _logger.Info("Intializing EffectManager");
-
             _events = events;
             _deviceManager = deviceManager;
 

Artemis/Artemis/Managers/LoopManager.cs

@@ -28,6 +28,8 @@ namespace Artemis.Managers
             _loopTimer = new Timer(40);
             _loopTimer.Elapsed += Render;
             _loopTimer.Start();
+
+            _logger.Info("Intialized LoopManager");
         }
 
         /// <summary>

Artemis/Artemis/Managers/MainManager.cs

@@ -23,22 +23,19 @@ namespace Artemis.Managers
         public delegate void PauseCallbackHandler();
 
         private readonly IEventAggregator _events;
-        private readonly ILogger _logger;
         private readonly Timer _processTimer;
 
         public MainManager(IEventAggregator events, ILogger logger, LoopManager loopManager,
             DeviceManager deviceManager, EffectManager effectManager, ProfileManager profileManager)
         {
-            _logger = logger;
+            _events = events;
+
+            Logger = logger;
             LoopManager = loopManager;
             DeviceManager = deviceManager;
             EffectManager = effectManager;
             ProfileManager = profileManager;
 
-            _logger.Info("Intializing MainManager");
-
-            _events = events;
-
             _processTimer = new Timer(1000);
             _processTimer.Elapsed += ScanProcesses;
             _processTimer.Start();
@@ -57,12 +54,13 @@ namespace Artemis.Managers
             PipeServer = new PipeServer();
             PipeServer.Start("artemis");
 
-            _logger.Info("Intialized MainManager");
+            Logger.Info("Intialized MainManager");
         }
 
         [Inject]
         public Lazy<ShellViewModel> ShellViewModel { get; set; }
 
+        public ILogger Logger { get; set; }
         public LoopManager LoopManager { get; }
         public DeviceManager DeviceManager { get; set; }
         public EffectManager EffectManager { get; set; }
@@ -76,7 +74,7 @@ namespace Artemis.Managers
 
         public void Dispose()
         {
-            _logger.Debug("Shutting down MainManager");
+            Logger.Debug("Shutting down MainManager");
 
             _processTimer?.Stop();
             _processTimer?.Dispose();
@@ -91,7 +89,7 @@ namespace Artemis.Managers
         /// </summary>
         public void EnableProgram()
         {
-            _logger.Debug("Enabling program");
+            Logger.Debug("Enabling program");
             ProgramEnabled = true;
             LoopManager.StartAsync();
             _events.PublishOnUIThread(new ToggleEnabled(ProgramEnabled));
@@ -102,7 +100,7 @@ namespace Artemis.Managers
         /// </summary>
         public void DisableProgram()
         {
-            _logger.Debug("Disabling program");
+            Logger.Debug("Disabling program");
             LoopManager.Stop();
             ProgramEnabled = false;
             _events.PublishOnUIThread(new ToggleEnabled(ProgramEnabled));
@@ -133,7 +131,7 @@ namespace Artemis.Managers
             {
                 if (!runningProcesses.Any(p => p.ProcessName == activeGame.ProcessName && p.HasExited == false))
                 {
-                    _logger.Info("Disabling game: {0}", activeGame.Name);
+                    Logger.Info("Disabling game: {0}", activeGame.Name);
                     EffectManager.DisableGame(activeGame);
                 }
             }
@@ -146,7 +144,7 @@ namespace Artemis.Managers
             if (newGame == null || EffectManager.ActiveEffect == newGame)
                 return;
             // If it's not already enabled, do so.
-            _logger.Info("Detected and enabling game: {0}", newGame.Name);
+            Logger.Info("Detected and enabling game: {0}", newGame.Name);
             EffectManager.ChangeEffect(newGame, LoopManager);
         }
     }

Artemis/Artemis/Managers/ProfileManager.cs

@@ -28,6 +28,8 @@ namespace Artemis.Managers
             var profilePreviewTimer = new Timer(500);
             profilePreviewTimer.Elapsed += SetupProfilePreview;
             profilePreviewTimer.Start();
+
+            _logger.Info("Intialized ProfileManager");
         }
 
         public ProfilePreviewModel ProfilePreviewModel { get; set; }

Artemis/Artemis/Models/EffectModel.cs

@@ -5,6 +5,8 @@ using System.Linq;
 using Artemis.Managers;
 using Artemis.Models.Interfaces;
 using Artemis.Models.Profiles;
+using Newtonsoft.Json;
+using NLog;
 using Brush = System.Windows.Media.Brush;
 
 namespace Artemis.Models
@@ -16,6 +18,7 @@ namespace Artemis.Models
         public bool Initialized;
         public MainManager MainManager;
         public string Name;
+        private DateTime _lastTrace;
 
         protected EffectModel(MainManager mainManager, IDataModel dataModel)
         {
@@ -49,6 +52,18 @@ namespace Artemis.Models
             // Get all enabled layers who's conditions are met
             var renderLayers = GetRenderLayers(renderMice, renderHeadsets);
 
+            // Trace debugging
+            if (DateTime.Now.AddSeconds(-2) > _lastTrace)
+            {
+                _lastTrace = DateTime.Now;
+                MainManager.Logger.Trace("Effect datamodel as JSON: \r\n{0}",
+                    JsonConvert.SerializeObject(DataModel, Formatting.Indented));
+                MainManager.Logger.Trace("Effect {0} has to render {1} layers", Name, renderLayers.Count);
+                foreach (var renderLayer in renderLayers)
+                    MainManager.Logger.Trace("    Layer name: {0}, layer type: {1}", renderLayer.Name,
+                        renderLayer.LayerType);
+            }
+
             // Render the keyboard layer-by-layer
             keyboard = Profile.GenerateBitmap(renderLayers, DataModel,
                 MainManager.DeviceManager.ActiveKeyboard.KeyboardRectangle(4), false, true);

Artemis/Artemis/NLog.config

@@ -1,25 +0,0 @@
-<?xml version="1.0" encoding="utf-8"?>
-
-<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
-      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
-      xsi:schemaLocation="http://www.nlog-project.org/schemas/NLog.xsd NLog.xsd"
-      autoReload="true"
-      throwExceptions="false"
-      internalLogLevel="Off" internalLogFile="c:\temp\nlog-internal.log">
-  <targets>
-    <target name="file"
-            xsi:type="File"
-            maxArchiveFiles="7"
-            fileName="${specialfolder:folder=MyDocuments}/Artemis/logs/${shortdate}.txt"
-            layout="${longdate}|${level:uppercase=true}|${logger}|${message} ${exception:format=tostring}" />
-
-    <target name="debugger"
-            xsi:type="Debugger"
-            layout="${logger:shortName=True} - ${uppercase:${level}}: ${message}" />
-  </targets>
-
-  <rules>
-    <logger name="*" minlevel="Debug" writeTo="file" />
-    <logger name="*" minlevel="Debug" writeTo="debugger" />
-  </rules>
-</nlog>

Artemis/Artemis/Settings/General.Designer.cs

@@ -25,7 +25,7 @@ namespace Artemis.Settings {
         
         [global::System.Configuration.UserScopedSettingAttribute()]
         [global::System.Diagnostics.DebuggerNonUserCodeAttribute()]
-        [global::System.Configuration.DefaultSettingValueAttribute("TypeWave")]
+        [global::System.Configuration.DefaultSettingValueAttribute("WindowsProfile")]
         public string LastEffect {
             get {
                 return ((string)(this["LastEffect"]));
@@ -130,5 +130,17 @@ namespace Artemis.Settings {
                 this["Theme"] = value;
             }
         }
+        
+        [global::System.Configuration.UserScopedSettingAttribute()]
+        [global::System.Diagnostics.DebuggerNonUserCodeAttribute()]
+        [global::System.Configuration.DefaultSettingValueAttribute("Info")]
+        public string LogLevel {
+            get {
+                return ((string)(this["LogLevel"]));
+            }
+            set {
+                this["LogLevel"] = value;
+            }
+        }
     }
 }

Artemis/Artemis/Settings/General.settings

@@ -1,11 +1,9 @@
 <?xml version='1.0' encoding='utf-8'?>
-
+<SettingsFile xmlns="http://schemas.microsoft.com/VisualStudio/2004/01/settings" CurrentProfile="(Default)" GeneratedClassNamespace="Artemis.Settings" GeneratedClassName="General">
-<SettingsFile xmlns="http://schemas.microsoft.com/VisualStudio/2004/01/settings" CurrentProfile="(Default)"
-              GeneratedClassNamespace="Artemis.Settings" GeneratedClassName="General">
   <Profiles />
   <Settings>
     <Setting Name="LastEffect" Type="System.String" Scope="User">
-      <Value Profile="(Default)">TypeWave</Value>
+      <Value Profile="(Default)">WindowsProfile</Value>
     </Setting>
     <Setting Name="LastKeyboard" Type="System.String" Scope="User">
       <Value Profile="(Default)" />
@@ -31,5 +29,8 @@
     <Setting Name="Theme" Type="System.String" Scope="User">
       <Value Profile="(Default)">Light</Value>
     </Setting>
+    <Setting Name="LogLevel" Type="System.String" Scope="User">
+      <Value Profile="(Default)">Info</Value>
+    </Setting>
   </Settings>
 </SettingsFile>

Artemis/Artemis/Settings/GeneralSettings.cs

@@ -5,6 +5,7 @@ using System.Runtime.InteropServices.ComTypes;
 using System.Windows;
 using Artemis.Utilities;
 using MahApps.Metro;
+using NLog;
 
 namespace Artemis.Settings
 {
@@ -76,6 +77,16 @@ namespace Artemis.Settings
             }
         }
 
+        public string LogLevel
+        {
+            get { return General.Default.LogLevel; }
+            set
+            {
+                if (General.Default.LogLevel == value) return;
+                General.Default.LogLevel = value;
+            }
+        }
+
         private void ApplyGamestatePort()
         {
             // TODO: Restart Gamestate server with new port
@@ -103,6 +114,7 @@ namespace Artemis.Settings
             ApplyAutorun();
             ApplyTheme();
             ApplyGamestatePort();
+            Logging.SetupLogging(LogLevel);
         }
 
         private void ApplyTheme()
@@ -136,6 +148,7 @@ namespace Artemis.Settings
             CheckForUpdates = true;
             ShowOnStartup = true;
             Theme = "Light";
+            LogLevel = "Info";
 
             SaveSettings();
         }

Artemis/Artemis/Utilities/Logging.cs

@@ -0,0 +1,47 @@
+using NLog;
+using NLog.Config;
+using NLog.Targets;
+
+namespace Artemis.Utilities
+{
+    public static class Logging
+    {
+        public static void SetupLogging(string logLevel)
+        {
+            SetupLogging(LogLevel.FromString(logLevel));
+        }
+
+        public static void SetupLogging(LogLevel logLevel)
+        {
+            // Step 1. Create configuration object 
+            var config = new LoggingConfiguration();
+
+            // Step 2. Create targets and add them to the configuration 
+            var debuggerTarget = new DebuggerTarget();
+            config.AddTarget("debugger", debuggerTarget);
+
+            var fileTarget = new FileTarget();
+            config.AddTarget("file", fileTarget);
+
+            // Step 3. Set target properties 
+            debuggerTarget.Layout = @"${logger:shortName=True} - ${uppercase:${level}}: ${message}";
+            fileTarget.FileName = "${specialfolder:folder=MyDocuments}/Artemis/logs/${shortdate}.txt";
+            fileTarget.Layout = "${longdate}|${level:uppercase=true}|${logger}|${message} ${exception:format=tostring}";
+            fileTarget.ArchiveEvery = FileArchivePeriod.Day;
+            fileTarget.MaxArchiveFiles = 7;
+
+            // Step 4. Define rules
+            var rule1 = new LoggingRule("*", logLevel, debuggerTarget);
+            config.LoggingRules.Add(rule1);
+            var rule2 = new LoggingRule("*", logLevel, fileTarget);
+            config.LoggingRules.Add(rule2);
+
+            // Step 5. Activate the configuration
+            LogManager.Configuration = config;
+
+            // Log as fatal so it always shows
+            var logger = LogManager.GetCurrentClassLogger();
+            logger.Fatal("INFO: Set log level to {0}", logLevel);
+        }
+    }
+}

Artemis/Artemis/ViewModels/Flyouts/FlyoutSettingsViewModel.cs

@@ -7,9 +7,7 @@ using Artemis.Settings;
 using Caliburn.Micro;
 using MahApps.Metro.Controls;
 using NLog;
-using NLog.Targets;
 using ILogger = Ninject.Extensions.Logging.ILogger;
-using LogManager = NLog.LogManager;
 
 namespace Artemis.ViewModels.Flyouts
 {
@@ -31,9 +29,11 @@ namespace Artemis.ViewModels.Flyouts
             Position = Position.Right;
             GeneralSettings = new GeneralSettings();
 
+            LogLevels = new BindableCollection<string>();
+            LogLevels.AddRange(LogLevel.AllLoggingLevels.Select(l => l.Name));
+
             PropertyChanged += KeyboardUpdater;
             events.Subscribe(this);
-            ApplyLogging();
         }
 
         public MainManager MainManager { get; set; }
@@ -71,8 +71,15 @@ namespace Artemis.ViewModels.Flyouts
             }
         }
 
-        public BindableCollection<string> Themes
+        public BindableCollection<string> Themes => new BindableCollection<string>
-            => new BindableCollection<string> {"Light", "Dark", "Corsair Light", "Corsair Dark"};
+        {
+            "Light",
+            "Dark",
+            "Corsair Light",
+            "Corsair Dark"
+        };
+
+        public BindableCollection<string> LogLevels { get; set; }
 
         public string SelectedTheme
         {
@@ -85,6 +92,17 @@ namespace Artemis.ViewModels.Flyouts
             }
         }
 
+        public string SelectedLogLevel
+        {
+            get { return GeneralSettings.LogLevel; }
+            set
+            {
+                if (value == GeneralSettings.LogLevel) return;
+                GeneralSettings.LogLevel = value;
+                NotifyOfPropertyChange(() => SelectedLogLevel);
+            }
+        }
+
         public string SelectedKeyboardProvider
         {
             get { return _selectedKeyboardProvider; }
@@ -130,27 +148,6 @@ namespace Artemis.ViewModels.Flyouts
             NotifyOfPropertyChange(() => Enabled);
         }
 
-        // TODO https://github.com/ninject/Ninject.Extensions.Logging/issues/35
-        private void ApplyLogging()
-        {
-            return;
-            var c = LogManager.Configuration;
-            var file = c.FindTargetByName("file") as FileTarget;
-            if (file == null)
-                return;
-
-            var rule = c.LoggingRules.FirstOrDefault(r => r.Targets.Contains(file));
-            if (rule == null)
-                return;
-
-            if (EnableDebug)
-                rule.EnableLoggingForLevel(LogLevel.Debug);
-            rule.DisableLoggingForLevel(LogLevel.Debug);
-
-            LogManager.ReconfigExistingLoggers();
-            _logger.Info("Set debug logging to: {0}", EnableDebug);
-        }
-
         /// <summary>
         ///     Takes proper action when the selected keyboard is changed in the UI
         /// </summary>

Artemis/Artemis/Views/Flyouts/FlyoutSettingsView.xaml

@@ -4,12 +4,22 @@
              xmlns:mc="http://schemas.openxmlformats.org/markup-compatibility/2006"
              xmlns:d="http://schemas.microsoft.com/expression/blend/2008"
              xmlns:controls="http://metro.mahapps.com/winfx/xaml/controls"
-             xmlns:cal="http://www.caliburnproject.org"
+             xmlns:cal="http://www.caliburnproject.org" 
+             xmlns:utilities="clr-namespace:Artemis.Utilities" 
+             xmlns:sys="clr-namespace:System;assembly=mscorlib"
+             xmlns:profileEnumerations="clr-namespace:Artemis.Models.Profiles"
              mc:Ignorable="d"
              d:DesignHeight="600" d:DesignWidth="300"
              Width="300">
     <UserControl.Resources>
-        <ResourceDictionary Source="pack://application:,,,/MahApps.Metro;component/Styles/Accents/BaseDark.xaml" />
+        <utilities:EnumDescriptionConverter x:Key="HEnumDescriptionConverter" />
+        <ObjectDataProvider MethodName="GetValues"
+                            ObjectType="{x:Type sys:Enum}"
+                            x:Key="LayerEnumValues">
+            <ObjectDataProvider.MethodParameters>
+                <x:Type TypeName="profileEnumerations:LayerType" />
+            </ObjectDataProvider.MethodParameters>
+        </ObjectDataProvider>
     </UserControl.Resources>
 
     <Grid>
@@ -27,6 +37,7 @@
             <RowDefinition Height="Auto" />
             <RowDefinition Height="Auto" />
             <RowDefinition Height="Auto" />
+            <RowDefinition Height="Auto" />
             <RowDefinition Height="*" />
         </Grid.RowDefinitions>
 
@@ -86,16 +97,23 @@
                                VerticalAlignment="Center" HorizontalAlignment="Right" Width="125"
                                IsChecked="{Binding Path=GeneralSettings.EnablePointersUpdate, Mode=TwoWay}" />
 
+        <!-- Logging -->
+        <Label Grid.Row="8" Grid.Column="0" Margin="5" VerticalAlignment="Center" HorizontalAlignment="Left"
+               Content="Log level:" />
+        <ComboBox Grid.Row="8" Grid.Column="1" x:Name="LogLevels" Margin="10" VerticalAlignment="Center"
+                  HorizontalAlignment="Right"
+                  Width="140" />
+
         <!-- Buttons -->
-        <Button Grid.Row="8" Grid.Column="0" Margin="10" x:Name="ResetSettings" Content="Reset settings"
+        <Button Grid.Row="9" Grid.Column="0" Margin="10" x:Name="ResetSettings" Content="Reset settings"
                 VerticalAlignment="Center" HorizontalAlignment="Left" Width="120"
                 Style="{DynamicResource SquareButtonStyle}" />
-        <Button Grid.Row="8" Grid.Column="1" Margin="10" x:Name="SaveSettings" Content="Save changes"
+        <Button Grid.Row="9" Grid.Column="1" Margin="10" x:Name="SaveSettings" Content="Save changes"
                 VerticalAlignment="Center" HorizontalAlignment="Right" Width="120"
                 Style="{DynamicResource SquareButtonStyle}" />
 
         <!-- Version -->
-        <Grid Grid.Row="9" Grid.Column="0" Grid.ColumnSpan="2" Margin="10" VerticalAlignment="Bottom">
+        <Grid Grid.Row="10" Grid.Column="0" Grid.ColumnSpan="2" Margin="10" VerticalAlignment="Bottom">
             <Grid.ColumnDefinitions>
                 <ColumnDefinition Width="*" />
                 <ColumnDefinition Width="*" />