You might remember me writing on how to warm up your App Service instances when moving between slots. The use of the applicationInitialization-element is implemented on nearly every IIS webserver nowadays and works great, until it doesn’t.

I’ve been working on a project which has been designed, as I’d like to call it, a distributed monolith. To give you an oversimplified overview, here’s what we have.

image

First off we have a single page web application which communicates directly to an ASP.NET Web API, which in turn communicates to a backend WCF service, which in turn also communicates with a bunch of other services. You can probably imagine I’m not very happy with this kind of a design, but I can’t do much about it currently.

One of the problems with this design is having cold-starts whenever a service is being deployed.
Since we’re deploying continuously to test & production there are a lot of cold starts. Using the applicationInitialization-element really helped spinning up our App Services, but we were still facing some slowness whenever the WCF service was being deployed to any of our environments. This service is being deployed to an ‘old-fashioned’ Cloud Service so we figured the applicationInitialization-element should just work as it’s still running on IIS.

After having added some logging to our warmup endpoints in the WCF service we quickly discovered these methods were never hit whenever the service was being deployed or swapped. Strange!

I started looking inside the WCF configuration and discovered HTTP GET requests should just work as expected.

<behaviors>
 <serviceBehaviors>
  <behavior name="MyBehavior">
    <serviceMetadata httpsGetEnabled="true" httpGetEnabled="true" />
  </behavior>
 </serviceBehaviors>
</behaviors>

The thing is, we apparently also have some XML transformation going on for all of our cloud environments, so these attributes were set to `false` for both the Test and Production services. This means we can’t do a warmup request via the applicationInitialization-element as it’s doing a normal GET request to the specified endpoints.

Since we still need this WCF service to be hot right after a deployment and swap VIP I had to come up with something else. There are multiple things you can do at this point, like creating a PowerShell script which runs right after a deployment, do a smoke-test in your release pipeline which touches all instances, etc. All of them didn’t feel quite right.

What I came up with is to extend the WebRole.OnStart method! This way I can know for sure that every time the WCF Service starts my code is being executed. Plus, all of the warmup source code is located in the same project as the service implementation which makes it easier to track. In order to do a warmup request you need to do a couple of things. First off, we need to figure out what the local IP-number is of the currently running instance. Once we’ve retrieved this IP-number we can use it to do a HTTP request to our (local) warmup endpoint. As I mentioned earlier, HTTP GET is disabled via our configuration, so we need to use a different method, like POST.

There’s an excellent blog post by Kevin Williamson on how to implement such a feature. In this post he states the following:

If your website takes several minutes to warmup (either standard IIS/ASP.NET warmup of precompilation and module loading, or warming up a cache or other app specific tasks) then your clients may experience an outage or random timeouts.  After a role instance restarts and your OnStart code completes then your role instance will be put back in the load balancer rotation and will begin receiving incoming requests.  If your website is still warming up then all of those incoming requests will queue up and time out.  If you only have 2 instances of your web role then IN_0, which is still warming up, will be taking 100% of the incoming requests while IN_1 is being restarted for the Guest OS update.  This can lead to a complete outage of your service until your website is finished warming up on both instances.  It is recommended to keep your instance in OnStart, which will keep it in the Busy state where it won't receive incoming requests from the load balancer, until your warmup is complete.

He also posts a small code snippet which can be used as inspiration for implementation, so I went and used this piece of code.

One of the problems you will face when implementing this, is realizing your IoC-container isn’t spun up yet. This doesn’t has to be a problem per se, but I wanted to add some logging to this code in order to check if everything was working correctly (or not). Well, this isn’t possible!
In order to add some kind of logging, I had to resort to writing entries to the Windows Event Log. This isn’t ideal of course, but it’s the cleanest way I could come up with. By adding entries to the event log you ‘only’ have to enable RDP on your cloud service in order to check what has happened. Needless to say, the RDP settings are reset every time you deploy a new update to the cloud service, so enabling it is quite safe in our scenario.

Adding this logging to my solution really saved the day, because after having added the HTTP request to the OnStart method I still couldn’t see the warmup events being triggered. By checking out the Event Log I quickly discovered this had to do with the installed certificate on the endpoint. The error I was facing told me the following

Could not establish a trust relationship for the SSL/TLS secure channel

This makes sense of course as the certificate is registered on the hostname and we’re now making a request directly to the internal IP-number which obviously is different (service.customer.com !== 12.34.56.78). Removing the certificate check is rather easy, but you should only do this when you’re 100% sure to do a thing like this. If you remove the certificate check on a global scope you’re opening up yourself for a massive amount of problems!

For future reference, here’s a piece of code which resembles what I came up with.

private void Warmup()
{
    string loggingPrefix = $"{nameof(WebRole)} - {nameof(Warmup)} - ";

    using (var eventLog = new EventLog("Application"))
    {
        eventLog.Source = "Application";
        eventLog.WriteEntry($"{loggingPrefix}Starting {nameof(Warmup)}.", EventLogEntryType.Information);

        IPHostEntry ipEntry = Dns.GetHostEntry(Dns.GetHostName());
        string ip = null;
        foreach (IPAddress ipaddress in ipEntry.AddressList)
        {
            if (ipaddress.AddressFamily.ToString() == "InterNetwork")
            {
                ip = ipaddress.ToString();
                eventLog.WriteEntry($"{loggingPrefix}Found IPv4 address is `{ip}`.", EventLogEntryType.Information);
            }
        }
        string urlToPing = $"https://{ip}/V1/MyService.svc/WarmUp";
        HttpWebRequest req = HttpWebRequest.Create(urlToPing) as HttpWebRequest;
        req.Method = "POST";
        req.ContentLength = 0;
        req.ContentType = "application/my-webrole-startup";

        RemoveCertificateValidationToMakeRequestOnInstanceInsteadOfPublicHostname(req);

        try
        {
            eventLog.WriteEntry($"{loggingPrefix}Posting to `{urlToPing}`.", EventLogEntryType.Information);
            var response = req.GetResponse();
        }
        catch (WebException webException)
        {
            // Warmup failed for some reason.
            eventLog.WriteEntry($"{loggingPrefix}Posting to endpoint `{urlToPing}` failed for reason: {webException.Message}.", EventLogEntryType.Error);
        }
        eventLog.WriteEntry($"{loggingPrefix}Finished {nameof(Warmup)}.", EventLogEntryType.Information);
    }
}

private static void RemoveCertificateValidationToMakeRequestOnInstanceInsteadOfPublicHostname(HttpWebRequest req)
{
    req.ServerCertificateValidationCallback = delegate { return true; };
}

This piece of code is based on the sample provided by Kevin Williamson with some Event Log logging added to it, a POST request and removed the certificate check.

Hope it helps you when facing a similar issue!

The last two posts had me writing about how logging can be implemented in your Azure Functions and how you can reuse class libraries using a different logging library, like log4net. You probably already have some logging- and monitoring system in place, but if you’re starting to use Azure Functions (or any other Azure service for that matter), the best tooling to use is Application Insights, in my opinion. You don’t even have to use Azure services in order to use Application Insights. You can also integrate it with any other on-premise server or client application.

For those of you who aren’t yet familiar with Application Insights, you should check it out immediately! It’s an awesome tool in Azure which enables you to view logging, metrics, exceptions, performance and more of your applications. It’s also possible to create enormous dashboards, reports and alerts, so everything you need in order to monitor your applications. A real must-have for a professional devops team.

Integrate with Azure Functions

Integrating your Azure Functions (Function App) with Application Insights is pretty straightforward.
The easiest way is to integrate is by selecting Application Insights when creating a Function App. Just press `On`, the location you want it deployed and proceed with creating the Function App. This will make sure the newly created Application Insights instance will be used by your Function App.

image

If you have neglected to turn this feature on, or have decided you want to use Application Insights after the Function App has been created, no worries you can still turn on this feature. If you need to integrate it manually, you should navigate to the `Application Settings` of your Function App and add a new entry with the key name `APPINSIGHTS_INSTRUMENTATIONKEY` and the value has to be the Instrumentation Key which can be found on the overview page of your Application Insights instance.

Having done so, you will immediately see a new notification popping up on the `Monitor` page of your Azure Function stating you can now check out your monitoring over there!

clip_image001

That’s all you need to do in order to integrate a Function App with this awesome monitoring system. Your operationsdevops people will be grateful for adding this to your solution.

Why add it?

‘Easy to add’ isn’t a very compelling reason to add Application Insights to your Function App. But if you take a moment to check out all of the basic features, I think you will see the power of this tool.

All of the metrics!

Just taking a look at the Overview page is fascinating already. Over here you are able to see how many server instances are running at this time, the response times of your functions and how many requests are being handled at a specific timespan.

clip_image001[5]

Clicking on either one of these graphs will show you even more details!

I like the Live Stream option a lot, because it gives me the feeling I’m an uber-cool-operations-guy by showing me a lot of graphs and telemetry data which gives you a good first impression of the status of your application.

clip_image001[7]

I know it can be quite overwhelming at first. Just spend a couple of minutes clicking and investigating all of the options is enough for most developers to understand what’s going on and which information is useful for your job.

One of the other useful pages available is the Performance page, this is especially useful if you’re providing public HTTP triggered endpoints via your Azure Functions.

clip_image001[9]

You can do some filtering, selecting timespans and inspect a lot of other metrics which have to do with performance of your piece of code.

Logging & Exceptions

Even though all of those metrics are useful in a production environment, as a developer I don’t do a lot with all of this information (mostly because I don’t have permission to view this data in Production).

What I do find interesting though is the availability of logging and being able to query through it quite fast. As I already mentioned, all of the Azure Function logging is stored in Application Insights (if configured) and you are able to search through all of this logging in the Search page. This is the main reason why I’ve spent some time in configuring log4net with a special appender in order to see ALL of my logging in Application Insights.

Just head down to the Search page and you’ll see all of the logging which has occurred in a specific interval.

clip_image001[11]

Obviously, you can change these filters and interval if you want to investigate some stuff. Most useful, to me, is the filtering on severity level of my logging messages and of course, being able to track (unhandled) Exceptions which are a special type.

clip_image001[1]

While this search page is great for doing some quick research and investigation, there’s an even more awesome page you can check out to see if there have been any exceptions. At this time, this page is labeled Failures. On this page you are able to see when exceptions have occurred and which type of exceptions have been thrown.

clip_image001[3]

Clicking on a specific exception will provide you with some more details.

clip_image001[5]

Zooming in further on such an exception will provide you with a lot of information of the client, server and even the stacktrace of the exception.

clip_image001[7]

As you probably  know, having a stacktrace is crucial information to do some proper investigation on problems which have occurred in the past. Along with all of the other logging you can store within Application Insights it provides you with all of the tooling and analysis information to do proper monitoring and troubleshooting of your service(s).

One of the other features which I like very much is the ability to set Alerts when something fishy is going on, like an increase of exceptions or Errors/Criticals logged being stored. This way you don’t have to keep track of the dashboards all day, but get notified when there’s something important to look at. I’ve only scratched the surface of Application Insights so far. There are a lot of other things you can check out and configure in order to automate your DevOps workflow as much as possible.

I need more!

Even though I like Application Insights very much, I can image a ‘real’ operations persons will probably find it a bit too ‘light’ as it might not provide all of the information they want to see. Well, no worries! The team has you covered and has added a button labelled Analytics on the overview page.

image

Pressing this button will navigate you to a new environment which is meant for power users of this system. You can do some SQL-like statements over here, create charts, query just about everything and visualize it just the way you want.

image

I’m not very familiar with this piece of tooling (yet), but it sure looks amazing and I know I’ll put some time in this as it appears to be even more powerful and useful compared to the ‘default’ Application Insights. My guess this piece has been built on top of the Kusto platform, which is an great piece of technology I’d like to get my hands on! I’ll be sure to follow up on these pieces of tooling, but for now I’ll leave it to this and hope I’ve triggered you in using Application Insights!

As I mentioned in my earlier post, there are 2 options available to you out of the box for logging. You can either use the `TraceWriter` or the `ILogger`. While this is fine when you are doing some small projects or Functions, it can become a problem if you want your Azure Functions to reuse earlier developed logic or modules used in different projects, a Web API for example.

In these shared class libraries you are probably leveraging the power of a ‘full-blown’ logging library. While it is possible to wire up a secondary logging instance in your Azure Function, it’s better to use something which is already available to you, like the `ILogger` or the `TraceWriter`.

I’m a big fan of the log4net logging library, so this post is about using log4net with Azure Functions. As it goes, you can apply the same principle for any other logging framework just the implementation will be a bit different.

Creating an appender

One way to extend the logging capabilities of log4net is by creating your own logging appender. You are probably already using some default file appender or console appender in your projects. Because there isn’t an out-of-the-box appender for the `ILogger`, yet, you have to create one yourself.

Creating an appender isn’t very hard. Make sure you have log4net added to your project and create a new class which derives from `AppenderSkeleton`. Having done so you are notified the `Append`-method should be implemented, which makes sense. The most basic implementation of an appender which is using the `ILogger` looks pretty much like the following.

internal class FunctionLoggerAppender : AppenderSkeleton
{
    private readonly ILogger logger;

    public FunctionLoggerAppender(ILogger logger)
    {
        this.logger = logger;
    }
    protected override void Append(LoggingEvent loggingEvent)
    {
        switch (loggingEvent.Level.Name)
        {
            case "DEBUG":
                this.logger.LogDebug($"{loggingEvent.LoggerName} - {loggingEvent.RenderedMessage}");
                break;
            case "INFO":
                this.logger.LogInformation($"{loggingEvent.LoggerName} - {loggingEvent.RenderedMessage}");
                break;
            case "WARN":
                this.logger.LogWarning($"{loggingEvent.LoggerName} - {loggingEvent.RenderedMessage}");
                break;
            case "ERROR":
                this.logger.LogError($"{loggingEvent.LoggerName} - {loggingEvent.RenderedMessage}");
                break;
            case "FATAL":
                this.logger.LogCritical($"{loggingEvent.LoggerName} - {loggingEvent.RenderedMessage}");
                break;
            default:
                this.logger.LogTrace($"{loggingEvent.LoggerName} - {loggingEvent.RenderedMessage}");
                break;
        }
    }
}

Easy, right?

You probably notice the injected `ILogger` in the constructor of this appender. That’s actually the ‘hardest’ part of setting up this thing, because it means you can only add this appender in a context where the ILogger has been instantiated!

Using the appender

Not only am I a big fan of log4net, but Autofac is also on my shortlist of favorite libraries.
In order to use Autofac and log4net together you can use the LoggingModule from the Autofac documentation page. I’m using this module all the time in my projects, with some changes if necessary.

Azure Functions doesn’t support the default app.config and web.configfiles, which means you can’t use the default XML configuration block which is used in a ‘normal’ scenario. It is possible to load some configuration file by yourself and providing it to log4net, but there are easier (& cleaner) implementations.

What I’ve done is pass along the Azure Functions `ILogger` to the module I mentioned earlier and configure log4net to use this newly created appender.

public class LoggingModule : Autofac.Module
{
    public LoggingModule(ILogger logger)
    {
        log4net.Config.BasicConfigurator.Configure(new FunctionLoggerAppender(logger));
    }
// All the other (default) LoggingModule stuff
}

// And for setting up the dependency container

internal class Dependency
{
    internal static IContainer Container { get; private set; }
    public static void CreateContainer(ILogger logger)
    {
        if (Container == null)
        {
            var builder = new ContainerBuilder();
            builder.RegisterType<Do>().As<IDo>();
            builder.RegisterModule(new LoggingModule(logger));
            Container = builder.Build();
        }
    }
}

I do find it a bit dirty to pass along the `ILogger` throughout the code. If you want to use this in a production system, please make the appropriate changes to make this a bit more clean.

You probably notice I’m storing the Autofac container in a static variable. This is to make sure the wiring of my dependencies is only done once, per instance of my Azure Function. Azure Functions are reused quite often and it’s a waste of resources to spin up a complete dependency container per invocation (IMO).

Once you’re done setting up your IoC and logging, you can use any piece of code which is using the log4net `ILog` implementations and still see the results in your Azure Functions tooling!

If you are running locally, you might not see anything being logged in your local Azure Functions emulator. This is a known issue of the currentprevious tooling, there is an openclosed issue on GitHub. Install the latest version of the tooling (1.0.12 at this time) and you’ll be able to see your log messages from the class library.

image

Of course, you can also check the logging in the Azure Portal if you want to. There are multiple ways to find the log messages, but the easiest option is probably the Log-window inside your Function.

image


Well, that’s all there is to it!

By using an easy to write appender you can reuse your class libraries between multiple projects and still have all the necessary logging available to you. I know this’ll help me in some of my projects!
If you want to see all of the source code on this demo project, it’s available on my GitHub page: https://github.com/Jandev/log4netfunction

Creating a solution with multiple small services is great of course. It provides you with a lot of flexibility and scalability.

There are however a couple of things you have to think about when designing and developing a solution with multiple services. One of the things you need to figure out is how to implement proper logging. For an actual production system you need to have this in place in order to monitor and debug the overall solution.

We, developers using Azure Functions, are already blessed with some logging mechanisms and tools provided out of the box! The out of the box stuff is pretty basic, but it gets the job done and will make your life much easier when the need arises to analyze a production issue.

Logging in your function

When first creating your Azure Function you will probably see a parameter being passed in your `Run` method called `log`.

public static class Function1
{
    [FunctionName("Function1")]
    public static async Task<HttpResponseMessage> Start(
        [HttpTrigger(AuthorizationLevel.Anonymous, "get", Route = null)]
        HttpRequestMessage req, 
        TraceWriter log)
    {
        log.Info("C# HTTP trigger function processed a request.");

        // Logic
    }
}

This `log`-parameter can be used to do some simple logging inside your Azure Function. When invoking this function you’ll be able to see the specified log entry in your console.

[10-4-2018 19:12:12] Function started (Id=a669fc9a-b15b-44b9-a863-47a303aca6b6)
[10-4-2018 19:12:13] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=a669fc9a-b15b-44b9-a863-47a303aca6b6)
[10-4-2018 19:12:13] C# HTTP trigger function processed a request.

All of the other common logging levels, like `Error`, `Warning` and `Verbose`, are also implemented in the TraceWriter.

After having deployed the Azure Function to Azure you will also be able to see the log messages in the Portal.

2018-04-10T19:30:09.112 [Info] Function started (Id=71cead2b-3f90-4c04-8c82-42f6a885491a)
2018-04-10T19:30:09.127 [Info] C# HTTP trigger function processed a request.
2018-04-10T19:30:09.205 [Info] Function completed (Success, Id=71cead2b-3f90-4c04-8c82-42f6a885491a, Duration=87ms)

Checking out the log messages inside the log monitor is nice and all, but the best thing over here is the (automatic) integration with Application Insights! If you have activated this feature you will be able to see all logs in the Application Insights Search blade.

image

I totally recommend using Application Insights to monitor your application, along with all of the logging, as it’s an awesome piece of technology with endless possibilities for your DevOps teams. I’ll share more of my experience with Application Insights in a later post, because it’s too much to share in a single post.

Using the `TraceWriter` is a nice way to get you started with logging, but it’s probably not something you want to use in an actual application.

Introducing the `ILogger`

A different way to start logging is by using the `ILogger` from the `Microsoft.Extensions.Logging` namespace. You can just replace the earlier mentioned `TraceWriter` with the `ILogger`, change the logging methods and be done with it. The Azure Functions runtime will make sure some concrete implementation is being injected which will act similarly to the `TraceWriter`.
The main benefit will be the improved testability of your Azure Function as this parameter is much easier to mock.

One thing I did notice though is the `ILogger` doesn’t output any logging to the Azure Functions console application when running locally. There appears to be an (now open) issue on GitHub which mentions this bug. But don’t worry, you can see all the expected logging in the available tooling of the Azure Portal.

As mentioned, the `ILogger` is a better solution if you want to use Azure Functions in your actual project, because it offers better testability. However, the functionality is quite limited and you can’t extend much on the `ILogger` at this time. If you already have some kind of logging mechanism or framework elsewhere in your solution your probably don’t want to introduce this new logging implementation. My go-to logging framework is log4net and I'd like to use it for the logging inside my Azure Functions also. In order to do so you need to configure a thing or two when setting up log4net. It isn’t very complicated, but something to keep in mind when setting up the Azure Functions.
I’ll describe the necessary steps in a later post.

For now my main advice is just to use the `ILogger` instead of the `TraceWriter`. Both work very well, but `ILogger` offers some advantages compared to the `TraceWriter`.

So you might remember me posting about using the Let’s Encrypt site extension for Azure App Services, called Azure Let’s Encrypt, created by SJKP.

This has quite well for over a year now and even works for Function Apps.

However, last month I got notified my SSL certificate was expired on one of my sites. Strange, as an automated job should just handle this for me. I thought the job probably didn’t execute because of some glitch in the matrix. Therefore I logged in manually, started the site extension wizard again and was stuck on this screen.

/posts/files/8f2e3008-da76-46b2-b583-065827452f3f.png

The reason I was stuck was because the ClientId and ClientSecret didn’t work anymore. As these settings hadn’t changed since I started using this extension I found it quite strange.

Apparently, the Server Principal, which I had created last year, somehow had changed and I didn’t know how to change it back. Lucky for me, managing the AAD isn’t very hard to do nowadays. With a bit of trial and error I was able to create a new SNP and use these details on the Let’s Encrypt site extension.

Creating a new application in AAD

First thing you need to do is add a new Appliction to your AAD. Be sure to pick the option App registrations over here and press the New application registration.

clip_image001

When creating an application you have to specify a name, I chose `LetsEncrypt` and which type it is. Just choose the `Web app/ API` option over here. The other mandatory field called `Sign-on URL` isn’t used in our scenario so you can use any URL you like.

When your application is created you’ll see be navigated to the overview page of this application. Be sure to copy the Application ID from over here as you need it later on. This value has to be used as the ClientId in the site extension.

image

Next thing we need to do is add a Key to this application. You can add new keys by Settings link and choose the Keys option. This key will be used as the Client Secret. Be sure to copy the value after saving as this is the only time you’ll be able to see it.

image

Also note the Expires option.

The default expiration date is set to 1 year from now. This has led me to believe the ClientSecret of my earlier SNP is probably expired. In hindsight I could probably have updated the value in my old SNP and be done with it.

We now have everything we need from our application, so the next thing is to set up the resource group.

Set up your resource group

We need the newly created application to do stuff inside our resource group. Therefore we need to add some permission to it.

To do so, head down to the resource group which contains your app service(s) and pick the Access control (IAM) option.

clip_image001[5]

From over here you can select your newly created application and grant it the Contributor role.

clip_image001[7]

If everything goes well you’ll see the application is added to the list of contributors of this resource.

image

Running the wizard again

Everything should be set up correctly now so you can head back to the wizard of the site extension. Be sure to fill out the ClientId and ClientSecret with the newly retrieved values from the application.

After doing so and trying to proceed to the next screen I was prompted with the message `The ClientId registered under application settings [guid] does not match the ClientId you entered here [guid]` as you can see in the screenshot below.

image

The first time I ran this wizard (a year ago) it was able to create and update the application settings of the App Service. Apparently this has changed and I had to change the Application Settings by myself in the App Service before I was able to continue in the Let’s Encrypt site extension.

For completeness sake, if you’re running a Function App, you can find the settings under All settings, which will navigate you to the App Service settings.

clip_image001[9]

After you’ve changed these settings you should be able to proceed and continue with requesting your SSL certificates.

That’s all there is to it!

Hope it helps whenever you run into problems if your SNP doesn’t work anymore. As I already mentioned, in hindsight it would probably have been much easier by just updating the Key of my original SNP, which I’ll probably need to do in 2 years from now when this new secret will expire.