aws / aws-lambda-dotnet

Libraries, samples and tools to help .NET Core developers develop AWS Lambda functions.
Apache License 2.0
1.57k stars 479 forks source link

Constructor of LambdaEntryPoint throws exception: Error unmarshalling response back from AWS #253

Closed mabead closed 6 years ago

mabead commented 6 years ago

We are hosting a .net core 2.0 REST API inside of a lambda as shown here. We were 5 developpers using the final application and at some point the lambda started failing. I tried to use the "Test" button of the API Gateway inside of the AWS Console and I saw the following error:

Request: /health
Status: 502
Latency: 300 ms
Response Body
{
  "message": "Internal server error"
}
Response Headers
{}
Logs
Execution log for request test-request
Wed Mar 28 18:43:15 UTC 2018 : Starting execution for request: test-invoke-request
Wed Mar 28 18:43:15 UTC 2018 : HTTP Method: GET, Resource Path: /health
Wed Mar 28 18:43:15 UTC 2018 : Method request path: {proxy=health}
Wed Mar 28 18:43:15 UTC 2018 : Method request query string: {}
Wed Mar 28 18:43:15 UTC 2018 : Method request headers: {}
Wed Mar 28 18:43:15 UTC 2018 : Method request body before transformations: 
Wed Mar 28 18:43:15 UTC 2018 : Endpoint request URI: https://lambda.us-east-1.amazonaws.com/2015-03-31/functions/arn:aws:lambda:us-east-1:714500182046:function:downloadbin_aspnet_api/invocations
Wed Mar 28 18:43:15 UTC 2018 : Endpoint request headers: {x-amzn-lambda-integration-tag=test-request, 
...
Wed Mar 28 18:43:15 UTC 2018 : Received response. Integration latency: 281 ms
Wed Mar 28 18:43:15 UTC 2018 : Endpoint response body before transformations: {
  "errorType": "LambdaException",
  "errorMessage": "An exception was thrown when the constructor for type 'LANDR.DownloadBin.LambdaEntryPoint' was invoked. Check inner exception for more details.",
  "cause":   {
    "errorType": "TargetInvocationException",
    "errorMessage": "Exception has been thrown by the target of an invocation.",
    "stackTrace": [
      "at System.RuntimeTypeHandle.CreateInstance(RuntimeType type, Boolean publicOnly, Boolean& canBeCached, RuntimeMethodHandleInternal& ctor)",
      "at System.RuntimeType.CreateInstanceSlow(Boolean publicOnly, Boolean skipCheckThis, Boolean fillCache, StackCrawlMark& stackMark)",
      "at System.Activator.CreateInstance(Type type, Boolean nonPublic)",
      "at System.Activator.CreateInstance(Type type)"
    ],
    "cause":     {
      "errorType": "AmazonUnmarshallingException",
      "errorMessage": "Error unmarshalling response back from AWS.",
      "stackTrace": [
        "at Amazon.Runtime.Inter [TRUNCATED]
Wed Mar 28 18:43:15 UTC 2018 : Endpoint response headers: {X-Amz-Executed-Version=$LATEST, x-amzn-Remapped-Content-Length=0, Connection=keep-alive, x-amzn-RequestId=e0166ce7-32b7-11e8-a1fe-918d8506d64d, Content-Length=6192, X-Amz-Function-Error=Unhandled, Date=Wed, 28 Mar 2018 18:43:15 GMT, X-Amzn-Trace-Id=root=1-5abbe243-39f30a08051981e45231f2f4;sampled=0, Content-Type=application/json}
Wed Mar 28 18:43:15 UTC 2018 : Execution failed due to configuration error: Malformed Lambda proxy response
Wed Mar 28 18:43:15 UTC 2018 : Method completed with status: 502

Do you have any idea of what this means?

Our lambda is now dead since 30 minutes :(

mabead commented 6 years ago

We redeployed the lambda and the lambda now works correctly.

Is this a know issue?

This API lambda is currently not used by our users but we were planning to turn it on next week. We are a little bit scared of having this problem randomly...

normj commented 6 years ago

Seeing the System.Activator.CreateInstance call in the stack trace seems like some resource added to the ASP.NET Core dependency injection system is failing to be created. If a CreateInstance is being done at the constructor level, meaning the ASP.NET Core initialization phase where it the code in startup.cs is invoked. It is most likely something being added as a singleton.

Is there anymore insight you can give on what is happening in your startup.cs file?

mabead commented 6 years ago

@normj As shown above, the error occurs in the constructor of my LambdaEntryPoint class. This class was generated through the AWS Templates. It looks like this:

    public class LambdaEntryPoint : Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction
    {
        protected override void Init(IWebHostBuilder builder)
        {
            builder
                .ConfigureLogging()
                .ConfigureAppConfiguration()
                .UseStartup<Startup>();
        }
    }

As you can see, I don't have any constructor. So, it is the constructor of the base class (provided by AWS SDK) that throws the exception. The base class constructor is available here. As we can see, it calls the abstract Init function that I override. (side note: calling an abstract method from a constructor is sometimes not safe because the derived class is not constructed yet as explained in multiple places like here and here).

Here are my extension methods called from Init:

        public static IWebHostBuilder ConfigureLogging(this IWebHostBuilder webHostBuilder)
        {
            return webHostBuilder.ConfigureLogging((hostingContext, logging) =>
            {
                logging
                    .ClearProviders()
                    .AddConfiguration(hostingContext.Configuration.GetSection("Logging"))
                    .AddLandrConsoleLoggly<Startup>(hostingContext);                
            });
        }

        public static IWebHostBuilder ConfigureAppConfiguration(this IWebHostBuilder webHostBuilder, string configurationBasePath = null)
        {
            return webHostBuilder.ConfigureAppConfiguration((hostcontext, config) =>
            {
                var env = hostcontext.HostingEnvironment;

                // delete all default configuration providers
                config.Sources.Clear();

                if (configurationBasePath != null)
                {
                    config.SetBasePath(configurationBasePath);
                }

                config.AddAwsParametersStoreWhen(!env.IsSwagger(), env, "global", "ms-downloadbin")
                    .AddLandrJsonFile("appsettings.json", true, true, AppSettingsEnvironmentVariables)
                    .AddLandrJsonFile($"appsettings.{env.EnvironmentName}.json", true, AppSettingsEnvironmentVariables)
                    .AddLandrEnvironmentVariables();
            });
        }

Here, what I see is that we try to connect to the AWS Parameter Store. That's the first suspect so far.

And our Startup:

    public class Startup
    {
        public Startup(
            IConfiguration configuration,
            IHostingEnvironment hosting,
            ILogger<Startup> log)
        {
            Configuration = configuration;
            _hosting = hosting;
        }

        public IConfiguration Configuration { get; }
        private readonly IHostingEnvironment _hosting;

        public void ConfigureServices(IServiceCollection services)
        {
            services.AddCors();

            // Add framework services.
            services.AddMvc()
                .AddJsonOptions(x =>
                {
                    x.SerializerSettings.Converters.Add(new TolerantEnumConverter());
                    x.SerializerSettings.ContractResolver = new CamelCasePropertyNamesContractResolver();
                    x.SerializerSettings.DateTimeZoneHandling = DateTimeZoneHandling.Utc;
                    x.SerializerSettings.TypeNameHandling = TypeNameHandling.None;
                    x.SerializerSettings.NullValueHandling = NullValueHandling.Ignore;
                })
                .AddFluentValidation(x => x.RegisterValidatorsFromAssemblyContaining<Startup>());

            // AWS
            services.AddLandrAWSOptions(Configuration, Configuration.GetValue<string>("AWS:Default:Region"));
            services.AddAWSService<IAmazonDynamoDB>();
            services.AddAWSService<IAmazonLambda>();
            services.AddAWSService<IAmazonS3>();
            services.AddSingleton<IDynamoDBContext>(x => new DynamoDBContext(x.GetService<IAmazonDynamoDB>()));

            var jwtConfiguration = Configuration.GetSection("JWT").GetOrNew<JwtConfiguration>();
            services.AddSingleton(jwtConfiguration);

            services.AddAuthentication(JwtBearerDefaults.AuthenticationScheme)
                .AddLandrJwtAuthentication(jwtConfiguration);

            services.AddSingleton(new APIKeysConfiguration(Configuration.GetValue<string>("APIKeys")));
            services.AddLandrSwaggerGen("Landr DownloadBin", "v1");
            services.AddSingleton(Configuration.GetSection("JobsRepositoryConfiguration").Get<JobsRepositoryConfiguration>());
            services.AddSingleton(Configuration.GetSection("JobLauncher").Get<JobLauncherConfiguration>());
            services.AddSingleton(Configuration.GetSection("ZipPreparationWorker").Get<ZipPreparationWorkerConfiguration>());

            services.AddScoped<IJobsRepository, JobsRepository>();            
            services.AddScoped<IDownloadJobPreparationWorker, DownloadJobPreparationWorker>();
            if (IsRunningInsideOfLambda())
            {
                services.AddScoped<IDownloadJobPreparationLauncher, LambdaDownloadJobPreparationLauncher>();
            }
            else
            {
                services.AddScoped<IDownloadJobPreparationLauncher, InProcessDownloadJobPreparationLauncher>();                
            }
        }

        private static bool IsRunningInsideOfLambda()
        {
            return !string.IsNullOrEmpty(Environment.GetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME"));
        }

        public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
        {
            app.UseMiddleware<CorrelationIdMiddleware>();
            app.UseMiddleware<RequestLoggingMiddleware>();

            app.UseCors(builder => builder
                        .WithWebAppOrigins(_hosting)
                        .AllowAnyHeader()
                        .AllowAnyMethod());

            if (env.IsLandrPublicEnvironment())
            {
                app.UseExceptionHandler("/Home/Error");
            }
            else
            {
                app.UseDeveloperExceptionPage();
                app.UseBrowserLink();
            }

            app.UsePathBase("/downloadbin");
            app.UseStaticFiles();

            app.UseAuthentication();
            app.UseMvc(routes =>
            {
                routes.MapRoute(
                "default",
                "{controller=Home}/{action=Index}/{id?}");
            });

            app.UseLandrSwagger("Landr DownloadBin", "v1", "downloadbin");
        }
    }

Here, I don't see anything that calls synchronously an AWS service. So I don't see what could cause a Error unmarshalling response back from AWS.

Note that since yesterday, I have enabled logging of API Gateway in CloudWatch. So if it fails again, we should have a log that is not truncated as it was truncated in the "Test" window of the AWS Console ;)

raban33 commented 6 years ago

@mabead,this might be the case attributed to cold starts. We have seen these happening on Apigateway /lambda's written in node.js. Every 9th or 10th call use to fail. What I couod read is when too many calls are fired at APIgateway, to handle the load AWS may spin newer instances of lambda which can take upto 20+seconds and a timeout could send back internal server(502 translated by Apigateway). I'd defer to @normj to comment on this

mabead commented 6 years ago

The error never came back. I will close the issue. If it ever comes back, I will reopen the issue.