Azure-functions-host: Application settings occasionally not accessible

[thusnjak]

Hello,

every once in a while we are experiencing a problem getting the application settings. Everything runs nice, but sometimes returned value is null.

First we tried getting the value using the configuration manager:

string apiKey = System.Configuration.ConfigurationManager.AppSettings["AzureSearchServiceApiKey"];

then we thought configuration manager might be the problem and changed to cloud configuration manager:

string apiKey = CloudConfigurationManager.GetSetting("AzureSearchServiceApiKey");

and still experiencing the same issue.

For example today from midnight till 9 AM value was returned successfully 46 times and 4 times null was returned.

Our problem seems similar to https://github.com/Azure/azure-webjobs-sdk-script/issues/1481 but npiasecki fixed it by fixing the memory leak. I don't think we have a memory leak, but who knows :)

Any idea how to fix or investigate this issue would be appreciated.

Thanks.

Tin

P.S. if anyone wants to take a look function app is the one with statisticprocess in name on the same account with sa-v4-reference and last errors occurred (UTC):
June 5th 22:03:59.322
June 6th 00:33:46.085
June 6th 05:47:23.887
June 6th 05:47:24.157

[npiasecki]

Hi @thusnjak

It turns out it wasn't the memory leak, but I forgot to reopen the issue. I noticed the same thing with AppSettings in Azure Functions, all I could figure out is that the host starts running your function before the configuration wizardry gets merged somehow, or runs your function after the environment has been torn down. I worked around it by using environment variables instead.

I ended up using a helper class I wrote to work around the issue. Basically I look in AppSettings, and if it's not there I try the environment variable instead. The environment variable always seems to be there.

public static class FunctionConfiguration
{
    public static string GetAppSetting(string name)
    {
        if (string.IsNullOrWhiteSpace(name))
        {
            throw new ArgumentException($"The parameter '{nameof(name)}' cannot be null or blank.");
        }

        var value = ConfigurationManager.AppSettings[name];

        if (string.IsNullOrWhiteSpace(value))
        {
            value = Environment.GetEnvironmentVariable($"APPSETTING_{name}");
        }

        return value;
    }
}

[brettsam]

@thusnjak / @npiasecki -- do these happen to be HttpTriggers that are hitting these issues?

[thusnjak]

@brettsam in our case it is queue triggered function.

[npiasecki]

@brettsam In my case, it was a timer triggered function.

[npiasecki]

I first noticed it on a timer triggered function that ran once per minute. I would hit it a few times per day.

[brettsam]

@thusnjak / @npiasecki -- Can either of you share the app names and timeframes where you saw this? I'd like to look through our backend logs and see if I can see any oddities. You can share your app names either directly or indirectly.

[thusnjak]

@brettsam please check p.s. In my first post

[brettsam]

Whoops -- missed that :-) Thanks!

[brettsam]

@thusnjak -- that helped. I think it's pointing me towards the underlying issue. I see the site was restarting just before your errors. I believe there may be a race somewhere during shutdown. I'm trying to set up a repro now, but haven't been able to catch it yet.

@npiasecki -- if you're able to share your site/times, that'd help me confirm what's happening.

[npiasecki]

@brettsam Unfortunately I had to move the function app to a different subscription had problems with that, so I had to blow it away and recreate it, by then I had instituted my workaround. I do realize now that it was indeed a queue triggered function as in @thusnjak 's case and not a timer triggered one, I remembered it wrong.

I did notice it seemed more frequent when I was doing deployments with WAWSDeploy, but I would still get an occasional one off. Based on my logging at the time, it seemed as if the function was running as the environment was not ready or was disappearing -- DNS resolution errors, missing configuration, etc.

In my case, I had a timer trigger function running once per minute that checked for tasks to run and posted them into a queue; then a queue triggered function would execute the tasks in parallel. If you set up a queue triggered function to read an expected value from app settings, and set a timer trigger to queue up maybe 50 units of work in that queue each minute, and then did a deploy or two, I'd be you'd be able to recreate it pretty easily.

[brettsam]

Thanks @npiasecki. I've set this up just like you suggested and I'll see if I get any hits. What kinds of files were you deploying? Just updates to .csx files? Or were you using precompiled functions? Trying to make sure I can replicate as closely as possible...

[npiasecki]

They were precompiled functions. Each invocation of the queue trigger could take anywhere from 5 seconds to a few minutes to complete (under App Service to avoid 5 minute timeout), but the call to AppSettings was one of the first things it did, and it'd be null there, right at the start of execution.

[brettsam]

Okay I've got something set up that roughly replicates this. I've been pushing updates via WAWSDeploy, making sure it restarts, etc, but still haven't caught the error. I'll let it run for a while and occasionally push a change up.

Is there anything else that you remember about your functions? Were they async or sync, for example?

[thusnjak]

In our case function is quite simple - it just invokes one method and both function and the invoked method are just plain static void methods.
Well, the invoked method invokes some other methods, creates some tasks etc. The problem with getting the application settings is somewhere very deep in code so it is very hard for me to tell everything what happens in between. My best guess is that there is "something" async "somewhere" on the way.

I can tell for sure that @npiasecki 's fix does work and after implementing that we have no more errors reading app settings. If it helps I can remove the fix and let the errors occur for a few days and log the error on App Insights.

If there is anything else I can do to help please let me know.

[npiasecki]

Mine was async, but nothing async would have happened before the call to ConfigurationManager.

[npiasecki]

I had replaced most of my code to fallback to the environment variable and the issue does not occur there. I did have a recently ported system where I missed replacing a call to ConfigurationManager.AppSettings, and this issue happened. The app is fn-sv-labels-prod in East US and it occurred at 2:44:47 p.m. Eastern on 11/5 if it helps you investigate. It is a TimerTrigger than runs once a minute. It's definitely not frequent, but the function was invoked and the AppSettings simply weren't there.

[oshevnin]

Hi @brettsam
it seems like we've faced a quite similar issue with one of our deployments. I doubt it will be easy to reproduce it (we've faced it for the first time), but at least can provide additional function details/times:
issue happened at: 11/27/2017 4:15:36 PM
invocationId: 7affd57e-a39b-4548-b4f8-d55a373f0de0
region: North Europe

as a part of the problem we have AI integration turned on and the function invocation wasn't logged there at all. Table storage logs is the only place where we were able to find the details.

Let me know if you need more details

[amit-kumar2]

I was facing a similar problem for days when some of the function executions were running into Null environment variable values.
The issue in the end turned out to be with the Slots deployment for those functions.
Function Slots were Started/Running as well but they did not have all the appsettings values configured/deployed.
Whenever the message was picked and processed by the Functions Slots instead of the main function deployment, then I would get Null reference error. This was obviously because the Slots deployment was missing some app settings.
When I stopped the Slots then everything started to work reliably.
Leaving this finding here in case someone runs into this error while using Slots.

[pragnagopa]

We have another CRI. Here is the Scenario (from the logs)
Function had service bus trigger and when under load i.e multiple executions with in a short span of time
sometimes, reading AppSettings returns null.

Moving it to triaged as we have multiple customer reports. We need to spend sometime to create a repro.

[davidebbo]

This could be related to how the 'envsettings' logic is applied during specialization. @suwatch or @mathewc do you know how that works, and whether there could be a race condition that could cause it not to be applied, or to be applied too late?

[paulbatum]

Yes I think David is correct. The work to fix is tracked here:
https://github.com/Azure/azure-functions-host/issues/2867

We can leave this issue open until its confirmed that the bug no longer repro's once the above issue is fixed.

[AlbertoDePena]

Do you guys have any suggestion on how to fix this while we wait for fix? I am having this issue with time trigger as well as queue trigger. I can get app settings using
Environment.GetEnvironmentVariable(sprintf "APPSETTING_%s" name) and Environment.GetEnvironmentVariable(sprintf "%s" name) but only in fsx file not precompiled functions. Hard coding values is not an option since we have multiple environments that we deploy to.

[brettsam]

@AlbertoDePena -- we believe that this has been fixed, but maybe something is missing. Can you give us some more details? Like:

• Does this happen consistently?
• How are you trying to access the environment variables?
• What version of functions are you using?
• Are you running in the Consumption plan?

[ghost]

Working with this Azure Functions example to add SQL Server functionality to a function:
https://docs.microsoft.com/en-us/azure/azure-functions/functions-scenario-database-table-cleanup

"sqldb_connection" is in my local.settings.json however, the value is not being found by a call to
System.Environment.GetEnvironmentVariable("sqldb_connection");
in my HttpTrigger Function.

[paaland]

Still get this from time to time. System.Configuration.ConfigurationManager.AppSettings["NameOfEnvironmentVariable"] returns null on some function runs that fails. Suspect it's some race condition that sometimes happens when Azure needs to restart the host for what ever reason. Can run for weeks without issue.

.Net 4 c# function running host 1.x
ServiceBus Topic Subscription trigger
Running in consumption plan
"Run" method is async, settings as static vars

public class MyFunc1
{
        private static string MySetting = ConfigurationManager.AppSettings["MySetting"];

        [FunctionName("MyFunc1")]
        public static async Task Run(
            [ServiceBusTrigger("TopicName", "SubscriptionName", Connection = "ServiceBus")]
            BrokeredMessage brokeredMessage,
            ExecutionContext executionContext,
            TraceWriter traceLog)
        {
             if (string.IsNullOrEmpty(MySetting)) {
                throw new Exception("Running without configuration");
             }
        }
}

[paulbatum]

@paaland We fixed a bug here a while ago. Sounds like maybe there is still another bug that we haven't found yet. In order to be able to investigate you would need to include the details that are in our issue template (region, app name, timestamp, etc).

You might want to consider switching to using the Environment Variable API as far as I know, nobody has had this issue when reading appsettings as environment variables.

[paaland]

We use ConfigurationManager.AppSettings since they work both with file (running locally) and with environment variables when running in Azure (we don't deploy the file).

[paulbatum]

@paaland The same should be true of the environment variable API.

[rehtori]

I have been experiencing this same problem as described here in this ongoing issue. I have created couple functions to test this. And as a result I think my functions are not able to access the application setting values when the consumption tier function auto scales horizontally to multiple instances.

My test:

Function A adds wanted amount of queue items to queue:test.

• Queue item contain id to be used in next function.

Function B triggers from queue:test.

• Function fetches data from external sources and parses them and then saves those to Azure SQL.

Now when Func:A adds a 1000 ids to queue, and the Func:B starts to process those, the auto scaling starts to add instances up to 20. This is all fine and makes the process fast, but the errors starts to show up when some of the instances are not able to access the values of the application settings (ie. process.env.URL_TO_EXTERNAL_SERVICE). I have also debugged this by logging the process.env keys count and that has been always correct, so only the values are occasionally not accessable.

And after the auto scale happens, some of the reqular http request are giving the error too. I think its because some of the request goes to the bad instances that does not have the application settings values.

[jansenbe]

I also see this in the emulator...random calls to CloudConfigurationManager.GetSetting return null. Running version 3.2.3 from Microsoft.WindowsAzure.ConfigurationManager

[jansenbe]

Seems to mainly happen if I have VS run 2 start to projects that require the emulator at the same time, starting them one by one does work better