New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 916187 link

Starred by 1 user
Status: WontFix
Owner:
edcourtney@chromium.org
Closed: Dec 21
Cc:
amistry@chromium.org
x...@chromium.org
kinaba@chromium.org
yusukes@chromium.org
edcourtney@chromium.org
█ hugobenichi@chromium.org
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

veyron_minnie informational PFQ failed cheets_CleanShutDown HWTest due to adb connection failure

Project Member Reported by x...@chromium.org, Dec 18 
It started failing since https://cros-goldeneye.corp.google.com/chromeos/healthmonitoring/buildDetails?buildbucketId=8926807078759944176

See logs https://stainless.corp.google.com/browse/chromeos-autotest-results/268328081-chromeos-test/

Selected error message:
12/18 06:45:48.222 ERROR|             utils:2763| Will raise error TestFail('Failed to connect to adb in 60 seconds.',) due to unexpected return: False
12/18 06:47:57.636 WARNI|              test:0606| The test failed with the following exception
Traceback (most recent call last):
  File "/usr/local/autotest/common_lib/test.py", line 600, in _exec
    _call_test_function(self.execute, *p_args, **p_dargs)
  File "/usr/local/autotest/common_lib/test.py", line 800, in _call_test_function
    return func(*args, **dargs)
  File "/usr/local/autotest/common_lib/test.py", line 464, in execute
    postprocess_profiled_run, args, dargs)
  File "/usr/local/autotest/common_lib/test.py", line 371, in _call_run_once
    self.run_once(*args, **dargs)
  File "/usr/local/autotest/tests/cheets_CleanShutDown/cheets_CleanShutDown.py", line 21, in run_once
    arc.wait_for_android_process('org.chromium.arc.intent_helper')
  File "/usr/local/autotest/common_lib/cros/arc.py", line 489, in wait_for_android_process
    sleep_interval=_PROCESS_CHECK_INTERVAL_SECONDS)
  File "/usr/local/autotest/common_lib/utils.py", line 2757, in poll_for_condition
    value = condition()
  File "/usr/local/autotest/common_lib/cros/arc.py", line 485, in <lambda>
    condition = lambda: is_android_process_running(process_name)
  File "/usr/local/autotest/common_lib/cros/arc.py", line 386, in is_android_process_running
    output = adb_shell('pgrep -c -f %s' % pipes.quote(process_name))
  File "/usr/local/autotest/common_lib/cros/arc.py", line 222, in adb_shell
    output = adb_cmd('shell %s' % pipes.quote(cmd), **kwargs)
  File "/usr/local/autotest/common_lib/cros/arc.py", line 213, in adb_cmd
    wait_for_adb_ready()
  File "/usr/local/autotest/common_lib/cros/arc.py", line 188, in wait_for_adb_ready
    raise error.TestFail('adbd TCP port is not reachable.')
TestFail: adbd TCP port is not reachable.


Assign to current ARC constable for investigation.

Comment 1 by yusukes@chromium.org, Dec 18

Cc: hugobenichi@chromium.org kinaba@chromium.org
Took a look at https://stainless.corp.google.com/browse/chromeos-autotest-results/268328081-chromeos-test/ and tl;dr I"m still not sure what's going on.

* cheets_CleanShutDown.DEBUG [329.7 kB] (in PST, I believe)

The log says

12/18 06:44:42.522 DEBUG|      global_hooks:0056| 'android-sh -c "getprop sys.boot_completed"'
12/18 06:44:43.668 INFO |        arc_common:0107| Android has booted completely.

the container reached the booted state but

12/18 06:45:45.163 DEBUG|             utils:0219| Running 'adb kill-server'
12/18 06:45:45.164 DEBUG|      global_hooks:0056| 'adb kill-server'
12/18 06:45:45.178 DEBUG|             utils:0219| Running 'adb connect localhost:22'
12/18 06:45:45.179 DEBUG|      global_hooks:0056| 'adb connect localhost:22'
12/18 06:45:48.197 DEBUG|             utils:0287| [stdout] * daemon not running. starting it now on port 5037 *
12/18 06:45:48.198 DEBUG|             utils:0287| [stdout] * daemon started successfully *
12/18 06:45:48.198 DEBUG|             utils:0287| [stdout] connected to localhost:22
12/18 06:45:48.199 DEBUG|             utils:0219| Running 'adb get-state'
12/18 06:45:48.200 DEBUG|      global_hooks:0056| 'adb get-state'
12/18 06:45:48.221 DEBUG|               arc:0080| adb get-state: unknown
12/18 06:45:48.222 ERROR|             utils:2763| Will raise error TestFail('Failed to connect to adb in 60 seconds.',) due to unexpected return: False

couldn't connect to adbd even with reties. After that, the log says

12/18 06:47:57.366 DEBUG|               arc:0175| adbd process: 739
12/18 06:47:57.366 DEBUG|               arc:0176| adbd port reachable: False

adbd process was up and running but the host couldn't connect to the '100.115.92.2:5555' tcp port where adbd was supposed to listen on.


* arc.log [859.6 kB] (in UTC)

The log ends with

2018-12-18T14:44:48.079158+00:00 NOTICE arc-kmsg-logger[31101]: <5>init: Starting service 'adbd'...

so it looks like the container's init process at least tried to start adbd. I think it's normal that arc.log ends with the line.


* logcat-boot [682.4 kB] (in PST, I believe)

This has logcat logs around 14:44:48+00:00, but none mentions adbd.


+kinaba@ and +Hugo who might be more familiar with adbd behavior on N.

Comment 2 by yusukes@chromium.org, Dec 18

Cc: yusukesuzuki@chromium.org
Owner: edcourtney@chromium.org
Eliot, could you take this over?

Comment 3 by x...@chromium.org, Dec 18 

Please note: the following run (https://cros-goldeneye.corp.google.com/chromeos/healthmonitoring/buildDetails?buildbucketId=8926782520254128768) just passed. So either this issue just happened once due to bad luck, or it's a flaky test that's still need investigation. 

Better to monitor this build for a few more runs to get more information before closing this out.

Comment 4 by yusukes@google.com, Dec 19

Cc: -yusukesuzuki@chromium.org yusukes@chromium.org

Comment 5 by lpique@google.com, Dec 21 

One failure today, but unrelated, and the other runs yesterday and today were green. Closing.

Comment 6 by lpique@google.com, Dec 21

Status: WontFix (was: Assigned)
►

Sign in to add a comment