[TBD] Failed to shutdown sl4a event dispatcher.

[johnklee]

I can follow Mobly101 to execute $ python hello_world_test.py -c sample_config.yml without issue. But when I updated hello_world_test.py to register SL4J service as below:

from mobly import base_test
from mobly import test_runner
from mobly.controllers import android_device
from mobly.controllers.android_device_lib.services import sl4a_service

class HelloWorldTest(base_test.BaseTestClass):

  def setup_class(self):
    # Registering android_device controller module declares the test's
    # dependency on Android device hardware. By default, we expect at least one
    # object is created from this.
    self.ads = self.register_controller(android_device)
    self.dut = self.ads[0]
    # Start Mobly Bundled Snippets (MBS).
    self.dut.load_snippet('mbs', 'com.google.android.mobly.snippet.bundled')
    # New: Register SL4A service
    self.dut.services.register('sl4a', sl4a_service.Sl4aService)

  def test_hello(self):
    self.dut.mbs.makeToast('Hello World!')

if __name__ == '__main__':
  test_runner.main()

I will get below error:

# python hello_world_test.py -c sample_config.yaml
...
[SampleTestBed] 05-18 00:47:54.028 INFO [Test] test_hello
[SampleTestBed] 05-18 00:47:54.054 INFO [Test] test_hello PASS
[SampleTestBed] 05-18 00:47:55.945 ERROR [AndroidDevice|07311JECB08252] Failed to shutdown sl4a event dispatcher.
Traceback (most recent call last):
  File "/root/Github/mobly/mobly/controllers/android_device_lib/sl4a_client.py", line 128, in stop_event_dispatcher
    self.ed.clean_up()
  File "/root/Github/mobly/mobly/controllers/android_device_lib/event_dispatcher.py", line 153, in clean_up
    self._sl4a.disconnect()
  File "/root/Github/mobly/mobly/controllers/android_device_lib/jsonrpc_client_base.py", line 261, in disconnect
    self.clear_host_port()
  File "/root/Github/mobly/mobly/controllers/android_device_lib/jsonrpc_client_base.py", line 267, in clear_host_port
    self._ad.adb.forward(['--remove', 'tcp:%d' % self.host_port])
  File "/root/Github/mobly/mobly/controllers/android_device_lib/adb.py", line 434, in forward
    return self._exec_adb_cmd('forward',
  File "/root/Github/mobly/mobly/controllers/android_device_lib/adb.py", line 288, in _exec_adb_cmd
    out = self._exec_cmd(adb_cmd, shell=shell, timeout=timeout, stderr=stderr)
  File "/root/Github/mobly/mobly/controllers/android_device_lib/adb.py", line 195, in _exec_cmd
    raise AdbError(cmd=args,
mobly.controllers.android_device_lib.adb.AdbError: Error executing adb cmd "adb -s 07311JECB08252 forward --remove tcp:20930". ret: 1, stdout: b'', stderr: b"error: listener 'tcp:20930' not found\n"
[SampleTestBed] 05-18 00:48:03.105 INFO Summary for test class HelloWorldTest: Error 0, Executed 1, Failed 0, Passed 1, Requested 1, Skipped 0
[SampleTestBed] 05-18 00:48:03.106 INFO Summary for test run SampleTestBed@05-18-2021_00-47-43-187: Error 0, Executed 1, Failed 0, Passed 1, Requested 1, Skipped 0
DEBUG:root:cmd: adb -s 07311JECB08252 forward --remove tcp:20930, stdout: b'', stderr: b"error: listener 'tcp:20930' not found\n", ret: 1
Exception ignored in: <function JsonRpcClientBase.__del__ at 0x7fb9ebc1eca0>
Traceback (most recent call last):
  File "/root/Github/mobly/mobly/controllers/android_device_lib/jsonrpc_client_base.py", line 147, in __del__
    self.disconnect()
  File "/root/Github/mobly/mobly/controllers/android_device_lib/jsonrpc_client_base.py", line 261, in disconnect
    self.clear_host_port()
  File "/root/Github/mobly/mobly/controllers/android_device_lib/jsonrpc_client_base.py", line 267, in clear_host_port
    self._ad.adb.forward(['--remove', 'tcp:%d' % self.host_port])
  File "/root/Github/mobly/mobly/controllers/android_device_lib/adb.py", line 434, in forward
    return self._exec_adb_cmd('forward',
  File "/root/Github/mobly/mobly/controllers/android_device_lib/adb.py", line 288, in _exec_adb_cmd
    out = self._exec_cmd(adb_cmd, shell=shell, timeout=timeout, stderr=stderr)
  File "/root/Github/mobly/mobly/controllers/android_device_lib/adb.py", line 195, in _exec_cmd
    raise AdbError(cmd=args,
mobly.controllers.android_device_lib.adb.AdbError: Error executing adb cmd "adb -s 07311JECB08252 forward --remove tcp:20930". ret: 1, stdout: b'', stderr: b"error: listener 'tcp:20930' not found\n"

May need some time to dig in to collect more information. Thanks!

[xpconanfan]

I'd avoid using sl4a. Please use Mobly snippets instead.

[johnklee]

I create below test case and configuration to deal with this issue:

• i748.py:

  
  import logging
  import pprint

from mobly import asserts from mobly import base_test from mobly import test_runner from mobly.controllers import android_device from mobly.controllers.android_device_lib.services import sl4a_service

class HelloWorldTest(base_test.BaseTestClass): ''' See: https://github.com/johnklee/mobly/blob/master/docs/tutorial.md#example-4-multiple-test-beds-and-default-test-parameters ''' def setup_class(self):

Registering android_device controller module, and declaring that the test

    # requires at least two Android devices.
    self.ads = self.register_controller(android_device)

    # The device used to discover Bluetooth devices.
    self.dut = android_device.get_device(self.ads, label='dut')
    # Sets the tag that represents this device in logs.
    self.dut.debug_tag = 'dut'
    # Setup MBS (Mobly Bundled Snippet)
    self.dut.load_snippet(
        'mbs',
        'com.google.android.mobly.snippet.bundled'
    )
    # New: Register SL4A service
    self.dut.services.register('sl4a', sl4a_service.Sl4aService)

def setup_test(self):
    # Make sure bluetooth is on.
    self.dut.mbs.btEnable()

    # Set Bluetooth name on target device.
    self.dut.mbs.btSetName('IamDUT')

def teardown_test(self):
    # Turn Bluetooth off on both devices after test finishes.
    self.dut.mbs.btDisable()

if name == 'main': test_runner.main()

* `i748_config.yaml`
```yaml
MoblyParams: {LogPath: /tmp/}
TestBeds:
  # A test bed where adb will find Android devices.
  - Name: SampleTestBed
    Controllers:
        AndroidDevice:
            - serial: 07311JECB08252
              label: dut
    TestParams:
        search_bluetooth_name: JohnPixel

I add debugging message and obtain below log message:

# python i748.py -c i748_config.yaml
[SampleTestBed] 05-20 05:08:12.899 INFO Test output folder: "/tmp/SampleTestBed/05-20-2021_05-08-12-898"
[SampleTestBed] 05-20 05:08:12.901 INFO ==========> HelloWorldTest <==========
[SampleTestBed] 05-20 05:08:18.750 INFO [AndroidDevice|07311JECB08252] Logging debug tag set to "dut"
[SampleTestBed] 05-20 05:08:20.840 INFO [AndroidDevice|dut] Launching snippet apk com.google.android.mobly.snippet.bundled with protocol 1.0
[10|jsonrpc_client_base|227] Connecting localhost on port=20363
[10|sl4a_service|40] Start service...
[10|jsonrpc_client_base|227] Connecting localhost on port=17019
[10|jsonrpc_client_base|227] Connecting localhost on port=17019
[10|sl4a_client|162] Start event client with host_port=17019; device_port=8080
[10|jsonrpc_client_base|227] Connecting localhost on port=17019
[30|jsonrpc_client_base|272] clear host port of JspRPC(17019)...
[30|jsonrpc_client_base|272] clear host port of JspRPC(17019)...
[30|jsonrpc_client_base|272] clear host port of JspRPC(20363)...
[SampleTestBed] 05-20 05:08:29.047 INFO Summary for test class HelloWorldTest: Error 0, Executed 0, Failed 0, Passed 0, Requested 0, Skipped 0
[SampleTestBed] 05-20 05:08:29.049 INFO Summary for test run SampleTestBed@05-20-2021_05-08-12-898: Error 0, Executed 0, Failed 0, Passed 0, Requested 0, Skipped 0

For somehow, the host port 17019 will be handled twice which leads to this issue. The fix for this issue is to check the existence of the port to be removed before executing adb command as below commit: https://github.com/johnklee/mobly/commit/e5da1c87f28ced82a66b1f3d5701caa8a9b3698e

If it makes sense here, I will create a PR as well. Many thanks! (Two failed test cases found. I will fix them if this solution is accepted.)

FAILED tests/mobly/controllers/android_device_lib/jsonrpc_client_base_test.py::JsonRpcClientBaseTest::test_clear_host_port_positive FAILED tests/mobly/controllers/android_device_lib/snippet_client_test.py::SnippetClientTest::test_snippet_stop_app_raises - Assertio

[johnklee]

Failed test cases are fixed in below commit: https://github.com/johnklee/mobly/commit/382d4542e51678183bde6c8f93e4def0a9fde561

[xpconanfan]

There are a lot of bug fixes in the sl4a client in the AOSP repo. The plan is to update the client here with that one, instead of doing small fixes here.

[johnklee]

Understood. Thanks for the update.

[johnklee]

Hi @xpconanfan , Is there any update from AOSP repo to fix this issue? Our automation is suffering from it and I am thinking if it is ok for us to have a quick fix for it and then I will work on it?

[xpconanfan]

We have decided to deprecate sl4a support as Mobly snippets can now be used in AOSP repo to gain the same level of access without all the legacy problems of sl4a