“Don’t forget to flush” .Net Core Application Insights

This post updates a previous post “Don’t forget to flush Application insights Revisited” for .Net Core 3.X and shows the small change required by the deprecation of on of the TelemetryClient constructor overloads.

warning CS0618: ‘TelemetryClient.TelemetryClient()’ is obsolete: ‘We do not recommend using TelemetryConfiguration.Active on .NET Core. See https://github.com/microsoft/ApplicationInsights-dotnet/issues/1152 for more details’

   class Program
   {
      static void Main(string[] args)
      {
#if INSTRUMENTATION_KEY_TELEMETRY_CONFIGURATION
         if (args.Length != 1)
         {
            Console.WriteLine("Usage AzureApplicationInsightsClientConsole <instrumentationKey>");
            return;
         }

         TelemetryConfiguration telemetryConfiguration = new TelemetryConfiguration(args[0]);
         TelemetryClient telemetryClient = new TelemetryClient(telemetryConfiguration);
         telemetryClient.TrackTrace("INSTRUMENTATION_KEY_TELEMETRY_CONFIGURATION", SeverityLevel.Information);
#endif
#if INSTRUMENTATION_KEY_APPLICATION_INSIGHTS_CONFIG
         TelemetryConfiguration telemetryConfiguration = TelemetryConfiguration.CreateDefault();
         TelemetryClient telemetryClient = new TelemetryClient(telemetryConfiguration);
         telemetryClient.TrackTrace("INSTRUMENTATION_KEY_APPLICATION_INSIGHTS_CONFIG", SeverityLevel.Information);
#endif
         telemetryClient.Context.User.Id = Environment.UserName;
         telemetryClient.Context.Device.Id = Environment.MachineName;
         telemetryClient.Context.Operation.Name = "Test harness";

         telemetryClient.TrackTrace("This is a .Net Core AI API Verbose message", SeverityLevel.Verbose);
         telemetryClient.TrackTrace("This is a .Net Core AI API Information message", SeverityLevel.Information);
         telemetryClient.TrackTrace("This is a .Net Core AI API Warning message", SeverityLevel.Warning);
         telemetryClient.TrackTrace("This is a .Net Core AI API Error message", SeverityLevel.Error);
         telemetryClient.TrackTrace("This is a .Net Core AI API Critical message", SeverityLevel.Critical);

         telemetryClient.Flush();

         telemetryConfiguration.Dispose(); // In real-world use a using or similar approach to ensure cleaned up

         Console.WriteLine("Press <enter> to exit");
         Console.ReadLine();
      }
   }

A sample project is available here

Apache Log4net and Application Insights Revisited

In a previous post I showed how we configured a client’s application to use Apache log4net and Azure Application Insights.

I modified the code to allow the Instrumentation Key input via a command line parameter or from the ApplicationInsights.config file.

class Program
{
   private static ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

   static void Main(string[] args)
   {
      if (( args.Length != 0) && (args.Length != 1 ))
      {
         Console.WriteLine("Usage AzureApplicationInsightsClientConsole");
         Console.WriteLine("      AzureApplicationInsightsClientConsole <instrumentationKey>");
         return;
      }

      if (args.Length == 1)
      {
         TelemetryConfiguration.Active.InstrumentationKey = args[0];
      }

      log.Debug("This is a Log4Net Debug message");
      log.Info("This is a Log4Net Info message");
      log.Warn("This is a Log4Net Warning message");
      log.Error("This is an Log4Net Error message");
      log.Fatal("This is a Log4Net Fatal message");

      TelemetryConfiguration.Active.TelemetryChannel.Flush();

      Console.WriteLine("Press <enter> to exit>");
      Console.ReadLine();
   }
}

I updated the Log4Net setup to use the ManagedColoredConsoleAppender which required a couple of modifications to the Log4Net.config file. (I had to remove HighIntensity)

 <appender name="ColoredConsoleAppender" type="log4net.Appender.ManagedColoredConsoleAppender">
      <mapping>
         <level value="ERROR" />
         <foreColor value="White" />
         <backColor value="Red" />
      </mapping>
      <mapping>
         <level value="DEBUG" />
         <backColor value="Green" />
      </mapping>
      <layout type="log4net.Layout.PatternLayout">
         <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
   </appender>

A sample project is available here.

“Don’t forget to flush” Application Insights Revisited

This post revisits a previous post “Don’t forget to flush” Application insights and shows how to configure the instrumentation key in code or via the ApplicationInsights.config file.

 class Program
   {
      static void Main(string[] args)
      {
#if INSTRUMENTATION_KEY_TELEMETRY_CONFIGURATION
         if (args.Length != 1)
         {
            Console.WriteLine("Usage AzureApplicationInsightsClientConsole <instrumentationKey>");
            return;
         }

         TelemetryConfiguration telemetryConfiguration = new TelemetryConfiguration(args[0]);
         TelemetryClient telemetryClient = new TelemetryClient(telemetryConfiguration);
         telemetryClient.TrackTrace("INSTRUMENTATION_KEY_TELEMETRY_CONFIGURATION", SeverityLevel.Information);
#endif
#if INSTRUMENTATION_KEY_APPLICATION_INSIGHTS_CONFIG
         TelemetryClient telemetryClient = new TelemetryClient();
         telemetryClient.TrackTrace("INSTRUMENTATION_KEY_APPLICATION_INSIGHTS_CONFIG", SeverityLevel.Information);
#endif
         telemetryClient.TrackTrace("This is an AI API Verbose message", SeverityLevel.Verbose);
         telemetryClient.TrackTrace("This is an AI API Information message", SeverityLevel.Information);
         telemetryClient.TrackTrace("This is an AI API Warning message", SeverityLevel.Warning);
         telemetryClient.TrackTrace("This is an AI API Error message", SeverityLevel.Error);
         telemetryClient.TrackTrace("This is an AI API Critical message", SeverityLevel.Critical);

         telemetryClient.Flush();

         Console.WriteLine("Press <enter> to exit");
         Console.ReadLine();
      }

A sample project is available here

Azure IoT Hub, Event Grid to Application Insights

For a second Proof of Concept (PoC) I wanted to upload sensor data from my MQTT LoRa Telemetry Field Gateway to an Azure IoT Hub, then using Azure EventGrid subscribe to the stream of telemetry data events, logging the payloads in Azure Application Insights (the aim was minimal code so no database etc.).

The first step was to create and deploy a simple Azure Function for unpacking the telemetry event payload.

Azure IoT Hub Azure Function Handler

Then wire the Azure function to the Microsoft.Devices.Device.Telemetry Event Type

Azure IoT Hub Event Metrics

On the Windows 10 IoT Core device in the Event Tracing Window(ETW) logging on the device I could see LoRa messages arriving and being unpacked.

Windows 10 Device ETW showing message payload

Then in Application Insights after some mucking around with code I could see in a series of Trace statements the event payload as it was unpacked.

{"id":"29108ebf-e5d5-7b95-e739-7d9048209d53","topic":"/SUBSCRIPTIONS/12345678-9012-3456-7890-123456789012/RESOURCEGROUPS/AZUREIOTHUBEVENTGRIDAZUREFUNCTION/PROVIDERS/MICROSOFT.DEVICES/IOTHUBS/FIELDGATEWAYHUB",
"subject":"devices/MQTTNetClient",
"eventType":"Microsoft.Devices.DeviceTelemetry",
"eventTime":"2020-02-01T04:30:51.427Z",
"data":
{
 "properties":{},
"systemProperties":{"iothub-connection-device-id":"MQTTNetClient","iothub-connection-auth-method":"{\"scope\":\"device\",\"type\":\"sas\",\"issuer\":\"iothub\",\"acceptingIpFilterRule\":null}",
"iothub-connection-auth-generation-id":"637149890997219611",
"iothub-enqueuedtime":"2020-02-01T04:30:51.427Z",
"iothub-message-source":"Telemetry"
},
"body":"eyJPZmZpY2VUZW1wZXJhdHVyZSI6IjIyLjUiLCJPZmZpY2VIdW1pZGl0eSI6IjkyIn0="
},
"dataVersion":"",
"metadataVersion":"1"
}
Application Insights logging with message unpacking
Application Insights logging message payload

Then in the last log entry the decoded message payload

/*
    Copyright ® 2020 Feb devMobile Software, All Rights Reserved
 
    MIT License

    Permission is hereby granted, free of charge, to any person obtaining a copy
    of this software and associated documentation files (the "Software"), to deal
    in the Software without restriction, including without limitation the rights
    to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
    copies of the Software, and to permit persons to whom the Software is
    furnished to do so, subject to the following conditions:

    The above copyright notice and this permission notice shall be included in all
    copies or substantial portions of the Software.

    THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
    IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
    FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
    AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
    LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
    OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
    SOFTWARE

    Default URL for triggering event grid function in the local environment.
    http://localhost:7071/runtime/webhooks/EventGrid?functionName=functionname
 */
namespace EventGridProcessorAzureIotHub
{
   using System;
   using System.IO;
   using System.Reflection;

   using Microsoft.Azure.WebJobs;
   using Microsoft.Azure.EventGrid.Models;
   using Microsoft.Azure.WebJobs.Extensions.EventGrid;

   using log4net;
   using log4net.Config;
   using Newtonsoft.Json;

   public static class Telemetry
    {
        [FunctionName("Telemetry")]
        public static void Run([EventGridTrigger]Microsoft.Azure.EventGrid.Models.EventGridEvent eventGridEvent, ExecutionContext executionContext )//, TelemetryClient telemetryClient)
        {
			ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

		   var logRepository = LogManager.GetRepository(Assembly.GetEntryAssembly());
			XmlConfigurator.Configure(logRepository, new FileInfo(Path.Combine(executionContext.FunctionAppDirectory, "log4net.config")));

         log.Info($"eventGridEvent.Data-{eventGridEvent}");

         log.Info($"eventGridEvent.Data.ToString()-{eventGridEvent.Data.ToString()}");

        IotHubDeviceTelemetryEventData iOThubDeviceTelemetryEventData = (IotHubDeviceTelemetryEventData)JsonConvert.DeserializeObject(eventGridEvent.Data.ToString(), typeof(IotHubDeviceTelemetryEventData));

         log.Info($"iOThubDeviceTelemetryEventData.Body.ToString()-{iOThubDeviceTelemetryEventData.Body.ToString()}");

         byte[] base64EncodedBytes = System.Convert.FromBase64String(iOThubDeviceTelemetryEventData.Body.ToString());

         log.Info($"System.Text.Encoding.UTF8.GetString(-{System.Text.Encoding.UTF8.GetString(base64EncodedBytes)}");
      }
	}
}

Overall it took roughly half a page of code (mainly generated by a tool) to unpack and log the contents of an Azure IoT Hub EventGrid payload to Application Insights.

Azure Function Log4Net configuration

This post was inspired by the couple of hours lost from my life yesterday while I figured out how to get Apache Log4Net and Azure Application Insights working in an Azure Function built with .Net Core 2.X.

After extensive searching I found a couple of relevant blog posts but these had complex approaches and I wanted to keep the churn in the codebase I was working on to an absolute minimum.

With the different versions of the libraries involved (Late March 2019) this was what worked for me so YMMV. To provide the simplest possible example I have created a TimerTrigger which logs information via Log4Net to Azure Application Insights.

Initially the Log4Net configuration wasn’t loaded because its location is usually configured in the AssemblyInfo.cs file and .Net Core 2.x code doesn’t have one.

// You can specify all the values or you can default the Build and Revision Numbers
// by using the '*' as shown below:
// [assembly: AssemblyVersion("1.0.*")]
[assembly: AssemblyVersion("1.0.0.0")]
[assembly: AssemblyFileVersion("1.0.0.0")]
[assembly: log4net.Config.XmlConfigurator]

I figured I would have to manually load the Log4Net configuration and had to look at the file system of machine running the function to figure out where the Log4Net XML configuration file was getting copied to.

The “Copy to output directory” setting is important

Then I had to get the Dependency Injection (DI) framework to build an ExecutionContext for me so I could get the FunctionAppDirectory to combine with the Log4Net config file name. I used Path.Combine which is more robust and secure than manually concatenating segments of a path together.

/*
    Copyright ® 2019 March devMobile Software, All Rights Reserved
 
    MIT License
...
*/
namespace ApplicationInsightsAzureFunctionLog4NetClient
{
	using System;
	using System.IO;
	using System.Reflection;
	using log4net;
	using log4net.Config;
	using Microsoft.ApplicationInsights.Extensibility;
	using Microsoft.Azure.WebJobs;

	public static class ApplicationInsightsTimer
	{
		[FunctionName("ApplicationInsightsTimerLog4Net")]
		public static void Run([TimerTrigger("0 */1 * * * *")]TimerInfo myTimer, ExecutionContext executionContext)
		{
			ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

			TelemetryConfiguration.Active.InstrumentationKey = Environment.GetEnvironmentVariable("InstrumentationKey", EnvironmentVariableTarget.Process);

			var logRepository = LogManager.GetRepository(Assembly.GetEntryAssembly());
			XmlConfigurator.Configure(logRepository, new FileInfo(Path.Combine(executionContext.FunctionAppDirectory, "log4net.config")));

			log.Debug("This is a Log4Net Debug message");
			log.Info("This is a Log4Net Info message");
			log.Warn("This is a Log4Net Warning message");
			log.Error("This is a Log4Net Error message");
			log.Fatal("This is a Log4Net Fatal message");

			TelemetryConfiguration.Active.TelemetryChannel.Flush();
		}
	}
}

Log4Net logging in Azure Application Insights

The latest code for my Azure Function Log4net to Applications Insights sample along with some samples for other logging platforms is available on GitHub.

ASP MVC Core V2.1 and Cross-Origin Resource Sharing

I’m working on an project for a customer which implements a number of application programming Interfaces(API) for a Single Page Application(SPA) and other clients. We are using entity tags (ETags) for versioning and the front end developers found the couldn’t access them from javascipt running in mainstream browser clients (June 2018).

The problems was understanding how Cross-Origin Resource Sharing (CORS) worked and how it interacted with our security model (API key and OAuth2.0 depending on the client)

In our scenario we first found the pre-flight check wasn’t working because in the HyperText Transfer Protocol (HTTP) OPTIONS method our X-API-KEY check was failing

OPTIONS http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
Access-Control-Request-Headers: x-api-key
Access-Control-Request-Method: GET
Accept-Encoding: gzip, deflate
Content-Length: 0
Host: xyz.azurewebsites.net
Connection: Keep-Alive
Pragma: no-cache

HTTP/1.1 400 Bad Request
Transfer-Encoding: chunked
Server: Kestrel
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 05:48:30 GMT

13
API Key is invalid.
0

So I disabled X-API-KEY validation in startup.cs

public async Task Invoke(HttpContext context)
{
   if (context.Request.Method == "OPTIONS")
   {
      await this.next.Invoke(context);
      return;
   }

   var claims = new List();
…

OPTIONS then worked

OPTIONS http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
Access-Control-Request-Headers: x-api-key
Access-Control-Request-Method: GET
Accept-Encoding: gzip, deflate
Content-Length: 0
Host: xyz.azurewebsites.net
Connection: Keep-Alive
Pragma: no-cache

HTTP/1.1 404 Not Found
Server: Kestrel
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 05:52:20 GMT
Content-Length: 0

I then turned on CORS allowing pretty much anything

public void ConfigureServices(IServiceCollection services)
{
   services.AddCors(options =>
   {
      options.AddPolicy("CorsPolicy",
      builder => builder.AllowAnyOrigin()
         .AllowAnyMethod()
         .AllowAnyHeader()
         .AllowCredentials());
   });
   services.AddMvc();
}

public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
{
   if (env.IsDevelopment())
   {
      app.UseDeveloperExceptionPage();
   }

   TelemetryConfiguration.Active.InstrumentationKey = this.configuration.GetSection("ApplicationInsights").GetSection("InstrumentationKey").Value;

   loggerFactory.AddLog4Net();
   this.log.Info("Startup.Configure called");

   app.ApplyUserKeyValidation();
   app.UseCors("CorsPolicy");
   app.UseMvc();
   }
}

OPTIONS then worked

OPTIONS http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
Access-Control-Request-Headers: x-api-key
Access-Control-Request-Method: GET
Accept-Encoding: gzip, deflate
Content-Length: 0
Host: xyz.azurewebsites.net
Connection: Keep-Alive
Pragma: no-cache

HTTP/1.1 204 No Content
Vary: Origin
Server: Kestrel
Access-Control-Allow-Credentials: true
Access-Control-Allow-Headers: x-api-key
Access-Control-Allow-Origin: file://
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 05:57:33 GMT

GET then worked

GET http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
X-API-KEY: ABCDEFGHIJKLMNOPQRSTUVWXYZ
Accept-Language: en-NZ
Accept-Encoding: gzip, deflate
If-None-Match: 00-00-00-00-00-00-00-76
Host: xyz.azurewebsites.net
Connection: Keep-Alive

HTTP/1.1 200 OK
Content-Type: application/json; charset=utf-8
ETag: 00-00-00-00-00-00-00-76
Vary: Origin,Accept-Encoding
Server: Kestrel
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: file://
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 05:57:34 GMT
Content-Length: 2216

[{"...."}}

But HEAD didn’t work

HEAD http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
X-API-KEY: ABCDEFGHIJKLMNOPQRSTUVWXYZ
Accept-Language: en-NZ
Accept-Encoding: gzip, deflate
If-None-Match: 00-00-00-00-00-00-00-76
Host: xyz.azurewebsites.net
Connection: Keep-Alive

HTTP/1.1 400 Bad Request
Content-Length: 0
Vary: Origin
Server: Kestrel
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: file://
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 05:59:55 GMT

From the Application Insights logging and RestTest client (which I ran locally and remotely) I could see that the client side code couldn’t access the value of our eTag.  It had to be “exposed”

public void ConfigureServices(IServiceCollection services)
{
   services.AddCors(options =>
   {
      options.AddPolicy("CorsPolicy",
            builder => builder.AllowAnyOrigin()
            .AllowAnyMethod()
            .AllowAnyHeader()
            .WithExposedHeaders("etag")
            .AllowCredentials()
         );
      });
      services.AddMvc();
   }
...

GET then worked

GET http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
X-API-KEY: ABCDEFGHIJKLMNOPQRSTUVWXYZ
ETag: 00-00-00-00-00-00-00-76
Accept-Language: en-NZ
Accept-Encoding: gzip, deflate
If-None-Match: 00-00-00-00-00-00-00-76
Host: xyz.azurewebsites.net
Connection: Keep-Alive

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Type: application/json; charset=utf-8
Content-Encoding: gzip
ETag: 00-00-00-00-00-00-00-76
Vary: Origin,Accept-Encoding
Server: Kestrel
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: file://
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 07:53:41 GMT

[{"...."}}

HEAD then worked

OPTIONS http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
Access-Control-Request-Headers: x-api-key,etag
Access-Control-Request-Method: HEAD
Accept-Encoding: gzip, deflate
Content-Length: 0
Host: xyz.azurewebsites.net
Connection: Keep-Alive
Pragma: no-cache

HTTP/1.1 204 No Content
Vary: Origin
Server: Kestrel
Access-Control-Allow-Credentials: true
Access-Control-Allow-Headers: x-api-key,etag
Access-Control-Allow-Origin: file://
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 07:57:31 GMT

HEAD http://xyz.azurewebsites.net/api/portfolio HTTP/1.1
...
X-API-KEY: ABCDEFGHIJKLMNOPQRSTUVWXYZ
ETag: 00-00-00-00-00-00-00-76
Accept-Language: en-NZ
Accept-Encoding: gzip, deflate
Host: xyz.azurewebsites.net
Connection: Keep-Alive
Pragma: no-cache

HTTP/1.1 304 Not Modified
Vary: Origin
Server: Kestrel
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: file://
X-Powered-By: ASP.NET
...
Date: Sun, 24 Jun 2018 07:57:31 GMT

I had some oddness with releasing code updates which I think was down to caching of pre-flight request responses.
Next steps tidy up the headers etc. and lock the CORS configuration down to expose the minimum necessary required for the application to work.

NLog and Application Insights

Another of my clients has an application which uses NLog and sooner or later they are going to want to move their logging to Azure Application Insights.

The application consists of a number of Azure websites and some embedded clients. The Azure applications log information to the local file system on each box but the number of boxes is growing so finding and tracing issues is becoming painful.

//---------------------------------------------------------------------------------
// Copyright (c) 2018, devMobile Software
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//     http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
//---------------------------------------------------------------------------------
using System;
using Microsoft.ApplicationInsights.Extensibility;
using NLog;

namespace devMobile.Azure.ApplicationInsightsNLogClient
{
   class Program
   {
      private static Logger log = LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType.ToString());

      static void Main(string[] args)
      {
         if (args.Length != 1)
         {
            Console.WriteLine("Command line argument InstrumentationKey missing");
            return;
         }
         TelemetryConfiguration.Active.InstrumentationKey = args[0];

         log.Trace("This is nLog");
         log.Debug("This is a Debug message");
         log.Info("This is a Info message");
         log.Warn("This is a Warning message");
         log.Error("This is an Error message");
         log.Fatal("This is a Fatal message");

         new Microsoft.ApplicationInsights.TelemetryClient().Flush();
      }
   }
}

Sample code ApplicationInsightsNLogClient

Two clients to go, one which uses serilog the other has a DIY system which I’m ignoring as long as possible.