mobly icon indicating copy to clipboard operation
mobly copied to clipboard
verified publisher icon google

[TBD] Failed to shutdown sl4a event dispatcher.

Open johnklee opened this issue 4 years ago • 6 comments

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!

johnklee avatar May 18 '21 07:05 johnklee

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

xpconanfan avatar May 18 '21 07:05 xpconanfan

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 
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 avatar May 20 '21 12:05 johnklee

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

johnklee avatar May 21 '21 12:05 johnklee

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.

xpconanfan avatar May 21 '21 15:05 xpconanfan

Understood. Thanks for the update.

johnklee avatar May 22 '21 01:05 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?

johnklee avatar Aug 02 '22 06:08 johnklee

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

xpconanfan avatar Jan 24 '23 18:01 xpconanfan