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

Issue 893636 link

Starred by 1 user
Status: Fixed
Owner:
█ f...@chromium.org
Last visit 29 days ago
Closed: Oct 12
Cc:
█ yuzhao@chromium.org
drinkcat@chromium.org
teravest@chromium.org
vapier@chromium.org
diand...@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

/var/log/messages timezone are always UTC

Project Member Reported by djkurtz@google.com, Oct 9 
Chrome OS Version: 11125.0.0
Chrome OS Platform: All

Steps To Reproduce:
(1) tail /var/log/messages 

Expected Result:

Timestamps use local timezone, like:

2018-10-04T17:38:10.981685-06:00 INFO kernel: [26065.017611] PM: suspend entry (deep)

Actual Result:

Timestamps always use UTC, like:

2018-10-05T02:43:43.690667+00:00 INFO kernel: [    0.000000] KERNEL supported cpus:

How frequently does this problem reproduce? (Always, sometimes, hard to
reproduce?)
Always.

What is the impact to the user, and is there a workaround? If so, what is
it?

/var/log/messages timestamps can no longer be correlated against other logs in the system, e.g. by Android Bug Tool.

A bisect shows this regression was introduced in R71-11108.0.0 by crrev.com/c/1248324.

A fix has been uploaded as crrev.com/c/1270210.

Comment 1 by vapier@chromium.org, Oct 9

Components: OS>Systems>Minijail OS>Packages
CL:1248324 is largely a red herring imo.  if the timezone was read & stored early on, then it was an accident rather than by design.  if the timezone changed later on, it wouldn't be reflected in the logs regardless of CL:1248324.

it comes down to us not mounting the target of the /etc/localtime symlink which is under /var/lib/timezone/.  that regression was introduced here:
  https://chromium-review.googlesource.com/1053418

issue 889067 would help, but until then, we need to manually bind mount the timezone directory.

then again, arguably we shouldn't be storing timezone data in our log files in the first place.  all storage should be using UTC and nothing else.  the UTC->*current* timezone translation should be done by the person viewing the logs.  that's a bigger issue to sort out, so i can understand if people just want to maintain the (not good) status quo of historical behavior.
Project Member

Comment 2 by bugdroid1@chromium.org, Oct 10 

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/69c44d560a6e7f3b21185dcb4d36542a298d5a23

commit 69c44d560a6e7f3b21185dcb4d36542a298d5a23
Author: Qijiang Fan <fqj@chromium.org>
Date: Wed Oct 10 16:45:03 2018

mount /var/lib/timezone so rsyslogd can read correct timezone.

In preload mode, libc read timezone earlier before the preload libarary
locks everything down.
But in static mode, rsyslogd is execve-ed after everything is locked
down, while /etc/localtime symlinks to /var/lib/timezone/localtime. libc
in rsyslogd needs to be able to read /var/lib/timezone/localtime to
determine the correct timezone.

This change alsl creates /var/lib/timezone directory in pre-start of
syslog.conf, and update selinux policy to make sure timezone created
by cros_init_scripts in cros_var_lib is labelled as cros_tz_data_file.

BUG=b:117351818,b:116072767,b:80461815, chromium:893636 
TEST=tail /var/log/messages and observes timezone

Change-Id: I708c6ab65a79f6dcdd6751673e70b3ea88f4c6ed
Reviewed-on: https://chromium-review.googlesource.com/1270210
Commit-Ready: Qijiang Fan <fqj@google.com>
Tested-by: Qijiang Fan <fqj@google.com>
Reviewed-by: Mike Frysinger <vapier@chromium.org>

[modify] https://crrev.com/69c44d560a6e7f3b21185dcb4d36542a298d5a23/sepolicy/policy/chromeos/cros_init.te
[modify] https://crrev.com/69c44d560a6e7f3b21185dcb4d36542a298d5a23/init/upstart/syslog.conf

Comment 3 by f...@chromium.org, Oct 12

Status: Fixed (was: Started)
►

Sign in to add a comment