Lambda runtime prints repeated messages (and some odd ones) when it can't find the handler for the function or when an exception is thrown in the constructor

[bjorg]

Using dotnetcore3.1 runtime, I get the following log statements from a single Lambda invocation when I create a Lambda function that has a misconfigured Handler property in CloudFormation (meaning, the Handler refers to a class or method that doesn't exist in the assembly).

The biggest problem is that Unable to load type 'LambdaSharp.Core.ProcessLogEventsFunction.Function' from assembly 'ProcessLogEvents'.: LambdaException is logged 3 times (highlighted in yellow). That means, upon querying the logs, it appears this error occurred more often than it actually did.

There are some other error messages being logged that seem to be an implementation issue of the lambda runtime and not useful to the Lambda function developer (highlighted in green).

• 12 May 2020 21:19:02,997 [WARN] (invoke@invoke.c:297 errno: Address family not supported by protocol) run_dotnet(dotnet_path, &args) failed
• Unknown application error occurred

[bjorg]

The same issue appears when an exception is thrown by the Lambda function constructor.

[ckuetbach]

This bug may be related to another issue and a special version of the Amazon.Lambda.AspNetCoreServer -> 5.1.1

The update from 5.0.0 to 5.1.1 triggers this bug within my project. https://github.com/d-velop/dvelop-app-template-cs/tree/bug/5_1_1

It could also be related with https://github.com/aws/aws-lambda-dotnet/issues/659

An exception was thrown when the constructor for type 'Dvelop.Lambda.EntryPoint.LambdaEntryPoint' was invoked. Check inner exception for more details.: LambdaException

   at System.RuntimeTypeHandle.CreateInstance(RuntimeType type, Boolean publicOnly, Boolean wrapExceptions, Boolean& canBeCached, RuntimeMethodHandleInternal& ctor, Boolean& hasNoDefaultCtor)
   at System.RuntimeType.CreateInstanceDefaultCtorSlow(Boolean publicOnly, Boolean wrapExceptions, Boolean fillCache)
   at System.RuntimeType.CreateInstanceDefaultCtor(Boolean publicOnly, Boolean skipCheckThis, Boolean fillCache, Boolean wrapExceptions)
   at System.Activator.CreateInstance(Type type, Boolean nonPublic, Boolean wrapExceptions)
   at System.Activator.CreateInstance(Type type)
Unable to resolve service for type 'Dvelop.Remote.ICustomServiceProviderFactory' while attempting to activate 'Dvelop.Remote.Startup'.: InvalidOperationException
   at Microsoft.Extensions.DependencyInjection.ActivatorUtilities.ConstructorMatcher.CreateInstance(IServiceProvider provider)
   at Microsoft.Extensions.DependencyInjection.ActivatorUtilities.CreateInstance(IServiceProvider provider, Type instanceType, Object[] parameters)
   at Microsoft.AspNetCore.Hosting.GenericWebHostBuilder.UseStartup(Type startupType, HostBuilderContext context, IServiceCollection services)
   at Microsoft.AspNetCore.Hosting.GenericWebHostBuilder.<>c__DisplayClass12_0.<UseStartup>b__0(HostBuilderContext context, IServiceCollection services)
   at Microsoft.Extensions.Hosting.HostBuilder.CreateServiceProvider()
   at Microsoft.Extensions.Hosting.HostBuilder.Build()
   at Amazon.Lambda.AspNetCoreServer.AbstractAspNetCoreFunction`2.Start()
   at Amazon.Lambda.AspNetCoreServer.AbstractAspNetCoreFunction`2..ctor(StartupMode startupMode)
   at Amazon.Lambda.AspNetCoreServer.AbstractAspNetCoreFunction`2..ctor()
   at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction..ctor()
   at Dvelop.Lambda.EntryPoint.LambdaEntryPoint..ctor()

[Meowzz95]

I have this error too when using 5.1.1 but I'm not using Autofac

[bjorg]

I don't see how this is related to #659. The original reported issue is about the code invoking the C# Lambda handler. Apparently, if there is an exception in the function constructor--or finding the constructor in the first place--the runtime emits the error multiple times. I'm going speculate here that the error is emitted as it works its way through the various try-catch layers, but that's a WAG. Regardless, because the error is emitted multiple times, even though it only happened once, doing a search on the log for frequency reports a much higher count than reality.

[mabublue]

The repeated messages are easy to explain: If a Lambda in AWS fails, it will retry twice more for a total of 3 runs, so if the error is caused by an exception that wont be fixed by rerunning the code, then you will see the error three times. You can override this behavior: https://aws.amazon.com/about-aws/whats-new/2019/11/aws-lambda-supports-max-retry-attempts-event-age-asynchronous-invocations/#:~:text=the%20event%20age.-,Maximum%20Retry%20Attempts,with%20fewer%20or%20no%20retries.

[bjorg]

I don't think it's that simple. The error is printed once before START RequestId:, then immediately after, and finally one more time after REPORT RequestId:.

Furthermore, this weird trace only occurs when (a) the function entry point is not found or (b) the exception occurs in the function constructor.

It's possible that it is related, but the fact that all other exceptions don't behave this way seems to indicate something more fundamental in how the runtime cold starts.

[VincentAdvocaat]

Has anyone gotten any update about this? I am also experiencing the same error: 15 Sep 2020 08:23:47,792 [WARN] (invoke@invoke.c:331 errno: Address family not supported by protocol) run_dotnet(dotnet_path, &args) failed

This happens occasionally, most of the times it works, but sometimes this error appears, it seems to be a bit random (as in, the next request which is handled by the lambda works without a problem)

[plittlewood-rpt]

@ckuetbach Have you found any sort of workaround to this problem yet? I've just run into it today. This is my entry point (I've tried using the IHostBuilder override and have the same result:

 protected override void Init(IWebHostBuilder builder)
        {
            var configuration = new ConfigurationBuilder()
                 .AddJsonFile("appsettings.json")
                 .Build();

            builder
                .ConfigureLogging(logging =>
                {
                    logging.ClearProviders();
                    logging.AddConsole();
                    logging.SetMinimumLevel(LogLevel.Trace);
                })
                .UseNLog()
                .AddCustomerConfigurations(configuration)
                .AddServiceConfiguration(configuration, "ServiceName")
                .ConfigureServices(s => s.AddSingleton<IStartupConfigurationService, StartupConfigurationService>())
                .UseStartup<Startup>();
        }

And this results in :

 at System.RuntimeTypeHandle.CreateInstance(RuntimeType type, Boolean publicOnly, Boolean wrapExceptions, Boolean& canBeCached, RuntimeMethodHandleInternal& ctor, Boolean& hasNoDefaultCtor)
   at System.RuntimeType.CreateInstanceDefaultCtorSlow(Boolean publicOnly, Boolean wrapExceptions, Boolean fillCache)
   at System.RuntimeType.CreateInstanceDefaultCtor(Boolean publicOnly, Boolean skipCheckThis, Boolean fillCache, Boolean wrapExceptions)
   at System.Activator.CreateInstance(Type type, Boolean nonPublic, Boolean wrapExceptions)
   at System.Activator.CreateInstance(Type type)
Unable to resolve service for type 'MyProject.Interfaces.IStartupConfigurationService' while attempting to activate 'MyProject.Startup'.: InvalidOperationException

[bjorg]

@plittlewood-rpt There is absolutely nothing you can do for some of these errors. The original issue was due to a misconfigured entry-point where the uploaded code never even got invoked. The same issue is also present when the constructor fails. For the constructor it's actually possible to at least catch the exception (unless it's in a base class from a package), but other than to mark your environment as failed, there isn't much more you can do.

I'm surprised this has not been addressed by AWS yet. It's an obvious defect of the runtime implementation.

[plittlewood-rpt]

Thanks @bjorg that's pretty annoying. I'm in the process of moving .NET Core 2.1 API's running inside docker containers on AWS Fargate over to Lambda and .NET Core 3.1 and this is a big hurdle right now. Going to see if I can remove the DI requirement for the Startup class instead to work around it.

[davidrevoledo]

Any solution yet ? I'm planning to do a downgrade to net 2.1 as there is no way to get this working. it looks like work if I remove dependency injection however it works locally with it.

[pariesz]

I had this issue when the application was erroring but the lambda had ran out of memory so it only logged [WARN] (invoke@invoke.c:331 errno: .... Once I added more memory the exception started logging.

[ckuetbach]

May be I have a solution for the @plittlewood-rpt https://github.com/aws/aws-lambda-dotnet/issues/669#issuecomment-702770874.

A coworker of mine (thanks to @janfoe), found some Issues in my application-template project. He helped me to update all my dependencies and code to get it running.

There are a few chenges at all:

First you'll have to use IHostBuilder instead of IWebHostBuilder: https://github.com/d-velop/dvelop-app-template-cs/commit/2a14dcb0fcd3bf59b9b089caed5dea6fb4744c30#diff-c03197fe954d86482a0698d0e0ff74f9dae5ad6dcd910e630c20ec53006754b0R40

The Startup must not get more parameter than the IConfiguration https://github.com/d-velop/dvelop-app-template-cs/commit/2a14dcb0fcd3bf59b9b089caed5dea6fb4744c30#diff-bcde2d9453c4b3b67ff4d51dc24db72514b326b803009770f2a4eea6f644e505R39

The Configure() must be void https://github.com/d-velop/dvelop-app-template-cs/commit/2a14dcb0fcd3bf59b9b089caed5dea6fb4744c30#diff-bcde2d9453c4b3b67ff4d51dc24db72514b326b803009770f2a4eea6f644e505R112

And you may have to use a ServiceProviderFactory https://github.com/d-velop/dvelop-app-template-cs/commit/2a14dcb0fcd3bf59b9b089caed5dea6fb4744c30#diff-c03197fe954d86482a0698d0e0ff74f9dae5ad6dcd910e630c20ec53006754b0R65

May be this helps. I had straged problems without these changes and

[normj]

@bjorg If a Lambda compute environment fails during initialization the Lambda service retries 2 more times in case the issue was intermittent. This is a done at the Lambda service level same for all runtimes. It is not specific design decision for .NET.

[bjorg]

@normj Thanks for the insight. That's helpful. Hopefully it also makes sense that this behavior makes it difficult to accurately count failures that occur during the constructor phase (e.g. due to throttled API access, such as SSM). Either the log analyzer overcounts those failure messages or needs to be stateful.

Since this will probably never be addressed, it makes sense to close this ticket. It's almost 2 years old.

[github-actions[bot]]

⚠️COMMENT VISIBILITY WARNING⚠️

Comments on closed issues are hard for our team to see. If you need more assistance, please either tag a team member or open a new issue that references this one. If you wish to keep having a conversation with other community members under this issue feel free to do so.