Skip to content
This repository has been archived by the owner on Dec 18, 2018. It is now read-only.

[1.1.2] Exception "Response Content-Length mismatch" on Azure #1376

Closed
pellea opened this issue Feb 20, 2017 · 64 comments
Closed

[1.1.2] Exception "Response Content-Length mismatch" on Azure #1376

pellea opened this issue Feb 20, 2017 · 64 comments

Comments

@pellea
Copy link

pellea commented Feb 20, 2017

Hello,

After some times, the following warning and error appears in the log file and I have to restart the website. This happens in a production environment on Azure!

Here are the "specs" of the website:

  • it's an ASP.NET Core Web Application
  • csproj version
  • target framework: netcoreapp1.1
  • all the Microsoft.AspNetCore.* packages have the version: 1.1.0

Here is the logs:

info: Microsoft.Extensions.DependencyInjection.DataProtectionServices[0]
      Azure Web Sites environment detected. Using 'D:\home\ASP.NET\DataProtection-Keys' as key repository; keys will not be encrypted at rest.
warn: Microsoft.AspNetCore.Server.Kestrel[0]
      Unable to bind to http://localhost:6074 on the IPv6 loopback interface.
System.AggregateException: One or more errors occurred. (Error -4089 EAFNOSUPPORT address family not supported) ---> Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4089 EAFNOSUPPORT address family not supported
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.Libuv.tcp_bind(UvTcpHandle handle, SockAddr& addr, Int32 flags)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvTcpHandle.Bind(ServerAddress address)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Http.TcpListener.CreateListenSocket()
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Http.Listener.<StartAsync>b__8_0(Object state)
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
   at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at System.Threading.Tasks.Task.Wait()
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelEngine.CreateServer(ServerAddress address)
   at Microsoft.AspNetCore.Server.Kestrel.KestrelServer.Start[TContext](IHttpApplication`1 application)
---> (Inner Exception #0) Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4089 EAFNOSUPPORT address family not supported
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.Libuv.tcp_bind(UvTcpHandle handle, SockAddr& addr, Int32 flags)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvTcpHandle.Bind(ServerAddress address)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Http.TcpListener.CreateListenSocket()
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Http.Listener.<StartAsync>b__8_0(Object state)<---

Hosting environment: Production
Content root path: D:\home\site\wwwroot
Now listening on: http://localhost:6074
Application started. Press Ctrl+C to shut down.
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET http://localhost/  
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch) with arguments ((null)) - ModelState is Valid
info: Microsoft.AspNetCore.Mvc.ViewFeatures.Internal.ViewResultExecutor[1]
      Executing ViewResult, running view at path /Views/Home/Index.cshtml.
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch) in 13267.2954ms
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      Request finished in 13579.3727ms 200 text/html; charset=utf-8
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET http://airxtouch.com/video/AIRxTOUCHBAR.mp4?version=3  
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      Connection id "0HL2N90ELHI3P": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (13688832 of 16307141).

How can I debug solve/debug this?

The warning seems harmless ("Unable to bind to http://localhost:6074 on the IPv6 loopback interface.").

But how is it possible to have this error "System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (13688832 of 16307141)." ?

Thanks,
Adrien.

@davidfowl
Copy link
Member

Request starting HTTP/1.1 GET http://airxtouch.com/video/AIRxTOUCHBAR.mp4?version=3

What does the controller action look like that handles this request?

@pellea
Copy link
Author

pellea commented Feb 20, 2017

It's the aspnetcore-spa template with React/Redux.

@halter73
Copy link
Member

@pellea Thanks for the bug report. You're correct about the IPv6 warning being harmless.

Is this the template you're talking about? Why do you have to restart the website? Does the error keep reoccurring after you see it once?

Is AIRxTOUCHBAR.mp4 being served by the StaticFiles middleware? If so, what does ?version=3 querystring mean? Do you know if 16307141 bytes is really the expected size for that file?

@pellea
Copy link
Author

pellea commented Feb 21, 2017

It's the right template (or here https://github.com/aspnet/JavaScriptServices).

The website is down with a CGI error page. That's why I have to restart it (quickly, it's in prod and we are at a critical moment; the website must be running all the time !).

The error is reoccurring.

Yes the file is served with the static files middleware. The ?version3 is to avoid caching problem when we update the video.

It's not the right size:
Size: 15,6 MB (16.405.445 bytes)
Size on disk: 15,6 MB (16.408.576 bytes)

I didn't have that error before migrating to the .csproj and 1.1.0 version (the "old" version used the package.json and 1.0.1).

@davidfowl
Copy link
Member

1.1.0 verifies the content length matches what was written to the response stream. That's why you're seeing it after upgrading.

@pellea
Copy link
Author

pellea commented Feb 21, 2017

Okay but then what can I do?
Is it an actual bug? Do I need to wait for a fix?

I'm considering removing the video and use a low definition animated GIF but it's still a temporary solution (that's not what we really want).

@davidfowl
Copy link
Member

Can you reproduce it with all files or just that specific file? Can you reproduce it locally as well as in production?

@pellea
Copy link
Author

pellea commented Feb 21, 2017

Yes the error appears after some times in a local environment too.

@cesarblum
Copy link
Contributor

cesarblum commented Feb 21, 2017

Athough it's not the exact same bug as #1289, you can try a similar workaround. Change your UseStaticFiles call to:

app.UseStaticFiles(new StaticFileOptions
{
    OnPrepareResponse = context =>
    {
        context.Context.Response.Headers.Remove("Content-Length");
    }
});

This will cause the response to use Transfer-Encoding: chunked instead of Content-Length. I hope that's not an issue for you. Let us know.

Do you have any custom middleware that's registering OnStarting callbacks?

@halter73
Copy link
Member

The Content-Length error might just be the symptom not the root issue. It's possible that this is fairly common scenario where the client (in this case the IIS ANCM module) disconnects during a download. Normally response write errors are ignored, but the static file middleware goes out of its way to verify that writes succeed and throws otherwise in order to avoid wasting cycles. The logs posted in this issue are what you would see if some other middleware swallowed the exception the static files middleware threw. If this is what's going on, the workaround mentioned above by @CesarBS would clear up the logs, but not really fix any underlying issues.

The CGI error page is unexpected though. More details would be helpful here.

  • Does the CGI error page include any helpful information like an HTTP status code or response body?
  • Are there any logs from IIS/ANCM in eventlog.xml?
  • Do all requests made to any endpoint fail after you see the Content-Length error?
  • How long does it take for the CGI error page to show up after making a request?

Upping the logging verbosity to "Trace" and posting the resulting logs could also help us track down this issue.

@Tratcher
Copy link
Member

Why could a content-length error be logged for an already aborted request?

@halter73
Copy link
Member

halter73 commented Feb 22, 2017

@Tratcher Kestrel doesn't check whether or not the request is aborted before it logs the Content-Length mismatch. That's an oversight that never came up before since most writers ignore errors, and those that don't ignore errors would normally throw from the app func. For this error to be logged in this scenario, both the write would have throw (uncommon) and the exception would have to be swallowed.

So that there is a logging issue that should be fixed, but that doesn't explain the CGI error page or the need to restart the site.

@pellea
Copy link
Author

pellea commented Feb 22, 2017

The video is never requested directly by the user. We use it as a background video on the home page (and it loops).

I have the Cors, Mvc and OpenIdConnectAuthentication middleware.

I enabled more log in Azure. I will not redeploy the web app to activate more log; it takes like 30 minutes to deploy; npm/webpack is super slow on Azure. But I can test whatever you want on my local environment.

Here is my local "full" log with more trace (and the exceptions obviously):

Hosting environment: Development
Content root path: E:\dev\airxtouch\airxtouch
Now listening on: http://0.0.0.0:5002
Application started. Press Ctrl+C to shut down.
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7J3 RequestPath:/
      Request starting HTTP/1.1 GET http://localhost:5002/
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      => RequestId:0HL2R05L4A7J3 RequestPath:/ => iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch)
      Executing action method iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch) with arguments ((null)) - ModelState is Valid
info: Microsoft.AspNetCore.Mvc.ViewFeatures.Internal.ViewResultExecutor[1]
      => RequestId:0HL2R05L4A7J3 RequestPath:/ => iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch)
      Executing ViewResult, running view at path /Views/Home/Index.cshtml.
info: Microsoft.AspNetCore.NodeServices[0]
      => RequestId:0HL2R05L4A7J3 RequestPath:/ => iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch)
      Node will restart because file changed: E:\dev\airxtouch\airxtouch\ClientApp\dist\main-server.js
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      => RequestId:0HL2R05L4A7J3 RequestPath:/ => iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch)
      Executed action iNUI.Web.Airxtouch.Controllers.HomeController.Index (airxtouch) in 4834.655ms
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7J3 RequestPath:/
      Request finished in 5059.7105ms 200 text/html; charset=utf-8
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7J5 RequestPath:/dist/site.css
      Request starting HTTP/1.1 GET http://localhost:5002/dist/site.css?v=MSEpftqBRCAQO3we7UY741cZSgYbb6LG0QvHYMp8t9s
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7J4 RequestPath:/dist/vendor.css
      Request starting HTTP/1.1 GET http://localhost:5002/dist/vendor.css?v=2GDUaJU4xEyOuil_jzZLevYvP37B9C07nV18QF_ChSk
info: Microsoft.AspNetCore.NodeServices[0]
      webpack built ae0a9823412ccc6d07fa in 42086ms
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7J4 RequestPath:/dist/vendor.css
      Sending file. Request path: '/dist/vendor.css'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\dist\vendor.css'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7J4 RequestPath:/dist/vendor.css
      Request finished in 4931.7937ms 200 text/css
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7J5 RequestPath:/dist/site.css
      Request finished in 4938.3374ms 200 text/css; charset=UTF-8
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7J6 RequestPath:/dist/vendor.js
      Request starting HTTP/1.1 GET http://localhost:5002/dist/vendor.js?v=fvgKa8tX-emo3B4-qQzLBmUiNIz5AJoovqi2QRnDF-U
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7J6 RequestPath:/dist/vendor.js
      Sending file. Request path: '/dist/vendor.js'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\dist\vendor.js'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7J7 RequestPath:/dist/main-client.js
      Request starting HTTP/1.1 GET http://localhost:5002/dist/main-client.js?v=c9GBd_5TwSiVrV7FuNGNwU9yiskowmCezkJejFFUkzw
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7J7 RequestPath:/dist/main-client.js
      Request finished in 117.1475ms 200 application/javascript; charset=UTF-8
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7J8 RequestPath:/images/arrow-down.gif
      Request starting HTTP/1.1 GET http://localhost:5002/images/arrow-down.gif
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7J8 RequestPath:/images/arrow-down.gif
      Sending file. Request path: '/images/arrow-down.gif'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\arrow-down.gif'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7J8 RequestPath:/images/arrow-down.gif
      Request finished in 39.6644ms 200 image/gif
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7J9 RequestPath:/images/pattern.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/pattern.png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JA RequestPath:/images/headerBackground.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/headerBackground.png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JB RequestPath:/images/background-gif.gif
      Request starting HTTP/1.1 GET http://localhost:5002/images/background-gif.gif?v=2
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JC RequestPath:/images/menuButton.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/menuButton.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JA RequestPath:/images/headerBackground.png
      Sending file. Request path: '/images/headerBackground.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\headerBackground.png'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7J9 RequestPath:/images/pattern.png
      Sending file. Request path: '/images/pattern.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\pattern.png'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JB RequestPath:/images/background-gif.gif
      Sending file. Request path: '/images/background-gif.gif'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\background-gif.gif'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JC RequestPath:/images/menuButton.svg
      Sending file. Request path: '/images/menuButton.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\menuButton.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JC RequestPath:/images/menuButton.svg
      Request finished in 9.7402ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JA RequestPath:/images/headerBackground.png
      Request finished in 63.0998ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7J9 RequestPath:/images/pattern.png
      Request finished in 115.1715ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JD RequestPath:/images/logo.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/logo.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JD RequestPath:/images/logo.svg
      Sending file. Request path: '/images/logo.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\logo.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JD RequestPath:/images/logo.svg
      Request finished in 52.3066ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JE RequestPath:/images/menuButton-red.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/menuButton-red.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JE RequestPath:/images/menuButton-red.svg
      Sending file. Request path: '/images/menuButton-red.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\menuButton-red.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JE RequestPath:/images/menuButton-red.svg
      Request finished in 6.4702ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JF RequestPath:/images/logo-red.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/logo-red.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JF RequestPath:/images/logo-red.svg
      Sending file. Request path: '/images/logo-red.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\logo-red.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JF RequestPath:/images/logo-red.svg
      Request finished in 13.6883ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JG RequestPath:/images/feather.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/feather.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JG RequestPath:/images/feather.svg
      Sending file. Request path: '/images/feather.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\feather.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JI RequestPath:/images/picto1ms.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/picto1ms.svg
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JH RequestPath:/images/picto247.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/picto247.svg
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JJ RequestPath:/images/pictoglazed.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/pictoglazed.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JH RequestPath:/images/picto247.svg
      Sending file. Request path: '/images/picto247.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\picto247.svg'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JI RequestPath:/images/picto1ms.svg
      Sending file. Request path: '/images/picto1ms.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\picto1ms.svg'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JJ RequestPath:/images/pictoglazed.svg
      Sending file. Request path: '/images/pictoglazed.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\pictoglazed.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JG RequestPath:/images/feather.svg
      Request finished in 47.8488ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JH RequestPath:/images/picto247.svg
      Request finished in 76.4642ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JI RequestPath:/images/picto1ms.svg
      Request finished in 76.4129ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JJ RequestPath:/images/pictoglazed.svg
      Request finished in 83.5427ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JK RequestPath:/images/gloves.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/gloves.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JK RequestPath:/images/gloves.svg
      Sending file. Request path: '/images/gloves.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\gloves.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7J6 RequestPath:/dist/vendor.js
      Request finished in 1324.8266ms 200 application/javascript
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JK RequestPath:/images/gloves.svg
      Request finished in 24.2918ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JL RequestPath:/images/pictoPlugPlay.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/pictoPlugPlay.svg
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JN RequestPath:/images/windows.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/windows.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JN RequestPath:/images/windows.svg
      Sending file. Request path: '/images/windows.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\windows.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JM RequestPath:/images/pictonfc.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/pictonfc.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JL RequestPath:/images/pictoPlugPlay.svg
      Sending file. Request path: '/images/pictoPlugPlay.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\pictoPlugPlay.svg'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JM RequestPath:/images/pictonfc.svg
      Sending file. Request path: '/images/pictonfc.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\pictonfc.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JL RequestPath:/images/pictoPlugPlay.svg
      Request finished in 56.5653ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JM RequestPath:/images/pictonfc.svg
      Request finished in 56.4687ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JN RequestPath:/images/windows.svg
      Request finished in 87.1251ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JO RequestPath:/images/pictopdf.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/pictopdf.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JO RequestPath:/images/pictopdf.png
      Sending file. Request path: '/images/pictopdf.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\pictopdf.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JO RequestPath:/images/pictopdf.png
      Request finished in 45.214ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JP RequestPath:/images/bar.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/bar.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JP RequestPath:/images/bar.png
      Sending file. Request path: '/images/bar.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\bar.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JQ RequestPath:/images/stand.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/stand.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JQ RequestPath:/images/stand.png
      Sending file. Request path: '/images/stand.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\stand.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JR RequestPath:/images/logo-handshake.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/logo-handshake.svg
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JS RequestPath:/images/logo-stand.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/logo-stand.svg
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JS RequestPath:/images/logo-stand.svg
      Sending file. Request path: '/images/logo-stand.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\logo-stand.svg'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JR RequestPath:/images/logo-handshake.svg
      Sending file. Request path: '/images/logo-handshake.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\logo-handshake.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JT RequestPath:/images/logo-digital-signage.svg
      Request starting HTTP/1.1 GET http://localhost:5002/images/logo-digital-signage.svg
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JS RequestPath:/images/logo-stand.svg
      Request finished in 28.8237ms 200 image/svg+xml
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JT RequestPath:/images/logo-digital-signage.svg
      Sending file. Request path: '/images/logo-digital-signage.svg'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\logo-digital-signage.svg'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JR RequestPath:/images/logo-handshake.svg
      Request finished in 32.0359ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JU RequestPath:/images/samsung-logo.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/samsung-logo.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JU RequestPath:/images/samsung-logo.png
      Sending file. Request path: '/images/samsung-logo.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\samsung-logo.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7JV RequestPath:/images/microsoft-logo.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/microsoft-logo.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7JV RequestPath:/images/microsoft-logo.png
      Sending file. Request path: '/images/microsoft-logo.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\microsoft-logo.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JT RequestPath:/images/logo-digital-signage.svg
      Request finished in 34.2718ms 200 image/svg+xml
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JQ RequestPath:/images/stand.png
      Request finished in 66.3979ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K0 RequestPath:/images/share-facebook.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/share-facebook.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K0 RequestPath:/images/share-facebook.png
      Sending file. Request path: '/images/share-facebook.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\share-facebook.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K1 RequestPath:/images/share-twitter.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/share-twitter.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K1 RequestPath:/images/share-twitter.png
      Sending file. Request path: '/images/share-twitter.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\share-twitter.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K0 RequestPath:/images/share-facebook.png
      Request finished in 17.6975ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K1 RequestPath:/images/share-twitter.png
      Request finished in 6.8302ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K2 RequestPath:/images/blog.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/blog.png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JU RequestPath:/images/samsung-logo.png
      Request finished in 60.4328ms 200 image/png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K2 RequestPath:/images/blog.png
      Sending file. Request path: '/images/blog.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\blog.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K3 RequestPath:/images/share-mail.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/share-mail.png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K2 RequestPath:/images/blog.png
      Request finished in 7.814ms 200 image/png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K3 RequestPath:/images/share-mail.png
      Sending file. Request path: '/images/share-mail.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\share-mail.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K3 RequestPath:/images/share-mail.png
      Request finished in 16.5484ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JV RequestPath:/images/microsoft-logo.png
      Request finished in 72.5268ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JP RequestPath:/images/bar.png
      Request finished in 134.7174ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K4 RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K5 RequestPath:/images/image247.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/image247.png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K6 RequestPath:/images/image1ms.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/image1ms.png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K7 RequestPath:/images/imageglazed.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/imageglazed.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K5 RequestPath:/images/image247.png
      Sending file. Request path: '/images/image247.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\image247.png'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K6 RequestPath:/images/image1ms.png
      Sending file. Request path: '/images/image1ms.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\image1ms.png'
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K7 RequestPath:/images/imageglazed.png
      Sending file. Request path: '/images/imageglazed.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\imageglazed.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K8 RequestPath:/images/imageGlove.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/imageGlove.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K8 RequestPath:/images/imageGlove.png
      Sending file. Request path: '/images/imageGlove.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\imageGlove.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K5 RequestPath:/images/image247.png
      Request finished in 379.1294ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K8 RequestPath:/images/imageGlove.png
      Request finished in 62.806ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7K9 RequestPath:/images/imagePlugAndPlay.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/imagePlugAndPlay.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7K9 RequestPath:/images/imagePlugAndPlay.png
      Sending file. Request path: '/images/imagePlugAndPlay.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\imagePlugAndPlay.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K9 RequestPath:/images/imagePlugAndPlay.png
      Request finished in 6.1924ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K6 RequestPath:/images/image1ms.png
      Request finished in 488.1899ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KA RequestPath:/images/imagenfc.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/imagenfc.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7KA RequestPath:/images/imagenfc.png
      Sending file. Request path: '/images/imagenfc.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\imagenfc.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KB RequestPath:/images/imageWindows.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/imageWindows.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7KB RequestPath:/images/imageWindows.png
      Sending file. Request path: '/images/imageWindows.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\imageWindows.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K7 RequestPath:/images/imageglazed.png
      Request finished in 526.5939ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KA RequestPath:/images/imagenfc.png
      Request finished in 71.1439ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KB RequestPath:/images/imageWindows.png
      Request finished in 71.2058ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KC RequestPath:/images/airxtouchbar.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/airxtouchbar.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7KC RequestPath:/images/airxtouchbar.png
      Sending file. Request path: '/images/airxtouchbar.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\airxtouchbar.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7JB RequestPath:/images/background-gif.gif
      Request finished in 2616.9985ms 200 image/gif
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KC RequestPath:/images/airxtouchbar.png
      Request finished in 586.8393ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KD RequestPath:/images/background.png
      Request starting HTTP/1.1 GET http://localhost:5002/images/background.png
info: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[2]
      => RequestId:0HL2R05L4A7KD RequestPath:/images/background.png
      Sending file. Request path: '/images/background.png'. Physical path: 'E:\dev\airxtouch\airxtouch\wwwroot\images\background.png'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KD RequestPath:/images/background.png
      Request finished in 149.6403ms 200 image/png
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7K4 RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 49896.6605ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KE RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GD9P" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GD9P" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KE RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GD9P": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (15679488 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KE RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 47080.2055ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KF RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GD9T" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KF RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GD9T": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (13897728 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KF RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 37001.9919ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KG RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GD9V" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GD9V" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KG RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GD9V": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (11493376 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KG RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 26976.3726ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KH RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GDA1" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KH RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GDA1": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (11436032 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KH RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 27027.8156ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KI RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GDA3" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GDA3" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KI RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GDA3": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (11780096 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KI RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 26992.1368ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KJ RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GDA5" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KJ RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GDA5": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (9228288 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KJ RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 32066.2131ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KK RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GDA7" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KK RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GDA7": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (9261056 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KK RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 16193.806ms 206 video/mp4
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HL2R05L4A7KL RequestPath:/video/AIRxTOUCHBAR.mp4
      Request starting HTTP/1.1 GET http://localhost:5002/video/AIRxTOUCHBAR.mp4?version=3
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GDA9" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
info: Microsoft.AspNetCore.Server.Kestrel[14]
      Connection id "0HL2R05L3GDA9" communication error.
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -4081 ECANCELED operation canceled
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      => RequestId:0HL2R05L4A7KL RequestPath:/video/AIRxTOUCHBAR.mp4
      Connection id "0HL2R05L3GDA9": An unhandled exception was thrown by the application.
System.InvalidOperationException: Response Content-Length mismatch: too few bytes written (10403840 of 16307141).
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HL2R05L4A7KL RequestPath:/video/AIRxTOUCHBAR.mp4
      Request finished in 16221.4864ms 206 video/mp4

@pellea
Copy link
Author

pellea commented Feb 22, 2017

image

If I take a look a Chrome dev tool; each time the video loops, I get another size ... Why?

@halter73
Copy link
Member

The StaticFiles middleware is using the HTTP range feature. The 206 status code indicates a partial response.

@cesarblum
Copy link
Contributor

@halter73 Good point on checking that the request was aborted. I've filed #1387 to track that.

@pellea
Copy link
Author

pellea commented Feb 23, 2017

I forgot to copy the CGI error page:
2017-02-17 15_57_17-iis detailed error - 502 3 - bad gateway and 2 more pages - microsoft edge

@pellea
Copy link
Author

pellea commented Feb 24, 2017

I got again the error today:

The specified CGI application encountered an error and the server terminated the process.

@halter73
Copy link
Member

@pellea I still don't think we have enough information to reproduce the issue. Here are some questions I still have:

  • Are there any logs from IIS/ANCM in eventlog.xml? You should be able to find this next to the stdout logs you already posted.
  • Do all requests made to any endpoint fail after you see the Content-Length error/502.3?
  • How long does it take for the CGI error page to show up after making a request?

If you could capture a memory dump of the failing "dotnet" (not w3wp) process before restarting that could prove instrumental in tracking down why the server is commingle completely unresponsive assuming that's the case.

Upping the logging verbosity to "Trace" and posting the resulting logs could help. You posted more detailed local logs, but those only included "Info" level logs and above which are less verbose. Publishing a sample application that you know also fails in this way on GitHub might also help.

@pellea
Copy link
Author

pellea commented Feb 25, 2017

I have created a sample that crashes exactly like my other website.
Repo: https://github.com/pellea/KestrelVideoBug

I use Chrome as my browser BTW.

@pellea
Copy link
Author

pellea commented Feb 28, 2017

@halter73 Were you able to reproduce the error in your environment?

As soon as the server (on Azure) crash again, I'll get diagnostics logs using the Azure support tools.

@halter73
Copy link
Member

I wasn't able to reproduce locally when directly loading the page from Kestrel or through IIS. I'll try deploying as an Azure Web App. Since I don't have real traffic going to the sample app, I just tried loading it a few times with Chrome.

Do you have any idea how many requests it usually takes to repro? Can you repro it quickly with some automated client?

@pellea
Copy link
Author

pellea commented Feb 28, 2017

You don't have to make a lot of request. Let the page opened, wait a few minutes for the video to play itself more than once and you'll get the error.

To reproduce the error I simply start the website using "dotnet run"; open Chrome; navigate to localhost:5000 and wait a few minutes.

@halter73
Copy link
Member

halter73 commented Mar 1, 2017

@pellea I am now able to reproduce the "Response Content-Length mismatch: too few bytes written" logs, but except for the annoying log messages, I don't see any other harmful affects. As mentioned above, I agree we shouldn't log this when the client has already aborted the request, but you claimed "I have to restart the website." This makes no sense to me. Despite these logs, the website remains completely responsive.

So to reiterate my previous questions:

  • Do all requests made to any endpoint fail after you see the Content-Length error/502.3?
  • How long does it take for the CGI error page to show up after making a request?
  • Are there any logs from IIS/ANCM in eventlog.xml? You should be able to find this in the D:\home\LogFiles folder on Azure Web Apps.

@pellea
Copy link
Author

pellea commented Mar 1, 2017

Yes the website seems responsive (with no video playing). I know that this is not the root of the problem that make the server unresponsive.

  • Request doesn't fail after the error.
  • Immediately after the error appeared, I think it takes 60 sec. When Azure notify me (after 30 minutes - 1 hours) the CGI error show up instantly.

Here is the log of eventlog.xml:

<Event>
<System>
<Provider Name="IIS AspNetCore Module"/>
<EventID>1001</EventID>
<Level>0</Level>
<Task>0</Task>
<Keywords>Keywords</Keywords>
<TimeCreated SystemTime="2017-02-24T11:10:21Z"/>
<EventRecordID>41805109</EventRecordID>
<Channel>Application</Channel>
<Computer>RD0003FF43194E</Computer>
<Security/>
</System>
<EventData>
<Data>Application 'MACHINE/WEBROOT/APPHOST/INUISTORE-SITE' started process '4232' successfully and is listening on port '32069'.</Data>
</EventData>
</Event>
<Event>
<System>
<Provider Name="IIS AspNetCore Module"/>
<EventID>1005</EventID>
<Level>0</Level>
<Task>0</Task>
<Keywords>Keywords</Keywords>
<TimeCreated SystemTime="2017-02-24T18:04:19Z"/>
<EventRecordID>66643640</EventRecordID>
<Channel>Application</Channel>
<Computer>RD0003FF43194E</Computer>
<Security/>
</System>
<EventData>
<Data>Failed to gracefully shutdown process '4232'.</Data>
</EventData>
</Event>
<Event>
<System>
<Provider Name="IIS AspNetCore Module"/>
<EventID>1001</EventID>
<Level>0</Level>
<Task>0</Task>
<Keywords>Keywords</Keywords>
<TimeCreated SystemTime="2017-02-24T18:04:55Z"/>
<EventRecordID>66679265</EventRecordID>
<Channel>Application</Channel>
<Computer>RD0003FF43194E</Computer>
<Security/>
</System>
<EventData>
<Data>Application 'MACHINE/WEBROOT/APPHOST/INUISTORE-SITE' started process '6668' successfully and is listening on port '14999'.</Data>
</EventData>
</Event>
<Event>
<System>
<Provider Name="IIS AspNetCore Module"/>
<EventID>1001</EventID>
<Level>0</Level>
<Task>0</Task>
<Keywords>Keywords</Keywords>
<TimeCreated SystemTime="2017-02-24T18:52:22Z"/>
<EventRecordID>69525890</EventRecordID>
<Channel>Application</Channel>
<Computer>RD0003FF43194E</Computer>
<Security/>
</System>
<EventData>
<Data>Application 'MACHINE/WEBROOT/APPHOST/INUISTORE-SITE' started process '11912' successfully and is listening on port '24316'.</Data>
</EventData>
</Event>
</Events>

@cesarblum
Copy link
Contributor

cesarblum commented Mar 3, 2017

@pellea Sorry, I'd like some clarification.

Immediately after the error appeared, I think it takes 60 sec. When Azure notify me (after 30 minutes - 1 hours) the CGI error show up instantly.

Are you saying that about 60 seconds after seeing the "too few bytes written" log message, the website becomes unresponsive and starts responding with the 502.3 error page to new requests? Do you see the error page on any request to any path?

@pellea
Copy link
Author

pellea commented Mar 3, 2017

No, not after seeing "too few bytes written" log message. I see this log entry a lot before the website is completely unresponsive. When the website is unesponsive it takes 60 seconds for Chrome/Firefox to display the CGI error page and after a while the page is displayed instantly.

@pellea
Copy link
Author

pellea commented Mar 3, 2017

I got the error today. It took more than 1 minute to get an error page ...

Is there a fix for the initial issue "Response Content-Length mismatch"?

Here is a screenshot of the "unresponsive" website:

image

@cesarblum
Copy link
Contributor

I see. There are two separate issues here then.

Unfortunately it's too late to ship a fix for the content length mismatch messages in the upcoming patch release. We'll consider including that in the next patch after that. cc @Eilon

The unresponsiveness needs further investigation. You could be running into #1278, which will be fixed in 1.1.1. A workaround some people have been using is to serve static files from a separate IIS instance, since the issue arises from the fact the StaticFiles middleware passes HttpContext.RequestAborted to Response.WriteAsync and that's where the deadlock comes from. I recommend you update Kestrel to 1.1.1 once that is released, and check if you still run into the same issue.

@cesarblum
Copy link
Contributor

Merged: 14aa07d

@Eilon
Copy link
Member

Eilon commented Apr 19, 2017

Preview builds of this patch fix should be available on the following feeds:

If you have a chance, please try out these preview builds and let us know if you have any feedback!

@clement911
Copy link

Thanks for the update. I'll have to wait for the 1.1.2 release to test...

@mxa0079
Copy link

mxa0079 commented Apr 28, 2017

Could anyone please provide guidance or a link on how to use the pre-release/public patches packages in our projects? We tried adding the preview feed to our nuget configuration and referencing the patch packages but the project is not downloading the correct version.

Example:

When we reference “1.0.5-rtm-201704200225” -> it downloads -> Microsoft.NETCore.App 1.1.0-preview1-001100-00

When we restore with the debug flag enabled we can see that the pre-release feed is being used:

Feeds used:
    https://dotnet.myget.org/F/aspnet-1-0-5-may2017-patch-public/api/v3/index.json
    https://dotnet.myget.org/F/aspnetcore-ci-dev/api/v3/index.json
    https://api.nuget.org/v3/index.json

@muratg
Copy link
Contributor

muratg commented Apr 28, 2017

@mxa0079 Why are you referencing aspnetcore-ci-dev feed in your nuget.config? Please remove that, clear your local caches, and retry.

@mxa0079
Copy link

mxa0079 commented Apr 28, 2017

@muratg we need that feed for another package we are using (signalR for .net core). We will clear the cache and try again

@muratg
Copy link
Contributor

muratg commented Apr 28, 2017

@mxa0079 Sounds good. One workaround would be, putting all the SignalR packages into a local folder, and adding that folder as a feed to your nuget.config for testing. This way, you'd only rely on nuget.org + this patch's myget feed for restore time.

Also please keep in mind that SignalR (Core) is not RTM yet.

@davidfowl
Copy link
Member

Nope,you can't use SignalR with ASP.NET Core 1.x it requires 2.0

@mxa0079
Copy link

mxa0079 commented Apr 28, 2017

@davidfowl We are using it and our internal tests have proven successful. However, we have yet to test it at a large scale - the funtionality that relies on it is hidden behind a feature switch - but we are about to turn it on. 😱 -- any heads up?

@mxa0079
Copy link

mxa0079 commented Apr 28, 2017

@muratg Local folder is not an option because our CI and CD process will not work like that (unless we check in the package, which I'de like to avoid). We just tried the restore the project using the exact version match notation (surrounding the version number by brackets) and got the following message:

Unable to resolve 'Microsoft.NETCore.App (= 1.0.5-rtm-201704200225)' for '.NETCoreApp,Version=v1.0'

Could you get your hands on a project.json file that is successfully restoring the patched version of the package?

Thanks!

@davidfowl
Copy link
Member

davidfowl commented Apr 28, 2017

@mxa0079 what version of SignalR are you using? What's the package id?

@mxa0079
Copy link

mxa0079 commented Apr 28, 2017

@davidfowl

"Microsoft.AspNetCore.SignalR.Server": "0.2.0-preview2-22683",
"Microsoft.AspNetCore.WebSockets": "0.2.0-*"

@davidfowl
Copy link
Member

Eek, those are deprecated ones.

@mxa0079
Copy link

mxa0079 commented Apr 28, 2017

@davidfowl 😭

@pellea
Copy link
Author

pellea commented May 2, 2017

Do you have an ETA for the 1.1.2 release? Is it around the 10 may like the corefx? There are no due dates available on this repo. Thanks.

@Eilon
Copy link
Member

Eilon commented May 2, 2017

@pellea - yeah should be in about a week or so. Very soon!

@AlisherSharopov
Copy link

Hi, I could not fix this error in the YII2 framework, what should be done.
Content-Length mismatch, received 173235 bytes out of the expected 1695210
http://packagist.org could not be fully loaded, package information was loaded from the local cache and may be out of date

@AlisherSharopov
Copy link

Especially that mistake:
Your requirements could not be resolved to an installable set of packages.

Problem 1
- yiisoft/yii2-jui 2.0.7 requires bower-asset/jquery-ui ~1.12.1 -> no matching package found.
- yiisoft/yii2-jui 2.0.6 requires bower-asset/jquery-ui 1.11.@stable -> no matching package found.
- yiisoft/yii2-jui 2.0.5 requires bower-asset/jquery-ui 1.11.
@stable -> no matching package found.
- yiisoft/yii2-jui 2.0.4 requires bower-asset/jquery-ui 1.11.@stable -> no matching package found.
- yiisoft/yii2-jui 2.0.3 requires bower-asset/jquery-ui 1.11.
@stable -> no matching package found.
- yiisoft/yii2-jui 2.0.2 requires bower-asset/jquery-ui 1.11.@stable -> no matching package found.
- yiisoft/yii2-jui 2.0.1 requires bower-asset/jquery-ui 1.11.
@stable -> no matching package found.
- yiisoft/yii2-jui 2.0.0 requires bower-asset/jquery-ui 1.11.*@stable -> no matching package found.
- Installation request for yiisoft/yii2-jui ^2.0 -> satisfiable by yiisoft/yii2-jui[2.0.0, 2.0.1, 2.0.2, 2.0.3, 2.0.4, 2.0.5, 2.0.6, 2.0.7].

Potential causes:

Read https://getcomposer.org/doc/articles/troubleshooting.md for further common problems.

Installation failed, reverting ./composer.json to its original content.

@AlisherSharopov
Copy link

When I have done this in the Console:

composer require --prefer-dist yiisoft/yii2-jui

@Tratcher
Copy link
Member

@AlisherSharopov this is a closed issue. Please open a new issue that covers your specific scenario.

@AlisherSharopov
Copy link

Who will be can fix this error?

@AlisherSharopov
Copy link

Well, I'm organizing now

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

10 participants