Azure Function, Logging part II

Time to put the logging into action, I am going to use a simple Azure Function (HTTP-trigger) to create the log entries in Application Insight.

Input message

This will be a simple input to the http-triggered function, an invoice containing rows

{
    "invoiceId": 1234,
    "rows": [
        {
            "amount": 1.00,
            "qty": 3,
            "description": "some description"
        },
        {
            "amount": 2.00,
            "qty": 4,
            "description": "some description"
        }
    ]
}

The Azure Function will also validate this message including some query parameters and a header (yes I use a API to trigger the function) This will further demonstrate the logging and how you can use it to your benefit when it comes to reacting quick on incoming queries of what has gone wrong.

 

I have implemented two validators, ValidateQueryParam and ValidateHeaderParam and a schema validator for the above json.
These will help out to produce some nice content in Application Insight.

Let’s look at the validators and what they will output

Here is the result from query parameter and header validators, note the response body and http response code

Lets head in to Application Insight, here we can see that 2 things have happened. func-int001 this is the API log and INT0001 is the az function log.

If we choose failures instead we will find failures raised by the API, this is based on the http response code <> 200
As i mentioned earlier, the importance of the Operation Name. By using a unique identifier here (INTId) we can easily filter out a specific integration using the “Search for filter items” box

Lets focus on the performance, click on samples and sort by date. Note the four examples (2 from function and 2 from api)

lets go with the second entry, POST /maconomy/invoice
The first view will give you slightly more information, we can se the response code – 400 and some events.

Lets dig deeper by pressing by clicking view all
Here we can se how our logging kicks in, from our Beginscope we find prop__INTId and from our logging of inputMessage we can see prop__inputMessage-http.

We all know we received a 400 bad request, this is logged as a warning like this

We also have the schema validation, it will also be shown as a warning
The consumer will get this response

And we will see this, the message will give you simple and readable information to act on.

And finally if all validations are passed (query, header and schema) lets process the content of the body and transform it.
This little snippet will transform and map the JSON to XML

public static Models.ReceivingSystem.Invoice MapToXMLInvoice(this Models.FunctionTrigger.Invoice invoice)
        => new()
        {
            InvoiceId = invoice.InvoiceId,
            Rows = invoice.Rows
                .Select(x => new Models.ReceivingSystem.Row
                {
                    Amount = x.Amount.ToString(),
                    Qty = x.Qty.ToString(),
                    Description = x.Description
                }).ToList()
        };

The consumer will receive a 200 OK

And we can find some more interesting outputs in Application Insight
First of all the total number of rows

Why two log entries?
The second row actually created a custom property and the first only writes an log entry

• The first row is logged using _logger.LogInformation($”Processing {invoice.Rows.Count} invoice rows”);
• The second row is loggen using _logger.LogInformation(“Processing {TotalnumberOfInvoiceRows} invoice rows”, invoice.Rows.Count);

Lets look at the output

Last but not least, Kusto (KQL)
Whats this you might ask? Well now you can put all your custom properties to work by composing your own queries to build BI-reports, alert rules and much more. I mainly use the if for alert rules as a part of the maintenance, making sure the end user/operation gets a signal when something goes wrong.

Why do i use the properties INTId and EntityId? Here is the WHY, this way i do not need to rewrite every Kust query to what ever the developer has chooses to name it for. Set your naming and stick to it!

Summerize

Logging is in a way simple but you have to think things through, find a pattern that suits your need and stick to it. Don’t forget to add informativ logging like the number of rows, it can be used in what we call none-events e.g., create alerts based on rules that aren’t code failures.