The Things Network Cayenne LPP Support

Uplink Encoding

In my applications the myDevices Cayenne Low power payload(LPP) uplink messages from my *duino devices are decoded by the built in The Things Network(TTN) decoder. I can also see the nicely formatted values in the device data view.

Downlink Encoding

I could successfully download raw data to the device but I found that manually unpacking it on the device was painful.

Raw data

I really want to send LPP formatted messages to my devices so I could use a standard LPP library. I initially populated the payload fields in the downlink message JSON. The TTN documentation appeared to indicate this was possible.

Download JSON payload format

Initially I tried a more complex data type because I was looking at downloading a location to the device.

Complex data type

I could see nicely formatted values in the device data view but they didn’t arrive at the device. I then tried simpler data type to see if the complex data type was an issue.

Simple Data Types

At this point I asked a few questions on the TTN forums and started to dig into the TTN source code.

Learning Go on demand

I had a look at the TTB Go code and learnt a lot as I figured out how the “baked in “encoder/decoder worked. I haven’t done any Go coding so it took a while to get comfortable with the syntax. The code my look a bit odd as a Pascal formatter was the closest I could get to Go.

In core/handler/cayennelpp/encoder.go there was

func (e *Encoder) Encode(fields map[string]interface{}, fPort uint8) ([]byte, bool, error) and func (d *Decoder) Decode(payload []byte, fPort uint8) (map[string]interface{}, bool, error)

Which was a positive sign…

Then in core/handler/convert_fields.go there are these two functions

> // ConvertFieldsUp converts the payload to fields using the application's payload formatter
> func (h *handler) ConvertFieldsUp(ctx ttnlog.Interface, _ *pb_broker.DeduplicatedUplinkMessage, appUp *types.UplinkMessage, dev *device.Device) error {
> 	// Find Application

and

> // ConvertFieldsDown converts the fields into a payload
> func (h *handler) ConvertFieldsDown(ctx ttnlog.Interface, appDown *types.DownlinkMessage, ttnDown *pb_broker.DownlinkMessage, _ *device.Device) error {

Then further down in the second function is this call

var encoder PayloadEncoder
	switch app.PayloadFormat {
	case application.PayloadFormatCustom:
		encoder = &CustomDownlinkFunctions{
			Encoder: app.CustomEncoder,
			Logger:  functions.Ignore,
		}
	case application.PayloadFormatCayenneLPP:
		encoder = &cayennelpp.Encoder{}
	default:
		return nil
	}var encoder PayloadEncoder
	switch app.PayloadFormat {
	case application.PayloadFormatCustom:
		encoder = &CustomDownlinkFunctions{
			Encoder: app.CustomEncoder,
			Logger:  functions.Ignore,
		}
	case application.PayloadFormatCayenneLPP:
		encoder = &cayennelpp.Encoder{}
	default:
		return nil
	}

Which I think calls

// Encode encodes the fields to CayenneLPP
func (e *Encoder) Encode(fields map[string]interface{}, fPort uint8) ([]byte, bool, error) {
	encoder := protocol.NewEncoder()
	for name, value := range fields {
		key, channel, err := parseName(name)
		if err != nil {
			continue
		}
		switch key {
		case valueKey:
			if val, ok := value.(float64); ok {
				encoder.AddPort(channel, float32(val))
			}
		}
	}
	return encoder.Bytes(), true, nil
}

Then right down at the very bottom of the call stack in keys.go

func parseName(name string) (string, uint8, error) {
	parts := strings.Split(name, "_")
	if len(parts) < 2 {
		return "", 0, errors.New("Invalid name")
	}
	key := strings.Join(parts[:len(parts)-1], "_")
	if key == "" {
		return "", 0, errors.New("Invalid key")
	}
	channel, err := strconv.Atoi(parts[len(parts)-1])
	if err != nil {
		return "", 0, err
	}
	if channel < 0 || channel > 255 {
		return "", 0, errors.New("Invalid range")
	}
	return key, uint8(channel), nil
}

At this point I started to hit the limits of my Go skills but with some trial and error I figured it out…

Executive Summary

The downlink payload values are sent as 2 byte floats with a sign bit, 100 multiplier. The fields have to be named “value_X” where X is is a byte value.

Dictionary<string, object> payloadFields = new Dictionary<string, object>();
payloadFields.Add(“value_0”, 0.0);
//00-00-00
payloadFields.Add(“value_1”, 1.0);
//01-00-64
payloadFields.Add(“value_2”, 2.0);
//02-00-C8
payloadFields.Add(“value_3”, 3.0);
//03-01-2C
payloadFields.Add(“value_4”, 4.0);
//04-01-90

payloadFields.Add(“value_0”, -0.0);
//00-00-00
payloadFields.Add(“value_1”, -1.0);
//01-FF-9C
payloadFields.Add(“value_2”, -2.0);
//02-FF-38
payloadFields.Add(“value_3”, -3.0);
//03-FE-D4
payloadFields.Add(“value_4”, -4.0);
//04-FE-70

I could see these arrive on my TinyCLR plus RAK811 device and could manually unpack them

The stream of bytes can be decoded on an Arduino using the electronic cats library (needs a small modification) with code this

byte data[] = {0xff,0x38} ; // bytes which represent -2 
float value = lpp.getValue( data, 2, 100, 1);
Serial.print("value:");
Serial.println(value);

It is possible to use the “baked” in Cayenne Encoder/Decoder to send payload fields to a device but I’m not certain is this is quite what myDevices/TTN intended.

The Things Network HTTP Integration Part13

Connection multiplexing

For the Proof of Concept(PoC) I had used a cache to store Azure IoT Hub connections to reduce the number of calls to the Device Provisioning Service(DPS).

Number of connections with no pooling

When stress testing with 1000’s of devices my program hit the host connection limit so I enabled Advanced Message Queuing Protocol(AMQP) connection pooling.

return DeviceClient.Create(result.AssignedHub,
                  authentication,
                  new ITransportSettings[]
                  {
                     new AmqpTransportSettings(TransportType.Amqp_Tcp_Only)
                     {
                        PrefetchCount = 0,
                        AmqpConnectionPoolSettings = new AmqpConnectionPoolSettings()
                        {
                           Pooling = true,
                        }
                     }
                  }
               );

My first attempt failed as I hadn’t configured “TransportType.Amqp_Tcp_Only” which would have allowed the AMQP implementation to fallback to other protocols which don’t support pooling.

Exception caused by not using TransportType.Amqp_Tcp_Only

I then deployed the updated code and ran my 1000 device stress test (note the different x axis scales)

Number of connections with pooling

This confirmed what I found in the Azure.AMQP source code

/// <summary>
/// The default size of the pool
/// </summary>
/// <remarks>
/// Allows up to 100,000 devices
/// </remarks>
/// private const uint DefaultPoolSize = 100;

The Things Network HTTP Integration Part12

Removing the DIY cache

For the Proof of Concept(PoC) I had written a simple cache using a ConcurrentDictionary to store Azure IoT Hub connections to reduce the number of calls to the Device Provisioning Service(DPS).

Device Provisioning Service calls in stress test

For a PoC the DIY cache was ok but I wanted to replace it with something more robust like the .Net ObjectCache which is in the System.Runtime.Caching namespace.

I started by replacing the ConcurrentDictionary declaration

static readonly ConcurrentDictionary<string, DeviceClient> DeviceClients = new ConcurrentDictionary<string, DeviceClient>();
     

With an ObjectCache declaration.

static readonly ObjectCache DeviceClients = MemoryCache.Default;
  

Then, where there were compiler errors I updated the method call.

// See if the device has already been provisioned or is being provisioned on another thread.
if (DeviceClients.Add(registrationId, deviceContext, cacheItemPolicy))
{
   log.LogInformation("RegID:{registrationId} Device provisioning start", registrationId);
...

One difference I found was that ObjectCache throws an exception if the value is null. I was using a null value to indicate that the Device Provisioning Service(DPS) process had been initiated on another thread and was underway.

I have been planning to add support for downlink messages so I added a new class to store the uplink (Azure IoT Hub DeviceClient) and downlink ( downlink_url in the uplink message) details.

 public class DeviceContext
   {
      public DeviceClient Uplink { get; set; }
      public Uri Downlink { get; set; }
   }

For the first version the only functionality I’m using is sliding expiration which is set to one day

CacheItemPolicy cacheItemPolicy = new CacheItemPolicy()
{
   SlidingExpiration = new TimeSpan(1, 0, 0, 0),
   //RemovedCallback
};

DeviceContext deviceContext = new DeviceContext()
{
   Uplink = null,
   Downlink = new Uri(payload.DownlinkUrl)
};

I didn’t have to make many changes and I’ll double check my implementation in the next round of stress and soak testing.

The Things Network HTTP Integration Part11

Moving Secrets to KeyVault

The application configuration file contained sensitive information like Device Provision Service(DPS) Group Enrollment Symmetric Keys and Azure IoT Hub connection strings which is OK for a proof of concept (PoC) but sub-optimal for production deployments.

"DeviceProvisioningService": {
      "GlobalDeviceEndpoint": "global.azure-devices-provisioning.net",
      "ScopeID": "",
      "EnrollmentGroupSymmetricKeyDefault": "TopSecretKey",
      "DeviceProvisioningPollingDelay": 500,
      "ApplicationEnrollmentGroupMapping": {
         "Application1": "TopSecretKey1",
         "Application2": "TopSecretKey2"
      }
   }

The Azure Key Vault is intended for securing sensitive information like connection strings so I added one to my resource group.

Azure Key Vault overview and basic metrics

I wrote a wrapper which resolves configuration settings based on the The Things Network(TTN) application identifier and port information in the uplink message payload. The resolve methods start by looking for configuration for the applicationId and port (separated by a – ), then the applicationId and then finally falling back to a default value. This functionality is used for AzureIoTHub connection strings, DPS IDScopes, DPS Enrollment Group Symmetric Keys, and is also used to format the cache keys.

public class ApplicationConfiguration
{
const string DpsGlobaDeviceEndpointDefault = "global.azure-devices-provisioning.net";

private IConfiguration Configuration;

public void Initialise( )
{
   // Check that KeyVault URI is configured in environment variables. Not a lot we can do if it isn't....
   if (Configuration == null)
   {
      string keyVaultUri = Environment.GetEnvironmentVariable("KeyVaultURI");
      if (string.IsNullOrWhiteSpace(keyVaultUri))
      {
         throw new ApplicationException("KeyVaultURI environment variable not set");
      }

      // Load configuration from KeyVault 
      Configuration = new ConfigurationBuilder()
         .AddEnvironmentVariables()
         .AddAzureKeyVault(keyVaultUri)
         .Build();
   }
}

public string DpsGlobaDeviceEndpointResolve()
{
   string globaDeviceEndpoint = Configuration.GetSection("DPSGlobaDeviceEndpoint").Value;
   if (string.IsNullOrWhiteSpace(globaDeviceEndpoint))
   {
      globaDeviceEndpoint = DpsGlobaDeviceEndpointDefault;
   }

   return globaDeviceEndpoint;
}

public string ConnectionStringResolve(string applicationId, int port)
{
   // Check to see if there is application + port specific configuration
   string connectionString = Configuration.GetSection($"AzureIotHubConnectionString-{applicationId}-{port}").Value;
   if (!string.IsNullOrWhiteSpace(connectionString))
   {
      return connectionString;
   }

   // Check to see if there is application specific configuration, otherwise run with default
   connectionString = Configuration.GetSection($"AzureIotHubConnectionString-{applicationId}").Value;
   if (!string.IsNullOrWhiteSpace(connectionString))
   {
      return connectionString;
   }

   // get the default as not a specialised configuration
   connectionString = Configuration.GetSection("AzureIotHubConnectionStringDefault").Value;

   return connectionString;
}

public string DpsIdScopeResolve(string applicationId, int port)
{
   // Check to see if there is application + port specific configuration
   string idScope = Configuration.GetSection($"DPSIDScope-{applicationId}-{port}").Value;
   if (!string.IsNullOrWhiteSpace(idScope))
   {
      return idScope;
   }

   // Check to see if there is application specific configuration, otherwise run with default
   idScope = Configuration.GetSection($"DPSIDScope-{applicationId}").Value;
   if (!string.IsNullOrWhiteSpace(idScope))
   {
      return idScope;
   }

   // get the default as not a specialised configuration
   idScope = Configuration.GetSection("DPSIDScopeDefault").Value;

   if (string.IsNullOrWhiteSpace(idScope))
   {
      throw new ApplicationException($"DPSIDScope configuration invalid");
   }

   return idScope;
}

The values of Azure function configuration settings are replaced by a reference to the secret in the Azure Key Vault.

Azure Function configuration value replacement

In the Azure Key Vault “Access Policies” I configured an “Application Access Policy” so my Azure TTNAzureIoTHubMessageV2Processor function identity could retrieve secrets.

Azure Key Vault Secrets

I kept on making typos in the secret names and types which was frustrating.

Azure Key Vault secret

While debugging in Visual Studio you may need to configure the Azure Identity so the application can access the Azure Key Vault.

The Things Network HTTP Integration Part10

Assembling the components

After a series of articles exploring how portions of solution could be built

I now had working code for receiving The Things Network(TTN) HTTP integration JSON messages with an Azure Function using an HTTPTrigger. (secured with an APIKey) and then putting them into an Azure Storage Queue for processing. This code was intentionally kept as small and as simple as possible so there was less to go wrong. The required configuration is also minimal.

HTTP Endpoint handler application

In the last couple of posts I had been building an Azure Function with a QueueTrigger to process the uplink messages. The function used custom bindings so that the CloudQueueMessage could be accessed, and load the Azure Storage account plus queue name from configuration. I’m still using classes generated by JSON2CSharp (with minimal modifications) for deserialising the payloads with JSON.Net.

The message processor Azure Function uses a ConcurrentCollection to store AzureDeviceClient objects constructed using the information returned by the Azure Device Provisioning Service(DPS). This is so the DPS doesn’t have to be called for the connection details for every message.(When the Azure function is restarted the dictionary of DeviceClient objects has to be repopulated). If there is a backlog of messages the message processor can process more than a dozen messages concurrently so the telemetry events displayed in an application like Azure IoT Central can arrive out of order.

The solution uses DPS Group Enrollment with Symmetric Key Attestation so Azure IoT Hub devices can be “automagically” created when a message from a new device is processed. The processing code is multi-thread and relies on many error conditions being handled by the Azure Function retry mechanism. After a number of failed retries the messages are moved to a poison queue. Azure Storage Explorer is a good tool for viewing payloads and moving poison messages back to the processing queue.

public static class UplinkMessageProcessor
{
   static readonly ConcurrentDictionary<string, DeviceClient> DeviceClients = new ConcurrentDictionary<string, DeviceClient>();

   [FunctionName("UplinkMessageProcessor")]
   public static async Task Run(
      [QueueTrigger("%UplinkQueueName%", Connection = "AzureStorageConnectionString")]
      CloudQueueMessage cloudQueueMessage, // Used to get CloudQueueMessage.Id for logging
      Microsoft.Azure.WebJobs.ExecutionContext context,
      ILogger log)
   {
      PayloadV5 payloadObect;
      DeviceClient deviceClient = null;
      DeviceProvisioningServiceSettings deviceProvisioningServiceConfig;

      string environmentName = Environment.GetEnvironmentVariable("ENVIRONMENT");

      // Load configuration for DPS. Refactor approach and store securely...
      var configuration = new ConfigurationBuilder()
      .SetBasePath(context.FunctionAppDirectory)
      .AddJsonFile($"appsettings.json")
      .AddJsonFile($"appsettings.{environmentName}.json")
      .AddEnvironmentVariables()
      .Build();

      // Load configuration for DPS. Refactor approach and store securely...
      try
      {
         deviceProvisioningServiceConfig = (DeviceProvisioningServiceSettings)configuration.GetSection("DeviceProvisioningService").Get<DeviceProvisioningServiceSettings>(); ;
      }
      catch (Exception ex)
      {
         log.LogError(ex, $"Configuration loading failed");
         throw;
      }

      // Deserialise uplink message from Azure storage queue
      try
      {
         payloadObect = JsonConvert.DeserializeObject<PayloadV5>(cloudQueueMessage.AsString);
      }
      catch (Exception ex)
      {
         log.LogError(ex, $"MessageID:{cloudQueueMessage.Id} uplink message deserialisation failed");
         throw;
      }

      // Extract the device ID as it's used lots of places
      string registrationID = payloadObect.hardware_serial;

      // Construct the prefix used in all the logging
      string messagePrefix = $"MessageID: {cloudQueueMessage.Id} DeviceID:{registrationID} Counter:{payloadObect.counter} Application ID:{payloadObect.app_id}";
      log.LogInformation($"{messagePrefix} Uplink message device processing start");

      // See if the device has already been provisioned
      if (DeviceClients.TryAdd(registrationID, deviceClient))
      {
         log.LogInformation($"{messagePrefix} Device provisioning start");

         string enrollmentGroupSymmetricKey = deviceProvisioningServiceConfig.EnrollmentGroupSymmetricKeyDefault;

         // figure out if custom mapping for TTN applicationID
         if (deviceProvisioningServiceConfig.ApplicationEnrollmentGroupMapping != null)
        {
            deviceProvisioningServiceConfig.ApplicationEnrollmentGroupMapping.GetValueOrDefault(payloadObect.app_id, deviceProvisioningServiceConfig.EnrollmentGroupSymmetricKeyDefault);
         }

         // Do DPS magic first time device seen
         await DeviceRegistration(log, messagePrefix, deviceProvisioningServiceConfig.GlobalDeviceEndpoint, deviceProvisioningServiceConfig.ScopeID, enrollmentGroupSymmetricKey, registrationID);
      }

      // Wait for the Device Provisioning Service to complete on this or other thread
      log.LogInformation($"{messagePrefix} Device provisioning polling start");
      if (!DeviceClients.TryGetValue(registrationID, out deviceClient))
      {
         log.LogError($"{messagePrefix} Device provisioning polling TryGet before while failed");

         throw new ApplicationException($"{messagePrefix} Device provisioning polling TryGet before while failed");
      }

      while (deviceClient == null)
      {
         log.LogInformation($"{messagePrefix} provisioning polling delay");
         await Task.Delay(deviceProvisioningServiceConfig.DeviceProvisioningPollingDelay);

         if (!DeviceClients.TryGetValue(registrationID, out deviceClient))
         {
            log.LogError($"{messagePrefix} Device provisioning polling TryGet while loop failed");

            throw new ApplicationException($"{messagePrefix} Device provisioning polling TryGet while loopfailed");
         }
      }

      // Assemble the JSON payload to send to Azure IoT Hub/Central.
      log.LogInformation($"{messagePrefix} Payload assembly start");
      JObject telemetryEvent = new JObject();
      try
      {
         JObject payloadFields = (JObject)payloadObect.payload_fields;
         telemetryEvent.Add("HardwareSerial", payloadObect.hardware_serial);
         telemetryEvent.Add("Retry", payloadObect.is_retry);
         telemetryEvent.Add("Counter", payloadObect.counter);
         telemetryEvent.Add("DeviceID", payloadObect.dev_id);
         telemetryEvent.Add("ApplicationID", payloadObect.app_id);
         telemetryEvent.Add("Port", payloadObect.port);
         telemetryEvent.Add("PayloadRaw", payloadObect.payload_raw);
         telemetryEvent.Add("ReceivedAt", payloadObect.metadata.time);

         // If the payload has been unpacked in TTN backend add fields to telemetry event payload
         if (payloadFields != null)
         {
            foreach (JProperty child in payloadFields.Children())
            {
               EnumerateChildren(telemetryEvent, child);
            }
         }
      }
      catch (Exception ex)
      {
         if (DeviceClients.TryRemove(registrationID, out deviceClient))
         {
            log.LogWarning($"{messagePrefix} TryRemove payload assembly failed");
         }

         log.LogError(ex, $"{messagePrefix} Payload assembly failed");
         throw;
      }

      // Send the message to Azure IoT Hub/Azure IoT Central
      log.LogInformation($"{messagePrefix} Payload SendEventAsync start");
      try
      {
         using (Message ioTHubmessage = new Message(Encoding.ASCII.GetBytes(JsonConvert.SerializeObject(telemetryEvent))))
         {
            // Ensure the displayed time is the acquired time rather than the uploaded time. esp. importan for messages that end up in poison queue
            ioTHubmessage.Properties.Add("iothub-creation-time-utc", payloadObect.metadata.time.ToString("s", CultureInfo.InvariantCulture));
            await deviceClient.SendEventAsync(ioTHubmessage);
         }
      }
      catch (Exception ex)
      {
         if (DeviceClients.TryRemove(registrationID, out deviceClient))
         {
            log.LogWarning($"{messagePrefix} TryRemove SendEventAsync failed");
         }

         log.LogError(ex, $"{messagePrefix} SendEventAsync failed");
         throw;
      }

   log.LogInformation($"{messagePrefix} Uplink message device processing completed");
   }
}

There is also support for using a specific GroupEnrollment based on the application_id in the uplink message payload.

"DeviceProvisioningService": {
      "GlobalDeviceEndpoint": "global.azure-devices-provisioning.net",
      "ScopeID": "",
      "EnrollmentGroupSymmetricKeyDefault": "TopSecretKey",
      "DeviceProvisioningPollingDelay": 500,
      "ApplicationEnrollmentGroupMapping": {
         "Application1": "TopSecretKey1",
         "Application2": "TopSecretKey2"
      }
   }

In addition to the appsettings.json there is configuration for application insights, uplink message queue name and Azure Storage connection strings. The “Environment” setting is important as it specifies what appsettings.json file should be used if code is being debugged etc..

TTN Integration uplink message processor configuration

The deployed solution application consists of Azure IoTHub and DPS instances. There are two Azure functions, one for putting the messages from the TTN into a queue the other is for processing them. The Azure Functions are hosted in an Azure AppService plan.

Azure solution deployment

An Azure Storage account is used for the queue and Azure Function synchronisation information and Azure Application Insights is used to monitor the solution.

Azure Function Log4Net configuration Revisted

In a previous post I showed how I configured Apache Log4Net and Azure Application Insights to work with an Azure Function, this is the code updated to .Net Core V3.1.

With the different versions of the libraries involved (Early April 2020) this was what I found worked for me so YMMV.

Initially the logging to Application Insights wasn’t working even though it was configured in the ApplicationIngisghts.config file. After some experimentation I found setting the APPINSIGHTS_INSTRUMENTATIONKEY environment variable was the only way I could get it to work.

namespace ApplicationInsightsAzureFunctionLog4NetClient
{
	using System;
	using System.IO;
	using System.Reflection;
	using log4net;
	using log4net.Config;
	using Microsoft.ApplicationInsights;
	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);

         using (TelemetryConfiguration telemetryConfiguration = TelemetryConfiguration.CreateDefault())
         {
            TelemetryClient telemetryClient = new TelemetryClient(telemetryConfiguration);
 
            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");

            telemetryClient.Flush();
         }
      }
   }
}

I did notice that there were a number of exceptions which warrant further investigation.

'func.exe' (CoreCLR: clrhost): Loaded 'C:\Users\BrynLewis\source\repos\AzureApplicationInsightsClients\ApplicationInsightsAzureFunctionLog4NetClient\bin\Debug\netcoreapp3.1\bin\log4net.dll'. 
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.dll
'func.exe' (CoreCLR: clrhost): Loaded 'C:\Users\BrynLewis\AppData\Local\AzureFunctionsTools\Releases\2.47.1\cli_x64\System.Xml.XmlDocument.dll'. 
'func.exe' (CoreCLR: clrhost): Loaded 'C:\Users\BrynLewis\source\repos\AzureApplicationInsightsClients\ApplicationInsightsAzureFunctionLog4NetClient\bin\Debug\netcoreapp3.1\bin\Microsoft.ApplicationInsights.Log4NetAppender.dll'. 
'func.exe' (CoreCLR: clrhost): Loaded 'C:\Users\BrynLewis\AppData\Local\AzureFunctionsTools\Releases\2.47.1\cli_x64\System.Reflection.TypeExtensions.dll'. 
Application Insights Telemetry: {"name":"Microsoft.ApplicationInsights.64b1950b90bb46aaa36c26f5dce0cad3.Message","time":"2020-04-09T09:22:33.2274370Z","iKey":"1234567890123-1234-12345-123456789012","tags":{"ai.cloud.roleInstance":"DESKTOP-C9IPNQ1","ai.operation.id":"bc6c4d10cebd954c9d815ad06add2582","ai.operation.parentId":"|bc6c4d10cebd954c9d815ad06add2582.d8fa83b88b175348.","ai.operation.name":"ApplicationInsightsTimerLog4Net","ai.location.ip":"0.0.0.0","ai.internal.sdkVersion":"log4net:2.13.1-12554","ai.internal.nodeName":"DESKTOP-C9IPNQ1"},"data":{"baseType":"MessageData","baseData":{"ver":2,"message":"This is a Log4Net Info message","severityLevel":"Information","properties":{"Domain":"NOT AVAILABLE","InvocationId":"91063ef9-70d0-4318-a1e0-e49ade07c51b","ThreadName":"14","ClassName":"?","LogLevel":"Information","ProcessId":"15824","Category":"Function.ApplicationInsightsTimerLog4Net","MethodName":"?","Identity":"NOT AVAILABLE","FileName":"?","LoggerName":"ApplicationInsightsAzureFunctionLog4NetClient.ApplicationInsightsTimer","LineNumber":"?"}}}}

The latest code for my Azure Function Log4net to Applications Insights sample is available on 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 IOT Hub and Event Grid Part1

I have one an Azure IoT Hub LoRa Telemetry Field Gateway running in my office and I wanted to process the data collected by the sensors around my property without using a Software as a Service(SaaS) Internet of Things (IoT) package.

Rather than lots of screen grabs of my configuration steps I figured people reading this series of posts would be able to figure the details out themselves.

Raspberry PI with M2M LoRa Hat

I created an Azure Resource Group for this project, and created an Azure IoT Hub.

Azure Resource Group with IoT Hub

I then provisioned an Azure IoT Hub device so I could get the connection string for my Windows 10 Azure IoT Hub LoRa Telemetry Field gateway.

LoRa Field Gateway Provisioned in Azure IoT Hub

I downloaded the JSON configuration file template from my Windows 10 device (which is created on first startup after installation) and configured the Azure IoT Hub connection string.

{
   "AzureIoTHubDeviceConnectionString": "HostName=FieldGatewayHub.azure-devices.net;DeviceId=LoRa915MHz;SharedAccessKey=123456789012345678901234567890123456789/arg=",
   "AzureIoTHubTransportType": "amqp",
   "SensorIDIsDeviceIDSensorID": false,
   "Address": "LoRaIoT1",
   "Frequency": 915000000.0,
   "PABoost": true
}

I then uploaded this to my Windows 10 IoT Core device and restarted the Azure IoT Hub Field gateway so it picked up the new settings.

I could then see on the device messages from sensor nodes being unpacked and uploaded to my Azure IoT Hub.

ETW logging on device

In the Azure IoT Hub metrics I graphed the number of devices connected and the number of telemetry messages sent and could see my device connect then start uploading telemetry.

Azure IoT Hub metrics

One of my customers uses Azure Event Grid for application integration and I wanted to explore using it in an IoT solution. The first step was to create an Event Grid Domain.

I then used the Azure IoT Hub Events tab to wire up these events.

  • Microsoft.Devices.DeviceConnected
  • Microsoft.Devices.DeviceDisconnected
  • Microsoft.Devices.DeviceTelemetry
Azure IoT Hub Event Metrics

To confirm my event subscriptions were successful I previously found the “simplest” approach was to use an Azure storage queue endpoint. I had to create an Azure Storage Account with two Azure Storage Queues one for device connectivity (.DeviceConnected & .DeviceDisconnected) events and the other for device telemetry (.DeviceTelemetry) events.

I created a couple of other subscriptions so I could compare the different Event schemas (Event Grid Schema & Cloud Event Schema v1.0). At this stage I didn’t configure any Filters or Additional Features.

Azure IoT Hub Telemetry Event Metrics

I use Cerebrate Cerculean for monitoring and managing a couple of other customer projects so I used it to inspect the messages in the storage queues.

Cerebrate Ceculean Storage queue Inspector

The message are quite verbose

{
"id":"b48b6376-b7f4-ee7d-82d9-12345678901a",
"source":"/SUBSCRIPTIONS/12345678-901234789-0123-456789012345/RESOURCEGROUPS/AZUREIOTHUBEVENTGRIDAZUREFUNCTION/PROVIDERS/MICROSOFT.DEVICES/IOTHUBS/FIELDGATEWAYHUB",
"specversion":"1.0",
"type":"Microsoft.Devices.DeviceTelemetry",
"dataschema":"#",
"subject":"devices/LoRa915MHz",
"time":"2020-01-24T04:27:30.842Z","data":
{"properties":{},
"systemProperties":{"iothub-connection-device-id":"LoRa915MHz",
"iothub-connection-auth-method":"{\"scope\":\"device\",\"type\":\"sas\",\"issuer\":\"iothub\",\"acceptingIpFilterRule\":null}",
"iothub-connection-auth-generation-id":"637149227434620853",
"iothub-enqueuedtime":"2020-01-24T04:27:30.842Z",
"iothub-message-source":"Telemetry"},
"body":"eyJQYWNrZXRTTlIiOiIxMC4wIiwiUGFja2V0UlNTSSI6LTY5LCJSU1NJIjotMTA5LCJEZXZpY2VBZGRyZXNzQkNEIjoiNEQtNjEtNjQtNzUtNjktNkUtNkYtMzIiLCJhdCI6Ijc2LjYiLCJhaCI6IjU4Iiwid3NhIjoiMiIsIndzZyI6IjUiLCJ3ZCI6IjMyMi44OCIsInIiOiIwLjAwIn0="
}
}

The message payload is base64 encoded, so I used an online tool to decode it.

{
 PacketSNR":"10.0",
"PacketRSSI":-69,
"RSSI":-109,
"DeviceAddressBCD":"4D-61-64-75-69-6E-6F-32",
"at":"76.6",
"ah":"58",
"wsa":"2",
"wsg":"5",
"wd":"322.88",
"r":"0.00"
}

Without writing any code (I will script the configuration) I could upload sensor data to an Azure IoT Hub, subscribe to a selection of events the Azure IoT Hub publishes and then inspect them in an Azure Storage Queue.

I did notice that the .DeviceConnected and .DeviceDisconnected events did take a while to arrive. When I started the field gateway application on the device I would get several DeviceTelemetry events before the DeviceConnected event arrived.

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.