IIS 7 and Above
Application Request Routing (ARR)
Any way to log ARR_SERVER_ROUTED Server in ASP.NET
Last post Jun 18, 2018 07:29 AM by deepakpanchal10
Jun 01, 2018 09:29 PM|anigo|LINK
We see a lot of 502.3 errors which is indicating that we are failing to receive a valid response from the server that the ARR routed to. To improve our telemetry we would like to log the ServerName that the ARR tried to connect to for a given request.
We have a custom httpmodule that fires for every request routed by the arr to the server farms. Looking at the ARR_SERVER_ROUTED event in the FREB traces i see a Server field and i would like to access it inside the httpmodule. Is this field exposed anywhere
as a Server Variable for us to log? I am going to setup a test page to log all server variables to find the answer but i was hoping if someone has already tried it and has a recommendation for us.
Example Log Entry for ARR_SERVER_ROUTED
RoutingReason="LoadBalancing", Server="192.168.0.216", State="Active", TotalRequests="3", FailedRequests="2", CurrentRequests="1", BytesSent="648", BytesReceived="0", ResponseTime="15225" 16:50:21.033
Jun 01, 2018 11:46 PM|Rovastar|LINK
I don't know about writing your own modules (and to be honest I doubt you will get much help to this here for module writing) but often you can work out what is happening and why you are getting your 502.3's
The server the request is going to is in the IIS logs.
502.3 errors are common on ARR. They occur when the request doesn't come back (or there are no available servers). Requests that take too long timeout can be a cause.
Really you should be able to work put what is happening from the backend server. You know the URL and timestamp and the backend server on the ARR. Then you can look to see what happened on there. The request in your case looks like it was routed through.
Maybe look at how long the request took on the backend and align that with your proxy timing on the ARR for that farm.
Jun 02, 2018 12:30 AM|anigo|LINK
Thanks for the response!
You know the URL and timestamp and the backend server on the ARR
I don't see backend server logged in the IIS logs, infact that's the question how do i log it anywhere at all outside FREB.
Jun 02, 2018 02:49 AM|Rovastar|LINK
Isn't it part of the query string in any request?
2018-05-31 13:00:00 W3SVC1 MYARR1 10.10.10.1 GET /js/mypage.main.js X-ARR-CACHE-HIT=0&SERVER-ROUTED=10.10.11.101&X-ARR-LOG-ID=64937363-01e6-4f80-b613-d50330c2b5da&SERVER-STATUS=200 443 - 22.214.171.124 HTTP/1.1 Mozilla/5.0+(iPhone;+CPU+iPhone+OS+11_3_1+like+Mac+OS+X)+AppleWebKit/604.1.34+(KHTML,+like+Gecko)+CriOS/66.0.3359.122+Mobile/15E302+Safari/604.1
ARRAffinityMyfarm1=39b4697431bdd322bcda2953247853ec5dacf9fc8096977714d66d11729622 https://www.mysite.com/login.asp www.mysite..com 200 0 0 39071 707 359
where all the IIS fields are logged and this is on the ARR server
Jun 02, 2018 03:33 PM|anigo|LINK
Jun 03, 2018 02:13 PM|Rovastar|LINK
I don't have anything special. There are no special rewrite rules or custom logging.
I just presumed all setups see this. Do you see the X-ARR-CACHE-HIT and X-ARR-LOG-ID?
The only thing I can think of is that I don't use the stupid wizard for creating the URLrewrite rules when setting up my farms. Maybe it is yet another reason to not use the wizard....
Maybe I'll have a dig around to see why.
Jun 04, 2018 03:27 AM|deepakpanchal10|LINK
I try to find the solution to log the server name in custom http module.
But I did not get any information to doing the same.
Further, You can try to use IIS logs to narrow down the issue.
You will find one example in link below.
502.3 Bad Gateway “The operation timed out” with IIS Application Request Routing(ARR)
Jun 12, 2018 11:27 PM|anigo|LINK
Deepak, yes i am aware of that but the problem is that it is too cumbersome to collect these trace files in a common place to analyze what went wrong. We have custom httpmodule for tracing the failures and would like to expose the information there. Looks
like it is not supported
Jun 13, 2018 04:20 AM|anigo|LINK
I found it, turns out if you enable logging of query string in the logging configuration on the arr box, server-routed then shows up in the IIS logs as a query string, that's why you saw it on your end. I don't think it is possible to read it inside the
modules. it is very limited and constrained.
Jun 18, 2018 07:29 AM|deepakpanchal10|LINK
I again try to make a search to find any way to log server name but at present it looks like it is not possible to achieve the same.
In future, I will try to inform you, If I find anything that can solve your issue.