NSURLConnection timing out

Question

I've been having intermittent problems with NSURLConnection requests timing out in our iPhone app. It seems to be occurring more of late. Once it enters this state, it stays in that state. The only resolution seems to be killing the app and restarting it.

Observations:

• The core code that executes the NSURLConnection has not changed (except for some custom user-agent code recently added).
• Have yet to find a reproducible case, but timeouts seem to occur after the app has been sitting in the background for a while, particularly if running on 3G (no WiFi).
• Apache on server is logging no requests from client while it's experiencing these timeouts.
• Some indications that other apps, like Mail and Safari are affected (i.e., experiencing timeouts), although not consistently.
• 3G coverage is solid where I'm at, not to rule out a transitory issue triggering the problem (assumed not likely).
• All requests are going to our own API server, and are restful POST requests.
• We use our own NSTimer-based timeout, due to the issues with timeoutInterval and POST requests. I've tried playing around with increasing the timeout value -- problem still occurs.

Other miscellaneous stuff:

• App was recently converted to ARC.
• Running app under iOS 5.1.1.
• App uses latest versions of UrbanAirship, TestFlight and Flurry SDKs.
• Also using ARC branch of TouchXML to parse responses.

As you can see below, the code runs on the main thread. I assumed something is blocking on that thread, but the stack traces I see when suspending the app suggest the main thread is fine. I take it that NSURLConnection is using its own thread and that must be blocked.

#define relnil(v) (v = nil)

- (id) initWebRequestController
{
    self = [super init];
    if (self)
    {
        //setup a queue to execute all web requests on synchronously
        dispatch_queue_t aQueue = dispatch_queue_create("com.myapp.webqueue", NULL);
        [self setWebQueue:aQueue];
    }
    return self;
}

- (void) getStuffFromServer
{
    dispatch_queue_t aQueue = dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_DEFAULT, 0);
    dispatch_async(aQueue, ^{
        dispatch_sync([self webQueue], ^{            
            error_block_t errorBlock = ^(MyAppAPIStatusCode code, NSError * error){
                dispatch_async(dispatch_get_main_queue(), ^{
                    [[self delegate] webRequestController:self didEncounterErrorGettingPointsWithCode:code andOptionalError:error];
                });
            };

            parsing_block_t parsingBlock = ^(CXMLDocument * doc, error_block_t errorHandler){
                NSError * error = nil;

                CXMLNode * node = [doc nodeForXPath:@"apiResult/data/stuff" error:&error];
                if (error || !node) {
                    errorHandler(MyAppAPIStatusCodeFailedToParse, error);
                }
                else {
                    stuffString = [node stringValue];
                }

                if (stuffString) {
                    dispatch_async(dispatch_get_main_queue(), ^{
                        [[self delegate] webRequestController:self didFinishGettingStuff:stuffString];
                    });
                }
                else {
                    errorHandler(MyAppAPIStatusCodeFailedToParse, error);
                }
            };

            NSURL * url = [[NSURL alloc] initWithString:[NSString stringWithFormat:MyAppURLFormat_MyAppAPI, @"stuff/getStuff"]];

            NSMutableURLRequest * urlRequest = [[NSMutableURLRequest alloc] initWithURL:url];
            NSMutableDictionary * postDictionary = [NSMutableDictionary dictionaryWithObjectsAndKeys:
                                                    [[NSUserDefaults standardUserDefaults] objectForKey:MyAppKey_Token], @"token",
                                                    origin, @"from",
                                                    destination, @"to",
                                                    transitTypeString, @"mode",
                                                    time, @"time",
                                                    nil];

            NSString * postString = [WebRequestController httpBodyFromDictionary:postDictionary];
            [urlRequest setHTTPBody:[postString dataUsingEncoding:NSUTF8StringEncoding]];
            [urlRequest setHTTPMethod:@"POST"];

            if (urlRequest)
            {
                [self performAPIRequest:urlRequest withRequestParameters:postDictionary parsing:parsingBlock errorHandling:errorBlock timeout:kTimeout_Standard];
            }
            else
            {
                errorBlock(MyAppAPIStatusCodeInvalidRequest, nil);
            }

            relnil(url);
            relnil(urlRequest);
        });
    });
}

- (void) performAPIRequest: (NSMutableURLRequest *) request
     withRequestParameters: (NSMutableDictionary *) requestParameters
                   parsing: (parsing_block_t) parsingBlock 
             errorHandling: (error_block_t) errorBlock
                   timeout: (NSTimeInterval) timeout
{
    NSAssert([self apiConnection] == nil, @"Requesting before previous request has completed");

    NSString * postString = [WebRequestController httpBodyFromDictionary:requestParameters];
    [request setHTTPBody:[postString dataUsingEncoding:NSUTF8StringEncoding]];

    NSString * erVersion = [[[NSBundle mainBundle] infoDictionary] objectForKey:@"CFBundleShortVersionString"];
    NSString * erBuildVersion = [[[NSBundle mainBundle] infoDictionary] objectForKey:@"CFBundleVersion"];
    if ([erBuildVersion isEqualToString:erVersion] || [erBuildVersion isEqualToString:@""]) {
        erBuildVersion = @"";
    } else {
        erBuildVersion = [NSString stringWithFormat:@"(%@)", erBuildVersion];
    }
    NSString * iosVersion = [[UIDevice currentDevice] systemVersion];
    NSString * userAgent = [NSString stringWithFormat:@"MyApp/%@%@ iOS/%@", erVersion, erBuildVersion, iosVersion];
    [request setValue:userAgent forHTTPHeaderField:@"User-Agent"];

    [request setTimeoutInterval:(timeout-3.0f)];

    dispatch_sync(dispatch_get_main_queue(), ^{
        NSURLConnection * urlConnection = [[NSURLConnection alloc] initWithRequest:request delegate:self startImmediately:NO];

        if (urlConnection)
        {
            [self setApiConnection:urlConnection];

            requestParseBlock = [parsingBlock copy];
            requestErrorBlock = [errorBlock copy];

            NSMutableData * aMutableData = [[NSMutableData alloc] init];
            [self setReceivedData:aMutableData];
            relnil(aMutableData);

            [urlConnection scheduleInRunLoop:[NSRunLoop currentRunLoop] forMode:NSRunLoopCommonModes];

            [urlConnection start];
            relnil(urlConnection);

            NSTimer * aTimer = [NSTimer scheduledTimerWithTimeInterval:timeout target:self selector:@selector(timeoutTimerFired:) userInfo:nil repeats:NO];
            [self setTimeoutTimer:aTimer];
        }
        else
        {
            errorBlock(MyAppAPIStatusCodeInvalidRequest, nil);
        }
    });

    //we want the web requests to appear synchronous from outside of this interface
    while ([self apiConnection] != nil)
    {
        [NSThread sleepForTimeInterval:.25];
    }
}

- (void) timeoutTimerFired: (NSTimer *) timer
{
    [[self apiConnection] cancel];

    relnil(apiConnection);
    relnil(receivedData);

    [self requestErrorBlock](MyAppAPIStatusCodeTimeout, nil);

    requestErrorBlock = nil;
    requestParseBlock = nil;
}


- (void)connection:(NSURLConnection *)connection didFailWithError:(NSError *)error
{    
    [self requestErrorBlock](MyAppAPIStatusCodeFailedToConnect, error);

    relnil(apiConnection);
    relnil(receivedData);
    [[self timeoutTimer] invalidate];
    relnil(timeoutTimer);
    requestErrorBlock = nil;
    requestParseBlock = nil;
}

- (void)connection:(NSURLConnection *)connection didReceiveResponse:(NSURLResponse *)response
{
    [receivedData setLength:0];
}

- (void)connection:(NSURLConnection *)connection didReceiveData:(NSData *)data
{
    [receivedData appendData:data];
}

- (void)connectionDidFinishLoading:(NSURLConnection *)connection
{    
    MyAppAPIStatusCode status = MyAppAPIStatusCodeFailedToParse;

    CXMLDocument *doc = [[self receivedData] length] ? [[CXMLDocument alloc] initWithData:[self receivedData] options:0 error:nil] : nil;

    DLog(@"response:\n%@", doc);

    if (doc)
    {
        NSError * error = nil;
        CXMLNode * node = [doc nodeForXPath:@"apiResult/result" error:&error];
        if (!error && node)
        {
            status = [[node stringValue] intValue];

            if (status == MyAppAPIStatusCodeOK)
            {
                [self requestParseBlock](doc, [self requestErrorBlock]);
            }
            else if (status == MyAppAPIStatusCodeTokenMissingInvalidOrExpired)
            {
                [Definitions setToken:nil];

                [self requestMyAppTokenIfNotPresent];

                [Definitions logout];

                dispatch_async(dispatch_get_main_queue(), ^{
                    [[self delegate] webRequestControllerDidRecivedExpiredTokenError:self];
                });
            }
            else
            {
                [self requestErrorBlock](status, nil);                
            }
        }
        else
        {
            [self requestErrorBlock](status, nil);
        }
    }
    else
    {
        status = MyAppAPIStatusCodeUnexpectedResponse;
        [self requestErrorBlock](status, nil);
    }
    relnil(doc);

    relnil(apiConnection);
    relnil(receivedData);
    [[self timeoutTimer] invalidate];
    relnil(timeoutTimer);
    requestErrorBlock = nil;
    requestParseBlock = nil;
}

URLs below are some screenshots of the queues/threads when the app was in the problematic state. Note, I believe thread 10 is related to the cancel performed on the previous timeout, although the mutex wait is curious. Also, the bit in thread 22 about Flurry does not consistently appear when experiencing the problem on other occasions.

Stack trace screenshots:

http://img27.imageshack.us/img27/5614/screenshot20120529at236.png http://img198.imageshack.us/img198/5614/screenshot20120529at236.png

Perhaps I'm overlooking something obviously wrong in those traces, as I'm relatively new to iOS/Apple development.

All of this would be much simpler to solve if I had the source for NSURLConnection and related code, but such as it is, I'm taking stabs in the dark at this point.

Answer 1

Removing the TestFlight 1.0 SDK seemed to fix the problem. TestFlight also confirmed that they're working on a fix. Given that it's been over a month since the bug was originally confirmed by others, I wonder how close we are to getting a fix.