patrol icon indicating copy to clipboard operation
patrol copied to clipboard

iOS & MacOS test failure due to port conflict, error message uninformative

Open ewann opened this issue 1 year ago • 3 comments

Steps to reproduce

  1. Run some software that uses ports 8081-82, eg Serverpod
  2. Attempt to use patrol with an IOS Simulator
  3. Wait for tests to eventually cross a timeout threshold
  4. Find nothing obvious in the logs regarding root cause

On the basis of "the logs still aren't useful, then it's a bug"...

Actual results

Exception is thrown, and doesn't hint at the root cause in a user friendly way.

Work around / solution: Specify ports that are not in use on the patrol command line, eg: --test-server-port 8096 --app-server-port 8095 perhaps after checking sudo lsof -i -P | grep LISTEN | grep :$PORT for potential conflicts

some mention about ports found in https://github.com/leancodepl/patrol/issues/1581 but doesn't seem to be closely related.

Logs

Logs
        2024-03-30 10:03:18.443328+0000 RunnerUITests-Runner[33741:291348] [Default] Running tests...
        2024-03-30 10:03:18.882887+0000 RunnerUITests-Runner[33741:291348] PatrolServer: INFO: PatrolServer constructor called
        2024-03-30 10:03:18.882960+0000 RunnerUITests-Runner[33741:291348] PatrolServer: INFO: PATROL_ENABLED flag is defined
        2024-03-30 10:03:18.886113+0000 RunnerUITests-Runner[33741:291348] PatrolServer: INFO: Starting server...
        2024-03-30 10:03:18.889024+0000 RunnerUITests-Runner[33741:291348] PatrolAppServiceClient: created, port: 8082
            t =      nans Checking existence of `"Allow" Button`
            t =      nans Open com.<redact>
            t =      nans     Launch com.<redact>
            t =      nans         Setting up automation session
            t =      nans         Wait for com.<redact> to idle


        *** If you believe this error represents a bug, please attach the result bundle at /Users/<redact>t/repos/<redact>/<redact>/build/ios_results_1711792997226.xcresult

        2024-03-30 10:09:13.304 xcodebuild[33738:291186] [MT] IDETestOperationsObserverDebug: 355.413 elapsed -- Testing started completed.
        2024-03-30 10:09:13.304 xcodebuild[33738:291186] [MT] IDETestOperationsObserverDebug: 0.000 sec, +0.000 sec -- start
        2024-03-30 10:09:13.304 xcodebuild[33738:291186] [MT] IDETestOperationsObserverDebug: 355.413 sec, +355.413 sec -- end

        Test session results, code coverage, and logs:
                /Users/<redact>/repos/<redact>/<redact>/build/ios_results_1711792997226.xcresult

        Testing failed:
                RunnerUITests-Runner (33741) encountered an error (Test runner never began executing tests after launching)

        ** TEST EXECUTE FAILED **

        Testing started
✗ Failed to execute tests of app with entrypoint test_bundle.dart for iOS simulator on simulator iPhone 15 Pro Max (xcodebuild exited with code 65) (357.0s)
Error: xcodebuild exited with code 65
#0      throwToolExit (package:patrol_cli/src/base/exceptions.dart:7:3)
#1      IOSTestBackend.execute.<anonymous closure> (package:patrol_cli/src/ios/ios_test_backend.dart:198:9)
<asynchronous suspension>
#2      DisposeScope.run (package:dispose_scope/src/dispose_scope.dart:46:7)
<asynchronous suspension>
#3      IOSTestBackend.execute (package:patrol_cli/src/ios/ios_test_backend.dart:153:5)
<asynchronous suspension>
#4      TestCommand._execute (package:patrol_cli/src/commands/test.dart:323:7)
<asynchronous suspension>
#5      TestCommand.run (package:patrol_cli/src/commands/test.dart:215:23)
<asynchronous suspension>
#6      CommandRunner.runCommand (package:args/command_runner.dart:212:13)
<asynchronous suspension>
#7      PatrolCommandRunner.runCommand (package:patrol_cli/src/runner/patrol_command_runner.dart:347:18)
<asynchronous suspension>
#8      PatrolCommandRunner.run (package:patrol_cli/src/runner/patrol_command_runner.dart:291:18)
<asynchronous suspension>
#9      patrolCommandRunner (package:patrol_cli/src/runner/patrol_command_runner.dart:70:20)
<asynchronous suspension>
#10     main (file:///Users/<redact>/.pub-cache/hosted/pub.dev/patrol_cli-2.7.0/bin/main.dart:6:20)
<asynchronous suspension>

See the logs above to learn what happened. Also consider running with --verbose. If the logs still aren't useful, then it's a bug - please report it.

Patrol version

patrol: ^3.6.1 patrol_cli: ^2.7.0

Patrol Doctor output

Patrol Doctor output
patrol doctor                                         
PathAccessException: Cannot open file, path = '/Users/<redact>/.zshrc' (OS Error: Permission denied, errno = 13)
fvm: Running version: "3.19.4"

PathAccessException: Cannot open file, path = '/Users/<redact>/.zshrc' (OS Error: Permission denied, errno = 13)
Patrol doctor:
Patrol CLI version: 2.7.0
Flutter command: flutter 
  Flutter 3.19.4 • channel stable
Android: 
• Program adb found in /etc/profiles/per-user/<redact>/bin/adb
• Env var $ANDROID_HOME set to /Users/<redact>/Library/Android/sdk
iOS / macOS: 
• Program xcodebuild found in /usr/bin/xcodebuild
• Program ideviceinstaller found in /etc/profiles/per-user/<redact>/bin/ideviceinstaller

Flutter Doctor output

Flutter Doctor output
flutter doctor --verbose                            
PathAccessException: Cannot open file, path = '/Users/<redact>/.zshrc' (OS Error: Permission denied, errno = 13)
[✓] Flutter (Channel stable, 3.19.4, on macOS 14.4.1 23E224 darwin-arm64, locale en-GB)
    • Flutter version 3.19.4 on channel stable at /Users/<redact>/fvm/versions/3.19.4
    • Upstream repository https://github.com/flutter/flutter.git
    • Framework revision 68bfaea224 (10 days ago), 2024-03-20 15:36:31 -0700
    • Engine revision a5c24f538d
    • Dart version 3.3.2
    • DevTools version 2.31.1

[✓] Android toolchain - develop for Android devices (Android SDK version 34.0.0)
    • Android SDK at /Users/<redact>/Library/Android/sdk
    • Platform android-34, build-tools 34.0.0
    • ANDROID_HOME = /Users/<redact>/Library/Android/sdk
    • Java binary at: /Applications/Android Studio.app/Contents/jbr/Contents/Home/bin/java
    • Java version OpenJDK Runtime Environment (build 17.0.9+0-17.0.9b1087.7-11185874)
    • All Android licenses accepted.

[✓] Xcode - develop for iOS and macOS (Xcode 15.3)
    • Xcode at /Applications/Xcode.app/Contents/Developer
    • Build 15E204a
    • CocoaPods version 1.15.2

[✓] Chrome - develop for the web
    • Chrome at /Applications/Google Chrome.app/Contents/MacOS/Google Chrome

[✓] Android Studio (version 2023.2)
    • Android Studio at /Applications/Android Studio.app/Contents
    • Flutter plugin can be installed from:
      🔨 https://plugins.jetbrains.com/plugin/9212-flutter
    • Dart plugin can be installed from:
      🔨 https://plugins.jetbrains.com/plugin/6351-dart
    • Java version OpenJDK Runtime Environment (build 17.0.9+0-17.0.9b1087.7-11185874)

[✓] Connected device (3 available)
    • iPhone 15 Pro Max (mobile) • 9174D58D-0DB2-4733-9DAE-41B50C914C53 • ios            •
      com.apple.CoreSimulator.SimRuntime.iOS-17-4 (simulator)
    • macOS (desktop)            • macos                                • darwin-arm64   • macOS 14.4.1
      23E224 darwin-arm64
    • Chrome (web)               • chrome                               • web-javascript • Google Chrome
      123.0.6312.87

[✓] Network resources
    • All expected network resources are available.

• No issues found!

ewann avatar Mar 30 '24 10:03 ewann

Hi. I can confirm that this issue exists. When PatrolServer or PatrolAppServiceClient fails because of the port conflict, we should exit the process and write an error message which will inform the user about what happened

piotruela avatar Apr 03 '24 12:04 piotruela

In my head there is a Mac joke about "fail different", but when I went to look I didn't find much...

Today I realised when running tests on MacOS, neither --test-server-port 8096 --app-server-port 8095 nor:

export PATROL_TEST_PORT=8096
export PATROL_APP_PORT=8095

appear to work. Based on:

2024-04-14 21:51:40.476839+0100 RunnerUITests-Runner[8137:43450] PatrolServer: INFO: PATROL_TEST_PORT is null, falling back to default (8081)
2024-04-14 21:51:40.476889+0100 RunnerUITests-Runner[8137:43450] PatrolServer: INFO: PatrolServer constructor called
2024-04-14 21:51:40.476914+0100 RunnerUITests-Runner[8137:43450] PatrolServer: INFO: PATROL_ENABLED flag is defined
2024-04-14 21:51:40.477263+0100 RunnerUITests-Runner[8137:43450] PatrolServer: INFO: Starting server...
2024-04-14 21:51:40.478539+0100 RunnerUITests-Runner[8137:43450] PatrolServer: INFO: Server started on http://0.0.0.0:8081
2024-04-14 21:51:40.478552+0100 RunnerUITests-Runner[8137:43450] Create PatrolAppServiceClient
2024-04-14 21:51:40.478604+0100 RunnerUITests-Runner[8137:43450] PatrolServer: INFO: PATROL_APP_PORT is null, falling back to default (8082)
2024-04-14 21:51:40.478623+0100 RunnerUITests-Runner[8137:43450] PatrolAppServiceClient: created, port: 8082
2024-04-14 21:51:40.478634+0100 RunnerUITests-Runner[8137:43450] Run the app for the first time

I guess they are not getting passed Through. Since the remaining workaround (move services on conflicting ports somewhere else) is trial for my use case I didn't look into the code.

Until that can be addressed (alpha status in https://patrol.leancode.co/getting-started is noted) this hopefully saves someone else some time.

ewann avatar Apr 14 '24 21:04 ewann

actually it's worse 🤣

This will hang indefinately

patrol test -d macos --verbose \
  --test-server-port 8096 --app-server-port 8095 \
  -t integration_test/enabled_tests

While this work work:

patrol test -d macos --verbose \
  -t integration_test/enabled_tests

ewann avatar Apr 15 '24 00:04 ewann