New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Random 502.3 errors #311

Closed
RLaptev opened this Issue Dec 13, 2016 · 62 comments

Comments

Projects
None yet
@RLaptev

RLaptev commented Dec 13, 2016

I started reporting this problem in issue #201, but because it’s already closed, I’m opening a new one.
We have a dedicated Windows 2008R2 server with IIS7.5 and ASP.NET Core 1.1 RTM (ANCM v7.1.1970.0) running production site for 3 weeks now.
There are two issues all linked to a random 502.3 error:

Issue 1. The site would be up and running for a variable amount of time (in hours), but all of a sudden would start constantly returning the following error
502 – Web server received an invalid response while acting as a gateway or proxy server
Restarting the site in IIS, or recycling site’s application pool brings the site up, but the problem reoccurs within a few hours or ~30 minutes. As workaround, we configured IIS to recycle app pool every 60 minutes, and that keeps the site up most of the time.

Issue 2. This identical to #201. We see a random 502.3 error in IIS log, while Kestrel log shows 200 status for the same request. This happens to all types of files - static JS/CSS, images and MVC views.

Example of the log: fr000011.pdf
The way I read the above log - IIS couldn't connect to Kestel to retrieve a simple static JPG image, and timed out after 2 minutes. I believe 2 minutes is a default IIS timeout. The site is still up in this case.

In both issues you would see the following entry in IIS failed request log:

ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", HttpStatus="502", HttpReason="Bad Gateway", HttpSubStatus="3", ErrorCode="2147954402", ConfigExceptionInfo=""

The difference between the two issues is that in a 2nd case you would still see successful request in Kestrel log, but in a 1st case there are NO entries whatsoever in Kestrel log, seems like IIS can’t connect to Kestrel at all.
Performance is NOT degrading over time. The site is nver under a heavy load. Lots of memory available.
Any suggestions on how to troubleshoot this problem? What could cause IIS to first randomly fail to connect to Kestrel and then constantly fail.
Thank you.

@Tratcher

This comment has been minimized.

Show comment
Hide comment
@Tratcher
Member

Tratcher commented Dec 13, 2016

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Dec 14, 2016

Contributor

could you please use Message Analyzer (https://www.microsoft.com/en-us/download/details.aspx?id=44226)  to capture the network traffic between ANCM and Kestrel? This will tell us what the response was sent by Kestrel caused 502.3 error.

Contributor

pan-wang commented Dec 14, 2016

could you please use Message Analyzer (https://www.microsoft.com/en-us/download/details.aspx?id=44226)  to capture the network traffic between ANCM and Kestrel? This will tell us what the response was sent by Kestrel caused 502.3 error.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 15, 2016

@pan-wang - please see attached screenshot from Message Analyzer. Is this is what you need? It's Local Network Traffic with 502 filter on Summary column. I assume it shows only traffic between IIS and the client. Do I need special setup in order to capture traffic between ANCM and Kestrel?

502-screenshot

RLaptev commented Dec 15, 2016

@pan-wang - please see attached screenshot from Message Analyzer. Is this is what you need? It's Local Network Traffic with 502 filter on Summary column. I assume it shows only traffic between IIS and the client. Do I need special setup in order to capture traffic between ANCM and Kestrel?

502-screenshot

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Dec 15, 2016

Contributor
Contributor

pan-wang commented Dec 15, 2016

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 15, 2016

@pan-wang Yes, the screenshot shows an example of IIS connection timeout after 2 minutes. However, according to the logs these requests never arrived to Kestrel. There are absolutely no entries in Kestrel stdout log for these timeout requests.
Any other suggestions?

RLaptev commented Dec 15, 2016

@pan-wang Yes, the screenshot shows an example of IIS connection timeout after 2 minutes. However, according to the logs these requests never arrived to Kestrel. There are absolutely no entries in Kestrel stdout log for these timeout requests.
Any other suggestions?

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Dec 15, 2016

Contributor
Contributor

pan-wang commented Dec 15, 2016

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 15, 2016

I think I don’t have this log. Do I need to use Message Analyzer for that? If yes, then that is what I was asking in my previous question - how do I configure Message Analyzer to track messages between IIS and Kestrel?

Thanks.

RLaptev commented Dec 15, 2016

I think I don’t have this log. Do I need to use Message Analyzer for that? If yes, then that is what I was asking in my previous question - how do I configure Message Analyzer to track messages between IIS and Kestrel?

Thanks.

@Tratcher

This comment has been minimized.

Show comment
Hide comment
@Tratcher

Tratcher Dec 15, 2016

Member

You need to set up Message Analyzer to track the loopback adapter.

Member

Tratcher commented Dec 15, 2016

You need to set up Message Analyzer to track the loopback adapter.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 15, 2016

Ok, i did that. Here is another screenshot:

502-screenshot3

I see 2 minutes 502 request between client and IIS, and the next line is what seems like a successful request to Kestrel at port 31520. I'm reading this correctly? Why IIS then returning 502???

RLaptev commented Dec 15, 2016

Ok, i did that. Here is another screenshot:

502-screenshot3

I see 2 minutes 502 request between client and IIS, and the next line is what seems like a successful request to Kestrel at port 31520. I'm reading this correctly? Why IIS then returning 502???

@Tratcher

This comment has been minimized.

Show comment
Hide comment
@Tratcher

Tratcher Dec 15, 2016

Member

That shows that IIS sent the request to Kestrel, but it doesn't show a response. The request appears to be stuck in your application somewhere, and IIS aborts the request after 2 minutes.

Member

Tratcher commented Dec 15, 2016

That shows that IIS sent the request to Kestrel, but it doesn't show a response. The request appears to be stuck in your application somewhere, and IIS aborts the request after 2 minutes.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 15, 2016

I'm reading the last two lines as a reply from Kestrel to IIS, port 31520 to 49803.
Request for IIS to Kestrel is line 3 from the bottom, port 49803 to 31520.
Anyway, where do I go from here?
Thanks

RLaptev commented Dec 15, 2016

I'm reading the last two lines as a reply from Kestrel to IIS, port 31520 to 49803.
Request for IIS to Kestrel is line 3 from the bottom, port 49803 to 31520.
Anyway, where do I go from here?
Thanks

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Dec 15, 2016

Contributor
Contributor

pan-wang commented Dec 15, 2016

@Tratcher

This comment has been minimized.

Show comment
Hide comment
@Tratcher

Tratcher Dec 15, 2016

Member

Those are just ACKs for receiving the request, it's not sending the response yet.

Member

Tratcher commented Dec 15, 2016

Those are just ACKs for receiving the request, it's not sending the response yet.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 15, 2016

Ok, assuming that is what's happening. Where do I look next?
Thank you.

RLaptev commented Dec 15, 2016

Ok, assuming that is what's happening. Where do I look next?
Thank you.

@Tratcher

This comment has been minimized.

Show comment
Hide comment
@Tratcher

Tratcher Dec 15, 2016

Member

Is that request for a static or dynamic resource? If it's dynamic then i'd suggest debugging the generation code. If it's static then we may need to capture a process dump and look deeper in the server.

Member

Tratcher commented Dec 15, 2016

Is that request for a static or dynamic resource? If it's dynamic then i'd suggest debugging the generation code. If it's static then we may need to capture a process dump and look deeper in the server.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 15, 2016

The example I provided is for completely static resources. This randomly happens to images/js/css files but sometimes MVC views.
Can you please point me to the instructions on how to capture this dump? I assume it needs to be done when IIS encounters 502 error?

RLaptev commented Dec 15, 2016

The example I provided is for completely static resources. This randomly happens to images/js/css files but sometimes MVC views.
Can you please point me to the instructions on how to capture this dump? I assume it needs to be done when IIS encounters 502 error?

@Tratcher

This comment has been minimized.

Show comment
Hide comment
@Tratcher

Tratcher Dec 15, 2016

Member

@halter73 can you let @RLaptev know what you'd need to debug a hung request in kestrel?

Member

Tratcher commented Dec 15, 2016

@halter73 can you let @RLaptev know what you'd need to debug a hung request in kestrel?

@halter73

This comment has been minimized.

Show comment
Hide comment
@halter73

halter73 Dec 15, 2016

Member

I haven't seen any logs from the .NET process. If you enable the most verbose logging like shown here and capture the logs corresponding to the same time frame as the 502, that might help us determine what's going on.

Member

halter73 commented Dec 15, 2016

I haven't seen any logs from the .NET process. If you enable the most verbose logging like shown here and capture the logs corresponding to the same time frame as the 502, that might help us determine what's going on.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 16, 2016

I only have the Information level logging enabled. I will enable Trace level tonight and will report my findings tomorrow. Maybe LogLevel.Debug is good enough? I wish there was a way to add timestamp to stdoutLogFile, is there?

Thanks

RLaptev commented Dec 16, 2016

I only have the Information level logging enabled. I will enable Trace level tonight and will report my findings tomorrow. Maybe LogLevel.Debug is good enough? I wish there was a way to add timestamp to stdoutLogFile, is there?

Thanks

@halter73

This comment has been minimized.

Show comment
Hide comment
@halter73

halter73 Dec 16, 2016

Member

@RLaptev You can use serilog instead of console logging. Instead of using stdout, you can write the same logs with time stamps straight to a log file.

Here's a blog post descrying how to set up Serilog.

Member

halter73 commented Dec 16, 2016

@RLaptev You can use serilog instead of console logging. Instead of using stdout, you can write the same logs with time stamps straight to a log file.

Here's a blog post descrying how to set up Serilog.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 16, 2016

@halter73 Thank you, I already configured nLog for this. I'm now trying to find relative information in the log so I can show it here.

RLaptev commented Dec 16, 2016

@halter73 Thank you, I already configured nLog for this. I'm now trying to find relative information in the log so I can show it here.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 19, 2016

Over the weekend IIS logged 460 errors with 502 status. All errors contained “An operation was attempted on a nonexistent network connection.” The error in IIS would look like so:

GENERAL_FLUSH_RESPONSE_END BytesSent="0", ErrorCode="An operation was attempted on a nonexistent network connection.
MODULE_SET_RESPONSE_ERROR_STATUS Warning ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", HttpStatus="502", HttpReason="Bad Gateway", HttpSubStatus="3", ErrorCode="An operation was attempted on a nonexistent network connection.  (0x800704cd)", ConfigExceptionInfo=""
SET_RESPONSE_ERROR_DESCRIPTION Warning ErrorDescription="There was a connection error while trying to route the request."

I can see from the IIS log that content of the JS file (as an example) is being transmitted and then IIS throws 502 error due to “nonexistent network connection.” I think client/browser just disconnects before finishing receiving the content from the server, e.g. user navigates from the page before it gets loaded. Is that normal for IIS to log 502 error in this case? Can this IIS behavior be changed?

There were no over 2 minutes request timeouts over weekend, not sure why, as I didn’t make any changes to the code. I did however lowered IIS pool recycling to 30 minutes. Does recycling so often negatively effects user experience???
I’m waiting for the site to crash with permanent 502 error, so I can see what’s going on in kestrel logs, but at the same time I don’t want to increase the recycling back to 60 minutes…

Thanks

RLaptev commented Dec 19, 2016

Over the weekend IIS logged 460 errors with 502 status. All errors contained “An operation was attempted on a nonexistent network connection.” The error in IIS would look like so:

GENERAL_FLUSH_RESPONSE_END BytesSent="0", ErrorCode="An operation was attempted on a nonexistent network connection.
MODULE_SET_RESPONSE_ERROR_STATUS Warning ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", HttpStatus="502", HttpReason="Bad Gateway", HttpSubStatus="3", ErrorCode="An operation was attempted on a nonexistent network connection.  (0x800704cd)", ConfigExceptionInfo=""
SET_RESPONSE_ERROR_DESCRIPTION Warning ErrorDescription="There was a connection error while trying to route the request."

I can see from the IIS log that content of the JS file (as an example) is being transmitted and then IIS throws 502 error due to “nonexistent network connection.” I think client/browser just disconnects before finishing receiving the content from the server, e.g. user navigates from the page before it gets loaded. Is that normal for IIS to log 502 error in this case? Can this IIS behavior be changed?

There were no over 2 minutes request timeouts over weekend, not sure why, as I didn’t make any changes to the code. I did however lowered IIS pool recycling to 30 minutes. Does recycling so often negatively effects user experience???
I’m waiting for the site to crash with permanent 502 error, so I can see what’s going on in kestrel logs, but at the same time I don’t want to increase the recycling back to 60 minutes…

Thanks

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 20, 2016

Tonight we had 25 timeout (after 2 minutes) 502.3 errors in IIS log. Like the one below:

ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", HttpStatus="502", HttpReason="Bad Gateway", HttpSubStatus="3", ErrorCode="2147954402", ConfigExceptionInfo=""

According to ASP.NET Core logs these requested were never received by Kestrel! There are absolutely no entries in the asp.net logs that match requested URL and the timestamp… All timeout requests happened during the same 5 minutes period, after that IIS recycled memory pool (scheduled), and no more timeouts in the log.

RLaptev commented Dec 20, 2016

Tonight we had 25 timeout (after 2 minutes) 502.3 errors in IIS log. Like the one below:

ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", HttpStatus="502", HttpReason="Bad Gateway", HttpSubStatus="3", ErrorCode="2147954402", ConfigExceptionInfo=""

According to ASP.NET Core logs these requested were never received by Kestrel! There are absolutely no entries in the asp.net logs that match requested URL and the timestamp… All timeout requests happened during the same 5 minutes period, after that IIS recycled memory pool (scheduled), and no more timeouts in the log.

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Dec 20, 2016

Contributor

frequently recycle IIS worker process is not a good idea as it will kill long running request and introduce cold start latency. You claimed that the timeout requests were never received by Kestrel. Do you have network traffic log to prove it? Could you please collect network traffic log so that we can isolate the root cause. I am really curious about where the request got lost.

Contributor

pan-wang commented Dec 20, 2016

frequently recycle IIS worker process is not a good idea as it will kill long running request and introduce cold start latency. You claimed that the timeout requests were never received by Kestrel. Do you have network traffic log to prove it? Could you please collect network traffic log so that we can isolate the root cause. I am really curious about where the request got lost.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Dec 21, 2016

I thought that recycling so often is not a good idea, but I have no other way of keeping out site running.
I don’t have the network logs for the timeouts from yesterday, but I think the log will look identical to the screenshot I posted 5 days ago:
502-screenshot3
Does the above log tell you anything?
What about the misleading 502 errors from IIS when client drops the connection? It’s not as important as the timeouts, but still would be nice to know if this is a “normal “ behavior for IIS.

Thanks.

RLaptev commented Dec 21, 2016

I thought that recycling so often is not a good idea, but I have no other way of keeping out site running.
I don’t have the network logs for the timeouts from yesterday, but I think the log will look identical to the screenshot I posted 5 days ago:
502-screenshot3
Does the above log tell you anything?
What about the misleading 502 errors from IIS when client drops the connection? It’s not as important as the timeouts, but still would be nice to know if this is a “normal “ behavior for IIS.

Thanks.

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Dec 21, 2016

Contributor

the above log tell us ANCM forwarded the request to Kestrel successfully but did not receive the response.
If it is still true for your latest case, it indicates a bug in Kestrel. The cause of packet lost may due to out of resource, e.g., queue is full or out of thread, I guess. We need a dump of the Kestrel process to analyze it.
I am not sure about whether other 502 error is caused by client disconnect. Will do some investigation and update you.

Contributor

pan-wang commented Dec 21, 2016

the above log tell us ANCM forwarded the request to Kestrel successfully but did not receive the response.
If it is still true for your latest case, it indicates a bug in Kestrel. The cause of packet lost may due to out of resource, e.g., queue is full or out of thread, I guess. We need a dump of the Kestrel process to analyze it.
I am not sure about whether other 502 error is caused by client disconnect. Will do some investigation and update you.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Jan 4, 2017

I thought I will update my findings so far. Our site is image heavy. All images are just static photos served by StaticFiles middleware. I noticed that most of the time IIS timeouts were for the images, so I setup a new IIS site just to serve images (no asp.net core). The result – no timeouts! ASP.NET Core still runs our main site but all images/photos are from a different IIS site/URL. I have been slowly increasing memory pool recycling interval (up to 3 hours now), so far no more permanent 502 crashes! I think this tells me that the problem is somewhere in AspNetCoreModule when it serves static files, or in StaticFiles middleware. Any thoughts on that?
@pan-wang - any more info on 502 error caused by client disconnect? We still get tons of those in the logs.

RLaptev commented Jan 4, 2017

I thought I will update my findings so far. Our site is image heavy. All images are just static photos served by StaticFiles middleware. I noticed that most of the time IIS timeouts were for the images, so I setup a new IIS site just to serve images (no asp.net core). The result – no timeouts! ASP.NET Core still runs our main site but all images/photos are from a different IIS site/URL. I have been slowly increasing memory pool recycling interval (up to 3 hours now), so far no more permanent 502 crashes! I think this tells me that the problem is somewhere in AspNetCoreModule when it serves static files, or in StaticFiles middleware. Any thoughts on that?
@pan-wang - any more info on 502 error caused by client disconnect? We still get tons of those in the logs.

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Jan 4, 2017

Contributor
Contributor

pan-wang commented Jan 4, 2017

@Ku4nCheang

This comment has been minimized.

Show comment
Hide comment
@Ku4nCheang

Ku4nCheang Jan 24, 2017

Got a same issue of serving a large static file. In my case, it is a mp4 file with 15Mb size. It caused 502 bad gateway. Look into the log file. It showed these requests were not finished. It just keep receiving new request for the static file.

HTML5 video tag for display a video
Some requests showed a strange response. The server tried to serve a file but never response successfully. It needs to try few times to deliver the file to the client.

Ku4nCheang commented Jan 24, 2017

Got a same issue of serving a large static file. In my case, it is a mp4 file with 15Mb size. It caused 502 bad gateway. Look into the log file. It showed these requests were not finished. It just keep receiving new request for the static file.

HTML5 video tag for display a video
Some requests showed a strange response. The server tried to serve a file but never response successfully. It needs to try few times to deliver the file to the client.

@muratg

This comment has been minimized.

Show comment
Hide comment
@muratg

muratg Feb 3, 2017

Member

@cesarbs Could you take a look? We can move the bug if necessary.

Member

muratg commented Feb 3, 2017

@cesarbs Could you take a look? We can move the bug if necessary.

@cesarbs

This comment has been minimized.

Show comment
Hide comment
@cesarbs

cesarbs Feb 3, 2017

Contributor

@muratg Will do.

Contributor

cesarbs commented Feb 3, 2017

@muratg Will do.

@cesarbs

This comment has been minimized.

Show comment
Hide comment
@cesarbs

cesarbs Feb 3, 2017

Contributor

This smells of aspnet/KestrelHttpServer#1278, which will be fixed in 1.1.1.

@RLaptev Do you pass the context.RequestAborted cancellation token to any writes done by your app? This would explain why you see the issue on views sometimes. StaticFiles uses that token, which is why it's affected by the deadlock.

Do you have a test environment where you're able to generate enough load to repro the issue?

Contributor

cesarbs commented Feb 3, 2017

This smells of aspnet/KestrelHttpServer#1278, which will be fixed in 1.1.1.

@RLaptev Do you pass the context.RequestAborted cancellation token to any writes done by your app? This would explain why you see the issue on views sometimes. StaticFiles uses that token, which is why it's affected by the deadlock.

Do you have a test environment where you're able to generate enough load to repro the issue?

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Feb 8, 2017

The cancellationToken.ThrowIfCancellationRequested is only used in one class - custom UserStore that implements IUserStore, IUserPasswordStore, IUserLoginStore, IUserPhoneNumberStore, IUserTwoFactorStore, IUserSecurityStampStore interfaces.
Sorry, no test enviroment.

RLaptev commented Feb 8, 2017

The cancellationToken.ThrowIfCancellationRequested is only used in one class - custom UserStore that implements IUserStore, IUserPasswordStore, IUserLoginStore, IUserPhoneNumberStore, IUserTwoFactorStore, IUserSecurityStampStore interfaces.
Sorry, no test enviroment.

@halter73

This comment has been minimized.

Show comment
Hide comment
@halter73

halter73 Feb 8, 2017

Member

@RLaptev You don't even need to use context.RequestAborted directly. Simply using the StaticFiles middleware could cause the issue described in aspnet/KestrelHttpServer#1278 since it uses the CancellationToken.

You mentioned in #311 (comment) that the StaticFiles middlware could be the problem. You may have been right.

Member

halter73 commented Feb 8, 2017

@RLaptev You don't even need to use context.RequestAborted directly. Simply using the StaticFiles middleware could cause the issue described in aspnet/KestrelHttpServer#1278 since it uses the CancellationToken.

You mentioned in #311 (comment) that the StaticFiles middlware could be the problem. You may have been right.

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang Feb 8, 2017

Contributor

@RLaptev In my test, I did find that a 502 error will be logged to IIS log if client dropped connection.

Contributor

pan-wang commented Feb 8, 2017

@RLaptev In my test, I did find that a 502 error will be logged to IIS log if client dropped connection.

@glennc glennc added this to the Discussions milestone Feb 9, 2017

@glennc

This comment has been minimized.

Show comment
Hide comment
@glennc

glennc Feb 9, 2017

Member

Moving to discussion until something falls out that is actionable or we close it.

Member

glennc commented Feb 9, 2017

Moving to discussion until something falls out that is actionable or we close it.

@krs99

This comment has been minimized.

Show comment
Hide comment
@krs99

krs99 Feb 9, 2017

Hello

I have exactly the same issue, we are trying to go around for a few days but no result.
502-server-error

Server environment Windows 2012R2 Standard, core ASPNET 1.1.0, IIS 8.5

We have four website, two of them has a short video file from 200KB to 10MB and the other two are not.

The problem only appears on the page where are video files. Sometimes this bug appear three times a days, another time 15 times a day.

This is very frustrating because there's no rule when the application stops working and someone must constantly monitor the application.

krs99 commented Feb 9, 2017

Hello

I have exactly the same issue, we are trying to go around for a few days but no result.
502-server-error

Server environment Windows 2012R2 Standard, core ASPNET 1.1.0, IIS 8.5

We have four website, two of them has a short video file from 200KB to 10MB and the other two are not.

The problem only appears on the page where are video files. Sometimes this bug appear three times a days, another time 15 times a day.

This is very frustrating because there's no rule when the application stops working and someone must constantly monitor the application.

@RLaptev

This comment has been minimized.

Show comment
Hide comment
@RLaptev

RLaptev Feb 10, 2017

@krs99 - as workaround you can setup a separate website in IIS that just serves static files (no .Net), e.g. media.xyz.com and serve all your video files from that site. That is what I did for ours.

RLaptev commented Feb 10, 2017

@krs99 - as workaround you can setup a separate website in IIS that just serves static files (no .Net), e.g. media.xyz.com and serve all your video files from that site. That is what I did for ours.

@halter73

This comment has been minimized.

Show comment
Hide comment
@halter73

halter73 Feb 10, 2017

Member

@krs99 @RLaptev's workaround should fix your issue if it's the same (and it definitely looks like it could be). Once 1.1.1 is release (or 1.0.3), it shouldn't be necessary.

Member

halter73 commented Feb 10, 2017

@krs99 @RLaptev's workaround should fix your issue if it's the same (and it definitely looks like it could be). Once 1.1.1 is release (or 1.0.3), it shouldn't be necessary.

@krs99

This comment has been minimized.

Show comment
Hide comment
@krs99

krs99 Feb 11, 2017

@RLaptev - From the beginning I created separate subdomain for media(media.mydomain.pl) but unfortunately I did not notice that it was assigned to the same app pool as the main domain. When I separate app pool for subdomain and domain it's start working without error 502. Thank you for help.

krs99 commented Feb 11, 2017

@RLaptev - From the beginning I created separate subdomain for media(media.mydomain.pl) but unfortunately I did not notice that it was assigned to the same app pool as the main domain. When I separate app pool for subdomain and domain it's start working without error 502. Thank you for help.

@krs99

This comment has been minimized.

Show comment
Hide comment
@krs99

krs99 Feb 13, 2017

Despite the fact that I served static file from subdomain (separate app pool) after three days when website worked well, error 502 reappeared.

krs99 commented Feb 13, 2017

Despite the fact that I served static file from subdomain (separate app pool) after three days when website worked well, error 502 reappeared.

@krugerm

This comment has been minimized.

Show comment
Hide comment
@krugerm

krugerm Feb 23, 2017

I am seeing exactly the same behaviour, except we're hosting our site on an Azure app service.

krugerm commented Feb 23, 2017

I am seeing exactly the same behaviour, except we're hosting our site on an Azure app service.

@nemenos

This comment has been minimized.

Show comment
Hide comment
@nemenos

nemenos Feb 23, 2017

@krugerm yes, I'm on azure app service too, and it's the biggest problem we have at the moment. we need it to be released asap!

nemenos commented Feb 23, 2017

@krugerm yes, I'm on azure app service too, and it's the biggest problem we have at the moment. we need it to be released asap!

@krs99

This comment has been minimized.

Show comment
Hide comment
@krs99

krs99 Feb 26, 2017

We also need release asap. Is there any information about release date?

krs99 commented Feb 26, 2017

We also need release asap. Is there any information about release date?

@halter73

This comment has been minimized.

Show comment
Hide comment
@halter73

halter73 Feb 27, 2017

Member

It will be released with VS 2017 on March 7th.

Member

halter73 commented Feb 27, 2017

It will be released with VS 2017 on March 7th.

@dhjf

This comment has been minimized.

Show comment
Hide comment
@dhjf

dhjf Mar 9, 2017

Hi. Can anyone confirm that the new release fixed the issue described here? We have a similar issue, getting 502.3's after a while on a service with long response times. It still happens after upgrading to 1.1.1 though...

dhjf commented Mar 9, 2017

Hi. Can anyone confirm that the new release fixed the issue described here? We have a similar issue, getting 502.3's after a while on a service with long response times. It still happens after upgrading to 1.1.1 though...

@thisispaulsmith

This comment has been minimized.

Show comment
Hide comment
@thisispaulsmith

thisispaulsmith Mar 9, 2017

We updated yesterday. No issues as yet.

thisispaulsmith commented Mar 9, 2017

We updated yesterday. No issues as yet.

@muratg

This comment has been minimized.

Show comment
Hide comment
@muratg

muratg May 12, 2017

Member

We are closing this issue because no further action is planned for this issue. If you still have any issues or questions, please log a new issue with any additional details that you have.

Member

muratg commented May 12, 2017

We are closing this issue because no further action is planned for this issue. If you still have any issues or questions, please log a new issue with any additional details that you have.

@muratg muratg closed this May 12, 2017

@zhangpengchen

This comment has been minimized.

Show comment
Hide comment
@zhangpengchen

zhangpengchen May 18, 2017

Too bad, I had a similar issue, getting a lot of 502 errors on Azure web app for a heavy load. No static contents API only. I did a upgrade from 1.0.1 to 1.1.0 seem no luck because we are using Visual Studio 2015. From @dhjf 's comment seem we have to upgrade to Visual Studio 2017 for 1.1.1.

zhangpengchen commented May 18, 2017

Too bad, I had a similar issue, getting a lot of 502 errors on Azure web app for a heavy load. No static contents API only. I did a upgrade from 1.0.1 to 1.1.0 seem no luck because we are using Visual Studio 2015. From @dhjf 's comment seem we have to upgrade to Visual Studio 2017 for 1.1.1.

@muratg

This comment has been minimized.

Show comment
Hide comment
@muratg

muratg May 18, 2017

Member

@zhangpeng-kooboo you don't NEED to update to VS 2017 for 1.1.1. Just update your references in your project file.

Member

muratg commented May 18, 2017

@zhangpeng-kooboo you don't NEED to update to VS 2017 for 1.1.1. Just update your references in your project file.

@zhangpengchen

This comment has been minimized.

Show comment
Hide comment
@zhangpengchen

zhangpengchen May 23, 2017

@muratg thks, but after I upgraded to 1.1.1, still does not help. every-time when I send a traffic 300 requests per second to azure web app I saw a lot of '502.3 bad gateway "The specified CGI application encountered an error and the server terminated the process. It's hard to say is it a issue within .NET Core, or Azure web app does not support that.

One thing I am not sure is it matter in global.json we are using
"sdk": {
"version": "1.0.0-preview2-003131"
}

'.
`30. URL_CACHE_ACCESS_START RequestURL="/promotion/details?promotionCode=TESTCODE" 12:35:25.208
31. URL_CACHE_ACCESS_END PhysicalPath="", URLInfoFromCache="true", URLInfoAddedToCache="false", ErrorCode="The operation completed successfully.
(0x0)" 12:35:25.208
32. GENERAL_GET_URL_METADATA PhysicalPath="", AccessPerms="513" 12:35:25.208
33. HANDLER_CHANGED OldHandlerName="", NewHandlerName="aspNetCore", NewHandlerModules="AspNetCoreModule", NewHandlerScriptProcessor="", NewHandlerType="" 12:35:25.208
34. NOTIFY_MODULE_START ModuleName="ModSecurity IIS (32bits)", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
35. NOTIFY_MODULE_END ModuleName="ModSecurity IIS (32bits)", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
36. NOTIFY_MODULE_START ModuleName="WebSocketMonitoringModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
37. NOTIFY_MODULE_END ModuleName="WebSocketMonitoringModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
38. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
39. GENERAL_SET_REQUEST_HEADER HeaderName="MWH-SecurityToken", HeaderValue="", Replace="true" 12:35:25.208
40. GENERAL_SET_REQUEST_HEADER HeaderName="Sec-WebSocket-Extensions", HeaderValue="", Replace="true" 12:35:25.208
41. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
42. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
43. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
44. NOTIFY_MODULE_START ModuleName="RequestFilteringModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
45. NOTIFY_MODULE_END ModuleName="RequestFilteringModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
46. NOTIFY_MODULE_START ModuleName="FailedRequestsTracingModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
47. NOTIFY_MODULE_END ModuleName="FailedRequestsTracingModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
48. NOTIFY_MODULE_START ModuleName="ConfigurationValidationModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
49. NOTIFY_MODULE_END ModuleName="ConfigurationValidationModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
50. NOTIFY_MODULE_START ModuleName="RewriteModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
51. NOTIFY_MODULE_END ModuleName="RewriteModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
52. NOTIFY_MODULE_START ModuleName="ApplicationInitializationModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
53. NOTIFY_MODULE_END ModuleName="ApplicationInitializationModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
54. NOTIFY_MODULE_START ModuleName="IpRestrictionModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
55. NOTIFY_MODULE_END ModuleName="IpRestrictionModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
56. NOTIFY_MODULE_START ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="false" 12:35:25.208
57. NOTIFY_MODULE_END ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
58. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="false" 12:35:25.208
59. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
60. NOTIFY_MODULE_START ModuleName="AnonymousAuthenticationModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="false" 12:35:25.208
61. AUTH_START AuthTypeSupported="Anonymous" 12:35:25.208
62. AUTH_REQUEST_AUTH_TYPE RequestAuthType="Anonymous" 12:35:25.208
63. AUTH_SUCCEEDED AuthType="NT", NTLMUsed="false", RemoteUserName="", AuthUserName="", TokenImpersonationLevel="ImpersonationDelegate" 12:35:25.208
64. USER_SET AuthType="", UserName="", SupportsIsInRole="true" 12:35:25.208
65. AUTH_END 12:35:25.208
66. NOTIFY_MODULE_END ModuleName="AnonymousAuthenticationModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
67. NOTIFY_MODULE_START ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="true" 12:35:25.208
68. FILTER_AUTH_COMPLETE_START 12:35:25.208
69. FILTER_AUTH_COMPLETE_END 12:35:25.208
70. NOTIFY_MODULE_END ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
71. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="AUTHORIZE_REQUEST", fIsPostNotification="false" 12:35:25.208
72. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="AUTHORIZE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
73. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="RESOLVE_REQUEST_CACHE", fIsPostNotification="false" 12:35:25.208
74. OUTPUT_CACHE_LOOKUP_START 12:35:25.208
75. OUTPUT_CACHE_LOOKUP_END Result="NOT_FOUND" 12:35:25.208
76. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="RESOLVE_REQUEST_CACHE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
77. NOTIFY_MODULE_START ModuleName="ApplicationRequestRouting", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
78. NOTIFY_MODULE_END ModuleName="ApplicationRequestRouting", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
79. NOTIFY_MODULE_START ModuleName="StaticCompressionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
80. NOTIFY_MODULE_END ModuleName="StaticCompressionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
81. NOTIFY_MODULE_START ModuleName="HttpRedirectionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
82. NOTIFY_MODULE_END ModuleName="HttpRedirectionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
83. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
84. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
85. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="true" 12:35:25.208
86. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
87. NOTIFY_MODULE_START ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
88. GENERAL_SET_REQUEST_HEADER HeaderName="MS-ASPNETCORE-TOKEN", HeaderValue="d0594dce-820b-4ef4-a036-4715bca3c531", Replace="true" 12:35:25.208
89. GENERAL_SET_REQUEST_HEADER HeaderName="X-Forwarded-For", HeaderValue="95.97.52.106:62637, 95.97.52.106:62637", Replace="true" 12:35:25.208
90. GENERAL_SET_REQUEST_HEADER HeaderName="X-Forwarded-Proto", HeaderValue="https", Replace="true" 12:35:25.208
91. GENERAL_SET_REQUEST_HEADER HeaderName="MS-ASPNETCORE-CLIENTCERT", HeaderValue="", Replace="true" 12:35:25.208
92. GENERAL_SET_REQUEST_HEADER HeaderName="Connection", HeaderValue="", Replace="true" 12:35:25.208
93. MODULE_SET_RESPONSE_ERROR_STATUS

Warning ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", HttpStatus="502", HttpReason="Bad Gateway", HttpSubStatus="3", ErrorCode="2147954429", ConfigExceptionInfo="" 12:35:28.130
94. NOTIFY_MODULE_COMPLETION ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", fIsPostNotificationEvent="false", CompletionBytes="0", ErrorCode="The operation completed successfully.
(0x0)" 12:35:28.192
95. NOTIFY_MODULE_END ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
96. NOTIFY_MODULE_START ModuleName="DynamicCompressionModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotification="true" 12:35:28.192
97. NOTIFY_MODULE_END ModuleName="DynamicCompressionModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
98. NOTIFY_MODULE_START ModuleName="RewriteModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotification="true" 12:35:28.192
99. NOTIFY_MODULE_END ModuleName="RewriteModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
100. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="UPDATE_REQUEST_CACHE", fIsPostNotification="false" 12:35:28.192
101. OUTPUT_CACHE_UPDATE_START CachePolicy="NO_CACHE", TimeToLive="0" 12:35:28.192
102. OUTPUT_CACHE_UPDATE_END Result="STATUS_NOT_OK" 12:35:28.192
103. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="UPDATE_REQUEST_CACHE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
104. NOTIFY_MODULE_START ModuleName="DynamicIpRestrictionModule", Notification="END_REQUEST", fIsPostNotification="false" 12:35:28.192
105. NOTIFY_MODULE_END ModuleName="DynamicIpRestrictionModule", Notification="END_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
106. NOTIFY_MODULE_START ModuleName="ProcessMonitoringModule", Notification="END_REQUEST", fIsPostNotification="false" 12:35:28.192
107. NOTIFY_MODULE_END ModuleName="ProcessMonitoringModule", Notification="END_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
108. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotification="false" 12:35:28.192
109. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
110. NOTIFY_MODULE_START ModuleName="ModSecurity IIS (32bits)", Notification="END_REQUEST", fIsPostNotification="true" 12:35:28.192
111. NOTIFY_MODULE_END ModuleName="ModSecurity IIS (32bits)", Notification="END_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
112. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotification="true" 12:35:28.192
113. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
114. NOTIFY_MODULE_START ModuleName="WebSocketMonitoringModule", Notification="END_REQUEST", fIsPostNotification="true" 12:35:28.192
115. NOTIFY_MODULE_END ModuleName="WebSocketMonitoringModule", Notification="END_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
116. NOTIFY_MODULE_START ModuleName="ModSecurity IIS (32bits)", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
117. NOTIFY_MODULE_END ModuleName="ModSecurity IIS (32bits)", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
118. NOTIFY_MODULE_START ModuleName="ApplicationIdentificationModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
119. NOTIFY_MODULE_END ModuleName="ApplicationIdentificationModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
120. NOTIFY_MODULE_START ModuleName="ProcessMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
121. NOTIFY_MODULE_END ModuleName="ProcessMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
122. NOTIFY_MODULE_START ModuleName="iisnode", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
123. NOTIFY_MODULE_END ModuleName="iisnode", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
124. NOTIFY_MODULE_START ModuleName="HttpLoggingModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
125. NOTIFY_MODULE_END ModuleName="HttpLoggingModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
126. NOTIFY_MODULE_START ModuleName="IsapiModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
127. NOTIFY_MODULE_END ModuleName="IsapiModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
128. NOTIFY_MODULE_START ModuleName="RequestFilteringModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
129. NOTIFY_MODULE_END ModuleName="RequestFilteringModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
130. NOTIFY_MODULE_START ModuleName="ProtocolSupportModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
131. NOTIFY_MODULE_END ModuleName="ProtocolSupportModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
132. NOTIFY_MODULE_START ModuleName="IsapiFilterModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
133. NOTIFY_MODULE_END ModuleName="IsapiFilterModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
134. NOTIFY_MODULE_START ModuleName="DynamicCompressionModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
135. NOTIFY_MODULE_END ModuleName="DynamicCompressionModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
136. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
137. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
138. NOTIFY_MODULE_START ModuleName="RewriteModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
139. NOTIFY_MODULE_END ModuleName="RewriteModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
140. NOTIFY_MODULE_START ModuleName="CustomErrorModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
141. GENERAL_SEND_CUSTOM_ERROR HttpStatus="502", HttpSubStatus="3", FileNameOrURL="" 12:35:28.192
142. NOTIFY_MODULE_END ModuleName="CustomErrorModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
143. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
144. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
145. NOTIFY_MODULE_START ModuleName="WebSocketMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
146. NOTIFY_MODULE_END ModuleName="WebSocketMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
147. NOTIFY_MODULE_START ModuleName="DynamicIpRestrictionModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
148. NOTIFY_MODULE_END ModuleName="DynamicIpRestrictionModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
149. HTTPSYS_CACHEABLE HttpsysCacheable="false", Reason="HANDLER_HTTPSYS_UNFRIENDLY", CachePolicy="NO_CACHE", TimeToLive="0" 12:35:28.192
150. GENERAL_FLUSH_RESPONSE_START 12:35:28.192
151. GENERAL_RESPONSE_HEADERS Headers="Content-Type: text/html
Server: Microsoft-IIS/8.0
X-FE-DATA: AppId:Unknown-StatusCode
X-Powered-By: ASP.NET
DWAS-Handler-Name: EXECUTE|502|3|0x2efd|CONFIG_SUCCESS|aspNetCore|100.88.116.47|\100.88.168.111\volume-17-default&ApiApp=0
" 12:35:28.192
152. GENERAL_RESPONSE_ENTITY_BUFFER Buffer="The specified CGI application encountered an error and the server terminated the process." 12:35:28.192
153. GENERAL_FLUSH_RESPONSE_END BytesSent="412", ErrorCode="The operation completed successfully.
(0x0)" 12:35:28.192
154. GENERAL_REQUEST_END BytesSent="412", BytesReceived="1470", HttpStatus="502", HttpSubStatus="3" 12:35:28.192`

zhangpengchen commented May 23, 2017

@muratg thks, but after I upgraded to 1.1.1, still does not help. every-time when I send a traffic 300 requests per second to azure web app I saw a lot of '502.3 bad gateway "The specified CGI application encountered an error and the server terminated the process. It's hard to say is it a issue within .NET Core, or Azure web app does not support that.

One thing I am not sure is it matter in global.json we are using
"sdk": {
"version": "1.0.0-preview2-003131"
}

'.
`30. URL_CACHE_ACCESS_START RequestURL="/promotion/details?promotionCode=TESTCODE" 12:35:25.208
31. URL_CACHE_ACCESS_END PhysicalPath="", URLInfoFromCache="true", URLInfoAddedToCache="false", ErrorCode="The operation completed successfully.
(0x0)" 12:35:25.208
32. GENERAL_GET_URL_METADATA PhysicalPath="", AccessPerms="513" 12:35:25.208
33. HANDLER_CHANGED OldHandlerName="", NewHandlerName="aspNetCore", NewHandlerModules="AspNetCoreModule", NewHandlerScriptProcessor="", NewHandlerType="" 12:35:25.208
34. NOTIFY_MODULE_START ModuleName="ModSecurity IIS (32bits)", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
35. NOTIFY_MODULE_END ModuleName="ModSecurity IIS (32bits)", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
36. NOTIFY_MODULE_START ModuleName="WebSocketMonitoringModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
37. NOTIFY_MODULE_END ModuleName="WebSocketMonitoringModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
38. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
39. GENERAL_SET_REQUEST_HEADER HeaderName="MWH-SecurityToken", HeaderValue="", Replace="true" 12:35:25.208
40. GENERAL_SET_REQUEST_HEADER HeaderName="Sec-WebSocket-Extensions", HeaderValue="", Replace="true" 12:35:25.208
41. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
42. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
43. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
44. NOTIFY_MODULE_START ModuleName="RequestFilteringModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
45. NOTIFY_MODULE_END ModuleName="RequestFilteringModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
46. NOTIFY_MODULE_START ModuleName="FailedRequestsTracingModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
47. NOTIFY_MODULE_END ModuleName="FailedRequestsTracingModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
48. NOTIFY_MODULE_START ModuleName="ConfigurationValidationModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
49. NOTIFY_MODULE_END ModuleName="ConfigurationValidationModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
50. NOTIFY_MODULE_START ModuleName="RewriteModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
51. NOTIFY_MODULE_END ModuleName="RewriteModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
52. NOTIFY_MODULE_START ModuleName="ApplicationInitializationModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
53. NOTIFY_MODULE_END ModuleName="ApplicationInitializationModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
54. NOTIFY_MODULE_START ModuleName="IpRestrictionModule", Notification="BEGIN_REQUEST", fIsPostNotification="false" 12:35:25.208
55. NOTIFY_MODULE_END ModuleName="IpRestrictionModule", Notification="BEGIN_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
56. NOTIFY_MODULE_START ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="false" 12:35:25.208
57. NOTIFY_MODULE_END ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
58. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="false" 12:35:25.208
59. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
60. NOTIFY_MODULE_START ModuleName="AnonymousAuthenticationModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="false" 12:35:25.208
61. AUTH_START AuthTypeSupported="Anonymous" 12:35:25.208
62. AUTH_REQUEST_AUTH_TYPE RequestAuthType="Anonymous" 12:35:25.208
63. AUTH_SUCCEEDED AuthType="NT", NTLMUsed="false", RemoteUserName="", AuthUserName="", TokenImpersonationLevel="ImpersonationDelegate" 12:35:25.208
64. USER_SET AuthType="", UserName="", SupportsIsInRole="true" 12:35:25.208
65. AUTH_END 12:35:25.208
66. NOTIFY_MODULE_END ModuleName="AnonymousAuthenticationModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
67. NOTIFY_MODULE_START ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotification="true" 12:35:25.208
68. FILTER_AUTH_COMPLETE_START 12:35:25.208
69. FILTER_AUTH_COMPLETE_END 12:35:25.208
70. NOTIFY_MODULE_END ModuleName="IsapiFilterModule", Notification="AUTHENTICATE_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
71. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="AUTHORIZE_REQUEST", fIsPostNotification="false" 12:35:25.208
72. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="AUTHORIZE_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
73. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="RESOLVE_REQUEST_CACHE", fIsPostNotification="false" 12:35:25.208
74. OUTPUT_CACHE_LOOKUP_START 12:35:25.208
75. OUTPUT_CACHE_LOOKUP_END Result="NOT_FOUND" 12:35:25.208
76. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="RESOLVE_REQUEST_CACHE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
77. NOTIFY_MODULE_START ModuleName="ApplicationRequestRouting", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
78. NOTIFY_MODULE_END ModuleName="ApplicationRequestRouting", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
79. NOTIFY_MODULE_START ModuleName="StaticCompressionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
80. NOTIFY_MODULE_END ModuleName="StaticCompressionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
81. NOTIFY_MODULE_START ModuleName="HttpRedirectionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
82. NOTIFY_MODULE_END ModuleName="HttpRedirectionModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
83. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
84. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
85. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotification="true" 12:35:25.208
86. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="MAP_REQUEST_HANDLER", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:25.208
87. NOTIFY_MODULE_START ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", fIsPostNotification="false" 12:35:25.208
88. GENERAL_SET_REQUEST_HEADER HeaderName="MS-ASPNETCORE-TOKEN", HeaderValue="d0594dce-820b-4ef4-a036-4715bca3c531", Replace="true" 12:35:25.208
89. GENERAL_SET_REQUEST_HEADER HeaderName="X-Forwarded-For", HeaderValue="95.97.52.106:62637, 95.97.52.106:62637", Replace="true" 12:35:25.208
90. GENERAL_SET_REQUEST_HEADER HeaderName="X-Forwarded-Proto", HeaderValue="https", Replace="true" 12:35:25.208
91. GENERAL_SET_REQUEST_HEADER HeaderName="MS-ASPNETCORE-CLIENTCERT", HeaderValue="", Replace="true" 12:35:25.208
92. GENERAL_SET_REQUEST_HEADER HeaderName="Connection", HeaderValue="", Replace="true" 12:35:25.208
93. MODULE_SET_RESPONSE_ERROR_STATUS

Warning ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", HttpStatus="502", HttpReason="Bad Gateway", HttpSubStatus="3", ErrorCode="2147954429", ConfigExceptionInfo="" 12:35:28.130
94. NOTIFY_MODULE_COMPLETION ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", fIsPostNotificationEvent="false", CompletionBytes="0", ErrorCode="The operation completed successfully.
(0x0)" 12:35:28.192
95. NOTIFY_MODULE_END ModuleName="AspNetCoreModule", Notification="EXECUTE_REQUEST_HANDLER", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
96. NOTIFY_MODULE_START ModuleName="DynamicCompressionModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotification="true" 12:35:28.192
97. NOTIFY_MODULE_END ModuleName="DynamicCompressionModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
98. NOTIFY_MODULE_START ModuleName="RewriteModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotification="true" 12:35:28.192
99. NOTIFY_MODULE_END ModuleName="RewriteModule", Notification="RELEASE_REQUEST_STATE", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
100. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="UPDATE_REQUEST_CACHE", fIsPostNotification="false" 12:35:28.192
101. OUTPUT_CACHE_UPDATE_START CachePolicy="NO_CACHE", TimeToLive="0" 12:35:28.192
102. OUTPUT_CACHE_UPDATE_END Result="STATUS_NOT_OK" 12:35:28.192
103. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="UPDATE_REQUEST_CACHE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
104. NOTIFY_MODULE_START ModuleName="DynamicIpRestrictionModule", Notification="END_REQUEST", fIsPostNotification="false" 12:35:28.192
105. NOTIFY_MODULE_END ModuleName="DynamicIpRestrictionModule", Notification="END_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
106. NOTIFY_MODULE_START ModuleName="ProcessMonitoringModule", Notification="END_REQUEST", fIsPostNotification="false" 12:35:28.192
107. NOTIFY_MODULE_END ModuleName="ProcessMonitoringModule", Notification="END_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
108. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotification="false" 12:35:28.192
109. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
110. NOTIFY_MODULE_START ModuleName="ModSecurity IIS (32bits)", Notification="END_REQUEST", fIsPostNotification="true" 12:35:28.192
111. NOTIFY_MODULE_END ModuleName="ModSecurity IIS (32bits)", Notification="END_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
112. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotification="true" 12:35:28.192
113. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="END_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
114. NOTIFY_MODULE_START ModuleName="WebSocketMonitoringModule", Notification="END_REQUEST", fIsPostNotification="true" 12:35:28.192
115. NOTIFY_MODULE_END ModuleName="WebSocketMonitoringModule", Notification="END_REQUEST", fIsPostNotificationEvent="true", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
116. NOTIFY_MODULE_START ModuleName="ModSecurity IIS (32bits)", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
117. NOTIFY_MODULE_END ModuleName="ModSecurity IIS (32bits)", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
118. NOTIFY_MODULE_START ModuleName="ApplicationIdentificationModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
119. NOTIFY_MODULE_END ModuleName="ApplicationIdentificationModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
120. NOTIFY_MODULE_START ModuleName="ProcessMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
121. NOTIFY_MODULE_END ModuleName="ProcessMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
122. NOTIFY_MODULE_START ModuleName="iisnode", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
123. NOTIFY_MODULE_END ModuleName="iisnode", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
124. NOTIFY_MODULE_START ModuleName="HttpLoggingModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
125. NOTIFY_MODULE_END ModuleName="HttpLoggingModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
126. NOTIFY_MODULE_START ModuleName="IsapiModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
127. NOTIFY_MODULE_END ModuleName="IsapiModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
128. NOTIFY_MODULE_START ModuleName="RequestFilteringModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
129. NOTIFY_MODULE_END ModuleName="RequestFilteringModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
130. NOTIFY_MODULE_START ModuleName="ProtocolSupportModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
131. NOTIFY_MODULE_END ModuleName="ProtocolSupportModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
132. NOTIFY_MODULE_START ModuleName="IsapiFilterModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
133. NOTIFY_MODULE_END ModuleName="IsapiFilterModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
134. NOTIFY_MODULE_START ModuleName="DynamicCompressionModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
135. NOTIFY_MODULE_END ModuleName="DynamicCompressionModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
136. NOTIFY_MODULE_START ModuleName="HttpCacheModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
137. NOTIFY_MODULE_END ModuleName="HttpCacheModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
138. NOTIFY_MODULE_START ModuleName="RewriteModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
139. NOTIFY_MODULE_END ModuleName="RewriteModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
140. NOTIFY_MODULE_START ModuleName="CustomErrorModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
141. GENERAL_SEND_CUSTOM_ERROR HttpStatus="502", HttpSubStatus="3", FileNameOrURL="" 12:35:28.192
142. NOTIFY_MODULE_END ModuleName="CustomErrorModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
143. NOTIFY_MODULE_START ModuleName="DWASModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
144. NOTIFY_MODULE_END ModuleName="DWASModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
145. NOTIFY_MODULE_START ModuleName="WebSocketMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
146. NOTIFY_MODULE_END ModuleName="WebSocketMonitoringModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
147. NOTIFY_MODULE_START ModuleName="DynamicIpRestrictionModule", Notification="SEND_RESPONSE", fIsPostNotification="false" 12:35:28.192
148. NOTIFY_MODULE_END ModuleName="DynamicIpRestrictionModule", Notification="SEND_RESPONSE", fIsPostNotificationEvent="false", NotificationStatus="NOTIFICATION_CONTINUE" 12:35:28.192
149. HTTPSYS_CACHEABLE HttpsysCacheable="false", Reason="HANDLER_HTTPSYS_UNFRIENDLY", CachePolicy="NO_CACHE", TimeToLive="0" 12:35:28.192
150. GENERAL_FLUSH_RESPONSE_START 12:35:28.192
151. GENERAL_RESPONSE_HEADERS Headers="Content-Type: text/html
Server: Microsoft-IIS/8.0
X-FE-DATA: AppId:Unknown-StatusCode
X-Powered-By: ASP.NET
DWAS-Handler-Name: EXECUTE|502|3|0x2efd|CONFIG_SUCCESS|aspNetCore|100.88.116.47|\100.88.168.111\volume-17-default&ApiApp=0
" 12:35:28.192
152. GENERAL_RESPONSE_ENTITY_BUFFER Buffer="The specified CGI application encountered an error and the server terminated the process." 12:35:28.192
153. GENERAL_FLUSH_RESPONSE_END BytesSent="412", ErrorCode="The operation completed successfully.
(0x0)" 12:35:28.192
154. GENERAL_REQUEST_END BytesSent="412", BytesReceived="1470", HttpStatus="502", HttpSubStatus="3" 12:35:28.192`

@muratg

This comment has been minimized.

Show comment
Hide comment
@muratg

muratg May 23, 2017

Member

@zhangpeng-kooboo Are you able to reproduce locally? i.e. on your machine, run the app and apply the same load? It could well be an app scalability issue.

Member

muratg commented May 23, 2017

@zhangpeng-kooboo Are you able to reproduce locally? i.e. on your machine, run the app and apply the same load? It could well be an app scalability issue.

@halter73

This comment has been minimized.

Show comment
Hide comment
@halter73

halter73 May 23, 2017

Member

@zhangpeng-kooboo A 502.3 usually means that the web app took 2 minutes or longer to respond. Looking at the ASP.NET logs instead of the IIS logs, might help you track down which requests are taking too long to get responses and perhaps why.

Member

halter73 commented May 23, 2017

@zhangpeng-kooboo A 502.3 usually means that the web app took 2 minutes or longer to respond. Looking at the ASP.NET logs instead of the IIS logs, might help you track down which requests are taking too long to get responses and perhaps why.

@pan-wang

This comment has been minimized.

Show comment
Hide comment
@pan-wang

pan-wang May 23, 2017

Contributor

It is not the timeout case per the freb log. The Error code 2147954429 ( WININET_E_CANNOT_CONNECT
A connection with the server could not be established). Something is wrong with the backend process which did not pick up the connection (deadlock?). You need to check the Kestrel log.

Contributor

pan-wang commented May 23, 2017

It is not the timeout case per the freb log. The Error code 2147954429 ( WININET_E_CANNOT_CONNECT
A connection with the server could not be established). Something is wrong with the backend process which did not pick up the connection (deadlock?). You need to check the Kestrel log.

@1amirjalai

This comment has been minimized.

Show comment
Hide comment
@1amirjalai

1amirjalai May 28, 2017

im on 1.1.2 but still have this issue :(

1amirjalai commented May 28, 2017

im on 1.1.2 but still have this issue :(

@halter73

This comment has been minimized.

Show comment
Hide comment
@halter73

halter73 May 30, 2017

Member

@1amirjalai To clarify, this issue tracked one specific cause for 502.3 timeout errors: a deadlock in SocketOutput fixed in 1.0.3 and 1.1.1.

Any bug that causes a request to take two or more minutes to complete, either in application or framework code, can cause a 502.3. That's why I recommend looking an ASP.NET and application logs: to see exactly what operation is stalling.

Member

halter73 commented May 30, 2017

@1amirjalai To clarify, this issue tracked one specific cause for 502.3 timeout errors: a deadlock in SocketOutput fixed in 1.0.3 and 1.1.1.

Any bug that causes a request to take two or more minutes to complete, either in application or framework code, can cause a 502.3. That's why I recommend looking an ASP.NET and application logs: to see exactly what operation is stalling.

@zhangpengchen

This comment has been minimized.

Show comment
Hide comment
@zhangpengchen

zhangpengchen Jun 1, 2017

@halter73 Thks, seem our MongoDB could not handle so many requests at a very short period. I will double check more details on our side.

zhangpengchen commented Jun 1, 2017

@halter73 Thks, seem our MongoDB could not handle so many requests at a very short period. I will double check more details on our side.

@sabiland

This comment has been minimized.

Show comment
Hide comment
@sabiland

sabiland Jun 16, 2017

Damn in my case calls to Redis started to timeout (2 minutes) after 30 minutes...
That's why I was getting 502.3.

sabiland commented Jun 16, 2017

Damn in my case calls to Redis started to timeout (2 minutes) after 30 minutes...
That's why I was getting 502.3.

@cinaradem

This comment has been minimized.

Show comment
Hide comment
@cinaradem

cinaradem Nov 27, 2017

How do you know that it is welded on redis, the same problem occasionally gives 502.3 error.

cinaradem commented Nov 27, 2017

How do you know that it is welded on redis, the same problem occasionally gives 502.3 error.

@juggleking

This comment has been minimized.

Show comment
Hide comment
@juggleking

juggleking Feb 12, 2018

I could bypass the issue by putting my staticfileshosting in the startup on no-cache,no-store.

juggleking commented Feb 12, 2018

I could bypass the issue by putting my staticfileshosting in the startup on no-cache,no-store.

@PrzemekGawron

This comment has been minimized.

Show comment
Hide comment
@PrzemekGawron

PrzemekGawron May 10, 2018

In my case it appeared to be a really nasty bug in my code. I was getting 502.3 errors on random endpoints however after a while I noticed that the preceding request was always the same. After further investigation it appeared that some async code was not awaited so:

  • the request finished with 200 but
  • async code threw exception when trying to use already disposed scope dependency
  • there were no trace of exception anywhere (until I reproduced it under debugger)
  • the next request coming into api always fails with famous 502.3

I hope someone will find it useful.

PrzemekGawron commented May 10, 2018

In my case it appeared to be a really nasty bug in my code. I was getting 502.3 errors on random endpoints however after a while I noticed that the preceding request was always the same. After further investigation it appeared that some async code was not awaited so:

  • the request finished with 200 but
  • async code threw exception when trying to use already disposed scope dependency
  • there were no trace of exception anywhere (until I reproduced it under debugger)
  • the next request coming into api always fails with famous 502.3

I hope someone will find it useful.

@muratg

This comment has been minimized.

Show comment
Hide comment
@muratg
Member

muratg commented May 11, 2018

Thanks @PrzemekGawron!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment