search

appium / WebDriverAgent

A WebDriver server for iOS and tvOS
Other
1.18k stars 370 forks source link

WDA crashes middle of execution automation scripts #571

Open Veeru5c4 opened 2 years ago

Veeru5c4 commented 2 years ago

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 commented 2 years ago

My environment setup

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

KazuCocoa commented 2 years ago

What's the device log?

Veeru5c4 commented 2 years ago

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

KazuCocoa commented 2 years ago

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.

Veeru5c4 commented 2 years ago

Please find Appium logs

2022-03-10 10:11:22:078 - [HTTP] {"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"}]}} 2022-03-10 10:11:22:081 - [debug] [W3C] 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] [BaseDriver] Event 'newSessionRequested' logged at 1646907082082 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:096 - [BaseDriver] The following capabilities are not standard capabilities and should have an extension prefix: 2022-03-10 10:11:22:098 - [BaseDriver] mjpegServerPort 2022-03-10 10:11:22:098 - [BaseDriver] webkitDebugProxyPort 2022-03-10 10:11:22:098 - [BaseDriver] clearSystemFiles 2022-03-10 10:11:22:098 - [BaseDriver] webDriverAgentUrl 2022-03-10 10:11:22:098 - [BaseDriver] derivedDataPath 2022-03-10 10:11:22:098 - [BaseDriver] preventWDAAttachments 2022-03-10 10:11:22:098 - [BaseDriver] simpleIsVisibleCheck 2022-03-10 10:11:22:098 - [BaseDriver] wdaLocalPort 2022-03-10 10:11:22:098 - [BaseDriver] usePrebuiltWDA 2022-03-10 10:11:22:099 - [BaseDriver] useNewWDA 2022-03-10 10:11:22:099 - [BaseDriver] platformVersion 2022-03-10 10:11:22:099 - [BaseDriver] automationName 2022-03-10 10:11:22:099 - [BaseDriver] deviceName 2022-03-10 10:11:22:106 - [Appium] 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 - [Appium] Trying to fix W3C capabilities by merging them with JSONWP caps 2022-03-10 10:11:22:108 - [BaseDriver] The following capabilities are not standard capabilities and should have an extension prefix: 2022-03-10 10:11:22:108 - [BaseDriver] showIOSLog 2022-03-10 10:11:22:108 - [BaseDriver] showXcodeLog 2022-03-10 10:11:22:108 - [BaseDriver] newCommandTimeout 2022-03-10 10:11:22:108 - [BaseDriver] autoWebview 2022-03-10 10:11:22:108 - [BaseDriver] udid 2022-03-10 10:11:22:108 - [BaseDriver] nativeWebTap 2022-03-10 10:11:22:108 - [BaseDriver] mjpegServerPort 2022-03-10 10:11:22:108 - [BaseDriver] webkitDebugProxyPort 2022-03-10 10:11:22:108 - [BaseDriver] clearSystemFiles 2022-03-10 10:11:22:108 - [BaseDriver] webDriverAgentUrl 2022-03-10 10:11:22:108 - [BaseDriver] derivedDataPath 2022-03-10 10:11:22:108 - [BaseDriver] preventWDAAttachments 2022-03-10 10:11:22:108 - [BaseDriver] simpleIsVisibleCheck 2022-03-10 10:11:22:108 - [BaseDriver] wdaLocalPort 2022-03-10 10:11:22:108 - [BaseDriver] usePrebuiltWDA 2022-03-10 10:11:22:108 - [BaseDriver] useNewWDA 2022-03-10 10:11:22:108 - [BaseDriver] platformVersion 2022-03-10 10:11:22:108 - [BaseDriver] automationName 2022-03-10 10:11:22:108 - [BaseDriver] deviceName 2022-03-10 10:11:22:110 - [Appium] Appium v1.22.2 creating new XCUITestDriver (v3.59.0) session 2022-03-10 10:11:22:114 - [debug] [BaseDriver] W3C capabilities and MJSONWP desired capabilities were provided 2022-03-10 10:11:22:115 - [debug] [BaseDriver] Creating session with W3C capabilities: { 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "alwaysMatch": { 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:showIOSLog": true, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:showXcodeLog": true, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:newCommandTimeout": 240000, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:autoWebview": true, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:udid": "00008027-001309861162402E", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:nativeWebTap": true, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "browserName": "safari", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "platformName": "ios", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "server:CONFIG_UUID": "880464bb-b261-46e0-9125-dcdfbf42b9ef", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:mjpegServerPort": 20093, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:webkitDebugProxyPort": 20094, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:clearSystemFiles": "false", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:webDriverAgentUrl": "http://10.216.45.41:20092", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:derivedDataPath": "/Users/zensar/mcloud-ios/tmp/DerivedData/00008027-001309861162402E", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:preventWDAAttachments": "true", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:simpleIsVisibleCheck": "true", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:wdaLocalPort": "20092", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:usePrebuiltWDA": "true", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:useNewWDA": "false", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:platformVersion": "15.0", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:automationName": "XCUITest", 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "appium:deviceName": "iPadPro12_ZD3229" 2022-03-10 10:11:22:115 - [debug] [BaseDriver] }, 2022-03-10 10:11:22:115 - [debug] [BaseDriver] "firstMatch": [ 2022-03-10 10:11:22:115 - [debug] [BaseDriver] {} 2022-03-10 10:11:22:115 - [debug] [BaseDriver] ] 2022-03-10 10:11:22:115 - [debug] [BaseDriver] } 2022-03-10 10:11:22:116 - [BaseDriver] Number capability passed in as string. Functionality may be compromised. 2022-03-10 10:11:22:120 - [BaseDriver] Capability 'clearSystemFiles' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [BaseDriver] Capability 'usePrebuiltWDA' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [BaseDriver] Capability 'useNewWDA' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [BaseDriver] Capability 'simpleIsVisibleCheck' changed from string to boolean. This may cause unexpected behavior 2022-03-10 10:11:22:120 - [BaseDriver] Capability 'wdaLocalPort' changed from string ('20092') to integer (20092). This may cause unexpected behavior 2022-03-10 10:11:22:122 - [BaseDriver] The following capabilities were provided, but are not recognized by Appium: 2022-03-10 10:11:22:122 - [BaseDriver] server:CONFIG_UUID 2022-03-10 10:11:22:122 - [BaseDriver] preventWDAAttachments 2022-03-10 10:11:22:133 - [BaseDriver] Session created with session id: fb7b7497-8b64-4c96-993b-ccde389f6f60 2022-03-10 10:11:22:331 - [debug] [XCUITest] Current user: 'zensar' 2022-03-10 10:11:22:361 - [debug] [XCUITest] 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] [XCUITest] Creating iDevice object with udid '00008027-001309861162402E' 2022-03-10 10:11:22:362 - [XCUITest] Determining device to run tests on: udid: '00008027-001309861162402E', real device: true 2022-03-10 10:11:22:363 - [debug] [BaseDriver] Event 'xcodeDetailsRetrieved' logged at 1646907082363 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:363 - [XCUITest] Safari test requested 2022-03-10 10:11:22:365 - [debug] [BaseDriver] Event 'appConfigured' logged at 1646907082364 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:366 - [debug] [BaseDriver] Event 'resetStarted' logged at 1646907082366 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:366 - [debug] [XCUITest] Reset: running ios real device reset flow 2022-03-10 10:11:22:366 - [debug] [BaseDriver] Event 'resetComplete' logged at 1646907082366 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:366 - [WebDriverAgent] 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 - [WebDriverAgent] 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] [XCUITest] 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] [BaseDriver] Event 'logCaptureStarted' logged at 1646907082641 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:642 - [XCUITest] Setting up real device 2022-03-10 10:11:22:643 - [DevCon Factory] Requesting connection for device 00008027-001309861162402E on local port 20092 2022-03-10 10:11:22:643 - [debug] [DevCon Factory] Cached connections count: 0 2022-03-10 10:11:22:643 - [DevCon Factory] Successfully requested the connection for 00008027-001309861162402E:20092 2022-03-10 10:11:22:646 - [debug] [XCUITest] Starting WebDriverAgent initialization with the synchronization key 'XCUITestDriver' 2022-03-10 10:11:22:646 - [debug] [XCUITest] Trying to start WebDriverAgent 1 times with 10000ms interval 2022-03-10 10:11:22:647 - [debug] [XCUITest] These values can be customized by changing wdaStartupRetries/wdaStartupRetryInterval capabilities 2022-03-10 10:11:22:647 - [debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1646907082647 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:647 - [WebDriverAgent] Using provided WebdriverAgent at 'http://10.216.45.41:20092' 2022-03-10 10:11:22:650 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2022-03-10 10:11:22:651 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://10.216.45.41:20092/status] with no body 2022-03-10 10:11:22:674 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] : Received request to exchange protocol versions, remote interface protocol version is: 0 2022-03-10 10:11:22:677 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC BE<2 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC BK<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC VI<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(70:70:8B:9C:0A:A0) AC VO<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:677 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : postMessageInternal:isPipeOpened:1, msg 169, dataLen 136 2022-03-10 10:11:22:678 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : 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 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC BE<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC BK<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC VI<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 kernel(IO80211Family)[0] : LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC VO<0 0 0 0 0 0 0 0 0 0 0> (5001ms) 2022-03-10 10:11:22:678 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 wifid(WiFiPolicy)[50] : __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] [WD Proxy] 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] [BaseDriver] Event 'wdaSessionAttempted' logged at 1646907082682 (15:41:22 GMT+0530 (India Standard Time)) 2022-03-10 10:11:22:682 - [debug] [XCUITest] Sending createSession command to WDA 2022-03-10 10:11:22:684 - [debug] [WD Proxy] Matched '/session' to command name 'createSession' 2022-03-10 10:11:22:686 - [debug] [WD Proxy] 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 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] : Terminating com.apple.mobilesafari 2022-03-10 10:11:22:722 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd(FrontBoardServices)[315] : FBSSystemAppProxy: Sending request to terminate application com.apple.mobilesafari 2022-03-10 10:11:22:722 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] : [FBSystemService] Request received from testmanagerd.315 to terminate application com.apple.mobilesafari: "Terminating for automation testing." 2022-03-10 10:11:22:722 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] : [application:4056] SpringBoard requested termination ("Terminating for automation testing.") 2022-03-10 10:11:22:722 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] : [application:4056] Now flagged as pending exit for reason: explicit kill request from client 2022-03-10 10:11:22:722 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] : [application: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 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] : [application: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 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] : Received termination request from [daemon:60] on <RBSProcessPredicate <RBSProcessHandlePredicateImpl| application:4056>> with context <RBSTerminateContext| domain:10 code:0xFBFBFBFB explanation:Terminating for automation testing. 2022-03-10 10:11:22:722 - [IOSDeviceLog] ProcessVisibility: Background 2022-03-10 10:11:22:723 - [IOSDeviceLog] ProcessState: Suspended reportType:None maxTerminationResistance:Interactive> 2022-03-10 10:11:22:723 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] : Executing termination request for: <RBSProcessPredicate <RBSProcessHandlePredicateImpl| application:4056>> 2022-03-10 10:11:22:724 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] : [application:4056] Terminating with context: <RBSTerminateContext| domain:10 code:0xFBFBFBFB explanation:Terminating for automation testing. 2022-03-10 10:11:22:724 - [IOSDeviceLog] ProcessVisibility: Background 2022-03-10 10:11:22:724 - [IOSDeviceLog] ProcessState: Suspended reportType:None maxTerminationResistance:Interactive> 2022-03-10 10:11:22:724 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] : [application:4056] terminate_with_reason() success 2022-03-10 10:11:22:724 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoard)[60] : [application:4056] Workspace connection invalidated. 2022-03-10 10:11:22:724 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 SpringBoard(FrontBoardServices)[60] : [SBApplicationServer] Removing client application:4056. 2022-03-10 10:11:22:724 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(IOKit)[63] : 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 - [IOSDeviceLog] HighFrequency = 1; 2022-03-10 10:11:22:725 - [IOSDeviceLog] bundleID = "com.apple.mobilesafari"; 2022-03-10 10:11:22:725 - [IOSDeviceLog] pid = 4056; 2022-03-10 10:11:22:725 - [IOSDeviceLog] } state:0x1 events:900 mask:0x800 2022-03-10 10:11:22:725 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 backboardd[63] : Received Connection Invalidation: <(null):0x12f2404e0> 2022-03-10 10:11:22:725 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 backboardd[63] : Connection: Remove: <(null):0x12f2404e0> 2022-03-10 10:11:22:725 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(BackBoardHIDEventFoundation)[63] : 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 - [IOSDeviceLog] HighFrequency = 1; 2022-03-10 10:11:22:725 - [IOSDeviceLog] bundleID = "com.apple.mobilesafari"; 2022-03-10 10:11:22:725 - [IOSDeviceLog] pid = 4056; 2022-03-10 10:11:22:726 - [IOSDeviceLog] } state:0x1 events:900 mask:0x800 source:HID 2022-03-10 10:11:22:726 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(GAXBackboardServer)[63] : Was notified gax client did become invalid: com.apple.mobilesafari. send right name: 6c480f 2022-03-10 10:11:22:726 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 backboardd(HIDAnalytics)[63] : HIDAnalytics Unregister Send event com.apple.hid.queueUsage 2022-03-10 10:11:22:729 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] : Connection to target invalidated. 2022-03-10 10:11:22:730 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] : Closed <XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056), removing from { 2022-03-10 10:11:22:730 - [IOSDeviceLog] 259 = "<XCTTargetBootstrapSession: 0x15ca12250>(pid 259)"; 2022-03-10 10:11:22:730 - [IOSDeviceLog] 4056 = "<XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056)"; 2022-03-10 10:11:22:730 - [IOSDeviceLog] 3037 = "<XCTTargetBootstrapSession: 0x15c804ba0>(pid 3037)"; 2022-03-10 10:11:22:730 - [IOSDeviceLog] 60 = "<XCTTargetBootstrapSession: 0x15ca12230>(pid 60)"; 2022-03-10 10:11:22:730 - [IOSDeviceLog] } 2022-03-10 10:11:22:730 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] : Invalidating <XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056) 2022-03-10 10:11:22:730 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 testmanagerd[315] : Invalidated <XCTTargetBootstrapSession: 0x15ca05db0>(pid 4056) 2022-03-10 10:11:22:733 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] : XPC connection invalidated: [application:4056] 2022-03-10 10:11:22:734 - [IOSDeviceLog] Mar 10 15:41:22 iPadPro12-ZD3229 runningboardd(RunningBoard)[31] : RBSStateCapture remove item called for untracked item <RBProcessMonitorObserver| qos:0 qos:(null) configs:{

KazuCocoa commented 2 years ago

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.

tobeitgit commented 8 months ago

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