Aws-lambda-dotnet: AspNetCoreServer and Duplicate Logging

[Artin-ST]

We're currently experiencing an issue with Amazon.Lambda.AspNetCoreServer and Logging.

We're hosting an asp.net core web site in Lambda. The web site works however I'm getting duplicates in the logs in CloudWatch and I haven't been able to figure out the cause.
I've removed all the logging setup identified in Amazon.Lambda.Logging.AspNetCore and the behaviour is exactly the same regardless.
App settings also has no logging configuration.

Here is an example of what I'm seeing in the log:

• 2020-06-20T20:50:56.705-04:00 START RequestId: fdbd1980-8263-4b5f-8bfc-ef8ec43e0085 Version: $LATEST
• 2020-06-20T20:50:56.705-04:00 [40m[32minfo[39m[22m[49m: Microsoft.Hosting.Lifetime[0]
• 2020-06-20T20:50:56.707-04:00 Application started. Press Ctrl+C to shut down.
• 2020-06-20T20:50:56.708-04:00 [Information] Microsoft.Hosting.Lifetime: Application started. Press Ctrl+C to shut down.
• 2020-06-20T20:50:56.708-04:00 [40m[32minfo[39m[22m[49m: Microsoft.Hosting.Lifetime[0]
• 2020-06-20T20:50:56.708-04:00 Hosting environment: Production
• 2020-06-20T20:50:56.708-04:00 [40m[32minfo[39m[22m[49m: Microsoft.Hosting.Lifetime[0]
• 2020-06-20T20:50:56.708-04:00 Content root path: /var/task
• 2020-06-20T20:50:56.708-04:00 [Information] Microsoft.Hosting.Lifetime: Hosting environment: Production
• 2020-06-20T20:50:56.708-04:00 [Information] Microsoft.Hosting.Lifetime: Content root path: /var/task
• 2020-06-20T20:50:56.880-04:00 [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Hosting.Diagnostics[1]
• 2020-06-20T20:50:57.456-04:00 [Information] Project.Classes.GetFileHandler: Started Project.Classes.GetFileHandler
• 2020-06-20T20:50:57.456-04:00 Started Project.Classes.GetFileHandler

Below is a simplified version of my code.

    public class LambdaEntryPoint : Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction
    {
        protected override void Init(IWebHostBuilder builder)
        {
            RegisterResponseContentEncodingForContentType("application/pdf",
                    ResponseContentEncoding.Base64);
            builder
                .UseStartup<Startup>();
        }

        protected override void Init(IHostBuilder builder)
        {
        }
    }

    public class Startup
    {
        public Startup(IConfiguration configuration)
        {
            Configuration = configuration;
        }

        public IConfiguration Configuration { get; }

        public void ConfigureServices(IServiceCollection services)
        {
            IConfigurationSection appSettings = Configuration.GetSection("AppSettings");

            services.Configure<AppSettings>(appSettings);
            services.AddAWSService<IAmazonS3>();
        }

        // This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
        public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
        {
            if (env.IsDevelopment())
            {
                app.UseDeveloperExceptionPage();
            }
            else
            {
                app.UseExceptionHandler("/Error");
                // The default HSTS value is 30 days. You may want to change this for production scenarios, see https://aka.ms/aspnetcore-hsts.
                app.UseHsts();
            }

            app.UseHttpsRedirection();
            app.UseStaticFiles();
            app.UseRouting();

            app.MapWhen(
                context => context.Request.Path.ToString().EndsWith("file.ashx"),
                appBranch => {
                    // ... optionally add more middleware to this branch
                    appBranch.UseGetFileHandler();
                });
        }
    }

    public class GetFileHandler
    {
        public GetFileHandler(RequestDelegate next)
        { }

        public async Task Invoke(HttpContext context, ILogger<GetFileHandler> logger)
        {
            logger.LogInformation("Started " + this.GetType());
        }
    }

Thanks for any help.

Regards
Artin

[Kralizek]

Not sure how applicable it is to your case, but consider that the default HostBuilder adds the ConsoleLogger and Lambda captures stdout and stderr and pushes it to CloudWatch.

[Artin-ST]

That pointed me in the right direction I think, in the Local entry point ConfigureDefault is explicitly called.

   public static IHostBuilder CreateHostBuilder(string[] args) =>
       Host.CreateDefaultBuilder(args)
           .ConfigureWebHostDefaults(webBuilder =>
           {
               webBuilder.UseStartup<Startup>();
           });

However it's not in the LambdaEntryPoint. I didn't think to look in the base classes. In AbstractAspNetCoreFunction the logging is configured in the virtual method CreateWebHostBuilder.

      .ConfigureLogging((hostingContext, logging) =>
      {
          logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));

          if (string.IsNullOrEmpty(Environment.GetEnvironmentVariable("LAMBDA_TASK_ROOT")))
          {
              logging.AddConsole();
              logging.AddDebug();
          }
          else
          {
              logging.AddLambdaLogger(hostingContext.Configuration, "Logging");
          }
      })

My guess is then that the LAMBDA_TASK_ROOT is not set, not sure how I should set it because its a reserved environment variable.

Regards
Artin

[Kralizek]

Is it a custom runtime?

[Artin-ST]

it's the .net core 3.1 runtime.

  AspNetCoreFunction:
    Type: AWS::Serverless::Function
    Properties:
      Handler: Project::Project.LambdaEntryPoint::FunctionHandlerAsync
      Runtime: dotnetcore3.1
      MemorySize: 512
      Timeout: 30
      Policies:
      - AWSLambdaBasicExecutionRole
      - !Ref S3ManagedPolicy
      Events:
        ProxyResource:
          Type: Api
          Properties:
            Path: "/{proxy+}"
            Method: ANY
        RootResource:
          Type: Api
          Properties:
            Path: "/"
            Method: ANY

Regards
Artin

[Artin-ST]

I'm able to confirm that LAMBDA_TASK_ROOT is /var/task

That should eliminate AddConsole() and AddDebug(). I realized because its .net core 3.1 it would not be using CreateWebHostBuilder but CreateHostBuilder instead. However ConfigureWebHostLambdaDefaults in HostBuilderExtensions uses the same logging configuration.

So really not sure how the duplicate logging is occurring.

[Artin-ST]

I've been able to work around the issue by doing the following in the LambdaEntryPoint class:

        protected override void Init(IWebHostBuilder builder)
        {
            RegisterResponseContentEncodingForContentType("application/pdf",
                    ResponseContentEncoding.Base64);
            builder
                .ConfigureLogging((hostingContext, logging) =>
                {
                    logging.ClearProviders();
                    logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));
                    logging.AddLambdaLogger(hostingContext.Configuration, "Logging");
                })
                .UseStartup<Startup>();
        }

Haven't been able to figure out what in the base class would be causing this issue.

[ashishdhingra]

Hi @Artin-ST,

Good morning.

Based on your inputs above, please confirm if the issue is resolved.

Thanks,
Ashish

[Artin-ST]

I resolved it by using the work around I specified. Specifically clearing the providers set by the library and resetting them myself. I don't know if the underlying issue has been resolved.

[ashishdhingra]

Hi @Artin-ST,

Your workaround would still work. I'm sure this is not an underlying issue with the framework, somehow duplicate loggers are configured in the runtime. Please refer ASP.NET Core Logging on how to configure AWS Cloudwatch logging. It specifies to configure logging as below:

```C#
WebHost.CreateDefaultBuilder(args)
.ConfigureLogging(logging =>
{
logging.AddAWSProvider();

        // When you need logging below set the minimum level. Otherwise the logging framework will default to Informational for external providers.
        logging.SetMinimumLevel(LogLevel.Debug);
    })
    .UseStartup<Startup>();

```

Please let me know if this provides guidance for the issue and if this issue could be closed.

Thanks,
Ashish

[github-actions[bot]]

This issue has not recieved a response in 2 weeks. If you want to keep this issue open, please just leave a comment below and auto-close will be canceled.

[sawankumarbundelkhandi]

@ashishdhingra In reference to your above message.
Aren't we not supposed to use Amazon.Lambda.Logging.AspNetCore instead of AWS.Logger.AspNetCore when running on .net core API on Lambda?

ref. https://github.com/aws/aws-logging-dotnet#aws-lambda