EventID 5566 Troubleshooting in InfoPath Form Services

This post has been snatched from the headlines of Premier Support. The names have been changed to protect the innocent. Now read on...

Imagine for a moment you're creating a new InfoPath form t recieve user input. Imagine furthermore that you're pre-populating this InfoPath form with information from a web service, in this case based on some sterling advice you found on a Microsoft blog. Further imagine that this InfoPath form works perfectly in the InfoPath client application itself, so you pat your own back and deploy it to SharePoint site for initial testing and feedback.

This is a very common scenario, and most people would never run into the problem my customer did, which was this: When SharePoint users who did not have the InfoPath client app installed came to use the form, it tried to open in InfoPath Forms Services, a wonderful feature of SharePoint. This is fine, the form was designed with this in mind and was set up to be a browser-compatible form. But this happened:

In addition, an Event with ID of 5566 was logged to the server's event log.

Interesting.

So what did we do here? Well, the first thing was to confirm that the form worked OK in the InfoPath client, which was confirmed. I then set about making sure the steps in the original blog article were valid and didn't contain anything weird. This I achieved by followig the steps myself in my repro environment. During this phase I observed exactly what was going on where for this to work correctly. Mine, of course, didn't work correctly right out of the box, and I discovered there are a  number of things that could potentially go wrong here.

Firstly, Internet Explorer Enhanced Security, which is enabled by default on Windows 2003 servers, may stymie your attempts to even get this working in the InfoPath client, as it did to me while developing on Windows 2003 Server. Create your form on a workstation or turn off IEES by removing it from Add/Remove Programs-> Windows Features

Second: On some Windows 2003 Sp1 installations, you may possibly run afoul of the LSA Local Loopback restriction. This is designed in order to prevent a class of attacks known as 'reflection attacks', but can, on occasion, have the unfortunate consequence of denying access to code which tries to connect back to the same server to, say, run a web service. There is a KB article on this, which can be used to eliminate this angle from the enquiry.

OK, so having eliminated those, we found that my local repro worked fine in both Office Client and IPFS, but the original problem at the customer's end was still extant.

At this point, we went to the logs. Having set this up myself, I had a set of IIS logs which reflected correct behaviour. I obtained the customer's logs for a similar period and managed to track down the requests in question - which was easy enough to do. IPFS uses /_layouts/FormResource.aspx to render forms and in our scenario I'd expect to see a logged line closely following this which would go to UserProfileService.asmx to do the info retrieval so that IPFS could pre-populate the form.

What we saw there was of interest.

Expected behaviour for a secured web service such as this one would be one (or two) HTTP 401 responses, then an HTTP 200 response signifying sucess. We saw three 401 responses in a row, and no 200. So IPFS was calling the Web Service, but being denied access.

2008-02-01 02:10:33 W3SVC533812677 10.254.72.102 POST /_vti_bin/UserProfileService.asmx - 80 - 10.254.76.37 InfoPathDA 401 2 21480742542008-02-01 02:10:33 W3SVC533812677 10.254.72.102 POST /_vti_bin/UserProfileService.asmx - 80 - 10.254.76.37 InfoPathDA 401 1 02008-02-01 02:10:33 W3SVC533812677 10.254.72.102 POST /_vti_bin/UserProfileService.asmx - 80 - 10.254.76.37 InfoPathDA 401 1 2148074248

More interestingly, from our point of view, the c-ip or Client IP field did not show the IP address of this server. In my good repro, the request came from 127.0.0.1, the local loopback address. The customer's log showed that the request to the web service was coming from a proxy server.

Light bulbs flashed on in our heads - the call out to the proxy shouldn't have been happening. To solve this, we need to stop IPFS using the proxy. INA quick consultation with the customer revealed that, why yes, we are using a proxy - some custom web parts need to call out to the internet and grab data, so there's a proxy configured in web.config for the MOSS site. Like this:

  <system.net>    <defaultProxy>      <proxy usesystemdefault="false" proxyaddress="https://xx.xx.xx.xx:8080/" bypassonlocal="true" />    </defaultProxy>  </system.net>

As you can see, bypass on local is enabled. So why wasn't IPFS bypassing the proxy? The answer lay in the URL used to access MOSS, which in this case was the dot-separated local address moss.company.local. WinHTTP sees this as an FQDN, and doesn't qualify it as local, and WinHTTP does our web service request. The finishing line was in sight. All that remained was to check this MSDN article on enabling bypass lists in web.config or machine.config, and our troubles were over.

  <system.net>    <defaultProxy>      <proxy usesystemdefault="false" proxyaddress="https://xx.xx.xx.xx:8080/" bypassonlocal="true" />      <bypasslist>         <add address="moss.company.local" />      </bypasslist>    </defaultProxy>  </system.net>

IPFS now works like a charm at the customer's site and serenity has returned to the IT department, just the way we like it.

Incidentally, the <bypasslist> element allows you to use Regular Expression to specify addresses, so you can exclude whole ranges at will - quite neat.