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

Issue 657156 link

Starred by 3 users

Issue metadata

Status: Started
Owner:
Last visit > 30 days ago
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 3
Type: Bug



Sign in to add a comment

Rendering chrome://system takes >30s on Chrome OS

Project Member Reported by yusukes@chromium.org, Oct 18 2016

Issue description

Chrome OS: 8869.0.0 cyan

Steps To Reproduce:
(1) visit chrome://system

Actual Result:

It takes more than 30 seconds to render the page.

 

Comment 1 by derat@chromium.org, Oct 18 2016

Cc: steve...@chromium.org
I added some trivial logging to GetLogsFrom in debugd's src/log_tool.cc file. Here are the strings that it produces, ordered by descending size (second number is size in bytes):

 37 ms  506762  netlog
 46 ms  203312  dmesg
 29 ms  169650  syslog
 18 ms  131048  console-ramoops
109 ms  100565  wifi_status
 17 ms   75235  chrome_system_log
 21 ms   65528  bios_log
 18 ms   56376  verified boot
 55 ms   53853  cheets_log
 63 ms   52302  ps
 19 ms   49136  powerd.LATEST
 19 ms   46857  powerd.PREVIOUS
 19 ms   45123  tlsdate
 25 ms   41612  i915_gem_gtt
 23 ms   36309  update_engine.log
194 ms   31001  network-services
 35 ms   15567  font_info
 14 ms   13913  eventlog
 15 ms   13810  storage_info
 14 ms    6405  bios_info
 17 ms    3728  cpuinfo
291 ms    2991  top
 23 ms    2831  lsmod
 32 ms    2783  ui_log
 20 ms    2461  input_devices
 45 ms    2250  network-devices
 18 ms    2118  ifconfig
 19 ms    2107  touch_fw_version
 18 ms    1234  i915_gem_objects
 16 ms    1042  meminfo
 45 ms     912  power_supply_info
 16 ms     850  memory_spd_info
 19 ms     832  mount-encrypted
 37 ms     581  lspci
113 ms     296  lsusb
 17 ms     224  clobber.log
 16 ms     152  uname
 25 ms     122  i915_error_state
 23 ms     105  ec_info
 15 ms      82  platform_info
 18 ms      76  board-specific
 23 ms      68  CLIENT_ID
 26 ms      59  net-diags.net.log
 18 ms      52  Xorg.0.log
 17 ms      51  touchpad_activity
 17 ms      51  touchpad
 18 ms      45  vpd_2.0
 16 ms      40  cpu
 16 ms      29  LOGDATE
 18 ms      20  hardware_class
 18 ms      13  hw_platform
 20 ms      12  bios_times
 23 ms      10  hostname
 21 ms       7  cros_ec_panicinfo
 20 ms       7  clobber-state.log
 19 ms       7  mali_memory
 19 ms       7  kernel-crashes
 19 ms       7  exynos_gem_objects
 19 ms       7  cros_ec
 18 ms       7  powerwash_count
 18 ms       7  powerd.out
 16 ms       7  nvmap_iovmm
 17 ms       6  zram total memory used
 16 ms       5  zram original data size
 23 ms       4  zram total reads
 17 ms       3  zram compressed data size
 16 ms       2  zram total writes

I'm not very familiar with chrome://system and assume that it's also getting data from other sources. For example, there's a big hack-33025-touchscreen_activity entry on the page that's base64-encoded, but I don't see it referenced in debugd. Presumably it's useless to include in chrome://system and should only be attached to feedback reports.

I'd guess that a good first step would be to use "tail" instead of "cat" on many of the files listed above to limit the amount of text that Chrome needs to render. chrome's CPU is pegged at 100% for most of the time after I load the page, so I assume that that's the particularly-slow part.

Maybe we need to support two sets of data, one for chrome://system and another for feedback reports, if we don't already.
Cc: teravest@chromium.org
Cc: jorgelo@chromium.org
Definitely interested in fixing this. Thanks for adding me. I agree with c#1's sentiment of splitting what goes into chrome:system and what goes into feedback reports.
Cc: khegde@chromium.org
+khegde who might have some time to peek at this.
Current times seem to be ~15sec on Octopus, so I don't know if we're collecting fewer files there.
Here is the approximate breakdown on times (in sequential order):

1. Time taken for chrome to send a request to debugd: < 1 second (I believe that this is the case because chrome is not sending a lot of data to debugd so there is no reason for a high latency)

2. Time taken to collect all attributes and their respective times (in the GetLogsFrom() function inside debugd's src/log_tool.cc file): 4 seconds

3. Time taken for debugd to serialize the data with the attributes and send it to chrome over D-bus: 5 seconds

NOTE: I used the D-bus monitor to find that the total time taken for debugd to collect the attributes (using the GetFromLogs() function) and serialize it is 9 seconds. See below for further info. 

4. Time taken for chrome to deserialize data and display as output: 5 seconds

NOTE: The time for this step is inferred from step 3 above. I believe the serialization and deserialization times would be nearly identical. 



For future use, here is the dubugging process I followed:

1. Add log statements to GetLogsFrom() function to find the total time debugd's src/log_tool.cc takes to collect all the attributes and the time taken by each of them. 

2. On your machine, run: 
dbus-monitor --system > /tmp/dbus_mon

3. Next, run:
grep GetAllLogs dbus-mon 

You should see in the output a line which contains "serial=$SOME_NUMBER". 

4. Use $SOME_NUMBER to run:
grep serial=$SOME_NUMBER dbus-mon

In the output, you should see two lines, each that contain "time=$SOME_TIME" in them. The first line contains details regarding the request made by chrome to GetAllLogs() and the second line contains details regarding the reply back. The time difference represents the total time taken for debugd to collect all the attributes, serialize it, and send it over D-bus to chrome.  

Next Steps:
-Since the marshalling and unmarshalling steps yield high latencies, I believe it may be best to only output a clipped version of extremely large messages. I am currently working on finding out which attributes are the largest, and whether they can be trimmed down. 
Owner: khegde@chromium.org
Status: Started (was: Untriaged)
Components: OS>Performance

Comment 9 Deleted

Sign in to add a comment