A lesson learned by debugging Silverlight through ISA Server
Let this be a lesson to all of us, just because someone complains about an application level problem doesn't mean it's always above layer-5 ... (Jim Harrison).
Some time ago, I wanted to catch up on some TechEd 2007 videos published on the TechNet Spotlight site. However I was unable to play any Silverlight enabled video through an up-to-date ISA 2006 server as long as my IE 7 browser was configured as a Web Proxy client. Each time the Silverlight ActiveX control showed the following error message:
This clearly indicated a connection problem. So, my best bet was to take a look at the ISA logging to find out what was going on. I found quickly that each time that error message appeared, I saw the following entry in the ISA logging:
The HTTP Status Code 13 The Data is invalid suggested that the ISA server complained about the HTTP request, although I couldn't see anything wrong in those ISA log entries. So, I decided to take a network monitor trace on the ISA internal and external interface. For a detailed scenario layout, check out my ISA lab. Here is an excerpt of that trace:
In frame #27 you see the request for a particular TechEd session given by Steve Riley, sent by the client to the ISA server. In frame #32 that request is forwarded by the ISA server to the web site. In frame #73 the last packet of the response is received by the ISA server from the web site and in frame #83 it is forwarded by the ISA server to the client. Now, in frame #444 we see the request for the actual video belonging to that TechEd session, sent by the client to the ISA server. In frame #447 you see the response from the ISA server to the client with the HTTP Status Code 400 Bad Request ( The Data is invalid. ). Here are the details of that HTTP request in frame #444:
Because I couldn't find anything wrong, I mailed all the info I have to Jim Harrison to get a second opinion. At first sight, Jim couldn't find anything wrong either in those traces. After some further investigation and testing, Jim saw the light. In fact, the answer was there right in front of us, even in the ISA logging! To clearly show the cause of this problem, let reformat a little bit the exact same excerpt of the network monitor trace:
As you can see, we just added the column source and destination port number. That means they are very important in this case. In frame #27 you see the request is sent to TCP port 8080 on the ISA server internal interface. That's normal behavior because the Web Proxy service is listening on that specific port number. In frame #32 that request is forwarded by the ISA server to the web site on TCP port 80. That's also normal behavior. Now, in frame #444 the request is sent to TCP port 80 on the ISA server internal interface. Oops... that's definitely wrong because the Web Proxy service is listening on TCP port 8080! Since only auto discovery requests are allowed to the TCP port 80 listener (/wpad.dat, /wspad.dat, /array.dll?Get.Routing.Script, /array.dll?Get.Info.v[1|2|3]), ISA server rejects it with the HTTP Status Code 400 Bad Request ( The Data is invalid. ).
In other words, the Silverlight ActiveX control does only partial honor the proxy settings obtained (only the host name, not the TCP port number). This is clearly a bug in the Silverlight ActiveX control and is resolved from version 1.0.21115.00 onwards (at least as far as I can determine). Also, if we would have thoroughly inspected the ISA log entry, we would have seen that it said that that request was originating from 192.168.22.100 (the client) and was destined for 192.168.22.1:80 (the ISA internal interface on TCP port 80). Again, the answer was right in front of us, but we didn't realize it at first sight.