New issue
Advanced search Search tips

Issue 724273 link

Starred by 1 user

Issue metadata

Status: Archived
Owner:
Closed: Jun 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

Autotest does not capture chrome user log

Project Member Reported by xiy...@chromium.org, May 18 2017

Issue description

Found this while looking at issue 719632. We have VLOG enabled for screen locker code but it is not captured in test results. Those VLOG goes into chrome user logs. The log is added to site_sysinfo.test_loggables [1] and be collected after test case finishes [2].

However, when run_once finishes, cros/chrome.py __exit__ will be invoked to logout the user before we collect the user logs, as shown in the following sample stack:

14:08:51 INFO | (Re)starting the ui (logs the user out)
14:08:51 INFO |   File "../bin/autotest", line 97, in <module>
... autotest infra stack omiited ...
14:08:51 INFO |     self.run_once(*args, **dargs)
14:08:51 INFO |   File "/usr/local/autotest/tests/desktopui_ScreenLocker/desktopui_ScreenLocker.py", line 175, in run_once
14:08:51 INFO |     higher_is_better=False)
14:08:51 INFO |   File "/usr/local/autotest/common_lib/cros/chrome.py", line 180, in __exit__
14:08:51 INFO |     self.close()
14:08:51 INFO |   File "/usr/local/autotest/common_lib/cros/chrome.py", line 304, in close
14:08:51 INFO |     self._browser.Close()
14:08:51 INFO |   File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/browser/browser.py", line 268, in Close
14:08:51 INFO |     self._browser_backend.Close()
14:08:51 INFO |   File "/usr/local/telemetry/src/third_party/catapult/common/py_trace_event/py_trace_event/trace_event_impl/decorators.py", line 52, in traced_function
14:08:51 INFO |     return func(*args, **kwargs)
14:08:51 INFO |   File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/cros_browser_backend.py", line 180, in Close
14:08:51 INFO |     self._cri.RestartUI(False) # Logs out.
14:08:51 INFO |   File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/core/cros_interface.py", line 550, in RestartUI
14:08:51 INFO |     traceback.print_stack(file=sys.stdout)
14:08:53 INFO | #### Collecting chrome log at /home/chronos/user/log

One possible approach would be disabling RedirectChromeLogging for autotest (maybe via a commandline switch) so that all chrome logs go to /var/log/chrome.

Passing to achuith@ to triage. Thanks.

======
[1]: https://cs.corp.google.com/chromeos_public/src/third_party/autotest/files/client/bin/site_sysinfo.py?rcl=5734df660a52c6c33a03474b61288cc2d09eb6a9&l=270-272
[2]: https://cs.corp.google.com/piper///depot/google3/third_party/py/autotest_lib/client/bin/test.py?rcl=68114670&l=116
[3]: https://cs.chromium.org/chromium/src/chrome/common/logging_chrome.cc?rcl=93304bdb30f35daf45c935a39f23d7277ee6ccfa&l=231
 
Labels: -Pri-3 Pri-2
Status: Started (was: Assigned)
https://codereview.chromium.org/2901603002/
https://codereview.chromium.org/2893313003/
Project Member

Comment 3 by bugdroid1@chromium.org, May 25 2017

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

commit 91f210ae83f8cc3a2cf10cd81cf0501b73067465
Author: sky <sky@chromium.org>
Date: Thu May 25 20:04:21 2017

Revert of Move RedirectChromeLogging to src/chromeos. (patchset #2 id:20001 of https://codereview.chromium.org/2901173002/ )

Reason for revert:
This is causing IO failures. Specifically the SetUpSymlinkIfNeeded causes an IO assertion to hit and login to crash.

Original issue's description:
> Move RedirectChromeLogging to src/chromeos.
>
> BUG= chromium:724273 
>
> Review-Url: https://codereview.chromium.org/2901173002
> Cr-Commit-Position: refs/heads/master@{#474725}
> Committed: https://chromium.googlesource.com/chromium/src/+/cb9bde9860d070b022407e3d988ba3239e00f35a

TBR=xiyuan@chromium.org,achuith@chromium.org
# Skipping CQ checks because original CL landed less than 1 days ago.
NOPRESUBMIT=true
NOTREECHECKS=true
NOTRY=true
BUG= chromium:724273 

Review-Url: https://codereview.chromium.org/2909483003
Cr-Commit-Position: refs/heads/master@{#474770}

[modify] https://crrev.com/91f210ae83f8cc3a2cf10cd81cf0501b73067465/chrome/browser/chromeos/BUILD.gn
[modify] https://crrev.com/91f210ae83f8cc3a2cf10cd81cf0501b73067465/chrome/browser/chromeos/chrome_browser_main_chromeos.cc
[delete] https://crrev.com/0ae38ad9a9c73c4bb36e8867cc1c5643142081ff/chrome/browser/chromeos/logging.cc
[delete] https://crrev.com/0ae38ad9a9c73c4bb36e8867cc1c5643142081ff/chrome/browser/chromeos/logging.h
[modify] https://crrev.com/91f210ae83f8cc3a2cf10cd81cf0501b73067465/chrome/browser/chromeos/login/session/user_session_manager.cc
[modify] https://crrev.com/91f210ae83f8cc3a2cf10cd81cf0501b73067465/chrome/common/logging_chrome.cc
[modify] https://crrev.com/91f210ae83f8cc3a2cf10cd81cf0501b73067465/chrome/common/logging_chrome.h
[modify] https://crrev.com/91f210ae83f8cc3a2cf10cd81cf0501b73067465/chrome/test/base/in_process_browser_test.cc

Project Member

Comment 4 by bugdroid1@chromium.org, Jun 1 2017

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

commit 7ea0aaca6b630b50a600fc57473d24e27302b9cb
Author: achuith <achuith@chromium.org>
Date: Thu Jun 01 20:31:42 2017

Move RedirectChromeLogging to src/chromeos.

BUG= chromium:724273 

Review-Url: https://codereview.chromium.org/2901173002
Cr-Original-Commit-Position: refs/heads/master@{#474725}
Committed: https://chromium.googlesource.com/chromium/src/+/cb9bde9860d070b022407e3d988ba3239e00f35a
Review-Url: https://codereview.chromium.org/2901173002
Cr-Commit-Position: refs/heads/master@{#476417}

[modify] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/browser/chromeos/BUILD.gn
[modify] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/browser/chromeos/chrome_browser_main_chromeos.cc
[add] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/browser/chromeos/logging.cc
[add] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/browser/chromeos/logging.h
[modify] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/browser/chromeos/login/session/user_session_manager.cc
[modify] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/common/logging_chrome.cc
[modify] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/common/logging_chrome.h
[modify] https://crrev.com/7ea0aaca6b630b50a600fc57473d24e27302b9cb/chrome/test/base/in_process_browser_test.cc

Project Member

Comment 5 by bugdroid1@chromium.org, Jun 1 2017

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

commit 279874b4b774288861a5bda6934fa6a7e3fc5153
Author: achuith <achuith@chromium.org>
Date: Thu Jun 01 23:14:45 2017

Add a switch to prevent logging redirection on chromeos.

This switch will be used by telemetry so all chrome logging goes to
/var/log/chrome/chrome instead of split between this location and
/home/chronos/user/log/chrome, which is in the cryptohome, and sometimes
not collected by autotests.

BUG= chromium:724273 
TEST=manual

Review-Url: https://codereview.chromium.org/2893313003
Cr-Commit-Position: refs/heads/master@{#476476}

[modify] https://crrev.com/279874b4b774288861a5bda6934fa6a7e3fc5153/chrome/browser/chromeos/logging.cc
[modify] https://crrev.com/279874b4b774288861a5bda6934fa6a7e3fc5153/chrome/common/chrome_switches.cc
[modify] https://crrev.com/279874b4b774288861a5bda6934fa6a7e3fc5153/chrome/common/chrome_switches.h

Project Member

Comment 6 by bugdroid1@chromium.org, Jun 2 2017

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

commit 1edede81c91a1057842e803f87ee1393ac5c172f
Author: catapult-deps-roller@chromium.org <catapult-deps-roller@chromium.org>
Date: Fri Jun 02 02:31:32 2017

Roll src/third_party/catapult/ 817b8684b..b33525e99 (4 commits)

https://chromium.googlesource.com/external/github.com/catapult-project/catapult.git/+log/817b8684be60..b33525e99124

$ git log 817b8684b..b33525e99 --date=short --no-merges --format='%ad %ae %s'
2017-06-01 benjhayden Check that Diagnostic subclasses are registered in presubmit.
2017-06-01 dtu [pinpoint] Handle Job failure.
2017-06-01 achuith Disable logging redirect on chromeos.
2017-06-01 benjhayden Simplify dashboard autocomplete-box.

Created with:
  roll-dep src/third_party/catapult
BUG= 724273 


Documentation for the AutoRoller is here:
https://skia.googlesource.com/buildbot/+/master/autoroll/README.md

If the roll is causing failures, see:
http://www.chromium.org/developers/tree-sheriffs/sheriff-details-chromium#TOC-Failures-due-to-DEPS-rolls


CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_optional_gpu_tests_rel
TBR=sullivan@chromium.org

Change-Id: Ife7287880104fcce2c3109c20e215645b0e13210
Reviewed-on: https://chromium-review.googlesource.com/521771
Reviewed-by: <catapult-deps-roller@chromium.org>
Commit-Queue: <catapult-deps-roller@chromium.org>
Cr-Commit-Position: refs/heads/master@{#476526}
[modify] https://crrev.com/1edede81c91a1057842e803f87ee1393ac5c172f/DEPS

Status: Fixed (was: Started)
I looked at desktopui_ScreenLocker from this run:
https://uberchromegw.corp.google.com/i/chromiumos.chromium/builders/amd64-generic-tot-chromium-pfq-informational/builds/12393

This tests logs in and locks the screen. I've attached the contents of /var/log/chrome/chrome, and it should be apparent that logging continues in the same file after login.
desktopui_screenlocker_log.txt
20.4 KB View Download
Cool. Thanks for the quick fix.

Comment 9 by dchan@chromium.org, Aug 1 2017

Labels: VerifyIn-61

Comment 10 by dchan@chromium.org, Jan 22 2018

Status: Archived (was: Fixed)

Sign in to add a comment