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

Issue 612366 link

Starred by 6 users

Issue metadata

Status: Verified
Owner:
Closed: May 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 3
Type: Bug



Sign in to add a comment

Hangouts does hundreds of context switches per second when idle

Project Member Reported by brucedaw...@chromium.org, May 17 2016

Issue description

Power consumption is very important in a world of laptops. One of the most important aspects of power consumption is using as little power as possible when idle - otherwise users who want long battery life are forced to shut down your program when not in use.

The Google Hangouts Extension does 150 to 250 context switches per second when idle. This happens even when Chrome is not running. In an idle scenario the Hangouts Extension process does more context switches than all other Chrome processes combined, and the hangouts process is actually responsible for the majority of the other context switches, by sending regular messages which cause the browser process to wake up.

One of the major causes is this code which asks Windows to wake up the SCTP timer thread 100 times per second:

#define TIMEOUT_INTERVAL 10

void *
user_sctp_timer_iterate(void *arg)
{
	sctp_userspace_set_threadname("SCTP timer");
	for (;;) {
#if defined (__Userspace_os_Windows)
		Sleep(TIMEOUT_INTERVAL);
#else

There are undoubtedly other causes but they will be invisible until this one is addressed.

This behavior continues even after exiting the hangouts extension - the icon disappears from the notification area but the process and its context switches continue. Only by killing the process can these context switches be avoided, at which point the browser process's context switches drop dramatically.

By forcibly killing the Hangouts Extension process the total context switches per second of all chrome.exe processes goes from 260/s to 5.4/s.

 
Components: -Platform>Apps>Hangouts Blink>WebRTC
Would you mind tracing the component that makes these calls. The only potential connection I can find between the Hangouts Extension and user_sctp_timer_iterate is WebRTC, but WebRTC is *not* the Hangouts Extension.
BTW, the best way to see this behavior is using process explorer from sysinternals, available from here:

https://technet.microsoft.com/en-us/sysinternals/processexplorer.aspx

Run it and add the Context Switch Delta column (under Process Performance) to see context switch counts in real time. In an idle scenario the context switches per second should be as low as possible - preferably zero.

The call stack of the repeated SleepEx calls is:

  ntdll.dll!RtlUserThreadStart
  kernel32.dll!BaseThreadInitThunk
  chrome_child.dll!sctp_create_thread_adapter
  chrome_child.dll!user_sctp_timer_iterate
  KernelBase.dll!SleepEx

This thread is started by sctp_start_timer, which is called by sctp_init, which appears to be called by usrsctp_init.

I assigned it to Hangouts just because it was happening in the context of the Hangouts Extension.
Cc: pthatcher@chromium.org tommi@chromium.org jansson@chromium.org
To be clear, is this the extension in question?
https://chrome.google.com/webstore/detail/google-hangouts/nckgahadagoaajjgafhacjanaoiihapd?hl=en-US


Yes, that is the extension.

After installing a new version of Chrome the high-context switch process was identified by Chrome's task manager as being "Subframe: https://google.com", however that seems to be an attribution error since that process went away when I disabled the Hangouts Extension. So, the high context switch rate is 100% reproducible on the two machines I have tested so far.
tommi@ - I'm not sure who should own this issue, so I've added this bug to the agenda of next Monday's triage meeting.
FYI, I just did some measurements using PowerMon (https://github.com/google/UIforETW/tree/master/PowerMon) which uses Intel's power estimation library to estimate how much power the CPU is drawing, sampled every two seconds. The difference after disabling the Hangouts Extension is significant. I think the key number is Process Energy (mWh) which more more than *halves* after closing, and this is 100% reproducible. Note that on Windows 8.1 audiodg.exe raises the timer frequency which complicates the measurement, so your mileage may vary. Power measurement is hard. FWIW:

With the hangouts extension running:
CPU Frequency = 3100 MHz
Processor Power (W) = 33.91
Processor Energy(J) = 68.24
Processor Energy(mWh)=18.96
IA Power (W) = 21.92
IA Energy(J) = 44.12
IA Energy(mWh)=12.26
Package Temp (C) =  46 (max is  90)

Without the hangouts extension running:
CPU Frequency = 3100 MHz
Processor Power (W) = 14.36
Processor Energy(J) = 28.95
Processor Energy(mWh)=8.04
IA Power (W) = 5.34
IA Energy(J) = 10.77
IA Energy(mWh)=2.99
Package Temp (C) =  46 (max is  90)
Labels: Performance-Power

Comment 8 by tommi@chromium.org, May 18 2016

Owner: deadbeef@chromium.org
Status: Assigned (was: Untriaged)
This looks like an unfortunate way to implement a timer. :-(

Taylor - I'm going to look at seeing if we can't use the reference count that's already in sctpdataengine.cc to initialize sctp on demand and uninitialize it when there are no sctp channels outstanding.  I don't know how much time I'll have though, so assigning to you for now.  Can you ping me when you get a chance to look at this?
Cc: lally@chromium.org
lally@: How much do you know about this 10ms SCTP timer? Is there any reason why usrsctp can't just order the events by time, and sleep only until the next event (like most event queues I know of)?

Tommi's idea should work for the idle case (I'll make a CL when I have time). But 200 extra context switches per second during a call isn't free either.
Project Member

Comment 10 by bugdroid1@chromium.org, May 18 2016

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

commit fcfeb8bc42fa37a8875480a0581372c496a303f0
Author: tommi <tommi@chromium.org>
Date: Wed May 18 22:25:35 2016

Remove WebRtc audio source references for local audio tracks.
Remove PeerConnectionDependencyFactory::CreateLocalAudioSource.
Remove audio source mock class that's not needed now.

BUG= 612809 , 612366 

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

[modify] https://crrev.com/fcfeb8bc42fa37a8875480a0581372c496a303f0/content/renderer/media/webrtc/mock_peer_connection_dependency_factory.cc
[modify] https://crrev.com/fcfeb8bc42fa37a8875480a0581372c496a303f0/content/renderer/media/webrtc/mock_peer_connection_dependency_factory.h
[modify] https://crrev.com/fcfeb8bc42fa37a8875480a0581372c496a303f0/content/renderer/media/webrtc/peer_connection_dependency_factory.cc
[modify] https://crrev.com/fcfeb8bc42fa37a8875480a0581372c496a303f0/content/renderer/media/webrtc/peer_connection_dependency_factory.h
[modify] https://crrev.com/fcfeb8bc42fa37a8875480a0581372c496a303f0/content/renderer/media/webrtc/processed_local_audio_source.cc
[modify] https://crrev.com/fcfeb8bc42fa37a8875480a0581372c496a303f0/content/renderer/media/webrtc/processed_local_audio_source.h
[modify] https://crrev.com/fcfeb8bc42fa37a8875480a0581372c496a303f0/content/renderer/media/webrtc/webrtc_media_stream_adapter.cc

Comment 11 by tommi@chromium.org, May 19 2016

The sctp timer function implementation seems to be basically to poll in case timers have been added or removed (and then to run due ones).  Granted, this is a naive implementation.  Since this is an external library though, I think the most important thing we can do now, is to make sure we only keep the library initialized when it's being used.

Comment 12 by tommi@chromium.org, May 19 2016

Bruce - I've checked in a change that removes one case that could trigger initialization of the library (and spinning a couple of more threads).  I don't know for sure if that improves the situation on Windows yet, but there's a chance it does.

Comment 13 by tommi@webrtc.org, May 19 2016

WebRTC cl out for review: https://codereview.webrtc.org/1995993002/
The webrtc branch for 52 has already been made, but there's a chance we could get this into 52 after testing on 53.
M52 would be great. Let me know what I can do to help with testing this in the short term - canary builds of Chrome?

The initial fix sounds like great progress. I hope that in the long term we can get sctp to use a real scheduler, but I imagine that could take quite a while.

Comment 16 by tommi@chromium.org, May 21 2016

Bruce - The second change I made has been rolled into Chrome and is available in Canary now, 53.0.2744.0.  I think this should be fixed now but would be good if you can verify.  I've also started a conversation with engineers that work on the sctp library about fixing this at the root.

Comment 17 by tommi@chromium.org, May 21 2016

Cc: -tommi@chromium.org deadbeef@chromium.org
Owner: tommi@chromium.org
Status: Fixed (was: Assigned)
Status: Verified (was: Fixed)
I verified the fix on Chrome canary - and I've re-enabled the hangouts extension!

Comment 19 by tommi@chromium.org, May 23 2016

Labels: Merge-Request-52
Requesting a merge for the webrtc change to 52.

Comment 20 by tin...@google.com, May 23 2016

Labels: -Merge-Request-52 Merge-Approved-52 Hotlist-Merge-Approved
Your change meets the bar and is auto-approved for M52 (branch: 2743)
Project Member

Comment 21 by bugdroid1@chromium.org, May 23 2016

Labels: merge-merged-52
The following revision refers to this bug:
  https://chromium.googlesource.com/external/webrtc.git/+/f811e290e1cabff400454890542b8ab33cd79dd7

commit f811e290e1cabff400454890542b8ab33cd79dd7
Author: Tommi <tommi@webrtc.org>
Date: Mon May 23 18:33:20 2016

Only initialize usrsctp when it's used and uninitialize when it's not being used.

BUG= chromium:612366 ,  webrtc:5909 
R=deadbeef@webrtc.org

Review URL: https://codereview.webrtc.org/1995993002 .

Cr-Commit-Position: refs/heads/master@{#12816}
(cherry picked from commit 7d01331eca13c620b3e6fa118c022438568f64b1)

Review URL: https://codereview.webrtc.org/2002183002 .

Cr-Commit-Position: refs/branch-heads/52@{#2}
Cr-Branched-From: a376e70cf9d0df3c35d53533b454da542661775b-refs/heads/master@{#12798}

[modify] https://crrev.com/f811e290e1cabff400454890542b8ab33cd79dd7/webrtc/media/sctp/sctpdataengine.cc
[modify] https://crrev.com/f811e290e1cabff400454890542b8ab33cd79dd7/webrtc/media/sctp/sctpdataengine.h
[modify] https://crrev.com/f811e290e1cabff400454890542b8ab33cd79dd7/webrtc/media/sctp/sctpdataengine_unittest.cc

Please merge your change to M52 branch 2743 before 4:00 PM PST tomorrow, Wednesday (05/25).So we can take it for this week last M52 Dev release on Thursday (05/26).Thank you.

Comment 23 by tommi@chromium.org, May 25 2016

My change has already been merged to WebRTC's 52 branch so we should be good to go.
Labels: -Merge-Approved-52
As per comment #23, the change is already merged to M52, hence removing - Merge-Approved-52 label.
Labels: M-52

Sign in to add a comment