HttpWebRequest .GetResponse throws WebException 'The operation has timed out'

Question

I've been working on a project which makes use of an RTC API and forms authentication. I've hit a bit of bizarre behaviour and I just can't figure this one out.

The scenario that has played out to date is that I can successfully run this project locally end to end. That is, this specific piece of code can:

1. Contact the remote server and successfully authenticate
2. After authentication I'm able to pass XML to update a ticket in RTC

The problem starts when I publish to our IIS (7.5) server. All works fine right up until the last .GetResponse call which uses a PUT method to pass my XML to update the ticket in RTC. I keep getting 'The operation has timed out'.

I've spent literally days trying to figure this one out doing all manner of things but nothing has proved useful.

As a test I changed the PUT method on the second call to a GET. And it works! If I used a PUT with the .AllowAutoRedirect = false it works in that I get a response back, but then nothing happens on the RTC side so the request is clearly being ignored. I also noticed that the status being returned is marked as 'Found' instead of 'OK'.

Some people thought at this stage perhaps it was a lack of connectivity between the remote server and the web server. This wouldn't be the case as authentication works and this happens against the same server. I have also manually passed the XML / PUT call using the RESTClient on the web server which was accepted fine.

I just can't understand why it works end to end when running locally, but plays up once deployed to IIS?

I tried using log tracing and I'm not entirely sure if I'm getting anything useful from it. It might be totally unrelated but I can see this in the log that is generated on the IIS server:

<EventData>
  <Data Name="ContextId">{00000000-0000-0000-12AF-0080000000F8}</Data>
  <Data Name="ModuleName">ManagedPipelineHandler</Data>
  <Data Name="Notification">128</Data>
  <Data Name="HttpStatus">500</Data>
  <Data Name="HttpReason">Internal Server Error</Data>
  <Data Name="HttpSubStatus">0</Data>
  <Data Name="ErrorCode">0</Data>
  <Data Name="ConfigExceptionInfo"></Data>
 </EventData>

As I say, I'm not sure if this is even related to the problem I'm having, but rather than ignore it I thought I'd share.

Code that forms the call (excuse the standard of coding, it's work in progress and got messy trying out different things to fix this problem)

  //Setup webrequest
                CookieContainer _cookies = new CookieContainer();
                HttpWebRequest request = (HttpWebRequest)WebRequest.Create(getPath);
                var test44 = test4.ToString();

                request.CookieContainer = _cookies;
                request.ContentType = "application/rdf+xml";
                request.Accept = "application/rdf+xml";
                request.Method = "PUT";
                request.AllowAutoRedirect = true;
                request.AllowWriteStreamBuffering = true;
                request.Timeout = 40000;


                byte[] bytes = Encoding.ASCII.GetBytes(test44);
                request.ContentLength = bytes.Length;
                Stream dataStream = request.GetRequestStream();

                dataStream.Write(bytes, 0, bytes.Length);
                dataStream.Close();



                //Pass request
                logger.Info("Made it up to start of RTC request for secure document.");
                using (HttpWebResponse getrespn = requestSecureDocument(request, "https://myserver:9100/jazz", "username", "pass", test44))
                {

                    //Stream ReceiveStream = getrespn.GetResponseStream();
                    // Encoding encode = System.Text.Encoding.GetEncoding("utf-8");
                    //StreamReader readStream = new StreamReader(ReceiveStream);
                    //response = readStream.ReadToEnd();


                    getrespn.Close();
                }

The segment of code which interacts with the RTC server (based on the example from: https://nkumar83.wordpress.com/2013/06/13/consuming-rtc-rational-team-concert-oslc-apis-using-c-post-1-authentication/ with my own tweaks):

 public static HttpWebResponse requestSecureDocument(HttpWebRequest _requestItem, string _rtcServerURL, string _userName, string _password, string passXml)
    {
        try
        {
            //FormBasedAuth Step 1: Request the resource 
            HttpWebRequest _request = (HttpWebRequest)WebRequest.Create(_requestItem.RequestUri);
            _request.CookieContainer = _requestItem.CookieContainer;

            //store the response in _docResponse variable
            HttpWebResponse _docResponse = (HttpWebResponse)_request.GetResponse();

            //HttpStatusCode.OK indicates that the request succeeded
            if (_docResponse.StatusCode == HttpStatusCode.OK)
            {
                //X-com-ibm-team... header signifies form based authentication is being used
                string _rtcAuthHeader = _docResponse.Headers["X-com-ibm-team-repository-web-auth-msg"];
                if ((_rtcAuthHeader != null) && _rtcAuthHeader.Equals("authrequired"))
                {
                    _docResponse.GetResponseStream().Flush();
                    _docResponse.Close();

                    //Prepare form for authentication 

                    HttpWebRequest _formPost = (HttpWebRequest)WebRequest.Create(_rtcServerURL + "/j_security_check");


                    _formPost.Method = "POST";
                    _formPost.Timeout = 30000;
                    _formPost.CookieContainer = _request.CookieContainer;
                    _formPost.Accept = "text/xml";
                    _formPost.ContentType = "application/x-www-form-urlencoded";



                    string _authString = "j_username=" + _userName + "&j_password=" + _password;
                    Byte[] _outBuffer = Encoding.UTF8.GetBytes(_authString);
                    _formPost.ContentLength = _outBuffer.Length;
                    Stream _str = _formPost.GetRequestStream();
                    _str.Write(_outBuffer, 0, _outBuffer.Length);
                    _str.Close();


                    //FormBasedAuth Step 2: Submit the login form and get response

                    HttpWebResponse _formResponse = (HttpWebResponse)_formPost.GetResponse();

                    _rtcAuthHeader = _formResponse.Headers["X-com.ibm-team.repository-web-auth-msg"];

                    //Check if auth failed
                    if ((_rtcAuthHeader != null) && _rtcAuthHeader.Equals("authfailed"))
                    {
                        //auth fialed
                        var fail = "";
                    }
                    else
                    {
                        //login successful

                        //FormBasedAuth Step 3: Resend the request for the protected resource
                        _formResponse.GetResponseStream().Flush();
                        _formResponse.Close();

                       using (HttpWebResponse getresp = (HttpWebResponse)_requestItem.GetResponse()) *** THIS IS TH LINE WHICH THROWS THE EXCEPTION ***
                       {
                           return getresp;
                       }
                    }
                }
            }
            return _docResponse;

        }
        catch (WebException e)
        {
             var filePath = AppDomain.CurrentDomain.GetData("DataDirectory") + @"/trapA.xml";
                    using (StreamWriter writer = new StreamWriter(filePath, true))
                    {
                        writer.WriteLine("Message: Failed to trigger getresponse successfully: " + e);
                    }

        }
        return null;
    }

Hope someone out there can help :o)

Answer 1

Well I'm pleased to say I've finally got to the bottom of this one. Turns out the problem wasn't anything to do with IIS and does actually work when published 'if' I'm not using the RTC client to make updates to a ticket.

The short story is that our RTC client uses a custom script to post out to our web api. However the RTC client appears to put a record lock on the ticket your trying to update which is persisted until a response from our API is provided. Of course this can't happen because part of the response is to confirm if the update was successful which can't happen due to the lock made by the RTC client.

The solution was to get the call in from RTC closed as quickly as possible. So the segment of code which authenticates and calls back out to RTC to make updates is now wrapped around with some new code to create a new thread. This has allowed the connection to be closed in about 5 seconds, all the while our app continues to make the necessary calls to complete the transaction.

Thread t = new Thread(() = > {
//code here

}