New issue
Advanced search Search tips

Issue 839207 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: May 2018
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

Clicking on Terminal in applist Search bar gives no feedback

Project Member Reported by nverne@chromium.org, May 3 2018

Issue description

https://listnr.corp.google.com/product/208/report/85390545361?dateRange=All

User clicked Terminal multiple times. No terminal started. System logs show multiple overlapping attempts to run container, all failing.

2018-05-02T15:57:59.867019-07:00 INFO vm_concierge[6782]: Launching run_container.sh inside VM 7
2018-05-02T15:58:02.268570-07:00 INFO VM(7)[6783]:  lxd_setup: Container 'penguin'  does not exist; creating from 'debian/stretch' on <URL: 37>
2018-05-02T15:58:02.268587-07:00 INFO VM(7)[6783]: message repeated 3 times: [  lxd_setup: Container 'penguin'  does not exist; creating from 'debian/stretch' on <URL: 37>]
2018-05-02T15:58:10.408639-07:00 INFO vm_concierge[6782]: Received CreateDiskImage request
2018-05-02T15:58:10.412717-07:00 INFO vm_concierge[6782]: Received StartVm request
2018-05-02T15:58:10.412792-07:00 INFO vm_concierge[6782]: VM with requested name is already running
2018-05-02T15:58:10.429707-07:00 INFO vm_concierge[6782]: Received StartContainer request
2018-05-02T15:58:10.429788-07:00 INFO vm_concierge[6782]: Checking if container penguin is running
2018-05-02T15:58:10.429815-07:00 INFO vm_concierge[6782]: No such container: penguin
2018-05-02T15:58:10.429884-07:00 INFO vm_concierge[6782]: Launching run_container.sh inside VM 7
2018-05-02T15:58:10.908020-07:00 INFO vm_concierge[6782]: Received CreateDiskImage request
2018-05-02T15:58:10.918830-07:00 INFO vm_concierge[6782]: Received StartVm request
2018-05-02T15:58:10.918917-07:00 INFO vm_concierge[6782]: VM with requested name is already running
2018-05-02T15:58:10.941417-07:00 INFO vm_concierge[6782]: Received StartContainer request
2018-05-02T15:58:10.941499-07:00 INFO vm_concierge[6782]: Checking if container penguin is running
2018-05-02T15:58:10.941525-07:00 INFO vm_concierge[6782]: No such container: penguin
2018-05-02T15:58:10.941603-07:00 INFO vm_concierge[6782]: Launching run_container.sh inside VM 7
2018-05-02T15:58:12.269664-07:00 INFO VM(7)[6783]:  lxd_setup: Container 'penguin'  does not exist; creating from 'debian/stretch' on <URL: 37>
2018-05-02T15:58:12.269674-07:00 INFO VM(7)[6783]:  lxd_setup: Container 'penguin'  does not exist; creating from 'debian/stretch' on <URL: 37>
2018-05-02T15:58:12.274085-07:00 INFO VM(7)[6783]: kernel: maitred: Received request to launch process
2018-05-02T15:58:12.274097-07:00 INFO VM(7)[6783]: kernel: maitred: Launched process run_container.sh
2018-05-02T15:58:12.274102-07:00 INFO VM(7)[6783]: kernel: maitred: Received request to launch process
2018-05-02T15:58:12.274106-07:00 INFO VM(7)[6783]: kernel: maitred: Launched process run_container.sh
2018-05-02T15:58:14.097117-07:00 ERR cras_server[1627]: pcm_avail returned frames larger than buf_size: kbl_r5514_5663_max: :0,0: 16399 > 16384 for 1 times
2018-05-02T15:58:17.843212-07:00 INFO permission_broker[1566]: ProcessPath(/dev/hidraw2)
2018-05-02T15:58:18.048170-07:00 INFO permission_broker[1566]:   AllowUsbDeviceRule: IGNORE
2018-05-02T15:58:18.048808-07:00 INFO permission_broker[1566]:   AllowTtyDeviceRule: IGNORE
2018-05-02T15:58:18.049280-07:00 INFO permission_broker[1566]:   DenyClaimedUsbDeviceRule: IGNORE
2018-05-02T15:58:18.049552-07:00 INFO permission_broker[1566]:   DenyUninitializedDeviceRule: IGNORE
2018-05-02T15:58:18.049949-07:00 INFO permission_broker[1566]:   DenyUsbDeviceClassRule: IGNORE
2018-05-02T15:58:18.050166-07:00 INFO permission_broker[1566]:   DenyUsbDeviceClassRule: IGNORE
2018-05-02T15:58:18.050954-07:00 INFO permission_broker[1566]:   DenyUsbVendorIdRule: IGNORE
2018-05-02T15:58:18.051337-07:00 INFO permission_broker[1566]:   AllowHidrawDeviceRule: ALLOW
2018-05-02T15:58:18.051554-07:00 INFO permission_broker[1566]:   AllowGroupTtyDeviceRule: IGNORE
2018-05-02T15:58:18.051895-07:00 INFO permission_broker[1566]:   DenyGroupTtyDeviceRule: IGNORE
2018-05-02T15:58:18.052345-07:00 INFO permission_broker[1566]: message repeated 2 times: [   DenyGroupTtyDeviceRule: IGNORE]
2018-05-02T15:58:18.352139-07:00 INFO permission_broker[1566]:   DenyClaimedHidrawDeviceRule: IGNORE
2018-05-02T15:58:18.507357-07:00 INFO permission_broker[1566]:   DenyUnsafeHidrawDeviceRule: IGNORE
2018-05-02T15:58:18.507376-07:00 INFO permission_broker[1566]: Verdict for /dev/hidraw2: ALLOW
2018-05-02T15:58:19.550742-07:00 ERR vm_concierge[6782]: Startup of container penguin for VM termina failed.
2018-05-02T15:58:21.639100-07:00 ERR vm_concierge[6782]: message repeated 6 times: [ Startup of container penguin for VM termina failed.]
2018-05-02T15:58:22.006282-07:00 INFO vm_concierge[6782]: Received CreateDiskImage request
2018-05-02T15:58:22.008014-07:00 INFO vm_concierge[6782]: Received StartVm request
2018-05-02T15:58:22.008091-07:00 INFO vm_concierge[6782]: VM with requested name is already running
2018-05-02T15:58:22.008969-07:00 INFO vm_concierge[6782]: Received StartContainer request
2018-05-02T15:58:22.009016-07:00 INFO vm_concierge[6782]: Checking if container penguin is running
2018-05-02T15:58:22.009034-07:00 INFO vm_concierge[6782]: No such container: penguin
2018-05-02T15:58:22.009088-07:00 INFO vm_concierge[6782]: Launching run_container.sh inside VM 7
2018-05-02T15:58:22.273742-07:00 ERR VM(7)[6783]:  run_container: Unable to launch container from image 'debian/stretch'
2018-05-02T15:58:22.273755-07:00 INFO VM(7)[6783]:  dnsmasq[318]: read /etc/hosts - 2 addresses
2018-05-02T15:58:22.273759-07:00 INFO VM(7)[6783]:  dnsmasq-dhcp[318]: read /mnt/stateful/lxd/networks/lxdbr0/dnsmasq.hosts/penguin
2018-05-02T15:58:22.273762-07:00 ERR VM(7)[6783]:  run_container: Unable to launch container from image 'debian/stretch'
2018-05-02T15:58:22.273784-07:00 ERR VM(7)[6783]: message repeated 5 times: [  run_container: Unable to launch container from image 'debian/stretch']
2018-05-02T15:58:22.276098-07:00 INFO VM(7)[6783]: kernel: maitred: run_container.sh (844) exited with status 1
2018-05-02T15:58:22.276108-07:00 ERR VM(7)[6783]: kernel: maitred: Detected failure in run_container.sh execution for container penguin
2018-05-02T15:58:22.276112-07:00 INFO VM(7)[6783]: kernel: maitred: run_container.sh (1179) exited with status 1
2018-05-02T15:58:22.276115-07:00 ERR VM(7)[6783]: kernel: maitred: Detected failure in run_container.sh execution for container penguin
2018-05-02T15:58:22.276119-07:00 INFO VM(7)[6783]: kernel: maitred: run_container.sh (535) exited with status 1
2018-05-02T15:58:22.276122-07:00 ERR VM(7)[6783]: kernel: maitred: Detected failure in run_container.sh execution for container penguin
2018-05-02T15:58:22.276126-07:00 INFO VM(7)[6783]: kernel: maitred: run_container.sh (647) exited with status 1
2018-05-02T15:58:22.276130-07:00 ERR VM(7)[6783]: kernel: maitred: Detected failure in run_container.sh execution for container penguin
2018-05-02T15:58:22.276133-07:00 INFO VM(7)[6783]: kernel: maitred: run_container.sh (757) exited with status 1
2018-05-02T15:58:22.276137-07:00 ERR VM(7)[6783]: kernel: maitred: Detected failure in run_container.sh execution for container penguin
2018-05-02T15:58:22.964349-07:00 ERR vm_concierge[6782]: Startup of container penguin for VM termina failed.
2018-05-02T15:58:27.278164-07:00 ERR VM(7)[6783]:  run_container: Failed to start container 'penguin'
 
A related problem here: run_container.sh in the container is not re-entrant. There is no need to make it re-entrant. CrostiniManager shouldn't be making overlapping StartContainer calls to concierge. This can be fixed in CrostiniRestarter.
Labels: Hotlist-Crostini-UI
Project Member

Comment 3 by bugdroid1@chromium.org, May 14 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/36d0cc248c312594ec052fa0c37b8592dc497326

commit 36d0cc248c312594ec052fa0c37b8592dc497326
Author: Nicholas Verne <nverne@chromium.org>
Date: Mon May 14 04:41:06 2018

CrostiniRestarter static data is now handled by a KeyedService.

CrostiniRestarterService and CrostiniRestarterServiceFactory are kept
local to CrostiniManager (for now) as they don't need to be exposed to
other code. There is one CrostiniRestarterService per profile, and it
owns CrostiniRestarter objects for that profile.

When multiple calls to CrostiniManager::RestartCrostini are made due to
user action, only one actual restart flow will run, and when it
completes, multiple completion callbacks will run in succession.

Bug:  839207 
Change-Id: Icbf1da00fd9c937cd51bb77f0ad57bd63476b27b
Reviewed-on: https://chromium-review.googlesource.com/1051208
Commit-Queue: Nicholas Verne <nverne@chromium.org>
Reviewed-by: Timothy Loh <timloh@chromium.org>
Cr-Commit-Position: refs/heads/master@{#558194}
[modify] https://crrev.com/36d0cc248c312594ec052fa0c37b8592dc497326/chrome/browser/chromeos/crostini/crostini_manager.cc
[modify] https://crrev.com/36d0cc248c312594ec052fa0c37b8592dc497326/chrome/browser/chromeos/crostini/crostini_manager.h
[modify] https://crrev.com/36d0cc248c312594ec052fa0c37b8592dc497326/chrome/browser/chromeos/crostini/crostini_manager_unittest.cc
[modify] https://crrev.com/36d0cc248c312594ec052fa0c37b8592dc497326/chrome/browser/chromeos/crostini/crostini_remover.cc
[modify] https://crrev.com/36d0cc248c312594ec052fa0c37b8592dc497326/chrome/browser/ui/app_list/crostini/crostini_installer_view.cc

Comment 4 by nverne@chromium.org, May 14 2018

The "no feedback because concierge is unhappy behind the scenes" part of this bug should now be fixed. 
Project Member

Comment 5 by bugdroid1@chromium.org, May 17 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/c5a040bb4c8de34b5171bd27e879044d2430e889

commit c5a040bb4c8de34b5171bd27e879044d2430e889
Author: Timothy Loh <timloh@chromium.org>
Date: Thu May 17 01:02:40 2018

Dismiss the App List when launching a CrostiniAppResult

Similar to how we dismiss the app list when launching a Crostini app or
terminal from the main list of apps, we should also dismiss it when
launching from search or the recently used app list.

Bug:  839207 
Change-Id: I2968e827c6feacb7e58660a0784463d091bf90e4
Reviewed-on: https://chromium-review.googlesource.com/1060834
Reviewed-by: Xiyuan Xia <xiyuan@chromium.org>
Commit-Queue: Timothy Loh <timloh@chromium.org>
Cr-Commit-Position: refs/heads/master@{#559376}
[modify] https://crrev.com/c5a040bb4c8de34b5171bd27e879044d2430e889/chrome/browser/ui/app_list/search/crostini_app_result.cc

Comment 6 by timloh@chromium.org, May 17 2018

Status: Fixed (was: Assigned)
Spinner work is being tracked in  bug 836673 .

Comment 7 by vapier@chromium.org, May 17 2018

Labels: -Restrict-View-Google

Sign in to add a comment