diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 34ac0df44f9..f8384a67daf 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -3,10 +3,10 @@ name: CI on: workflow_dispatch: push: - branches: ["main"] - pull_request: - # The branches below must be a subset of the branches above - branches: ["main"] + # branches: ["main"] + # pull_request: + # # The branches below must be a subset of the branches above + # branches: ["main"] # See https://docs.github.com/en/actions/using-jobs/using-concurrency#example-using-a-fallback-value concurrency: @@ -20,58 +20,58 @@ jobs: fail-fast: false matrix: include: - # Release builds - - os: macos-26 - config: "release" - # We want to test C++ and Swift only (in each direction) - cross_test_flags: "--all-cross --filter cpp --filter swift" - python_tests: true - - os: ubuntu-24.04 - config: "release" - cross_test_flags: "--all-cross" - - os: ubuntu-24.04-arm - config: "release" - build_flags: "SKIP=csharp" # Skip C# on ARM as .NET compiler keeps crashing - test_flags: "--rfilter=csharp" - python_tests: true - - os: windows-2022 - config: "release" - build_flags: "/p:Platform=x64" - test_flags: "--platform=x64" - python_tests: true - - os: windows-2022 - config: "cpp-win32-release" - working_directory: "cpp" - build_flags: "/p:Platform=Win32" - msbuild_project: "msbuild/ice.proj" - test_flags: "--platform=Win32" - python_tests: true - - os: windows-2025 - config: "release" - build_flags: "/p:Platform=x64" - test_flags: "--platform=x64" - python_tests: true - - # Debug builds - - os: macos-26 - config: "debug" - build_flags: "OPTIMIZE=no" - test_flags: "--swift-config=debug --csharp-config=Debug" - python_tests: true - - os: ubuntu-24.04 - config: "debug" - build_flags: "OPTIMIZE=no" - test_flags: "--csharp-config=Debug" - python_tests: true - - # TODO - figure out how to properly install debug Python - - os: windows-2022 - config: "debug" - working_directory: "cpp" - build_flags: "/p:Platform=x64 /p:Configuration=Debug" - test_flags: "--platform=x64 --config=Debug" - msbuild_project: "msbuild/ice.proj" - python_tests: true + # # Release builds + # - os: macos-26 + # config: "release" + # # We want to test C++ and Swift only (in each direction) + # cross_test_flags: "--all-cross --filter cpp --filter swift" + # python_tests: true + # - os: ubuntu-24.04 + # config: "release" + # cross_test_flags: "--all-cross" + # - os: ubuntu-24.04-arm + # config: "release" + # build_flags: "SKIP=csharp" # Skip C# on ARM as .NET compiler keeps crashing + # test_flags: "--rfilter=csharp" + # python_tests: true + # - os: windows-2022 + # config: "release" + # build_flags: "/p:Platform=x64" + # test_flags: "--platform=x64" + # python_tests: true + # - os: windows-2022 + # config: "cpp-win32-release" + # working_directory: "cpp" + # build_flags: "/p:Platform=Win32" + # msbuild_project: "msbuild/ice.proj" + # test_flags: "--platform=Win32" + # python_tests: true + # - os: windows-2025 + # config: "release" + # build_flags: "/p:Platform=x64" + # test_flags: "--platform=x64" + # python_tests: true + + # # Debug builds + # - os: macos-26 + # config: "debug" + # build_flags: "OPTIMIZE=no" + # test_flags: "--swift-config=debug --csharp-config=Debug" + # python_tests: true + # - os: ubuntu-24.04 + # config: "debug" + # build_flags: "OPTIMIZE=no" + # test_flags: "--csharp-config=Debug" + # python_tests: true + + # # TODO - figure out how to properly install debug Python + # - os: windows-2022 + # config: "debug" + # working_directory: "cpp" + # build_flags: "/p:Platform=x64 /p:Configuration=Debug" + # test_flags: "--platform=x64 --config=Debug" + # msbuild_project: "msbuild/ice.proj" + # python_tests: true # iOS - os: macos-26 @@ -81,32 +81,32 @@ jobs: test_flags: "--languages='cpp,swift' --config=debug --platform=iphonesimulator --controller-app --rfilter=swift/Ice/udp" build_cpp_and_python: true - # Static builds - - os: ubuntu-24.04 - config: "static" - build_flags: "CONFIGS=static" - test_flags: "--config=static --filter=Ice/ --filter=IceDiscovery/" - working_directory: "cpp" - - # MATLAB - - os: ubuntu-24.04 - config: "matlab" - working_directory: "matlab" - build_cpp_and_python: true - - os: windows-2022 - config: "matlab" - working_directory: "matlab" - build_flags: "/p:Platform=x64" - msbuild_project: "msbuild/ice.proj" - test_flags: "--platform=x64" - build_cpp_and_python: true - - - os: ubuntu-24.04 - config: "android" - working_directory: "java" - test_flags: "--android --controller-app" - build_cpp_and_python: true - build_android_controller: true + # # Static builds + # - os: ubuntu-24.04 + # config: "static" + # build_flags: "CONFIGS=static" + # test_flags: "--config=static --filter=Ice/ --filter=IceDiscovery/" + # working_directory: "cpp" + + # # MATLAB + # - os: ubuntu-24.04 + # config: "matlab" + # working_directory: "matlab" + # build_cpp_and_python: true + # - os: windows-2022 + # config: "matlab" + # working_directory: "matlab" + # build_flags: "/p:Platform=x64" + # msbuild_project: "msbuild/ice.proj" + # test_flags: "--platform=x64" + # build_cpp_and_python: true + + # - os: ubuntu-24.04 + # config: "android" + # working_directory: "java" + # test_flags: "--android --controller-app" + # build_cpp_and_python: true + # build_android_controller: true runs-on: ${{ matrix.os }} steps: diff --git a/scripts/Util.py b/scripts/Util.py index b9d81d669b6..f1e062c59b3 100644 --- a/scripts/Util.py +++ b/scripts/Util.py @@ -2819,17 +2819,42 @@ def startControllerApp(self, current, ident): run('xcrun simctl install "{0}" "{1}"'.format(self.device, appFullPath)) print("ok") + logStreamProcess = subprocess.Popen( + [ + "xcrun", + "simctl", + "spawn", + "booted", + "log", + "stream", + "--level", + "debug", + # "--predicate", + # f'subsystem contains "{ident.name}"', + ], + stdout=subprocess.PIPE, + stderr=subprocess.STDOUT, + ) + sys.stdout.write("launching {0}... ".format(os.path.basename(appFullPath))) sys.stdout.flush() n = 0 while n < 5: try: - subprocess.run(["xcrun", "simctl", "launch", self.device, ident.name], check=True, timeout=60) + subprocess.run(["xcrun", "simctl", "launch", self.device, ident.name], check=True, timeout=120) break except subprocess.TimeoutExpired: n += 1 - sys.stdout.write(f"\nlaunch timeout, retrying {n}/5... ") - sys.stdout.flush() + + print(f"ok ({n} retries)") + logStreamProcess.terminate() + + if n == 5: + output = logStreamProcess.stdout.readlines() + with open("ios_simulator.log", "wb") as f: + for line in output: + f.write(line) + raise RuntimeError("failed to launch the controller application") # No "ok" as the command prints its own output def restartControllerApp(self, current, ident): @@ -2845,7 +2870,8 @@ def restartControllerApp(self, current, ident): except Exception: time.sleep(1.0) nRetry += 1 - run('xcrun simctl launch "{0}" {1}'.format(self.device, ident.name)) + + subprocess.run(["xcrun", "simctl", "launch", self.device, ident.name], check=True, timeout=60) def stopControllerApp(self, ident): controllerBundleIdentifier = ident.name diff --git a/swift/src/Ice/ObjectAdapterI.swift b/swift/src/Ice/ObjectAdapterI.swift index ebffe1e1b95..0b053551965 100644 --- a/swift/src/Ice/ObjectAdapterI.swift +++ b/swift/src/Ice/ObjectAdapterI.swift @@ -234,6 +234,12 @@ final class ObjectAdapterI: LocalObject, ObjectAdapter, ICEDis ) { precondition(handle == adapter) + + let logger = getCommunicator().getLogger() + + logger.print( + "Swift Dispatch started: time=\(Date().formatted(.iso8601.year().month().day().time(includingFractionalSeconds: true))) identity=\(name) operation=\(operation) starting dispatch") + let connection = con?.getSwiftObject(ConnectionI.self) { ConnectionI(handle: con!) } let encoding = EncodingVersion(major: encodingMajor, minor: encodingMinor) @@ -255,17 +261,22 @@ final class ObjectAdapterI: LocalObject, ObjectAdapter, ICEDis let request = IncomingRequest(current: current, inputStream: istr) + logger.print( + "About to start Task: time=\(Date().formatted(.iso8601.year().month().day().time(includingFractionalSeconds: true))) identity=\(name) operation=\(operation) starting dispatch") Task { let response: OutgoingResponse // TODO: the request is in the Task capture and we need to send it. Is there a better syntax? nonisolated(unsafe) let request = request do { + logger.print( + "Dispatching OA request: time=\(Date().formatted(.iso8601.year().month().day().time(includingFractionalSeconds: true))) identity=\(name) operation=\(operation) starting dispatch") response = try await dispatchPipeline.dispatch(request) } catch { response = current.makeOutgoingResponse(error: error) } - + logger.print( + "Completed OA request: time=\(Date().formatted(.iso8601.year().month().day().time(includingFractionalSeconds: true))) identity=\(name) operation=\(operation) dispatch completed, sending response") response.outputStream.finished().withUnsafeBytes { outgoingResponseHandler( response.replyStatus, diff --git a/swift/src/IceImpl/DispatchAdapter.mm b/swift/src/IceImpl/DispatchAdapter.mm index 1487389c6c5..f24d074cfef 100644 --- a/swift/src/IceImpl/DispatchAdapter.mm +++ b/swift/src/IceImpl/DispatchAdapter.mm @@ -6,12 +6,39 @@ #import "include/LocalExceptionFactory.h" #import "include/ObjectAdapter.h" +#include + +namespace +{ + std::string timePointToString(const std::chrono::system_clock::time_point& timePoint) + { + auto time = std::chrono::system_clock::to_time_t(timePoint); + struct tm tr; + + localtime_r(&time, &tr); + + char buf[32]; + strftime(buf, sizeof(buf), "%x %H:%M:%S", &tr); + + auto usec = std::chrono::duration_cast(timePoint.time_since_epoch()); + return std::string(buf) + "." + std::to_string(usec.count() % 1000000 / 1000); + } +} + void CppDispatcher::dispatch(Ice::IncomingRequest& request, std::function sendResponse) { // Captured as a const copy by the block according to https://clang.llvm.org/docs/BlockLanguageSpec.html Ice::Current current{request.current()}; + auto logger = current.adapter->getCommunicator()->getLogger(); + + auto startTime = std::chrono::system_clock::now(); + + logger->print( + "C++ Dispatch into Swift: time=" + timePointToString(startTime) + " identity=" + current.id.name + + " operation=" + current.operation + " start time"); + int32_t sz; const std::byte* inEncaps; std::function cleanup; @@ -49,6 +76,12 @@ ICEOutgoingResponse outgoingResponse = ^(uint8_t replyStatus, NSString* exceptionId, NSString* exceptionDetails, const void* message, long count) { + auto endTime = std::chrono::system_clock::now(); + logger->print( + "C++ Dispatch completed: time=" + timePointToString(endTime) + " identity=" + current.id.name + + " operation=" + current.operation + " duration=" + + std::to_string(std::chrono::duration_cast(endTime - startTime).count()) + + " ms"); cleanup(); // We need to copy the message here as we don't own the memory and it can be sent asynchronously. @@ -61,6 +94,9 @@ fromNSString(exceptionDetails), std::move(ostr), current}); + logger->print( + "Swift Dispatch: time=" + timePointToString(std::chrono::system_clock::now()) + + " identity=" + current.id.name + " operation=" + current.operation + " response sent"); }; ICEObjectAdapter* adapter = [ICEObjectAdapter getHandle:current.adapter]; diff --git a/swift/test/Ice/location/Server.swift b/swift/test/Ice/location/Server.swift index 0363b9ca870..5b5b273e05a 100644 --- a/swift/test/Ice/location/Server.swift +++ b/swift/test/Ice/location/Server.swift @@ -1,9 +1,25 @@ // Copyright (c) ZeroC, Inc. -import Dispatch import Ice import TestCommon + +struct DispatchWrapper: Dispatcher { + let dispatcher: Dispatcher + + func dispatch(_ request: sending IncomingRequest) async throws -> OutgoingResponse { + let startTime = ContinuousClock.now + let response = try await dispatcher.dispatch(request) + let endTime = ContinuousClock.now + let elapsed = startTime.duration(to: endTime) + + let logger = request.current.adapter.getCommunicator().getLogger() + logger.print("Swift Dispatch: identity=\(request.current.id) operation=\(request.current.operation) duration=\(Double(elapsed.components.attoseconds) / 1_000_000_000_000_000.0) ms") + + return response + } +} + class Server: TestHelperI, @unchecked Sendable { override public func run(args: [String]) async throws { // @@ -11,6 +27,7 @@ class Server: TestHelperI, @unchecked Sendable { // 'server'(a server isn't a different process, it's just a new // communicator and object adapter). // + let properties = try createTestProperties(args) properties.setProperty(key: "Ice.ThreadPool.Server.Size", value: "2") let communicator = try initialize(Ice.InitializationData(properties: properties)) @@ -32,7 +49,7 @@ class Server: TestHelperI, @unchecked Sendable { // Make sure we use a separate copy of the properties as the servant modifies them. let object = ServerManagerI(registry: registry, properties: properties.clone(), helper: self) - try adapter.add(servant: object, id: Ice.stringToIdentity("ServerManager")) + try adapter.add(servant: DispatchWrapper(dispatcher: object), id: Ice.stringToIdentity("ServerManager")) try await registry.addObject(adapter.createProxy(Ice.stringToIdentity("ServerManager"))) let registryPrx = try uncheckedCast( @@ -42,7 +59,7 @@ class Server: TestHelperI, @unchecked Sendable { type: Ice.LocatorRegistryPrx.self) let locator = ServerLocator(registry: registry, registryPrx: registryPrx) - try adapter.add(servant: locator, id: Ice.stringToIdentity("locator")) + try adapter.add(servant: DispatchWrapper(dispatcher: locator), id: Ice.stringToIdentity("locator")) try adapter.activate() serverReady() diff --git a/swift/test/Ice/location/TestI.swift b/swift/test/Ice/location/TestI.swift index df9d573859e..c987b1b7ce4 100644 --- a/swift/test/Ice/location/TestI.swift +++ b/swift/test/Ice/location/TestI.swift @@ -67,12 +67,17 @@ actor ServerManagerI: ServerManager { _properties.setProperty(key: "Ice.PrintAdapterReady", value: "0") } - func startServer(current _: Ice.Current) async throws { + func startServer(current: Ice.Current) async throws { + + let startTime = CFAbsoluteTimeGetCurrent() for c in _communicators { - c.waitForShutdown() + await c.shutdownCompleted() c.destroy() } _communicators.removeAll() + let endTime = CFAbsoluteTimeGetCurrent() + current.adapter.getCommunicator().getLogger().print( + "Previous servers shutdown took \(endTime - startTime) seconds") // // Simulate a server: create a new communicator and object @@ -118,12 +123,11 @@ actor ServerManagerI: ServerManager { try adapter2.setLocator(uncheckedCast(prx: locator, type: Ice.LocatorPrx.self)) let object = try TestI(adapter1: adapter, adapter2: adapter2, registry: _registry) - try await _registry.addObject(adapter.add(servant: HelloI(), id: Ice.stringToIdentity("hello"))) - + try await _registry.addObject(adapter.add(servant: HelloI(), id: Ice.Identity(name: "hello"))) try await _registry.addObject(adapter.add(servant: object, id: Ice.Identity(name: "test"))) - try await _registry.addObject(adapter.add(servant: object, id: Ice.stringToIdentity("test2"))) + try await _registry.addObject(adapter.add(servant: object, id: Ice.Identity(name: "test2"))) - _ = try adapter.add(servant: object, id: Ice.stringToIdentity("test3")) + _ = try adapter.add(servant: object, id: Ice.Identity(name: "test3")) try adapter.activate() try adapter2.activate() @@ -187,7 +191,7 @@ actor ServerLocator: TestLocator { return try await _registry.getObject(id) } - func getRegistry(current _: Ice.Current) -> Ice.LocatorRegistryPrx? { + nonisolated func getRegistry(current _: Ice.Current) -> Ice.LocatorRegistryPrx? { return _registryPrx }