appium / appium-flutter-driver

Appium Flutter Driver is a test automation tool for Flutter apps on multiple platforms/OSes. Appium Flutter Driver is part of the Appium mobile test automation tool maintained by community
MIT License
463 stars 184 forks source link

iproxy never starts when attempting to launch iOS app on real device #138

Closed ajschwieterman closed 1 year ago

ajschwieterman commented 3 years ago

I am trying to launch the Flutter app on my iPhone, but I get this error below saying it failed to connect. It looks like iproxy was never started. When I launch iproxy in another terminal window, Appium successfully connects to my iPhone.

Appium Flutter Driver v0.0.28 Appium v1.19.0

Appium log without launching iproxy in separate terminal window. ``` 2021-01-28 14:52:00:930 - [BaseDriver] The following capabilities were provided, but are not recognized by Appium: 2021-01-28 14:52:00:930 - [BaseDriver] simpleIsVisibleCheck 2021-01-28 14:52:00:931 - [BaseDriver] Session created with session id: fac96d71-ed43-4427-ac7b-61e522fd9deb 2021-01-28 14:52:00:932 - [FlutterDriver] Starting an IOS proxy session 2021-01-28 14:52:00:933 - [debug] [BaseDriver] Creating session with MJSONWP desired capabilities: { 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "app": "/Users/aaron.schwieterman/Apps/iOS.ipa", 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "simpleIsVisibleCheck": true, 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "noReset": true, 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "language": "en", 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "maxRetryCount": 10, 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "locale": "US", 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "deviceName": "iPhone", 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "newCommandTimeout": 0, 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "platformVersion": "14.4", 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "retryBackoffTime": 1000, 2021-01-28 14:52:00:933 - [debug] [BaseDriver] "automationName": "Flutter", 2021-01-28 14:52:00:934 - [debug] [BaseDriver] "platformName": "iOS", 2021-01-28 14:52:00:934 - [debug] [BaseDriver] "udid": "8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a" 2021-01-28 14:52:00:934 - [debug] [BaseDriver] } 2021-01-28 14:52:00:936 - [BaseDriver] The following capabilities were provided, but are not recognized by Appium: 2021-01-28 14:52:00:936 - [BaseDriver] maxRetryCount 2021-01-28 14:52:00:936 - [BaseDriver] retryBackoffTime 2021-01-28 14:52:00:937 - [BaseDriver] Session created with session id: 36c986ec-15af-4079-a6da-77b6920bf9a0 2021-01-28 14:52:00:965 - [debug] [XCUITest] Current user: 'aaron.schwieterman' 2021-01-28 14:52:00:984 - [debug] [XCUITest] Available devices: 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a 2021-01-28 14:52:00:984 - [debug] [XCUITest] Creating iDevice object with udid '8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a' 2021-01-28 14:52:00:984 - [XCUITest] Determining device to run tests on: udid: '8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a', real device: true 2021-01-28 14:52:01:033 - [debug] [BaseDriver] Event 'xcodeDetailsRetrieved' logged at 1611845521033 (09:52:01 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:01:036 - [BaseDriver] Using local app '/Users/aaron.schwieterman/Apps/iOS.ipa' 2021-01-28 14:52:01:070 - [debug] [BaseDriver] Unzipping '/Users/aaron.schwieterman/Apps/iOS.ipa' 2021-01-28 14:52:01:070 - [debug] [BaseDriver] Enforcing UTF-8 encoding on the extracted file names for 'iOS.ipa' 2021-01-28 14:52:01:423 - [debug] [BaseDriver] Extracted 89 items from '/Users/aaron.schwieterman/Apps/iOS.ipa' in 317ms 2021-01-28 14:52:01:425 - [debug] [BaseDriver] Matched 1 item in the extracted archive. Assuming 'Payload/Runner.app' is the correct bundle 2021-01-28 14:52:01:428 - [BaseDriver] Unzipped local app to '/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13087-iqfsac.wwit/Runner.app' 2021-01-28 14:52:01:428 - [debug] [BaseDriver] Event 'appConfigured' logged at 1611845521428 (09:52:01 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:01:428 - [debug] [XCUITest] Checking whether app '/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13087-iqfsac.wwit/Runner.app' is actually present on file system 2021-01-28 14:52:01:428 - [debug] [XCUITest] App is present 2021-01-28 14:52:01:429 - [debug] [iOS] Getting bundle ID from app '/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13087-iqfsac.wwit/Runner.app': 'com.sample.app' 2021-01-28 14:52:01:429 - [debug] [BaseDriver] Event 'resetStarted' logged at 1611845521429 (09:52:01 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:01:429 - [debug] [XCUITest] Reset: fullReset not set. Leaving as is 2021-01-28 14:52:01:429 - [debug] [BaseDriver] Event 'resetComplete' logged at 1611845521429 (09:52:01 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:01:430 - [WebDriverAgent] Using WDA path: '/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-webdriveragent' 2021-01-28 14:52:01:430 - [WebDriverAgent] Using WDA agent: '/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj' 2021-01-28 14:52:01:894 - [debug] [XCUITest] Crash reports root '/Users/aaron.schwieterman/Library/Logs/CrashReporter/MobileDevice/iPhone' does not exist. Got nothing to gather. 2021-01-28 14:52:01:894 - [debug] [BaseDriver] Event 'logCaptureStarted' logged at 1611845521894 (09:52:01 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:01:895 - [XCUITest] Setting up real device 2021-01-28 14:52:01:895 - [debug] [XCUITest] Verifying application platform 2021-01-28 14:52:01:896 - [debug] [XCUITest] CFBundleSupportedPlatforms: ["iPhoneOS"] 2021-01-28 14:52:02:270 - [debug] [XCUITest] App 'com.sample.app' is already installed. No need to reinstall. 2021-01-28 14:52:02:270 - [debug] [BaseDriver] Event 'appInstalled' logged at 1611845522270 (09:52:02 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:02:358 - [debug] [WebDriverAgent] No obsolete cached processes from previous WDA sessions listening on port 8100 have been found 2021-01-28 14:52:02:359 - [DevCon Factory] Requesting connection for device 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a on local port 8100, device port 8100 2021-01-28 14:52:02:359 - [debug] [DevCon Factory] Cached connections count: 0 2021-01-28 14:52:02:362 - [DevCon Factory] Successfully requested the connection for 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a:8100 2021-01-28 14:52:02:363 - [debug] [XCUITest] Starting WebDriverAgent initialization with the synchronization key 'XCUITestDriver' 2021-01-28 14:52:02:365 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2021-01-28 14:52:02:366 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8100/status] with no body 2021-01-28 14:52:02:398 - [debug] [WD Proxy] Got response with status 200: {"value":{"message":"WebDriverAgent is ready to accept commands","state":"success","os":{"testmanagerdVersion":28,"name":"iOS","sdkVersion":"14.2","version":"14.4"},"ios":{"ip":"192.168.1.202"},"ready":true,"build":{"upgradedAt":"1611844501208","time":"Jan 28 2021 09:44:47","productBundleIdentifier":"com.facebook.WebDriverAgentRunner"}},"sessionId":"CD5C0E37-8173-470E-9EFC-788B5D721F4F"} 2021-01-28 14:52:02:398 - [debug] [WebDriverAgent] Upgrade timestamp of the currently bundled WDA: 1611844501208 2021-01-28 14:52:02:398 - [debug] [WebDriverAgent] Upgrade timestamp of the WDA on the device: 1611844501208 2021-01-28 14:52:02:399 - [WebDriverAgent] Will reuse previously cached WDA instance at 'http://127.0.0.1:8100/' with 'com.facebook.WebDriverAgentRunner'. Set the wdaLocalPort capability to a value different from 8100 if this is an undesired behavior. 2021-01-28 14:52:02:399 - [debug] [XCUITest] Trying to start WebDriverAgent 1 times with 10000ms interval 2021-01-28 14:52:02:399 - [debug] [XCUITest] These values can be customized by changing wdaStartupRetries/wdaStartupRetryInterval capabilities 2021-01-28 14:52:02:399 - [debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1611845522399 (09:52:02 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:02:399 - [WebDriverAgent] Using provided WebdriverAgent at 'http://127.0.0.1:8100/' 2021-01-28 14:52:02:400 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2021-01-28 14:52:02:400 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8100/status] with no body 2021-01-28 14:52:02:422 - [debug] [WD Proxy] Got response with status 200: {"value":{"message":"WebDriverAgent is ready to accept commands","state":"success","os":{"testmanagerdVersion":28,"name":"iOS","sdkVersion":"14.2","version":"14.4"},"ios":{"ip":"192.168.1.202"},"ready":true,"build":{"upgradedAt":"1611844501208","time":"Jan 28 2021 09:44:47","productBundleIdentifier":"com.facebook.WebDriverAgentRunner"}},"sessionId":"CD5C0E37-8173-470E-9EFC-788B5D721F4F"} 2021-01-28 14:52:02:423 - [debug] [BaseDriver] Event 'wdaSessionAttempted' logged at 1611845522423 (09:52:02 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:02:423 - [debug] [XCUITest] Sending createSession command to WDA 2021-01-28 14:52:02:423 - [debug] [WD Proxy] Matched '/session' to command name 'createSession' 2021-01-28 14:52:02:424 - [debug] [WD Proxy] Proxying [POST /session] to [POST http://127.0.0.1:8100/session] with body: {"capabilities":{"firstMatch":[{"bundleId":"com.sample.app","arguments":["-AppleLanguages","(en)","-NSLanguages","(en)","-AppleLocale","US"],"environment":{},"eventloopIdleDelaySec":0,"shouldWaitForQuiescence":true,"shouldUseTestManagerForVisibilityDetection":true,"maxTypingFrequency":60,"shouldUseSingletonTestManager":true}],"alwaysMatch":{}}} 2021-01-28 14:52:04:270 - [debug] [WebDriverAgent] Parsed BUILD_DIR configuration value: '/Users/aaron.schwieterman/Library/Developer/Xcode/DerivedData/WebDriverAgent-arimheosmnvgtvcmlhgvblhlelkm/Build/Products' 2021-01-28 14:52:04:270 - [debug] [WebDriverAgent] Got derived data root: '/Users/aaron.schwieterman/Library/Developer/Xcode/DerivedData/WebDriverAgent-arimheosmnvgtvcmlhgvblhlelkm' 2021-01-28 14:52:05:300 - [debug] [WD Proxy] Got response with status 200: {"value":{"sessionId":"044C39ED-1120-4021-AFAB-FA7CB0139F5C","capabilities":{"device":"iphone","browserName":"Toyota DVR","sdkVersion":"14.4","CFBundleIdentifier":"com.sample.app"}},"sessionId":"044C39ED-1120-4021-AFAB-FA7CB0139F5C"} 2021-01-28 14:52:05:301 - [WD Proxy] Determined the downstream protocol as 'W3C' 2021-01-28 14:52:05:301 - [debug] [BaseDriver] Event 'wdaSessionStarted' logged at 1611845525301 (09:52:05 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:05:301 - [debug] [BaseDriver] Event 'wdaStarted' logged at 1611845525301 (09:52:05 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:05:301 - [XCUITest] Skipping setting of the initial display orientation. Set the "orientation" capability to either "LANDSCAPE" or "PORTRAIT", if this is an undesired behavior. 2021-01-28 14:52:05:302 - [debug] [BaseDriver] Event 'orientationSet' logged at 1611845525302 (09:52:05 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:05:302 - [debug] [BaseDriver] The value of 'elementResponseAttributes' setting did not change. Skipping the update for it 2021-01-28 14:52:05:302 - [debug] [BaseDriver] The value of 'shouldUseCompactResponses' setting did not change. Skipping the update for it 2021-01-28 14:52:05:305 - [FlutterDriver] Running on iOS real device 2021-01-28 14:52:05:306 - [FlutterDriver] Port forwarding to: 49794 2021-01-28 14:52:05:306 - [FlutterDriver] Attempt #1 2021-01-28 14:52:05:306 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:05:472 - [FlutterDriver] [object Object] 2021-01-28 14:52:05:472 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:05:473 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:06:475 - [FlutterDriver] Attempt #2 2021-01-28 14:52:06:475 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:06:725 - [FlutterDriver] [object Object] 2021-01-28 14:52:06:725 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:06:725 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:07:726 - [FlutterDriver] Attempt #3 2021-01-28 14:52:07:726 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:07:889 - [FlutterDriver] [object Object] 2021-01-28 14:52:07:889 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:07:889 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:08:891 - [FlutterDriver] Attempt #4 2021-01-28 14:52:08:891 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:09:055 - [FlutterDriver] [object Object] 2021-01-28 14:52:09:056 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:09:056 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:10:057 - [FlutterDriver] Attempt #5 2021-01-28 14:52:10:058 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:10:215 - [FlutterDriver] [object Object] 2021-01-28 14:52:10:215 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:10:215 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:11:217 - [FlutterDriver] Attempt #6 2021-01-28 14:52:11:217 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:11:397 - [FlutterDriver] [object Object] 2021-01-28 14:52:11:397 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:11:398 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:12:400 - [FlutterDriver] Attempt #7 2021-01-28 14:52:12:400 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:12:565 - [FlutterDriver] [object Object] 2021-01-28 14:52:12:565 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:12:566 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:13:566 - [FlutterDriver] Attempt #8 2021-01-28 14:52:13:566 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:13:731 - [FlutterDriver] [object Object] 2021-01-28 14:52:13:732 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:13:732 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 14:52:14:731 - [FlutterDriver] Attempt #9 2021-01-28 14:52:14:732 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:14:898 - [FlutterDriver] [object Object] 2021-01-28 14:52:14:898 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49794/lJwQDCtpv-k=/ws 2021-01-28 14:52:14:898 - [FlutterDriver] Failed to connect 10 times. Aborting. 2021-01-28 14:52:14:899 - [debug] [FlutterDriver] Deleting Flutter Driver session 2021-01-28 14:52:14:901 - [debug] [BaseDriver] Event 'newSessionStarted' logged at 1611845534901 (09:52:14 GMT-0500 (Eastern Standard Time)) 2021-01-28 14:52:14:936 - [debug] [W3C] Encountered internal error running command: Error: Failed to connect 10 times. Aborting. 2021-01-28 14:52:14:937 - [debug] [W3C] at Object.wrappedLogger.errorAndThrow (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-support/lib/logging.js:94:35) 2021-01-28 14:52:14:937 - [debug] [W3C] at Object.exports.connectSocket (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/lib/sessions/observatory.ts:114:11) 2021-01-28 14:52:14:937 - [debug] [W3C] at runMicrotasks () 2021-01-28 14:52:14:937 - [debug] [W3C] at processTicksAndRejections (internal/process/task_queues.js:93:5) 2021-01-28 14:52:14:937 - [debug] [W3C] at async Promise.all (index 1) 2021-01-28 14:52:14:937 - [debug] [W3C] at FlutterDriver.exports.createSession (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/lib/sessions/session.ts:15:47) 2021-01-28 14:52:14:937 - [debug] [W3C] at AppiumDriver.createSession (/usr/local/lib/node_modules/appium/lib/appium.js:356:35) 2021-01-28 14:52:14:950 - [debug] [W3C] Destroying socket connection 2021-01-28 14:52:14:951 - [HTTP] <-- POST /wd/hub/session 500 16167 ms - 571 2021-01-28 14:52:14:952 - [HTTP] ```
Appium log while launching iproxy in separate terminal window. ``` 2021-01-28 15:01:16:554 - [BaseDriver] The following capabilities are not standard capabilities and should have an extension prefix: 2021-01-28 15:01:16:554 - [BaseDriver] maxRetryCount 2021-01-28 15:01:16:555 - [BaseDriver] retryBackoffTime 2021-01-28 15:01:18:913 - [Appium] Appium v1.19.0 creating new FlutterDriver (v0.0.28) session 2021-01-28 15:01:18:915 - [Appium] Applying relaxed security to 'FlutterDriver' as per server command line argument. All insecure features will be enabled unless explicitly disabled by --deny-insecure (node:13213) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 exit listeners added to [process]. Use emitter.setMaxListeners() to increase limit (Use `node --trace-warnings ...` to show where the warning was created) 2021-01-28 15:01:18:919 - [debug] [BaseDriver] Creating session with MJSONWP desired capabilities: { 2021-01-28 15:01:18:919 - [debug] [BaseDriver] "app": "/Users/aaron.schwieterman/Apps/iOS.ipa", 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "simpleIsVisibleCheck": true, 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "noReset": true, 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "language": "en", 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "maxRetryCount": 300, 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "locale": "US", 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "deviceName": "iPhone", 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "newCommandTimeout": 6000, 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "platformVersion": "14.4", 2021-01-28 15:01:18:920 - [debug] [BaseDriver] "retryBackoffTime": 1000, 2021-01-28 15:01:18:921 - [debug] [BaseDriver] "automationName": "Flutter", 2021-01-28 15:01:18:921 - [debug] [BaseDriver] "platformName": "iOS", 2021-01-28 15:01:18:921 - [debug] [BaseDriver] "udid": "8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a" 2021-01-28 15:01:18:921 - [debug] [BaseDriver] } 2021-01-28 15:01:18:924 - [BaseDriver] The following capabilities were provided, but are not recognized by Appium: 2021-01-28 15:01:18:925 - [BaseDriver] simpleIsVisibleCheck 2021-01-28 15:01:18:925 - [BaseDriver] Session created with session id: 78a40d7f-987d-404f-9cfc-b06bb4417dfa 2021-01-28 15:01:18:926 - [FlutterDriver] Starting an IOS proxy session 2021-01-28 15:01:18:927 - [debug] [BaseDriver] Creating session with MJSONWP desired capabilities: { 2021-01-28 15:01:18:927 - [debug] [BaseDriver] "app": "/Users/aaron.schwieterman/Apps/iOS.ipa", 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "simpleIsVisibleCheck": true, 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "noReset": true, 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "language": "en", 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "maxRetryCount": 300, 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "locale": "US", 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "deviceName": "iPhone", 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "newCommandTimeout": 0, 2021-01-28 15:01:18:928 - [debug] [BaseDriver] "platformVersion": "14.4", 2021-01-28 15:01:18:929 - [debug] [BaseDriver] "retryBackoffTime": 1000, 2021-01-28 15:01:18:929 - [debug] [BaseDriver] "automationName": "Flutter", 2021-01-28 15:01:18:929 - [debug] [BaseDriver] "platformName": "iOS", 2021-01-28 15:01:18:929 - [debug] [BaseDriver] "udid": "8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a" 2021-01-28 15:01:18:929 - [debug] [BaseDriver] } 2021-01-28 15:01:18:933 - [BaseDriver] The following capabilities were provided, but are not recognized by Appium: 2021-01-28 15:01:18:933 - [BaseDriver] maxRetryCount 2021-01-28 15:01:18:934 - [BaseDriver] retryBackoffTime 2021-01-28 15:01:18:935 - [BaseDriver] Session created with session id: 54d7009c-702d-4495-beb8-97791963e3b2 2021-01-28 15:01:18:966 - [debug] [XCUITest] Current user: 'aaron.schwieterman' 2021-01-28 15:01:18:981 - [debug] [XCUITest] Available devices: 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a 2021-01-28 15:01:18:981 - [debug] [XCUITest] Creating iDevice object with udid '8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a' 2021-01-28 15:01:18:981 - [XCUITest] Determining device to run tests on: udid: '8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a', real device: true 2021-01-28 15:01:19:023 - [debug] [BaseDriver] Event 'xcodeDetailsRetrieved' logged at 1611846079022 (10:01:19 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:19:025 - [BaseDriver] Using local app '/Users/aaron.schwieterman/Apps/iOS.ipa' 2021-01-28 15:01:19:056 - [debug] [BaseDriver] Unzipping '/Users/aaron.schwieterman/Apps/iOS.ipa' 2021-01-28 15:01:19:057 - [debug] [BaseDriver] Enforcing UTF-8 encoding on the extracted file names for 'iOS.ipa' 2021-01-28 15:01:19:476 - [debug] [BaseDriver] Extracted 89 items from '/Users/aaron.schwieterman/Apps/iOS.ipa' in 398ms 2021-01-28 15:01:19:479 - [debug] [BaseDriver] Matched 1 item in the extracted archive. Assuming 'Payload/Runner.app' is the correct bundle 2021-01-28 15:01:19:482 - [BaseDriver] Unzipped local app to '/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13213-1legr8k.mawu/Runner.app' 2021-01-28 15:01:19:482 - [debug] [BaseDriver] Event 'appConfigured' logged at 1611846079482 (10:01:19 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:19:482 - [debug] [XCUITest] Checking whether app '/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13213-1legr8k.mawu/Runner.app' is actually present on file system 2021-01-28 15:01:19:482 - [debug] [XCUITest] App is present 2021-01-28 15:01:19:483 - [debug] [iOS] Getting bundle ID from app '/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13213-1legr8k.mawu/Runner.app': 'com.sample.app' 2021-01-28 15:01:19:484 - [debug] [BaseDriver] Event 'resetStarted' logged at 1611846079484 (10:01:19 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:19:484 - [debug] [XCUITest] Reset: fullReset not set. Leaving as is 2021-01-28 15:01:19:484 - [debug] [BaseDriver] Event 'resetComplete' logged at 1611846079484 (10:01:19 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:19:484 - [WebDriverAgent] Using WDA path: '/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-webdriveragent' 2021-01-28 15:01:19:484 - [WebDriverAgent] Using WDA agent: '/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-webdriveragent/WebDriverAgent.xcodeproj' 2021-01-28 15:01:20:986 - [debug] [XCUITest] Crash reports root '/Users/aaron.schwieterman/Library/Logs/CrashReporter/MobileDevice/iPhone' does not exist. Got nothing to gather. 2021-01-28 15:01:20:986 - [debug] [BaseDriver] Event 'logCaptureStarted' logged at 1611846080986 (10:01:20 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:20:986 - [XCUITest] Setting up real device 2021-01-28 15:01:20:987 - [debug] [XCUITest] Verifying application platform 2021-01-28 15:01:20:988 - [debug] [XCUITest] CFBundleSupportedPlatforms: ["iPhoneOS"] 2021-01-28 15:01:22:274 - [debug] [WebDriverAgent] Parsed BUILD_DIR configuration value: '/Users/aaron.schwieterman/Library/Developer/Xcode/DerivedData/WebDriverAgent-arimheosmnvgtvcmlhgvblhlelkm/Build/Products' 2021-01-28 15:01:22:274 - [debug] [WebDriverAgent] Got derived data root: '/Users/aaron.schwieterman/Library/Developer/Xcode/DerivedData/WebDriverAgent-arimheosmnvgtvcmlhgvblhlelkm' 2021-01-28 15:01:22:999 - [debug] [XCUITest] App 'com.sample.app' is already installed. No need to reinstall. 2021-01-28 15:01:22:999 - [debug] [BaseDriver] Event 'appInstalled' logged at 1611846082999 (10:01:22 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:23:076 - [debug] [WebDriverAgent] No obsolete cached processes from previous WDA sessions listening on port 8100 have been found 2021-01-28 15:01:23:077 - [DevCon Factory] Requesting connection for device 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a on local port 8100, device port 8100 2021-01-28 15:01:23:077 - [debug] [DevCon Factory] Cached connections count: 0 2021-01-28 15:01:23:080 - [DevCon Factory] Successfully requested the connection for 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a:8100 2021-01-28 15:01:23:082 - [debug] [XCUITest] Starting WebDriverAgent initialization with the synchronization key 'XCUITestDriver' 2021-01-28 15:01:23:084 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2021-01-28 15:01:23:084 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8100/status] with no body 2021-01-28 15:01:23:313 - [debug] [WD Proxy] Got response with status 200: {"value":{"message":"WebDriverAgent is ready to accept commands","state":"success","os":{"testmanagerdVersion":28,"name":"iOS","sdkVersion":"14.2","version":"14.4"},"ios":{"ip":"192.168.1.202"},"ready":true,"build":{"upgradedAt":"1611844501208","time":"Jan 28 2021 09:44:47","productBundleIdentifier":"com.facebook.WebDriverAgentRunner"}},"sessionId":"044C39ED-1120-4021-AFAB-FA7CB0139F5C"} 2021-01-28 15:01:23:314 - [debug] [WebDriverAgent] Upgrade timestamp of the currently bundled WDA: 1611844501208 2021-01-28 15:01:23:314 - [debug] [WebDriverAgent] Upgrade timestamp of the WDA on the device: 1611844501208 2021-01-28 15:01:23:314 - [WebDriverAgent] Will reuse previously cached WDA instance at 'http://127.0.0.1:8100/' with 'com.facebook.WebDriverAgentRunner'. Set the wdaLocalPort capability to a value different from 8100 if this is an undesired behavior. 2021-01-28 15:01:23:314 - [debug] [XCUITest] Trying to start WebDriverAgent 1 times with 10000ms interval 2021-01-28 15:01:23:314 - [debug] [XCUITest] These values can be customized by changing wdaStartupRetries/wdaStartupRetryInterval capabilities 2021-01-28 15:01:23:315 - [debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1611846083315 (10:01:23 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:23:315 - [WebDriverAgent] Using provided WebdriverAgent at 'http://127.0.0.1:8100/' 2021-01-28 15:01:23:316 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2021-01-28 15:01:23:316 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8100/status] with no body 2021-01-28 15:01:23:607 - [debug] [WD Proxy] Got response with status 200: {"value":{"message":"WebDriverAgent is ready to accept commands","state":"success","os":{"testmanagerdVersion":28,"name":"iOS","sdkVersion":"14.2","version":"14.4"},"ios":{"ip":"192.168.1.202"},"ready":true,"build":{"upgradedAt":"1611844501208","time":"Jan 28 2021 09:44:47","productBundleIdentifier":"com.facebook.WebDriverAgentRunner"}},"sessionId":"044C39ED-1120-4021-AFAB-FA7CB0139F5C"} 2021-01-28 15:01:23:607 - [debug] [BaseDriver] Event 'wdaSessionAttempted' logged at 1611846083607 (10:01:23 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:23:607 - [debug] [XCUITest] Sending createSession command to WDA 2021-01-28 15:01:23:609 - [debug] [WD Proxy] Matched '/session' to command name 'createSession' 2021-01-28 15:01:23:609 - [debug] [WD Proxy] Proxying [POST /session] to [POST http://127.0.0.1:8100/session] with body: {"capabilities":{"firstMatch":[{"bundleId":"com.sample.app","arguments":["-AppleLanguages","(en)","-NSLanguages","(en)","-AppleLocale","US"],"environment":{},"eventloopIdleDelaySec":0,"shouldWaitForQuiescence":true,"shouldUseTestManagerForVisibilityDetection":true,"maxTypingFrequency":60,"shouldUseSingletonTestManager":true}],"alwaysMatch":{}}} 2021-01-28 15:01:26:426 - [debug] [WD Proxy] Got response with status 200: {"value":{"sessionId":"BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA","capabilities":{"device":"iphone","browserName":"Toyota DVR","sdkVersion":"14.4","CFBundleIdentifier":"com.sample.app"}},"sessionId":"BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA"} 2021-01-28 15:01:26:427 - [WD Proxy] Determined the downstream protocol as 'W3C' 2021-01-28 15:01:26:427 - [debug] [BaseDriver] Event 'wdaSessionStarted' logged at 1611846086427 (10:01:26 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:26:427 - [debug] [BaseDriver] Event 'wdaStarted' logged at 1611846086427 (10:01:26 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:26:428 - [XCUITest] Skipping setting of the initial display orientation. Set the "orientation" capability to either "LANDSCAPE" or "PORTRAIT", if this is an undesired behavior. 2021-01-28 15:01:26:428 - [debug] [BaseDriver] Event 'orientationSet' logged at 1611846086428 (10:01:26 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:26:428 - [debug] [BaseDriver] The value of 'elementResponseAttributes' setting did not change. Skipping the update for it 2021-01-28 15:01:26:428 - [debug] [BaseDriver] The value of 'shouldUseCompactResponses' setting did not change. Skipping the update for it 2021-01-28 15:01:26:430 - [FlutterDriver] Running on iOS real device 2021-01-28 15:01:26:431 - [FlutterDriver] Port forwarding to: 49804 2021-01-28 15:01:26:431 - [FlutterDriver] Attempt #1 2021-01-28 15:01:26:431 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:26:711 - [FlutterDriver] [object Object] 2021-01-28 15:01:26:711 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:26:712 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 15:01:27:714 - [FlutterDriver] Attempt #2 2021-01-28 15:01:27:714 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:28:091 - [FlutterDriver] [object Object] 2021-01-28 15:01:28:092 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:28:092 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 15:01:29:095 - [FlutterDriver] Attempt #3 2021-01-28 15:01:29:095 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:29:364 - [FlutterDriver] [object Object] 2021-01-28 15:01:29:364 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:29:364 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 15:01:30:364 - [FlutterDriver] Attempt #4 2021-01-28 15:01:30:364 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:30:552 - [FlutterDriver] [object Object] 2021-01-28 15:01:30:552 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:30:552 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 15:01:31:557 - [FlutterDriver] Attempt #5 2021-01-28 15:01:31:557 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:31:727 - [FlutterDriver] [object Object] 2021-01-28 15:01:31:728 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:31:728 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 15:01:32:729 - [FlutterDriver] Attempt #6 2021-01-28 15:01:32:730 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:33:035 - [FlutterDriver] [object Object] 2021-01-28 15:01:33:036 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:33:036 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 15:01:34:037 - [FlutterDriver] Attempt #7 2021-01-28 15:01:34:037 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:34:195 - [FlutterDriver] [object Object] 2021-01-28 15:01:34:195 - [FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:34:196 - [FlutterDriver] Waiting 1 seconds before trying... 2021-01-28 15:01:35:196 - [FlutterDriver] Attempt #8 2021-01-28 15:01:35:197 - [FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:35:206 - [FlutterDriver] Connected to ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws 2021-01-28 15:01:35:212 - [FlutterDriver] Listing all isolates: [{"type":"@Isolate","id":"isolates/1742451010612871","name":"main","number":"1742451010612871","isSystemIsolate":false}] 2021-01-28 15:01:35:227 - [Appium] New FlutterDriver session created successfully, session 78a40d7f-987d-404f-9cfc-b06bb4417dfa added to master session list 2021-01-28 15:01:35:229 - [debug] [BaseDriver] Event 'newSessionStarted' logged at 1611846095229 (10:01:35 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:35:230 - [debug] [MJSONWP (78a40d7f)] Cached the protocol value 'MJSONWP' for the new session 78a40d7f-987d-404f-9cfc-b06bb4417dfa 2021-01-28 15:01:35:231 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.createSession() result: {"shell":false,"allowCors":false,"reboot":false,"ipa":null,"address":"127.0.0.1","port":4723,"basePath":"/wd/hub","callbackAddress":null,"callbackPort":null,"bootstrapPort":4724,"backendRetries":3,"sessionOverride":false,"launch":false,"logFile":null,"loglevel":"debug","logTimestamp":true,"localTimezone":false,"logNoColors":false,"webhook":null,"safari":false,"defaultDevice":false,"forceIphone":false,"forceIpad":false,"automationTraceTemplatePath":null,"instrumentsPath":null,"nodeconfig":null,"robotAddress":"0.0.0.0","robotPort":-1,"chromedriverExecutable":null,"showConfig":false,"noPermsCheck":false,"enforceStrictCaps":false,"isolateSimDevice":false,"tmpDir":"/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T","traceDir":null,"debugLogSpacing":false,"suppressKillServer":false,"longStacktrace":false,"webkitDebugProxyPort":27753,"wdaLocalPort":8100,"defaultCapabilities":{},"relaxedSecurityEnabled":true,"allowInsecure":[],"denyInsecure":[],"defaultCommandTimeout":60,"keepArtifacts":false,"platformName":"iOS","... 2021-01-28 15:01:35:234 - [HTTP] <-- POST /wd/hub/session 200 18683 ms - 2261 2021-01-28 15:01:35:234 - [HTTP] 2021-01-28 15:01:35:320 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/context 2021-01-28 15:01:35:320 - [HTTP] {"name":"NATIVE_APP"} 2021-01-28 15:01:35:326 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.setContext() with args: ["NATIVE_APP","78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:35:327 - [debug] [FlutterDriver] Executing Flutter driver command 'setContext' 2021-01-28 15:01:35:328 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.setContext() result: "NATIVE_APP" 2021-01-28 15:01:35:329 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/context 200 9 ms - 84 2021-01-28 15:01:35:330 - [HTTP] 2021-01-28 15:01:35:335 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/timeouts 2021-01-28 15:01:35:335 - [HTTP] {"type":"implicit","ms":0} 2021-01-28 15:01:35:336 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.timeouts() with args: ["implicit",0,null,null,null,"78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:35:336 - [debug] [FlutterDriver] Executing proxied driver command 'timeouts' 2021-01-28 15:01:35:336 - [debug] [XCUITest] Executing command 'timeouts' 2021-01-28 15:01:35:337 - [debug] [BaseDriver] MJSONWP timeout arguments: {"type":"implicit","ms":0}} 2021-01-28 15:01:35:337 - [debug] [BaseDriver] Set implicit wait to 0ms 2021-01-28 15:01:35:338 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.timeouts() result: null 2021-01-28 15:01:35:339 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/timeouts 200 3 ms - 76 2021-01-28 15:01:35:339 - [HTTP] 2021-01-28 15:01:35:483 - [HTTP] --> GET /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/context 2021-01-28 15:01:35:483 - [HTTP] {} 2021-01-28 15:01:35:487 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.getCurrentContext() with args: ["78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:35:487 - [debug] [FlutterDriver] Executing Flutter driver command 'getCurrentContext' 2021-01-28 15:01:35:487 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.getCurrentContext() result: "NATIVE_APP" 2021-01-28 15:01:35:489 - [HTTP] <-- GET /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/context 200 5 ms - 84 2021-01-28 15:01:35:489 - [HTTP] 2021-01-28 15:01:35:498 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 2021-01-28 15:01:35:499 - [HTTP] {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:35:499 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.findElement() with args: ["class name","XCUIElementTypeAlert","78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:35:499 - [debug] [FlutterDriver] Executing proxied driver command 'findElement' 2021-01-28 15:01:35:499 - [debug] [XCUITest] Executing command 'findElement' 2021-01-28 15:01:35:499 - [debug] [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, -ios predicate string, -ios class chain, accessibility id 2021-01-28 15:01:35:500 - [debug] [BaseDriver] Waiting up to 0 ms for condition 2021-01-28 15:01:35:504 - [debug] [WD Proxy] Matched '/element' to command name 'findElement' 2021-01-28 15:01:35:504 - [debug] [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/element] with body: {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:35:578 - [WD Proxy] Got response with status 404: {"value":{"error":"no such element","message":"unable to find an element using 'class name', value 'XCUIElementTypeAlert'","traceback":"(\n\t0 WebDriverAgentLib 0x0000000105037f5c FBNoSuchElementErrorResponseForRequest + 340\n\t1 WebDriverAgentLib 0x0000000105037d0c +[FBFindElementCommands handleFindElement:] + 368\n\t2 WebDriverAgentLib 0x0000000104ff9660 -[FBRoute_TargetAction mountRequest:intoResponse:] + 212\n\t3 WebDriverAgentLib 0x0000000104fd75cc __37-[FBWebServer registerRouteHandlers:]_block_invoke + 500\n\t4 WebDriverAgentLib 0x000000010501cb70 -[RoutingHTTPServer handleRoute:withRequest:response:] + 184\n\t5 WebDriverAgentLib 0x000000010501d6a8 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 72\n\t6 libdispatch.dylib 0x000000018c7fa280 AF27E74C-BE4A-3364-BB27-AED9916CE02D + 397952\n\t7 libdispatch.dylib ... 2021-01-28 15:01:35:579 - [debug] [W3C] Matched W3C error code 'no such element' to NoSuchElementError 2021-01-28 15:01:35:591 - [debug] [MJSONWP (78a40d7f)] Encountered internal error running command: NoSuchElementError: An element could not be located on the page using the given search parameters. 2021-01-28 15:01:35:592 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.doNativeFind (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:126:11) 2021-01-28 15:01:35:592 - [debug] [MJSONWP (78a40d7f)] at runMicrotasks () 2021-01-28 15:01:35:592 - [debug] [MJSONWP (78a40d7f)] at processTicksAndRejections (internal/process/task_queues.js:93:5) 2021-01-28 15:01:35:592 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findNativeElementOrElements (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:86:10) 2021-01-28 15:01:35:592 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrEls (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:22:12) 2021-01-28 15:01:35:592 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrElsWithProcessing (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:33:12) 2021-01-28 15:01:35:592 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElement (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:53:10) 2021-01-28 15:01:35:593 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 500 94 ms - 164 2021-01-28 15:01:35:593 - [HTTP] 2021-01-28 15:01:36:119 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 2021-01-28 15:01:36:119 - [HTTP] {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:36:120 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.findElement() with args: ["class name","XCUIElementTypeAlert","78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:36:120 - [debug] [FlutterDriver] Executing proxied driver command 'findElement' 2021-01-28 15:01:36:120 - [debug] [XCUITest] Executing command 'findElement' 2021-01-28 15:01:36:120 - [debug] [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, -ios predicate string, -ios class chain, accessibility id 2021-01-28 15:01:36:120 - [debug] [BaseDriver] Waiting up to 0 ms for condition 2021-01-28 15:01:36:121 - [debug] [WD Proxy] Matched '/element' to command name 'findElement' 2021-01-28 15:01:36:121 - [debug] [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/element] with body: {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:36:181 - [WD Proxy] Got response with status 404: {"value":{"error":"no such element","message":"unable to find an element using 'class name', value 'XCUIElementTypeAlert'","traceback":"(\n\t0 WebDriverAgentLib 0x0000000105037f5c FBNoSuchElementErrorResponseForRequest + 340\n\t1 WebDriverAgentLib 0x0000000105037d0c +[FBFindElementCommands handleFindElement:] + 368\n\t2 WebDriverAgentLib 0x0000000104ff9660 -[FBRoute_TargetAction mountRequest:intoResponse:] + 212\n\t3 WebDriverAgentLib 0x0000000104fd75cc __37-[FBWebServer registerRouteHandlers:]_block_invoke + 500\n\t4 WebDriverAgentLib 0x000000010501cb70 -[RoutingHTTPServer handleRoute:withRequest:response:] + 184\n\t5 WebDriverAgentLib 0x000000010501d6a8 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 72\n\t6 libdispatch.dylib 0x000000018c7fa280 AF27E74C-BE4A-3364-BB27-AED9916CE02D + 397952\n\t7 libdispatch.dylib ... 2021-01-28 15:01:36:181 - [debug] [W3C] Matched W3C error code 'no such element' to NoSuchElementError 2021-01-28 15:01:36:182 - [debug] [MJSONWP (78a40d7f)] Encountered internal error running command: NoSuchElementError: An element could not be located on the page using the given search parameters. 2021-01-28 15:01:36:182 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.doNativeFind (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:126:11) 2021-01-28 15:01:36:182 - [debug] [MJSONWP (78a40d7f)] at runMicrotasks () 2021-01-28 15:01:36:182 - [debug] [MJSONWP (78a40d7f)] at processTicksAndRejections (internal/process/task_queues.js:93:5) 2021-01-28 15:01:36:182 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findNativeElementOrElements (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:86:10) 2021-01-28 15:01:36:183 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrEls (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:22:12) 2021-01-28 15:01:36:183 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrElsWithProcessing (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:33:12) 2021-01-28 15:01:36:183 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElement (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:53:10) 2021-01-28 15:01:36:183 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 500 64 ms - 164 2021-01-28 15:01:36:183 - [HTTP] 2021-01-28 15:01:36:693 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 2021-01-28 15:01:36:694 - [HTTP] {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:36:694 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.findElement() with args: ["class name","XCUIElementTypeAlert","78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:36:694 - [debug] [FlutterDriver] Executing proxied driver command 'findElement' 2021-01-28 15:01:36:694 - [debug] [XCUITest] Executing command 'findElement' 2021-01-28 15:01:36:694 - [debug] [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, -ios predicate string, -ios class chain, accessibility id 2021-01-28 15:01:36:695 - [debug] [BaseDriver] Waiting up to 0 ms for condition 2021-01-28 15:01:36:695 - [debug] [WD Proxy] Matched '/element' to command name 'findElement' 2021-01-28 15:01:36:695 - [debug] [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/element] with body: {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:36:751 - [WD Proxy] Got response with status 404: {"value":{"error":"no such element","message":"unable to find an element using 'class name', value 'XCUIElementTypeAlert'","traceback":"(\n\t0 WebDriverAgentLib 0x0000000105037f5c FBNoSuchElementErrorResponseForRequest + 340\n\t1 WebDriverAgentLib 0x0000000105037d0c +[FBFindElementCommands handleFindElement:] + 368\n\t2 WebDriverAgentLib 0x0000000104ff9660 -[FBRoute_TargetAction mountRequest:intoResponse:] + 212\n\t3 WebDriverAgentLib 0x0000000104fd75cc __37-[FBWebServer registerRouteHandlers:]_block_invoke + 500\n\t4 WebDriverAgentLib 0x000000010501cb70 -[RoutingHTTPServer handleRoute:withRequest:response:] + 184\n\t5 WebDriverAgentLib 0x000000010501d6a8 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 72\n\t6 libdispatch.dylib 0x000000018c7fa280 AF27E74C-BE4A-3364-BB27-AED9916CE02D + 397952\n\t7 libdispatch.dylib ... 2021-01-28 15:01:36:751 - [debug] [W3C] Matched W3C error code 'no such element' to NoSuchElementError 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] Encountered internal error running command: NoSuchElementError: An element could not be located on the page using the given search parameters. 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.doNativeFind (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:126:11) 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] at runMicrotasks () 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] at processTicksAndRejections (internal/process/task_queues.js:93:5) 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findNativeElementOrElements (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:86:10) 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrEls (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:22:12) 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrElsWithProcessing (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:33:12) 2021-01-28 15:01:36:752 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElement (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:53:10) 2021-01-28 15:01:36:753 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 500 59 ms - 164 2021-01-28 15:01:36:753 - [HTTP] 2021-01-28 15:01:37:261 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 2021-01-28 15:01:37:261 - [HTTP] {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:37:261 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.findElement() with args: ["class name","XCUIElementTypeAlert","78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:37:262 - [debug] [FlutterDriver] Executing proxied driver command 'findElement' 2021-01-28 15:01:37:262 - [debug] [XCUITest] Executing command 'findElement' 2021-01-28 15:01:37:262 - [debug] [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, -ios predicate string, -ios class chain, accessibility id 2021-01-28 15:01:37:262 - [debug] [BaseDriver] Waiting up to 0 ms for condition 2021-01-28 15:01:37:263 - [debug] [WD Proxy] Matched '/element' to command name 'findElement' 2021-01-28 15:01:37:263 - [debug] [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/element] with body: {"using":"class name","value":"XCUIElementTypeAlert"} 2021-01-28 15:01:37:305 - [WD Proxy] Got response with status 404: {"value":{"error":"no such element","message":"unable to find an element using 'class name', value 'XCUIElementTypeAlert'","traceback":"(\n\t0 WebDriverAgentLib 0x0000000105037f5c FBNoSuchElementErrorResponseForRequest + 340\n\t1 WebDriverAgentLib 0x0000000105037d0c +[FBFindElementCommands handleFindElement:] + 368\n\t2 WebDriverAgentLib 0x0000000104ff9660 -[FBRoute_TargetAction mountRequest:intoResponse:] + 212\n\t3 WebDriverAgentLib 0x0000000104fd75cc __37-[FBWebServer registerRouteHandlers:]_block_invoke + 500\n\t4 WebDriverAgentLib 0x000000010501cb70 -[RoutingHTTPServer handleRoute:withRequest:response:] + 184\n\t5 WebDriverAgentLib 0x000000010501d6a8 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 72\n\t6 libdispatch.dylib 0x000000018c7fa280 AF27E74C-BE4A-3364-BB27-AED9916CE02D + 397952\n\t7 libdispatch.dylib ... 2021-01-28 15:01:37:305 - [debug] [W3C] Matched W3C error code 'no such element' to NoSuchElementError 2021-01-28 15:01:37:306 - [debug] [MJSONWP (78a40d7f)] Encountered internal error running command: NoSuchElementError: An element could not be located on the page using the given search parameters. 2021-01-28 15:01:37:306 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.doNativeFind (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:126:11) 2021-01-28 15:01:37:306 - [debug] [MJSONWP (78a40d7f)] at runMicrotasks () 2021-01-28 15:01:37:306 - [debug] [MJSONWP (78a40d7f)] at processTicksAndRejections (internal/process/task_queues.js:93:5) 2021-01-28 15:01:37:306 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findNativeElementOrElements (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:86:10) 2021-01-28 15:01:37:306 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrEls (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:22:12) 2021-01-28 15:01:37:306 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrElsWithProcessing (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:33:12) 2021-01-28 15:01:37:307 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElement (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:53:10) 2021-01-28 15:01:37:307 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 500 46 ms - 164 2021-01-28 15:01:37:308 - [HTTP] 2021-01-28 15:01:37:316 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/execute 2021-01-28 15:01:37:316 - [HTTP] {"script":"mobile:source","args":[{"format":"xml","excludedAttributes":"visible"}]} 2021-01-28 15:01:37:316 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.execute() with args: ["mobile:source",[{"format":"xml","excludedAttributes":"visible"}],"78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:37:316 - [debug] [FlutterDriver] Executing proxied driver command 'execute' 2021-01-28 15:01:37:317 - [debug] [XCUITest] Executing command 'execute' 2021-01-28 15:01:37:318 - [debug] [WD Proxy] Matched '/source?format=xml&excluded_attributes=visible' to command name 'getPageSource' 2021-01-28 15:01:37:319 - [debug] [WD Proxy] Proxying [GET /source?format=xml&excluded_attributes=visible] to [GET http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/source?format=xml&excluded_attributes=visible] with no body 2021-01-28 15:01:37:442 - [debug] [WD Proxy] Got response with status 200: {"value":"\n\n \n \n \n \n \n \n \n\n","sessionId":"BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA"} 2021-01-28 15:01:37:442 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.execute() result: "\n\n \n \n \n \n \n \n \n\n" 2021-01-28 15:01:37:443 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/execute 200 127 ms - 953 2021-01-28 15:01:37:443 - [HTTP] 2021-01-28 15:01:37:446 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/timeouts 2021-01-28 15:01:37:447 - [HTTP] {"type":"implicit","ms":0} 2021-01-28 15:01:37:447 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.timeouts() with args: ["implicit",0,null,null,null,"78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:37:447 - [debug] [FlutterDriver] Executing proxied driver command 'timeouts' 2021-01-28 15:01:37:447 - [debug] [XCUITest] Executing command 'timeouts' 2021-01-28 15:01:37:447 - [debug] [BaseDriver] MJSONWP timeout arguments: {"type":"implicit","ms":0}} 2021-01-28 15:01:37:447 - [debug] [BaseDriver] Set implicit wait to 0ms 2021-01-28 15:01:37:448 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.timeouts() result: null 2021-01-28 15:01:37:448 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/timeouts 200 1 ms - 76 2021-01-28 15:01:37:448 - [HTTP] 2021-01-28 15:01:38:458 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/execute 2021-01-28 15:01:38:458 - [HTTP] {"script":"mobile:source","args":[{"format":"xml","excludedAttributes":"visible"}]} 2021-01-28 15:01:38:459 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.execute() with args: ["mobile:source",[{"format":"xml","excludedAttributes":"visible"}],"78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:38:459 - [debug] [FlutterDriver] Executing proxied driver command 'execute' 2021-01-28 15:01:38:459 - [debug] [XCUITest] Executing command 'execute' 2021-01-28 15:01:38:460 - [debug] [WD Proxy] Matched '/source?format=xml&excluded_attributes=visible' to command name 'getPageSource' 2021-01-28 15:01:38:460 - [debug] [WD Proxy] Proxying [GET /source?format=xml&excluded_attributes=visible] to [GET http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/source?format=xml&excluded_attributes=visible] with no body 2021-01-28 15:01:38:588 - [debug] [WD Proxy] Got response with status 200: {"value":"\n\n \n \n \n \n \n \n \n\n","sessionId":"BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA"} 2021-01-28 15:01:38:589 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.execute() result: "\n\n \n \n \n \n \n \n \n\n" 2021-01-28 15:01:38:590 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/execute 200 131 ms - 953 2021-01-28 15:01:38:590 - [HTTP] 2021-01-28 15:01:38:593 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 2021-01-28 15:01:38:594 - [HTTP] {"using":"class name","value":"XCUIElementTypeActivityIndicator"} 2021-01-28 15:01:38:594 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.findElement() with args: ["class name","XCUIElementTypeActivityIndicator","78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:38:594 - [debug] [FlutterDriver] Executing proxied driver command 'findElement' 2021-01-28 15:01:38:594 - [debug] [XCUITest] Executing command 'findElement' 2021-01-28 15:01:38:594 - [debug] [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, -ios predicate string, -ios class chain, accessibility id 2021-01-28 15:01:38:594 - [debug] [BaseDriver] Waiting up to 0 ms for condition 2021-01-28 15:01:38:595 - [debug] [WD Proxy] Matched '/element' to command name 'findElement' 2021-01-28 15:01:38:595 - [debug] [WD Proxy] Proxying [POST /element] to [POST http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/element] with body: {"using":"class name","value":"XCUIElementTypeActivityIndicator"} 2021-01-28 15:01:38:623 - [WD Proxy] Got response with status 404: {"value":{"error":"no such element","message":"unable to find an element using 'class name', value 'XCUIElementTypeActivityIndicator'","traceback":"(\n\t0 WebDriverAgentLib 0x0000000105037f5c FBNoSuchElementErrorResponseForRequest + 340\n\t1 WebDriverAgentLib 0x0000000105037d0c +[FBFindElementCommands handleFindElement:] + 368\n\t2 WebDriverAgentLib 0x0000000104ff9660 -[FBRoute_TargetAction mountRequest:intoResponse:] + 212\n\t3 WebDriverAgentLib 0x0000000104fd75cc __37-[FBWebServer registerRouteHandlers:]_block_invoke + 500\n\t4 WebDriverAgentLib 0x000000010501cb70 -[RoutingHTTPServer handleRoute:withRequest:response:] + 184\n\t5 WebDriverAgentLib 0x000000010501d6a8 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 72\n\t6 libdispatch.dylib 0x000000018c7fa280 AF27E74C-BE4A-3364-BB27-AED9916CE02D + 397952\n\t7 libdispatch.dyl... 2021-01-28 15:01:38:624 - [debug] [W3C] Matched W3C error code 'no such element' to NoSuchElementError 2021-01-28 15:01:38:624 - [debug] [MJSONWP (78a40d7f)] Encountered internal error running command: NoSuchElementError: An element could not be located on the page using the given search parameters. 2021-01-28 15:01:38:625 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.doNativeFind (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:126:11) 2021-01-28 15:01:38:625 - [debug] [MJSONWP (78a40d7f)] at runMicrotasks () 2021-01-28 15:01:38:625 - [debug] [MJSONWP (78a40d7f)] at processTicksAndRejections (internal/process/task_queues.js:93:5) 2021-01-28 15:01:38:625 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findNativeElementOrElements (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:86:10) 2021-01-28 15:01:38:625 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrEls (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/lib/commands/find.js:22:12) 2021-01-28 15:01:38:625 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElOrElsWithProcessing (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:33:12) 2021-01-28 15:01:38:625 - [debug] [MJSONWP (78a40d7f)] at XCUITestDriver.findElement (/usr/local/lib/node_modules/appium/node_modules/appium-flutter-driver/node_modules/appium-xcuitest-driver/node_modules/appium-base-driver/lib/basedriver/commands/find.js:53:10) 2021-01-28 15:01:38:626 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/element 500 32 ms - 164 2021-01-28 15:01:38:626 - [HTTP] 2021-01-28 15:01:38:631 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/timeouts 2021-01-28 15:01:38:631 - [HTTP] {"type":"implicit","ms":0} 2021-01-28 15:01:38:631 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.timeouts() with args: ["implicit",0,null,null,null,"78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:38:631 - [debug] [FlutterDriver] Executing proxied driver command 'timeouts' 2021-01-28 15:01:38:631 - [debug] [XCUITest] Executing command 'timeouts' 2021-01-28 15:01:38:632 - [debug] [BaseDriver] MJSONWP timeout arguments: {"type":"implicit","ms":0}} 2021-01-28 15:01:38:632 - [debug] [BaseDriver] Set implicit wait to 0ms 2021-01-28 15:01:38:632 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.timeouts() result: null 2021-01-28 15:01:38:633 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/timeouts 200 1 ms - 76 2021-01-28 15:01:38:633 - [HTTP] 2021-01-28 15:01:39:590 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/appium/start_recording_screen 2021-01-28 15:01:39:590 - [HTTP] {"options":{"timeLimit":1200,"videoType":"libx264"}} 2021-01-28 15:01:39:591 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.startRecordingScreen() with args: [{"timeLimit":1200,"videoType":"libx264"},"78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:39:591 - [debug] [FlutterDriver] Executing proxied driver command 'startRecordingScreen' 2021-01-28 15:01:39:591 - [debug] [XCUITest] Executing command 'startRecordingScreen' 2021-01-28 15:01:39:592 - [XCUITest] Checking if there is/was a previous screen recording. Set 'forceRestart' option to 'true' if you'd like to skip this step. 2021-01-28 15:01:39:592 - [XCUITest] Screen recording is not running. There is nothing to stop. 2021-01-28 15:01:39:593 - [DevCon Factory] Releasing connections for 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a device on 9100 port number 2021-01-28 15:01:39:593 - [DevCon Factory] No cached connections have been found 2021-01-28 15:01:39:601 - [debug] [WD Proxy] Matched '/appium/settings' to command name 'getSettings' 2021-01-28 15:01:39:601 - [debug] [WD Proxy] Proxying [GET /appium/settings] to [GET http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA/appium/settings] with no body 2021-01-28 15:01:39:616 - [debug] [WD Proxy] Got response with status 200: {"value":{"boundElementsByIndex":false,"mjpegServerFramerate":10,"screenshotOrientation":"auto","reduceMotion":false,"elementResponseAttributes":"type,label","screenshotQuality":1,"mjpegScalingFactor":100,"keyboardPrediction":0,"defaultActiveApplication":"auto","mjpegServerScreenshotQuality":25,"defaultAlertAction":"","keyboardAutocorrection":0,"useFirstMatch":false,"shouldUseCompactResponses":true,"customSnapshotTimeout":15,"dismissAlertButtonSelector":"","activeAppDetectionPoint":"64.00,64.00","snapshotMaxDepth":50,"waitForIdleTimeout":10,"includeNonModalElements":false,"acceptAlertButtonSelector":"","animationCoolOffTimeout":2},"sessionId":"BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA"} 2021-01-28 15:01:39:622 - [DevCon Factory] Requesting connection for device 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a on local port 9100, device port 9100 2021-01-28 15:01:39:622 - [debug] [DevCon Factory] Cached connections count: 1 2021-01-28 15:01:39:624 - [DevCon Factory] Successfully requested the connection for 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a:9100 2021-01-28 15:01:39:878 - [ffmpeg] ffmpeg version 4.3.1 Copyright (c) 2000-2020 the FFmpeg developers 2021-01-28 15:01:39:878 - [ffmpeg] built with Apple clang version 12.0.0 (clang-1200.0.32.2) 2021-01-28 15:01:39:878 - [ffmpeg] 2021-01-28 15:01:39:878 - [ffmpeg] configuration: --prefix=/usr/local/Cellar/ffmpeg/4.3.1_1 --enable-shared --enable-pthreads --enable-version3 --enable-avresample --cc=clang --host-cflags= --host-ldflags= --enable-ffplay --enable-gnutls --enable-gpl --enable-libaom --enable-libbluray --enable-libdav1d --enable-libmp3lame --enable-libopus --enable-librav1e --enable-librubberband --enable-libsnappy --enable-libsrt --enable-libtesseract --enable-libtheora --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libxvid --enable-lzma --enable-libfontconfig --enable-libfreetype --enable-frei0r --enable-libass --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-librtmp --enable-libspeex --enable-libsoxr --enable-videotoolbox --disable-libjack --disable-indev=jack 2021-01-28 15:01:39:879 - [ffmpeg] libavutil 56. 51.100 / 56. 51.100 2021-01-28 15:01:39:879 - [ffmpeg] libavcodec 58. 91.100 / 58. 91.100 2021-01-28 15:01:39:879 - [ffmpeg] libavformat 58. 45.100 / 58. 45.100 2021-01-28 15:01:39:879 - [ffmpeg] libavdevice 58. 10.100 / 58. 10.100 2021-01-28 15:01:39:879 - [ffmpeg] libavfilter 7. 85.100 / 7. 85.100 2021-01-28 15:01:39:879 - [ffmpeg] libavresample 4. 0. 0 / 4. 0. 0 2021-01-28 15:01:39:879 - [ffmpeg] libswscale 5. 7.100 / 5. 7.100 2021-01-28 15:01:39:879 - [ffmpeg] libswresample 3. 7.100 / 3. 7.100 2021-01-28 15:01:39:879 - [ffmpeg] libpostproc 55. 7.100 / 55. 7.100 2021-01-28 15:01:39:879 - [ffmpeg] 2021-01-28 15:01:40:112 - [ffmpeg] Input #0, mjpeg, from 'http://127.0.0.1:9100': 2021-01-28 15:01:40:112 - [ffmpeg] Duration: N/A, bitrate: N/A 2021-01-28 15:01:40:112 - [ffmpeg] 2021-01-28 15:01:40:113 - [ffmpeg] Stream #0:0: Video: mjpeg (Baseline), yuvj420p(pc, bt470bg/unknown/unknown), 750x1334 [SAR 144:144 DAR 375:667], 10 tbr, 1200k tbn, 10 tbc 2021-01-28 15:01:40:113 - [ffmpeg] 2021-01-28 15:01:40:113 - [ffmpeg] Stream mapping: 2021-01-28 15:01:40:113 - [ffmpeg] Stream #0:0 -> #0:0 2021-01-28 15:01:40:113 - [ffmpeg] (mjpeg (native) -> h264 (libx264)) 2021-01-28 15:01:40:114 - [ffmpeg] Press [q] to stop, [?] for help 2021-01-28 15:01:40:114 - [ffmpeg] 2021-01-28 15:01:40:118 - [ffmpeg] [libx264 @ 0x7fa565008800] using SAR=1/1 2021-01-28 15:01:40:118 - [ffmpeg] 2021-01-28 15:01:40:119 - [ffmpeg] [libx264 @ 0x7fa565008800] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2 2021-01-28 15:01:40:119 - [ffmpeg] 2021-01-28 15:01:40:124 - [ffmpeg] [libx264 @ 0x7fa565008800] profile High, level 3.2, 4:2:0, 8-bit 2021-01-28 15:01:40:124 - [ffmpeg] 2021-01-28 15:01:40:124 - [ffmpeg] [libx264 @ 0x7fa565008800] 264 - core 160 r3011M cde9a93 - H.264/MPEG-4 AVC codec - Copyleft 2003-2020 - http://www.videolan.org/x264.html - options: cabac=1 ref=3 deblock=1:0:0 analyse=0x3:0x113 me=hex subme=7 psy=1 psy_rd=1.00:0.00 mixed_ref=1 me_range=16 chroma_me=1 trellis=1 8x8dct=1 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=-2 threads=18 lookahead_threads=3 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=3 b_pyramid=2 b_adapt=1 b_bias=0 direct=1 weightb=1 open_gop=0 weightp=2 keyint=250 keyint_min=10 scenecut=40 intra_refresh=0 rc_lookahead=40 rc=crf mbtree=1 crf=23.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00 2021-01-28 15:01:40:124 - [ffmpeg] Output #0, mp4, to '/var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13213-1k19p37.wnhk/appium_7934a6.mp4': 2021-01-28 15:01:40:125 - [ffmpeg] Metadata: 2021-01-28 15:01:40:125 - [ffmpeg] encoder : Lavf58.45.100 2021-01-28 15:01:40:125 - [ffmpeg] Stream #0:0: Video: h264 (libx264) (avc1 / 0x31637661), yuvj420p(pc), 750x1334 [SAR 144:144 DAR 375:667], q=-1--1, 10 fps, 10240 tbn, 10 tbc 2021-01-28 15:01:40:125 - [ffmpeg] Metadata: 2021-01-28 15:01:40:125 - [ffmpeg] encoder : Lavc58.91.100 libx264 2021-01-28 15:01:40:125 - [ffmpeg] Side data: 2021-01-28 15:01:40:125 - [ffmpeg] cpb: bitrate max/min/avg: 0/0/0 buffer size: 0 vbv_delay: N/A 2021-01-28 15:01:40:125 - [ffmpeg] 2021-01-28 15:01:40:840 - [XCUITest] Starting screen capture on the device '8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a' with command: 'ffmpeg -f mjpeg -r 10 -i http://127.0.0.1:9100 -vcodec libx264 -y /var/folders/th/81dl1gzj1rzb4ddwg22mmhbj_105pc/T/2021028-13213-1k19p37.wnhk/appium_7934a6.mp4'. Will timeout in 1200000ms 2021-01-28 15:01:40:840 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.startRecordingScreen() result: "" 2021-01-28 15:01:40:841 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/appium/start_recording_screen 200 1251 ms - 74 2021-01-28 15:01:40:841 - [HTTP] 2021-01-28 15:01:48:116 - [HTTP] --> POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/appium/stop_recording_screen 2021-01-28 15:01:48:116 - [HTTP] {} 2021-01-28 15:01:48:117 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.stopRecordingScreen() with args: [null,"78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:48:117 - [debug] [FlutterDriver] Executing proxied driver command 'stopRecordingScreen' 2021-01-28 15:01:48:117 - [debug] [XCUITest] Executing command 'stopRecordingScreen' 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] frame I:1 Avg QP:13.74 size: 70778 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] frame P:20 Avg QP:19.50 size: 92 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] frame B:57 Avg QP:27.33 size: 69 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] consecutive B-frames: 2.6% 0.0% 0.0% 97.4% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] mb I I16..4: 32.0% 58.0% 10.0% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] mb P I16..4: 0.0% 0.1% 0.0% P16..4: 0.4% 0.0% 0.0% 0.0% 0.0% skip:99.5% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] mb B I16..4: 0.0% 0.2% 0.0% B16..8: 0.2% 0.0% 0.0% direct: 0.0% skip:99.6% L0:49.2% L1:50.8% BI: 0.0% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] 8x8 transform intra:62.8% inter:65.2% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] coded y,uvDC,uvAC intra: 22.1% 15.9% 13.9% inter: 0.0% 0.1% 0.0% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] i16 v,h,dc,p: 59% 41% 0% 0% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] i8 v,h,dc,ddl,ddr,vr,hd,vl,hu: 33% 26% 30% 2% 1% 1% 2% 2% 3% 2021-01-28 15:01:48:277 - [ffmpeg] [libx264 @ 0x7fa565008800] i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 36% 25% 10% 4% 5% 6% 6% 4% 5% 2021-01-28 15:01:48:278 - [ffmpeg] [libx264 @ 0x7fa565008800] i8c dc,h,v,p: 82% 10% 6% 2% 2021-01-28 15:01:48:278 - [ffmpeg] [libx264 @ 0x7fa565008800] Weighted P-Frames: Y:0.0% UV:0.0% 2021-01-28 15:01:48:278 - [ffmpeg] [libx264 @ 0x7fa565008800] ref P L0: 95.2% 0.2% 1.6% 3.0% 2021-01-28 15:01:48:278 - [ffmpeg] 2021-01-28 15:01:48:278 - [ffmpeg] [libx264 @ 0x7fa565008800] ref B L0: 64.5% 34.3% 1.2% 2021-01-28 15:01:48:278 - [ffmpeg] [libx264 @ 0x7fa565008800] ref B L1: 93.4% 6.6% 2021-01-28 15:01:48:278 - [ffmpeg] [libx264 @ 0x7fa565008800] kb/s:78.51 2021-01-28 15:01:48:278 - [ffmpeg] 2021-01-28 15:01:48:331 - [iProxy@8abff29c:9100] read ECONNRESET 2021-01-28 15:01:48:331 - [ffmpeg] Exiting normally, received signal 2. 2021-01-28 15:01:48:331 - [ffmpeg] 2021-01-28 15:01:48:332 - [DevCon Factory] Releasing connections for 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a device on 9100 port number 2021-01-28 15:01:48:332 - [DevCon Factory] Found cached connections to release: ["8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a:9100"] 2021-01-28 15:01:48:333 - [DevCon Factory] Releasing the listener for '8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a:9100' 2021-01-28 15:01:48:333 - [debug] [iProxy@8abff29c:9100] Closing the connection 2021-01-28 15:01:48:333 - [debug] [DevCon Factory] Cached connections count: 1 2021-01-28 15:01:48:333 - [iProxy@8abff29c:9100] The connection has been closed 2021-01-28 15:01:48:334 - [debug] [XCUITest] The size of the file is 77.19 KB 2021-01-28 15:01:48:338 - [DevCon Factory] Releasing connections for 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a device on 9100 port number 2021-01-28 15:01:48:339 - [DevCon Factory] No cached connections have been found 2021-01-28 15:01:48:342 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.stopRecordingScreen() result: "AAAAIGZ0eXBpc29tAAACAGlzb21pc28yYXZjMW1wNDEAAAAIZnJlZQABLcRtZGF0AAACsAYF//+s3EXpvebZSLeWLNgg2SPu73gyNjQgLSBjb3JlIDE2MCByMzAxMU0gY2RlOWE5MyAtIEguMjY0L01QRUctNCBBVkMgY29kZWMgLSBDb3B5bGVmdCAyMDAzLTIwMjAgLSBodHRwOi8vd3d3LnZpZGVvbGFuLm9yZy94MjY0Lmh0bWwgLSBvcHRpb25zOiBjYWJhYz0xIHJlZj0zIGRlYmxvY2s9MTowOjAgYW5hbHlzZT0weDM6MHgxMTMgbWU9aGV4IHN1Ym1lPTcgcHN5PTEgcHN5X3JkPTEuMDA6MC4wMCBtaXhlZF9yZWY9MSBtZV9yYW5nZT0xNiBjaHJvbWFfbWU9MSB0cmVsbGlzPTEgOHg4ZGN0PTEgY3FtPTAgZGVhZHpvbmU9MjEsMTEgZmFzdF9wc2tpcD0xIGNocm9tYV9xcF9vZmZzZXQ9LTIgdGhyZWFkcz0xOCBsb29rYWhlYWRfdGhyZWFkcz0zIHNsaWNlZF90aHJlYWRzPTAgbnI9MCBkZWNpbWF0ZT0xIGludGVybGFjZWQ9MCBibHVyYXlfY29tcGF0PTAgY29uc3RyYWluZWRfaW50cmE9MCBiZnJhbWVzPTMgYl9weXJhbWlkPTIgYl9hZGFwdD0xIGJfYmlhcz0wIGRpcmVjdD0xIHdlaWdodGI9MSBvcGVuX2dvcD0wIHdlaWdodHA9MiBrZXlpbnQ9MjUwIGtleWludF9taW49MTAgc2NlbmVjdXQ9NDAgaW50cmFfcmVmcmVzaD0wIHJjX2xvb2thaGVhZD00MCByYz1jcmYgbWJ0cmVlPTEgY3JmPTIzLjAgcWNvbXA9MC42MCBxcG1pbj0wIHFwbWF4PTY5IHFwc3RlcD00IGlwX3JhdGlvPTEuNDAgYXE9MToxLjAwAIAAARR2ZYiEAF+oguQbBj+Y7um07cbBXKOg... 2021-01-28 15:01:48:343 - [HTTP] <-- POST /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa/appium/stop_recording_screen 200 228 ms - 105458 2021-01-28 15:01:48:344 - [HTTP] 2021-01-28 15:01:48:362 - [HTTP] --> DELETE /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa 2021-01-28 15:01:48:362 - [HTTP] {} 2021-01-28 15:01:48:362 - [debug] [MJSONWP (78a40d7f)] Calling AppiumDriver.deleteSession() with args: ["78a40d7f-987d-404f-9cfc-b06bb4417dfa"] 2021-01-28 15:01:48:362 - [debug] [BaseDriver] Event 'quitSessionRequested' logged at 1611846108362 (10:01:48 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:48:363 - [Appium] Removing session 78a40d7f-987d-404f-9cfc-b06bb4417dfa from our master session list 2021-01-28 15:01:48:364 - [debug] [FlutterDriver] Deleting Flutter Driver session 2021-01-28 15:01:48:366 - [debug] [WD Proxy] Matched '/session/54d7009c-702d-4495-beb8-97791963e3b2' to command name 'deleteSession' 2021-01-28 15:01:48:366 - [debug] [WD Proxy] Proxying [DELETE /session/54d7009c-702d-4495-beb8-97791963e3b2] to [DELETE http://127.0.0.1:8100/session/BC9C0DA9-1BD5-4AA7-B3C4-9CE82E0FA8CA] with no body 2021-01-28 15:01:48:390 - [FlutterDriver] Connection to ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws closed 2021-01-28 15:01:48:391 - [FlutterDriver] Connection to ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws closed 2021-01-28 15:01:48:391 - [FlutterDriver] Connection to ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws closed 2021-01-28 15:01:48:392 - [FlutterDriver] Connection to ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws closed 2021-01-28 15:01:48:392 - [FlutterDriver] Connection to ws://127.0.0.1:49804/dXeQ5JfsEPQ=/ws closed 2021-01-28 15:01:49:435 - [debug] [WD Proxy] Got response with status 200: {"value":null,"sessionId":null} 2021-01-28 15:01:49:435 - [DevCon Factory] Releasing connections for 8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a device on any port number 2021-01-28 15:01:49:436 - [DevCon Factory] Found cached connections to release: ["8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a:8100"] 2021-01-28 15:01:49:436 - [DevCon Factory] Releasing the listener for '8abff29ccb8613abff8fc2c1a05cfd3108ea1b6a:8100' 2021-01-28 15:01:49:436 - [debug] [iProxy@8abff29c:8100] Closing the connection 2021-01-28 15:01:49:436 - [debug] [DevCon Factory] Cached connections count: 0 2021-01-28 15:01:49:436 - [debug] [XCUITest] Not clearing log files. Use `clearSystemFiles` capability to turn on. 2021-01-28 15:01:49:437 - [debug] [BaseDriver] Event 'quitSessionFinished' logged at 1611846109437 (10:01:49 GMT-0500 (Eastern Standard Time)) 2021-01-28 15:01:49:437 - [debug] [MJSONWP (78a40d7f)] Received response: null 2021-01-28 15:01:49:437 - [debug] [MJSONWP (78a40d7f)] But deleting session, so not returning 2021-01-28 15:01:49:438 - [debug] [MJSONWP (78a40d7f)] Responding to client with driver.deleteSession() result: null 2021-01-28 15:01:49:439 - [debug] [MJSONWP (78a40d7f)] Destroying socket connection 2021-01-28 15:01:49:440 - [HTTP] <-- DELETE /wd/hub/session/78a40d7f-987d-404f-9cfc-b06bb4417dfa 200 1076 ms - 76 2021-01-28 15:01:49:440 - [HTTP] 2021-01-28 15:02:19:515 - [iProxy@8abff29c:8100] The connection has been closed ```
shibupanda commented 3 years ago

cc @KazuCocoa

shibupanda commented 3 years ago

@ajschwieterman mean time could you please check usbmuxd is there in you machine in /var/run/usbmuxd

ajschwieterman commented 3 years ago

@shibupanda usbmuxd is not in /var/run/usbmuxd on my machine, but I do have libusbmuxd installed on my machine via brew at /usr/local/Cellar/libusbmuxd.

KazuCocoa commented 3 years ago

it seems strange... Afaik, macOS communicate with iPhones via /var/run/usbmuxd, in general.

Current port forwarding logic does not use iproxy/libusbmuxd. It uses nodejs implementation used part of Appium as same as XCUITest in appium.

2021-01-28 15:01:23:084 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8100/status] with no body

This line worked, so probably port forwarding itself worked, but maybe something wrong occurred.

Maybe I should dig Check Dart Observatory this logic in this library. (hopefully this weekend)

shibupanda commented 3 years ago

Hi @KazuCocoa just to confirm Where we are getting localSocket value. https://github.com/truongsinh/appium-flutter-driver/blob/22d71e112dd965280fb41d73b5e0d83ebbcea415/driver/lib/sessions/ios.ts#L36

ajschwieterman commented 3 years ago

@shibupanda @KazuCocoa I was wrong about my previous comment. I found /var/run/usbmuxd via the terminal. However, it doesn't appear to have been edited when I was testing v0.0.28

KazuCocoa commented 3 years ago

https://nodejs.org/api/net.html#net_net_createserver_options_connectionlistener cc @shibupanda

It is a unix domain socket > /var/run/usbmuxd https://www.theiphonewiki.com/wiki/Usbmux is a good source about it

KazuCocoa commented 3 years ago

btw, what response can you get against http://127.0.0.1:49794 which is part of ws://127.0.0.1:49794/lJwQDCtpv-k=/ws? curl http://127.0.0.1:49794 is enough. If port forwarding itself does not work, it will print something connection refused error. Afaik, the return value probably will be something auth error message. (Then, port forwarding itself works. But probably something wrong happened in websocket connection)

hex0cter commented 3 years ago

I can confirm the problem occurred after 4a9d0beba89620ef6509d724aa94747b7e8ab9eb.

After seeing

[FlutterDriver] Port forwarding to: 57540
[FlutterDriver] Attempt #1
[FlutterDriver] Connecting to Dart Observatory: ws://127.0.0.1:57540/pWZKMQuABUg=/ws
[FlutterDriver] [object Object]
[FlutterDriver] Check Dart Observatory URI ws://127.0.0.1:57540/pWZKMQuABUg=/ws
[FlutterDriver] Waiting 3 seconds before trying...
[FlutterDriver] Attempt #2

this is what I got:

[11:46:54]  ~  $ curl --verbose http://127.0.0.1:57540/pWZKMQuABUg=/ws
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 57540 (#0)
> GET /pWZKMQuABUg=/ws HTTP/1.1
> Host: 127.0.0.1:57540
> User-Agent: curl/7.64.1
> Accept: */*
>
* Empty reply from server
* Connection #0 to host 127.0.0.1 left intact
curl: (52) Empty reply from server
* Closing connection 0
[11:47:04]  ~  $ curl --verbose http://127.0.0.1:57540
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 57540 (#0)
> GET / HTTP/1.1
> Host: 127.0.0.1:57540
> User-Agent: curl/7.64.1
> Accept: */*
>
* Empty reply from server
* Connection #0 to host 127.0.0.1 left intact
curl: (52) Empty reply from server
* Closing connection 0
ajschwieterman commented 3 years ago

I updated to Appium v1.20.2, and it seems to working now.

KazuCocoa commented 3 years ago

Okay, thanks. It seems some corner cases were there I did not get.

As a fallback, https://github.com/truongsinh/appium-flutter-driver/blob/c9c91769962b06e09f129acfae97fc8a9d7a3c4e/driver/lib/sessions/ios.ts#L39 can switch with iproxy command for now. The previous iproxy command line was for newer versions. Older (I'm not sure which version) ones had a different argument format. I mean port:port style argument is the new format. I forgot, but probably an older one was port port

So, the line will be

  1. Current utilities.connectPort (primary. users no need to install additional tools)
  2. Spawn iproxy (secondary way)
    • With two types of arguments format or only new one?
      • This case requires users to install iproxy on their environment

Let me take a look this weekend a bit further

KazuCocoa commented 3 years ago

Hi, could someone try https://github.com/truongsinh/appium-flutter-driver/pull/139 this branch and share the log? I'd like to check if something port busy status is there before adding the fallback.

hex0cter commented 3 years ago

I will give it a try now.

hex0cter commented 3 years ago

I got the same result with this branch. Full logs attached.

appium-appium-flutter-driver-pr139.log

~  $ curl --verbose http://127.0.0.1:64770
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 64770 (#0)
> GET / HTTP/1.1
> Host: 127.0.0.1:64770
> User-Agent: curl/7.64.1
> Accept: */*
>
* Empty reply from server
* Connection #0 to host 127.0.0.1 left intact
curl: (52) Empty reply from server
* Closing connection 0
KazuCocoa commented 3 years ago

Thanks! I've added one more check logic in https://github.com/truongsinh/appium-flutter-driver/pull/139/files#diff-9e4b47764b826fd907f881068caf0f9872da1fe7c2d7cb2de5f62afc98e83cf7R105-R108 Could you try the latest branch again? (Only the logfile is enough, thanks)

hex0cter commented 3 years ago

I tested it a dozen of times today. But somehow I cannot see this problem anymore. It works perfectly ok with appium@1.20.0-beta.0 which includes appium-flutter-driver@0.0.28. I am not really sure what has changed since yesterday. 😥😥😥

I might play a bit more with it during the day, and get back if I can find something. Otherwise I am sure what else can be done.

@ajschwieterman, you mentioned it works with appium v1.20.2. That is even more confusing to me. As far I I can see that uses appium-flutter-driver 0.0.25, which is six months old.

KazuCocoa commented 3 years ago

Okay, thanks. hm.. it seems strange, but glad to hear current logic worked on your environment.

My guess was something port busy or 'listening' status. https://github.com/truongsinh/appium-flutter-driver/pull/139 itself handles such possible edge case well than only current method. So, the PR itself should improve the logic, I believe.

hex0cter commented 3 years ago

Cool. Please let me know if you still need to the logs of that branch (there won't be errors though, I guess).

ajschwieterman commented 3 years ago

@hex0cter I replaced the appium-flutter-driver directory in Appium v1.20.2 with the v0.0.28 release code.

hex0cter commented 3 years ago

@KazuCocoa I am able to reproduce the issue again on your branch. Not sure if has anything to do with the status of the phone (rebooting the phone does not help).

appium-appium-flutter-driver-pr-139-ii.log appium-appium-flutter-driver-pr-139.log

KazuCocoa commented 3 years ago

Potentially, retry might help... like https://github.com/libimobiledevice/libusbmuxd/blob/f48ffb1a6cc32214c91f1cc09c572ab19a72924d/src/libusbmuxd.c#L951 ? But I have no good idea... Let me add iproxy command stuff later as a new PR

KazuCocoa commented 1 year ago

Currently this driver allows users to run 3rd party tools and find the url from the log as https://github.com/appium/appium-flutter-driver?tab=readme-ov-file#several-ways-to-start-an-application One possible issue here is to launch an app with debug mode, available via ios-deploy for example. The readme may help.

Or flutter:launchApp launches an app via instrument implemented in appium-ios-devices. it is probably similar to the iproxy as well