Incorporating logging into Cast

Incorporating logging into Cast: 
1. Adding logging to CastEnvironment.
2. Actually triggering logging within the cast library.
3. Adding thread checks.
4. Removing trace calls outside of the logging class.

Open issues: 
1.Use of rtp_timestamp and frame id is not consistent.
In addition, the AudioBus does not include these values.
2. There is a pending cl to switch frame_id to int. This cl does not include that.
3. There are a few more places to add logging.

As this cl is already big enough, all of the above will come in a follow-up cl.

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=236034

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=236118

[mikhal, 2013-11-12 18:12:34]

Please review,
-Mikhal

[Alpha Left Google, 2013-11-14 00:29:24]

Some minor suggestions.

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_environm...
File media/cast/cast_environment.cc (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_environm...
media/cast/cast_environment.cc:30: logging_(new LoggingImpl(clock,
main_thread_proxy,
Use a separate method to start logging instead of doing it in the constructor.

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_environm...
media/cast/cast_environment.cc:98: return logging_.get();
Check that this accessor is called on the right thread. Or will caller of this
method post task to the main thread to access the LoggingImpl object?

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_environm...
File media/cast/cast_environment.h (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_environm...
media/cast/cast_environment.h:43: bool enable_data_collection,
These shouldn't be boolean but method to enable additional logging. It is not
critical to provide these parameters to construct CastEnvironment.

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_environm...
media/cast/cast_environment.h:65: LoggingImpl* const Logging();
LoggingImpl is not thread safe. Can you add a comment here on which thread this
can be called?

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_sender_i...
File media/cast/cast_sender_impl.cc (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_sender_i...
media/cast/cast_sender_impl.cc:38: GetVideoRtpTimestamp(capture_time), -1);
Add a TODO here to replace -1 with something meaningful.

https://codereview.chromium.org/69603002/diff/200001/media/cast/cast_sender_i...
media/cast/cast_sender_impl.cc:57: GetVideoRtpTimestamp(recorded_time), -1);
Add a TODO here to replace -1 with something meaningful.

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtcp/rtcp.cc
File media/cast/rtcp/rtcp.cc (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtcp/rtcp.cc#...
media/cast/rtcp/rtcp.cc:114: clock_(cast_environment->Clock()),
You're removing clock from the constructor parameter anyway, might as well
remove |clock_| entirely.

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtcp/rtcp.cc#...
media/cast/rtcp/rtcp.cc:263:
cast_environment_->Logging()->InsertGenericEvent(kJitterMs,
nit: indent by 2 spaces.

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtcp/rtcp.cc#...
media/cast/rtcp/rtcp.cc:265:
cast_environment_->Logging()->InsertGenericEvent(kPacketLoss,
nit: indent by 2 spaces.

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtcp/rtcp.h
File media/cast/rtcp/rtcp.h (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtcp/rtcp.h#n...
media/cast/rtcp/rtcp.h:118: base::TickClock* const clock_;  // Not owned by this
class.
While you're at it please remove this member. The code can access the clock
through cast_environment_ anyway. There's just a handful of call sites.

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtp_sender/rt...
File media/cast/rtp_sender/rtp_sender.cc (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/rtp_sender/rt...
media/cast/rtp_sender/rtp_sender.cc:21: : clock_(cast_environment->Clock()),
This is not used anywhere in this file. Please remove it.

https://codereview.chromium.org/69603002/diff/200001/media/cast/video_receive...
File media/cast/video_receiver/codecs/vp8/vp8_decoder.cc (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/video_receive...
media/cast/video_receiver/codecs/vp8/vp8_decoder.cc:87: -1,
encoded_frame->frame_id);
Add a TODO here to replace -1 with something meaningful.

https://codereview.chromium.org/69603002/diff/200001/media/cast/video_sender/...
File media/cast/video_sender/video_encoder.cc (right):

https://codereview.chromium.org/69603002/diff/200001/media/cast/video_sender/...
media/cast/video_sender/video_encoder.cc:71: -1, rtp_timestamp);
Add a TODO here to replace -1 with something meaningful.

https://codereview.chromium.org/69603002/diff/200001/media/cast/video_sender/...
media/cast/video_sender/video_encoder.cc:88: rtp_timestamp, -1);
Add a TODO here to replace -1 with something meaningful.

[mikhal, 2013-11-14 17:42:30]

PTAL

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_e...
File media/cast/cast_environment.cc (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_e...
media/cast/cast_environment.cc:30: logging_(new LoggingImpl(clock,
main_thread_proxy,
Don't see why.
On 2013/11/14 00:29:24, Alpha wrote:
> Use a separate method to start logging instead of doing it in the constructor.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_e...
media/cast/cast_environment.cc:98: return logging_.get();
Added a dcheck
On 2013/11/14 00:29:24, Alpha wrote:
> Check that this accessor is called on the right thread. Or will caller of this
> method post task to the main thread to access the LoggingImpl object?

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_e...
File media/cast/cast_environment.h (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_e...
media/cast/cast_environment.h:43: bool enable_data_collection,
As a design choice, throughout cast we set all parameters in construction time,
and not via setters. Would like to be consistent.
On 2013/11/14 00:29:24, Alpha wrote:
> These shouldn't be boolean but method to enable additional logging. It is not
> critical to provide these parameters to construct CastEnvironment.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_e...
media/cast/cast_environment.h:65: LoggingImpl* const Logging();
On 2013/11/14 00:29:24, Alpha wrote:
> LoggingImpl is not thread safe. Can you add a comment here on which thread
this
> can be called?

Done.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_s...
File media/cast/cast_sender_impl.cc (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_s...
media/cast/cast_sender_impl.cc:38: GetVideoRtpTimestamp(capture_time), -1);
Added a const value for his. The -1 will be a valid entry once the frame_id are
represented in ints (pwestin pending cl).
On 2013/11/14 00:29:24, Alpha wrote:
> Add a TODO here to replace -1 with something meaningful.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_s...
media/cast/cast_sender_impl.cc:57: GetVideoRtpTimestamp(recorded_time), -1);
Same as above
On 2013/11/14 00:29:24, Alpha wrote:
> Add a TODO here to replace -1 with something meaningful.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtcp/r...
File media/cast/rtcp/rtcp.cc (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtcp/r...
media/cast/rtcp/rtcp.cc:114: clock_(cast_environment->Clock()),
removed
On 2013/11/14 00:29:24, Alpha wrote:
> You're removing clock from the constructor parameter anyway, might as well
> remove |clock_| entirely.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtcp/r...
media/cast/rtcp/rtcp.cc:263:
cast_environment_->Logging()->InsertGenericEvent(kJitterMs,
On 2013/11/14 00:29:24, Alpha wrote:
> nit: indent by 2 spaces.

Done.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtcp/r...
media/cast/rtcp/rtcp.cc:265:
cast_environment_->Logging()->InsertGenericEvent(kPacketLoss,
On 2013/11/14 00:29:24, Alpha wrote:
> nit: indent by 2 spaces.

Done.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtcp/r...
File media/cast/rtcp/rtcp.h (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtcp/r...
media/cast/rtcp/rtcp.h:118: base::TickClock* const clock_;  // Not owned by this
class.
On 2013/11/14 00:29:24, Alpha wrote:
> While you're at it please remove this member. The code can access the clock
> through cast_environment_ anyway. There's just a handful of call sites.

Done.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtp_se...
File media/cast/rtp_sender/rtp_sender.cc (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/rtp_se...
media/cast/rtp_sender/rtp_sender.cc:21: : clock_(cast_environment->Clock()),
On 2013/11/14 00:29:24, Alpha wrote:
> This is not used anywhere in this file. Please remove it.

Done.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/video_...
File media/cast/video_receiver/codecs/vp8/vp8_decoder.cc (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/video_...
media/cast/video_receiver/codecs/vp8/vp8_decoder.cc:87: -1,
encoded_frame->frame_id);
On 2013/11/14 00:29:24, Alpha wrote:
> Add a TODO here to replace -1 with something meaningful.

Done.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/video_...
File media/cast/video_sender/video_encoder.cc (right):

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/video_...
media/cast/video_sender/video_encoder.cc:71: -1, rtp_timestamp);
Replaced with const, as in other locations.
On 2013/11/14 00:29:24, Alpha wrote:
> Add a TODO here to replace -1 with something meaningful.

https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/video_...
media/cast/video_sender/video_encoder.cc:88: rtp_timestamp, -1);
see above
On 2013/11/14 00:29:24, Alpha wrote:
> Add a TODO here to replace -1 with something meaningful.

[Alpha Left Google, 2013-11-14 19:54:41]

>
https://chromiumcodereview.appspot.com/69603002/diff/200001/media/cast/cast_e...
> media/cast/cast_environment.cc:30: logging_(new LoggingImpl(clock,
> main_thread_proxy,
> Don't see why.

This patch overall looks good. However I still don't like the idea of putting a
bunch of logging options to the constructor. The reason is they are not critical
to CastSender. The usage in this CL is mostly just 3 false values which meant
they are just optional. I think having them as EnableLogging() makes a cleaner
API.

[Alpha Left Google, 2013-11-14 19:54:56]

https://codereview.chromium.org/69603002/diff/370002/media/cast/rtp_sender/rt...
File media/cast/rtp_sender/rtp_packetizer/rtp_packetizer.cc (right):

https://codereview.chromium.org/69603002/diff/370002/media/cast/rtp_sender/rt...
media/cast/rtp_sender/rtp_packetizer/rtp_packetizer.cc:82: std::vector<uint8>
data) {
I just noticed that this code does a copy of |data|. And all it does internally
is use it with an iterator. This should be fixed to just take a const ref.
Please add a TODO.

[mikhal, 2013-11-14 20:13:22]

PTAL

[mikhal, 2013-11-15 00:41:22]

PTAL

[Alpha Left Google, 2013-11-15 00:51:57]

On 2013/11/15 00:41:22, mikhal wrote:
> PTAL

Okay. LGTM.

[commit-bot: I haz the power, 2013-11-15 04:12:01]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/960001

[commit-bot: I haz the power, 2013-11-15 05:33:44]

Retried try job too often on chromium_presubmit for step(s) presubmit
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=chromium_p...

[mikhal, 2013-11-15 15:53:20]

+scherkus for cast_message_delegate update.

[scherkus (not reviewing), 2013-11-15 21:20:13]

lgtm

[commit-bot: I haz the power, 2013-11-15 22:55:16]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/1190002

[commit-bot: I haz the power, 2013-11-15 22:55:31]

Failed to apply patch for media/cast/logging/logging_impl.cc:
While running patch -p1 --forward --force --no-backup-if-mismatch;
  patching file media/cast/logging/logging_impl.cc
  Hunk #2 FAILED at 22.
  Hunk #3 succeeded at 38 with fuzz 2.
  Hunk #4 succeeded at 59 with fuzz 2.
  Hunk #5 succeeded at 80 with fuzz 1.
  1 out of 10 hunks FAILED -- saving rejects to file
media/cast/logging/logging_impl.cc.rej

Patch:       media/cast/logging/logging_impl.cc
Index: media/cast/logging/logging_impl.cc
diff --git a/media/cast/logging/logging_impl.cc
b/media/cast/logging/logging_impl.cc
index
7f91df273759417c021477a01262139828f233cd..66066b6cc219e1f776a913a304851f42151bfc29
100644
--- a/media/cast/logging/logging_impl.cc
+++ b/media/cast/logging/logging_impl.cc
@@ -10,12 +10,10 @@ namespace media {
 namespace cast {
 
 LoggingImpl::LoggingImpl(base::TickClock* clock,
-                         bool enable_data_collection,
-                         bool enable_uma_stats,
-                         bool enable_tracing)
-    : enable_data_collection_(enable_data_collection),
-      enable_uma_stats_(enable_uma_stats),
-      enable_tracing_(enable_tracing),
+                         scoped_refptr<base::TaskRunner> main_thread_proxy,
+                         const CastLoggingConfig& config)
+    : main_thread_proxy_(main_thread_proxy),
+      config_(config),
       raw_(clock),
       stats_(clock) {}
 
@@ -24,11 +22,12 @@ LoggingImpl::~LoggingImpl() {}
 void LoggingImpl::InsertFrameEvent(CastLoggingEvent event,
                                    uint32 rtp_timestamp,
                                    uint8 frame_id) {
-  if (enable_data_collection_) {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
+  if (config_.enable_data_collection) {
     raw_.InsertFrameEvent(event, rtp_timestamp, frame_id);
     stats_.InsertFrameEvent(event, rtp_timestamp, frame_id);
   }
-  if (enable_tracing_) {
+  if (config_.enable_tracing) {
     std::string event_string = CastLoggingToString(event);
     TRACE_EVENT_INSTANT2(event_string.c_str(), "FE",
         TRACE_EVENT_SCOPE_THREAD, "rtp_timestamp", rtp_timestamp, "frame_id",
@@ -40,14 +39,15 @@ void LoggingImpl::InsertFrameEventWithSize(CastLoggingEvent
event,
                                            uint32 rtp_timestamp,
                                            uint8 frame_id,
                                            int frame_size) {
-  if (enable_data_collection_) {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
+  if (config_.enable_data_collection) {
     raw_.InsertFrameEventWithSize(event, rtp_timestamp, frame_id, frame_size);
     stats_.InsertFrameEventWithSize(event, rtp_timestamp, frame_id,
frame_size);
   }
-  if (enable_uma_stats_) {
+  if (config_.enable_uma_stats) {
     UMA_HISTOGRAM_COUNTS(CastLoggingToString(event), frame_size);
   }
-  if (enable_tracing_) {
+  if (config_.enable_tracing) {
     std::string event_string = CastLoggingToString(event);
     TRACE_EVENT_INSTANT2(event_string.c_str(), "FES",
         TRACE_EVENT_SCOPE_THREAD, "rtp_timestamp", rtp_timestamp, "frame_size",
@@ -60,14 +60,15 @@ void LoggingImpl::InsertFrameEventWithDelay(CastLoggingEvent
event,
                                             uint32 rtp_timestamp,
                                             uint8 frame_id,
                                             base::TimeDelta delay) {
-  if (enable_data_collection_) {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
+  if (config_.enable_data_collection) {
     raw_.InsertFrameEventWithDelay(event, rtp_timestamp, frame_id, delay);
     stats_.InsertFrameEventWithDelay(event, rtp_timestamp, frame_id, delay);
   }
-  if (enable_uma_stats_) {
+  if (config_.enable_uma_stats) {
     UMA_HISTOGRAM_TIMES(CastLoggingToString(event), delay);
   }
-   if (enable_tracing_) {
+   if (config_.enable_tracing) {
       std::string event_string = CastLoggingToString(event);
       TRACE_EVENT_INSTANT2(event_string.c_str(), "FED",
           TRACE_EVENT_SCOPE_THREAD, "rtp_timestamp", rtp_timestamp, "delay",
@@ -80,14 +81,15 @@ void LoggingImpl::InsertPacketEvent(CastLoggingEvent event,
                                     uint8 frame_id,
                                     uint16 packet_id,
                                     uint16 max_packet_id,
-                                    int size) {
-  if (enable_data_collection_) {
+                                    size_t size) {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
+  if (config_.enable_data_collection) {
     raw_.InsertPacketEvent(event, rtp_timestamp, frame_id, packet_id,
                            max_packet_id, size);
     stats_.InsertPacketEvent(event, rtp_timestamp, frame_id, packet_id,
                              max_packet_id, size);
   }
-    if (enable_tracing_) {
+    if (config_.enable_tracing) {
       std::string event_string = CastLoggingToString(event);
       TRACE_EVENT_INSTANT2(event_string.c_str(), "PE",
           TRACE_EVENT_SCOPE_THREAD, "rtp_timestamp", rtp_timestamp,
@@ -96,14 +98,15 @@ void LoggingImpl::InsertPacketEvent(CastLoggingEvent event,
 }
 
 void LoggingImpl::InsertGenericEvent(CastLoggingEvent event, int value) {
-  if (enable_data_collection_) {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
+  if (config_.enable_data_collection) {
     raw_.InsertGenericEvent(event, value);
     stats_.InsertGenericEvent(event, value);
   }
-  if (enable_uma_stats_) {
+  if (config_.enable_uma_stats) {
     UMA_HISTOGRAM_COUNTS(CastLoggingToString(event), value);
   }
-  if (enable_tracing_) {
+  if (config_.enable_tracing) {
     std::string event_string = CastLoggingToString(event);
     TRACE_EVENT_INSTANT1(event_string.c_str(), "GE",
         TRACE_EVENT_SCOPE_THREAD, "value", value);
@@ -113,21 +116,25 @@ void LoggingImpl::InsertGenericEvent(CastLoggingEvent
event, int value) {
 
 // should just get the entire class, would be much easier.
 FrameRawMap LoggingImpl::GetFrameRawData() {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
   return raw_.GetFrameData();
 }
 
 PacketRawMap LoggingImpl::GetPacketRawData() {
- return raw_.GetPacketData();
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
+  return raw_.GetPacketData();
 }
 
 GenericRawMap LoggingImpl::GetGenericRawData() {
- return raw_.GetGenericData();
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
+  return raw_.GetGenericData();
 }
 
 const FrameStatsMap* LoggingImpl::GetFrameStatsData() {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
   // Get stats data.
   const FrameStatsMap* stats = stats_.GetFrameStatsData();
-  if (enable_uma_stats_) {
+  if (config_.enable_uma_stats) {
     FrameStatsMap::const_iterator it;
     for (it = stats->begin(); it != stats->end(); ++it) {
       // Check for an active event.
@@ -159,9 +166,10 @@ const FrameStatsMap* LoggingImpl::GetFrameStatsData() {
 }
 
 const PacketStatsMap* LoggingImpl::GetPacketStatsData() {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
   // Get stats data.
   const PacketStatsMap* stats = stats_.GetPacketStatsData();
-  if (enable_uma_stats_) {
+  if (config_.enable_uma_stats) {
     PacketStatsMap::const_iterator it;
     for (it = stats->begin(); it != stats->end(); ++it) {
       if (it->second > 0) {
@@ -174,9 +182,10 @@ const PacketStatsMap* LoggingImpl::GetPacketStatsData() {
 }
 
 const GenericStatsMap* LoggingImpl::GetGenericStatsData() {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
   // Get stats data.
   const GenericStatsMap* stats = stats_.GetGenericStatsData();
-   if (enable_uma_stats_) {
+   if (config_.enable_uma_stats) {
     GenericStatsMap::const_iterator it;
     for (it = stats->begin(); it != stats->end(); ++it) {
       if (it->second > 0) {
@@ -188,6 +197,7 @@ const GenericStatsMap* LoggingImpl::GetGenericStatsData() {
 }
 
 void LoggingImpl::Reset() {
+  DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread());
   raw_.Reset();
   stats_.Reset();
 }

[commit-bot: I haz the power, 2013-11-15 23:24:21]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/1370002

[commit-bot: I haz the power, 2013-11-16 00:48:18]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/1370002

[commit-bot: I haz the power, 2013-11-16 02:57:19]

Retried try job too often on win_x64_rel for step(s) base_unittests
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win_x64_re...

[commit-bot: I haz the power, 2013-11-16 17:42:07]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/1370002

[commit-bot: I haz the power, 2013-11-16 17:42:29]

Failed to apply patch for media/cast/rtcp/rtcp.cc:
While running patch -p1 --forward --force --no-backup-if-mismatch;
  patching file media/cast/rtcp/rtcp.cc
  Hunk #3 FAILED at 102.
  Hunk #4 succeeded at 109 (offset -1 lines).
  Hunk #5 succeeded at 164 (offset -1 lines).
  Hunk #6 succeeded at 175 (offset -1 lines).
  Hunk #7 succeeded at 198 (offset -1 lines).
  Hunk #8 succeeded at 256 (offset -3 lines).
  Hunk #9 succeeded at 295 (offset -5 lines).
  Hunk #10 succeeded at 308 (offset -5 lines).
  Hunk #11 FAILED at 356.
  Hunk #12 succeeded at 399 (offset 23 lines).
  Hunk #13 succeeded at 410 (offset 23 lines).
  Hunk #14 succeeded at 443 (offset 23 lines).
  2 out of 14 hunks FAILED -- saving rejects to file media/cast/rtcp/rtcp.cc.rej

Patch:       media/cast/rtcp/rtcp.cc
Index: media/cast/rtcp/rtcp.cc
diff --git a/media/cast/rtcp/rtcp.cc b/media/cast/rtcp/rtcp.cc
index
a1720ffe1a2e433c9026d21c6482df8e79e6bb86..263a65ced258b65a2d8fda7369960eca7e9a4b27
100644
--- a/media/cast/rtcp/rtcp.cc
+++ b/media/cast/rtcp/rtcp.cc
@@ -4,10 +4,10 @@
 
 #include "media/cast/rtcp/rtcp.h"
 
-#include "base/debug/trace_event.h"
 #include "base/rand_util.h"
 #include "media/cast/cast_config.h"
 #include "media/cast/cast_defines.h"
+#include "media/cast/cast_environment.h"
 #include "media/cast/rtcp/rtcp_defines.h"
 #include "media/cast/rtcp/rtcp_receiver.h"
 #include "media/cast/rtcp/rtcp_sender.h"
@@ -84,7 +84,7 @@ class LocalRtcpReceiverFeedback : public RtcpReceiverFeedback
{
   Rtcp* rtcp_;
 };
 
-Rtcp::Rtcp(base::TickClock* clock,
+Rtcp::Rtcp(scoped_refptr<CastEnvironment> cast_environment,
            RtcpSenderFeedback* sender_feedback,
            PacedPacketSender* paced_packet_sender,
            RtpSenderStatistics* rtp_sender_statistics,
@@ -102,7 +102,8 @@ Rtcp::Rtcp(base::TickClock* clock,
       rtp_receiver_statistics_(rtp_receiver_statistics),
       receiver_feedback_(new LocalRtcpReceiverFeedback(this)),
       rtt_feedback_(new LocalRtcpRttFeedback(this)),
-      rtcp_sender_(new RtcpSender(paced_packet_sender, local_ssrc, c_name)),
+      rtcp_sender_(new RtcpSender(cast_environment, paced_packet_sender,
+                                  local_ssrc, c_name)),
       last_report_sent_(0),
       last_report_received_(0),
       last_received_rtp_timestamp_(0),
@@ -110,8 +111,9 @@ Rtcp::Rtcp(base::TickClock* clock,
       last_received_ntp_fraction_(0),
       min_rtt_(base::TimeDelta::FromMilliseconds(kMaxRttMs)),
       number_of_rtt_in_avg_(0),
-      clock_(clock) {
-  rtcp_receiver_.reset(new RtcpReceiver(sender_feedback,
+      cast_environment_(cast_environment) {
+  rtcp_receiver_.reset(new RtcpReceiver(cast_environment,
+                                        sender_feedback,
                                         receiver_feedback_.get(),
                                         rtt_feedback_.get(),
                                         local_ssrc));
@@ -164,7 +166,7 @@ void Rtcp::IncomingRtcpPacket(const uint8* rtcp_buffer,
size_t length) {
 
 void Rtcp::SendRtcpCast(const RtcpCastMessage& cast_message) {
   uint32 packet_type_flags = 0;
-  base::TimeTicks now = clock_->NowTicks();
+  base::TimeTicks now = cast_environment_->Clock()->NowTicks();
 
   if (rtcp_mode_ == kRtcpCompound || now >= next_time_to_send_rtcp_) {
     if (sending_media_) {
@@ -175,12 +177,15 @@ void Rtcp::SendRtcpCast(const RtcpCastMessage&
cast_message) {
   }
   packet_type_flags |= RtcpSender::kRtcpCast;
 
+  cast_environment_->Logging()->InsertGenericEvent(kAckSent,
+                                                   cast_message.ack_frame_id_);
+
   SendRtcp(now, packet_type_flags, 0, &cast_message);
 }
 
 void Rtcp::SendRtcpPli(uint32 pli_remote_ssrc) {
   uint32 packet_type_flags = 0;
-  base::TimeTicks now = clock_->NowTicks();
+  base::TimeTicks now = cast_environment_->Clock()->NowTicks();
 
   if (rtcp_mode_ == kRtcpCompound || now >= next_time_to_send_rtcp_) {
     if (sending_media_) {
@@ -195,7 +200,7 @@ void Rtcp::SendRtcpPli(uint32 pli_remote_ssrc) {
 
 void Rtcp::SendRtcpReport(uint32 media_ssrc) {
   uint32 packet_type_flags;
-  base::TimeTicks now = clock_->NowTicks();
+  base::TimeTicks now = cast_environment_->Clock()->NowTicks();
   if (sending_media_) {
     packet_type_flags = RtcpSender::kRtcpSr;
   } else {
@@ -255,6 +260,11 @@ void Rtcp::SendRtcp(const base::TimeTicks& now,
           &report_block.cumulative_lost,
           &report_block.extended_high_sequence_number,
           &report_block.jitter);
+      cast_environment_->Logging()->InsertGenericEvent(kJitterMs,
+          report_block.jitter);
+      cast_environment_->Logging()->InsertGenericEvent(kPacketLoss,
+          report_block.fraction_lost);
+
     }
 
     report_block.last_sr = last_report_received_;
@@ -291,7 +301,7 @@ void Rtcp::SendRtcp(const base::TimeTicks& now,
 void Rtcp::OnReceivedNtp(uint32 ntp_seconds, uint32 ntp_fraction) {
   last_report_received_ = (ntp_seconds << 16) + (ntp_fraction >> 16);
 
-  base::TimeTicks now = clock_->NowTicks();
+  base::TimeTicks now = cast_environment_->Clock()->NowTicks();
   time_last_report_received_ = now;
 }
 
@@ -304,7 +314,7 @@ void Rtcp::OnReceivedLipSyncInfo(uint32 rtp_timestamp,
 }
 
 void Rtcp::OnReceivedSendReportRequest() {
-  base::TimeTicks now = clock_->NowTicks();
+  base::TimeTicks now = cast_environment_->Clock()->NowTicks();
 
   // Trigger a new RTCP report at next timer.
   next_time_to_send_rtcp_ = now;
@@ -347,7 +357,8 @@ void Rtcp::OnReceivedDelaySinceLastReport(uint32
receivers_ssrc,
   if (last_report_sent_ != last_report)  return;  // Feedback on another
report.
   if (time_last_report_sent_.is_null())  return;
 
-  base::TimeDelta sender_delay = clock_->NowTicks() - time_last_report_sent_;
+  base::TimeDelta sender_delay = cast_environment_->Clock()->NowTicks()
+      - time_last_report_sent_;
   UpdateRtt(sender_delay, ConvertFromNtpDiff(delay_since_last_report));
 }
 
@@ -367,7 +378,6 @@ void Rtcp::UpdateRtt(const base::TimeDelta& sender_delay,
     avg_rtt_ms_ = rtt.InMilliseconds();
   }
   number_of_rtt_in_avg_++;
-  TRACE_COUNTER_ID1("cast_rtcp", "RTT", local_ssrc_, rtt.InMilliseconds());
 }
 
 bool Rtcp::Rtt(base::TimeDelta* rtt,
@@ -379,7 +389,9 @@ bool Rtcp::Rtt(base::TimeDelta* rtt,
   DCHECK(min_rtt) << "Invalid argument";
   DCHECK(max_rtt) << "Invalid argument";
 
-  if (number_of_rtt_in_avg_ == 0)  return false;
+  if (number_of_rtt_in_avg_ == 0) return false;
+  cast_environment_->Logging()->InsertGenericEvent(kRttMs,
+                                                   rtt->InMilliseconds());
 
   *rtt = rtt_;
   *avg_rtt = base::TimeDelta::FromMilliseconds(avg_rtt_ms_);
@@ -410,7 +422,7 @@ void Rtcp::UpdateNextTimeToSendRtcp() {
   base::TimeDelta time_to_next = (rtcp_interval_ / 2) +
       (rtcp_interval_ * random / 1000);
 
-  base::TimeTicks now = clock_->NowTicks();
+  base::TimeTicks now = cast_environment_->Clock()->NowTicks();
   next_time_to_send_rtcp_ = now + time_to_next;
 }

[commit-bot: I haz the power, 2013-11-18 17:14:40]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/2000001

[commit-bot: I haz the power, 2013-11-18 18:08:51]

Retried try job too often on android_dbg for step(s) slave_steps
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=android_db...

[commit-bot: I haz the power, 2013-11-18 19:36:11]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/2240001

[commit-bot: I haz the power, 2013-11-18 21:52:43]

Retried try job too often on win_rel for step(s) base_unittests, browser_tests,
interactive_ui_tests, net_unittests, sync_integration_tests, unit_tests
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win_rel&nu...

[commit-bot: I haz the power, 2013-11-18 23:19:36]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/2240001

[commit-bot: I haz the power, 2013-11-18 23:19:55]

Failed to apply patch for media/cast/audio_sender/audio_sender.cc:
While running patch -p1 --forward --force --no-backup-if-mismatch;
  patching file media/cast/audio_sender/audio_sender.cc
  Hunk #2 FAILED at 56.
  1 out of 2 hunks FAILED -- saving rejects to file
media/cast/audio_sender/audio_sender.cc.rej

Patch:       media/cast/audio_sender/audio_sender.cc
Index: media/cast/audio_sender/audio_sender.cc
diff --git a/media/cast/audio_sender/audio_sender.cc
b/media/cast/audio_sender/audio_sender.cc
index
c9d1bff446f8101ed52277f3e27affaec78a586f..ce0ed040f8204359df94e8dd63bcc28e505929b7
100644
--- a/media/cast/audio_sender/audio_sender.cc
+++ b/media/cast/audio_sender/audio_sender.cc
@@ -8,6 +8,7 @@
 #include "base/logging.h"
 #include "base/message_loop/message_loop.h"
 #include "media/cast/audio_sender/audio_encoder.h"
+#include "media/cast/cast_environment.h"
 #include "media/cast/rtcp/rtcp.h"
 #include "media/cast/rtp_sender/rtp_sender.h"
 
@@ -55,12 +56,11 @@ AudioSender::AudioSender(scoped_refptr<CastEnvironment>
cast_environment,
                          PacedPacketSender* const paced_packet_sender)
       : incoming_feedback_ssrc_(audio_config.incoming_feedback_ssrc),
         cast_environment_(cast_environment),
-        rtp_sender_(cast_environment->Clock(), &audio_config, NULL,
-                    paced_packet_sender),
+        rtp_sender_(cast_environment, &audio_config, NULL,
paced_packet_sender),
         rtcp_feedback_(new LocalRtcpAudioSenderFeedback(this)),
         rtp_audio_sender_statistics_(
             new LocalRtpSenderStatistics(&rtp_sender_)),
-        rtcp_(cast_environment->Clock(),
+        rtcp_(cast_environment,
               rtcp_feedback_.get(),
               paced_packet_sender,
               rtp_audio_sender_statistics_.get(),

[commit-bot: I haz the power, 2013-11-19 17:03:43]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/2450001

[commit-bot: I haz the power, 2013-11-19 19:52:00]

Change committed as 236034

[commit-bot: I haz the power, 2013-11-19 21:40:45]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mikhal@google.com/69603002/2860001

[commit-bot: I haz the power, 2013-11-20 03:24:06]

Change committed as 236118