No observatory URL matching error is seen even though the iPhone system log has Observatory URL.

[pothurajtharun]

Test Environment:

• Java 11 (temurin)
• Appium: 2.2.1
• flutter@2.2.0 [installed (npm)]
• xcuitest@5.8.0 (automationName 'XCUITest')
• iPhone 8 Plus (16.7.3)

Steps followed:

1. Start a session without app capability and session has been created successfully.
2. Install and launch the app with ios-deploy commands programmatically. (While execution is going on, in parallel i started observing the iPhone device log through Console app in Mac OS)
3. App has been launched successfully. The observatory URL has been displayed in iPhone system log at 10:06 pm IST (4:36 pm UTC) as per the attached screenshot.
4. Called the flutter:connectObservatoryWsUrl to identify the observatory URL at 10:07 pm IST(4:37 pm UTC)

Actual Output: Even though there is an observatory URL in iPhone system log at 10:06 pm IST (4:36 pm UTC) , flutter:connectObservatoryWsUrl is failed to identify the observatory URL for 10 times and thrown the error at 10:08 pm IST(4:38 pm UTC)

- No observatory URL matching to '/(Observatory listening on |An Observatory debugger and profiler on\s.+\sis available at: |The Dart VM service is listening on )((http|\/\/)[a-zA-Z0-9:/=_\-.\[\]]+)/' was found in the device log. Please make sure the application under test is configured properly according to https://github.com/appium-userland/appium-flutter-driver#usage and that it does not crash on startup.

Attaching the full appium log: appium.log

Reproducibility: Some times.

[KazuCocoa]

What happens when you switch the step of launching the app with ios-deploy and flutter:connectObservatoryWsUrl? So, like the README, ios-deploy is just after calling flutter:connectObservatoryWsUrl

iii. Calls flutter:connectObservatoryWsUrl command to keep finding an observatory URL to the Dart VM iv. (at the same time) Launch the application under test via outside the appium-flutter-driver

https://github.com/appium/appium-flutter-driver?tab=readme-ov-file#several-ways-to-start-an-application

[pothurajtharun]

@KazuCocoa , As mentioned the Step 3 here https://github.com/appium/appium-flutter-driver?tab=readme-ov-file#several-ways-to-start-an-application the code snippets I'm using are as follows.

Step 3.i I'm using the below code.

driver = new IOSDriver(remote, mobileCapabilities);  //Start a session without app capability.

Step 3.ii - 3.iv I'm using the below code, to install and launch the app using ios-deploy. (I'm not using driver.installApphere, because Observatory URL is printing in iPhone device log only after the app launch.)

ProcessBuilder processBuilder = new ProcessBuilder();
processBuilder.command(
        "ios-deploy",
        "--debug",
        "--justlaunch",
        "--bundle",
        "/usr/local/automation/MobileApps/ios/Payload/Runner.app");
run(processBuilder);
log.debug("App installed and launched successfully.");

Step 3.v After launching the app with ios-deploy I'm calling the flutter:connectObservatoryWsUrl as follows.

LOG.debug("Running flutter connectObservatoryWsUrl script after launching the app with ios-deploy.");
driver.executeScript("flutter:connectObservatoryWsUrl");

What happens when you switch the step of launching the app with ios-deploy and flutter:connectObservatoryWsUrl?

As I'm already covering your question, i faced the same error that No observatory URL matching error is seen even though the iPhone system log has Observatory URL

The main problem is that observatory URL is in iPhone device log but flutter:connectObservatoryWsUrl is unable to connect.

[KazuCocoa]

As I'm already covering your question, i faced the same error that No observatory URL matching error is seen even though the iPhone system log has Observatory URL

Then, could you share the Appium log and the system log? So the observatory url should present during the flutter:connectObservatoryWsUrl command execution.

The no observatory url error occurs when the url is logs outside the flutter command, appium fails to get the syslog, or the matching pattern has changed by the Flutter’s update

[pothurajtharun]

@KazuCocoa I have taken the iPhone system logs in two methods as follows during the test executions.

Method 1:

1. Connect the iPhone to the mac system.
2. Open the Console app.
3. Select the iPhone in left side bar.
4. Start collecting the logs once the test executions are triggered.

Method_1.log

Method 2:

1. Start the appium-flutter-driver session.
2. Collected the logs through driver.manage().logs().get("syslog");

Method_2.log

Only Method 1 iPhone syslog contains the Observatory URL. Method 2 iPhone syslog doesn't contain any Observatory URL.

So the question is, could you please let me know which iPhone system log is appium-flutter-driver reading to get the Observatory URL ?

[KazuCocoa]

Appium gets logs via com.apple.syslog_relay service https://github.com/appium/appium-ios-device/blob/5735774b79dffc7f2b4afa60cd8132e16a6385ca/lib/syslog/index.js#L7, thus this driver also depends on the result of the service. Past logs may not be in the result.

You could use idevicesyslog for example to check the same as well if the com.apple.syslog_relay service contains the observatory URL. https://github.com/libimobiledevice/libimobiledevice Probably Flutter uses the idevicesyslog https://github.com/search?q=repo%3Aflutter%2Fflutter%20idevicesyslog&type=code as well, thus if com.apple.syslog_relay contains the URL in your case, theatrically Appium also can get the same one.

[pothurajtharun]

@KazuCocoa , During the app launch i tried to take the logs with idevicesyslog command as well along with previously mentioned two methods.

Method 1: [Console App Sys Log]

1.Connect the iPhone to the mac system. 2.Open the Console app. 3.Select the iPhone in left side bar. 4.Start collecting the logs once the test executions are triggered.

console_sys_log.log

Method 2: [Driver Sys Log]

1. Start the appium-flutter-driver session.
2. Collected the logs through driver.manage().logs().get("syslog");

driver_sys_log.log

Method 3: [idevicesyslog]

1. Start collecting the logs once the test executions are triggered with the following command. 2.idevicesyslog > idevicelog.log

idevicesyslog.log

Method 1 & Method 3 sys logs has the observatory URL but still No observatory URL matching error is seen. Attached three sys logs and appium log for the same.

appium-port-4779.log

[KazuCocoa]

When did you start com.xyz.xyzenterprise in the Method 2? Could you start a session with "appium:showIOSLog": true in the Method 2 so that the Appium log can show when the app starts instead of collecting logs with driver.manage().logs().get("syslog");?

[pothurajtharun]

@KazuCocoa , I have started the session with "appium:showIOSLog": true as mentioned in the comment. Now the appium log has the observatory URL as part of iOSDeviceLog. But still driver is unable to connect to the printed observatory URL. The error message is now changed to the port is busy due to the latest changes here. When i check the port at the same time it is free and not occupied with any other process.

Attaching the appium log: appium-showIOSLog.log

[KazuCocoa]

For the busy port, probably it is by the previous port forward remained. It could be fixed by killing the port forward before the next attempt, but what weird thing was below first attempt's result. If the dart observatory url has been valid, The Dart VM service is listening on http://127.0.0.1:49775/LPGAC72v9K0=/, maybe the first attempt succeeded but did not, thus the following attempt got the busy port message. It could indicate even if we fix the port issue, it won't get succeeded.

This situation could happen when the connection was not established by the Dart VM side's something, or the local connection got something error. Trying to find something new.

2023-11-21 04:35:02:403 [FlutterDriver] Forwarding the remote port 49775 to the local port 49775
2023-11-21 04:35:02:542 [FlutterDriver] {}
2023-11-21 04:35:02:543 [FlutterDriver] Waiting 3000ms before retrying

[pothurajtharun]

@KazuCocoa Understood. Thanks for the quick look. Please let me know if you need anything to be tested to provide more info about the issue.

[KazuCocoa]

The busy port thing is perhaps ok with 2.2.3.

[pothurajtharun]

@KazuCocoa , I tried the latest version #2.2.3 and the port busy issue is fixed.

However i can see the error message Got an error while finding an observatory url. from Attempt #5 onwards. Does it mean first four attempts driver was matching the URL with this regx ?

Attached the log : appium.log

[KazuCocoa]

As below steps in https://github.com/appium/appium-flutter-driver?tab=readme-ov-file#several-ways-to-start-an-application , can you start the app under test after flutter:connectObservatoryWsUrl call?

3. Launch the app outside the driver: for users who want to manage the application under test by yourselves
   1. Start a session without app capability
   2. Install the application under test via driver.install_app or mobile:installApp command etc
   3. Calls flutter:connectObservatoryWsUrl command to keep finding an observatory URL to the Dart VM appium:retryBackoffTime and appium:maxRetryCount will control the duration to keep finding an observatory URL to the Dart VM
      • (at the same time) Launch the application under test via outside the appium-flutter-driver
   4. Once flutter:connectObservatoryWsUrl identify the observatory URL, the command will establish a connection to the Dart VM

Current timeline is below. Thus the flutter:connectObservatoryWsUrl was not able to get the observatory url logged before the flutter:connectObservatoryWsUrl procedure.

2023-11-23 10:40:04:131 [IOSDeviceLog] Nov 23 16:10:04 iPhone-8-Plus Runner(Flutter)[557] <Notice>: flutter: The Dart VM service is listening on http://127.0.0.1:50790/3yxZuS23YBI=/
...
2023-11-23 10:40:29:985 [HTTP] --> POST /session/bb173db0-a943-48c6-bc03-e15dd7dedff9/execute/sync
2023-11-23 10:40:29:985 [HTTP] {"script":"flutter:connectObservatoryWsUrl","args":[]}
2023-11-23 10:40:29:992 [FlutterDriver@0f3d (bb173db0)] Calling AppiumDriver.execute() with args: ["flutter:connectObservatoryWsUrl",[],"bb173db0-a943-48c6-bc03-e15dd7dedff9"]
2023-11-23 10:40:29:992 [FlutterDriver] Executing Flutter driver command 'execute'
2023-11-23 10:40:29:993 [FlutterDriver] Establishing a connection to the Dart Observatory. Will retry 10 times with 3000ms delay between retries. These values could be customized by changing 'maxRetryCount' and 'retryBackoffTime' capabilities.
2023-11-23 10:40:29:993 [FlutterDriver] Attempt #1 of 10
2023-11-23 10:40:29:997 [FlutterDriver] Running on iOS real device

[pothurajtharun]

@KazuCocoa If i follow the below steps as per the documentation. After the 2nd step even if i call the flutter:connectObservatoryWsUrl the control will go to 4th step after completing the 3rd step. It means that the connectObservatoryWsUrl command job is done before launching the app outside the appium-flutter-driver.

1. Start a session without app capability.
2. Install the application under test via driver.install_app or mobile:installApp command etc
3. Calls flutter:connectObservatoryWsUrl command to keep finding an observatory URL to the Dart VM appium:retryBackoffTime and appium:maxRetryCount will control the duration to keep finding an observatory URL to the Dart VM
4. (at the same time) Launch the application under test via outside the appium-flutter-driver

Code as follows:

driver = new IOSDriver(remote, mobileCapabilities);
processBuilder.command("ios-deploy", "--bundle", "/usr/local/automation/MobileApps/ios/Payload/Runner.app"); 
// Installed the app successfully.
...
LOG.debug("Running flutter connectObservatoryWsUrl script.");
driver.executeScript("flutter:connectObservatoryWsUrl");
processBuilder.command("ios-deploy", "--justlaunch", "--bundle", "/usr/local/automation/MobileApps/ios/Payload/Runner.app"); 
//The control didn't come here until it finishes the 10 retries for above command.

How it can be achievable to launch the app parallel while flutter:connectObservatoryWsUrl command is in process ?

[KazuCocoa]

appium:retryBackoffTime and appium:maxRetryCount will control the duration to keep finding an observatory URL to the Dart VM

Did you try out these capabilities?

[pothurajtharun]

@KazuCocoa , I tried using these two capabilities as well. The problem is that the controller will go the further lines(i.e. appLaunch by outside flutter driver) of code only after finishing the flutter:connectObservatoryWsUrl commands successfully.

Whether it is 10 retries by default or custom retires (20) by appium:maxRetryCount capability the controller goes to next lines after 10 or 20 retries are finished and during this time the app is not launched so obviously the command won't find any observatoryURL.

[KazuCocoa]

It sounds like the test code matters like spawning the launching app part as a process or thread.

[pothurajtharun]

I'm using java. Do you mean the problem is at my test code of running flutter:connectObservatoryWsUrl & launching the app ?

[KazuCocoa]

Yes, you may need to run the ios-deploy command code on a thread for example

[pothurajtharun]

@KazuCocoa , I found a way to run the flutter:connectObservatoryWsUrl and then launch the app in parallel.

Here is how i achieved it:

driver = new IOSDriver(remote, mobileCapabilities);
LOG.debug("Running flutter connectObservatoryWsUrl script.");
ExecutorService executorService = Executors.newFixedThreadPool(1);
// Submit a task to the ExecutorService
Future<?> future = executorService.submit(() -> {
       driver.executeScript("flutter:connectObservatoryWsUrl");
});
processBuilder.command("ios-deploy", "--debug", "--justlaunch", "--bundle", "/usr/local/automation/MobileApps/ios/Payload/Runner.app");
// You can optionally wait for the Appium command to complete by calling future.get()
try {
      future.get();
} catch (Exception e) {
LOG.error(e.getMessage());
}
// Shutdown the ExecutorService when you're done.
executorService.shutdown();

However now there is another problem while executing the scripts through USB cable and over Wi-Fi. The observatoryURL is successfully found via USB Cable execution but not over Wi-Fi.

The error over Wi-Fi executions is : Encountered internal error running command: TypeError: Cannot read properties of null (reading 'executeSocketCommand')

Attaching the appium logs for both USB cable & Wi-Fi executions, please take a look.

appium-usb-cable.log

appium-wifi.log

Thanks!

[KazuCocoa]

It looks like a socket connection was not established. Not sure the exact reason right now, but basically Appium supports USB connected devices officially. I'd recommend you to use usb connection as the primary method to make the device connection stable.