search

Azure / azure-functions-host

The host/runtime that powers Azure Functions
https://functions.azure.com
MIT License
1.93k stars 441 forks source link

Throws exception on cold start #7470

Open vinaydate opened 3 years ago

vinaydate commented 3 years ago

Investigative information

Repro steps

  1. When we restart function app from azure portal console, it works
  2. But after some time, when we invoke the function by sending an http request to messages endpoint, it fails with an exception

Expected behavior

It should execute the function after cold start, as it does when restarted from portal console

Actual behavior

Generally it fails with exception on cold start

Known workarounds

NA

Related information

The exception thrown indicates that this is a DI issue. So providing my startup code and the exception

Source ```csharp public class Startup : FunctionsStartup { public override void Configure(IFunctionsHostBuilder builder) { builder.Services.AddBotRuntime(builder.GetContext().Configuration); builder.Services .AddSingleton((s) => new ShowTypingMiddleware(delay: 500)); var memoryStorage = new MemoryStorage(); var inspectionState = new InspectionState(memoryStorage); var userState = new UserState(memoryStorage); var conversationState = new ConversationState(memoryStorage); builder.Services .AddSingleton((s) => new InspectionMiddleware(inspectionState, userState, conversationState)); } public override void ConfigureAppConfiguration(IFunctionsConfigurationBuilder configurationBuilder) { FunctionsHostBuilderContext context = configurationBuilder.GetContext(); string applicationRoot = context.ApplicationRootPath; string environmentName = context.EnvironmentName; string settingsDirectory = "settings"; configurationBuilder.ConfigurationBuilder.AddBotRuntimeConfiguration( applicationRoot, settingsDirectory, environmentName); } } ``` The exception thrown is: ``` 2021-06-17T10:56:29.944 [Error] Executed 'messages' (Failed, Id=dcaee1ff-d8c1-43e8-af85-fba28541c495, Duration=2ms)System.NullReferenceException : Object reference not set to an instance of an object.at System.Linq.Expressions.Interpreter.CastInstruction.CastInstructionT`1.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.Interpreter.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.LightLambda.Run(Object[] arguments)at Thunk(Func`2 ,IResolverContext )at DryIoc.Factory.<>c__DisplayClass26_0.b__2() at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6605at DryIoc.Scope.TryGetOrAdd(ImMap`1 items,Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7849at DryIoc.Scope.GetOrAdd(Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7834at DryIoc.Factory.ApplyReuse(Expression serviceExpr,Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6604at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6564at DryIoc.WrappersSupport.GetArrayExpression(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 2903at DryIoc.ExpressionFactory.CreateExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7699at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6554at DryIoc.ReflectionFactory.CreateExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7083at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6554at DryIoc.Factory.GetDelegateOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6634at DryIoc.Container.ResolveAndCacheDefaultFactoryDelegate(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 211at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 196at Microsoft.Azure.WebJobs.Script.WebHost.DependencyInjection.JobHostServiceProvider.GetService(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\JobHostServiceProvider.cs : 99at Microsoft.Azure.WebJobs.Script.WebHost.DependencyInjection.JobHostServiceProvider.GetRequiredService(Type serviceType) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\JobHostServiceProvider.cs : 82at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider,Type serviceType)at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)at Microsoft.Bot.Builder.Dialogs.Adaptive.Runtime.Extensions.ServiceCollectionExtensions.<>c.b__0_0(IServiceProvider sp)at DryIoc.Microsoft.DependencyInjection.DryIocAdapter.<>c__DisplayClass3_0.b__0(IResolverContext r) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\DryIocAdapter.cs : 156at DryIoc.Registrator.<>c__DisplayClass27_0.b__0(IResolverContext r) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 4550at System.Linq.Expressions.Interpreter.FuncCallInstruction`3.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.Interpreter.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.LightLambda.Run(Object[] arguments)at Thunk(Func`2 ,IResolverContext )at DryIoc.Factory.<>c__DisplayClass26_0.b__2() at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6605at DryIoc.Scope.TryGetOrAdd(ImMap`1 items,Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7849at DryIoc.Scope.GetOrAdd(Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7834at DryIoc.Factory.ApplyReuse(Expression serviceExpr,Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6604at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6564at DryIoc.Factory.GetDelegateOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6634at DryIoc.DelegateFactory.GetDelegateOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7740at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType,Object serviceKey,IfUnresolved ifUnresolved,Type requiredServiceType,Request preResolveParent,Object[] args) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 291at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw(Exception source)at System.Linq.Expressions.Interpreter.ExceptionHelpers.UnwrapAndRethrow(TargetInvocationException exception)at System.Linq.Expressions.Interpreter.MethodInfoCallInstruction.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.Interpreter.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.LightLambda.Run(Object[] arguments)at Thunk(Func`2 ,IResolverContext )at DryIoc.Container.ResolveAndCacheDefaultFactoryDelegate(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 225at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 196at Microsoft.Azure.WebJobs.Script.WebHost.DependencyInjection.ScopedServiceProvider.GetService(Type serviceType) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\ScopedServiceProvider.cs : 25at Microsoft.Extensions.DependencyInjection.ActivatorUtilities.GetService(IServiceProvider sp,Type type,Type requiredBy,Boolean isDefaultParameterRequired)at lambda_method(Closure ,IServiceProvider ,Object[] )at Microsoft.Azure.WebJobs.Host.Executors.DefaultJobActivator.CreateInstance[T](IServiceProvider serviceProvider) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\DefaultJobActivator.cs : 42at Microsoft.Azure.WebJobs.Host.Executors.DefaultJobActivator.CreateInstance[T](IFunctionInstanceEx functionInstance) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\DefaultJobActivator.cs : 32at Microsoft.Azure.WebJobs.Host.Executors.ActivatorInstanceFactory`1.<>c__DisplayClass1_1.<.ctor>b__0(IFunctionInstanceEx i) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\ActivatorInstanceFactory.cs : 20at Microsoft.Azure.WebJobs.Host.Executors.ActivatorInstanceFactory`1.Create(IFunctionInstanceEx functionInstance) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\ActivatorInstanceFactory.cs : 26at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker`2.CreateInstance(IFunctionInstanceEx functionInstance) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionInvoker.cs : 44at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ParameterHelper.Initialize() at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs : 759at async Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.TryExecuteAsync(IFunctionInstance functionInstance,CancellationToken cancellationToken) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs : 90 ```
v-anvari commented 3 years ago

Hi @vinaydate , Thank you for reaching out to us, I have checked the backend logs and I can see the exception multiple times during the day. While we investigate the cause, can you tell us if you have a support team analyzing the error as well. As I can see the team from botbuilder-dotnet is looking into this issue. Please confirm if yes.

vinaydate commented 3 years ago

Hi @v-anvari, I don't have any support team,

v-anvari commented 3 years ago

Thank you for the confirmation, we will further investigate the error and update as appropriate

v-anvari commented 3 years ago

Hi @vinaydate , I was trying to reach the App data yesterday and it says the App is disabled or deleted. Can you tell us if you are still seeing the errors. Can you also provide me the repro steps, how did you deploy and what templates have you used. This will help us to reproduce the issue

vinaydate commented 3 years ago

@v-anvari, wonder why you could not get app errors. I checked from my side. The app is running and gives same error trace after cold start.

Repro steps:

  1. Create a bot project (e.g. from core bot template or empty bot template) in bot framework composer (v 2)
  2. Deploy it on azure functions (consumption plan) (v 3)
  3. ping the function on the messages endpoint
  4. default response from bot api will be received
  5. Let the function scale down to 0 instances (wait for say, 20 odd minutes)
  6. ping again the function on the messages endpoint

This results in an exception trace that I have provided earlier

v-anvari commented 3 years ago

Hi @vinaydate ,Thank you for the details, I am able to see the error logs, but I don't see the App deployed. I would try to repro this scenario and update the findings

v-anvari commented 3 years ago

Hi @vinaydate , Can you provide us the stack trace of the exception.

vinaydate commented 3 years ago

@v-anvari

2021-07-27T12:12:50.464 [Error] Executed 'messages' (Failed, Id=e42a0bbf-fcf9-44d4-93f2-71f007436742, Duration=68ms)System.NullReferenceException : Object reference not set to an instance of an object.at System.Linq.Expressions.Interpreter.CastInstruction.CastInstructionT1.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.Interpreter.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.LightLambda.Run(Object[] arguments)at Thunk(Func2 ,IResolverContext )at DryIoc.Factory.<>c__DisplayClass26_0.<ApplyReuse>b__2() at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6605at DryIoc.Scope.TryGetOrAdd(ImMap1 items,Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7849at DryIoc.Scope.GetOrAdd(Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7834at DryIoc.Factory.ApplyReuse(Expression serviceExpr,Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6604at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6564at DryIoc.WrappersSupport.GetArrayExpression(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 2903at DryIoc.ExpressionFactory.CreateExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7699at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6554at DryIoc.ReflectionFactory.CreateExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7083at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6554at DryIoc.Factory.GetDelegateOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6634at DryIoc.Container.ResolveAndCacheDefaultFactoryDelegate(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 211at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 196at Microsoft.Azure.WebJobs.Script.WebHost.DependencyInjection.JobHostServiceProvider.GetService(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\JobHostServiceProvider.cs : 99at Microsoft.Azure.WebJobs.Script.WebHost.DependencyInjection.JobHostServiceProvider.GetRequiredService(Type serviceType) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\JobHostServiceProvider.cs : 82at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider,Type serviceType)at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)at Microsoft.Bot.Builder.Dialogs.Adaptive.Runtime.Extensions.ServiceCollectionExtensions.<>c.b0_0(IServiceProvider sp)at DryIoc.Microsoft.DependencyInjection.DryIocAdapter.<>c__DisplayClass3_0.b0(IResolverContext r) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\DryIocAdapter.cs : 156at DryIoc.Registrator.<>cDisplayClass27_0.b0(IResolverContext r) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 4550at System.Linq.Expressions.Interpreter.FuncCallInstruction3.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.Interpreter.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.LightLambda.Run(Object[] arguments)at Thunk(Func2 ,IResolverContext )at DryIoc.Factory.<>cDisplayClass26_0.b2() at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6605at DryIoc.Scope.TryGetOrAdd(ImMap1 items,Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7849at DryIoc.Scope.GetOrAdd(Int32 id,CreateScopedValue createValue,Int32 disposalOrder) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7834at DryIoc.Factory.ApplyReuse(Expression serviceExpr,Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6604at DryIoc.Factory.GetExpressionOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6564at DryIoc.Factory.GetDelegateOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 6634at DryIoc.DelegateFactory.GetDelegateOrDefault(Request request) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 7740at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType,Object serviceKey,IfUnresolved ifUnresolved,Type requiredServiceType,Request preResolveParent,Object[] args) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 291at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw(Exception source)at System.Linq.Expressions.Interpreter.ExceptionHelpers.UnwrapAndRethrow(TargetInvocationException exception)at System.Linq.Expressions.Interpreter.MethodInfoCallInstruction.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.Interpreter.Run(InterpretedFrame frame)at System.Linq.Expressions.Interpreter.LightLambda.Run(Object[] arguments)at Thunk(Func2 ,IResolverContext )at DryIoc.Container.ResolveAndCacheDefaultFactoryDelegate(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 225at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType,IfUnresolved ifUnresolved) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\DryIoc\Container.cs : 196at Microsoft.Azure.WebJobs.Script.WebHost.DependencyInjection.ScopedServiceProvider.GetService(Type serviceType) at D:\a\1\s\src\WebJobs.Script.WebHost\DependencyInjection\ScopedServiceProvider.cs : 25at Microsoft.Extensions.DependencyInjection.ActivatorUtilities.GetService(IServiceProvider sp,Type type,Type requiredBy,Boolean isDefaultParameterRequired)at lambda_method(Closure ,IServiceProvider ,Object[] )at Microsoft.Azure.WebJobs.Host.Executors.DefaultJobActivator.CreateInstance[T](IServiceProvider serviceProvider) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\DefaultJobActivator.cs : 37at Microsoft.Azure.WebJobs.Host.Executors.DefaultJobActivator.CreateInstance[T](IFunctionInstanceEx functionInstance) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\DefaultJobActivator.cs : 32at Microsoft.Azure.WebJobs.Host.Executors.ActivatorInstanceFactory1.<>c__DisplayClass1_1.<.ctor>b__0(IFunctionInstanceEx i) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\ActivatorInstanceFactory.cs : 20at Microsoft.Azure.WebJobs.Host.Executors.ActivatorInstanceFactory1.Create(IFunctionInstanceEx functionInstance) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\ActivatorInstanceFactory.cs : 26at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker2.CreateInstance(IFunctionInstanceEx functionInstance) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionInvoker.cs : 44at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ParameterHelper.Initialize() at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs : 758at async Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.TryExecuteAsync(IFunctionInstance functionInstance,CancellationToken cancellationToken) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs : 90

compulim commented 3 years ago

@v-anvari Please sync up with Monica Rivera internally. There is a good investigation on this thread, https://github.com/microsoft/botbuilder-dotnet/issues/5692.