Updating how we handle logging.

Instead of using Console.WriteLine for everything, I decided that it's time to switch to a more mature logging platform. This will enable me to better track any kinds of issues, and make sure that there is an actual log file that lives outside the console that I can use for diagnostics.
This commit is contained in:
Den Delimarsky 2021-04-29 08:02:24 -07:00
parent 994af18770
commit 8496b1dc09
No known key found for this signature in database
GPG Key ID: E1BE1355085F0BCF
4 changed files with 85 additions and 25 deletions

View File

@ -2,6 +2,7 @@
// The Microsoft Corporation licenses this file to you under the MIT license.
// See the LICENSE file in the project root for more information.
using NLog;
using System;
using System.Runtime.InteropServices;
using System.Threading;
@ -27,6 +28,13 @@ namespace Espresso.Shell.Core
private static CancellationTokenSource TokenSource = new CancellationTokenSource();
private static CancellationToken ThreadToken;
private static Logger log;
static APIHelper()
{
log = LogManager.GetCurrentClassLogger();
}
// More details about the API used: https://docs.microsoft.com/windows/win32/api/winbase/nf-winbase-setthreadexecutionstate
[DllImport("kernel32.dll", CharSet = CharSet.Auto, SetLastError = true)]
static extern EXECUTION_STATE SetThreadExecutionState(EXECUTION_STATE esFlags);
@ -44,7 +52,6 @@ namespace Espresso.Shell.Core
{
var stateResult = SetThreadExecutionState(state);
bool stateSettingSucceeded = (stateResult != 0);
Console.WriteLine($"State setting result: {stateResult}");
if (stateSettingSucceeded)
{
@ -103,7 +110,7 @@ namespace Espresso.Shell.Core
success = SetAwakeState(EXECUTION_STATE.ES_SYSTEM_REQUIRED | EXECUTION_STATE.ES_DISPLAY_REQUIRED | EXECUTION_STATE.ES_CONTINUOUS);
if (success)
{
Console.WriteLine("Timed keep-awake with display on.");
log.Info("Timed keep-awake with display on.");
var startTime = DateTime.UtcNow;
while (DateTime.UtcNow - startTime < TimeSpan.FromSeconds(seconds))
{
@ -124,7 +131,7 @@ namespace Espresso.Shell.Core
success = SetAwakeState(EXECUTION_STATE.ES_SYSTEM_REQUIRED | EXECUTION_STATE.ES_CONTINUOUS);
if (success)
{
Console.WriteLine("Timed keep-awake with display off.");
log.Info("Timed keep-awake with display off.");
var startTime = DateTime.UtcNow;
while (DateTime.UtcNow - startTime < TimeSpan.FromSeconds(seconds))
{

View File

@ -1,4 +1,4 @@
<Project Sdk="Microsoft.NET.Sdk">
<Project Sdk="Microsoft.NET.Sdk">
<PropertyGroup>
<OutputType>Exe</OutputType>
@ -7,9 +7,22 @@
<ItemGroup>
<PackageReference Include="Newtonsoft.Json" Version="13.0.1" />
<PackageReference Include="NLog" Version="4.7.9" />
<PackageReference Include="System.CommandLine" Version="2.0.0-beta1.20071.2" />
<PackageReference Include="System.Reactive" Version="5.0.0" />
<PackageReference Include="System.Runtime.Caching" Version="6.0.0-preview.1.21102.12" />
</ItemGroup>
<ItemGroup>
<Compile Update="Program.cs">
<CopyToOutputDirectory>Never</CopyToOutputDirectory>
</Compile>
</ItemGroup>
<ItemGroup>
<None Update="NLog.config">
<CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
</None>
</ItemGroup>
</Project>

View File

@ -0,0 +1,14 @@
<?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">
<targets async="true">
<target name="logfile" xsi:type="File" fileName="espresso.log" layout="[${longdate} ${level:uppercase=true} ${logger}] ${message}" />
<target name="logconsole" xsi:type="Console" layout="[${longdate} ${level:uppercase=true}] ${message}" />
</targets>
<rules>
<logger name="*" minlevel="Info" writeTo="logconsole" />
<logger name="*" minlevel="Debug" writeTo="logfile" />
</rules>
</nlog>

View File

@ -5,13 +5,16 @@
using Espresso.Shell.Core;
using Espresso.Shell.Models;
using Newtonsoft.Json;
using NLog;
using System;
using System.CommandLine;
using System.CommandLine.Invocation;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Reactive.Concurrency;
using System.Reactive.Linq;
using System.Reflection;
using System.Threading;
namespace Espresso.Shell
@ -23,6 +26,8 @@ namespace Espresso.Shell
private static FileSystemWatcher watcher = null;
public static Mutex Mutex { get => mutex; set => mutex = value; }
private static Logger log;
static int Main(string[] args)
{
bool instantiated;
@ -33,7 +38,10 @@ namespace Espresso.Shell
ForceExit(appName + " is already running! Exiting the application.", 1);
}
Console.WriteLine("Espresso - Computer Caffeination Engine");
log = LogManager.GetCurrentClassLogger();
log.Info("Launching Espresso...");
log.Info(FileVersionInfo.GetVersionInfo(Assembly.GetExecutingAssembly().Location).FileVersion);
var configOption = new Option<string>(
aliases: new[] { "--config", "-c" },
@ -90,15 +98,16 @@ namespace Espresso.Shell
private static void ForceExit(string message, int exitCode)
{
Console.WriteLine(message);
log.Debug(message);
log.Info(message);
Console.ReadKey();
Environment.Exit(exitCode);
}
private static void HandleCommandLineArguments(string config, bool displayOn, long timeLimit)
{
Console.WriteLine($"The value for --display-on is: {displayOn}");
Console.WriteLine($"The value for --time-limit is: {timeLimit}");
log.Info($"The value for --display-on is: {displayOn}");
log.Info($"The value for --time-limit is: {timeLimit}");
if (!string.IsNullOrWhiteSpace(config))
{
@ -129,7 +138,9 @@ namespace Espresso.Shell
}
catch (Exception ex)
{
Console.WriteLine($"There was a problem with the configuration file. Make sure it exists.\n{ex.Message}");
var errorString = $"There was a problem with the configuration file. Make sure it exists.\n{ex.Message}";
log.Info(errorString);
log.Debug(errorString);
}
}
else
@ -140,11 +151,13 @@ namespace Espresso.Shell
bool success = APIHelper.SetIndefiniteKeepAwake(displayOn);
if (success)
{
Console.WriteLine($"Currently in indefinite keep awake. Display always on: {displayOn}");
log.Info($"Currently in indefinite keep awake. Display always on: {displayOn}");
}
else
{
Console.WriteLine("Could not set up the state to be indefinite keep awake.");
var errorMessage = "Could not set up the state to be indefinite keep awake.";
log.Info(errorMessage);
log.Debug(errorMessage);
}
}
else
@ -159,9 +172,9 @@ namespace Espresso.Shell
private static void HandleEspressoConfigChange(FileSystemEventArgs fileEvent)
{
Console.WriteLine("Resetting keep-awake to normal state due to settings change.");
log.Info("Detected a settings file change. Updating configuration...");
log.Info("Resetting keep-awake to normal state due to settings change.");
ResetNormalPowerState();
Console.WriteLine("Detected a file change. Reacting...");
ProcessSettings(fileEvent.FullPath);
}
@ -185,7 +198,6 @@ namespace Espresso.Shell
// If the settings were successfully processed, we need to set the right mode of operation.
// INDEFINITE = 0
// TIMED = 1
switch (settings.Properties.Mode)
{
case 0:
@ -194,11 +206,13 @@ namespace Espresso.Shell
bool success = APIHelper.SetIndefiniteKeepAwake(settings.Properties.KeepDisplayOn.Value);
if (success)
{
Console.WriteLine($"Currently in indefinite keep awake. Display always on: {settings.Properties.KeepDisplayOn.Value}");
log.Info($"Indefinite keep-awake. Display always on: {settings.Properties.KeepDisplayOn.Value}");
}
else
{
Console.WriteLine("Could not set up the state to be indefinite keep awake.");
var errorMessage = "Could not set up the state to be indefinite keep-awake.";
log.Info(errorMessage);
log.Debug(errorMessage);
}
break;
}
@ -206,7 +220,7 @@ namespace Espresso.Shell
{
// Timed keep-awake.
long computedTime = (settings.Properties.Hours.Value * 60 * 60) + (settings.Properties.Minutes.Value * 60);
Console.WriteLine($"In timed keep-awake mode. Expecting to be awake for {computedTime} seconds.");
log.Info($"Timed keep-awake. Expected runtime: {computedTime} seconds.");
APIHelper.SetTimedKeepAwake(computedTime, LogTimedKeepAwakeCompletion, LogUnexpectedOrCancelledKeepAwakeCompletion, settings.Properties.KeepDisplayOn.Value);
@ -214,35 +228,45 @@ namespace Espresso.Shell
}
default:
{
Console.WriteLine("Unknown mode of operation. Check config file.");
var errorMessage= "Unknown mode of operation. Check config file.";
log.Info(errorMessage);
log.Debug(errorMessage);
break;
}
}
}
else
{
Console.WriteLine("Settings are null.");
var errorMessage = "Settings are null.";
log.Info(errorMessage);
log.Debug(errorMessage);
}
}
else
{
Console.WriteLine("Could not get handle on file.");
var errorMessage = "Could not get handle on file.";
log.Info(errorMessage);
log.Debug(errorMessage);
}
}
catch (Exception ex)
{
Console.WriteLine($"There was a problem reading the configuration file.\n{ex.Message}");
var errorMessage = $"There was a problem reading the configuration file.\n{ex.Message}";
log.Info(errorMessage);
log.Debug(errorMessage);
}
}
private static void LogUnexpectedOrCancelledKeepAwakeCompletion()
{
Console.Write("The keep-awake thread was terminated early.");
var errorMessage = "The keep-awake thread was terminated early.";
log.Info(errorMessage);
log.Debug(errorMessage);
}
private static void LogTimedKeepAwakeCompletion(bool result)
{
Console.Write($"Completed timed keep-awake successfully: {result}");
log.Info($"Completed timed keep-awake successfully: {result}");
}
private static void ResetNormalPowerState()
@ -250,11 +274,13 @@ namespace Espresso.Shell
bool success = APIHelper.SetNormalKeepAwake();
if (success)
{
Console.WriteLine("Returned to normal keep-awake state.");
log.Info("Returned to normal keep-awake state.");
}
else
{
Console.WriteLine("Could not return to normal keep-awake state.");
var errorMessage = "Could not return to normal keep-awake state.";
log.Info(errorMessage);
log.Debug(errorMessage);
}
}
}