Handle timing-out Simulator/Devices #84

valeriomazzeo · 2015-07-09T10:53:22Z

Certain times Xcode server failed to start the simulator with the following error:

2015-07-06 22:06:45.335 Initializing test infrastructure.
2015-07-06 22:08:45.335 Test operation failure: Timed out waiting 120 seconds for simulator to boot, current state is 1.
2015-07-06 22:08:45.335 _finishWithError:Error Domain=IDEUnitTestsOperationsObserverErrorDomain Code=3 "Timed out waiting 120 seconds for simulator to boot, current state is 1." UserInfo=0x7fe168bb6af0 {NSLocalizedDescription=Timed out waiting 120 seconds for simulator to boot, current state is 1.} didCancel: 1
2015-07-06 22:08:45.335 Finished syncing device diagnostic logs after 0.0s.

When that happen the bot show Unknown Status and doesn't mark the build as failed.

Buildasaur comment then says:

Result of integration 1
Integration took 25 minutes and 46 seconds.
All 0 tests passed, but please fix 567 warnings.

and make the build pass.

It would be super awesome if buildasaur could detect the above error in the logs, flag the build as failed and start a new integration, that in most of the cases fixes the problem.

The text was updated successfully, but these errors were encountered:

czechboy0 · 2015-07-13T17:23:45Z

Hi @valeriomazzeo, sorry for the late response, I was on vacation.

I personally don't test on iOS Simulators (only on real devices), so I haven't seen this problem. Do you know what the exact Xcode Server status is when this happens?

czechboy0 · 2015-07-13T17:44:01Z

This is strange, I looked at the code and as you can see, the integration state must have been 'success', 'warnings' or 'analyzer warnings', because you got this kind of a GitHub comment from Buildasaur.

Please provide more info, this looks like a weird bug either in Buildasaur or in Xcode Server 👍

valeriomazzeo · 2015-07-13T20:12:46Z

The bug is in Xcode server / xcodebuild, but buildasaur could actually get around it!

Is it possible to search in the logs for that error and let the integration fail and then run again automatically when that error is present?

This happens also when testing on one simulator only.

This is how it looks like, you can see the simulator that failed to start:

When tests are running on one simulator only and it timeouts then probably the status is 'warnings', because the tests didn't run.

If it can help, this is happening almost all the time for us, but I think it's somehow related to have a very big project.

czechboy0 · 2015-07-13T20:30:09Z

Interesting. What would be very useful to me would be if you could just go to https://YOUR_XCODE_SERVER_IP:20343/api/integrations, where you'd put your xcode server IP address and copied the output. I'd like to see what the integrations end up looking in this case.

Downloading and parsing the output would also be possible, but it'd be a lot of work + hacky "solution", so I'd like to avoid that if possible.

Feel free to DM me a Dropbox link or something: czechboy0

valeriomazzeo · 2015-07-13T21:23:25Z

this is interesting, the json file is very big 5+ MB but this is the part regarding the screenshot I posted previously:

"buildResultSummary": {
        "analyzerWarningCount": 26,
        "testFailureCount": 2,
        "testsChange": 0,
        "errorCount": 0,
        "testsCount": 1804,
        "testFailureChange": 0,
        "warningChange": 0,
        "regressedPerfTestCount": 0,
        "warningCount": 583,
        "errorChange": -3,
        "improvedPerfTestCount": 0,
        "analyzerWarningChange": 0
      },
      "result": "test-failures",
      "testedDevices": [
        {
          "connected": true,
          "ID": "f02d2cc25ce157ecaaee40afbb01d028",
          "simulator": true,
          "revision": "3-e27e8395b96a1fcca93c0d9cd2606b99",
          "osVersion": "8.4",
          "deviceType": "com.apple.iphone-simulator",
          "supported": true,
          "identifier": "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9",
          "enabledForDevelopment": true,
          "architecture": "x86_64",
          "isServer": false,
          "doc_type": "device",
          "platformIdentifier": "com.apple.platform.iphonesimulator",
          "name": "iPhone 6 Plus",
          "retina": false
        },
        {
          "connected": true,
          "ID": "9c4825c058392cda698831bb9000a637",
          "simulator": true,
          "revision": "9-1e17b53ab0f98ad8c30b40739c7d937e",
          "osVersion": "7.1",
          "deviceType": "com.apple.iphone-simulator",
          "supported": true,
          "identifier": "DB981248-DF25-464A-871E-37FA1FAD137B",
          "enabledForDevelopment": true,
          "architecture": "i386",
          "isServer": false,
          "doc_type": "device",
          "platformIdentifier": "com.apple.platform.iphonesimulator",
          "name": "iPhone 4s",
          "retina": false
        },
        {
          "connected": true,
          "ID": "f02d2cc25ce157ecaaee40afbb019f18",
          "simulator": true,
          "revision": "3-d6877a8bee889d931320468e157ad001",
          "osVersion": "8.4",
          "deviceType": "com.apple.iphone-simulator",
          "supported": true,
          "identifier": "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F",
          "enabledForDevelopment": true,
          "architecture": "i386",
          "isServer": false,
          "doc_type": "device",
          "platformIdentifier": "com.apple.platform.iphonesimulator",
          "name": "iPhone 4s",
          "retina": false
        }

So, the timeout error is definitely on Xcode server / xcodebuild, but maybe there is something also in buildasaur!

czechboy0 · 2015-07-13T21:28:46Z

Hmm yeah, I see what the problem is. Since you're testing on multiple simulators and two of them tested just fine, the third one (the one that never ran), doesn't affect the result. Which is test-failures right now, but since it never started, I'd expect it to be something like internal-error.

Before we go any further, are you using Xcode Server with Xcode 6 or 7?

valeriomazzeo · 2015-07-13T21:43:33Z

Xcode 6.

I think there are two things going on here:

Xcode server is not considering the timed out simulator in "result": "test-failures", so if the others two simulators were passing the tests in this specific case the result would have probably been warnings instead.
Buildasaur is reading the result field but when posting the comment may instead say:

Result of integration 1
Integration took 25 minutes and 46 seconds.
All 0 tests passed, but please fix 567 warnings on iPhone 6 Plus iOS 8.4
1800 tests passed and 2 failed, but please fix 567 warnings on iPhone 4s iOS 7.1
1800 tests passed and 2 failed, but please fix 567 warnings on iPhone 4s iOS 8.4

Because it looks like buildasaur it's reading the report only of the first device, but that won't all the time be correct (assuming that multiple report are available).

czechboy0 · 2015-07-13T21:52:14Z

Ok - first thing: I'm focusing all my time now to getting onto Xcode 7's API so that new Buildasaur is ready when it comes out this fall. This is not to say I won't fix bugs in the older Buildasaur versions, just that major changes will require you to move to Xcode 7 at some point, maybe even before its stable release.

But this issue I think exists the same way in both Xcode 6 and 7.

I agree, I think that if those tests succeeded, you might even have Buildasaur say "Perfect Build, all 12345 tests passed", even when one simulator fails to initialize altogether.
Buildasaur uses the result field of the whole integration, not of the device. This seems to be a bug in Xcode Server that it reports success even when one device failed to start, but I guess that's the same as when one device isn't connected at all - Xcode Server just gives you a warning but overall creates the result based on just the devices that the tests actually ran on. This is definitely radar-able.

This way of reporting is actually a great idea! I'll create a new ticket just for investigating how much work that would be, but I would actually like that level of detail as well.

valeriomazzeo · 2015-07-13T22:17:14Z

My concern is that the same happen with a bot that tests only on 1 simulator at the time. Therefore, only adding a more detailed report won't help because in that case it won't make any difference.

czechboy0 · 2015-07-13T22:21:16Z

Yup, that's correct. The detailed report was not to fix this issues, which is an Xcode Server bug, just to make results a bit more informative.

What would really help me is to get that response from integrations endpoint, so that I can take a look at how to parse test results from multiple devices/simulators.

valeriomazzeo · 2015-07-13T23:17:21Z

Do you mean the whole version of what I pasted above or is another endpoint?

czechboy0 · 2015-07-13T23:19:51Z

Yeah the whole output of the above, so that I could see what it looks like when one simulator fails to launch but the rest runs fine.

valeriomazzeo · 2015-07-14T07:42:32Z

Isn't something you can do configuring the builadsaur project to test on more than one simulator?

I'll see what I can do about stripping personal information from that log file so I can send it to you.

czechboy0 · 2015-07-14T07:45:22Z

Yes, you can. When editing a Build Template, you select an iOS scheme and then Selected Devices and Simulators, which lets you tick devices/simulators below.

valeriomazzeo · 2015-07-14T08:40:20Z

I meant, you in the sense that you can replicate it on your server.

Looking at the logs, it doesn't seem there is a summary for device available.

"testHierarchy": {
"TestFile1": {
          "TestSpec": {
            "_xcsAggrDeviceStatus": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testThereIsNoFormatter": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testStringWithWhatTheFormaterGives": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testTheOptionsAndTheTemplate": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            }
          },
          "_xcsAggrDeviceStatus": {
            "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
            "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
            "DB981248-DF25-464A-871E-37FA1FAD137B": 1
          },
          "AnotherSpec": {
            "testShouldDuplicateTheSizeIfTheResolutionIs2": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testShouldReturnDefaultValuesForTheRequiredFields": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testShouldUseTheSameSizeIfTheResolutionIs1": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testShouldUse10AsSizeForTheOriginalSize": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "_xcsAggrDeviceStatus": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            }
          },
          "AndAnotherSpec": {
            "testShouldNOTGiveThePreviosLocation": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testShouldHaveAPreviousLocation": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testShouldGiveInmedialtyThePreviosLocation": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testShouldNOTHavePreviousLocation": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },
            "testShouldStopUpdating": {
              "F5D4D20E-4A43-403B-AD8B-BD58B137BB2F": 1,
              "9D4A2BAC-AD1A-4CD0-B7BB-403F3C9D98F9": 1,
              "DB981248-DF25-464A-871E-37FA1FAD137B": 1
            },

if you look inside each test, those are the identifier of the device, you can match them with the other snippet in the previous post.

czechboy0 · 2015-07-14T09:21:57Z

Yeah I might need to do some processing myself. But that's fine as long as everything is included in the Integration object.

Cool, thanks. I'll look into it.

valeriomazzeo · 2015-07-14T09:52:18Z

👍

valeriomazzeo · 2015-07-16T16:01:18Z

To get back to the original topic, would it be possible to add an option to check that log for errors and launch another integration?

This happens also when testing on a single device and in this case adding more information about the device being tested won't solve the problem.

czechboy0 · 2015-07-16T19:36:43Z

I am worried about continuously starting new integrations. I'm not saying I won't do it, just sharing my reservations about trying to fix the bugs of Xcode Server by just running it again. Also, downloading the log and parsing it would be pretty slow. Again, doable, I just want to make sure there is no other way to recognize this case and react appropriately.

czechboy0 · 2015-07-17T10:45:50Z

@valeriomazzeo

There might be a way to detect this (possibly). In this timing-out case, this seems to be true:
currentStep is completed
result doesn't say something that we'd expect (like test-errors or something like that), instead shows a result as if everything went fine
performsTestAction is true (tests should be ran)
testingDeviceIDs and testingDestinationType tells us what devices tests should be ran on
and most importantly:
testHierarchy is empty (this won't be the case if only one of multiple simulators times out, so we have to be careful here)

I'm just noting this down here, so that we can go back and try to figure out logic to detect the case without false positives.

One thing to consider, however, is if you mark the bot as testable on a couple of devices/simulators, but your test target doesn't actually have any tests. Then we might get into an infinite re-integrating loop.

valeriomazzeo · 2015-07-27T08:59:24Z

Hi @czechboy0, is there any progress on this?

Is there anything I can help you with?

czechboy0 · 2015-07-27T09:27:59Z

Hey @valeriomazzeo,

sorry, no, I haven't had time to do this yet. Feel free to send a PR with a fix if you can come up with something based on the conversation we had above.

czechboy0 · 2015-09-25T10:55:34Z

Hi @valeriomazzeo, it's been a while. Could you please update to the latest Xcode 7, OS X Server 5 and Buildasaur 0.4.0 and try whether this is still happening? It's a known issue in xcodebuild, so I'm wondering whether you're still seeing this issue. Thanks! 👍

valeriomazzeo · 2015-09-25T13:42:43Z

We changed project structure and we didn't encounter this issue anymore to be honest after that.
Also updating cocoapods, the result was to end up with less targets (in total) and that may have helped.

czechboy0 · 2015-09-25T13:58:42Z

Okay, let's close this for now and feel free to reopen it if you see it again. Thanks!

czechboy0 added bug investigate labels Jul 11, 2015

czechboy0 mentioned this issue Jul 13, 2015

Give more detailed test result comments #87

Closed

czechboy0 changed the title ~~Buildasaur build pass when Simulator failed to start~~ Handle failing Simulator/Devices better when multiple devices are tested Jul 15, 2015

czechboy0 changed the title ~~Handle failing Simulator/Devices better when multiple devices are tested~~ Handle timing-out Simulator/Devices Jul 17, 2015

czechboy0 added waiting-for-input and removed bug labels Sep 25, 2015

czechboy0 removed the investigate label Sep 25, 2015

czechboy0 mentioned this issue Sep 25, 2015

New status comment format (details of warnings, errors, test failures) #49

Open

6 tasks

czechboy0 closed this as completed Sep 25, 2015

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Handle timing-out Simulator/Devices #84

Handle timing-out Simulator/Devices #84

valeriomazzeo commented Jul 9, 2015

czechboy0 commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 14, 2015

czechboy0 commented Jul 14, 2015

valeriomazzeo commented Jul 14, 2015

czechboy0 commented Jul 14, 2015

valeriomazzeo commented Jul 14, 2015

valeriomazzeo commented Jul 16, 2015

czechboy0 commented Jul 16, 2015

czechboy0 commented Jul 17, 2015

valeriomazzeo commented Jul 27, 2015

czechboy0 commented Jul 27, 2015

czechboy0 commented Sep 25, 2015

valeriomazzeo commented Sep 25, 2015

czechboy0 commented Sep 25, 2015

Handle timing-out Simulator/Devices #84

Handle timing-out Simulator/Devices #84

Comments

valeriomazzeo commented Jul 9, 2015

czechboy0 commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 13, 2015

czechboy0 commented Jul 13, 2015

valeriomazzeo commented Jul 14, 2015

czechboy0 commented Jul 14, 2015

valeriomazzeo commented Jul 14, 2015

czechboy0 commented Jul 14, 2015

valeriomazzeo commented Jul 14, 2015

valeriomazzeo commented Jul 16, 2015

czechboy0 commented Jul 16, 2015

czechboy0 commented Jul 17, 2015

valeriomazzeo commented Jul 27, 2015

czechboy0 commented Jul 27, 2015

czechboy0 commented Sep 25, 2015

valeriomazzeo commented Sep 25, 2015

czechboy0 commented Sep 25, 2015