Improve reliability of communication between test and the tunneled app

Author: Seweryn Plazuk

Sources/SBTUITestTunnelClient/SBTUITestTunnelClient.m

@@ -79,6 +79,10 @@ - (void)resetInternalState
     self.connected = NO;
     self.connectionPort = 0;
     self.connectionTimeout = SBTUITunneledApplicationDefaultTimeout;
+
+    [self.ipcConnection invalidate];
+    self.ipcConnection = nil;
+    self.ipcProxy = nil;
 }
 
 - (void)shutDownWithError:(NSError *)error
@@ -159,20 +163,24 @@ - (void)launchTunnelWithStartupBlock:(void (^)(void))startupBlock
         self.application.launchEnvironment = launchEnvironment;
 
         __weak typeof(self)weakSelf = self;
-        // Start polling the server with the choosen port
         dispatch_after(dispatch_time(DISPATCH_TIME_NOW, (int64_t)(2.0 * NSEC_PER_SEC)), dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_DEFAULT, 0), ^{
             [weakSelf waitForConnection];
-            NSLog(@"[SBTUITestTunnel] HTTP tunnel did connect after, %fs", CFAbsoluteTimeGetCurrent() - self.launchStart);
-            
+
+            if (!weakSelf || weakSelf.connectionPort == 0) {
+                return;
+            }
+
+            NSLog(@"[SBTUITestTunnel] HTTP tunnel did connect after, %fs", CFAbsoluteTimeGetCurrent() - weakSelf.launchStart);
+
             dispatch_async(dispatch_get_main_queue(), ^{
                 weakSelf.connected = YES;
                 if (weakSelf.startupBlock) {
                     weakSelf.startupBlock();
                     NSLog(@"[SBTUITestTunnel] Did perform startupBlock");
                 }
-                
+
                 NSAssert([NSThread isMainThread], @"We synch on main thread");
-                weakSelf.startupCompleted = [[self sendSynchronousRequestWithPath:SBTUITunneledApplicationCommandStartupCommandsCompleted params:@{}] isEqualToString:@"YES"];
+                weakSelf.startupCompleted = [[weakSelf sendSynchronousRequestWithPath:SBTUITunneledApplicationCommandStartupCommandsCompleted params:@{}] isEqualToString:@"YES"];
             });
         });
     }
@@ -1131,8 +1139,10 @@ - (NSString *)sendSynchronousRequestWithPath:(NSString *)path params:(NSDictiona
         dispatch_semaphore_signal(synchRequestSemaphore);
     }] resume];
 
-    if (dispatch_semaphore_wait(synchRequestSemaphore, dispatch_time(DISPATCH_TIME_NOW, (int64_t)(SBTUITunneledApplicationDefaultTimeout * NSEC_PER_SEC))) != 0) {}
-    
+    if (dispatch_semaphore_wait(synchRequestSemaphore, dispatch_time(DISPATCH_TIME_NOW, (int64_t)(SBTUITunneledApplicationDefaultTimeout * NSEC_PER_SEC))) != 0) {
+        NSLog(@"[SBTUITestTunnel] HTTP request timeout after %ds for %@", (int)SBTUITunneledApplicationDefaultTimeout, request.URL);
+    }
+
     return responseId;
 }
 

Sources/SBTUITestTunnelCommon/DetoxIPC/DTXIPCConnection-Private.h

@@ -10,7 +10,8 @@
 
 @protocol _DTXIPCImpl <NSObject>
 
-- (oneway void)_slaveDidConnectWithName:(NSString*)slaveServiceName;
+// Intentionally synchronous (not oneway): caller must block until master sets _otherConnection.
+- (void)_slaveDidConnectWithName:(NSString*)slaveServiceName;
 - (oneway void)_invokeFromRemote:(NSDictionary*)serializedInvocation;
 - (oneway void)_invokeRemoteBlock:(NSDictionary*)serializedBlock;
 - (oneway void)_cleanupRemoteBlock:(NSString*)identifier;

Sources/SBTUITestTunnelCommon/DetoxIPC/DTXIPCConnection.m

@@ -192,13 +192,22 @@ @implementation DTXIPCConnection
 	BOOL _resumed;
 }
 
-- (void)_runQueue
+- (void)_startConnectionSignalingReady:(dispatch_semaphore_t)readySemaphore
 {
 	_runLoop = NSRunLoop.currentRunLoop;
-	
-	[_connection run];
-	
 	_resumed = YES;
+
+	[_connection addRunLoop:_runLoop];
+
+	if (readySemaphore) {
+		CFRunLoopRef rl = CFRunLoopGetCurrent();
+		CFRunLoopPerformBlock(rl, kCFRunLoopDefaultMode, ^{
+			dispatch_semaphore_signal(readySemaphore);
+		});
+		CFRunLoopWakeUp(rl);
+	}
+
+	CFRunLoopRun();
 }
 
 - (BOOL)_commonInit
@@ -282,12 +291,20 @@ - (void)resume
 	{
 		return;
 	}
-	
+
 	NSAssert(_exportedObject != nil || _remoteObjectInterface != nil, @"An exported object or a remote object interface must be set before resuming the connection.");
-	
+
+	dispatch_semaphore_t readySemaphore = dispatch_semaphore_create(0);
 	dispatch_async(_dispatchQueue, ^{
-		[self _runQueue];
+		[self _startConnectionSignalingReady:readySemaphore];
 	});
+	// Wait for the connection's run loop to be actively processing messages.
+	// This prevents a race where the remote endpoint connects before
+	// the run loop is ready to handle incoming Mach port messages.
+	long waitResult = dispatch_semaphore_wait(readySemaphore, dispatch_time(DISPATCH_TIME_NOW, (int64_t)(10.0 * NSEC_PER_SEC)));
+	if (waitResult != 0) {
+		NSLog(@"[DTXIPCConnection] WARNING: Timed out waiting for connection run loop to start for service '%@'", _serviceName);
+	}
 }
 
 - (void)invalidate
@@ -330,7 +347,7 @@ - (void)setExportedObject:(id)exportedObject
 
 #pragma mark _DTXIPCImpl
 
-- (oneway void)_slaveDidConnectWithName:(NSString*)slaveServiceName
+- (void)_slaveDidConnectWithName:(NSString*)slaveServiceName
 {
     dispatch_sync(_otherConnectionQueue, ^{
         _otherConnection = [NSConnection connectionWithRegisteredName:slaveServiceName host:nil];

Sources/SBTUITestTunnelServer/SBTUITestTunnelServer.m

@@ -263,8 +263,11 @@ - (BOOL)takeOffOnceUsingHTTPPort:(NSString *)tunnelPort
 
             dispatch_semaphore_signal(sem);
         });
-
-        if (dispatch_semaphore_wait(sem, dispatch_time(DISPATCH_TIME_NOW, (int64_t)(SBTUITunneledServerDefaultTimeout * NSEC_PER_SEC))) != 0) {}
+        
+        if (dispatch_semaphore_wait(sem, dispatch_time(DISPATCH_TIME_NOW, (int64_t)(SBTUITunneledServerDefaultTimeout * NSEC_PER_SEC))) != 0) {
+            NSString *command = [request.path stringByReplacingOccurrencesOfString:@"/" withString:@""];
+            NSLog(@"[SBTUITestTunnel] Server command queue timeout after %ds for command '%@'", (int)SBTUITunneledServerDefaultTimeout, command);
+        }
         return ret;
     }];