Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ios_ui_test runner is flaky #185

Open
jverkoey opened this issue May 17, 2018 · 21 comments
Open

ios_ui_test runner is flaky #185

jverkoey opened this issue May 17, 2018 · 21 comments
Assignees
Labels
P3 Would be nice, but probably next quarter at the earliest type: customer issue This issue is not a problem with the codebase, but an issue a customer is having.

Comments

@jverkoey
Copy link
Contributor

jverkoey commented May 17, 2018

We're attempting to make use of ios_ui_test on the MDC iOS repo and encountering fairly flaky builds as a result.

The errors we're seeing are:

  • "Timed out waiting 120 seconds for simulator to boot, current state is 1."
  • "(ipc/mig) server died"

Example failure logs from this PR:

FAIL: //components/BottomSheet:app_tests (see /Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/components/BottomSheet/app_tests/test.log)
INFO: From Testing //components/BottomSheet:app_tests:
==================== Test output for //components/BottomSheet:app_tests:
2018-05-17 20:09:38,551 Will consider the test as test type xctest to run.
2018-05-17 20:09:38,680 The signing options only works on sdk iphoneos, but current sdk is iphonesimulator
2018-05-17 20:09:38,680 Generating xctestrun file.
2018-05-17 20:09:38,681 Generating dummy project.
2018-05-17 20:09:38,694 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2018-05-17 20:09:38,823 Dummy project is generated.
2018-05-17 20:09:38,824 Preparing build products directory /tmpfs/tmp/test_runner_work_dir.BsxgNY/TEST_ROOT for dummy project.
2018-05-17 20:09:38,825 Running `xcodebuild build-for-testing` with dummy project.
	built_product_dir = /tmpfs/tmp/test_runner_work_dir.BsxgNY/TEST_ROOT
	derived_data_path = /tmpfs/tmp/test_runner_work_dir.BsxgNY/dummyproject_derived_data

2018-05-17 20:09:42,480 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2018-05-17 20:09:42,494 Creating a new simulator:
Name: NEW_IPHONE_5_8_1
OS: iOS 8.1
Type: iPhone 5
2018-05-17 20:09:43,427 Created new simulator 4CC7829A-504A-44BC-AEDD-FF2CBB0671CD.
2018-05-17 20:09:43,427 Running test-without-building with device 4CC7829A-504A-44BC-AEDD-FF2CBB0671CD
User defaults from command line:
    IDEDerivedDataPathOverride = /Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/bin/components/BottomSheet/app_tests.runfiles/__main__/Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/components/BottomSheet/app_tests/test.outputs
    IDETestRunSpecificationPath = /Volumes/BuildData/tmpfs/tmp/test_runner_work_dir.BsxgNY/TEST_ROOT/xctestrun.plist

2018-05-17 20:09:45.060 xcodebuild[22583:77096]  IDETestOperationsObserverDebug: Writing diagnostic log for test session to:
/Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/bin/components/BottomSheet/app_tests.runfiles/__main__/Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/components/BottomSheet/app_tests/test.outputs/Logs/Test/3BFD2A73-57BA-4E0F-A947-F991A82931B7/Session-app_tests-2018-05-17_200945-XNT4Yh.log
2018-05-17 20:09:45.060 xcodebuild[22583:77018] [MT] IDETestOperationsObserverDebug: (83847887-5130-4C8E-BE87-12079E1E327A) Beginning test session app_tests-83847887-5130-4C8E-BE87-12079E1E327A at 2018-05-17 20:09:45.060 with Xcode 8E3004b on target <DVTiPhoneSimulator: 0x7fbd8e62dba0> {
		SimDevice: SimDevice : NEW_IPHONE_5_8_1 (4CC7829A-504A-44BC-AEDD-FF2CBB0671CD) : state={ Shutdown } deviceType={ SimDeviceType : com.apple.CoreSimulator.SimDeviceType.iPhone-5 } runtime={ SimRuntime : 8.1 (12B411) - com.apple.CoreSimulator.SimRuntime.iOS-8-1 }
} (8.1 (12B411))
2018-05-17 20:11:56.767 xcodebuild[22583:77018] [MT] IDETestOperationsObserverDebug: (83847887-5130-4C8E-BE87-12079E1E327A) Failed to make test runner session:
Error Domain=com.apple.dt.xctest.error Code=7 "Timed out waiting 120 seconds for simulator to boot, current state is 1." UserInfo={NSLocalizedDescription=Timed out waiting 120 seconds for simulator to boot, current state is 1.}
2018-05-17 20:11:56.771 xcodebuild[22583:77018] Error Domain=IDETestOperationsObserverErrorDomain Code=3 "Timed out waiting 120 seconds for simulator to boot, current state is 1. If you believe this error represents a bug, please attach the log file at /Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/bin/components/BottomSheet/app_tests.runfiles/__main__/Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/components/BottomSheet/app_tests/test.outputs/Logs/Test/3BFD2A73-57BA-4E0F-A947-F991A82931B7/Session-app_tests-2018-05-17_200945-XNT4Yh.log" UserInfo={NSLocalizedDescription=Timed out waiting 120 seconds for simulator to boot, current state is 1. If you believe this error represents a bug, please attach the log file at /Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/bin/components/BottomSheet/app_tests.runfiles/__main__/Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/components/BottomSheet/app_tests/test.outputs/Logs/Test/3BFD2A73-57BA-4E0F-A947-F991A82931B7/Session-app_tests-2018-05-17_200945-XNT4Yh.log}
2018-05-17 20:12:13,601 The xcodebuild command got stuck and has not started test in 150. Will kill the command directly.
** BUILD INTERRUPTED **
2018-05-17 20:12:13,622 xcodebuild command can not launch test on device/simulator in 150s.
2018-05-17 20:12:13,628 Failed to parse test summaries /Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/bin/components/BottomSheet/app_tests.runfiles/__main__//Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/bazel-sandbox/8061246070028729815/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/components/BottomSheet/app_tests/test.outputs/Logs/Test/3BFD2A73-57BA-4E0F-A947-F991A82931B7_TestSummaries.plist: The field TestableSummaries:0:Tests:0 can not be found in the target object. The object content is []
2018-05-17 20:12:13,651 Simulator 4CC7829A-504A-44BC-AEDD-FF2CBB0671CD has already shut down.
2018-05-17 20:12:14,116 Deleted simulator 4CC7829A-504A-44BC-AEDD-FF2CBB0671CD.
2018-05-17 20:12:14,116 Done.
================================================================================
@jverkoey
Copy link
Contributor Author

jverkoey commented May 17, 2018

I isolated the test target in a while true bash loop and could not get it to flake after a half dozen iterations locally, making me believe the flakiness may be due to parallel builds in some manner.

@thomasvl
Copy link
Member

@sergiocampama isn't this going to be the test runner and not the ios_ui_test rule itself?

@jverkoey
Copy link
Contributor Author

Flakiness has gone down now that I’ve marked ui tests with tags = ["exclusive"], but I am still seeing flakes on a runner that uses a conditional device type.

E.g.:

device_type = select({ ":xcode8_3_3": "iPad 2", ":xcode_9_0": "iPhone2017-C", "//conditions:default": "iPhone X" }),

Still working on isolating this.

@jverkoey
Copy link
Contributor Author

Am continuing to update this PR: material-components/material-components-ios#4182

You can view the kokoro log outputs on the pr commit statuses.

@jverkoey
Copy link
Contributor Author

More failure logs:

==================== Test output for //components/BottomSheet:app_tests_DYNAMIC_RUNNER:
2018-05-18 23:56:43,190 Will consider the test as test type xctest to run.
2018-05-18 23:56:43,274 The signing options only works on sdk iphoneos, but current sdk is iphonesimulator
2018-05-18 23:56:43,274 Generating xctestrun file.
2018-05-18 23:56:43,275 Generating dummy project.
2018-05-18 23:56:43,281 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2018-05-18 23:56:43,301 Dummy project is generated.
2018-05-18 23:56:43,301 Preparing build products directory /tmpfs/tmp/test_runner_work_dir.JknpNi/TEST_ROOT for dummy project.
2018-05-18 23:56:43,301 Running `xcodebuild build-for-testing` with dummy project.
	built_product_dir = /tmpfs/tmp/test_runner_work_dir.JknpNi/TEST_ROOT
	derived_data_path = /tmpfs/tmp/test_runner_work_dir.JknpNi/dummyproject_derived_data

2018-05-18 23:56:44,939 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2018-05-18 23:56:44,954 Creating a new simulator:
Name: NEW_IPHONE2017-C_11_0
OS: iOS 11.0
Type: iPhone2017-C
2018-05-18 23:56:45,981 Created new simulator 3F057BFC-E563-404D-B104-3CE8D2B33972.
2018-05-18 23:56:45,981 Running test-without-building with device 3F057BFC-E563-404D-B104-3CE8D2B33972
User defaults from command line:
    IDEDerivedDataPathOverride = /Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/execroot/__main__/bazel-out/darwin-fastbuild/bin/components/BottomSheet/app_tests_DYNAMIC_RUNNER.runfiles/__main__/Volumes/BuildData/tmpfs/tmp/bazel/3eb3c42fcd20d50a831da151c89283a1/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/components/BottomSheet/app_tests_DYNAMIC_RUNNER/test.outputs
    IDETestRunSpecificationPath = /Volumes/BuildData/tmpfs/tmp/test_runner_work_dir.JknpNi/TEST_ROOT/xctestrun.plist

2018-05-18 23:56:47.476 xcodebuild[38519:135824]  IDETestOperationsObserverDebug: Writing diagnostic log for test session to:
/var/folders/yh/crtc3sq52n34tstm39cljbcr0000gn/T/com.apple.dt.XCTest/IDETestRunSession-203C42EC-C33F-48A8-8CF1-EA6605344F3D/app_tests_DYNAMIC_RUNNER-622E0F5E-94BB-4134-BCEC-D86A7210A710/Session-app_tests_DYNAMIC_RUNNER-2018-05-18_235647-QLj1r2.log
2018-05-18 23:56:47.478 xcodebuild[38519:135816] [MT] IDETestOperationsObserverDebug: (84D9E90D-6616-41AC-B3DA-A2FF4786B99D) Beginning test session app_tests_DYNAMIC_RUNNER-84D9E90D-6616-41AC-B3DA-A2FF4786B99D at 2018-05-18 23:56:47.476 with Xcode 9A235 on target <DVTiPhoneSimulator: 0x7f9748d0e640> {
		SimDevice: NEW_IPHONE2017-C_11_0 (3F057BFC-E563-404D-B104-3CE8D2B33972, iOS 11.0, Booted)
} (11.0 (15A372))
2018-05-18 23:59:17,180 The xcodebuild command got stuck and has not started test in 150. Will kill the command directly.
** BUILD INTERRUPTED **
2018-05-18 23:59:24,331 xcodebuild command can not launch test on device/simulator in 150s.
2018-05-18 23:59:24,340 Simulator 3F057BFC-E563-404D-B104-3CE8D2B33972 has already shut down.
2018-05-18 23:59:24,819 Deleted simulator 3F057BFC-E563-404D-B104-3CE8D2B33972.
2018-05-18 23:59:24,819 Done.

@jverkoey
Copy link
Contributor Author

@thomasvl likely that it's the runner and not the target — I'm still grokking how bazel's built under the hood as I dive in to this.

@jverkoey jverkoey changed the title ios_ui_test is flaky ios_ui_test runner is flaky May 19, 2018
@jverkoey
Copy link
Contributor Author

jverkoey commented May 19, 2018

I have four ios_ui_test targets running on our CI, but I've been noticing for some time now that only one of the tests flakes on any given run. I duplicated these test targets and am still only seeing one target flaking now that there are eight, which makes me believe that there is something to do with either the first or last simulator run that's causing this flakiness.

@jverkoey
Copy link
Contributor Author

I can't find any of the strings output in the build logs in the bazelbuild org. Who is generating the strings like "Generating xctestrun file" and "xcodebuild command can not launch test"?

@jverkoey
Copy link
Contributor Author

I think I've hit the edge of what I can explore options-wise from our end. The only solution I found that worked ok'ish was to retry the tests after failure a couple times with the hopes that the flakiness eventually resolves itself.

Would it be possible to build simulator flakiness resilience into bazel in some manner?

@jverkoey
Copy link
Contributor Author

jverkoey commented May 20, 2018

Additional context:

  • Mac OS X 10.12.6.
  • Xcode 8.3.3, 9.0, 9.1, and 9.2 all experience equivalent flakiness.

@thomasvl
Copy link
Member

The runner is an external dep: https://github.com/bazelbuild/rules_apple#quick-setup, _ xctestrunner_

That's what is defaulted into the runner argument on xc_unit_test.

@jverkoey
Copy link
Contributor Author

Ah! Thank you :) Will dig into that...

@sergiocampama
Copy link
Contributor

Hi @jverkoey, we've just updated the test runner dependency to 0.2.3, can you try with that one?

@sergiocampama sergiocampama added P3 Would be nice, but probably next quarter at the earliest type: customer issue This issue is not a problem with the codebase, but an issue a customer is having. labels Mar 12, 2019
@keith
Copy link
Member

keith commented May 23, 2019

We just hit this case with xctestrunner 0.2.7. Our log doesn't add much here:

2019-05-23 19:04:40,046 Will consider the test as test type xcuitest to run.
2019-05-23 19:04:40,121 Generating xctestrun file.
2019-05-23 19:04:40,180 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2019-05-23 19:04:40,185 Running test-without-building with device 0BD49FD3-9D51-4435-9181-E97EA5FB79D8
User defaults from command line:
    IDEDerivedDataPathOverride = /var/tmp/_bazel_iosci/8fe8f10a98f0aa02812fc7ef90554d42/execroot/lyftios/bazel-out/darwin-fastbuild/bin/Modules/PassengerApp/Lyft-UITests.runfiles/lyftios/private/var/tmp/_bazel_iosci/8fe8f10a98f0aa02812fc7ef90554d42/execroot/lyftios/bazel-out/darwin-fastbuild/testlogs/Modules/PassengerApp/Lyft-UITests/test.outputs
    IDETestRunSpecificationPath = /tmp/test_runner_work_dir.ZjrHVp/TEST_ROOT/xctestrun.plist
 
Testing started on 'BAZEL_TEST_iPhone X_12.2'
2019-05-23 19:04:40.844 xcodebuild[84499:5535182]  IDETestOperationsObserverDebug: Writing diagnostic log for test session to:
/var/tmp/_bazel_iosci/8fe8f10a98f0aa02812fc7ef90554d42/execroot/lyftios/bazel-out/darwin-fastbuild/bin/Modules/PassengerApp/Lyft-UITests.runfiles/lyftios/private/var/tmp/_bazel_iosci/8fe8f10a98f0aa02812fc7ef90554d42/execroot/lyftios/bazel-out/darwin-fastbuild/testlogs/Modules/PassengerApp/Lyft-UITests/test.outputs/Logs/Test/Test-Transient Testing-2019.05.23_19-04-40-+0000.xcresult/1_Test/Diagnostics/Lyft-UITests-DA25532F-9870-45B6-9AFB-0EFDD89A16FB/Lyft-UITests-88C6839C-F1BB-435A-A851-F5EAAD098C29/Session-Lyft-UITests-2019-05-23_190440-8ftShC.log
2019-05-23 19:04:40.844 xcodebuild[84499:5535144] [MT] IDETestOperationsObserverDebug: (825DF6A2-DB45-43BA-84E1-01CE64560D56) Beginning test session Lyft-UITests-825DF6A2-DB45-43BA-84E1-01CE64560D56 at 2019-05-23 19:04:40.844 with Xcode 10E1001 on target <DVTiPhoneSimulator: 0x7fa880854110> {
		SimDevice: BAZEL_TEST_iPhone X_12.2 (0BD49FD3-9D51-4435-9181-E97EA5FB79D8, iOS 12.2, Booted)
} (12.2 (16E226))
2019-05-23 19:04:41.196 xcodebuild[84499:5535144] [MT] IDETestOperationsObserverDebug: (825DF6A2-DB45-43BA-84E1-01CE64560D56) Finished requesting crash reports. Continuing with testing.
2019-05-23 19:07:10,698 The xcodebuild command got stuck and has not started test in 150. Will kill the command directly.
** BUILD INTERRUPTED **
2019-05-23 19:07:10,704 xcodebuild command can not launch test on device/simulator in 150s.
2019-05-23 19:07:10,705 Done.

This is with Xcode 10.2.1 on macOS 14.4 testing on iOS 12.2

@jerrymarino
Copy link
Contributor

I was also running into this issue at a fairly consistent rate and isolated the issue to com.apple.CoreSimulator.CoreSimulatorService.
It seems to deadlock under the following scenarios:

  • many concurrent simctl invocations
  • many actool ( uses CoreSimulatorService internally ) and simctl invocations. Here actool hangs.

Prior to running bazel I simply kill com.apple.CoreSimulator.CoreSimulatorService which has 100% fixed this over the last few months. Previously, all threads locked here:

-[SimDeviceSet updateDefaultDevicesAndPairingsForDeveloperDir:force:]

    frame #4: 0x000000010c9de539 CoreSimulator`-[SimDeviceSet updateDefaultDevicesAndPairingsForDeveloperDir:force:] + 142
    frame #5: 0x000000010c9aeb5c CoreSimulator`__56-[SimServiceContext supportedRuntimesAddProfilesAtPath:]_block_invoke.646 + 362
    frame #6: 0x00007fff7af835fa libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #7: 0x00007fff7af7bdb8 libdispatch.dylib`_dispatch_client_callout + 8
    frame #8: 0x00007fff7af7db2c libdispatch.dylib`_dispatch_root_queue_drain + 902
    frame #9: 0x00007fff7af7d755 libdispatch.dylib`_dispatch_worker_thread3 + 101
    frame #10: 0x00007fff7b2cd169 libsystem_pthread.dylib`_pthread_wqthread + 1387
    frame #11: 0x00007fff7b2ccbe9 libsystem_pthread.dylib`start_wqthread + 13
  thread #12, queue = 'com.apple.root.background-qos'
    frame #0: 0x00007fff7b10615a libsystem_kernel.dylib`__ulock_wait + 10
    frame #1: 0x00007fff7af8b9ff libdispatch.dylib`_dispatch_ulock_wait + 40
    frame #2: 0x00007fff7af8baf0 libdispatch.dylib`_dispatch_thread_event_wait_slow + 26
    frame #3: 0x00007fff7af921da libdispatch.dylib`_dispatch_sync_wait + 510
    frame #4: 0x000000010c9dc9d7 CoreSimulator`__26-[SimDeviceSet saveToDisk]_block_invoke + 230
    frame #5: 0x00007fff7af835fa libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #6: 0x00007fff7af7bdb8 libdispatch.dylib`_dispatch_client_callout + 8
    frame #7: 0x00007fff7af7db2c libdispatch.dylib`_dispatch_root_queue_drain + 902
    frame #8: 0x00007fff7af7d755 libdispatch.dylib`_dispatch_worker_thread3 + 101
    frame #9: 0x00007fff7b2cd169 libsystem_pthread.dylib`_pthread_wqthread + 1387
    frame #10: 0x00007fff7b2ccbe9 libsystem_pthread.dylib`start_wqthread + 13
  thread #13, queue = 'com.apple.root.background-qos'
    frame #0: 0x00007fff7b10615a libsystem_kernel.dylib`__ulock_wait + 10
    frame #1: 0x00007fff7af8b9ff libdispatch.dylib`_dispatch_ulock_wait + 40
    frame #2: 0x00007fff7af8baf0 libdispatch.dylib`_dispatch_thread_event_wait_slow + 26
    frame #3: 0x00007fff7af921da libdispatch.dylib`_dispatch_sync_wait + 510
    frame #4: 0x000000010c9de539 CoreSimulator`-[SimDeviceSet updateDefaultDevicesAndPairingsForDeveloperDir:force:] + 142
    frame #5: 0x000000010c9aeb5c CoreSimulator`__56-[SimServiceContext supportedRuntimesAddProfilesAtPath:]_block_invoke.646 + 362
    frame #6: 0x00007fff7af835fa libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #7: 0x00007fff7af7bdb8 libdispatch.dylib`_dispatch_client_callout + 8
    frame #8: 0x00007fff7af7db2c libdispatch.dylib`_dispatch_root_queue_drain + 902
    frame #9: 0x00007fff7af7d755 libdispatch.dylib`_dispatch_worker_thread3 + 101
    frame #10: 0x00007fff7b2cd169 libsystem_pthread.dylib`_pthread_wqthread + 1387
    frame #11: 0x00007fff7b2ccbe9 libsystem_pthread.dylib`start_wqthread + 13..```

Hope it helps, and that there is a better fix than `killall` 🤦‍♀ 

@acecilia
Copy link

acecilia commented Mar 31, 2020

I just hit also this issue. It is running perfectly locally, but failing multiple times on CI (github actions).

The very few tries I have done so far, I have worked around the problem thanks to @jerrymarino solution, executing the following line before running bazel:

pgrep Simulator | xargs kill || true

The log is the following:

2020-03-31T15:47:50.9772570Z ==================== Test output for //Libraries/App:AppTests:
2020-03-31T15:47:50.9786440Z 2020-03-31 15:45:09,996 Will consider the test as test type xctest to run.
2020-03-31T15:47:50.9787490Z 2020-03-31 15:45:10,114 Generating xctestrun file.
2020-03-31T15:47:50.9810700Z 2020-03-31 15:45:10,140 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2020-03-31T15:47:50.9811600Z 2020-03-31 15:45:10,382 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2020-03-31T15:47:50.9812530Z 2020-03-31 15:45:10,632 Failed to import biplist module. Will use tool /usr/libexec/PlistBuddy to handle the binary format plist.
2020-03-31T15:47:50.9813160Z 2020-03-31 15:45:10,636 Creating a new simulator:
2020-03-31T15:47:50.9872780Z Name: New-iPhone 11 Pro Max-13.3
2020-03-31T15:47:50.9873020Z OS: iOS 13.3
2020-03-31T15:47:50.9873130Z Type: iPhone 11 Pro Max
2020-03-31T15:47:50.9874030Z 2020-03-31 15:45:11,593 Created new simulator D73F08ED-87E7-473D-ACA7-86E0E862ABAD.
2020-03-31T15:47:50.9874560Z 2020-03-31 15:45:11,593 Running test-without-building with device D73F08ED-87E7-473D-ACA7-86E0E862ABAD
2020-03-31T15:47:50.9874700Z User defaults from command line:
2020-03-31T15:47:50.9875590Z     IDEDerivedDataPathOverride = /var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/bin/Libraries/App/AppTests.runfiles/__main__/private/var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/Libraries/App/AppTests/test.outputs
2020-03-31T15:47:50.9875820Z     IDETestRunSpecificationPath = /var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/test_runner_work_dir.c1Kj8V/TEST_ROOT/xctestrun.plist
2020-03-31T15:47:50.9875910Z 
2020-03-31T15:47:50.9876370Z Testing started on 'New-iPhone 11 Pro Max-13.3'
2020-03-31T15:47:50.9876980Z 2020-03-31 15:45:14.806 xcodebuild[5792:30817]  IDETestOperationsObserverDebug: Writing diagnostic log for test session to:
2020-03-31T15:47:50.9878060Z /var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/bin/Libraries/App/AppTests.runfiles/__main__/private/var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/Libraries/App/AppTests/test.outputs/Logs/Test/Test-Transient Testing-2020.03.31_15-45-14-+0000.xcresult/Staging/1_Test/Diagnostics/AppTests-F0064961-672F-43EE-A2A8-A17885A6C539/AppTests-D6E05D76-90F7-4CF1-B3FB-FFF46B266FBC/Session-AppTests-2020-03-31_154514-AnmGKP.log
2020-03-31T15:47:50.9878870Z 2020-03-31 15:45:14.806 xcodebuild[5792:30582] [MT] IDETestOperationsObserverDebug: (70E1FC26-469A-4606-98B5-2F066BE2F07D) Beginning test session AppTests-70E1FC26-469A-4606-98B5-2F066BE2F07D at 2020-03-31 15:45:14.807 with Xcode 11C505 on target <DVTiPhoneSimulator: 0x7f8b0f59c0b0> {
2020-03-31T15:47:51.0807650Z 		SimDevice: New-iPhone 11 Pro Max-13.3 (D73F08ED-87E7-473D-ACA7-86E0E862ABAD, iOS 13.3, Shutdown)
2020-03-31T15:47:51.0808110Z } (13.3 (17C45))
2020-03-31T15:47:51.0809310Z 2020-03-31 15:45:26.688 xcodebuild[5792:30582] [MT] IDETestOperationsObserverDebug: (70E1FC26-469A-4606-98B5-2F066BE2F07D) Finished requesting crash reports. Continuing with testing.
2020-03-31T15:47:51.0809990Z 2020-03-31 15:47:42,714 The xcodebuild command got stuck and has not started test in 150. Will kill the command directly.
2020-03-31T15:47:51.0810590Z 2020-03-31 15:47:43.446 xcodebuild[5792:45540]  iOSSimulator: D73F08ED-87E7-473D-ACA7-86E0E862ABAD: Failed to launch app with identifier: com.acecilia.App and options: {
2020-03-31T15:47:51.0810750Z     "activate_suspended" = 0;
2020-03-31T15:47:51.0810860Z     arguments =     (
2020-03-31T15:47:51.0811290Z         "-NSTreatUnknownArgumentsAsOpen",
2020-03-31T15:47:51.0811420Z         NO,
2020-03-31T15:47:51.0811830Z         "-ApplePersistenceIgnoreState",
2020-03-31T15:47:51.0811980Z         YES
2020-03-31T15:47:51.0812090Z     );
2020-03-31T15:47:51.0812190Z     environment =     {
2020-03-31T15:47:51.0812310Z         "CA_ASSERT_MAIN_THREAD_TRANSACTIONS" = 0;
2020-03-31T15:47:51.0812420Z         "CA_DEBUG_TRANSACTIONS" = 0;
2020-03-31T15:47:51.0812750Z         "DYLD_FRAMEWORK_PATH" = "/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/test_runner_work_dir.c1Kj8V/TEST_ROOT:/Applications/Xcode_11.3.1.app/Contents/Developer/Platforms/iPhoneSimulator.platform/Developer//Library/Frameworks:/Applications/Xcode_11.3.1.app/Contents/Developer/Platforms/iPhoneSimulator.platform/Developer//Library/PrivateFrameworks";
2020-03-31T15:47:51.0813020Z         "DYLD_INSERT_LIBRARIES" = "/Applications/Xcode_11.3.1.app/Contents/Developer/Platforms/iPhoneSimulator.platform/Developer//usr/lib/libXCTestBundleInject.dylib";
2020-03-31T15:47:51.0813240Z         "DYLD_LIBRARY_PATH" = "/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/test_runner_work_dir.c1Kj8V/TEST_ROOT:/Applications/Xcode_11.3.1.app/Contents/Developer/Platforms/iPhoneSimulator.platform/Developer//usr/lib:";
2020-03-31T15:47:51.0813450Z         NSUnbufferedIO = YES;
2020-03-31T15:47:51.0813590Z         XCInjectBundleInto = "/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/test_runner_work_dir.c1Kj8V/TEST_ROOT/AppBundle.app/AppBundle";
2020-03-31T15:47:51.0814780Z         XCTestConfigurationFilePath = "/var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/bin/Libraries/App/AppTests.runfiles/__main__/private/var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/Libraries/App/AppTests/test.outputs/Logs/Test/Test-Transient Testing-2020.03.31_15-45-14-+0000.xcresult/Staging/1_Test/Diagnostics/AppTests-F0064961-672F-43EE-A2A8-A17885A6C539/AppTests-D6E05D76-90F7-4CF1-B3FB-FFF46B266FBC/LaunchSessions/70E1FC26-469A-4606-98B5-2F066BE2F07D/remote-container/tmp/AppTests-70E1FC26-469A-4606-98B5-2F066BE2F07D.xctestconfiguration";
2020-03-31T15:47:51.0815110Z     };
2020-03-31T15:47:51.0815280Z     stderr = "/dev/ttys000";
2020-03-31T15:47:51.0815400Z     stdout = "/dev/ttys000";
2020-03-31T15:47:51.0815510Z     "wait_for_debugger" = 0;
2020-03-31T15:47:51.0816020Z } (error = Error Domain=NSMachErrorDomain Code=-308 "(ipc/mig) server died")
2020-03-31T15:47:51.0816110Z 
2020-03-31T15:47:51.0816170Z 
2020-03-31T15:47:51.0817050Z *** If you believe this error represents a bug, please attach the result bundle at /var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/bin/Libraries/App/AppTests.runfiles/__main__/private/var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/Libraries/App/AppTests/test.outputs/Logs/Test/Test-Transient Testing-2020.03.31_15-45-14-+0000.xcresult
2020-03-31T15:47:51.0817200Z 
2020-03-31T15:47:51.0818710Z 2020-03-31 15:47:44.663 xcodebuild[5792:30817]  IDETestOperationsObserverDebug: Failure collecting logarchive: Couldn’t communicate with a helper application.
2020-03-31T15:47:51.0819340Z 2020-03-31 15:47:44.664 xcodebuild[5792:30582] [MT] IDETestOperationsObserverDebug: 149.868 elapsed -- Testing started completed.
2020-03-31T15:47:51.0819880Z 2020-03-31 15:47:44.664 xcodebuild[5792:30582] [MT] IDETestOperationsObserverDebug: 0.000 sec, +0.000 sec -- start
2020-03-31T15:47:51.0820400Z 2020-03-31 15:47:44.664 xcodebuild[5792:30582] [MT] IDETestOperationsObserverDebug: 149.868 sec, +149.868 sec -- end
2020-03-31T15:47:51.0820910Z 2020-03-31 15:47:44.664 xcodebuild[5792:30582] Error Domain=NSMachErrorDomain Code=-308 "(ipc/mig) server died"
2020-03-31T15:47:51.0821000Z 
2020-03-31T15:47:51.0821110Z Test session results, code coverage, and logs:
2020-03-31T15:47:51.0821990Z 	/var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/bin/Libraries/App/AppTests.runfiles/__main__/private/var/tmp/_bazel_runner/be40e32bcb059cba7db721280c1738b2/sandbox/darwin-sandbox/270/execroot/__main__/bazel-out/darwin-fastbuild/testlogs/Libraries/App/AppTests/test.outputs/Logs/Test/Test-Transient Testing-2020.03.31_15-45-14-+0000.xcresult
2020-03-31T15:47:51.0822240Z 
2020-03-31T15:47:51.0822420Z Testing failed:
2020-03-31T15:47:51.0822530Z 	Runner:
2020-03-31T15:47:51.0823140Z 		AppBundle.app encountered an error (Failed to install or launch the test runner. (Underlying error: The operation couldn’t be completed. (Mach error -308 - (ipc/mig) server died)))
2020-03-31T15:47:51.0823320Z 
2020-03-31T15:47:51.0823480Z ** TEST EXECUTE FAILED **

Environment:

  • macOS Catalina 10.15
  • Xcode 11.3.1
  • Simulator: New-iPhone 11 Pro Max, iOS 13.3
  • Bazel 2.2.0
  • Rules apple 0.19.0

EDIT1: I still see the problem, despite @jerrymarino proposed solution.

EDIT2: I did not realise that rules_apple are not creating releases anymore (#741), so the version I was using (0.19.0) is pretty old. When updating to the latest commit on master the problems mentioned in this issue seems to have gone away, as an updated rules_apple depends on an updated test runner (https://github.com/google/xctestrunner). My WORKSPACE file looks as follows:

  load("@bazel_tools//tools/build_defs/repo:git.bzl", "git_repository")

  git_repository(
      name = "build_bazel_rules_apple",
      remote = "https://github.com/bazelbuild/rules_apple.git",
      commit = "8a86023a2d66382e5f481eb177ddf58e6295bfd1", # Latest on master at the time of writing (31-03-2020)
  )

  load("@build_bazel_rules_apple//apple:repositories.bzl", "apple_rules_dependencies")
  apple_rules_dependencies()

  load("@build_bazel_rules_swift//swift:repositories.bzl", "swift_rules_dependencies")
  swift_rules_dependencies()

  load("@build_bazel_apple_support//lib:repositories.bzl", "apple_support_dependencies")
  apple_support_dependencies()

  load("@com_google_protobuf//:protobuf_deps.bzl", "protobuf_deps")
  protobuf_deps()

EDIT3: I experienced the problem again, despite the updated rules_apple. Did not find a workaround yet.

@acecilia
Copy link

acecilia commented Oct 19, 2020

New update. Using tags = ["exclusive"] seems to alleviate the issue.

I will need some more time to confirm if this is a reliable workaround, will update in a while
cc @barbasevich

EDIT: Yep, since using exclusive I am not finding the issue

@zachgray-slack
Copy link

Bump--this is still a pretty big issue and exclusive is a non-starter. Short of using bluepill, which is definitely not a silver bullet, I'm curious what can be done to improve the situation here and happy to contribute.

Seems like everyone is basically creating their own test infrastructure when they adopt bazel for ios AFAICT

@jerrymarino
Copy link
Contributor

jerrymarino commented Sep 14, 2022

I stumbled across this thread when digging into related issues. IMO the issue "simulator is flaky" demonstrates the core of it: this rule fails for hundreds of reasons but there is no way for someone to identify what part of the system is flaky or why. I estimate it's not actually tied to rules_apple - but components inside of xctestrunner, xctest, and simulator.

rules_apple, xctestrunner, and xcodebuild automation layers combined make it difficult to reason about where it is failing today. In practice root causes range from application issues, to resource contention, to driver level flake. I'd suggest filing a radar to make xcodebuild / unbounded complexity more debuggable.

I like @zachgray-slack 's idea overall: replacing xcodebuild simulator management by an OSS component that we can fix on a per version release, optimize, and make easier to debug. If we can get a drop in rule for bluepill that might be one way to do it. cc @ob - is that something ya'll added?

@ob
Copy link
Contributor

ob commented Sep 14, 2022

We wrote our own test runner for bluepill called bptestrunner.

We use it something like this

load("@bptestrunner//:bluepill_batch_test.bzl", "bluepill_batch_test")
bluepill_batch_test(
    name = "Some.xcscheme",
    test_targets = [
        "SomeTests"
    ],
    config_file = "scripts/bluepill/config.json",
    time_estimates = "scripts/bluepill/testTimeEstimates.json"
)

jerrymarino added a commit to bazel-ios/xctestrunner that referenced this issue Sep 14, 2022
Try to unveil problems with xctestrunner:
bazelbuild/rules_apple#185

Here is 1 quick idea: we can attach sample when it fails here -
obviously it extends to other possibilities. This is
just a start - it should have more logging
@jerrymarino
Copy link
Contributor

jerrymarino commented Sep 14, 2022

Awesome, thanks for posting up the example - I'll have to take a look at it. We've also had some rules_ios PRs to dice up the methods / enable sharding them with RBE. I imagine that'll work with bluepill: configurable via config_file: passing the individual methods there 👍

For xctestrunner / xcodebuild I really don't know of any flags that will increase verbosity to help indicate where it's failing. It'd be nice if they added that. The most basic way I'm addressing this now is to call general system level tools to dump state

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
P3 Would be nice, but probably next quarter at the earliest type: customer issue This issue is not a problem with the codebase, but an issue a customer is having.
Projects
None yet
Development

No branches or pull requests

8 participants