Adding Azure App Insights logging to Durable Functions

Adding Azure App Insights logging to Durable Functions

Firstly, when I approached this my question was "what are durable functions"? That question is best answered by beginning with what are Azure Functions. I need to prefix this with I am not someone who is in the know. I am making these notes as I learn things and I am no expert. It is likely this will contain information that is outdated or just plain wrong. Also I don't plan to keep it up-to-date, this is simply a dumping ground for my notes.

Azure functions are a part of Microsoft's solution to the serverless programming paradigm through Functions as a Service (Faas). This is coding for a solution without any concern for infrastructure. You write your code and azure automatically creates a box for it to run in and uses your code to achieve the desired response / action.

Your code can be triggered in a number of ways including a timer event such as running once an hour. It can run if there are messages on a queue waiting to be processed and run for each queued item. It can also run as a result of a http request.

The result of the design of this process is that the function is stateless. No matter what happens the function would always run the same, it never remembers anything between the times that it runs and never gets into a new state where it would run any different from how it would run otherwise.

Also Azure Functions runs on a consumption-based pricing model, which means you are only charged when you're using it. Because there's no infrastructure you do need to pay for it. Until such a time as the function needs to run there's no server required to sit and wait for incoming requests. Then when you receive a request Microsoft ups a container, which is probably based on a VM on one of their machines that you're totally unaware of. The implementation details of the infrastructure is totally handle by Microsoft so you don't experience the server and instead only pay when you need to run briefly on one. An advantage of this is that when you need lots of infrastructure because for example there are loads of messages on the queue right now, the host can up lots of infrastructure and scale to meet your needs without you needing to pay for infrastructure that might not be used again for a while.

Often an Azure functions has a binding which can easily link its output to a SendGrid, CosmosDB / blobstorage which allows for many different outputs.

So that's Azure Functions. But what I might make a function "Durable"? Well is an extension to Azure Functions which results from trying to solve a number of limitations in the serverless paradigm.

When running the Serveless paradigm is limited due to its stateless nature. Durable functions provides a means to handle state. In order for state to be achievable in Azure functions without this extension you would need to rely on some kind of storage like blobs or databases.

Also Azure functions has difficulty handling what's called fan out and fan in workflows where one function can execute many function and then another continues when all those functions have finished. Fan out is a description of the workflow diagram that results.

Also Azure functions have difficulty trying to handle errors when they could occur anywhere in the workflow. Without using this extension for a function to call another function, it would normally rely on message queues or http requests to trigger the additional functions. In order to handle errors a system needs to be written to allow the error to propagate such as passing back the error state to the http caller or processing a poison queue.

With durable function you can write a function, which calls other functions and waits for a response. This is known as an Orchestrator function and it calls "action functions". The Orchestrator can then sleep while waiting for activity functions to complete. Activity functions can receive and return data. The Orchestrator function is only the workflow and does not perform any actions. So Durable functions allows you to write better workflows isolated from other code.

In order to start an Orchestrator Function running you need to write a OrchestrationClient binding which allows you to start a orchestrator running from a normal azure function or get information about an orchestration. So for example imagine you have items on a queue. A normal Azure function is bound to the queue and triggers when each item is on the queue. It then uses the OrchestratorClient binding to call an Orchestrator function which defines a workflow. As it flows through the work flow it triggers a number of action functions. Each time a function is run various App Insights records are made recording success and metrics to enable better diagnosis of issues, analysis of processing needs and costs and better feedback.

Durable functions also allows for waiting for human interaction before continuing.

Under the hood

Durable functions uses Azure Storage to implement its workflows. It will therefore need a connection string to do so. It uses Message Queues to trigger other action functions, storage tables to store the state of current orchestrations and in a format called event sourcing. Event sourcing requires that everything is stored by appending new records rather than overwriting previous records which allows for better diagnosis of issues. When an orchestrator wakes up it can then play through this list to see what parts of the work flow have completed.

Creating a Function App

Luckily Visual Studio, when you enable the workload for azure development in the VS installer, has the boiler plate for a typical function app. A function app is a container for multiple functions. You can easily deploy each function into a separate function app, but sometimes you might benefit from group similar or related functions together. In the case of durable functions where they are involved in the same workload it is likely to become useful, due to the common deployment process.

Included in the boiler plate is a proj file which declare the AzureFunctionsVersion, includes a reference to the Azure Functions SDK. Also included are some settings file such as the host.json which explains which version of Azure functions is used and what logging is done. There is also a properties folder with some server dependencies for deployment and a local version.

The boiler plate includes a sample function according to whatever you requested. So for example a Http Request based function has one of those.

You can add more functions by right clicking on the project, clicking Add and clicking New Azure Function. You will need one for the Orchestrator function.

Before you can add any durable azure function's stuff we will need the Nuget package Microsoft.Azure.WebJobs.Extensions.DurableTask and a using directive

using Microsoft.Azure.WebJobs.Extensions.DurableTask;

Then you just add the IDurableOrchestrationClient interface as a parameter. The SDK should inject the orchestration client you need.

public static class FunctionCallsOrchestration
    {
        [FunctionName("FunctionCallsOrchestration")]
        public static async Task<IActionResult> Run(
            [HttpTrigger(AuthorizationLevel.Function, "get")]
            HttpRequest req,
            [DurableClient] IDurableOrchestrationClient orchClient,
            ILogger log
        )
        {
            throw new NotImplementedException();
        }
    }

First things first you will need to extract from the Http Request whatever data you intend to send to the function. I am not going to explain how to do that because it could be stored in any number of ways and getting data from a http Request is a different issue to working with Azure Functions, but I will include this boiler plate code for anyone that might benefit from it. It gets the string from the Http requests body, assumes that is a json encoded data object and creates the variable data based on it.

string requestBody = await new StreamReader(req.Body).ReadToEndAsync();
            dynamic data = JsonConvert.DeserializeObject(requestBody);

Once you have your data then you can use the Orchestration Client that you injected as parameter to create a new orchestration function. If you remember you will know that this is the function that handles the work flow of your Durable Azure Function. It doesn't do any of the actions itself it just figures out where we are in the process and orchestrates other functions to do the work, known as Action Functions. You need to pick a name which we will use when we are creating the Orchestrator for the name of the Orchestrator here, I have chosen O_RepondToName. As far as I can tell there seems to be a standard of prefixing Orchestrator Functions with "O_" and Action functions with "A_" particularly where coders are likely to have the same or similar names for each.

var orchesrtrationId = await orchClient.StartNewAsync(Orchestrators.RespondToNameConst, Guid.NewGuid().ToString(), name);

Finally it is helpful to respond with the means to get progress on the running of this orchestration. Note this uses the orchestrationId generated when the orchestration function was called and the Http Request message that was received to generate a response.

return orchClient.CreateCheckStatusResponse(req, orchesrtrationId);

Okay so that should compile, but it is not complete. When it attempts to run the function it will not find a function with the name O_RespondToName. So we need to create the Orchestrator function.

You can just create a basic static class to provide this. You can also create a static method to outline the Orchestration. It needs to have the attribute FunctionName with the name of the Orchestration function you chose earlier in this case "O_RespondToName".

using Microsoft.Azure.WebJobs;
using Microsoft.Azure.WebJobs.Extensions.DurableTask;
using Microsoft.Extensions.Logging;
using System;
using System.Threading.Tasks;

namespace FunctionApp1
{
    public static class Orchestrators
    {
        [FunctionName("O_RespondToName")]
        public static async Task<string> RespondToName(
            [OrchestrationTrigger] IDurableOrchestrationContext orchContext,
            ILogger log)
        {

            throw new NotImplementedException();
        }
    }
}

You will notice I included a couple of parameters. The most significant of which is the IDurableOrchestrationContext which we will be using. By prefixing it with the attribute OrchestrationTrigger this informs the compiler that this is an Orchestration function.

Obviously when we received the Http Request we removed a piece of data from it and passed it to the Orchestrator. We can do this with Queues as well. We passed the data to the Orchestrator when we called it so we might want to grab that data back now. We can do that with the GetInput function on the context.

var input = orchContext.GetInput<string>();

This doesn't have to be a string.

Now for my first Activity I have chosen to call a function called "A_GetFullName". Again I'm using the convention of beginning the Action Function names with A_ and prefixing O_ to the beginning of Orchestrator Function names. You will note that I specify the type of data that is returned, in this case a string. And once again we are calling a function that has not yet been created but we will do that next. I like to replace these function names with consts after they're made to help link up the reference for anyone who is reading your code later.

var firstActionOutput = await orchContext.CallActivityAsync<string>("A_GetFullName", input);

Something to be aware of, here is that the await keyword works a little bit differently from how you might expect. In Durable functions this Orchestrator will queue up the Activity function to run using its connection to Azure storage (or in a dev environment azure storage emulator) and then it will record where it got to and stop running the Orchestrator so you're not paying for functions running. The next time it runs the function it will run from the beginning to, but reaching lines like this, it will be able to determine from its records whether that Action Function has completed running and will be able to keep going through until it reaches a point where it has to wait for Action function to complete or it can return data.

Same process for second action...

var secondActionOutput = await orchContext.CallActivityAsync<string>("A_Greet", firstActionOutput);

Finally I am going to return something so I can get the data using the Durable Functions REST API later.

You can return the data you generated or just a string whatever you need.

return new
            {
                a = firstActionOutput,
                b = secondActionOutput
            };
// or
return secondActionOutput;

Now just like we did before we have an Activity or Action Function which is not yet defined and we need to define it. We can do so through the same process we did before however the parameters are slightly different. The OrchestrationTrigger is replaced with the ActivityTrigger which is not an Orchestration context but instead whatever the argument is that we had intended to pass into this function.

Here is a sample. I removed any references to my own servers and api keys replacing with just "google.com/api". You will notice I have deliberately made distinct paths through the function where some do not rely on external servers so I can make sure that the function is working, even if the dependency is not available. This is simply for test purposed when setting up.

using Microsoft.Azure.WebJobs;
using Microsoft.Azure.WebJobs.Extensions.DurableTask;
using Microsoft.Extensions.Logging;
using System.Net.Http;
using System.Threading.Tasks;

namespace FunctionApp1
{
    public static class Activities
    {
        [FunctionName("A_GetFullName")]
        public static async Task<string> GetFullName(
            [ActivityTrigger] string input,
            ILogger logger)
        {
            if (input == "Grey" || input == "Gray")
            {
                return "Graeme Chetcuti";
            }

            if (input == "John" || input == "Jonny")
            {
                return "Agent John Smith";
            }

            if (input == "neo")
            {
                return "Mr Anderson";
            }

            //Won't work don't want to reveal my details
            //Also not example of good code
            var httpClient = new HttpClient();
            var result = await httpClient.GetAsync($"google.com/api/GetfulName?name={input}");
            var data = JsonConvert.DeserializeObject<FullName>(await result.Content.ReadAsStringAsync());
            return data.fullName;
        }

        [FunctionName("A_Greet")]
        public static async Task<string> Greet(
        [ActivityTrigger] string input,
        ILogger logger)
        {
            if (input == "Graeme Chetcuti")
                return "Hello Dolores Day";

            if (input.Contains("Anderson"))
            {
                return "Take the blue pill Neo!";
            }

            if (input.Contains("Agent"))
            {
                return "Goodbye Smith";
            }

            //Won't work. Don't want to reveal any of my details.
            var httpClient = new HttpClient();
            var result = await httpClient.GetAsync($"google.com/api/GetGreeting?name={input}");
            var data = JsonConvert.DeserializeObject<FullName>(await result.Content.ReadAsStringAsync());
            return data.greeting;
        }
    }
}

So that gives us our basic Durable function. Next we need to add application insights loggin.

Adding Distributed Tracing to Durable Azure Functions Logging

Okay so one of the issues with logging these is that, as we said before the function is called a number of times. Each time the Orchestrator function is called it could end up logging a different piece of data in application insights which does not give us any continuity with regards to exceptions and how the function arrived at certain points. By adding the following code to the host.json file the logging becomes correlated with other log messages arising from the running of the same Orchestration.

  "extensions": {
    "durableTask": {
      "tracing": {
        "DistributedTracingProtocol": "W3CTraceContext"
      }
    }
  },
  "logging": {
    "applicationInsights": {
      "httpAutoCollectionOptions": {
        "enableW3CDistributedTracing": true
      } 
    }
  },

When an error occurs, this allows you to see where in the running of Orchestrations it was. This is often called distributed tracing.

Check Status Object

When we originally wrote the return statement of the function we returned a Check Status Object which does more than just check status.

When this function is called is immediately starts the Orchestration Function and returns a few URI. These include a URI for checking the status and ultimately getting the data that has resulted from the completed running of the function. Another which is for adding more information for example when a user has responded to question and the last one is to terminate a long running orchestration which is no longer needed.

All you need to do is create an object which is ready to receive this response and then use the URIs when required.

Code

I have included my code on git hub.

https://github.com/gchetcuti/experimenting-with-azure-functions