Nodejs Web App on Azure

Question

2020-12-18T17:39:06.652323823Z [41m [30mfail [39m [22m [49m: Middleware[0]
2020-12-18T17:39:06.652355023Z Failed to forward request to application. Encountered a System.Net.Http.HttpRequestException exception after 30585.959ms with message: An error occurred while sending the request.. Check application logs to verify the application is properly handling HTTP traffic.

Have tried to debug my application but havent been able to pin down the exact reason. What maybe causing this error for a nodejs webapp?

Answer

I resolved the issue by removing the 'Poetry run'. The container was running fine on the local machine but was only failing in the web app. I was using FastAPI with Poetry for managing Python dependencies. It seems like the Azure Web app has issues with 'Poetry run'.

This was the issue in my Docker

CMD ["poetry", "run", "python", "serve.py"]

I resolved the issue by exporting the dependencies to a requirements.txt file and performing a global pip install. I then ran the following commands to make it work


CMD ["python", "serve.py"]

Answer

Just an FYI, I found this which might be related: https://stackoverflow.com/questions/56300156/query-headers-too-large-on-azure-if-auth-enabled. I have updated my package.json file with the following in the scripts section and so far, so good:

"scripts": {
    "start": "node --max-http-header-size=16384"
  }

Answer

Had the same issue; added the Ip to CORS to see if that elevates that issue.

Answer

Has there been any resolutions found for this issue.

I've been experiencing this issue for months now, throwing "Failed to forward request to http://xxx.xxx.xxx.xxx:8000. Encountered a System.Net.Http.HttpRequestException exception after 42045.407ms with message: An error occurred while sending the request.. Check application logs to verify the application is properly handling HTTP traffic."

For us, this occurs roughly once a way, but as we add more services to this app service, it is now starting to show more frequent.

App service is python 3.9, running a FastAPI app.

I've enabled logging against the app itself, and when this error occurs, there is no attempt against the API itself. The communication is lost between the docker layer and the app itself.

Answer

I am having the same problem on a Linux Web App on Azure, that is running PHP 8.
The application seem to run well, but these error worry us a bit.

Starting Live Log Stream ---  
2022-08-09T13:08:38.592233981Z: [ERROR]  127.0.0.1 -  09/Aug/2022:13:08:33 +0000 "GET /index.php" 302  
  
2022-08-09T13:09:43.687377248Z: [INFO]  fail: Middleware[0]  
  
2022-08-09T13:09:43.688504071Z: [INFO]        Failed to forward request to http://169.254.129.4:8080. Encountered a System.IO.IOException exception after 70253.455ms with message: The response ended prematurely.. Check application logs to verify the application is properly handling HTTP traffic.  
  
2022-08-09T13:09:43.734692421Z: [INFO]  fail: Microsoft.AspNetCore.Server.Kestrel[13]  
  
2022-08-09T13:09:43.734750322Z: [INFO]        Connection id "0HMJQ101V7MO3", Request id "0HMJQ101V7MO3:00000002": An unhandled exception was thrown by the application.  
  
2022-08-09T13:09:43.735841144Z: [INFO]  System.InvalidOperationException: StatusCode cannot be set because the response has already started.  
  
2022-08-09T13:09:43.735857745Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ThrowResponseAlreadyStartedException(String value)  
  
2022-08-09T13:09:43.736564059Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.set_StatusCode(Int32 value)  
  
2022-08-09T13:09:43.736581860Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.Microsoft.AspNetCore.Http.Features.IHttpResponseFeature.set_StatusCode(Int32 value)  
  
2022-08-09T13:09:43.736587560Z: [INFO]     at Microsoft.AspNetCore.Http.DefaultHttpResponse.set_StatusCode(Int32 value)  
  
2022-08-09T13:09:43.736592260Z: [INFO]     at Microsoft.Azure.AppService.Middleware.Forwarding.RequestForwarder.OnRequest(HttpContext context) in /EasyAuth/Middleware.Forwarding/RequestForwarder.cs:line 90  
  
2022-08-09T13:09:43.736840865Z: [INFO]     at Microsoft.Azure.AppService.Middleware.NetCore.AppServiceMiddleware.InvokeAsync(HttpContext context) in /EasyAuth/Microsoft.Azure.AppService.Middleware.NetCore/AppServiceMiddleware.cs:line 140  
  
2022-08-09T13:09:43.738523100Z: [INFO]     at Microsoft.Azure.AppService.MiddlewareShim.AutoHealing.AutoHealingMiddleware.Invoke(HttpContext context) in /EasyAuth/Middleware.Host/AutoHealing/AutoHealingMiddleware.cs:line 55  
  
2022-08-09T13:09:43.738557500Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)  
  
2022-08-09T13:09:47.671874675Z: [ERROR]  127.0.0.1 -  09/Aug/2022:13:09:46 +0000 "GET /index.php" 200  
  
2022-08-09T13:10:08.974435654Z: [ERROR]  127.0.0.1 -  09/Aug/2022:13:10:08 +0000 "GET /index.php" 302  
  
2022-08-09T13:10:15.040348709Z: [ERROR]  127.0.0.1 -  09/Aug/2022:13:10:14 +0000 "HEAD /index.php" 302  
  
2022-08-09T13:10:16.359477056Z: [ERROR]  127.0.0.1 -  09/Aug/2022:13:10:16 +0000 "GET /index.php" 302  
  
2022-08-09T13:10:27.838754089Z: [ERROR]  127.0.0.1 -  09/Aug/2022:13:10:27 +0000 "GET /index.php" 302  
  
2022-08-09T13:10:41.709107871Z: [ERROR]  127.0.0.1 -  09/Aug/2022:13:10:41 +0000 "GET /index.php" 302  
  
2022-08-09T13:11:14.073137089Z: [INFO]  fail: Middleware[0]  
  
2022-08-09T13:11:14.074202512Z: [INFO]        Failed to forward request to http://169.254.129.4:8080. Encountered a System.IO.IOException exception after 65317.273ms with message: The response ended prematurely.. Check application logs to verify the application is properly handling HTTP traffic.  
  
2022-08-09T13:11:14.075365237Z: [INFO]  fail: Microsoft.AspNetCore.Server.Kestrel[13]  
  
2022-08-09T13:11:14.075398537Z: [INFO]        Connection id "0HMJQ101V7MO5", Request id "0HMJQ101V7MO5:00000001": An unhandled exception was thrown by the application.  
  
2022-08-09T13:11:14.075405337Z: [INFO]  System.InvalidOperationException: StatusCode cannot be set because the response has already started.  
  
2022-08-09T13:11:14.075421838Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ThrowResponseAlreadyStartedException(String value)  
  
2022-08-09T13:11:14.075426238Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:14.075430538Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.Microsoft.AspNetCore.Http.Features.IHttpResponseFeature.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:14.075435138Z: [INFO]     at Microsoft.AspNetCore.Http.DefaultHttpResponse.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:14.075439238Z: [INFO]     at Microsoft.Azure.AppService.Middleware.Forwarding.RequestForwarder.OnRequest(HttpContext context) in /EasyAuth/Middleware.Forwarding/RequestForwarder.cs:line 90  
  
2022-08-09T13:11:14.075443438Z: [INFO]     at Microsoft.Azure.AppService.Middleware.NetCore.AppServiceMiddleware.InvokeAsync(HttpContext context) in /EasyAuth/Microsoft.Azure.AppService.Middleware.NetCore/AppServiceMiddleware.cs:line 140  
  
2022-08-09T13:11:14.075447738Z: [INFO]     at Microsoft.Azure.AppService.MiddlewareShim.AutoHealing.AutoHealingMiddleware.Invoke(HttpContext context) in /EasyAuth/Middleware.Host/AutoHealing/AutoHealingMiddleware.cs:line 55  
  
2022-08-09T13:11:14.075451938Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)  
  
2022-08-09T13:11:21.382398561Z: [INFO]  fail: Middleware[0]  
  
2022-08-09T13:11:21.383315481Z: [INFO]        Failed to forward request to http://169.254.129.4:8080. Encountered a System.IO.IOException exception after 65250.654ms with message: The response ended prematurely.. Check application logs to verify the application is properly handling HTTP traffic.  
  
2022-08-09T13:11:21.409675240Z: [INFO]  fail: Microsoft.AspNetCore.Server.Kestrel[13]  
  
2022-08-09T13:11:21.409706141Z: [INFO]        Connection id "0HMJQ101V7MO7", Request id "0HMJQ101V7MO7:00000003": An unhandled exception was thrown by the application.  
  
2022-08-09T13:11:21.411322575Z: [INFO]  System.InvalidOperationException: StatusCode cannot be set because the response has already started.  
  
2022-08-09T13:11:21.411342975Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ThrowResponseAlreadyStartedException(String value)  
  
2022-08-09T13:11:21.411405277Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:21.411413577Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.Microsoft.AspNetCore.Http.Features.IHttpResponseFeature.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:21.411418577Z: [INFO]     at Microsoft.AspNetCore.Http.DefaultHttpResponse.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:21.414006432Z: [INFO]     at Microsoft.Azure.AppService.Middleware.Forwarding.RequestForwarder.OnRequest(HttpContext context) in /EasyAuth/Middleware.Forwarding/RequestForwarder.cs:line 90  
  
2022-08-09T13:11:21.414050433Z: [INFO]     at Microsoft.Azure.AppService.Middleware.NetCore.AppServiceMiddleware.InvokeAsync(HttpContext context) in /EasyAuth/Microsoft.Azure.AppService.Middleware.NetCore/AppServiceMiddleware.cs:line 140  
  
2022-08-09T13:11:21.414058133Z: [INFO]     at Microsoft.Azure.AppService.MiddlewareShim.AutoHealing.AutoHealingMiddleware.Invoke(HttpContext context) in /EasyAuth/Middleware.Host/AutoHealing/AutoHealingMiddleware.cs:line 55  
  
2022-08-09T13:11:21.414062533Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)  
  
2022-08-09T13:11:32.899838400Z: [INFO]  fail: Middleware[0]  
  
2022-08-09T13:11:32.900839428Z: [INFO]        Failed to forward request to http://169.254.129.4:8080. Encountered a System.IO.IOException exception after 65141.117ms with message: The response ended prematurely.. Check application logs to verify the application is properly handling HTTP traffic.  
  
2022-08-09T13:11:32.909000356Z: [INFO]  fail: Microsoft.AspNetCore.Server.Kestrel[13]  
  
2022-08-09T13:11:32.909052758Z: [INFO]        Connection id "0HMJQ101V7MO8", Request id "0HMJQ101V7MO8:00000002": An unhandled exception was thrown by the application.  
  
2022-08-09T13:11:32.910280192Z: [INFO]  System.InvalidOperationException: StatusCode cannot be set because the response has already started.  
  
2022-08-09T13:11:32.910308493Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ThrowResponseAlreadyStartedException(String value)  
  
2022-08-09T13:11:32.910314793Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:32.910318993Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.Microsoft.AspNetCore.Http.Features.IHttpResponseFeature.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:32.910322993Z: [INFO]     at Microsoft.AspNetCore.Http.DefaultHttpResponse.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:32.912468353Z: [INFO]     at Microsoft.Azure.AppService.Middleware.Forwarding.RequestForwarder.OnRequest(HttpContext context) in /EasyAuth/Middleware.Forwarding/RequestForwarder.cs:line 90  
  
2022-08-09T13:11:32.912486254Z: [INFO]     at Microsoft.Azure.AppService.Middleware.NetCore.AppServiceMiddleware.InvokeAsync(HttpContext context) in /EasyAuth/Microsoft.Azure.AppService.Middleware.NetCore/AppServiceMiddleware.cs:line 140  
  
2022-08-09T13:11:32.912491654Z: [INFO]     at Microsoft.Azure.AppService.MiddlewareShim.AutoHealing.AutoHealingMiddleware.Invoke(HttpContext context) in /EasyAuth/Middleware.Host/AutoHealing/AutoHealingMiddleware.cs:line 55  
  
2022-08-09T13:11:32.912496254Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)  
  
2022-08-09T13:11:46.781256679Z: [INFO]  fail: Middleware[0]  
  
2022-08-09T13:11:46.783085521Z: [INFO]        Failed to forward request to http://169.254.129.4:8080. Encountered a System.IO.IOException exception after 65159.147ms with message: The response ended prematurely.. Check application logs to verify the application is properly handling HTTP traffic.  
  
2022-08-09T13:11:46.785448276Z: [INFO]  fail: Microsoft.AspNetCore.Server.Kestrel[13]  
  
2022-08-09T13:11:46.785523478Z: [INFO]        Connection id "0HMJQ101V7MO9", Request id "0HMJQ101V7MO9:00000002": An unhandled exception was thrown by the application.  
  
2022-08-09T13:11:46.787296519Z: [INFO]  System.InvalidOperationException: StatusCode cannot be set because the response has already started.  
  
2022-08-09T13:11:46.787314719Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ThrowResponseAlreadyStartedException(String value)  
  
2022-08-09T13:11:46.787320519Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:46.787325419Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.Microsoft.AspNetCore.Http.Features.IHttpResponseFeature.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:46.787330019Z: [INFO]     at Microsoft.AspNetCore.Http.DefaultHttpResponse.set_StatusCode(Int32 value)  
  
2022-08-09T13:11:46.787342920Z: [INFO]     at Microsoft.Azure.AppService.Middleware.Forwarding.RequestForwarder.OnRequest(HttpContext context) in /EasyAuth/Middleware.Forwarding/RequestForwarder.cs:line 90  
  
2022-08-09T13:11:46.787348620Z: [INFO]     at Microsoft.Azure.AppService.Middleware.NetCore.AppServiceMiddleware.InvokeAsync(HttpContext context) in /EasyAuth/Microsoft.Azure.AppService.Middleware.NetCore/AppServiceMiddleware.cs:line 140  
  
2022-08-09T13:11:46.787371420Z: [INFO]     at Microsoft.Azure.AppService.MiddlewareShim.AutoHealing.AutoHealingMiddleware.Invoke(HttpContext context) in /EasyAuth/Middleware.Host/AutoHealing/AutoHealingMiddleware.cs:line 55  
  
2022-08-09T13:11:46.787379520Z: [INFO]     at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)

Nodejs Web App on Azure

8 answers