Category Archives: Programming

Using Microsoft.Extensions.Logging

The Microsoft.Extensions.Logging namespace includes interfaces and implementations for a common logging interface. It’s a little like common-logging and whilst it’s not restricted to ASP.NET Core it’s got things entry points to work with ASP.NET Core.

What’s common logging all about?

In the past we’ve been hit with the problem of multiple logging frameworks/libraries which have slightly different interfaces. On top of this we might have other libraries which require those specific interfaces.

So for example, popular .NET logging frameworks such as log4net, NLog, Serilog along with the likes of the Microsoft Enterprise Block Logging might be getting used/expected in different parts of our application and libraries. Each ultimately offers similar functionality but we really don’t want multiple logging frameworks if we can help it.

The common-logging was introduced a fair few years back to allow us to write code with a standarised interface, but allow us to use whatever logging framework we wanted behind the scenes. Microsoft’s Microsoft.Extensions.Logging offers a similar abstraction.

Out of the box, the Microsoft.Extensions.Logging comes with some standard logging capabilities, Microsoft.Extensions.Logging.Console, Microsoft.Extensions.Logging.Debug, Microsoft.Extensions.Logging.EventLog, Microsoft.Extensions.Logging.TraceSource and Microsoft.Extensions.Logging.AzureAppServices. As the names suggest, these give us logging to the console, to debug, to the event log, to trace source and to Azure’s diagnostic logging.

Microsoft.Extensions.Logging offers is a relatively simple mechanism for adding further logging “providers” and third part logging frameworks such as NLog, log4net and SeriLog.

How to use Microsoft.Extensions.Logging

Let’s start by simply seeing how we can create a logger using this framework.

Add the Microsoft.Extensions.Logging and Microsoft.Extensions.Logging.Debug NuGet packages to your application.

The first gives us the interfaces and code for the LoggerFactory etc. whilst the second gives us the debug extensions for the logging factory.

Note: The following code has been deprecated and replaced with ILoggerBuilder extensions.

var factory = new LoggerFactory()
   .AddDebug(LogLevel.Debug);

Once the logger factory has been created we can create an ILogger using

ILogger logger = factory.CreateLogger<MyService>();

The MyService may be a type that you want to create logs for, alternatively you can pass the CreateLogger a category name.

Finally, using a standard interface we can log something using the following code

logger.Log(LogLevel.Debug, "Some message to log");

Using other logging frameworks

I’ll just look at a couple of other frameworks, NLog and Serilog.

For NLog add the NuGet package NLog.Extensions.Logging, for Serilog add Serilog.Extensions.Logging and in my case I’ve added Serilog.Sinks.RollingFile to create logs to a rolling file and Serilog.Sinks.Debug for debug output.

Using NLog

Create a file named nlog.config and set it’s properties within Visual Studio as Copy always. Here’s a sample

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" 
   xsi:schemaLocation="NLog NLog.xsd"
   xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
   autoReload="true"
   internalLogFile="c:\temp\mylog.log"
   internalLogLevel="Info" >


<targets>
   <target xsi:type="File" name="fileTarget" 
      fileName="c:\temp\mylog.log"      
      layout="${date}|${level:uppercase=true}|${message}
         ${exception}|${logger}|${all-event-properties}" />
   <target xsi:type="Console" name="consoleTarget"
      layout="${date}|${level:uppercase=true}|${message} 
         ${exception}|${logger}|${all-event-properties}" />
</targets>

<rules>
   <logger name="*" minlevel="Trace" writeTo="fileTarget,consoleTarget" />
</rules>
</nlog>

Now in code we can load this configuration file using

NLog.LogManager.LoadConfiguration("nlog.config");

and now the only difference from the previous example of using the LoggerFactory is change the creation of the factory to

var factory = new LoggerFactory()
   .AddNLog();

Everything else remains the same. Now you should be seeing a file named mylog.log in c:\temp along with debug output.

Using serilog

In Serilog’s case we’ll create the logger configuration in code, hence here’s the code to create both a file and debug log

Note: See Serilog documentation for creating the configuration via a config or settings file.

Log.Logger = new LoggerConfiguration()
   .MinimumLevel.Debug()
   .WriteTo.RollingFile("c:\\temp\\log-{Date}.txt")
   .WriteTo.Debug()
   .CreateLogger();

The will create a log file in c:\temp named log-{Date}.txt, where {Date} is replaced with today’s date. Obviously the include of WriteTo.Debug also gives us debug output.

We simply create the logger using familiar looking code

var factory = new LoggerFactory()
   .AddSerilog();

Everything else works the same but now we’ll see Serilog output.

Creating our own LoggerProvider

As you’ve seen in all examples, extension methods are used to AddDebug, AddNLog, AddSerilog. Basically each of these adds an ILoggerProvider to the factory. We can easily add our own provider by implementing the ILoggerProvider interface, here’s a simple example of a DebugLoggerProvider

public class DebugLoggerProvider : ILoggerProvider
{
   private readonly ConcurrentDictionary<string, ILogger> _loggers;

   public DebugLoggerProvider()
   {
      _loggers = new ConcurrentDictionary<string, ILogger>();
   }

   public void Dispose()
   {
   }

   public ILogger CreateLogger(string categoryName)
   {
      return _loggers.GetOrAdd(categoryName, new DebugLogger());
   }
}

The provider needs to keep track of any ILogger’s created based upon the category name. Next we’ll create a DebugLogger which implements the ILogger interface

public class DebugLogger : ILogger
{
   public void Log<TState>(
      LogLevel logLevel, EventId eventId, 
      TState state, Exception exception, 
      Func<TState, Exception, string> formatter)
   {
      if (formatter != null)
      {
         Debug.WriteLine(formatter(state, exception));
      }
   }

   public bool IsEnabled(LogLevel logLevel)
   {
      return true;
   }

   public IDisposable BeginScope<TState>(TState state)
   {
      return null;
   }
}

In this sample logger, we’re going to handle all LogLevel’s and are not supporting BeginScope. So all the work is done in the Log method and even that is pretty simple as we use the supplied formatter to create our message then output it to our log sink, in this case Debug. If no formatter is passed, we’ll currently not output anything, but obviously we could create our own formatter to be used instead.

Finally, sticking with the extension method pattern to add a provider, we’ll create the following

public static class DebugLoggerFactoryExtensions
{
   public static ILoggerFactory AddDebugLogger(
      this ILoggerFactory factory)
   {
      factory.AddProvider(new DebugLoggerProvider());
      return factory;
   }
}

That’s all there is to this very simple example, we create the factory in the standard way, i.e.

var factory = new LoggerFactory()
   .AddDebugLogger();

and everything else works without any changes.

A .NET service registered with Eureka

To create a .NET service which is registered with Eureka we’ll use the Steeltoe libraries…

Create an ASP.NET Core Web Application and select WebApi. Add the Steeltoe.Discovery.Client NuGet package, now in the Startup.cs within ConfigureServices add the following

services.AddDiscoveryClient(Configuration);

and within the Configure method add

app.UseDiscoveryClient();

We’re not going to create any other code to implement a service, but we will need some configuration added to the appsettings.json file, so add the following

"spring": {
    "application": {
      "name": "eureka-test-service"
    }
  },
  "eureka": {
    "client": {
      "serviceUrl": "http://localhost:8761/eureka/",
      "shouldRegisterWithEureka": true,
      "shouldFetchRegistry": false
    },
    "instance": {
      "hostname": "localhost",
      "port": 5000
    }
  }

The application name is what’s going to be displayed within Eureka and visible via http://localhost:8761/eureka/apps (obviously replacing the host name and ip with your Eureka server’s).

The Elvis (conditional null) operator is not magic

I was looking over somebody else’s code the other day and was intrigued by the liberal use of the Elvis or correctly known as, conditional null operator, i.e. the ?.

I assumed that for every ?. the compiler would create an IF statement, but it did make me wonder whether the compiler was actually able to optimize such code (where the ?. is used multiple times on the same object), so for example, what’s produced in IL for the following

var s = ??? // null or an instance 
Console.WriteLine(s?.Name?.Length);
Console.WriteLine(s?.Name);

My assumption would be that (without any optimization) we’d end up with the following

Console.WriteLine(s != null ? (s.Name != null ? s.Name.Length : 0) : 0);
Console.WriteLine(s != null ? s.Name : null);

Or, would if magically create code like this

object o = null;
int? l = null;

if (s != null)
{
   o = s.Name;
   if (s.Name != null)
   {
      l = s.Name.Length;
   }
}

Console.WriteLine(l);
Console.WriteLine(o);

With the first snippet of code, a best case scenario results in the IF statement being called twice (when s is null), the worst case (when nothing is null) is that the IF statement will be called three times. Whereas the second example would have the IF called once (when s is null) and twice in the worst case (when nothing is null).

Ofcourse the easiest way to see what happens is to fire up ILSpy and take a look at the generated IL/C# code. Here’s the C# that ILSpy created for us based upon the IL

object obj;
if (s == null)
{
   obj = null;
}
else
{
   string name = s.Name;
   obj = ((name != null) ? new int?(name.Length) : null);
}
Console.WriteLine((int?)obj);
Console.WriteLine((s != null) ? s.Name : null);

In this code, the best case (when s is null), the IF statement is called twice and worst case (when nothing is null), it’s called three times.

This is a simple example, but it’s worth being aware of what code is being produced using such syntactic sugar.

Tasks and CancellationTokens

We’re executing some code on a background thread using the Task API, for example let’s create a really simple piece of code where we loop on a task every second and call UpdateStatus to display the current iteration to some UI control, such as this

Task.Factory.StartNew(() =>
{
   for (var i = 1; i <= 100; i++)
   {
      UpdateStatus(i.ToString());
      Thread.Sleep(1000);
   }
});

Now this is fine, but what about if we want to call this code multiple times, stopping any previous iterations or we simply want a way to cancel the thread mid-operation.

Cancellation is a co-operative process, i.e. we can call the Cancel method on a CancellationTokenSource but we still need code within our task’s loop (in this case) to check if cancel has been called and then exit the loop.

The cancellation token is actually taken from CancellationTokenSource which acts as a wrapper for a single token (see References for information about this separation of concerns). So in our class we’d have the following member field

private CancellationTokenSource _cancellationTokenSource;

If the code which uses this token is called prior to completion then we’d potentially want to call the Cancel method on it and then dispose of it.

_cancellationTokenSource.Cancel();
_cancellationTokenSource.Dispose();

As mentioned, the separation of the token source and token means that when we execute a task we pass, not the token source, but a token take from the source, i.e.

var cancellationToken = _cancellationTokenSource.Token;
Task.Factory.StartNew(() =>
{
   // do something
}, cancellationToken);

The final piece of using the cancellation token is within our task, where we need to check if the cancellation token has been cancelled and if so, we can throw an exception using the following

cancellationToken.ThrowIfCancellationRequested();

Here’s a very simple example of using the cancellation token

public partial class MainWindow : Window
{
   private CancellationTokenSource _cancellationTokenSource;

   public MainWindow()
   {
      InitializeComponent();
   }

   private void Start_OnClick(object sender, RoutedEventArgs e)
   {
      DisposeOfCancellationTokenSource(true);

      _cancellationTokenSource = new CancellationTokenSource();
      var cancellationToken = _cancellationTokenSource.Token;

      UpdateStatus("Starting");
      Task.Factory.StartNew(() =>
      {
         for (var i = 1; i <= 100; i++)
         {
            cancellationToken.ThrowIfCancellationRequested();

            UpdateStatus(i.ToString());

            Thread.Sleep(1000);
         }
      }, cancellationToken)
      .ContinueWith(ca =>
      {
         DisposeOfCancellationTokenSource();
      }, TaskContinuationOptions.OnlyOnFaulted);
   }

   private void UpdateStatus(string status)
   {
      Status.Dispatcher.Invoke(() => Status.Content = status);
   }

   private void DisposeOfCancellationTokenSource(bool cancelFirst = false)
   {
      if (_cancellationTokenSource != null)
      {
         if (cancelFirst)
         {
            _cancellationTokenSource.Cancel();
            UpdateStatus("Cancel called");
         }
         _cancellationTokenSource.Dispose();
         _cancellationTokenSource = null;
         UpdateStatus("TokenSource Disposed");
      }
   }

   private void Stop_OnClick(object sender, RoutedEventArgs e)
   {
      DisposeOfCancellationTokenSource(true);
   }
}
    <Grid>
        <Grid.RowDefinitions>
            <RowDefinition />
            <RowDefinition />
            <RowDefinition />
        </Grid.RowDefinitions>
        <Button Grid.Row="0" Content="Start" Margin="10" Click="Start_OnClick"/>
        <Button Grid.Row="1" Content="Stop" Margin="10" Click="Stop_OnClick"/>
        <Label Grid.Row="2" Name="Status" Content=""/>
    </Grid>

References

Why CancellationToken is separate from CancellationTokenSource?
Task Cancellation
CancellationTokenSource.Dispose Method

Creating a TaskScheduler

In my previous post, ExecutorService based multi-threading in Java, I looked at the ExectorService which allows us to create our own fixed size threadpool which can, at times, be extremely useful.

As part of a port of some Java code (which used the ExectorService) to C# I had a need for a similar class in .NET and came across the LimitedConcurrencyLevelTaskScheduler which is part of the Samples for Parallel Programming with the .NET Framework. The code and example of this class can also be found here, TaskScheduler Class.

The Task factory’s StartNew method comes with an overload which takes a TaskScheduler class and this is where the LimitedConcurrencyLevelTaskScheduler is used. For example

var taskScheduler = new LimitedConcurrencyLevelTaskScheduler(3);
var tsk = Task.Factory.StartNew(() =>
{
   // do something
}, 
CancellationToken.None, 
TaskCreationOptions.None, 
taskScheduler);

So, if we’re in a situation where we need to create a new TaskScheduler then we simply implement a TaskScheduler class, here’s the required overrides.

public class MyTaskScheduler : TaskScheduler
{
   protected override IEnumerable<Task> GetScheduledTasks()
   {
   }

   protected override void QueueTask(Task task)
   {
   }

   protected override bool TryExecuteTaskInline(
      Task task, bool taskWasPreviouslyQueued)
   {
   }
}

The QueueTask method is called when a Task is added to the scheduler. In the case of an implementation such as LimitedConcurrencyLevelTaskScheduler, this is where we add a task to a queue prior to executing the task.

TryExecuteTaskInline is called when trying to execute a task on the current thread, it’s passed a Boolean taskWasPreviouslyQueued which denotes whether the task has already been queued.

GetScheduledTasks is called to get an enumerable of the tasks currently scheduled within our TaskScheduler.

Optionally, we may wish to override the MaximumConcurrencyLevel property which stipulates the maximum concurrency level supported (i.e. number of threads), the default is MaxValue. Also where we might be maintaining a queue of tasks, we wold want to override the TryDequeue method for when the scheduler tries to remove a previously scheduled task.

Obviously implementing the TaskScheduler will also require the developer to handle any thread synchronization etc. within the implementation.

IValueConverter.Convert return values

I was updating some value converters in my converters GitHub repos. PutridParrot.Presentation.Converters and realised I had been returning a null in situations where I really should have been returning DependencyProperty.UnsetValue.

Generally we’ll either return a valid value from a converter or one of the following

  • null
  • DependencyProperty.UnsetValue
  • Binding.DoNothing
  • The original value

The documentation (see References) states that when a null is returned then a “valid null value is used”.

However we may actually prefer that the FallbackValue is used (if supplied) instead, hence we can return a DependencyProperty.UnsetValue.

In cases where we neither want a value returned and do not want the FallbackValue to be called, then we return the Binding.DoNothing.

Obviously, in situations where you do not know what to do with a binding value, it might be better to simply return the value passed into the Convert method.

References

IValueConverter.Convert(Object, Type, Object, CultureInfo) Method

Singletons using C# 6 syntax

A while back I wrote the post The Singleton Pattern in C# and just thought it’d be nice to use C# 6 syntax to update this post.

So here’s the code with the change for to use default property syntax

public sealed class Singleton
{
public static Singleton Instance { get; } = new Singleton();

static Singleton() { }
private Singleton() { }
}

fuslogvw, how could I forget you?

This is one of those reminder’s to myself…

Don’t forget that you can use fuslogvw to find problems loading assemblies.

Why do I need reminding?

I had an issue whereby a release build of an application I was working on had been configured for live/prod for the first time and somebody went to test the application which simply failed at start-up – just displaying a Windows dialog asking whether I wanted to close or debug the application.

Ofcourse, the application worked perfectly on my machine and oddly the non-prod versions also worked fine on the other user’s machine. However the live/prod release had one change to the previous build. A new feature had been removed which wasn’t ready to go live and unbeknown to me, the removal of it’s project caused the build to deploy older versions of a couple of DLL’s as part of the new live/prod build.

On my machine this wasn’t an issue as .NET located the newer versions of the DLL’s, on the other user’s machines these could not be located.

This is fine, it was all part of pre-release testing cycle but a little confusing as all the non-prod configurations worked fine on other user’s machines.

When do we get to fuslogvw?

I haven’t had the need to use fuslogvw for ages, but really should probably use it a lot more. To be honest, it makes sense to have it on all the time to catch such potential issues.

What fuslogvw can do is list any failures during start-up of a .NET application. Running fuxlogvw.exe from the Windows SDK folder (for example C:\Program Files (x86)\Microsoft SDKs\Windows\v10.0A\bin\NETFX 4.7.1 Tools) will result in the fuslog UI being displayed. As you might have guessed from the name the fus-log-vw is a viewer for the fusion log files.

Note: You must run fuslogvw as Admin if you want to change the settings, i.e. set the path of the log files, change the level of loggin, i.e. I just wanted to log all the bind failures, etc.

Leave fuslogvw open and then run the .NET application you’re wanting to take a look at. Now you’ll need to press the Refresh button on fuslogvw to see the logs after the application has started and depending on what you are logging you may see either a list of assemblies that were loaded (for example when just logging everything) or see failures etc.

We can now see what assembly and what version of that assembly the application (we’re monitoring) tried to load and we can inspect the log itself for more information on the failure (via the log file or the fuslogvw).

It’s as simple as that.

Where to store your application data?

Actually I don’t intend to answer the question “Where to store your application data?” because this will depend on your requirements, but what this post will look at is, some of the options available and hopefully help shed light on what best suits your application.

Application data can be separated into two types, user specific data and application specific data (or if you prefer “All User” data).

Obviously multiple user’s might have access to a single machine but an application may be available to all users of a machine, hence we need a way to store settings specific to each user on the machine, for example user preferences. However we also may have application specific data, maybe the application stores a list of URL’s specific, in essence global settings.

Let’s look at some of our options for storing data…

Within your application’s folder

Obviously we could simply store configuration data etc. along with the application, one way to locate this folder is, as follows

var folder = Path.GetDirectoryName(
   Assembly.GetExecutingAssembly().Location) +
   Path.DirectorySeparatorChar + 
   SettingsFileName;

Here we might store a file for application specific data then create another file using the username (here we can use the Environment.UserName) of the user logged into the machine for each user.

This is a simple solution and in some cases more than adequate, plus it has the benefit that if we delete the application (i.e. it wasn’t installed via an installer) then we delete any configuration files.

Program Data

The ProgramData folder is on the system drive and is hidden by default (see C:\ProgramData). As can be inferred from the name, it’s generally used for settings specific to the application itself, i.e. not based upon specific users on a machine.

We can access it using the following code

var folder = Path.Combine(
   Environment.GetFolderPath(
      Environment.SpecialFolder.CommonApplicationData),
      "YourAppName");

Interestingly you can access the ProgramData using C:\Users\AllUsers in File Explorer, although File Explorer will state that you are in C:\Users\AllUsers it’s the same folder as C:\ProgramData.

Program Data can also be located using the environment variable %programdata%.

User Data

So we’ve seen that we can use the Environment.UserName to combine with our file name to create user files, but Windows already has the capability locations for user data. Plus, depending how your OS is set up, this data may be used across any machine a user logs into (known as Roaming).

The default location for the following “User Data” folders is under the location C:\Users\<username>\AppData

Local

The Local folder can be located using the special folder LocalApplicationData, for example

var folder = Path.Combine(
   Environment.GetFolderPath(
      Environment.SpecialFolder.LocalApplicationData),
      "YourAppName");

and is also available via the environment variable %localappdata%.

This location contains data that cannot be stored in the Roaming folder, for example data that’s specific to the machine the user is logged into or that is too large to store in a synchronized roaming folder (i.e. where Roaming folders are synchronized with a server).

Roaming

As hinted at in the section on the Local folder. The Roaming folder can be synchronized with a server, i.e. this is a profile which is accessible from other machines that a user logs into on the same domain. Hence anything stored here will “follow” the user around and so is very useful for preferences, favourites etc. However the space available may be limited depending upon quota settings or other space limitations.

To access this folder we simply use the ApplicationData special folder or environment variable %appdata%, for example

var folder = Path.Combine(
   Environment.GetFolderPath(
      Environment.SpecialFolder.ApplicationData),
      "YourAppName");

LocalLow

The LocalLow folder is basically a restricted version of the Local folder. The data is not synchronized with a server and hence does not move from the machine its created on and it has a lower level of access.

When I say “restricted” or “lower level access” basically this means the application being run, itself has security constraints placed upon it.

The LocalLow folder does not have an entry within the SpecialFolder enumeration, so access the folder you need to use the following (copied from Thomans Levesque’s answer on StackOverflow – https://stackoverflow.com/questions/4494290/detect-the-location-of-appdata-locallow)

[DllImport("shell32.dll")]
static extern int SHGetKnownFolderPath(
   [MarshalAs(UnmanagedType.LPStruct)] Guid rfid, 
   uint dwFlags, 
   IntPtr hToken, 
   out IntPtr pszPath);

public static string GetFolderLocalLow()
{
   var pszPath = IntPtr.Zero;
   try
   {
      var hr = SHGetKnownFolderPath(folderGuid, 0, IntPtr.Zero, out pszPath);
      if (hr < 0)
      {
         throw Marshal.GetExceptionForHR(hr);
      }
      return Marshal.PtrToStringAuto(pszPath);
   }
   finally
   {
      if (pszPath != IntPtr.Zero)
      {
         Marshal.FreeCoTaskMem(pszPath);
      }
   }
}

Accessing location via the environment variables

In a few places I’ve shown the environment variable for each of the locations mentioned. We can also use these variables to locate the folders, for example

var location = 
   Environment.ExpandEnvironmentVariables("%AppData%")

This will result in returning the Roaming folder location, but what’s nice is this static method will work with environment variables combined with file locations (as you’d probably expect), so for example

var location = 
   Environment.ExpandEnvironmentVariables("%AppData%\MyApp")

This will return a path along the lines C:\Users\<username>\AppData\Roaming\MyApp

Source added to https://github.com/putridparrot/blog-projects/tree/master/FileLocations

The WPF Hyperlink

WPF comes with a HyperLink class, but it’s from the System.Windows.Documents namespace, so is mean’t to be embedded within a textual control, such as a TextBlock (i.e. it’s not a standalone control like the System.Windows.Forms.LinkLabel) and within WPF it doesn’t support opening the supplied Uri in an associated process.

Let’s see it’s usage in some XAML

<TextBlock>
   <Hyperlink NavigateUri="http://putridparrot.com/blog/the-wpf-hyperlink">
   The WPF Hyperlink
   </Hyperlink>
</TextBlock>

This XAML will display a the text “The WPF Hyperlink” with underline and when you move your mouse over the link it’ll change colour and the mouse cursor will change to the hand cursor, but clicking on the link will not result in any web browser (or other associated application opening). We must implement such functionality ourselves either responding to the Click event or supplying an ICommand to the Command property.

Here’s a simple example of the sort of code we’d use to running the Uri via it’s associated application.

var process = new Process
{
   StartInfo = new ProcessStartInfo(Uri)
};
process.Start();

We can use databinding to supply the NavigateUri in the standard way, but if you wanted to change the displayed text, then we need to embed another control into the Hyperlink. For example, here we’re using another class from the System.Windows.Documents namespace, the Run class

<TextBlock>
   <Hyperlink NavigateUri="{Binding Uri}">
      <Run>
         <Run.Text>
            <Binding Path="DisplayText"/>
         </Run.Text>
      </Run>
   </Hyperlink>
</TextBlock>