WebDriverAgent icon indicating copy to clipboard operation
WebDriverAgent copied to clipboard

Published 20 hours ago • verified publisher icon appium

WDA crashes middle of execution automation scripts

Open Veeru5c4 opened this issue 2 years ago • 7 comments

WDA crashes middle of execution and getting this error

Restarting after unexpected exit or crash in UITestingUITests/testSocketRunner; summary will include totals from previous launches.

Test Suite 'Selected tests' started at 2019-05-07 14:58:30.836 Test Suite 'WebDriverAgentRunner.xctest' started at 2019-05-07 14:58:30.836 Test Suite 'WebDriverAgentRunner.xctest' failed at 2019-05-07 14:58:30.837. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.000) seconds Test Suite 'WebDriverAgentLib.framework' started at 2019-05-07 14:58:30.837 Test Suite 'WebDriverAgentLib.framework' passed at 2019-05-07 14:58:30.838. Executed 0 tests, with 0 failures (0 unexpected) in 0.000 (0.000) seconds Test Suite 'Selected tests' failed at 2019-05-07 14:58:30.838. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.003) seconds

Please post the fix for the above issue.

Veeru5c4 avatar Mar 08 '22 11:03 Veeru5c4

My environment setup

Wda version : Xcode : 13.2.1 appium: 1.22.2 iOS version : 15.0

Veeru5c4 avatar Mar 08 '22 13:03 Veeru5c4

What's the device log?

KazuCocoa avatar Mar 08 '22 15:03 KazuCocoa

Restarting after unexpected exit, crash, or test timeout in -[UITestingUITests testRunner]; summary will include totals from previous launches.

Test Suite 'Selected tests' started at 2022-03-09 11:05:20.729 Test Suite 'WebDriverAgentRunner.xctest' started at 2022-03-09 11:05:20.730 Test Suite 'UITestingUITests' started at 2022-03-09 11:05:20.730 t = nans Suite Set Up 2022-03-09 11:05:20.743587+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( KeyboardAutocorrection ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.743989+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_changedAt" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.744313+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_buildAtChange" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.744603+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_previousValue" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.744899+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_analyzedAt" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.751954+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( KeyboardPrediction ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.752348+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( KeyboardShowPredictionBar ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.752878+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( DidShowGestureKeyboardIntroduction ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access Test Suite 'UITestingUITests' failed at 2022-03-09 11:05:20.756. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.026) seconds Test Suite 'WebDriverAgentRunner.xctest' failed at 2022-03-09 11:05:20.756. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.026) seconds Test Suite 'Selected tests' failed at 2022-03-09 11:05:20.756. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.027) seconds 2022-03-09 11:05:20.674 xcodebuild[59886:823024401] [MT] IDETestOperationsObserverDebug: 7111.567 elapsed -- Testing started completed. 2022-03-09 11:05:20.674 xcodebuild[59886:823024401] [MT] IDETestOperationsObserverDebug: 0.000 sec, +0.000 sec -- start 2022-03-09 11:05:20.674 xcodebuild[59886:823024401] [MT] IDETestOperationsObserverDebug: 7111.567 sec, +7111.567 sec -- end

Test session results, code coverage, and logs: /Users//Projects/mcloud-ios/tmp/DerivedData/00008020-00011C141E80402E/Logs/Test/Test-WebDriverAgentRnner-2022.03.09_09-06-48-+0530.xcresult

Failing tests: WebDriverAgentRunner: -[UITestingUITests testRunner]

** TEST FAILED **

Testing started Restarting after unexpected exit, crash, or test timeout in -[UITestingUITests testRunner]; summary will include totals from previous launches.

Test Suite 'Selected tests' started at 2022-03-09 11:05:20.729 Test Suite 'WebDriverAgentRunner.xctest' started at 2022-03-09 11:05:20.730 Test Suite 'UITestingUITests' started at 2022-03-09 11:05:20.730 t = nans Suite Set Up 2022-03-09 11:05:20.743587+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( KeyboardAutocorrection ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.743989+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_changedAt" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.744313+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_buildAtChange" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.744603+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_previousValue" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.744899+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( "KeyboardAutocorrection_analyzedAt" ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.751954+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( KeyboardPrediction ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.752348+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( KeyboardShowPredictionBar ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access 2022-03-09 11:05:20.752878+0530 WebDriverAgentRunner-Runner[1951:448707] [User Defaults] Couldn't write values for keys ( DidShowGestureKeyboardIntroduction ) in CFPrefsPlistSource<0x283b9ab80> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access Test Suite 'UITestingUITests' failed at 2022-03-09 11:05:20.756. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.026) seconds Test Suite 'WebDriverAgentRunner.xctest' failed at 2022-03-09 11:05:20.756. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.026) seconds Test Suite 'Selected tests' failed at 2022-03-09 11:05:20.756. Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.027) seconds 2022-03-09 11:05:20.674 xcodebuild[59886:823024401] [MT] IDETestOperationsObserverDebug: 7111.567 elapsed -- Testing started completed. 2022-03-09 11:05:20.674 xcodebuild[59886:823024401] [MT] IDETestOperationsObserverDebug: 0.000 sec, +0.000 sec -- start 2022-03-09 11:05:20.674 xcodebuild[59886:823024401] [MT] IDETestOperationsObserverDebug: 7111.567 sec, +7111.567 sec -- end

Test session results, code coverage, and logs: /Users/xxxr/Projects/mcloud-ios/tmp/DerivedData/00008020-00011C141E80402E/Logs/Test/Test-WebDriverAgentRunner-2022.03.09_09-06-48-+0530.xcresult

Failing tests: WebDriverAgentRunner: -[UITestingUITests testRunner]

** TEST FAILED **

Testing started

Veeru5c4 avatar Mar 09 '22 09:03 Veeru5c4

It was xcodebuild log. Could you specify appium:showIOSLog capability to get the device log as part of appium log? I would share it with GIST.

KazuCocoa avatar Mar 09 '22 16:03 KazuCocoa

Please find Appium logs

2022-03-10 10:11:22:078 - [35m[HTTP][39m [90m{"desiredCapabilities":{"showIOSLog":true,"server:CONFIG_UUID":"880464bb-b261-46e0-9125-dcdfbf42b9ef","showXcodeLog":true,"newCommandTimeout":240000,"platformVersion":"15.2","browserName":"safari","autoWebview":true,"platformName":"ios","udid":"00008027-001309861162402E","deviceName":"iPad","nativeWebTap":true},"capabilities":{"firstMatch":[{"browserName":"safari","platformName":"ios","server:CONFIG_UUID":"880464bb-b261-46e0-9125-dcdfbf42b9ef"}]}}[39m 2022-03-10 10:11:22:081 - [debug] [35m[W3C][39m Calling AppiumDriver.createSession() with args: [{"showIOSLog":true,"server:CONFIG_UUID":"880464bb-b261-46e0-9125-dcdfbf42b9ef","showXcodeLog":true,"newCommandTimeout":240000,"platformVersion":"15.2","browserName":"safari","autoWebview":true,"platformName":"ios","udid":"00008027-001309861162402E","deviceName":"Pune-iPad12Pro","nativeWebTap":true},null,{"firstMatch":[{"browserName":"safari","platformName":"ios","server:CONFIG_UUID":"880464bb-b261-46e0-9125-dcdfbf42b9ef"}]}] 2022-03-10 10:11:22:082 - [debug] [35m[BaseDriver][39m Event 'newSessionRequested' logged at 1646907082082 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:096 - [35m[BaseDriver][39m The following capabilities are not standard capabilities and should have an extension prefix: 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m mjpegServerPort 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m webkitDebugProxyPort 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m clearSystemFiles 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m webDriverAgentUrl 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m derivedDataPath 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m preventWDAAttachments 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m simpleIsVisibleCheck 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m wdaLocalPort 2022-03-10 10:11:22:098 - [35m[BaseDriver][39m usePrebuiltWDA 2022-03-10 10:11:22:099 - [35m[BaseDriver][39m useNewWDA 2022-03-10 10:11:22:099 - [35m[BaseDriver][39m platformVersion 2022-03-10 10:11:22:099 - [35m[BaseDriver][39m automationName 2022-03-10 10:11:22:099 - [35m[BaseDriver][39m deviceName 2022-03-10 10:11:22:106 - [35m[Appium][39m The following capabilities were provided in the JSONWP desired capabilities that are missing in W3C capabilities: ["showIOSLog","showXcodeLog","newCommandTimeout","autoWebview","udid","nativeWebTap"] 2022-03-10 10:11:22:107 - [35m[Appium][39m Trying to fix W3C capabilities by merging them with JSONWP caps 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m The following capabilities are not standard capabilities and should have an extension prefix: 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m showIOSLog 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m showXcodeLog 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m newCommandTimeout 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m autoWebview 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m udid 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m nativeWebTap 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m mjpegServerPort 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m webkitDebugProxyPort 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m clearSystemFiles 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m webDriverAgentUrl 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m derivedDataPath 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m preventWDAAttachments 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m simpleIsVisibleCheck 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m wdaLocalPort 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m usePrebuiltWDA 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m useNewWDA 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m platformVersion 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m automationName 2022-03-10 10:11:22:108 - [35m[BaseDriver][39m deviceName 2022-03-10 10:11:22:110 - [35m[Appium][39m Appium v1.22.2 creating new XCUITestDriver (v3.59.0) session 2022-03-10 10:11:22:114 - [debug] [35m[BaseDriver][39m W3C capabilities and MJSONWP desired capabilities were provided 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m Creating session with W3C capabilities: { 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "alwaysMatch": { 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:showIOSLog": true, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:showXcodeLog": true, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:newCommandTimeout": 240000, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:autoWebview": true, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:udid": "00008027-001309861162402E", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:nativeWebTap": true, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "browserName": "safari", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "platformName": "ios", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "server:CONFIG_UUID": "880464bb-b261-46e0-9125-dcdfbf42b9ef", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:mjpegServerPort": 20093, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:webkitDebugProxyPort": 20094, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:clearSystemFiles": "false", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:webDriverAgentUrl": "http://10.216.45.41:20092", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:derivedDataPath": "/Users/zensar/mcloud-ios/tmp/DerivedData/00008027-001309861162402E", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:preventWDAAttachments": "true", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:simpleIsVisibleCheck": "true", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:wdaLocalPort": "20092", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:usePrebuiltWDA": "true", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:useNewWDA": "false", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:platformVersion": "15.0", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:automationName": "XCUITest", 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "appium:deviceName": "iPadPro12_ZD3229" 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m }, 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m "firstMatch": [ 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m {} 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m ] 2022-03-10 10:11:22:115 - [debug] [35m[BaseDriver][39m } 2022-03-10 10:11:22:116 - [35m[BaseDriver][39m Number capability passed in as string. Functionality may be compromised. 2022-03-10 10:11:22:120 - [35m[BaseDriver][39m Capability 'clearSystemFiles' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [35m[BaseDriver][39m Capability 'usePrebuiltWDA' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [35m[BaseDriver][39m Capability 'useNewWDA' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [35m[BaseDriver][39m Capability 'simpleIsVisibleCheck' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [35m[BaseDriver][39m Capability 'wdaLocalPort' changed from string ('20092') to integer (20092). This may cause unexpected behavior 2022-03-10 10:11:22:122 - [35m[BaseDriver][39m The following capabilities were provided, but are not recognized by Appium: 2022-03-10 10:11:22:122 - [35m[BaseDriver][39m server:CONFIG_UUID 2022-03-10 10:11:22:122 - [35m[BaseDriver][39m preventWDAAttachments 2022-03-10 10:11:22:133 - [35m[BaseDriver][39m Session created with session id: fb7b7497-8b64-4c96-993b-ccde389f6f60 2022-03-10 10:11:22:331 - [debug] [35m[XCUITest][39m Current user: 'zensar' 2022-03-10 10:11:22:361 - [debug] [35m[XCUITest][39m Available devices: 00008030-001E05462186402E, 5b71650ea1a6c52cac875a31f4c736894dacbbf3, 00008030-000219E1227B802E, 00008101-000D70C92192001E, faf69563d98e0a5196608d10fa382891378bf8fb, 00008027-001309861162402E, 098d5077472fcb0e48c81b6840d05cfbfaca1902, 00008027-000268D60C92402E, beb099198878cc83b3843e9fc1dc4c0e4ea8a410, 00008101-001C205C22B8001E 2022-03-10 10:11:22:362 - [debug] [35m[XCUITest][39m Creating iDevice object with udid '00008027-001309861162402E' 2022-03-10 10:11:22:362 - [35m[XCUITest][39m Determining device to run tests on: udid: '00008027-001309861162402E', real device: true 2022-03-10 10:11:22:363 - [debug] [35m[BaseDriver][39m Event 'xcodeDetailsRetrieved' logged at 1646907082363 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:363 - [35m[XCUITest][39m Safari test requested 2022-03-10 10:11:22:365 - [debug] [35m[BaseDriver][39m Event 'appConfigured' logged at 1646907082364 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:366 - [debug] [35m[BaseDriver][39m Event 'resetStarted' logged at 1646907082366 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:366 - [debug] [35m[XCUITest][39m Reset: running ios real device reset flow 2022-03-10 10:11:22:366 - [debug] [35m[BaseDriver][39m Event 'resetComplete' logged at 1646907082366 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:366 - [35m[WebDriverAgent][39m Using WDA path: '/Users/zensar/.nvm/versions/node/v14.15.3/lib/node_modules/appium/node_modules/appium-webdriveragent' 2022-03-10 10:11:22:366 - [35m[WebDriverAgent][39m Using WDA agent: '/Users/zensar/.nvm/versions/node/v14.15.3/lib/node_modules/appium/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj' 2022-03-10 10:11:22:640 - [debug] [35m[XCUITest][39m Crash reports root '/Users/zensar/Library/Logs/CrashReporter/MobileDevice/iPadPro12_ZD3229' does not exist. Got nothing to gather. 2022-03-10 10:11:22:641 - [debug] [35m[BaseDriver][39m Event 'logCaptureStarted' logged at 1646907082641 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:642 - [35m[XCUITest][39m Setting up real device 2022-03-10 10:11:22:643 - [35m[DevCon Factory][39m Requesting connection for device 00008027-001309861162402E on local port 20092 2022-03-10 10:11:22:643 - [debug] [35m[DevCon Factory][39m Cached connections count: 0 2022-03-10 10:11:22:643 - [35m[DevCon Factory][39m Successfully requested the connection for 00008027-001309861162402E:20092 2022-03-10 10:11:22:646 - [debug] [35m[XCUITest][39m Starting WebDriverAgent initialization with the synchronization key 'XCUITestDriver' 2022-03-10 10:11:22:646 - [debug] [35m[XCUITest][39m Trying to start WebDriverAgent 1 times with 10000ms interval 2022-03-10 10:11:22:647 - [debug] [35m[XCUITest][39m These values can be customized by changing wdaStartupRetries/wdaStartupRetryInterval capabilities 2022-03-10 10:11:22:647 - [debug] [35m[BaseDriver][39m Event 'wdaStartAttempted' logged at 1646907082647 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:647 - [35m[WebDriverAgent][39m Using provided WebdriverAgent at 'http://10.216.45.41:20092' 2022-03-10 10:11:22:650 - [debug] [35m[WD Proxy][39m Matched '/status' to command name 'getStatus' 2022-03-10 10:11:22:651 - [debug] [35m[WD Proxy][39m Proxying [GET /status] to [GET http://10.216.45.41:20092/status] with no body 2022-03-10 10:11:22:674 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] <Notice>: Received request to exchange protocol versions, remote interface protocol version is: 0 2022-03-10 10:11:22:677 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> BE<2 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> BK<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> VI<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> VO<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: postMessageInternal:isPipeOpened:1, msg 169, dataLen 136 2022-03-10 10:11:22:678 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:L3 Control VO TX(70:70:8B:9C:0A:A0) Success=0 NoACK=0 Expired=0 OtherErr=0 2022-03-10 10:11:22:678 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> BE<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> BK<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> VI<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] <Notice>: LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> VO<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 wifid(WiFiPolicy)[50] <Notice>: __WiFiDeviceProcessLqmTxStatsEvent: LQM-TX: Success:2(100.0%) Failure:0(0.0%) Retries:0(0.0%) NoACK:0(0.0%) Drops:0(0.0%) NoBuff:0(0.0%) NoRes:0(0.0%) ChipErr:0(0.0%) Expired:0(0.0%) ForcedExpiry:0(0.0%) Free:0(0.0%) 2022-03-10 10:11:22:682 - [debug] [35m[WD Proxy][39m Got response with status 200: {"value":{"message":"WebDriverAgent is ready to accept commands","state":"success","os":{"testmanagerdVersion":28,"name":"iPadOS","sdkVersion":"15.2","version":"15.2.1"},"ios":{"ip":"169.254.11.16"},"ready":true,"build":{"time":"Mar 7 2022 09:31:47","productBundleIdentifier":"com.facebook.WebDriverAgentRunner"}},"sessionId":"D6D242EB-C548-4842-8482-55968AF8522C"} 2022-03-10 10:11:22:682 - [debug] [35m[BaseDriver][39m Event 'wdaSessionAttempted' logged at 1646907082682 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:682 - [debug] [35m[XCUITest][39m Sending createSession command to WDA 2022-03-10 10:11:22:684 - [debug] [35m[WD Proxy][39m Matched '/session' to command name 'createSession' 2022-03-10 10:11:22:686 - [debug] [35m[WD Proxy][39m Proxying [POST /session] to [POST http://10.216.45.41:20092/session] with body: {"capabilities":{"firstMatch":[{"bundleId":"com.apple.mobilesafari","arguments":[],"environment":{},"eventloopIdleDelaySec":0,"shouldWaitForQuiescence":true,"shouldUseTestManagerForVisibilityDetection":true,"maxTypingFrequency":60,"shouldUseSingletonTestManager":true,"shouldTerminateApp":true,"forceAppLaunch":true,"useNativeCachingStrategy":true,"forceSimulatorSoftwareKeyboardPresence":true}],"alwaysMatch":{}}} 2022-03-10 10:11:22:721 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] <Notice>: Terminating com.apple.mobilesafari 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd(FrontBoardServices)[315] <Notice>: FBSSystemAppProxy: Sending request to terminate application com.apple.mobilesafari 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] <Notice>: [FBSystemService] Request received from testmanagerd.315 to terminate application com.apple.mobilesafari: "Terminating for automation testing." 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] <Notice>: [application<com.apple.mobilesafari>:4056] SpringBoard requested termination ("Terminating for automation testing.") 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] <Notice>: [application<com.apple.mobilesafari>:4056] Now flagged as pending exit for reason: explicit kill request from client 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] <Notice>: [application<com.apple.mobilesafari>:4056] Received termination request: <FBSProcessTerminationRequest: 0x282ad6f80; label: "Terminating for automation testing."; exceptionCode: "Force Quit (0xFBFBFBFB)"; reportType: (none); explanation: "Terminating for automation testing."> 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] <Notice>: [application<com.apple.mobilesafari>:4056] Executing termination request: <FBSProcessTerminationRequest: 0x282ab0080; label: "Terminating for automation testing."; exceptionCode: "Force Quit (0xFBFBFBFB)"; reportType: (none); explanation: "Terminating for automation testing."> 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] <Notice>: Received termination request from [daemon<com.apple.SpringBoard>:60] on <RBSProcessPredicate <RBSProcessHandlePredicateImpl| application<com.apple.mobilesafari>:4056>> with context <RBSTerminateContext| domain:10 code:0xFBFBFBFB explanation:Terminating for automation testing. 2022-03-10 10:11:22:722 - [35m[IOSDeviceLog][39m ProcessVisibility: Background 2022-03-10 10:11:22:723 - [35m[IOSDeviceLog][39m ProcessState: Suspended reportType:None maxTerminationResistance:Interactive> 2022-03-10 10:11:22:723 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] <Notice>: Executing termination request for: <RBSProcessPredicate <RBSProcessHandlePredicateImpl| application<com.apple.mobilesafari>:4056>> 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] <Notice>: [application<com.apple.mobilesafari>:4056] Terminating with context: <RBSTerminateContext| domain:10 code:0xFBFBFBFB explanation:Terminating for automation testing. 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m ProcessVisibility: Background 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m ProcessState: Suspended reportType:None maxTerminationResistance:Interactive> 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] <Notice>: [application<com.apple.mobilesafari>:4056] terminate_with_reason() success 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] <Notice>: [application<com.apple.mobilesafari>:4056] Workspace connection invalidated. 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoardServices)[60] <Notice>: [SBApplicationServer] Removing client application<com.apple.mobilesafari>:4056. 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(IOKit)[63] <Notice>: Connection removed: IOHIDEventSystemConnection uuid:33592F05-F546-401E-ACEF-D13796A10C29 pid:4056 process:MobileSafari type:Passive entitlements:0x0 caller:BackBoardServices: + 340 attributes:{ 2022-03-10 10:11:22:724 - [35m[IOSDeviceLog][39m HighFrequency = 1; 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m bundleID = "com.apple.mobilesafari"; 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m pid = 4056; 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m } state:0x1 events:900 mask:0x800 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 backboardd[63] <Notice>: Received Connection Invalidation: <(null):0x12f2404e0> 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 backboardd[63] <Notice>: Connection: Remove: <(null):0x12f2404e0> 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(BackBoardHIDEventFoundation)[63] <Notice>: Removing client connection <BKHIDClientConnection: 0x107707680; IOHIDEventSystemConnectionRef: 0x12e8c6c20; vpid: 4056(v2E92); taskPort: 0x5EB4B7; bundleID: com.apple.mobilesafari> for client: IOHIDEventSystemConnection uuid:33592F05-F546-401E-ACEF-D13796A10C29 pid:4056 process:MobileSafari type:Passive entitlements:0x0 caller:BackBoardServices: + 340 attributes:{ 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m HighFrequency = 1; 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m bundleID = "com.apple.mobilesafari"; 2022-03-10 10:11:22:725 - [35m[IOSDeviceLog][39m pid = 4056; 2022-03-10 10:11:22:726 - [35m[IOSDeviceLog][39m } state:0x1 events:900 mask:0x800 source:HID 2022-03-10 10:11:22:726 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(GAXBackboardServer)[63] <Notice>: Was notified gax client did become invalid: com.apple.mobilesafari. send right name: 6c480f 2022-03-10 10:11:22:726 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(HIDAnalytics)[63] <Notice>: HIDAnalytics Unregister Send event com.apple.hid.queueUsage 2022-03-10 10:11:22:729 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] <Notice>: Connection to target invalidated. 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] <Notice>: Closed <XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056), removing from { 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m 259 = "<XCTTargetBootstrapSession: 0x15ca12250>(pid 259)"; 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m 4056 = "<XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056)"; 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m 3037 = "<XCTTargetBootstrapSession: 0x15c804ba0>(pid 3037)"; 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m 60 = "<XCTTargetBootstrapSession: 0x15ca12230>(pid 60)"; 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m } 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] <Notice>: Invalidating <XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056) 2022-03-10 10:11:22:730 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] <Notice>: Invalidated <XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056) 2022-03-10 10:11:22:733 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] <Notice>: XPC connection invalidated: [application<com.apple.mobilesafari>:4056] 2022-03-10 10:11:22:734 - [35m[IOSDeviceLog][39m Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] <Error>: RBSStateCapture remove item called for untracked item <RBProcessMonitorObserver| qos:0 qos:(null) configs:{

Veeru5c4 avatar Mar 10 '22 13:03 Veeru5c4

Perhaps the above attached log was in the middle of a new session request (and not the crash)? GitHub GIST helps to not cut the log in the middle.

KazuCocoa avatar Apr 20 '22 01:04 KazuCocoa

I experience same issue when running tests for an enough long time. WebDriverAgent stops working and crashes after one or more days running.

My environment:

XCode 15.0.1 iOS 15.8 Appium 2.1.3 WebDriverAgent 5.11 (it happens with every release since, at least, 4.10)

My WebDriverAgent log:

2024-01-23 06:27:30.364115+0100 WebDriverAgentRunner-Runner[63809:7878667] Getting the most recent active application (out of 1 total items)
2024-01-23 06:27:30.368108+0100 WebDriverAgentRunner-Runner[63809:7878667] The following attributes were requested to be included into the XML: {(
        FBNameAttribute
)}
        t = 69747.21s Requesting snapshot of accessibility hierarchy for app with pid 72040
2024-01-23 06:27:32.767657+0100 WebDriverAgentRunner-Runner[63809:8343589] [Default] Exiting due to IDE disconnection.
2024-01-23 06:27:35.568578+0100 WebDriverAgentRunner-Runner[72051:8346103] [Default] Running tests...

Restarting after unexpected exit, crash, or test timeout in -[UITestingUITests testRunner]; summary will include totals from previous launches.

Test Suite 'Selected tests' started at 2024-01-23 06:27:37.186.
Test Suite 'WebDriverAgentRunner.xctest' started at 2024-01-23 06:27:37.187.
Test Suite 'UITestingUITests' started at 2024-01-23 06:27:37.191.
        t =            nans Suite Set Up
2024-01-23 06:27:37.421405+0100 WebDriverAgentRunner-Runner[72051:8346103] [User Defaults] Couldn't write values for keys (
        KeyboardAutocorrection
) in CFPrefsPlistSource<0x2832ce680> (Domain: com.apple.keyboard.preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access

[...]

Test Suite 'UITestingUITests' failed at 2024-01-23 06:27:37.495.
	 Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.303) seconds
Test Suite 'WebDriverAgentRunner.xctest' failed at 2024-01-23 06:27:37.495.
	 Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.308) seconds
Test Suite 'Selected tests' failed at 2024-01-23 06:27:37.497.
	 Executed 1 test, with 1 failure (0 unexpected) in 0.000 (0.311) seconds
2024-01-23 06:27:37.572 xcodebuild[45194:44919173] [MT] IDETestOperationsObserverDebug: 69757.904 elapsed -- Testing started completed.
2024-01-23 06:27:37.572 xcodebuild[45194:44919173] [MT] IDETestOperationsObserverDebug: 0.000 sec, +0.000 sec -- start
2024-01-23 06:27:37.572 xcodebuild[45194:44919173] [MT] IDETestOperationsObserverDebug: 69757.904 sec, +69757.904 sec -- end

Test session results, code coverage, and logs:
	/Users/tobeit/Library/Developer/Xcode/DerivedData/WebDriverAgent-gfoyreandsphzlfkogbdrtcjqdzo/Logs/Test/Test-WebDriverAgentRunner-2024.01.22_11-04-55-+0100.xcresult

Failing tests:
	-[UITestingUITests testRunner]

 TEST FAILED

tobeitgit avatar Jan 23 '24 10:01 tobeitgit