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

Issue 888038 link

Starred by 1 user

Issue metadata

Status: Assigned
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux , Windows , Mac
Pri: 2
Type: Bug



Sign in to add a comment

[remoting host] "Probe delay too high" warning is spammy

Project Member Reported by lambroslambrou@chromium.org, Sep 21

Issue description

When connecting via the website, the host logs many lines from bitrate_prober.cc:

[0921/105127.811383:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297730187, now_ms: 1297730191)
[0921/105127.816203:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297730189, now_ms: 1297730195)
[0921/105132.865386:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297735241, now_ms: 1297735245)
[0921/105132.869922:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297735243, now_ms: 1297735249)
[0921/105132.875300:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297735245, now_ms: 1297735254)
[0921/105132.880013:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297735247, now_ms: 1297735259)
[0921/105138.154028:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297740529, now_ms: 1297740533)
[0921/105138.158836:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297740531, now_ms: 1297740538)
[0921/105138.163592:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297740533, now_ms: 1297740543)
[0921/105138.168506:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297740535, now_ms: 1297740548)
[0921/105142.974361:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297745350, now_ms: 1297745354)
[0921/105142.979652:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297745352, now_ms: 1297745359)
[0921/105148.184801:WARNING:bitrate_prober.cc(129)] Probe delay too high (next_ms:1297750560, now_ms: 1297750564)

 
Cc: sergeyu@chromium.org
@Sergey, can we safely remove this warning (change to info or verbose level)?
Or does it indicate an underlying problem that needs fixing?

It's even more spammy with a Firefox client, printing out hundreds of such messages every second.
Labels: -Pri-3 Pri-2
Ping Sergey.
Cc: philipel@chromium.org
Owner: srte@chromium.org
This message was added in https://webrtc-review.googlesource.com/c/src/+/30681 . Description on that CL lacks details - it's not clear what was the motivation behind it.

The problem here is that thread wakes up too late to send next packet for the BW probe, which means that it's likely to provide incorrect results. Previously it would cause the probe to be restarted, which doesn't happen anymore. 
Owner: philipel@chromium.org
I don't think this is important. I think philipel@ knows more about it.
philipel@, can you comment on this? We'd really like to remove this message, or find some way of disabling it for CRD.
When probing timing has to be fairly precise. Before we reset the probe attempt and tried again, but we removed that and instead added this warning to indicate that something interfered with the probe.

I think you should investigate why you even get these warnings.
Owner: lambroslambrou@chromium.org
If you get this message hundreds of time per second then you should really investigate what is going on.

Probing is at most done ~10 times per minute, and a typical probe cluster is 5-10 packets (for higher bitrates it can be more though), so even if there was a timing issue with every packet then you should still only see this message about 50~100 times per minute.
Project Member

Comment 10 by bugdroid1@chromium.org, Oct 25

The following revision refers to this bug:
  https://webrtc.googlesource.com/src.git/+/9c8ae4b9a13cc87429d94181e7dd945dc9ae388b

commit 9c8ae4b9a13cc87429d94181e7dd945dc9ae388b
Author: Jamie Walch <jamiewalch@google.com>
Date: Thu Oct 25 16:00:16 2018

Disable probe delay warning in release builds.

This log is triggering many times a second for Chrome Remote Desktop on some
browsers. This CL just turns it off for release builds to avoid log files
filling up users' disks until we figure out what's going on.

Bug: chromium:888038
Change-Id: Ibbe9d47295b3633314feb28e155e3f59b878dbdb
Reviewed-on: https://webrtc-review.googlesource.com/c/107688
Commit-Queue: Jamie Walch <jamiewalch@google.com>
Reviewed-by: Philip Eliasson <philipel@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#25372}
[modify] https://crrev.com/9c8ae4b9a13cc87429d94181e7dd945dc9ae388b/modules/pacing/bitrate_prober.cc

Project Member

Comment 11 by bugdroid1@chromium.org, Oct 25

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

commit d6003da075b745865943174c7d44a18f05097e32
Author: chromium-autoroll <chromium-autoroll@skia-public.iam.gserviceaccount.com>
Date: Thu Oct 25 23:09:22 2018

Roll src/third_party/webrtc 6c6c9df99db6..8c27ccac7597 (4 commits)

https://webrtc.googlesource.com/src.git/+log/6c6c9df99db6..8c27ccac7597


git log 6c6c9df99db6..8c27ccac7597 --date=short --no-merges --format='%ad %ae %s'
2018-10-25 benwright@webrtc.org Promotoing webrtc::CryptoOptions to RTCConfiguration.
2018-10-25 benwright@webrtc.org Fixes use after free error when setting a new FrameEncryptor on ChannelSend.
2018-10-25 scottmg@chromium.org fuchsia: Stub out timing and memory functions
2018-10-25 jamiewalch@google.com Disable probe delay warning in release builds.


Created with:
  gclient setdep -r src/third_party/webrtc@8c27ccac7597

The AutoRoll server is located here: https://autoroll.skia.org/r/webrtc-chromium-autoroll

Documentation for the AutoRoller is here:
https://skia.googlesource.com/buildbot/+/master/autoroll/README.md

If the roll is causing failures, please contact the current sheriff, who should
be CC'd on the roll, and stop the roller if necessary.

CQ_INCLUDE_TRYBOTS=luci.chromium.try:linux_chromium_archive_rel_ng;luci.chromium.try:mac_chromium_archive_rel_ng

BUG= chromium:808287 ,chromium:888038
TBR=webrtc-chromium-sheriffs-robots@google.com

Change-Id: I6bda4329d38b26019758d06a637ffa44712f12c2
Reviewed-on: https://chromium-review.googlesource.com/c/1299590
Reviewed-by: chromium-autoroll <chromium-autoroll@skia-public.iam.gserviceaccount.com>
Commit-Queue: chromium-autoroll <chromium-autoroll@skia-public.iam.gserviceaccount.com>
Cr-Commit-Position: refs/heads/master@{#602918}
[modify] https://crrev.com/d6003da075b745865943174c7d44a18f05097e32/DEPS

Status: Assigned (was: Untriaged)
This issue has an owner, a component and a priority, but is still listed as untriaged or unconfirmed. By definition, this bug is triaged. Changing status to "assigned". Please reach out to me if you disagree with how I've done this.

Sign in to add a comment