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

Issue 672535 link

Starred by 5 users

Issue metadata

Status: Verified
Owner:
Last visit > 30 days ago
Closed: Dec 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

frecon(515): Chrome failed to take display ownership. Trying again

Reported by abhay.ku...@intel.com, Dec 8 2016

Issue description

UserAgent: Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.99 Safari/537.36
Platform: SKL,BSW<APL

Steps to reproduce the problem:
1. boot the board.
2. I dmesg logs we can see.

Line 675: [ 3.508756] frecon(515): Chrome failed to take display ownership. Trying again.
Line 677: [ 4.009581] frecon(515): Chrome failed to take display ownership. Trying again.
Line 678: [ 4.510638] frecon(515): Chrome failed to take display ownership. Trying again.
Line 682: [ 5.011791] frecon(515): Chrome failed to take display ownership. Trying again.
Line 683: [ 7.530198] frecon(515): Chrome started, splash screen is not needed anymore.
The number of retries is variable. Each retry makes boot time stamp go up which results in boot time delay. boot time of 8 sec depends on this.

What is the expected behavior?
Line 682: [ 5.011791] frecon(515): Chrome failed to take display ownership. Trying again.

This shouldn't happen.

What went wrong?
Line 682: [ 5.011791] frecon(515): Chrome failed to take display ownership. Trying again.

this happened three times which is making boot time stamp longer

Did this work before? N/A 

Does this work in other browsers? Yes

Chrome version: 54.0.2840.99  Channel: n/a
OS Version: 6.3
Flash Version: Shockwave Flash 23.0 r0
 
dmesg_9038_pow_01.txt
58.1 KB View Download
Cc: marc...@chromium.org bleung@chromium.org
Components: -Blink>Media UI
Owner: dbehr@chromium.org
Status: Assigned (was: Unconfirmed)
Dominik, can you help take a look at this one?
Reproduced consistently with
Version 56.0.2924.20 beta (64-bit)
Platform 9000.22.0 (Official Build) beta-channel cyan

However the "failed to take display ownership" line shows only once per boot there.

Comment 4 by dbehr@chromium.org, Dec 8 2016

So frecon prints out a message if it fails to send DBus signal to Chrome.
At that time frecon is in background and not blocking anyone, just waiting for Chrome to start and receive DBus message.
Frecon will retry 5 times sleeping 0.5 second in between. In this dmesg it looks like Chrome received the message on 5th try and later send LoginPromptVisible signal at 7.53.
Are you guys suggesting that printing few dmesg messages is delaying boot?
If you want less of these messages, just make Chrome start faster ;-)

> Are you guys suggesting that printing few dmesg messages is delaying boot?

... only when logging on serial :-)

Thanks Dominik for the very quick analysis. I noticed in /var/log/messages that every frecon log message is at the WARNING level, any clue why?

Comment 6 Deleted

Dominik,

The following autotest command is used for measuring boot performance:
test_that -b <BOARD> <DUT_IP> platform_BootPerf

The above command extracts the time stamp of the "boot-complete" event and reports it as the kernel to login time. The "boot-complete" event time stamp can also be retrieved by running "bootstat_summary" from the command prompt of the DUT. 

"boot-complete" event is emitted when the "/etc/init/boot-complete.conf" is executed. 

The relevant line from "/etc/init/boot-complete.conf" is as follows:

start on login-prompt-visible

Unless the "login-prompt-visible" event is emitted, "boot-complete" event wont be emitted. "login-prompt-visible" in turn depends on "LoginPromptVisible" being sent.

Thus, "LoginPromptVisible" directly affects the "boot-complete" event. And not getting display ownership in less number of tries is affecting the boot performance. Even though frecon is in background not blocking anyone,  "LoginPromptVisible" is in critical path for measurement of kernel to login time which in turn affects the overall boot performance.

Also, in this discussion "LoginPromptVisible" is happening at 7.53 and boot-complete event fires around 7.64.
@7: you have the issue backwards. Frecon isn't blocking boot, frecon is waiting for chrome to be ready. Chrome isn't ready at that point, so even if frecon wasn't around, Chrome wouldn't be able to display the login prompt.

Basically you are complaining that boot is slow on your device, and blaming it on frecon.
@7 As far as frecon is late issue. Can we comment any other device like touch track,i2c,usb anyone of them and if then we get rid of below
Frecon msg then it will prove what Dominik stating  is right.

Comment 10 by dbehr@chromium.org, Dec 13 2016

Frecon does not send login-prompt-visible DBUS signal. Chrome sends it. 
Frecon just peeks this message so it can free some resources.
The real recipient of this message is session_manager. Session_manager will in turn send login-prompt-visible to upstart and it will be used from there by bootperf.

So for login prompt visible the path is Chrome -> session_manager -> upstart -> bootperf

Frecon does peek this meessage on dbus between Chrome and session_manager but it is not delaying it or anything like that.

If you want this message to show up sooner, you have to make Chrome boot faster.
Project Member

Comment 11 by bugdroid1@chromium.org, Dec 13 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform/frecon/+/3384733aad1c73c50a760c0c52e3851aa8fff455

commit 3384733aad1c73c50a760c0c52e3851aa8fff455
Author: Dominik Behr <dbehr@chromium.org>
Date: Tue Dec 13 01:27:56 2016

frecon: do not retry DBUS message to Chrome at startup

Also, do not sleep on the last retry, because it is pointless.

BUG= chromium:672535 
TEST=boot Chrome OS and observe no error messages in dmesg anymore.

Change-Id: I093d3b975aaf1d98c06ca8a59da8f01dac5a34bc
Signed-off-by: Dominik Behr <dbehr@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/419177
Reviewed-by: Stéphane Marchesin <marcheu@chromium.org>

[modify] https://crrev.com/3384733aad1c73c50a760c0c52e3851aa8fff455/term.c
[modify] https://crrev.com/3384733aad1c73c50a760c0c52e3851aa8fff455/term.h
[modify] https://crrev.com/3384733aad1c73c50a760c0c52e3851aa8fff455/main.c

Comment 12 by dbehr@chromium.org, Dec 13 2016

Status: Fixed (was: Assigned)

Comment 13 by dchan@google.com, Mar 4 2017

Labels: VerifyIn-58
Status: Verified (was: Fixed)
Verified with repro steps in bug description. Did not see any "Chrome failed to take display ownership. Trying again." messages.

9334.23.0 / 58.0.3029.39

Sign in to add a comment