Merge pull request #1284 from billhollings/queue-submit-finish-logging

Ensure queue submission message logging occurs before submission object is destroyed.
diff --git a/MoltenVK/MoltenVK/GPUObjects/MVKQueue.h b/MoltenVK/MoltenVK/GPUObjects/MVKQueue.h
index b72edd4..512c17a 100644
--- a/MoltenVK/MoltenVK/GPUObjects/MVKQueue.h
+++ b/MoltenVK/MoltenVK/GPUObjects/MVKQueue.h
@@ -181,7 +181,6 @@
 
 	MVKQueue* _queue;
 	MVKSmallVector<std::pair<MVKSemaphore*, uint64_t>> _waitSemaphores;
-	bool _trackPerformance;
 };
 
 
diff --git a/MoltenVK/MoltenVK/GPUObjects/MVKQueue.mm b/MoltenVK/MoltenVK/GPUObjects/MVKQueue.mm
index e80be13..c502387 100644
--- a/MoltenVK/MoltenVK/GPUObjects/MVKQueue.mm
+++ b/MoltenVK/MoltenVK/GPUObjects/MVKQueue.mm
@@ -244,8 +244,6 @@
 									   uint32_t waitSemaphoreCount,
 									   const VkSemaphore* pWaitSemaphores) {
 	_queue = queue;
-	_trackPerformance = mvkGetMVKConfiguration()->performanceTracking;
-
 	_waitSemaphores.reserve(waitSemaphoreCount);
 	for (uint32_t i = 0; i < waitSemaphoreCount; i++) {
 		_waitSemaphores.push_back(make_pair((MVKSemaphore*)pWaitSemaphores[i], (uint64_t)0));
@@ -315,25 +313,19 @@
 	// If using inline semaphore waiting, do so now.
 	for (auto& ws : _waitSemaphores) { ws.first->encodeWait(nil, ws.second); }
 
-	MVKDevice* mkvDev = _queue->_device;
-	uint64_t startTime = mkvDev->getPerformanceTimestamp();
+	// If we need to signal completion, use getActiveMTLCommandBuffer() to ensure at least
+	// one MTLCommandBuffer is used, otherwise if this instance has no content, it will not
+	// finish(), signal the fence and semaphores ,and be destroyed.
+	// Use temp var for MTLCommandBuffer commit and release because completion callback
+	// may destroy this instance before this function ends.
+	id<MTLCommandBuffer> mtlCmdBuff = signalCompletion ? getActiveMTLCommandBuffer() : _activeMTLCommandBuffer;
+	_activeMTLCommandBuffer = nil;
 
-	// Use getActiveMTLCommandBuffer() to ensure at least one MTLCommandBuffer is used,
-	// otherwise if this instance has no content, it will not finish() and be destroyed.
-	if (signalCompletion || _trackPerformance) {
-		[getActiveMTLCommandBuffer() addCompletedHandler: ^(id<MTLCommandBuffer> mtlCmdBuff) {
-			mkvDev->addActivityPerformance(mkvDev->_performanceStatistics.queue.mtlCommandBufferCompletion, startTime);
-			if (signalCompletion) { this->finish(); }
-		}];
-	}
-
-	// Use temp vars because callback may destroy this instance before this function ends.
-	MVKDevice* device = _queue->getDevice();
-	id<MTLCommandBuffer> mtlCmdBuff = _activeMTLCommandBuffer;
-	// If command buffer execution fails, log it, and mark the device lost.
+	MVKDevice* mvkDev = _queue->getDevice();
+	uint64_t startTime = mvkDev->getPerformanceTimestamp();
 	[mtlCmdBuff addCompletedHandler: ^(id<MTLCommandBuffer> mtlCB) {
 		if (mtlCB.status == MTLCommandBufferStatusError) {
-			device->reportError(device->markLost(), "Command buffer %p \"%s\" execution failed (code %li): %s", mtlCB, mtlCB.label ? mtlCB.label.UTF8String : "", mtlCB.error.code, mtlCB.error.localizedDescription.UTF8String);
+			getVulkanAPIObject()->reportError(mvkDev->markLost(), "Command buffer %p \"%s\" execution failed (code %li): %s", mtlCB, mtlCB.label ? mtlCB.label.UTF8String : "", mtlCB.error.code, mtlCB.error.localizedDescription.UTF8String);
 			// Some errors indicate we lost the physical device as well.
 			switch (mtlCB.error.code) {
 				case MTLCommandBufferErrorBlacklisted:
@@ -342,7 +334,7 @@
 #if MVK_MACOS && !MVK_MACCAT
 				case MTLCommandBufferErrorDeviceRemoved:
 #endif
-					device->getPhysicalDevice()->setConfigurationResult(VK_ERROR_DEVICE_LOST);
+					mvkDev->getPhysicalDevice()->setConfigurationResult(VK_ERROR_DEVICE_LOST);
 					break;
 			}
 #if MVK_XCODE_12
@@ -366,15 +358,22 @@
 		}
 #if MVK_XCODE_12
 		if (mvkGetMVKConfiguration()->debugMode) {
-			MVKLogInfo("Shader log messages:");
+			bool isFirstMsg = true;
 			for (id<MTLFunctionLog> log in mtlCB.logs) {
+				if (isFirstMsg) {
+					MVKLogInfo("Shader log messages:");
+					isFirstMsg = false;
+				}
 				MVKLogInfo("%s", log.description.UTF8String);
 			}
 		}
 #endif
+
+		// Ensure finish() is the last thing the completetion callback does.
+		mvkDev->addActivityPerformance(mvkDev->_performanceStatistics.queue.mtlCommandBufferCompletion, startTime);
+		if (signalCompletion) { this->finish(); }
 	}];
 
-	_activeMTLCommandBuffer = nil;
 	[mtlCmdBuff commit];
 	[mtlCmdBuff release];		// retained
 }