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

Issue 677525 link

Starred by 1 user
Status: Duplicate
Owner:
xixuan@chromium.org
Closed: Jun 2017
Cc:
x...@chromium.org
█ gkihumba@chromium.org
akes...@chromium.org
█ dtor@chromium.org
█ mka@chromium.org
xixuan@chromium.org
dgarr...@chromium.org
afakhry@chromium.org
semenzato@chromium.org
█ kevcheng@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

devserver portfile does not exist (or other problem)

Project Member Reported by semenzato@chromium.org, Dec 29 2016 
NOTE: I am opening this as a substitute for issue 658374.  (That one has become unusable because we didn't know better and duplicated auto-filed bugs into it, so the auto-filing has taken over.  Please do not duplicate that one into here.)

I am copying owner and cc list from issue 658374.

In addition to the cases reported and linked on issue 658374, a new one just came up and was auto-filed as issue 671542.  However, other errors are present before the "devserver portfile" message, so I have opened  issue 677524  for those.  If the devserver portfile message is spurious, it would be nice to avoid it.

https://uberchromegw.corp.google.com/i/chromeos/builders/nyan_blaze-release/builds/714

https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/93265619-chromeos-test/chromeos4-row7-rack6-host15/debug/

Comment 1 by semenzato@chromium.org, Dec 29 2016

Cc: kevcheng@chromium.org
Components: Infra>Client>ChromeOS
Labels: OS-Chrome

Comment 2 by semenzato@chromium.org, Dec 29 2016 

Also at this build, but different from the nyan_blaze failure above.

https://uberchromegw.corp.google.com/i/chromeos/builders/veyron_jerry-release/builds/710

https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/93267160-chromeos-test/chromeos4-row4-rack4-host20/debug/

12/29 05:34:13.016 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.133 'curl "http://100.115.219.133:8082/get_au_status?build_name=veyron_jerry-release/R57-9132.0.0&force_update=True&pid=7372&host_name=chromeos4-row4-rack4-host20&full_update=False"''
12/29 05:34:13.909 DEBUG|        dev_server:1723| Current CrOS auto-update status: rootfs update
12/29 05:34:23.957 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.133 'curl "http://100.115.219.133:8082/get_au_status?build_name=veyron_jerry-release/R57-9132.0.0&force_update=True&pid=7372&host_name=chromeos4-row4-rack4-host20&full_update=False"''
12/29 05:34:24.847 DEBUG|        dev_server:1785| Failed to trigger auto-update process on devserver
12/29 05:34:24.848 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.133 'curl "http://100.115.219.133:8082/handler_cleanup?pid=7372&host_name=chromeos4-row4-rack4-host20"''
12/29 05:34:25.746 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.133 'curl "http://100.115.219.133:8082/collect_cros_au_log?pid=7372&host_name=chromeos4-row4-rack4-host20"''
12/29 05:34:26.743 DEBUG|        dev_server:1617| Saving auto-update logs into /usr/local/autotest/results/hosts/chromeos4-row4-rack4-host20/616066-provision/20162912053004/autoupdate_logs/CrOS_update_chromeos4-row4-rack4-host20_7372.log
12/29 05:34:26.744 DEBUG|        dev_server:1884| Exception raised on auto_update attempt #1:
 Traceback (most recent call last):
  File "/home/chromeos-test/chromiumos/src/platform/dev/cros_update.py", line 222, in TriggerAU
    self._RootfsUpdate(chromeos_AU)
  File "/home/chromeos-test/chromiumos/src/platform/dev/cros_update.py", line 151, in _RootfsUpdate
    cros_updater.UpdateRootfs()
  File "/home/chromeos-test/chromiumos/chromite/lib/auto_updater.py", line 483, in UpdateRootfs
    raise RootfsUpdateError(error_msg % e)
RootfsUpdateError: Failed to perform rootfs update: DevServerStartupError('Devserver portfile does not exist!',)
12/29 05:34:26.745 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.133 'curl "http://100.115.219.133:8082/kill_au_proc?host_name=chromeos4-row4-rack4-host20"''
12/29 05:34:47.738 DEBUG|        dev_server:1902| AU failed, trying IP instead of hostname: 100.115.195.26
12/29 05:34:47.738 DEBUG|        dev_server:1847| Start CrOS auto-update for host chromeos4-row4-rack4-host20 at 2 time(s).
12/29 05:34:47.739 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.133 'curl "http://100.115.219.133:8082/cros_au?build_name=veyron_jerry-release/R57-9132.0.0&async=True&force_update=True&host_name=100.115.195.26&full_update=False"''
12/29 05:34:48.676 INFO |        dev_server:1667| Received response from devserver for cros_au call: '[true, 18787]'
12/29 05:34:48.676 DEBUG|        dev_server:1782| start process 18787 for auto_update in devserver
12/29 05:34:48.676 DEBUG|        dev_server:1688| Check the progress for auto-update process 18787

Comment 3 by semenzato@chromium.org, Dec 29 2016

Cc: dtor@chromium.org

Comment 4 by semenzato@chromium.org, Feb 9 2017 

I am hoping this is the right bug for "Devserver portfile does not exist".

https://uberchromegw.corp.google.com/i/chromeos/builders/veyron_jaq-release/builds/839

https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/100292536-chromeos-test/chromeos4-row4-rack6-host19/debug/


02/09 05:36:25.920 DEBUG|        dev_server:1794| Current CrOS auto-update status: transfer rootfs update package
02/09 05:36:35.970 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:36:37.360 DEBUG|        dev_server:1794| Current CrOS auto-update status: pre-setup rootfs update
02/09 05:36:47.411 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:36:48.808 DEBUG|        dev_server:1794| Current CrOS auto-update status: pre-setup rootfs update
02/09 05:36:58.858 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:37:00.190 DEBUG|        dev_server:1794| Current CrOS auto-update status: pre-setup rootfs update
02/09 05:37:10.238 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:37:11.456 DEBUG|        dev_server:1794| Current CrOS auto-update status: rootfs update
02/09 05:37:21.477 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:37:23.004 DEBUG|        dev_server:1794| Current CrOS auto-update status: rootfs update
02/09 05:37:33.042 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:37:34.679 DEBUG|        dev_server:1794| Current CrOS auto-update status: rootfs update
02/09 05:37:44.730 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:37:46.233 DEBUG|        dev_server:1794| Current CrOS auto-update status: rootfs update
02/09 05:37:56.264 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:37:57.902 DEBUG|        dev_server:1794| Current CrOS auto-update status: rootfs update
02/09 05:38:07.943 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/get_au_status?build_name=veyron_jaq-release/R58-9267.0.0&force_update=True&pid=489&host_name=chromeos4-row4-rack6-host19&full_update=False"''
02/09 05:38:09.710 DEBUG|        dev_server:1856| Failed to trigger auto-update process on devserver
02/09 05:38:09.710 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/handler_cleanup?pid=489&host_name=chromeos4-row4-rack6-host19"''
02/09 05:38:11.161 DEBUG|        base_utils:0185| Running 'ssh 100.115.219.129 'curl "http://100.115.219.129:8082/collect_cros_au_log?pid=489&host_name=chromeos4-row4-rack6-host19"''
02/09 05:38:12.683 DEBUG|        dev_server:1688| Saving auto-update logs into /usr/local/autotest/results/hosts/chromeos4-row4-rack6-host19/753824-provision/20170902053329/autoupdate_logs/CrOS_update_chromeos4-row4-rack6-host19_489.log
02/09 05:38:12.683 DEBUG|        dev_server:1955| Exception raised on auto_update attempt #1:
 Traceback (most recent call last):
  File "/home/chromeos-test/chromiumos/src/platform/dev/cros_update.py", line 222, in TriggerAU
    self._RootfsUpdate(chromeos_AU)
  File "/home/chromeos-test/chromiumos/src/platform/dev/cros_update.py", line 151, in _RootfsUpdate
    cros_updater.UpdateRootfs()
  File "/home/chromeos-test/chromiumos/chromite/lib/auto_updater.py", line 501, in UpdateRootfs
    raise RootfsUpdateError(error_msg % e)
RootfsUpdateError: Failed to perform rootfs update: DevServerStartupError('Devserver portfile does not exist!',)


We're seeing the "pre-setup rootfs update" phase complete, and about 60 seconds into the "rootfs update" phase, we get the "devserver portfile" error.

Comment 5 by semenzato@chromium.org, Feb 10 2017 

I am looking at the code that generates this error.  There are two places, both in chromite/lib/dev_server_wrapper.py, in two methods: _ReadPortNumber() in class RemoteDevServerWrapper and class DevServerWrapper.

In the latter:

    try:
      timeout_util.WaitForReturnTrue(os.path.exists,
                                     func_args=[self.port_file],
                                     timeout=self.DEV_SERVER_TIMEOUT,
                                     period=5)
    except timeout_util.TimeoutError:
      self.terminate()
      raise DevServerStartupError('Devserver portfile does not exist!')

in the former:

    try:
      timeout_util.WaitForReturnTrue(PortFileExists,
                                     timeout=self.DEV_SERVER_TIMEOUT,
                                     period=5)
    except timeout_util.TimeoutError:
      self.terminate()
      raise DevServerStartupError('Devserver portfile does not exist!')


A few problems.  First, it would be useful to have different error messages, to help understand where we are.  Second, it's not clear why retries with a timeout are necessary in the local case.  Third, in the remote case it would also be useful to distinguish a communication failure from a missing portfile.

Comment 6 by adurbin@chromium.org, Feb 14 2017 

veyron_jaq appears to be very much affected by this bug.
Project Member

Comment 7 by bugdroid1@chromium.org, Feb 21 2017 

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/chromite/+/41bfde6b23d7682f32b915b40abd38fffbe94381

commit 41bfde6b23d7682f32b915b40abd38fffbe94381
Author: Luigi Semenzato <semenzato@chromium.org>
Date: Tue Feb 21 22:07:43 2017

chromite: change some devserver failure messages

The purpose is to differentiate some messages, as well
as make it clearer what the failure reasons may be.

BUG= chromium:677525 
TEST=none

Change-Id: Ic553b1e659527ab7d206c319e32751c888a498bd
Reviewed-on: https://chromium-review.googlesource.com/441186
Commit-Ready: Luigi Semenzato <semenzato@chromium.org>
Tested-by: Luigi Semenzato <semenzato@chromium.org>
Reviewed-by: Xixuan Wu <xixuan@chromium.org>

[modify] https://crrev.com/41bfde6b23d7682f32b915b40abd38fffbe94381/lib/dev_server_wrapper.py
[delete] https://crrev.com/b321453fbd94e5fe69e598288e4f50c099bc2dc9/chromite

Comment 9 by xixuan@chromium.org, Jun 20 2017

Mergedinto: 658374
Status: Duplicate (was: Untriaged)
►

Sign in to add a comment