Probing: Add support for exponential startup probing

webrtc/modules/pacing/paced_sender.cc

 /*
  *  Copyright (c) 2012 The WebRTC project authors. All Rights Reserved.
  *
  *  Use of this source code is governed by a BSD-style license
  *  that can be found in the LICENSE file in the root of the source
  *  tree. An additional intellectual property rights grant can be found
  *  in the file PATENTS.  All contributing project authors may
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
@@ skipping 14 matching lines @@
 #include "webrtc/system_wrappers/include/field_trial.h"
 
 namespace {
 // Time limit in milliseconds between packet bursts.
 const int64_t kMinPacketLimitMs = 5;
 
 // Upper cap on process interval, in case process has not been called in a long
 // time.
 const int64_t kMaxIntervalTimeMs = 30;
 
+// Maximum waiting time from the time of sending first probe to getting
+// the measured results back.
+const int64_t kMaxTimeWaitingForProbingResultMs = 1000;
+
 }  // namespace
 
 // TODO(sprang): Move at least PacketQueue and MediaBudget out to separate
 // files, so that we can more easily test them.
 
 namespace webrtc {
 namespace paced_sender {
 struct Packet {
   Packet(RtpPacketSender::Priority priority,
          uint32_t ssrc,
@@ skipping 207 matching lines @@
       paused_(false),
       media_budget_(new paced_sender::IntervalBudget(0)),
       padding_budget_(new paced_sender::IntervalBudget(0)),
       prober_(new BitrateProber()),
       estimated_bitrate_bps_(0),
       min_send_bitrate_kbps_(0u),
       max_padding_bitrate_kbps_(0u),
       pacing_bitrate_kbps_(0),
       time_last_update_us_(clock->TimeInMicroseconds()),
       packets_(new paced_sender::PacketQueue(clock)),
-      packet_counter_(0) {
+      packet_counter_(0),
+      pacing_state_(State::kInit) {
   UpdateBytesPerInterval(kMinPacketLimitMs);
 }
 
 PacedSender::~PacedSender() {}
 
 void PacedSender::Pause() {
   LOG(LS_INFO) << "PacedSender paused.";
   CriticalSectionScoped cs(critsect_.get());
   paused_ = true;
 }
 
 void PacedSender::Resume() {
   LOG(LS_INFO) << "PacedSender resumed.";
   CriticalSectionScoped cs(critsect_.get());
   paused_ = false;
 }
 
 void PacedSender::SetProbingEnabled(bool enabled) {
   RTC_CHECK_EQ(0u, packet_counter_);
   CriticalSectionScoped cs(critsect_.get());
   prober_->SetEnabled(enabled);
 }
 
-void PacedSender::SetEstimatedBitrate(uint32_t bitrate_bps) {
+void PacedSender::SetEstimatedBitrate(int bitrate_bps) {
   if (bitrate_bps == 0)
     LOG(LS_ERROR) << "PacedSender is not designed to handle 0 bitrate.";
   CriticalSectionScoped cs(critsect_.get());
   estimated_bitrate_bps_ = bitrate_bps;
   padding_budget_->set_target_rate_kbps(
       std::min(estimated_bitrate_bps_ / 1000, max_padding_bitrate_kbps_));
   pacing_bitrate_kbps_ =
       std::max(min_send_bitrate_kbps_, estimated_bitrate_bps_ / 1000) *
       kDefaultPaceMultiplier;
 }
@@ skipping 14 matching lines @@
                                uint32_t ssrc,
                                uint16_t sequence_number,
                                int64_t capture_time_ms,
                                size_t bytes,
                                bool retransmission) {
   CriticalSectionScoped cs(critsect_.get());
   RTC_DCHECK(estimated_bitrate_bps_ > 0)
         << "SetEstimatedBitrate must be called before InsertPacket.";
 
   int64_t now_ms = clock_->TimeInMilliseconds();
-  prober_->OnIncomingPacket(estimated_bitrate_bps_, bytes, now_ms);
+
+  if (bytes >= PacedSender::kMinProbePacketSize) {
+    switch (pacing_state_) {
+      case State::kInit: {
+        int multipliers[] = {3, 6};
+        if (!prober_->InitiateProbing(estimated_bitrate_bps_, multipliers, 2)) {
+          LOG(LS_ERROR) << "kInit: Failed to initiate probing";
+          pacing_state_ = State::kNormal;
+        } else {
+          LOG(LS_INFO) << "kInit: entering kWaitForProbingResult";
+          pacing_state_ = State::kWaitForProbingResult;
+          start_time_wait_probe_result_ms_ = clock_->TimeInMilliseconds();
+          // When probing at 1.8 Mbps, this represents a threshold of
+          // 1.2 Mbps to continue probing.
+          min_bitrate_to_probe_further_ = 4 * estimated_bitrate_bps_;

[stefan-webrtc, 2016/08/16 11:27:04]

What is different between being here and in kStartupProbing? Here we have a
factor of 4 while in startup we have a factor of 1.25?

[Irfan, 2016/08/16 18:12:47]

The multiplers are 3 and 6 on the very first time (if you recall, we kept this
to avoid slowing down ramp up). so we place a requirement of 4.

Afterwards, the multiplier is 2 and we keep a requirement of 1.25.

+        }
+      } break;
+      case State::kStartupProbing: {
+        int multipliers[] = {2};
+        if (!prober_->InitiateProbing(estimated_bitrate_bps_, multipliers, 1)) {
+          LOG(LS_ERROR) << "kStartupProbing: Failed to initiate probing";
+          pacing_state_ = State::kNormal;
+        } else {
+          LOG(LS_INFO) << "kStartupProbing: entering kWaitForProbingResult";
+          // A minimum of 25% gain to continue.
+          pacing_state_ = State::kWaitForProbingResult;
+          start_time_wait_probe_result_ms_ = clock_->TimeInMilliseconds();
+          min_bitrate_to_probe_further_ = 1.25 * estimated_bitrate_bps_;
+        }
+      } break;
+      case State::kWaitForProbingResult:
+        if ((clock_->TimeInMilliseconds() - start_time_wait_probe_result_ms_) >
+            kMaxTimeWaitingForProbingResultMs) {
+          pacing_state_ = State::kNormal;
+          LOG(LS_INFO) << "kWaitForProbingResult: timeout";
+        }
+        break;
+      case State::kNormal:
+        LOG(LS_INFO) << "Probing complete... kNormal";
+        break;
+      default:
+        RTC_NOTREACHED();
+    }
+  }

[stefan-webrtc, 2016/08/16 11:27:04]

Isn't this adding a lot of complexity to paced_sender.cc when it could as well
be in birtate_prober.cc?

[Irfan, 2016/08/16 18:12:47]

I will evaluate a way to simplify paced_sender and see if it works withm moving
to bitrate_prober.

 
   if (capture_time_ms < 0)
     capture_time_ms = now_ms;
 
   packets_->Push(paced_sender::Packet(priority, ssrc, sequence_number,
                                       capture_time_ms, now_ms, bytes,
                                       retransmission, packet_counter_++));
 }
 
 int64_t PacedSender::ExpectedQueueTimeMs() const {
   CriticalSectionScoped cs(critsect_.get());
-  RTC_DCHECK_GT(pacing_bitrate_kbps_, 0u);
+  RTC_DCHECK_GT(pacing_bitrate_kbps_, 0);
   return static_cast<int64_t>(packets_->SizeInBytes() * 8 /
                               pacing_bitrate_kbps_);
 }
 
 size_t PacedSender::QueueSizePackets() const {
   CriticalSectionScoped cs(critsect_.get());
   return packets_->SizeInPackets();
 }
 
 int64_t PacedSender::QueueInMs() const {
@@ skipping 17 matching lines @@
   if (prober_->IsProbing()) {
     int64_t ret = prober_->TimeUntilNextProbe(clock_->TimeInMilliseconds());
     if (ret >= 0)
       return ret;
   }
   int64_t elapsed_time_us = clock_->TimeInMicroseconds() - time_last_update_us_;
   int64_t elapsed_time_ms = (elapsed_time_us + 500) / 1000;
   return std::max<int64_t>(kMinPacketLimitMs - elapsed_time_ms, 0);
 }
 
+PacedSender::State PacedSender::PacingState() {
+  CriticalSectionScoped(critsect_.get());
+  return pacing_state_;
+}
+
+void PacedSender::OnProbingBitrateMeasured(int bitrate_bps) {
+  CriticalSectionScoped cs(critsect_.get());
+  if (pacing_state_ == State::kWaitForProbingResult) {
+    LOG(LS_INFO) << "kWaitForProbingResult OnProbingBitrateMeasured "
+                 << bitrate_bps << " min_bitrate_to_probe_further_  "
+                 << min_bitrate_to_probe_further_
+                 << " bitrate_below_expected_count_ "
+                 << bitrate_below_expected_count_;
+    if (bitrate_bps > min_bitrate_to_probe_further_) {
+      pacing_state_ = State::kStartupProbing;
+    }
+    if (bitrate_bps > estimated_bitrate_bps_)
+      estimated_bitrate_bps_ = bitrate_bps;

[stefan-webrtc, 2016/08/16 11:27:04]

I'm not sure this is the right way to set this. It will also be set via
PacedSender::SetEstimatedBitrate(int bitrate_bps), and that estimate will
possibly be different as it takes lost packets into account. Can we have a
single way of setting the estimated bitrate to PacedSender?

[Irfan, 2016/08/16 18:12:47]

This is a good point. The reason its happening here now is to sync up on bitrate
the moment pacing state is updated.

I will see if we can get rid of duplicate setting of bitrate.

+  } else {
+    LOG(LS_WARNING) << "OnProbingBitrateMeasured while not waiting on results";

[stefan-webrtc, 2016/08/16 11:27:04]

Should we simply DCHECK on this?

[Irfan, 2016/08/16 18:12:47]

Done.

+  }
+}

[stefan-webrtc, 2016/08/16 11:27:04]

To keep the pacer simpler, I think it would be nice to move this into
bitrate_prober.cc. WDYT?

[Irfan, 2016/08/16 18:12:47]

Right, will evaluate simplifiying pacer

+
 void PacedSender::Process() {
   int64_t now_us = clock_->TimeInMicroseconds();
   CriticalSectionScoped cs(critsect_.get());
   int64_t elapsed_time_ms = (now_us - time_last_update_us_ + 500) / 1000;
   time_last_update_us_ = now_us;
   int target_bitrate_kbps = pacing_bitrate_kbps_;
   // TODO(holmer): Remove the !paused_ check when issue 5307 has been fixed.
   if (!paused_ && elapsed_time_ms > 0) {
     size_t queue_size_bytes = packets_->SizeInBytes();
     if (queue_size_bytes > 0) {
@@ skipping 65 matching lines @@
       return false;
     }
   }
   critsect_->Leave();
   const bool success = packet_sender_->TimeToSendPacket(
       packet.ssrc, packet.sequence_number, packet.capture_time_ms,
       packet.retransmission, probe_cluster_id);
   critsect_->Enter();
 
   if (success) {
-    prober_->PacketSent(clock_->TimeInMilliseconds(), packet.bytes);
+    // Is this a probe ?
+    if (probe_cluster_id != PacketInfo::kNotAProbe) {

[stefan-webrtc, 2016/08/16 11:27:04]

Why only notify about sent probe packets?

[Irfan, 2016/08/16 18:12:47]

I clarified this in an earlier reply. Let me know if I have missed something
here.

+      if (prober_->PacketSent(clock_->TimeInMilliseconds(), packet.bytes) ==
+          BitrateProber::State::kComplete) {
+        LOG(LS_INFO) << "Probe complete";
+      }
+    }
     // TODO(holmer): High priority packets should only be accounted for if we
     // are allocating bandwidth for audio.
     if (packet.priority != kHighPriority) {
       // Update media bytes sent.
       media_budget_->UseBudget(packet.bytes);
       padding_budget_->UseBudget(packet.bytes);
     }
   }
 
   return success;
 }
 
 void PacedSender::SendPadding(size_t padding_needed, int probe_cluster_id) {
   critsect_->Leave();
   size_t bytes_sent =
       packet_sender_->TimeToSendPadding(padding_needed, probe_cluster_id);
   critsect_->Enter();
 
   if (bytes_sent > 0) {
-    prober_->PacketSent(clock_->TimeInMilliseconds(), bytes_sent);
+    // Is this a probe ?
+    if (probe_cluster_id != PacketInfo::kNotAProbe) {
+      if (prober_->PacketSent(clock_->TimeInMilliseconds(), bytes_sent) ==
+          BitrateProber::State::kComplete) {
+        LOG(LS_INFO) << "Probe complete";
+      }
+    }
     media_budget_->UseBudget(bytes_sent);
     padding_budget_->UseBudget(bytes_sent);
   }
 }
 
 void PacedSender::UpdateBytesPerInterval(int64_t delta_time_ms) {
   media_budget_->IncreaseBudget(delta_time_ms);
   padding_budget_->IncreaseBudget(delta_time_ms);
 }
 }  // namespace webrtc