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

System.AccesssViolationException encountered in Lambda based AspNetCore Kestrel Hosting #185

Closed ibuchan72390 closed 6 years ago

ibuchan72390 commented 6 years ago

Hi there,

I've been working with a Lambda based AspNetCore Kestrel hosted website for almost a year now. It appears that I've encountered my first memory leak. It took me a few days to realize what was going on. I had figured I was somehow running into a bad .NET Core 1.0 reference because the issue was relatively intermittent and seemed to largely occur when working with an asynchronous context. After drilling through logs for hours on end, I was finally able to notice the following pattern:

REPORT RequestId: 3dc67903-dc6e-11e7-b70b-f31bf853f674  Duration: 202.36 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 94 MB
REPORT RequestId: 3e0186b1-dc6e-11e7-bba9-cbb50eea6ba9  Duration: 5356.47 ms    Billed Duration: 5400 ms Memory Size: 1024 MB   Max Memory Used: 104 MB
REPORT RequestId: 44329b95-dc6e-11e7-90d7-2182089f4926  Duration: 11254.99 ms   Billed Duration: 11300 ms Memory Size: 1024 MB  Max Memory Used: 332 MB
REPORT RequestId: 4d5615ed-dc6e-11e7-9c98-716c7ef1723a  Duration: 394.21 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 333 MB
REPORT RequestId: 52da7074-dc6e-11e7-9119-a5d0b8a8fdb4  Duration: 334.18 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 333 MB
REPORT RequestId: 53364c70-dc6e-11e7-896c-7b016224c80c  Duration: 1023.85 ms    Billed Duration: 1100 ms Memory Size: 1024 MB   Max Memory Used: 347 MB
REPORT RequestId: 571a8ad8-dc6e-11e7-a845-cf16d636b90a  Duration: 317.14 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 348 MB
REPORT RequestId: 5773f563-dc6e-11e7-8dc6-a511bfb15ed3  Duration: 206.93 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 354 MB
REPORT RequestId: 5bb8a443-dc6e-11e7-a659-19b60c381b76  Duration: 304.21 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 361 MB
REPORT RequestId: 5c2ac769-dc6e-11e7-a798-67709e053235  Duration: 246.65 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 364 MB
REPORT RequestId: 6152a9ff-dc6e-11e7-b081-af7f83c5a458  Duration: 248.99 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 370 MB
REPORT RequestId: 63376f28-dc6e-11e7-abff-05587fca15ab  Duration: 353.03 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 382 MB
REPORT RequestId: 66371a86-dc6e-11e7-943d-476fdbc4a89e  Duration: 302.32 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 389 MB
REPORT RequestId: 67bad4cf-dc6e-11e7-98ce-c9bd53b06765  Duration: 280.72 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 398 MB
REPORT RequestId: 6961f4ef-dc6e-11e7-9be0-854d80ba7e47  Duration: 287.53 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 408 MB
REPORT RequestId: 6b865b1c-dc6e-11e7-a7a3-9fe091123029  Duration: 313.54 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 417 MB
REPORT RequestId: 6cf15d65-dc6e-11e7-a30e-f75bdf934684  Duration: 265.60 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 422 MB
REPORT RequestId: 6ede8798-dc6e-11e7-983d-637afb276ab6  Duration: 325.28 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 426 MB
REPORT RequestId: 70c8f1cf-dc6e-11e7-b14e-abacaf2bcd85  Duration: 327.12 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 431 MB
REPORT RequestId: 712bab41-dc6e-11e7-b9bd-a7abf148bb2f  Duration: 142.82 ms Billed Duration: 200 ms Memory Size: 1024 MB    Max Memory Used: 436 MB
REPORT RequestId: 72a7c46d-dc6e-11e7-88c8-03031d971a5e  Duration: 291.63 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 444 MB
REPORT RequestId: 73059b9e-dc6e-11e7-80f0-8fc1070e72d3  Duration: 179.62 ms Billed Duration: 200 ms Memory Size: 1024 MB    Max Memory Used: 449 MB
REPORT RequestId: 781c18e8-dc6e-11e7-b23f-87f00aea05f3  Duration: 280.97 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 457 MB
REPORT RequestId: 79789c37-dc6e-11e7-a931-3939b64a1005  Duration: 277.57 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 485 MB
REPORT RequestId: 7b02223e-dc6e-11e7-8e1a-b763e3a90f96  Duration: 258.71 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 487 MB
REPORT RequestId: 7c4fb0d0-dc6e-11e7-986e-2d7a10d25acb  Duration: 274.12 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 501 MB
REPORT RequestId: 7e197447-dc6e-11e7-b014-d103a19007c1  Duration: 268.75 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 501 MB
REPORT RequestId: 7f4830b6-dc6e-11e7-9286-b53eee0eeb97  Duration: 265.90 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 515 MB
REPORT RequestId: 80640011-dc6e-11e7-a4e9-7f5813bc1d9b  Duration: 249.71 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 526 MB
REPORT RequestId: 827e7c48-dc6e-11e7-9882-553249bb136f  Duration: 280.02 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 535 MB
REPORT RequestId: 834ffd3a-dc6e-11e7-a179-3f8683750833  Duration: 283.13 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 546 MB
REPORT RequestId: 83adfb90-dc6e-11e7-a8b9-41d613e950a4  Duration: 190.46 ms Billed Duration: 200 ms Memory Size: 1024 MB    Max Memory Used: 562 MB
REPORT RequestId: 8469f847-dc6e-11e7-a4aa-b57bba0768d9  Duration: 258.33 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 573 MB
REPORT RequestId: 84b46f28-dc6e-11e7-834b-1b7516fa4c49  Duration: 157.16 ms Billed Duration: 200 ms Memory Size: 1024 MB    Max Memory Used: 577 MB
REPORT RequestId: 8691e148-dc6e-11e7-9e55-5de525454cc7  Duration: 240.47 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 602 MB
REPORT RequestId: 87a06b57-dc6e-11e7-819c-53693dcc9ff9  Duration: 262.19 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 621 MB
REPORT RequestId: 88b6e413-dc6e-11e7-a578-0dbbbe0950ce  Duration: 276.35 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 635 MB
REPORT RequestId: 89b827fa-dc6e-11e7-bb16-69053db8f778  Duration: 259.09 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 700 MB
REPORT RequestId: 8ad1d4f6-dc6e-11e7-8f57-1bf6944b48ee  Duration: 230.31 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 711 MB
REPORT RequestId: 8c3b2906-dc6e-11e7-8a23-73cb8c4a31ae  Duration: 273.98 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 729 MB
REPORT RequestId: 8d89efba-dc6e-11e7-b0af-fd0d10e41231  Duration: 230.58 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 743 MB
REPORT RequestId: 8edfbca7-dc6e-11e7-b8bc-47811c280c05  Duration: 249.17 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 757 MB
REPORT RequestId: 8f538ccd-dc6e-11e7-b026-f39c6b7800ea  Duration: 50.67 ms  Billed Duration: 100 ms Memory Size: 1024 MB    Max Memory Used: 760 MB
REPORT RequestId: 8fd2f5fd-dc6e-11e7-9765-2d56e3bf64ea  Duration: 234.21 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 773 MB
REPORT RequestId: 90370e64-dc6e-11e7-9156-e5870857454b  Duration: 175.30 ms Billed Duration: 200 ms Memory Size: 1024 MB    Max Memory Used: 785 MB
REPORT RequestId: 90f7511c-dc6e-11e7-983d-637afb276ab6  Duration: 261.36 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 841 MB
REPORT RequestId: 914c9d8e-dc6e-11e7-898b-1585b8f8e7d4  Duration: 320.56 ms Billed Duration: 400 ms Memory Size: 1024 MB    Max Memory Used: 889 MB
REPORT RequestId: 921a269d-dc6e-11e7-accb-17367ab2cdd9  Duration: 254.26 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 892 MB
REPORT RequestId: 938d17d0-dc6e-11e7-8436-01961fd413f3  Duration: 275.37 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 897 MB
REPORT RequestId: 9549bbfd-dc6e-11e7-97dc-bf10238f2752  Duration: 246.73 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 900 MB
REPORT RequestId: 968807ad-dc6e-11e7-a9e8-bf97d825ac8c  Duration: 258.74 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 904 MB
REPORT RequestId: 98707793-dc6e-11e7-832e-7703726b047a  Duration: 224.04 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 908 MB
REPORT RequestId: 99aa2fbb-dc6e-11e7-82a7-2f2cc7d38d3b  Duration: 264.40 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 912 MB
REPORT RequestId: 9ad62c85-dc6e-11e7-81b0-456cdc9dc8d7  Duration: 258.75 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 917 MB
REPORT RequestId: 9b27cf02-dc6e-11e7-9694-dffb979f1940  Duration: 846.53 ms Billed Duration: 900 ms Memory Size: 1024 MB    Max Memory Used: 937 MB
REPORT RequestId: 9cf318eb-dc6e-11e7-9580-05514ef1ee68  Duration: 17867.03 ms   Billed Duration: 17900 ms Memory Size: 1024 MB  Max Memory Used: 1024 MB

As you can see from the "Max Memory Used", it's progressively increasing to a breaking point where the Memory Used equals Memory Allocated. At this point, the Lambda crashes, returns a 502 error and restarts the container as if it were brand new. I would normally start drilling through to try and find the memory leak point, but I was slightly concerned by the following post:

https://forums.aws.amazon.com/message.jspa?messageID=587945

According to the post above, there's a point at which the Lambda will stabilize and stop consuming extra memory allocation. I'm about to take advantage of the increased Lambda Memory limit and up my Max Memory Allocation to 3008 MB and see if there is a stabilization point. Is this normal for a Lambda-based Kestrel hosting to be surpassing a 1024 MB limit with a Lambda based Kestrel hosting?

My AspNetCore API is getting somewhat large intensive. It is quite possible that all of this added functionality is truly causing an increase in memory consumption, but this seems very heavily in excess of some of the original memory usages I've seen.

I was experimenting with an in-memory caching mechanism for a short time period about a month ago, so it's possible some remnants of this functionality could be causing the underlying issue as well.

normj commented 6 years ago

I have not heard of others having a memory leak when using the ASP.NET Core bridge for Lambda. I'm happy to investigate if you could provide a small reproducible code example.

ibuchan72390 commented 6 years ago

My project is almost a year along now, so it's kind of hard for me to reproduce anything on a smaller scale by this point. I feel like I'm more in the investigation stage and I'm curious if you've possibly seen any of these ASP.NET Core bridge for Lambda applications surpassing 1024 MB prior to Lambda stabilizing it's memory consumption? I found the previous article interesting in that it mentions some applications may continue to consume memory until they reach a stability point. I will say though, that seems like an excessive stabilization point even for a relatively large API. I'm going to do some testing with a larger memory allocation and attempt to determine if it will level out. If not, I most definitely have a bad caching mechanism implemented somewhere. I had doubts about implementing an in-memory object cache in Lambda, so that may be the source of my issue.

Sorry I can't give more information, I'm still trying to figure out how to properly debug a memory leak in Lambda. Is there any chance AWS will make their Lambda docker containers for each runtime environment public in the future? That way we could mimic a Lambda environment locally using the same container.

ibuchan72390 commented 6 years ago

Now that I've increased the memory capacity to 3008 MB and now, It's failing on a slightly different error once it surpasses about the 1024 MB point. I'd have to image it's got to be a memory leak of some form in my implementation.

I had a deep suspicion that it was possibly my use of the Microsoft.Extensions.Caching.Memory package; however, I've removed that and I still seem to be running into a similar problem. Below are the current logs that I appear to be encountering upon crashing. It almost appears to be failing on a container resolution when it's attempting to activate an instance of a controller. I'll have to re-examine my lifestyles, particularly on my controllers and double-check that everything is properly implementing IDisposable.

Unhandled Exception: System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
at lambda_method(Closure , ServiceProvider )
at Microsoft.Extensions.Internal.ActivatorUtilities.GetService(IServiceProvider sp, Type type, Type requiredBy, Boolean isDefaultParameterRequired)
at lambda_method(Closure , IServiceProvider , Object[] )
at Microsoft.AspNetCore.Mvc.Internal.TypeActivatorCache.CreateInstance[TInstance](IServiceProvider serviceProvider, Type implementationType)
at Microsoft.AspNetCore.Mvc.Controllers.DefaultControllerFactory.CreateController(ControllerContext context)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeAllActionFiltersAsync>d__26.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeAllActionFiltersAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeExceptionFilterAsync>d__25.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeExceptionFilterAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeResourceFilterAsync>d__23.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeResourceFilterAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeResourceFilterAsync>d__23.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeResourceFilterAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeAsync>d__18.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeAsync()
at Microsoft.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware`1.<Invoke>d__18.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware`1.Invoke(HttpContext context)
at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.<Invoke>d__7.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.Invoke(HttpContext context)
at Elmah.Io.AspNetCore.ElmahIoMiddleware.<Invoke>d__6.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Elmah.Io.AspNetCore.ElmahIoMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.<Invoke>d__3.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.Invoke(HttpContext httpContext)
at Microsoft.AspNetCore.Hosting.Internal.HostingApplication.ProcessRequestAsync(Context context)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.<ProcessRequest>d__15.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.ProcessRequest(ILambdaContext lambdaContext, Context context, InvokeFeatures features, Boolean rethrowUnhandledError)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.<FunctionHandlerAsync>d__12.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.FunctionHandlerAsync(APIGatewayProxyRequest request, ILambdaContext lambdaContext)
at lambda_method(Closure , Stream , Stream , ContextInfo )
at AWSLambda.Internal.Bootstrap.UserCodeLoader.Invoke(Stream lambdaData, Stream outStream, ContextInfo contextInfo)
at AWSLambda.Internal.Bootstrap.LambdaBootstrap.Invoke(ContextInfo contextInfo, Stream inputStream, Stream outputStream)
at AWSLambda.Internal.Bootstrap.UnsafeEntry.Invoke(Int64 maxBodySize, Byte* payload, Int64& payloadLength, Byte* requestIdBuffer, Int64 requestIdBufferLength, Byte* functionArn, Int64 functionArnLength, Byte* clientContext, Int64 
ibuchan72390 commented 6 years ago

Upon further investigation, the following link seems to indicate that Lambda supports up to .NET Core 1.0.1 - http://docs.aws.amazon.com/lambda/latest/dg/current-supported-versions.html

Does that mean that Lambda has not been keeping up with the other minor updates that have been released for .NET Core 1.0? As 1.0.2 - 1.0.5 have come out, I have continued to allow my libraries to upgrade within the .NET Core 1.0 Framework as long as they were within the minor releases. If Lambda only officially supports 1.0.1, I'm curious if my use of some other supporting libraries outside of that Framework version are causing some unexpected runtime failures.

If Lambda is explicitly 1.0.1 compatible. That might also explain why there is some hidden depdendency I've been running into that seems to only allow certain libraries to work with System.Security.Cryptography.x509Certificates in 4.1.0 only. Any attempts to upgrade this library outside of the 4.1.0 range seems to cause the following failure for me:

Unable to find an entry point named 'CryptoNative_X509StoreCtxInit2' in DLL 'System.Security.Cryptography.Native'
ibuchan72390 commented 6 years ago

I've dropped everything back into 1.0.1 and I'm still running into the System.AccessViolationException. It feels like a memory leak by the way it gradually builds to an exception and then releases pressure for a while until it reoccurs, but it doesn't seem to be demonstrating a memory-leak exception. I've never had to deal with a System.AccessViolationException and have absolutely no idea where this could feasibly be coming from. It's hard to get any visibility into the memory allocations of AWS Lambda, so I feel at a loss.

I also had a suspicion that it was possibly an issue with container bloat. I've attempted to edit container lifestyles from singleton to scoped and that doesn't seem to have helped. I can specifically identify a single API method that appears to be heavily contributing to the issue. It appears that simply resolving this controller many times in a row will eventually lead to the issue occurring. The memory will start to bloat, but sometimes it appears I've gotten it to level off around 500MB, and it will still end up crashing with a System.AccessViolationException.

When examining my local running instance via the Visual Studio Debugger, I've noticed that the memory in my application is capable of climbing up to about 1.5 GB prior to stabilization around the 600-700 MB point. I feel like I'm running out of options, I'm about to try and see if I can implement XRay to find anything else. Otherwise, I'll have to try to use dotMemory on it to see if I can get any better visibility into memory consumption under the hopes that I can find a source of the issue. If not, the only other option I can think to try is to create a docker container mimicking Lambda as close as I possibly can and try to reproduce the issue.

ibuchan72390 commented 6 years ago

After continuing my work on this troublesome issue, I've been able to identify the exact API Method capable of forcing the System.AccessViolationException. It seems if I use PostMan to repeat on this API Method, I can see the memory build up over time before it culminates in the AccessViolationException. I've been slowly adding more logging in various places to see if I can figure out what's going on; however, it almost seems to fail at the point of controller resolution from IServiceCollection.

Upon adding more logging, I started getting some very strange logs in CloudWatch. It almost appears as if some of these logs are C++ level memory management logs. These are very concerning to me, and I'm hoping they're indicative of my larger memory management issue.

I've never seen logs in CloudWatch predicated with the "\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m" string and I find these to be extremely suspicous.

Beginning ConfigureServices
Completed service collection development
Added HttpContextAccessor
Completed Amazon Registrations
Completed CORS
Completed Logging
Completed Caching
Completed Authentication
Completed MVC
Built Service Provider
Service Locator Initialized!
Seed Connection String Provider Obtained!
Key Manager Initialization Started!
Initializing Key Manager!Seed Configuration Service Initialized! Conn String: server=iam-public-stage.cjwql5zt0del.us-west-2.rds.amazonaws.com;database=stage_iam_seed;uid=stageService;pwd=stageServicePassword00!;
Entering Configure
Logging has been configured - Proceeding with Startup.Configure()
Cors has been configured - Proceeding with Startup.Configure()
Key Manager Initialization Complete!
JWT Auth has been skipped - Proceeding with Startup.Configure()
Removing No Content Formatter!Removing No Content Formatter Completed!Completed configure, about to wait on keys!
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: IAGE.School.Api.Startup[0]
Application Configure method completed! Hosting Environment: Staging
START RequestId: fd8006aa-df6b-11e7-b7e7-f109bedf6e8f Version: $LATEST
Incoming GET requests to /api/values
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
Request starting GET https://1234567890.execute-api.us-east-1.amazonaws.com/api/values
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: AWSSDK[0]
Found credentials using the AWS SDK's default credential search
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: AWSSDK[0]
Found credentials using the AWS SDK's default credential search
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
Executing action method IAGE.School.Api.Controllers.ValuesController.Get (IAGE.School.Api) with arguments () - ModelState is Valid
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: Microsoft.AspNetCore.Mvc.Internal.ObjectResultExecutor[1]
Executing ObjectResult, writing value Microsoft.AspNetCore.Mvc.ControllerContext.
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
Executed action IAGE.School.Api.Controllers.ValuesController.Get (IAGE.School.Api) in 368.4223ms
\u001b[100m\u001b[32minfo\u001b[39m\u001b[0m: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
Request finished in 840.5629ms 0 text/plain; charset=utf-8
Response Base 64 Encoded: False
END RequestId: fd8006aa-df6b-11e7-b7e7-f109bedf6e8f
REPORT RequestId: fd8006aa-df6b-11e7-b7e7-f109bedf6e8f  Duration: 1127.30 ms    Billed Duration: 1200 ms Memory Size: 3008 MB   Max Memory Used: 97 MB
ibuchan72390 commented 6 years ago

I'm making slow, but eventual progress here. It seems the problems are almost definitely stemming from an issue with IServiceCollection and container management. I've isolated a specific controller that is capable of replicating the issue after repeated runs. It takes about 40 runs to hit the error point, but even if I remove all of the logic and simply inject my questionable service into a brand new controller, I'm able to overload it with the aforementioned error.

Right now, I'm individually testing service injections to my questionable API-level service. I'm replacing all implementation details of the executed method with a simple "return null;" and playing with the constructor injection. It appears that there are 2 Data-level services that are being injected to my API-level service that are suspect. If I remove either of these injected services, the application levels out and everything seems to work as expected. I don't need to remove both of them, only one of them, and everything stops overloading. It almost seems like the container is improperly managing lifestyles for some of its services and growing until it explodes.

Now that I've targeted down one of the exact services causing the issue, I'm simply going to have to try experimenting with them until I can tell what's going on exactly.

ibuchan72390 commented 6 years ago

I've attempted to add logging to a custom service provider and it appears that controller resolution is happening at a layer above the IServiceProvider. I created a custom IServiceProvider that basically wraps the original ServiceProvider functionality with an ILogger. I can see the initial resolutions occurring during the application startup and the first request is definitely firing through the container to configure the application; however, it appears that all subsequent controller-resolution and dependency tree determinations are occurring at a different level, so nothing ever gets logged about them.

Startup Logs:

Beginning ConfigureServices
Completed service collection development
Added HttpContextAccessor
Completed Amazon Registrations
Completed CORS
Completed Logging
Completed Caching
Completed Authentication
Completed MVC
Generated Container
Service Locator Initialized!
Seed Connection String Provider Obtained!
Key Manager Initialization Started!
Entering Configure
Logger Seed Configurations Obtained!
Logger Seed Configurations Filtered!
Key Manager Initialization Complete!
Logger Configurations Complete!
Logging has been configured - Proceeding with Startup.Configure()
Cors has been configured - Proceeding with Startup.Configure()
JWT Auth has been configured - Proceeding with Startup.Configure()
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcMarkerService from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Routing.Internal.RoutingMarkerService from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Infrastructure.IActionDescriptorCollectionProvider from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Routing.Internal.RoutingMarkerService from IContainer
[Information] IAGE.School.Api.Startup: Application Configure method completed! Hosting Environment: Staging
Removing No Content Formatter!Removing No Content Formatter Completed!Completed configure, about to wait on keys!
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.Extensions.Logging.ILoggerFactory from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.Extensions.Logging.ILoggerFactory from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of System.Text.Encodings.Web.UrlEncoder from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Cors.Infrastructure.ICorsService from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Cors.Infrastructure.ICorsPolicyProvider from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.Extensions.DependencyInjection.IServiceScopeFactory from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.Extensions.Logging.ILogger`1[[Microsoft.AspNetCore.Hosting.Internal.WebHost, Microsoft.AspNetCore.Hosting, Version=1.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]] from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of System.Diagnostics.DiagnosticSource from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Http.IHttpContextFactory from IContainer
[Debug] Microsoft.AspNetCore.Hosting.Internal.WebHost: Hosting starting
[Debug] Microsoft.AspNetCore.Hosting.Internal.WebHost: Hosting started
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Hosting.Server.IServer from IContainer

First Request Logs:

START RequestId: 2fb2cc10-e058-11e7-a3ae-d1ef062985df Version: $LATEST
Incoming GET requests to /api/values/auth-user
[Information] Microsoft.AspNetCore.Hosting.Internal.WebHost: Request starting GET https://stage-class-api.iamglobaleducation.com/api/values/auth-user application/json
[Information] Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerMiddleware: Successfully validated the token.
[Information] Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerMiddleware: HttpContext.User merged via AutomaticAuthentication from authenticationScheme: Bearer.
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Routing.Tree.TreeRouteBuilder from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Ivy.IoC.Core.IContainer: Resolving type of Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler from IContainer
[Debug] Microsoft.AspNetCore.Routing.Tree.TreeRouter: Request successfully matched the route with name '' and template 'api/Values/Auth-User'.
[Debug] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker: Executing action IAGE.School.Api.Controllers.ValuesController.AuthUserGet (IAGE.School.Api)
[Information] Microsoft.AspNetCore.Authorization.DefaultAuthorizationService: Authorization was successful for user: auth0|58f7db5d70ef0428e3089f5c.
[Information] AWSSDK: Found credentials using the AWS SDK's default credential search
[Information] AWSSDK: Found credentials using the AWS SDK's default credential search
[Information] IAGE.School.Api.Controllers.ValuesController: HttpContext Item Count: 2
[Information] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker: Executing action method IAGE.School.Api.Controllers.ValuesController.AuthUserGet (IAGE.School.Api) with arguments () - ModelState is Valid
[Information] Ivy.Auth0.Management.Core.Services.IAuth0UserManagementService: GetUserAsync - Obtaining Token
[Information] Ivy.Web.Core.Client.IHttpClientHelper: Sending request to https://iamglobaleducation.auth0.com/oauth/token
[Information] Ivy.Web.Core.Client.IHttpClientHelper: Completing request
[Information] Ivy.Web.Core.Client.IApiHelper: SendApiDataAsync - Request Completed
[Information] Ivy.Web.Core.Client.IApiHelper: SendApiDataAsync - Content Read
[Information] Ivy.Web.Core.Client.IApiHelper: GetApiDataAsync - Request Completed
[Information] Ivy.Web.Core.Client.IApiHelper: GetApiDataAsync - Content Read
[Information] Ivy.Web.Core.Client.IApiHelper: GetApiDataAsync - Content Deserialized
[Information] Ivy.Auth0.Management.Core.Services.IAuth0UserManagementService: GetUserAsync - Obtained Token, Generating Request
[Information] Ivy.Auth0.Management.Core.Services.IAuth0UserManagementService: GetUserAsync - Request Generated, Sending
[Information] Ivy.Web.Core.Client.IHttpClientHelper: Sending request to https://iamglobaleducation.auth0.com/api/v2/users/auth0|58f7db5d70ef0428e3089f5c
[Information] Ivy.Web.Core.Client.IHttpClientHelper: Completing request
[Information] Ivy.Web.Core.Client.IApiHelper: SendApiDataAsync - Request Completed
[Information] Ivy.Web.Core.Client.IApiHelper: SendApiDataAsync - Content Read
[Information] Ivy.Web.Core.Client.IApiHelper: GetApiDataAsync - Request Completed
[Information] Ivy.Web.Core.Client.IApiHelper: GetApiDataAsync - Content Read
[Information] Ivy.Web.Core.Client.IApiHelper: GetApiDataAsync - Content Deserialized
[Information] Ivy.Auth0.Management.Core.Services.IAuth0UserManagementService: GetUserAsync - Request Completed
[Debug] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker: Executed action method IAGE.School.Api.Controllers.ValuesController.AuthUserGet (IAGE.School.Api), returned result Microsoft.AspNetCore.Mvc.ObjectResult.
[Debug] Microsoft.AspNetCore.Mvc.Internal.ObjectResultExecutor: No information found on request to perform content negotiation.
[Debug] Microsoft.AspNetCore.Mvc.Internal.ObjectResultExecutor: Selected output formatter 'Microsoft.AspNetCore.Mvc.Formatters.StringOutputFormatter' and content type 'text/plain; charset=utf-8' to write the response.
[Information] Microsoft.AspNetCore.Mvc.Internal.ObjectResultExecutor: Executing ObjectResult, writing value Microsoft.AspNetCore.Mvc.ControllerContext.
[Information] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker: Executed action IAGE.School.Api.Controllers.ValuesController.AuthUserGet (IAGE.School.Api) in 842.7999ms
[Information] Microsoft.AspNetCore.Hosting.Internal.WebHost: Request finished in 2401.5066ms 0 text/plain; charset=utf-8
Response Base 64 Encoded: False
END RequestId: 2fb2cc10-e058-11e7-a3ae-d1ef062985df

Result Failure Logs:

START RequestId: 2f54cd60-e058-11e7-a0e3-b5c08321ec9a Version: $LATEST
Incoming GET requests to /api/values/auth-user
[Information] Microsoft.AspNetCore.Hosting.Internal.WebHost: Request starting GET https://stage-class-api.iamglobaleducation.com/api/values/auth-user application/json
[Information] Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerMiddleware: Successfully validated the token.
[Information] Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerMiddleware: HttpContext.User merged via AutomaticAuthentication from authenticationScheme: Bearer.
[Debug] Microsoft.AspNetCore.Routing.Tree.TreeRouter: Request successfully matched the route with name '' and template 'api/Values/Auth-User'.
[Debug] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker: Executing action IAGE.School.Api.Controllers.ValuesController.AuthUserGet (IAGE.School.Api)
[Information] Microsoft.AspNetCore.Authorization.DefaultAuthorizationService: Authorization was successful for user: auth0|58f7db5d70ef0428e3089f5c.
Unhandled Exception: System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
at lambda_method(Closure , ServiceProvider )
at Microsoft.Extensions.Internal.ActivatorUtilities.GetService(IServiceProvider sp, Type type, Type requiredBy, Boolean isDefaultParameterRequired)
at lambda_method(Closure , IServiceProvider , Object[] )
at Microsoft.AspNetCore.Mvc.Internal.TypeActivatorCache.CreateInstance[TInstance](IServiceProvider serviceProvider, Type implementationType)
at Microsoft.AspNetCore.Mvc.Controllers.DefaultControllerFactory.CreateController(ControllerContext context)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeAllActionFiltersAsync>d__26.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeAllActionFiltersAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeExceptionFilterAsync>d__25.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeExceptionFilterAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeResourceFilterAsync>d__23.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeResourceFilterAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeResourceFilterAsync>d__23.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeResourceFilterAsync()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeAsync>d__18.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeAsync()
at Microsoft.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware`1.<Invoke>d__18.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware`1.Invoke(HttpContext context)
at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.<Invoke>d__7.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.Invoke(HttpContext context)
at Elmah.Io.AspNetCore.ElmahIoMiddleware.<Invoke>d__6.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Elmah.Io.AspNetCore.ElmahIoMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.<Invoke>d__3.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.Invoke(HttpContext httpContext)
at Microsoft.AspNetCore.Hosting.Internal.HostingApplication.ProcessRequestAsync(Context context)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.<ProcessRequest>d__15.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.ProcessRequest(ILambdaContext lambdaContext, Context context, InvokeFeatures features, Boolean rethrowUnhandledError)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.<FunctionHandlerAsync>d__12.MoveNext()
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
at Amazon.Lambda.AspNetCoreServer.APIGatewayProxyFunction.FunctionHandlerAsync(APIGatewayProxyRequest request, ILambdaContext lambdaContext)
at lambda_method(Closure , Stream , Stream , ContextInfo )
at AWSLambda.Internal.Bootstrap.UserCodeLoader.Invoke(Stream lambdaData, Stream outStream, ContextInfo contextInfo)
at AWSLambda.Internal.Bootstrap.LambdaBootstrap.Invoke(ContextInfo contextInfo, Stream inputStream, Stream outputStream)
at AWSLambda.Internal.Bootstrap.UnsafeEntry.Invoke(Int64 maxBodySize, Byte* payload, Int64& payloadLength, Byte* requestIdBuffer, Int64 requestIdBufferLength, Byte* functionArn, Int64 functionArnLength, Byte* clientContext, Int64 clientContextLength, Byte* cognitoIdentityId, Int64 cognitoIdentityIdLength, Byte* cognitoPoolId, Int64 cognitoPoolIdLength, Byte* credsKey, Int64 credsKeyLength, Byte
END RequestId: 2f54cd60-e058-11e7-a0e3-b5c08321ec9a
REPORT RequestId: 2f54cd60-e058-11e7-a0e3-b5c08321ec9a  Duration: 271.01 ms Billed Duration: 300 ms Memory Size: 1024 MB    Max Memory Used: 674 MB
RequestId: 2f54cd60-e058-11e7-a0e3-b5c08321ec9a Process exited before completing request

It almost seems as if the failure on the System.AccessViolationException is occurring somewhere internal to an MVC-level service. I can't see into any logs here or anything besides what I can write out at the application level, I'm just at a loss as to what to do. I guess tomorrow I'll try to create a Docker container that replicates the Lambda environment and see if I can recreate the issue. I have no idea how else I can attempt to replicate the failures of the Docker-based Lambda environment without a proper capability to run the entire Lambda process locally.

ibuchan72390 commented 6 years ago

Hey, @normj, I THINK I've been able to replicate this on a smaller scale. I've setup a repo at the following GitHub url: https://github.com/ibuchan72390/iage-lambda-failure

I am still referencing some proprietary packages, but they're all accessible via the modified NuGet.config file included in the repo. I am registering them to a container and resolving a single service into a controller; however, I'm not doing anything with that service other than resolving it. If this still is not slim enough of a reproduction, please let me know and I'll try to slim it down further.

The issue does NOT replicate locally; however, I haven't tried another Ubuntu 16.04 container yet. The project should be able to be packaged using the "dotnet lambda package" command and uploaded to a Lambda function. If you simply execute the following test event targeting the single controller method, you will see the memory expand and then explode within 20 executions:

{
  "resource": "/{proxy+}",
  "requestContext": {
    "resourceId": "123456",
    "apiId": "1234567890",
    "resourcePath": "/{proxy+}",
    "httpMethod": "POST",
    "requestId": "c6af9ac6-7b61-11e6-9a41-93e8deadbeef",
    "accountId": "123456789012",
    "identity": {
      "apiKey": null,
      "userArn": null,
      "cognitoAuthenticationType": null,
      "caller": null,
      "userAgent": "Custom User Agent String",
      "user": null,
      "cognitoIdentityPoolId": null,
      "cognitoIdentityId": null,
      "cognitoAuthenticationProvider": null,
      "sourceIp": "127.0.0.1",
      "accountId": null
    },
    "stage": "prod"
  },
  "headers": {
    "Via": "1.1 08f323deadbeefa7af34d5feb414ce27.cloudfront.net (CloudFront)",
    "Accept-Language": "en-US,en;q=0.8",
    "CloudFront-Is-Desktop-Viewer": "true",
    "CloudFront-Is-SmartTV-Viewer": "false",
    "CloudFront-Is-Mobile-Viewer": "false",
    "X-Forwarded-For": "127.0.0.1, 127.0.0.2",
    "CloudFront-Viewer-Country": "US",
    "Accept": "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8",
    "Upgrade-Insecure-Requests": "1",
    "X-Forwarded-Port": "443",
    "Host": "1234567890.execute-api.us-east-1.amazonaws.com",
    "X-Forwarded-Proto": "https",
    "X-Amz-Cf-Id": "cDehVQoZnx43VYQb9j2-nvCh-9z396Uhbp027Y2JvkCPNLmGJHqlaA==",
    "CloudFront-Is-Tablet-Viewer": "false",
    "Cache-Control": "max-age=0",
    "User-Agent": "Custom User Agent String",
    "CloudFront-Forwarded-Proto": "https",
    "Accept-Encoding": "gzip, deflate, sdch"
  },
  "pathParameters": {
    "proxy": "api/values/wait/2"
  },
  "httpMethod": "GET",
  "path": "api/values/wait/2"
}
normj commented 6 years ago

I'm getting the following error when I try and run the code. Is there something I'm missing?

System.InvalidOperationException: Unable to resolve service for type 'Microsoft.AspNetCore.Http.IHttpContextAccessor' while attempting to activate 'Ivy.Auth0.Web.Services.UserProvider'.
ibuchan72390 commented 6 years ago

Stupid mistake on my part. I must have accidentally removed it when cleaning up my comments. Just pushed the fixed version.

Over the weekend, I've replaced the hosting method with a docker container instead of the Lambda function so that I can get more visibility into what's happening in the execution and memory management; however, I don't believe I've been able to replicate the issue yet.

normj commented 6 years ago

Okay, I'm taking a look to see if I see anything.

normj commented 6 years ago

I believe there is something with your dependencies that isn't compatible with .NET Core and Linux, not Lambda related.

Here is what I have done to try and figure this out. I deployed your test case and after 4 executions Lambda reported the process died and restarted it. Then hoping that are upcoming .NET Core 2.0 runtime would have more information I ported the sample to .NET Core 2.0 and ran it on our internal .NET Core 2.0 Lambda runtime. The process suddenly died in .NET Core 2.0 Lambda just like it did in .NET Core 1.0.

The next step was I took my .NET Core 2.0 port of your code to an Amazon Linux EC2 instance with .NET Core 2.0. Ran the values request in a loop and the dotnet process suddenly died after a few runs. From their I got an error message from the dotnet runtime saying "Aborted" and exit code of 134 which is basically saying the process was aborted. So now we have the failing behavior outside of Lambda.

One other interesting debugging information. In .NET Core 2.0 version I attached an event for unresolved types from the AppDomain.

AppDomain.CurrentDomain.TypeResolve += CurrentDomain_TypeResolve;

...

private System.Reflection.Assembly CurrentDomain_TypeResolve(object sender, ResolveEventArgs args)
{
    Console.WriteLine($"|TypeResolve| " + args.Name);
    return null;
}

And it got a notification about an unresolved assembly Mono.Runtime. That seems very suspect to me. Can you think of anything in your dependencies that would cause the Mono.Runtime to be loaded.

ibuchan72390 commented 6 years ago

I can't think of any reason that my code would be explicitly asking for Mono.Runtime; however, I will start digging into it. That's extremely suspicious to me because the only external packages I really use are the following, everything else are directly from System and Microsoft:

AWSSDK Dapper Moq MySql Newtonsoft XUnit

I've currently ported my code to a docker-based EC2 instance using the same code leveraging a T2.small and I haven't run into any issues. There's a good chance this could be that I based my docker instance from the microsoft/aspnetcore-build:2.0 - perhaps this image is not running into the same linux-based dependency issues that I've been experiencing in Lambda because it's using only the Windows-specific DLL configurations.

My guess it that one of the linux-specific libraries is causing an issue here due to the specific "runtime" configurations allowed in the csproj file. I've been working with Docker to get the new hosting method up and running, so I'll try to use it to get a local replication of the issue. If possible, hopefully that will point me in the right direction while the docker container holds up the API in the meantime.

Thank you very much for your assistance. I will continue seeing what I can find and I will be sure to update this thread accordingly to help anyone else who may hit this in the future.

ibuchan72390 commented 6 years ago

Started searching for references in DotPeek on my output folder. It appears this may be an attempt by the Microsoft internal facilities to detect if the system is currently using Mono.

Microsoft.AspNetCore.Mvc.Core.Internal.ReferenceEqualityComparer.cs

Microsoft.AspNetCore.Mvc.Core.Internal.DefaultComplexValidationStrategy.cs

It also appears that DotPeek has detected a similar attempt to check if the system is using Mono in the MySql library I'm referencing.

using System;
using System.Runtime.InteropServices;

namespace MySql.Data.Common
{
  internal class Platform
  {
    private static bool _inited;
    private static bool _isMono;

    private Platform()
    {
    }

    public static bool IsWindows()
    {
      return RuntimeInformation.IsOSPlatform(OSPlatform.get_Windows());
    }

    public static bool IsMono()
    {
      if (!Platform._inited)
        Platform.Init();
      return Platform._isMono;
    }

    private static void Init()
    {
      Platform._inited = true;
      Platform._isMono = Type.GetType("Mono.Runtime") != null;
    }

    public static bool IsDotNetCore()
    {
      return true;
    }
  }
}
using System;

namespace MySql.Web.Security
{
  internal static class Runtime
  {
    private static bool inited;
    private static bool isMono;

    public static bool IsMono
    {
      get
      {
        if (!Runtime.inited)
          Runtime.Init();
        return Runtime.isMono;
      }
    }

    private static void Init()
    {
      Runtime.isMono = Type.GetType("Mono.Runtime") != null;
      Runtime.inited = true;
    }
  }
}

None of these appear as if they'd be the cause of anything particularly dangerous; however, I've had issues with this MySql library and some of it's specific dependencies in the past. I may have to experiment an upgrade to .NET Core 2.0 upgrade locally and upgrade that referenced library as well; they only have a single release of MySql.Data that is .NET Core 1.0.1 compatible.

ibuchan72390 commented 6 years ago

Hey, @normj, may I ask what Linux version you were running in your EC2 instance in which you were able to reproduce the issue? I'm going to try to run it in an EC2 instance with an Apache reverse proxy and I'd just like to make sure I'm following your reproduction steps as closely as possible.

I've been trying to locally reproduce the issue leveraging some modified Linux Docker containers; however, my dotnet enabled Ubuntu 16.04 container does not seem to be failing on me.

normj commented 6 years ago

I used the latest Amazon Linux available from the EC2 console, Amazon Linux AMI 2017.09.1 (HVM) SSD Volume Type, and then installed .NET Core 2.0 on it. Here is my code I used to call your Lambda function.

using System;
using System.IO;
using System.Threading.Tasks;
using IAGE.School.Api;

using Amazon.Lambda.APIGatewayEvents;
using Amazon.Lambda.TestUtilities;
using Amazon.Lambda.Serialization.Json;

namespace TestDriver
{
    class Program
    {
        static void Main(string[] args)
        {
            RunRequest(10, "./sample-request.json").Wait();
            Console.WriteLine("Done");
        }

        static async Task RunRequest(int iterations, string requestPath)
        {
            var point = new LambdaEntryPoint();

            for (int i = 0; i < iterations; i++)
            {
                Console.WriteLine("Attempt: " + i);

                var context = new TestLambdaContext();
                var serializer = new JsonSerializer();
                try
                {
                    using (var stream = File.OpenRead(requestPath))
                    {
                        var apiRequest = serializer.Deserialize<APIGatewayProxyRequest>(stream);
                        await point.FunctionHandlerAsync(apiRequest, context);
                    }
                }
                catch (Exception e)
                {
                    Console.WriteLine(e.Message);
                    Console.WriteLine(e.StackTrace);
                }
            }
        }
    }
}
ibuchan72390 commented 6 years ago

I have been heavily detoured for the past few weeks; however, the code sample you posted is one of the most valuable things I've seen for understanding how this whole process works. I would love to see this piece publicized a little bit more because it really helps demonstrate the flow from the JSON test files, to the interpretation into a .NET HTTP Request, and it's pass to the LambdaEntryPoint.

I've finally been able to reproduce the issue in a Docker instance running .NET 1.0.4 and Ubuntu 16.04 today. You are 100% correct that this is a linux-specific issue. The exact same code running on a Windows instance runs completely fine. I find it interesting that the API runs fine if it's simply a raw deployment of the executable within an Ubuntu 16.04 Docker where that request is repeated with Postman; however, when run through the TestLambdaContext the request on the same HTTP method will run into this issue. I've currently converted an old laptop to run Ubuntu 16.04 and am going to copy the project over there to see if I can dig into the issue with VS Code tomorrow.

ibuchan72390 commented 6 years ago

After spending a few more days working on this issue, I've got a bit more information, but still no result. I've been able to pull the test project failure over to an Ubuntu instance and it definitely replicates the issue as expected; however, debugging into the aws-lambda-dotnet libraries has been difficult because of the Ubuntu environment. It appears VS Code doesn't share the Visual Studio capability of loading files included in the project and the build-process in your custom build.proj file seems to depend on some Windows-specific commands.

I've since performed a few more experiments leveraging Docker to test out the application across different OS environments. I've created a corresponding sample project that runs the same request against an API without going through the TestLambdaContext. The corresponding sample project can be instantiated in both Windows and Ubuntu and have 100+ requests run against it without issue. I find it interesting that when I make the exact same request via an instantiated IWebHost via an HttpRequestMessage and an HttpClient, I never once experience the issue; it ONLY seems to occur when running the request through the LambdaEntryPoint and the TestLambdaContext.

Using your sample code that specifically invokes the LambdaEntryPoint via the TestLambdaContext, I get some very different results. If I pass NO credentials to the Windows-based Docker instance, each request will fail due to an inability to find the "Default" profile. If I pass valid credentials, the entire application runs fine on all 100 requests. If I pass INVALID credentials, I appear to see the Windows instance replicate the issue; however, this only occurs in Docker. I've attempted to wipe my local AWS credentials by clearing out the /.aws folder before populating it with an Access Key and Secret Key simply equal to "TEST"; however, this appears to run locally without issue.

Now, I'm doing my best to debug into the specific libraries for invoking the TestLambdaContext and specifically the LambdaEntryPoint.FunctionHandlerAsync methods. The problem I seem to be running into here is a lack of symbol files that will allow me to properly debug into the AWS SDK NuGet packages. I've currently tried to replicate your repository locally so that I can create a custom build of the versions with Symbols and Source on my Windows machine. I'm then using these files in a hope to essentially "poison" my NuGet package stream on Ubuntu with a valid replicate DLL containing symbol files and source.

I have since moved my code over to BitBucket. If you would still like to examine the status of the issue, I can share my repository with you.

ibuchan72390 commented 6 years ago

@normj, I wish I could give a better explanation as to what was causing this exact issue; however, your release of Lambda supporting .NET Core 2.0 seems to have fixed everything for me. I've gone through all the way up from my Framework project, through my API, and the shared reproduction and upgraded everything to run in netcoreapp2.0. Upon updating all of the supporting libraries and modifying my docker instances to use .NET Core 2.0, my Docker-based Linux reproductions started running without issue.

Originally, your code sample was able to blow up my Docker-based Linux instantiation of the console application within 5 executions. Now, using Core 2.0, I'm cruising through 100+ executions with zero errors. I know you had experimented upgrading the reproduction to leverage .NET Core 2.0 and it was still experiencing the memory issue. I'm curious if something might have changed in either one of my supporting Framework libraries that now had access to newer NuGet references or perhaps a change in your Amazon.Lambda releases per the new .NET Core 2.0 libraries that fixed the issue. Regardless, everything is now running as expected!

normj commented 6 years ago

I would have liked to known the cause as well but I'll take the win :)

When I tested it before it would have been under .NET Core 2.0.0 and now Lambda has 2.0.4 so maybe something in that patch fixed the issue.

raRaRa commented 6 years ago

I'm running into similar memory leak with .NET Core 2, but no exception is thrown AFAIK. Going to debug my issue further.

ibuchan72390 commented 6 years ago

I find the best method of replicating the Lambda runtime environment is the code sample that normj posted above. If you have a JSON execution you can pass to your Lambda that will definitively cause the failure after a couple executions, that will closely mimic the actions that Lambda is taking. If you can use that to try and replicate your issue locally, that's your best shot. I had to spend hours with Docker to try and test out my application in many different OS environments as it was only replicating in a Linux based system when run through the LambdaEntryPoint; the base Kestrel API could repeat the executions without issue.

I believe my issue specifically came down to a System.AccessViolationException once I did a little bit more debugging. I had initially assumed it was a StackOverflow based on the way the issue progressively built up and shut down, but it appears in the long run, it was much more of a memory space management issue.