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

Issue 840510 link

Starred by 2 users
Status: Assigned
Owner:
michae...@chromium.org
Cc:
derat@chromium.org
alemate@chromium.org
█ wad@chromium.org
puthik@chromium.org
steve...@chromium.org
dpa...@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug-Regression



Sign in to add a comment

"Check your system time" available when time is set correctly

Project Member Reported by michae...@chromium.org, May 7 2018 
Chrome Version: 67.0.3396.26
OS: Chrome

1. Have a working network connection, so date and time are synced properly
2. Visit Date and Time settings at chrome://settings/dateTime or by clicking the date in the system tray

Expected: "Set date and time" row should not be visible
Actual: "Set date and time" row is visible and the "Check your system time" dialog can be launched

This dialog shouldn't be accessible when time is set from the network. It's impossible for the user to override network-synced time, so if they make changes to the time in the dialog and click "Done", the new time doesn't persist.

When originally implemented, the "Set date and time" row wasn't available unless we hadn't synced the time since the last boot.

Comment 1 by michae...@chromium.org, May 7 2018

Cc: wad@chromium.org
Owner: ----
Status: Available (was: Started)
AFAICT the SystemClockClient is telling us that we CAN set the system time, which implies tlsdate is misbehaving, which would surprise me.

tlsdate successfully acquires network time, although there are several errors beforehand:

2018-05-07T12:27:44.297236-07:00 INFO tlsdated[2155]: [event:action_kickoff_time_sync] clock delta desync detected (1525654163 != 1525719184)
2018-05-07T12:27:44.297429-07:00 NOTICE tlsdate[2156]: [event:action_kickoff_time_sync] clock delta desync detected (1525654163 != 1525719184)
2018-05-07T12:28:22.313572-07:00 INFO tlsdated[2155]: [event:action_resolve_proxy] no resolve_proxy sent; pending method_reply
2018-05-07T12:28:22.313628-07:00 NOTICE tlsdate[2156]: [event:action_resolve_proxy] no resolve_proxy sent; pending method_reply
2018-05-07T12:28:52.326560-07:00 INFO tlsdated[2155]: [event:action_run_tlsdate] attempt 1 backoff 10
2018-05-07T12:28:52.326748-07:00 NOTICE tlsdate[2156]: [event:action_run_tlsdate] attempt 1 backoff 10
2018-05-07T12:28:52.327252-07:00 NOTICE tlsdate[2156]: V: tlsdate version 0.0.5
2018-05-07T12:28:52.327264-07:00 NOTICE tlsdate[2156]: V: We were called with the following arguments:
2018-05-07T12:28:52.327272-07:00 NOTICE tlsdate[2156]: V: validate SSL certificates host = clients3.google.com:443
2018-05-07T12:28:52.328366-07:00 NOTICE tlsdate[2156]: V: time is currently 1525721332.328254872
2018-05-07T12:28:52.328378-07:00 NOTICE tlsdate[2156]: V: time is greater than RECENT_COMPILE_DATE
2018-05-07T12:28:52.331929-07:00 NOTICE tlsdate[2156]: V: using TLSv1_client_method()
2018-05-07T12:28:52.331947-07:00 NOTICE tlsdate[2156]: V: opening socket to clients3.google.com:443
2018-05-07T12:28:52.439937-07:00 NOTICE tlsdate[2156]: V: freezing time for x509 verification
2018-05-07T12:28:52.439954-07:00 NOTICE tlsdate[2156]: V: remote peer provided: 1525721332, preferred over compile time: 1525065270
2018-05-07T12:28:52.439963-07:00 NOTICE tlsdate[2156]: V: freezing time with X509_VERIFY_PARAM_set_time
2018-05-07T12:28:52.449359-07:00 NOTICE tlsdate[2156]: V: certificate verification passed
2018-05-07T12:28:52.449374-07:00 NOTICE tlsdate[2156]: V: commonName mismatch! Expected: clients3.google.com - received: *.google.com
2018-05-07T12:28:52.449382-07:00 NOTICE tlsdate[2156]: V: found non subjectAltName extension
2018-05-07T12:28:52.449390-07:00 NOTICE tlsdate[2156]: V: Inspecting 'clients3.google.com' for possible wildcard match against '*.google.com'
2018-05-07T12:28:52.449398-07:00 NOTICE tlsdate[2156]: V: label found; total label count: 1
2018-05-07T12:28:52.449405-07:00 NOTICE tlsdate[2156]: V: label found; total label count: 2
2018-05-07T12:28:52.449413-07:00 NOTICE tlsdate[2156]: V: label found; total label count: 3
2018-05-07T12:28:52.449422-07:00 NOTICE tlsdate[2156]: V: Found wildcard in at start of provided certificate name
2018-05-07T12:28:52.449429-07:00 NOTICE tlsdate[2156]: V: Attempting match of 'clients3' against '*'
2018-05-07T12:28:52.449437-07:00 NOTICE tlsdate[2156]: V: Forced match of 'clients3' against '*'
2018-05-07T12:28:52.449445-07:00 NOTICE tlsdate[2156]: V: Attempting match of 'google' against 'google'
2018-05-07T12:28:52.449455-07:00 NOTICE tlsdate[2156]: V: Attempting match of 'com' against 'com'
2018-05-07T12:28:52.449464-07:00 NOTICE tlsdate[2156]: V: remaining labels match!
2018-05-07T12:28:52.449472-07:00 NOTICE tlsdate[2156]: V: wildcard match of clients3.google.com against *.google.com
2018-05-07T12:28:52.449479-07:00 NOTICE tlsdate[2156]: V: hostname verification passed
2018-05-07T12:28:52.449487-07:00 NOTICE tlsdate[2156]: V: public key is ready for inspection
2018-05-07T12:28:52.449495-07:00 NOTICE tlsdate[2156]: V: key type: EVP_PKEY_RSA
2018-05-07T12:28:52.449502-07:00 NOTICE tlsdate[2156]: V: keybits: 2048
2018-05-07T12:28:52.449517-07:00 NOTICE tlsdate[2156]: V: key length appears safe
2018-05-07T12:28:52.450015-07:00 INFO tlsdated[2155]: [event:handle_child_death] tlsdate reaped => pid:13228 uid:234 status:0 code:1
2018-05-07T12:28:52.000339-07:00 INFO tlsdated[2155]: [event:handle_time_setter] time set from the network (1525721332)
2018-05-07T12:28:52.000603-07:00 NOTICE tlsdate[2156]: V: server time 1525721332 (difference is about 0 s) was fetched in 121 ms
2018-05-07T12:28:52.000615-07:00 NOTICE tlsdate[2156]: [event:handle_child_death] tlsdate reaped => pid:13228 uid:234 status:0 code:1
2018-05-07T12:28:52.000623-07:00 NOTICE tlsdate[2156]: [event:handle_time_setter] time set from the network (1525721332)
2018-05-07T13:03:17.430080-07:00 INFO tlsdated[2155]: [event:handle_set_time]: time is already synchronized.
2018-05-07T13:03:17.430145-07:00 NOTICE tlsdate[2156]: [event:handle_set_time]: time is already synchronized.
2018-05-07T13:04:17.240051-07:00 INFO tlsdated[2155]: [event:handle_set_time]: time is already synchronized.
2018-05-07T13:04:17.240257-07:00 NOTICE tlsdate[2156]: [event:handle_set_time]: time is already synchronized.

Comment 2 by michae...@chromium.org, May 7 2018

Cc: derat@chromium.org
Owner: puthik@chromium.org
Status: Assigned (was: Available)
puthik: Could your change be responsible? https://chromium.googlesource.com/chromiumos/third_party/tlsdate/+/27c3d790346933897a8178227eeca031ce6583f9

Comment 3 by puthik@chromium.org, May 17 2018

Cc: puthik@chromium.org
Owner: michae...@chromium.org
I can't reproduce this behavior. Do you still see this?

Comment 4 by michae...@chromium.org, May 17 2018 

Yes.

What if you set the time manually, then sync?

1. Disable WiFi or other networks
2. Reboot device
3. Set time in chrome://settings
4. Re-enable WiFi
5. Reboot device

The "Set date and time" row in chrome://settings should be gone after the second reboot, so check if it's still there.

Comment 5 by puthik@chromium.org, May 21 2018 

I can repro with #4 instruction.


1. Disable WiFi or other networks
2. Reboot device
3. Set time in chrome://settings
4. Re-enable WiFi
5. Reboot device

Here is what I found

6. "Set date and time" is there
7. open chrome://reboot
8. "Set date and time" is gone

I don't think the problem is from #2 CL.
It looks like Chrome settings page UI caches the result of can_set_date() at boot.
And it will think we can set date because it call that before tlsdate can do network time sync.
►

Sign in to add a comment