asp.net core 3.0 application exited with stack overflow after a period of time.

[ousiax]

Describe the bug

A clear and concise description of what the bug is.

To Reproduce

Steps to reproduce the behavior:

asp.net core 3.0 application exited with stack overflow after a period of time.

Expected behavior

A clear and concise description of what you expected to happen.

Screenshots

If applicable, add screenshots to help explain your problem.

Additional context

Add any other context about the problem here.
Include the output of dotnet --info

{ "time": "2019\/09\/18 05:37:37.946 +00:00", "category": "Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository", "log_level": "warn", "message": "Storing keys in a directory '\/root\/.aspnet\/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed." }
{ "time": "2019\/09\/18 05:37:38.045 +00:00", "category": "Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager", "log_level": "info", "message": "User profile is available. Using '\/root\/.aspnet\/DataProtection-Keys' as key repository; keys will not be encrypted at rest." }
{ "time": "2019\/09\/18 05:37:38.056 +00:00", "category": "Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager", "log_level": "info", "message": "Creating key {06c18e84-41e0-4d37-9050-8b03ab2b1e07} with creation date 2019-09-18 05:37:38Z, activation date 2019-09-18 05:37:38Z, and expiration date 2019-12-17 05:37:38Z." }
{ "time": "2019\/09\/18 05:37:38.061 +00:00", "category": "Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager", "log_level": "warn", "message": "No XML encryptor configured. Key {06c18e84-41e0-4d37-9050-8b03ab2b1e07} may be persisted to storage in unencrypted form." }
{ "time": "2019\/09\/18 05:37:38.065 +00:00", "category": "Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository", "log_level": "info", "message": "Writing data to file '\/root\/.aspnet\/DataProtection-Keys\/key-06c18e84-41e0-4d37-9050-8b03ab2b1e07.xml'." }
Hosting environment: Production
Content root path: /web
Now listening on: http://[::]:80
Application started. Press Ctrl+C to shut down.
{ "time": "2019\/09\/18 05:37:44.889 +00:00", "category": "Microsoft.AspNetCore.Hosting.Diagnostics", "log_level": "info", "message": "Request starting HTTP\/1.1 GET http:\/\/10.244.1.105:80\/healthz  ", "trace_id": "0HLPRV9AEGLLC:00000001" }
{ "time": "2019\/09\/18 05:37:44.944 +00:00", "category": "Microsoft.AspNetCore.Hosting.Diagnostics", "log_level": "info", "message": "Request finished in 56.5026ms 200 text\/plain", "trace_id": "0HLPRV9AEGLLC:00000001" }
{ "time": "2019\/09\/18 05:37:47.837 +00:00", "category": "Microsoft.AspNetCore.Hosting.Diagnostics", "log_level": "info", "message": "Request starting HTTP\/1.1 GET http:\/\/10.244.1.105:80\/healthz  ", "trace_id": "0HLPRV9AEGLLD:00000001" }
{ "time": "2019\/09\/18 05:37:47.838 +00:00", "category": "Microsoft.AspNetCore.Hosting.Diagnostics", "log_level": "info", "message": "Request finished in 1.2990000000000002ms 200 text\/plain", "trace_id": "0HLPRV9AEGLLD:00000001" }
{ "time": "2019\/09\/18 05:37:48.908 +00:00", "category": "Microsoft.AspNetCore.Hosting.Diagnostics", "log_level": "info", "message": "Request starting HTTP\/1.1 GET .... ", "trace_id": "0HLPRV9AEGLLE:00000001", "request_id": "b5a062e0641c495028f2982c8553a40a" }
{ "time": "2019\/09\/18 05:37:48.943 +00:00", "category": "Microsoft.AspNetCore.Routing.EndpointMiddleware", "log_level": "info", "message": "Executing endpoint ....'", "trace_id": "0HLPRV9AEGLLE:00000001", "request_id": "b5a062e0641c495028f2982c8553a40a" }
{ "time": "2019\/09\/18 05:37:48.982 +00:00", "category": "Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker", "log_level": "info", "message": "Route matched with {action = \"Auth\", controller = \"Session\"}. Executing controller action with signature System.Threading.Tasks.Task`1[....] AuthAsync(System.String) on controller ....", "trace_id": "0HLPRV9AEGLLE:00000001", "request_id": "b5a062e0641c495028f2982c8553a40a" }
{ "time": "2019\/09\/18 05:37:49.453 +00:00", "category": "Microsoft.AspNetCore.Hosting.Diagnostics", "log_level": "info", "message": "Request starting HTTP\/1.1 GET http:...  ", "trace_id": "0HLPRV9AEGLLF:00000001", "request_id": "e0f2c80ac85915e4f88a2b2bd9a3b214" }


... a lot of information logging ...

 "time": "2019\/09\/18 05:37:52.653 +00:00", "category": "...", "log_level": "info", "message": "Success to authenticate with HMAC: Key: ..., Mac: ..., Timestamp: 1568785042, Method: GET, Path: ...", "trace_id": "0HLPRV9AEGLLO:00000001", "request_id": "5e90162411e4429bad1f04c19eabeb17" }
{ "time": "2019\/09\/18 05:37:52.653 +00:00", "category": "....", "log_level": "info", "message": "Success to authenticate with HMAC: Key: ..., Mac: ..., Timestamp: 1568785042, Method: GET, Path: ....", "trace_id": "0HLPRV9AEGLLP:00000001", "request_id": "cffedf4f4c25ecb41fe5a5c61fdbf55a" }
Stack overflow.

dotnet --info
  It was not possible to find any installed .NET Core SDKs
  Did you mean to run .NET Core SDK commands? Install a .NET Core SDK from:
      https://aka.ms/dotnet-download

Host (useful for support):
  Version: 3.0.0-rc1-19456-20
  Commit:  8f5d7b1ba4

.NET Core SDKs installed:
  No SDKs were found.

.NET Core runtimes installed:
  Microsoft.AspNetCore.App 3.0.0-rc1.19457.4 [/usr/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 3.0.0-rc1-19456-20 [/usr/share/dotnet/shared/Microsoft.NETCore.App]

To install additional .NET Core runtimes or SDKs:
  https://aka.ms/dotnet-download

kubectl describe po webapp-8cbddfcf5-q9zfp 
Name:           webapp-8cbddfcf5-q9zfp

Status:         Running
IP:             10.244.1.105
Controlled By:  ReplicaSet/webapp-8cbddfcf5
Containers:

    State:          Waiting
      Reason:       CrashLoopBackOff
    Last State:     Terminated
      Reason:       Error
      Exit Code:    139
      Started:      Wed, 18 Sep 2019 13:48:03 +0800
      Finished:     Wed, 18 Sep 2019 13:48:24 +0800
    Ready:          False
    Restart Count:  4
    Limits:
      cpu:     500m
      memory:  1500Mi
    Requests:
      cpu:      100m
      memory:   100Mi
    Liveness:   http-get http://:80/healthz delay=5s timeout=5s period=10s #success=1 #failure=3
    Readiness:  http-get http://:80/healthz delay=10s timeout=5s period=10s #success=1 #failure=3

$ kubectl get po
NAME                     READY   STATUS             RESTARTS   AGE
webapp-8cbddfcf5-br4wb   0/1     CrashLoopBackOff   3          20m
webapp-8cbddfcf5-q9zfp   0/1     Error              4          20m

FROM ...  as builder
. . . .

FROM mcr.microsoft.com/dotnet/core/aspnet:3.0
LABEL maintainer="Xu <xuqiang@gridsum.com>"
WORKDIR /web
COPY --from=builder /web/_build .
CMD ["dotnet", "Gridsum.HMAC.App.dll"]

[pranavkm]

@qqbuby perhaps you're running in to #13924. The exception is triggered during serialization of certain JSON payload, which might explain why it doesn't happen all the time.

Any chance you have a minimal repro of the application or logs that indicate a control action performing JSON serialization when the stack overflow happens?

[ousiax]

@pakrym

There aren't exception messages or any other signal to indicate what happened, just stack overflow. So I don't where is wrong.

$ kubectl get po -l app.kubernetes.io/name=AspNetCore
NAME                     READY   STATUS    RESTARTS   AGE
webapp-9d4dd68c4-nvg7x   1/1     Running   3          13m
webapp-9d4dd68c4-rfk4v   1/1     Running   3          12m
$ kubectl top po -l app.kubernetes.io/name=AspNetCore
NAME                     CPU(cores)   MEMORY(bytes)   
webapp-9d4dd68c4-nvg7x   72m          87Mi            
webapp-9d4dd68c4-rfk4v   104m         78Mi            
$ kubectl logs -l app.kubernetes.io/name=AspNetCore --previous
{ "time": "2019\/09\/19 02:18:04.154 +00:00", "category": "Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository", "log_level": "warn", "message": "Storing keys in a directory '\/root\/.aspnet\/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed." }
{ "time": "2019\/09\/19 02:18:04.191 +00:00", "category": "Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager", "log_level": "warn", "message": "No XML encryptor configured. Key {d2f500b0-4fb4-411f-9475-9f8058d5f5bc} may be persisted to storage in unencrypted form." }
Hosting environment: Production
Content root path: /web
Now listening on: http://[::]:80
Application started. Press Ctrl+C to shut down.
Stack overflow.
{ "time": "2019\/09\/19 02:18:02.834 +00:00", "category": "Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository", "log_level": "warn", "message": "Storing keys in a directory '\/root\/.aspnet\/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed." }
{ "time": "2019\/09\/19 02:18:02.888 +00:00", "category": "Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager", "log_level": "warn", "message": "No XML encryptor configured. Key {961bdefc-f2e5-436d-b3ed-aa309dd74fce} may be persisted to storage in unencrypted form." }
Hosting environment: Production
Content root path: /web
Now listening on: http://[::]:80
Application started. Press Ctrl+C to shut down.
Stack overflow.

[ousiax]

BTW, if I give the pod more resources as below:

    Limits:
      cpu:     2
      memory:  5000Mi
    Requests:
      cpu:      100m
      memory:   100Mi

it seems that the app could run a long long period of time, but still crashed with stack overflow.

[davidfowl]

@qqbuby if you can reproduce the problem you can configure the runtime to generate a coredump on crash https://github.com/dotnet/coreclr/blob/master/Documentation/botr/xplat-minidump-generation.md#configurationpolicy

[ousiax]

After upgrade the app from RC1 to .NET Core 3.0, the problem has been solved.