My new company is using something called cordova - not a very cool one but serves the purpose. The native experience of an app cannot be matched by cordova, not to mention the heavy javascript framework we are using.

One big challenge we are facing is how to debug the client-server issues. I come up with an idea of intercepting all the HTTP(s) calls by using a custom NSURLProtocol implementation such that I can print all the http request and response into log file. This sounds like a simple stupid idea but it works generally good until when we start to send POST request to server in the UIWebView. The time required to post anything to server is almost exact 10 seconds. Also, the request will be considered failing from the javascript perspective. This breaks most of our features and one of my engineer worked till 2AM then figure out my change is causing the problem and I have to back out my change.

I started to investigate the problem. It just doesn’t make sense. I added a lot of logs to the custom NSURLProtocol class, which immediately I noticed a lot of strange behaviors like the canInitWithRequest method is called many more times than others, and the pattern is also different when the POST is sent - it actually kind of create the request twice. I carefully examine the object IDs of all the request objects etc but didn’t find a clue. The startLoading method, however, is called only once. After that, there is exact 10 seconds delay before the connection:didReceiveResponse delegate method is called.

The bad part about iOS is that it is pretty hard to debug this kind of problem. You don’t have the source code of the system so you have no idea what is going on. I cannot even have a nice stack with a breakpoint. On the other hand, it seems the iOS networking library is fully asynchronous so you don’t see a socket read anywhere in any thread (unlike android, which usually one of the thread will be on socket operation for apache http client or URLConnection).

More carefully google search indicates that the multiple call to canInitWithRequest should be fine. It is the way the URL loading system works and it is trying to determine what is the best way to handle the request. It must be something wrong with the special POST method we were using. I decided to create a simple application with a simple cordova application to reproduce and isolate the problem. The funny thing is, with the simplified application, the problem disappears.

I only get a clue during my dream last night. Our javascript must be using some strange code, like, synchronous HTTP request. Tested an HTTP request with sync status set - yes, problem reproduced. The request cost exactly 10.134 seconds while the 134ms is the real request time.

I have not much idea about how apple handle this 10 seconds timeout. I only remembered some strange comment from one of apple’s own sample code of " CustomHTTPProtocol". The comment said:


// Calculate our effective run loop modes.  In some circumstances (yes I'm looking at
// you UIWebView!) we can be called from a non-standard thread which then runs a
// non-standard run loop mode waiting for the request to finish.  We detect this
// non-standard mode and add it to the list of run loop modes we use when scheduling
// our callbacks.  Exciting huh?
//
// For debugging purposes the non-standard mode is "WebCoreSynchronousLoaderRunLoopMode"
// but it's better not to hard-code that here.

I put the exact same code as this example did and it fixes the problem. Basically, one should not run the NSURLConnection on the WebCoreSynchronousLoaderRunLoopMode. I may need dig further into this NSRunLoop and scheduleInRunLoop:forMode method, but for now, I’m satisfied. The big surprise is this problem has not been fixed by apple till today’s iOS 7.1.