search

dotnet / aspnetcore

ASP.NET Core is a cross-platform .NET framework for building modern cloud-based web applications on Windows, Mac, or Linux.
https://asp.net
MIT License
35.5k stars 10.04k forks source link

System.Net.Sockets.SocketException (125): Operation canceled #22186

Closed j4587698 closed 3 years ago

j4587698 commented 4 years ago

Describe the bug

call Microsoft Account external login setup with nginx proxy fails(502 Bad Gateway). Local debugging and not using nginx proxy are success.

logs:

warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessReceives()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoReceive()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.ReadAsync(CancellationToken token)
   at System.IO.Pipelines.Pipe.DefaultPipeReader.ReadAsync(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.BeginRead(ValueTask`1& awaitable)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)

nginx configuration

location / {
       proxy_pass http://localhost:5000;
       proxy_http_version 1.1;
       proxy_set_header Upgrade $http_upgrade;
       proxy_set_header Connection keep-alive;
       proxy_set_header Host $host;
       proxy_cache_bypass $http_upgrade;
       proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
       proxy_set_header X-Forwarded-Proto $scheme;
     }

Further technical details

运行时环境: OS Name: Windows OS Version: 6.1.7601 OS Platform: Windows RID: win7-x64 Base Path: C:\Program Files\dotnet\sdk\5.0.100-preview.4.20258.7\

Host (useful for support): Version: 5.0.0-preview.4.20251.6 Commit: 47ec733ba7

.NET SDKs installed: 3.1.300-preview-015135 [C:\Program Files\dotnet\sdk] 3.1.300 [C:\Program Files\dotnet\sdk] 5.0.100-preview.2.20176.6 [C:\Program Files\dotnet\sdk] 5.0.100-preview.4.20258.7 [C:\Program Files\dotnet\sdk]

.NET runtimes installed: Microsoft.AspNetCore.All 2.1.16 [C:\Program Files\dotnet\shared\Microsoft.AspN etCore.All] Microsoft.AspNetCore.App 2.1.16 [C:\Program Files\dotnet\shared\Microsoft.AspN etCore.App] Microsoft.AspNetCore.App 3.1.2 [C:\Program Files\dotnet\shared\Microsoft.AspNe tCore.App] Microsoft.AspNetCore.App 3.1.4 [C:\Program Files\dotnet\shared\Microsoft.AspNe tCore.App] Microsoft.AspNetCore.App 5.0.0-preview.4.20257.10 [C:\Program Files\dotnet\sha red\Microsoft.AspNetCore.App] Microsoft.NETCore.App 2.1.16 [C:\Program Files\dotnet\shared\Microsoft.NETCore .App] Microsoft.NETCore.App 3.1.2 [C:\Program Files\dotnet\shared\Microsoft.NETCore. App] Microsoft.NETCore.App 3.1.4 [C:\Program Files\dotnet\shared\Microsoft.NETCore. App] Microsoft.NETCore.App 5.0.0-preview.4.20251.6 [C:\Program Files\dotnet\shared\ Microsoft.NETCore.App] Microsoft.WindowsDesktop.App 3.1.2 [C:\Program Files\dotnet\shared\Microsoft.W indowsDesktop.App] Microsoft.WindowsDesktop.App 3.1.4 [C:\Program Files\dotnet\shared\Microsoft.W indowsDesktop.App] Microsoft.WindowsDesktop.App 5.0.0-preview.4.20251.1 [C:\Program Files\dotnet\ shared\Microsoft.WindowsDesktop.App]

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


- The IDE (VS / VS Code/ VS4Mac) you're running on, and it's version
VS preview 16.6
Tratcher commented 4 years ago

Can you share the rest of the server logs (on debug)?

Also, check these proxy debugging tips. https://docs.microsoft.com/en-us/aspnet/core/host-and-deploy/proxy-load-balancer?view=aspnetcore-3.1#troubleshoot

j4587698 commented 4 years ago

@Tratcher logs

Request Method: GET
Request Scheme: https
Request Path: /
Request Headers:
Connection: keep-alive
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9
Accept-Encoding: gzip, deflate, br
Accept-Language: zh-CN,zh;q=0.9
Cookie: pgv_pvi=2531707904; Hm_lvt_723b41ba2ab1cc2370f96d181acebbd1=1587021454,1587611441,1587884718,1588047635; _ga=GA1.2.2056240862.1590109664; portainer.datatable_text_filter_home_endpoints=; portainer.datatable_settings_registries=%7B%22open%22%3Afalse%2C%22repeater%22%3A%7B%22autoRefresh%22%3Afalse%2C%22refreshRate%22%3A%2230%22%7D%7D; portainer.datatable_settings_users=%7B%22open%22%3Afalse%2C%22repeater%22%3A%7B%22autoRefresh%22%3Afalse%2C%22refreshRate%22%3A%2230%22%7D%7D; portainer.datatable_settings_containers=%7B%22open%22%3Afalse%2C%22repeater%22%3A%7B%22autoRefresh%22%3Afalse%2C%22refreshRate%22%3A%2230%22%7D%2C%22truncateContainerName%22%3Atrue%2C%22containerNameTruncateSize%22%3A32%2C%22showQuickActionStats%22%3Atrue%2C%22showQuickActionLogs%22%3Atrue%2C%22showQuickActionExec%22%3Atrue%2C%22showQuickActionInspect%22%3Atrue%2C%22showQuickActionAttach%22%3Afalse%7D; portainer.datatable_settings_container-networks=%7B%22open%22%3Afalse%2C%22repeater%22%3A%7B%22autoRefresh%22%3Afalse%2C%22refreshRate%22%3A%2230%22%7D%7D; portainer.datatable_settings_networks=%7B%22open%22%3Afalse%2C%22repeater%22%3A%7B%22autoRefresh%22%3Afalse%2C%22refreshRate%22%3A%2230%22%7D%7D; portainer.datatable_settings_images=%7B%22open%22%3Afalse%2C%22repeater%22%3A%7B%22autoRefresh%22%3Afalse%2C%22refreshRate%22%3A%2230%22%7D%7D; portainer.LOGIN_STATE_UUID=5b89417d-9b76-4c4e-ada4-aa26f0ba3e4d
Host: e5.jvxiang.com
User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.138 Safari/537.36
Upgrade-Insecure-Requests: 1
X-Original-Proto: http
Sec-Fetch-Site: none
Sec-Fetch-Mode: navigate
Sec-Fetch-User: ?1
Sec-Fetch-Dest: document
X-Original-For: 127.0.0.1:54200

Request RemoteIp: 120.224.111.90
Tratcher commented 4 years ago

Looks like your proxy is configured right.

How about the rest of the server logs around that exception above?

j4587698 commented 4 years ago

@Tratcher nothing in asp.net core. nginx errors log like

2020/05/24 20:14:06 [error] 26629#0: *386 upstream prematurely closed connection while reading response header from upstream, client: 182.33.179.22, server: e5.jvxiang.com, request: "POST /User/Login?returnUrl=%2F HTTP/2.0", upstream: "http://[::1]:5000/User/Login?returnUrl=%2F", host: "e5.jvxiang.com", referrer: "https://e5.jvxiang.com/User/Login?ReturnUrl=%2F"
2020/05/24 20:20:30 [error] 7993#0: *409 upstream prematurely closed connection while reading response header from upstream, client: 182.33.179.22, server: e5.jvxiang.com, request: "GET /User/Login?ReturnUrl=%2F HTTP/1.1", upstream: "http://[::1]:5000/User/Login?ReturnUrl=%2F", host: "e5.jvxiang.com"
2020/05/24 20:20:30 [error] 7993#0: *409 upstream prematurely closed connection while reading response header from upstream, client: 182.33.179.22, server: e5.jvxiang.com, request: "GET /User/Login?ReturnUrl=%2F HTTP/1.1", upstream: "http://127.0.0.1:5000/User/Login?ReturnUrl=%2F", host: "e5.jvxiang.com"
2020/05/24 20:20:31 [error] 7993#0: *409 no live upstreams while connecting to upstream, client: 182.33.179.22, server: e5.jvxiang.com, request: "GET /favicon.ico HTTP/1.1", upstream: "http://localhost/favicon.ico", host: "e5.jvxiang.com", referrer: "https://e5.jvxiang.com/User/Login?ReturnUrl=%2F"
2020/05/24 20:20:31 [error] 7993#0: *409 no live upstreams while connecting to upstream, client: 182.33.179.22, server: e5.jvxiang.com, request: "GET /User/Login?ReturnUrl=%2F HTTP/1.1", upstream: "http://localhost/User/Login?ReturnUrl=%2F", host: "e5.jvxiang.com"
2020/05/24 20:20:33 [error] 7993#0: *409 no live upstreams while connecting to upstream, client: 182.33.179.22, server: e5.jvxiang.com, request: "GET /favicon.ico HTTP/1.1", upstream: "http://localhost/favicon.ico", host: "e5.jvxiang.com", referrer: "https://e5.jvxiang.com/User/Login?ReturnUrl=%2F"
Tratcher commented 4 years ago

Then where did you get that SocketException? I'm not looking for just errors, I'm hoping the full debug level logs can provide context for it.

j4587698 commented 4 years ago

@Tratcher Console log. all log is here

info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: /app
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessReceives()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoReceive()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.ReadAsync(CancellationToken token)
   at System.IO.Pipelines.Pipe.DefaultPipeReader.ReadAsync(CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.BeginRead(ValueTask`1& awaitable)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
Tratcher commented 4 years ago

Those are still info and warning levels, can you turn them up to debug?

j4587698 commented 4 years ago

@Tratcher Ok, all the debug log

dbug: Microsoft.Extensions.Hosting.Internal.Host[1]
      Hosting starting
dbug: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[37]
      Reading data from file '/app/key-e34c53dd-64c4-41eb-b909-46697bc5e645.xml'.
dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[18]
      Found key {e34c53dd-64c4-41eb-b909-46697bc5e645}.
dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.DefaultKeyResolver[13]
      Considering key {e34c53dd-64c4-41eb-b909-46697bc5e645} with expiration date 2020-08-21 10:26:43Z as default key.
dbug: Microsoft.AspNetCore.DataProtection.TypeForwardingActivator[0]
      Forwarded activator type request from Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Version=3.1.2.0, Culture=neutral, PublicKeyToken=adb9793829ddae60 to Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Culture=neutral, PublicKeyToken=adb9793829ddae60
dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[11]
      Using managed symmetric algorithm 'System.Security.Cryptography.Aes'.
dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[10]
      Using managed keyed hash algorithm 'System.Security.Cryptography.HMACSHA256'.
dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider[2]
      Using key {e34c53dd-64c4-41eb-b909-46697bc5e645} as the default key.
dbug: Microsoft.AspNetCore.DataProtection.Internal.DataProtectionHostedService[0]
      Key ring with default key {e34c53dd-64c4-41eb-b909-46697bc5e645} was loaded during application startup.
dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[2]
      Failed to locate the development https certificate at '(null)'.
dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[1]
      Unable to locate an appropriate development https certificate.
dbug: Microsoft.AspNetCore.Server.Kestrel[0]
      No listening endpoints were configured. Binding to http://localhost:5000 by default.
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
dbug: Microsoft.AspNetCore.Hosting.Diagnostics[0]
      Loaded hosting startup assembly DeveloperRenewal
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: /app
dbug: Microsoft.Extensions.Hosting.Internal.Host[2]
      Hosting started
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM01S8AH52NV" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM01S8AH52NV" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/  
dbug: Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware[0]
      Wildcard detected, all requests with hosts will be allowed.
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path / does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.HomeController.Index (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.HomeController.Index (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Authorization.DefaultAuthorizationService[2]
      Authorization failed.
info: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[12]
      AuthenticationScheme: Identity.Application was challenged.
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM01S8AH52NV" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 318.3292ms 302 
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM01S8AH52NV" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM01S8AH52NV" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM01S8AH52NV" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM01S8AH52NV" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM01S8AH52O0" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM01S8AH52O0" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ModelBinderFactory[12]
      Registered model binder providers, in the following order: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BinderTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ServicesModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.HeaderModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FloatingPointTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.EnumTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CancellationTokenModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ByteArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormFileModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormCollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.KeyValuePairModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.DictionaryModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ComplexTypeModelBinderProvider
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/AddApplication.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/Index.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/ShowLog.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/Error.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/_Layout.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/_ValidationScriptsPartial.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/User/Index.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/User/Login.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/_ViewImports.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/_ViewStart.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[1]
      View lookup cache miss for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 37.2962ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 384.4308ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 708.3771ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM01S8AH52O0" completed keep alive response.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM01S8AH52O0" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM01S8AH52O0" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM01S8AH52O0" disconnecting.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 803.7479ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM01S8AH52O0" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM01S8AH52O1" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM01S8AH52O1" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[2]
      View lookup cache hit for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 1.5645ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 8.6195ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 11.9117ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM01S8AH52O1" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 22.8899ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM01S8AH52O2" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM01S8AH52O2" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM01S8AH52O1" sending FIN because: "Operation canceled"
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM01S8AH52O2" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM01S8AH52O2" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM01S8AH52O2" disconnecting.
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM01S8AH52O1" disconnecting.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[2]
      View lookup cache hit for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 0.1095ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 1.357ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 12.87ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 13.7749ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM01S8AH52O2" stopped.
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM01S8AH52O1" stopped.
Tratcher commented 4 years ago

@halter73 thoughts?

      Connection id "0HM01S8AH52O1" completed keep alive response.
...
      Connection id "0HM01S8AH52O1" sending FIN because: "Operation canceled"
      Connection id "0HM01S8AH52O1" disconnecting.
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM01S8AH52O1" stopped
halter73 commented 4 years ago

Is there any chance that HttpContext.Abort() was called or a CancellationToken passed to Request.Body.ReadAsync/Response.Body.WriteAsync fired during any of the previous requests on the connection? I would expect some sort of log if that was the case though...

I wonder if the "SocketException (125): Operation canceled" is really a connection reset. If that's the case, it would make sense to classify it as a ConnectionResetException so we don't get the warning logs when we observe it between requests.

j4587698 commented 4 years ago

@halter73 it looks like nginx keep-alive timeout? the Challenge will keep a persistent connection If the user is not logged in? Because it is normal for a certain period of time after startup

BrennanConroy commented 4 years ago

Could you enable timestamps in the app logs: Use TimestampFormat in either your app.settings.json file or in code when setting up the console logger. "TimestampFormat": "[HH:mm:ss] "

j4587698 commented 4 years ago

@BrennanConroy How can I add timestamp in default console log? I try add it in appsettings.json > Logging. But it doesn't seem to work My appsettings.json is

{
  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "Microsoft": "Debug",
      "Microsoft.Hosting.Lifetime": "Debug"
    },
  "TimestampFormat": "[HH:mm:ss]"
  },
  "AllowedHosts": "*",
  "ReturnUrl": "",
  "Authentication": {
    "Microsoft": {
      "ClientId": "xxxx",
      "ClientSecret": "xxxx"
    }
  }
}

console log is 

dbug: Microsoft.Extensions.Hosting.Internal.Host[1]
      Hosting starting
dbug: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[37]
      Reading data from file '/app/key-e34c53dd-64c4-41eb-b909-46697bc5e645.xml'.
dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[18]
      Found key {e34c53dd-64c4-41eb-b909-46697bc5e645}.
dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.DefaultKeyResolver[13]
      Considering key {e34c53dd-64c4-41eb-b909-46697bc5e645} with expiration date 2020-08-21 10:26:43Z as default key.
dbug: Microsoft.AspNetCore.DataProtection.TypeForwardingActivator[0]
      Forwarded activator type request from Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Version=3.1.2.0, Culture=neutral, PublicKeyToken=adb9793829ddae60 to Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Culture=neutral, PublicKeyToken=adb9793829ddae60
dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[11]
      Using managed symmetric algorithm 'System.Security.Cryptography.Aes'.
dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[10]
      Using managed keyed hash algorithm 'System.Security.Cryptography.HMACSHA256'.
dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider[2]
      Using key {e34c53dd-64c4-41eb-b909-46697bc5e645} as the default key.
dbug: Microsoft.AspNetCore.DataProtection.Internal.DataProtectionHostedService[0]
      Key ring with default key {e34c53dd-64c4-41eb-b909-46697bc5e645} was loaded during application startup.
dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[2]
      Failed to locate the development https certificate at '(null)'.
dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[1]
      Unable to locate an appropriate development https certificate.
dbug: Microsoft.AspNetCore.Server.Kestrel[0]
      No listening endpoints were configured. Binding to http://localhost:5000 by default.
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
dbug: Microsoft.AspNetCore.Hosting.Diagnostics[0]
      Loaded hosting startup assembly DeveloperRenewal
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: /app
dbug: Microsoft.Extensions.Hosting.Internal.Host[2]
      Hosting started
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205B" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205B" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware[0]
      Wildcard detected, all requests with hosts will be allowed.
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ModelBinderFactory[12]
      Registered model binder providers, in the following order: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BinderTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ServicesModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.HeaderModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FloatingPointTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.EnumTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CancellationTokenModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ByteArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormFileModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormCollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.KeyValuePairModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.DictionaryModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ComplexTypeModelBinderProvider
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/AddApplication.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/Index.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/ShowLog.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/Error.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/_Layout.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/_ValidationScriptsPartial.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/User/Index.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/User/Login.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/_ViewImports.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/_ViewStart.cshtml'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[1]
      View lookup cache miss for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 35.7571ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 399.9465ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 711.0516ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205B" completed keep alive response.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM04DHQC205B" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04DHQC205B" sending FIN because: "The client closed the connection."
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 1083.4563ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04DHQC205B" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04DHQC205B" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205C" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205C" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/favicon.ico  
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      Sending file. Request path: '/favicon.ico'. Physical path: '/app/wwwroot/favicon.ico'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205C" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 29.7069ms 200 image/x-icon
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM04DHQC205C" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04DHQC205C" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04DHQC205C" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04DHQC205C" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205D" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205D" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[2]
      View lookup cache hit for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 2.3261ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 9.9916ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 12.9116ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205D" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 20.9987ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM04DHQC205D" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04DHQC205D" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04DHQC205D" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04DHQC205D" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205E" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205E" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/favicon.ico  
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      Sending file. Request path: '/favicon.ico'. Physical path: '/app/wwwroot/favicon.ico'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205E" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 3.5415ms 200 image/x-icon
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM04DHQC205E" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04DHQC205E" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04DHQC205E" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04DHQC205E" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205F" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205F" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[2]
      View lookup cache hit for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 0.3577ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 7.3591ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 26.9685ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205F" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 36.7677ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205G" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205G" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[2]
      View lookup cache hit for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 0.2705ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 3.8051ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 5.8477ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205G" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 9.3756ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205H" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205H" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/favicon.ico  
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      Sending file. Request path: '/favicon.ico'. Physical path: '/app/wwwroot/favicon.ico'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205H" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 2.6612ms 200 image/x-icon
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM04DHQC205H" received FIN.
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04DHQC205H" disconnecting.
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04DHQC205H" sending FIN because: "The client closed the connection."
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04DHQC205H" stopped.
dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04DHQC205I" accepted.
dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04DHQC205I" started.
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[2]
      View lookup cache hit for view 'Login' in controller 'User'.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 0.1607ms.
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 2.7861ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 4.1368ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04DHQC205I" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 6.5704ms 200 text/html; charset=utf-8
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04DHQC205I" sending FIN because: "Operation canceled"
dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04DHQC205I" disconnecting.
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04DHQC205I" stopped.
BrennanConroy commented 4 years ago

Sorry, you need to put it in the "Console" section in "Logging":

"Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    },
    "Console": {
      "TimestampFormat": "[HH:mm:ss]"
    }
  }
j4587698 commented 4 years ago

@BrennanConroy new log

[16:57:55]dbug: Microsoft.Extensions.Hosting.Internal.Host[1]
      Hosting starting
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[37]
      Reading data from file '/app/key-e34c53dd-64c4-41eb-b909-46697bc5e645.xml'.
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[18]
      Found key {e34c53dd-64c4-41eb-b909-46697bc5e645}.
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.DefaultKeyResolver[13]
      Considering key {e34c53dd-64c4-41eb-b909-46697bc5e645} with expiration date 2020-08-21 10:26:43Z as default key.
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.TypeForwardingActivator[0]
      Forwarded activator type request from Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Version=3.1.2.0, Culture=neutral, PublicKeyToken=adb9793829ddae60 to Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Culture=neutral, PublicKeyToken=adb9793829ddae60
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[11]
      Using managed symmetric algorithm 'System.Security.Cryptography.Aes'.
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ManagedAuthenticatedEncryptorFactory[10]
      Using managed keyed hash algorithm 'System.Security.Cryptography.HMACSHA256'.
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider[2]
      Using key {e34c53dd-64c4-41eb-b909-46697bc5e645} as the default key.
[16:57:55]dbug: Microsoft.AspNetCore.DataProtection.Internal.DataProtectionHostedService[0]
      Key ring with default key {e34c53dd-64c4-41eb-b909-46697bc5e645} was loaded during application startup.
[16:57:55]dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[2]
      Failed to locate the development https certificate at '(null)'.
[16:57:55]dbug: Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer[1]
      Unable to locate an appropriate development https certificate.
[16:57:55]dbug: Microsoft.AspNetCore.Server.Kestrel[0]
      No listening endpoints were configured. Binding to http://localhost:5000 by default.
[16:57:55]info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
[16:57:55]dbug: Microsoft.AspNetCore.Hosting.Diagnostics[0]
      Loaded hosting startup assembly DeveloperRenewal
[16:57:55]info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
[16:57:55]info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
[16:57:55]info: Microsoft.Hosting.Lifetime[0]
      Content root path: /app
[16:57:55]dbug: Microsoft.Extensions.Hosting.Internal.Host[2]
      Hosting started
[16:58:03]dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04EU7VADGS" accepted.
[16:58:03]dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04EU7VADGS" started.
[16:58:03]info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/  
[16:58:03]dbug: Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware[0]
      Wildcard detected, all requests with hosts will be allowed.
[16:58:03]dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path / does not match a supported file type
[16:58:03]dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/'
[16:58:03]dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.HomeController.Index (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/'
[16:58:03]dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.HomeController.Index (DeveloperRenewal)'
[16:58:03]dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
[16:58:03]info: Microsoft.AspNetCore.Authorization.DefaultAuthorizationService[2]
      Authorization failed.
[16:58:03]info: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[12]
      AuthenticationScheme: Identity.Application was challenged.
[16:58:03]dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04EU7VADGS" completed keep alive response.
[16:58:03]info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 321.6891ms 302 
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM04EU7VADGS" received FIN.
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04EU7VADGS" disconnecting.
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04EU7VADGS" sending FIN because: "The client closed the connection."
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04EU7VADGS" stopped.
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04EU7VADGT" accepted.
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04EU7VADGT" started.
[16:58:04]info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
[16:58:04]dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
[16:58:04]dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
[16:58:04]dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
[16:58:04]dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
[16:58:04]dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
[16:58:04]info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ModelBinderFactory[12]
      Registered model binder providers, in the following order: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BinderTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ServicesModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.HeaderModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FloatingPointTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.EnumTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CancellationTokenModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ByteArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormFileModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormCollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.KeyValuePairModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.DictionaryModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ArrayModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CollectionModelBinderProvider, Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ComplexTypeModelBinderProvider
[16:58:04]info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/AddApplication.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/Index.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Home/ShowLog.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/Error.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/_Layout.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/Shared/_ValidationScriptsPartial.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/User/Index.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/User/Login.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/_ViewImports.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.Compilation.DefaultViewCompiler[3]
      Initializing Razor view compiler with compiled view: '/Views/_ViewStart.cshtml'.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[1]
      View lookup cache miss for view 'Login' in controller 'User'.
[16:58:04]info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
[16:58:04]dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 36.8064ms.
[16:58:04]dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
[16:58:04]dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
[16:58:04]dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
[16:58:04]dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
[16:58:04]info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 367.8688ms.
[16:58:04]info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 686.1159ms
[16:58:04]info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04EU7VADGT" completed keep alive response.
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM04EU7VADGT" received FIN.
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04EU7VADGT" sending FIN because: "The client closed the connection."
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04EU7VADGT" disconnecting.
[16:58:04]info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 783.4225ms 200 text/html; charset=utf-8
[16:58:04]dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04EU7VADGT" stopped.
[16:58:15]dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM04EU7VADGU" accepted.
[16:58:15]dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM04EU7VADGU" started.
[16:58:15]info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/User/Login?ReturnUrl=%2F  
[16:58:15]dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[4]
      The request path /User/Login does not match a supported file type
[16:58:15]dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
      1 candidate(s) found for the request path '/User/Login'
[16:58:15]dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
      Endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)' with route pattern '{controller=Home}/{action=Index}/{id?}' is valid for the request path '/User/Login'
[16:58:15]dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
      Request matched endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
[16:58:15]dbug: Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler[9]
      AuthenticationScheme: Identity.Application was not authenticated.
[16:58:15]info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
[16:58:15]info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Login", controller = "User"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Login(System.String) on controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal).
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of authorization filters (in the following order): None
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of resource filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648), Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of exception filters (in the following order): None
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Execution plan of result filters (in the following order): Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
      Executing controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed controller factory for controller DeveloperRenewal.Controllers.UserController (DeveloperRenewal)
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[22]
      Attempting to bind parameter 'returnUrl' of type 'System.String' ...
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[44]
      Attempting to bind parameter 'returnUrl' of type 'System.String' using the name 'returnUrl' in request data ...
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder[45]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[23]
      Done attempting to bind parameter 'returnUrl' of type 'System.String'.
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[26]
      Attempting to validate the bound parameter 'returnUrl' of type 'System.String' ...
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder[27]
      Done attempting to validate the bound parameter 'returnUrl' of type 'System.String'.
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine[2]
      View lookup cache hit for view 'Login' in controller 'User'.
[16:58:15]info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1]
      Executing ViewResult, running view Login.
[16:58:15]dbug: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[2]
      The view path '/Views/User/Login.cshtml' was found in 1.7642ms.
[16:58:15]dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[100]
      Found the endpoints Route: {controller=Home}/{action=Index}/{id?} for address Microsoft.AspNetCore.Routing.RouteValuesAddress
[16:58:15]dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[102]
      Successfully processed template {controller=Home}/{action=Index}/{id?} for Route: {controller=Home}/{action=Index}/{id?} resulting in /User/Login and ?returnUrl=%2F
[16:58:15]dbug: Microsoft.AspNetCore.Routing.DefaultLinkGenerator[105]
      Link generation succeeded for endpoints Route: {controller=Home}/{action=Index}/{id?} with result /User/Login?returnUrl=%2F
[16:58:15]dbug: Microsoft.AspNetCore.Antiforgery.DefaultAntiforgery[6]
      An antiforgery cookie token was reused.
[16:58:15]info: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4]
      Executed ViewResult - view Login executed in 8.6729ms.
[16:58:15]info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal) in 11.65ms
[16:58:15]info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'DeveloperRenewal.Controllers.UserController.Login (DeveloperRenewal)'
[16:58:15]dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM04EU7VADGU" completed keep alive response.
[16:58:15]info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 19.5352ms 200 text/html; charset=utf-8
[16:58:15]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM04EU7VADGU" sending FIN because: "Operation canceled"
[16:58:15]dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM04EU7VADGU" disconnecting.
[16:58:15]warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Connection processing ended abnormally.
System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
[16:58:15]dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM04EU7VADGU" stopped.
BrennanConroy commented 4 years ago

If you don't use "Microsoft Account external login" does the issue go away?

Do you have a simple repro app as well? We'd love to repro this and try to figure it out.

j4587698 commented 4 years ago

@BrennanConroy this is my test repo. https://github.com/j4587698/DeveloperRenewal

halter73 commented 4 years ago

Thanks. Is there a client script or something that con reproduce the error when run against the test repo? It would be awesome if nginx was configured in the Dockerfile.

j4587698 commented 4 years ago

os is centos dotnet core running in docker. nginx also running in docker. use https://hub.docker.com/_/nginx image. login page refresh about 1 min will throw this excption

OGMods commented 4 years ago

I've encountered the same issue and after some investigation, it turned out that the issue is occurring because of the AspNetCore.Identity.LiteDB library...

I didn't find what's wrong exactly or what is causing it, but switching to another library LiteDB.Identity solved the issue...

j4587698 commented 4 years ago

@OGMods It looks you are right. There is no such error after changing the library.

But also has FIN. I don't know if this is a problem. Some log like

[11:00:32]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM0SK4Q5NJK9" received FIN.
[11:00:32]dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM0SK4Q5NJK9" disconnecting.
[11:00:32]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM0SK4Q5NJK9" sending FIN because: "The client closed the connection."
[11:00:32]dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM0SK4Q5NJK9" stopped.
[11:00:33]dbug: Microsoft.AspNetCore.Server.Kestrel[39]
      Connection id "0HM0SK4Q5NJKA" accepted.
[11:00:33]dbug: Microsoft.AspNetCore.Server.Kestrel[1]
      Connection id "0HM0SK4Q5NJKA" started.
[11:00:33]info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://e5.jvxiang.com/favicon.ico  
[11:00:33]info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      Sending file. Request path: '/favicon.ico'. Physical path: '/app/wwwroot/favicon.ico'
[11:00:33]dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM0SK4Q5NJKA" completed keep alive response.
[11:00:33]info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 1.6072ms 200 image/x-icon
[11:00:33]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM0SK4Q5NJKA" received FIN.
[11:00:33]dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM0SK4Q5NJKA" disconnecting.
[11:00:33]dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM0SK4Q5NJKA" stopped.
[11:00:33]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM0SK4Q5NJKA" sending FIN because: "The Socket transport's send loop completed gracefully."
halter73 commented 4 years ago

Those FINs in the last log look normal. The client gracefully closed 2 idle connections. This would only be a problem if the same client is repeatedly closing and reopening connections when it should be using keep-alive connections.

Usamax80 commented 4 years ago

@OGMods i am having the same issue, but i am not using the https://github.com/fabian-blum/AspNetCore.Identity.LiteDB. image

Usamax80 commented 4 years ago

@halter73 any help would be appreciated.

j4587698 commented 4 years ago

@Usamax80 Do you have a simple repro app? My simple repro may not be able to reproduce your problem.

BrennanConroy commented 4 years ago

What version of AspNetCore are you using?

Usamax80 commented 4 years ago

@BrennanConroy .Net Core 3.1 image

ghost commented 4 years ago

Thanks for contacting us. We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We will evaluate the request when we are planning the work for the next milestone. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

halter73 commented 4 years ago 
dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM01S8AH52O1" sending FIN because: "Operation canceled"

The above is really the peculiar log. It makes it clear that we're disposing the socket because SocketException (125): Operation canceled was thrown from Socket.SendAsync(). We wouldn't log this if we had already shutdown/disposed the socket, and Kestrel's Socket transport uses no other mechanism to cancel ongoing sends or receives. Given that, an exception like this indicating that it was Kestrel that canceled an ongoing operation makes no sense me.

@geoffkizer @scalablecory Do either of you know of any reason why SocketException (125): Operation canceled might be thrown on Linux before Socket.Shutdown() or Socket.Dispose() was called? None of the Send or Receive operations use a CancellationToken.

scalablecory commented 4 years ago

It can also happen if the thread that initiated the I/O is killed.

halter73 commented 4 years ago

So this could happen if an epoll thread dies? Do you know of any likely cause for that?

geoffkizer commented 4 years ago

Do you have a stack trace for the exception?

scalablecory commented 4 years ago

So this could happen if an epoll thread dies? Do you know of any likely cause for that?

This is a Windows behavior. Basically if you start a thread, call SendAsync(), and then kill the thread before that I/O is complete, it will kill the I/O.

I doubt we would have tried to clone this weird behavior for epoll.

halter73 commented 4 years ago

Do you have a stack trace for the exception?

Unfortunately the reported stacktrace is wrong because we store and rethrow the System.Net.Sockets.SocketException (125): Operation canceled without using ExceptionDispatchInfo.Capture(. That's something I plan to fix when I address this issue.

Based on the logs, I'm pretty confident the exception is being thrown from here in Socket.SendAsync() and caught here in Kestrel's SocketConnection, but unfortunately I couldn't tell you what the internal stacktrace is.

halter73 commented 4 years ago

Scratch everything from my last comment! I should have taken a closer look at the exception rather than assume the stack trace was clobbered. Even though I didn't capture the exception using ExceptionDispatchInfo in SocketConnection, I forgot for a second that the Pipe already does this for me.

System.Net.Sockets.SocketException (125): Operation canceled
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.<GetResult>g__ThrowSocketException|7_0(SocketError e)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketAwaitableEventArgs.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessSends()
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.DoSend()
   at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)

The top of the stack trace shows the exception originated from here in Kestrel's managed Socket transport because of a non-Success SocketError. Not sure how helpful that is, but there it is.

harrybotboy commented 4 years ago

I have the same problem in Azure App service on Linux. I am using ASP.NET Core 3.1. When I changed to Azure App service (not on Linux), my system run smoothly. I think the problem was in Linux, it is not compatible with Linux. I don't know why, because before I upgraded some nuget package, my system are still good. I think some nuget are not compatible with Azure App service on Linux now.

ghost commented 4 years ago

Thanks for contacting us. We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We will evaluate the request when we are planning the work for the next milestone. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

halter73 commented 4 years ago

I moved this to our "Next sprint planning" milestone which means this likely won't be fixed for .NET 5. I was considering turning SocketException (125) into a ConnectionResetException which would very likely get rid of the "Connection processing ended abnormally" warning. But rereading the original issue, the problem isn't just log noise. Whatever's happening, it appears to be causing NGINX to respond with 502s.

I'm very confident based on the detail logs that were provided (thanks everyone!) that Kestrel itself didn't close the socket, but that doesn't necessarily mean it was the client that closed the socket. For all I know, this could be caused by a bug in System.Net.Sockets. Given that something is really going wrong as evidenced by NGINX's 502 responses, keeping the "Connection processing ended abnormally" warning seems like a good idea.

If anyone can reproduce this reliably and wants to help us close this issue, getting a Wireshark capture of the broken connection could help us figure out if it's really the client or server initiating the connection close.

mashbrno commented 4 years ago

I would like to add mee too. Exception is the same as in the issue description. But I can exclude NGNIX from the pipe and the problem is still reproducible. It's observable on my Kubernetes cluster even accessing the service directly through NodePort. Same application on IIS behaves well.

The application uses Serilog.Sinks.File and for some requests the Serilog's output which should go to the file has leaked as a response instead of proper JSON response or some error message. Without this sink there are no other "internals" leaking, but SocketException (125) remained. Might be a different issue.

Application is running 3.1.7 runtime inside buster container.

sunliusi commented 4 years ago

Websocket applications migrate from Windows to Linux, and this happens occasionally

dwigand commented 3 years ago

I have the same problem using docker-compose running on Docker Desktop (Windows 10). I'm also using ASP.NET Core 3.1. When I host the app inside a Windows container everything works well. I am experiencing the same issues from within Kestrel but also when querying SqlServer running inside a container.

Is there any known workaround except hosting on windows?

Microsoft.AspNetCore.Server.Kestrel: Debug: Connection id "0HM4LSFNHENL9", Request id "0HM4LSFNHENL9:00000001": started reading request body.
[10:30:08]dbug: Microsoft.AspNetCore.Server.Kestrel[25]
      Connection id "0HM4LSFNHENL9", Request id "0HM4LSFNHENL9:00000001": started reading request body.
[10:30:08]dbug: Microsoft.AspNetCore.Server.Kestrel[26]
      Connection id "0HM4LSFNHENL9", Request id "0HM4LSFNHENL9:00000001": done reading request body.
Microsoft.AspNetCore.Server.Kestrel: Debug: Connection id "0HM4LSFNHENL9", Request id "0HM4LSFNHENL9:00000001": done reading request body.
[10:30:08]info: SoapCore.SoapEndpointMiddleware[0]
      Request for operation IZksRequesterSoapContract.Login received
SoapCore.SoapEndpointMiddleware: Information: Request for operation IZksRequesterSoapContract.Login received

Exception thrown: 'System.Net.Sockets.SocketException' in System.Net.Sockets.dll
Exception thrown: 'System.IO.IOException' in System.Net.Sockets.dll
Exception thrown: 'Microsoft.Data.SqlClient.SqlException' in Microsoft.Data.SqlClient.dll
Exception thrown: 'Microsoft.Data.SqlClient.SqlException' in Microsoft.Data.SqlClient.dll
Exception thrown: 'Microsoft.Data.SqlClient.SqlException' in Microsoft.Data.SqlClient.dll
Exception thrown: 'Microsoft.Data.SqlClient.SqlException' in Microsoft.Data.SqlClient.dll
Exception thrown: 'Microsoft.Data.SqlClient.SqlException' in Microsoft.Data.SqlClient.dll
Exception thrown: 'Microsoft.Data.SqlClient.SqlException' in Powerscript.Base.dll
Microsoft.Data.SqlClient.SqlException (0x80131904): A transport-level error has occurred when sending the request to the server. (provider: TCP Provider, error: 35 - An internal exception was caught)
 ---> System.IO.IOException: Unable to write data to the transport connection: Operation canceled.
 ---> System.Net.Sockets.SocketException (125): Operation canceled
   at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at Microsoft.Data.SqlClient.SNI.SNIPacket.WriteToStream(Stream stream)
   at Microsoft.Data.SqlClient.SNI.SNITCPHandle.Send(SNIPacket packet)
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
   at Microsoft.Data.SqlClient.TdsParserStateObject.ThrowExceptionAndWarning(Boolean callerHasConnectionLock, Boolean asyncClose)
   at Microsoft.Data.SqlClient.TdsParserStateObject.SNIWritePacket(PacketHandle packet, UInt32& sniError, Boolean canAccumulate, Boolean callerHasConnectionLock)
   at Microsoft.Data.SqlClient.TdsParserStateObject.WriteSni(Boolean canAccumulate)
   at Microsoft.Data.SqlClient.TdsParserStateObject.WritePacket(Byte flushMode, Boolean canAccumulate)
   at Microsoft.Data.SqlClient.TdsParserStateObject.ExecuteFlush()
   at Microsoft.Data.SqlClient.TdsParser.TdsExecuteRPC(SqlCommand cmd, _SqlRPC[] rpcArray, Int32 timeout, Boolean inSchema, SqlNotificationRequest notificationRequest, TdsParserStateObject stateObj, Boolean isCommandProc, Boolean sync, TaskCompletionSource`1 completion, Int32 startRpc, Int32 startParam)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   [...]
ClientConnectionId:5cf158f6-e34a-435d-9b94-a926dec13718

[10:30:08]info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'SoapCore'
Microsoft.AspNetCore.Routing.EndpointMiddleware: Information: Executed endpoint 'SoapCore'
Microsoft.AspNetCore.Server.Kestrel: Debug: Connection id "0HM4LSFNHENL9" completed keep alive response.
[10:30:08]dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HM4LSFNHENL9" completed keep alive response.
Microsoft.AspNetCore.Hosting.Diagnostics: Information: Request finished in 290.4583ms 200 text/xml; charset=utf-8
[10:30:08]info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 290.4583ms 200 text/xml; charset=utf-8
[10:30:09]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
      Connection id "0HM4LSFNHENL9" received FIN.
Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets: Debug: Connection id "0HM4LSFNHENL9" received FIN.
Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets: Debug: Connection id "0HM4LSFNHENL9" sending FIN because: "The client closed the connection."
[10:30:09]dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
      Connection id "0HM4LSFNHENL9" sending FIN because: "The client closed the connection."
[10:30:09]dbug: Microsoft.AspNetCore.Server.Kestrel[10]
      Connection id "0HM4LSFNHENL9" disconnecting.
Microsoft.AspNetCore.Server.Kestrel: Debug: Connection id "0HM4LSFNHENL9" disconnecting.
[10:30:09]dbug: Microsoft.AspNetCore.Server.Kestrel[2]
      Connection id "0HM4LSFNHENL9" stopped.
Microsoft.AspNetCore.Server.Kestrel: Debug: Connection id "0HM4LSFNHENL9" stopped.
dwigand commented 3 years ago

I just removed the "aspnetcore"-part and was able to reproduce the SocketException caused by the sql query with a plain console app.

gurolayanlar commented 3 years ago

Hi,

I am following the above topics.

We are at the stage of distributing our application to our customers in the production environment.We need to fix this problem. It is work at normally when tested on IIS. When solve this problem?

Our configration: Redhat 7.7 .Net Core v5.0.100

ayende commented 3 years ago

I'm also seeing this when putting the system under load. This is a Kesterl using HttpClient to hit a remote server (which has abundance of capacity) , but we are getting this randomly.

Any ideas what the root cause / workaround are?

halter73 commented 3 years ago

Can anyone find a reliable way to repro this issue so I can verify what's really causing it? More debug-level logs could also help verify everyone is dealing with the same type of situation.

This is a Kesterl using HttpClient to hit a remote server (which has abundance of capacity) , but we are getting this randomly.

Is the exception coming from Kestrel or HttpClient? Both use System.Net.Sockets under the covers. Same with SqlClient which was mentioned earlier. Logs would help here.

We have to throw something to indicate that the input stream closed ungracefully. However, the "Connection processing ended abnormally" logs can probably be less severe in this case.

My current thinking is that we should turn this into a ConnectionAbortedException instead of a ConnectionResetException like I was suggesting earlier. Unlike a ConnectionResetException it would always be logged even between requests, but only at a debug level. This would probably be more accurate as my current assumption is that something is calling HttpContext.Abort() or cancelling a write to the response body with a CancellationToken.

I don't want to do this if it's really connection resets or, even worse, some bug in framework code causing this.

ayende commented 3 years ago

I can reproduce this given enough load, yes. Not consistently. The exception happens on the client side, and I'm not seeing anything on the server side. I would assume that this is related to the HttpClient, not Kestrel.

The issue is that this looks to be surfacing to my code, causing some errors to happen.

dwigand commented 3 years ago

Some observations that may help:

Variant A: works

Variant B: works

Variant C: works

Variant D: doesn't work

dwigand commented 3 years ago

Variant E: doesn't work

milind009 commented 3 years ago

I'm also observing this issue after a recent change we made to our .net core 3.1 web app using Kestrel which runs on a linux (ubuntu 18.04) docker container. Basically the change we had made involved adding multiple Azure Devops API calls(additional 4 network calls) and we are using the VssConnection class to initialize a new connection before each network call. Could this be causing this issue or there could be another reason? Is there any configuration i can use to avoid this if the failure is indeed due to new instances of VssConnection ?

dwigand commented 3 years ago

Finally we found the issue in our code base: There were some usages of Microsoft.Win32.SafeHandles. We removed them and it works well now.