Locking up main thread at times

[iwasrobbed]

Doesn't happen often, but occasionally sendTimeQuery locks up the main thread in the beginReceiving for as much as 10-15 seconds:

- (void) sendTimeQuery {
    NSError *   error = nil;

    [socket sendData:[self createPacket] toHost:server port:123 withTimeout:2.0 tag:0];

    if(![socket beginReceiving:&error]) {
        NTP_Logging(@"Unable to start listening on socket for [%@] due to error [%@]", server, error);
        return;
    }
}

Breaking on this, it seems it's getting stuck in GCSAsyncUdpSocket's on dispatch_sync(socketQueue, block);

Any insight into what could be going wrong? Ideally, none of this should ever be touching the main thread.

[gavineadie]

Curious .. as you say, "none of this should ever be touching the main thread." Can you quantify the "Doesn't happen often, but occasionally" frequency? I'll check the AsyncUdpSocket code -- I've not read the documentation for a few years!

[gavineadie]

If you add the "CocoaLumberjack" code to your project, set "#if 1" around line 32 in GCDAsyncUdpSocket.h, and add "#import "DDTTYLogger.h" in your app delegate and #import "DDTTYLogger.h" in your "didFinishLaunchingWithOptions" method, you'll detailed tracing inside the GCDAsyncUdpSocket code.

Meanwhile, I'm reading code and documentation ..

[iwasrobbed]

Thanks for the quick reply, Gavin! Sorry for the vagueness in my original post.

Out of the 3 weeks we've been using the library, this has only happened a couple of times today within a minute or two of each other while I was on the metro/subway, so I'm guessing it's network related and something I'll try replicating using the "network link conditioner" debugging tool on device.

I guess the larger concern was the fact that the GCSAsyncUdpSocket class was using a dispatch_sync which locks the main thread until it's finished. A more normal pattern would be:

dispatch_async(dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_HIGH, 0), ^{
    // Do some work here in the background thread

    // Once we have something to report to the UI, dispatch it back to the main thread
    dispatch_async(dispatch_get_main_queue(), ^{
        // Update UI or call completion/error block
    });
});

[gavineadie]

D’you think we should bump this up to the CocoaAsynch project, Rob ?

On Apr 27, 2015, at 4:00 PM, rob phillips notifications@github.com wrote:

I guess the larger concern was the fact that the GCSAsyncUdpSocket class was using a dispatch_sync which locks the main thread until it's finished. A more normal pattern would be:

[iwasrobbed]

For sure, just wanted to make you aware of it since it also impacts all of the users of this library unfortunately

[iwasrobbed]

Just to update: this seems to be happening a couple of times each day during testing and we are even receiving failed to scene-update in time crashes from the main thread hanging on this. Since CocoaAsyncSocket appears to be abandoned, we are going to remove this for now instead of trying to fix.

[gavineadie]

Hm .. If it is worth maintaining a time capability like ios-ntp, I could look at using AFNetworking instead of CocoaAsyncSocket as a UDP layer. I use its TCP services in other work, but haven't looked at how much the UDP methods stay off the main-thread.

[gavineadie]

AFNetworking won't handle connectionless networking, and I'm not going to adopt the CocoaAsyncSocket code, so I'm not sure what to do about this. Thinking ..

[iwasrobbed]

You may want to look into: https://github.com/square/SocketRocket

[gavineadie]

Will do .. meanwhile:

In the "initWithServerName" method of "NetAssociation" the socket to be used is given the "dispatch_get_main_queue()" as its "delegateQueue:". This seems likely to interfere with the main thread's work, so I changed that line to:

socket = [[GCDAsyncUdpSocket alloc] initWithDelegate:self
   delegateQueue:dispatch_queue_create("com.ramsaycons.ios-ntp", DISPATCH_QUEUE_SERIAL)];

When I run the ios-ntp-app with that change[1] I see that the times reported by the various servers are less dispersed (much less!). I'm not familiar enough with GCD, or CocoaAsyncSocket, to know if I'm doing a Good Thing™ but you've got a test case I can reproduce and I'm wondering if you could try this (if you think it makes sense)?

Doing this has modified the 'instant time' derivation from immediate to several seconds so, meanwhile, I'll explore the reason for that. I suspect the slowdown of the hit rate on the time servers is involved ..

[1] The "delegateQueue:" could be different for each "NetAssociation" too, I guess.