media-internals: Differentiate error, info, and debug log messages

media/formats/webm/webm_cluster_parser.cc

 // Copyright 2014 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "media/formats/webm/webm_cluster_parser.h"
 
 #include <vector>
 
 #include "base/logging.h"
 #include "base/sys_byteorder.h"
@@ skipping 167 matching lines @@
                                                     int size) {
   // Masks and constants for Opus packets. See
   // https://tools.ietf.org/html/rfc6716#page-14
   static const uint8_t kTocConfigMask = 0xf8;
   static const uint8_t kTocFrameCountCodeMask = 0x03;
   static const uint8_t kFrameCountMask = 0x3f;
   static const base::TimeDelta kPacketDurationMax =
       base::TimeDelta::FromMilliseconds(120);
 
   if (size < 1) {
-    LIMITED_MEDIA_LOG(log_cb_, num_duration_errors_, kMaxDurationLogs)
+    LIMITED_MEDIA_LOG(DEBUG, log_cb_, num_duration_errors_, kMaxDurationLogs)
         << "Invalid zero-byte Opus packet; demuxed block duration may be "
            "imprecise.";
     return kNoTimestamp();
   }
 
   // Frame count type described by last 2 bits of Opus TOC byte.
   int frame_count_type = data[0] & kTocFrameCountCodeMask;
 
   int frame_count = 0;
   switch (frame_count_type) {
     case 0:
       frame_count = 1;
       break;
     case 1:
     case 2:
       frame_count = 2;
       break;
     case 3:
       // Type 3 indicates an arbitrary frame count described in the next byte.
       if (size < 2) {
-        LIMITED_MEDIA_LOG(log_cb_, num_duration_errors_, kMaxDurationLogs)
+        LIMITED_MEDIA_LOG(DEBUG, log_cb_, num_duration_errors_,
+                          kMaxDurationLogs)
             << "Second byte missing from 'Code 3' Opus packet; demuxed block "
                "duration may be imprecise.";
         return kNoTimestamp();
       }
 
       frame_count = data[1] & kFrameCountMask;
 
       if (frame_count == 0) {
-        LIMITED_MEDIA_LOG(log_cb_, num_duration_errors_, kMaxDurationLogs)
+        LIMITED_MEDIA_LOG(DEBUG, log_cb_, num_duration_errors_,
+                          kMaxDurationLogs)
             << "Illegal 'Code 3' Opus packet with frame count zero; demuxed "
                "block duration may be imprecise.";
         return kNoTimestamp();
       }
 
       break;
     default:
-      LIMITED_MEDIA_LOG(log_cb_, num_duration_errors_, kMaxDurationLogs)
+      LIMITED_MEDIA_LOG(DEBUG, log_cb_, num_duration_errors_, kMaxDurationLogs)
           << "Unexpected Opus frame count type: " << frame_count_type << "; "
           << "demuxed block duration may be imprecise.";
       return kNoTimestamp();
   }
 
   int opusConfig = (data[0] & kTocConfigMask) >> 3;
   CHECK_GE(opusConfig, 0);
   CHECK_LT(opusConfig, static_cast<int>(arraysize(kOpusFrameDurationsMu)));
 
   DCHECK_GT(frame_count, 0);
   base::TimeDelta duration = base::TimeDelta::FromMicroseconds(
       kOpusFrameDurationsMu[opusConfig] * frame_count);
 
   if (duration > kPacketDurationMax) {
     // Intentionally allowing packet to pass through for now. Decoder should
     // either handle or fail gracefully. MEDIA_LOG as breadcrumbs in case
     // things go sideways.
-    LIMITED_MEDIA_LOG(log_cb_, num_duration_errors_, kMaxDurationLogs)
+    LIMITED_MEDIA_LOG(DEBUG, log_cb_, num_duration_errors_, kMaxDurationLogs)
         << "Warning, demuxed Opus packet with encoded duration: " << duration
         << ". Should be no greater than " << kPacketDurationMax;
   }
 
   return duration;
 }
 
 WebMParserClient* WebMClusterParser::OnListStart(int id) {
   if (id == kWebMIdCluster) {
     cluster_timecode_ = -1;
@@ skipping 12 matching lines @@
 
   return this;
 }
 
 bool WebMClusterParser::OnListEnd(int id) {
   if (id != kWebMIdBlockGroup)
     return true;
 
   // Make sure the BlockGroup actually had a Block.
   if (block_data_size_ == -1) {
-    MEDIA_LOG(log_cb_) << "Block missing from BlockGroup.";
+    MEDIA_LOG(ERROR, log_cb_) << "Block missing from BlockGroup.";
     return false;
   }
 
   bool result = ParseBlock(false, block_data_.get(), block_data_size_,
                            block_additional_data_.get(),
                            block_additional_data_size_, block_duration_,
                            discard_padding_set_ ? discard_padding_ : 0);
   block_data_.reset();
   block_data_size_ = -1;
   block_duration_ = -1;
@@ skipping 32 matching lines @@
                                    const uint8_t* additional,
                                    int additional_size,
                                    int duration,
                                    int64 discard_padding) {
   if (size < 4)
     return false;
 
   // Return an error if the trackNum > 127. We just aren't
   // going to support large track numbers right now.
   if (!(buf[0] & 0x80)) {
-    MEDIA_LOG(log_cb_) << "TrackNumber over 127 not supported";
+    MEDIA_LOG(ERROR, log_cb_) << "TrackNumber over 127 not supported";
     return false;
   }
 
   int track_num = buf[0] & 0x7f;
   int timecode = buf[1] << 8 | buf[2];
   int flags = buf[3] & 0xff;
   int lacing = (flags >> 1) & 0x3;
 
   if (lacing) {
-    MEDIA_LOG(log_cb_) << "Lacing " << lacing << " is not supported yet.";
+    MEDIA_LOG(ERROR, log_cb_) << "Lacing " << lacing
+                              << " is not supported yet.";
     return false;
   }
 
   // Sign extend negative timecode offsets.
   if (timecode & 0x8000)
     timecode |= ~0xffff;
 
   const uint8_t* frame_data = buf + 4;
   int frame_size = size - (frame_data - buf);
   return OnBlock(is_simple_block, track_num, timecode, duration, flags,
                  frame_data, frame_size, additional, additional_size,
                  discard_padding);
 }
 
 bool WebMClusterParser::OnBinary(int id, const uint8_t* data, int size) {
   switch (id) {
     case kWebMIdSimpleBlock:
       return ParseBlock(true, data, size, NULL, 0, -1, 0);
 
     case kWebMIdBlock:
       if (block_data_) {
-        MEDIA_LOG(log_cb_) << "More than 1 Block in a BlockGroup is not "
-                              "supported.";
+        MEDIA_LOG(ERROR, log_cb_) << "More than 1 Block in a BlockGroup is not "
+                                     "supported.";
         return false;
       }
       block_data_.reset(new uint8_t[size]);
       memcpy(block_data_.get(), data, size);
       block_data_size_ = size;
       return true;
 
     case kWebMIdBlockAdditional: {
       uint64 block_add_id = base::HostToNet64(block_add_id_);
       if (block_additional_data_) {
         // TODO(vigneshv): Technically, more than 1 BlockAdditional is allowed
         // as per matroska spec. But for now we don't have a use case to
         // support parsing of such files. Take a look at this again when such a
         // case arises.
-        MEDIA_LOG(log_cb_) << "More than 1 BlockAdditional in a BlockGroup is "
-                              "not supported.";
+        MEDIA_LOG(ERROR, log_cb_) << "More than 1 BlockAdditional in a "
+                                     "BlockGroup is not supported.";
         return false;
       }
       // First 8 bytes of side_data in DecoderBuffer is the BlockAddID
       // element's value in Big Endian format. This is done to mimic ffmpeg
       // demuxer's behavior.
       block_additional_data_size_ = size + sizeof(block_add_id);
       block_additional_data_.reset(new uint8_t[block_additional_data_size_]);
       memcpy(block_additional_data_.get(), &block_add_id,
              sizeof(block_add_id));
       memcpy(block_additional_data_.get() + 8, data, size);
@@ skipping 21 matching lines @@
                                 int timecode,
                                 int block_duration,
                                 int flags,
                                 const uint8_t* data,
                                 int size,
                                 const uint8_t* additional,
                                 int additional_size,
                                 int64 discard_padding) {
   DCHECK_GE(size, 0);
   if (cluster_timecode_ == -1) {
-    MEDIA_LOG(log_cb_) << "Got a block before cluster timecode.";
+    MEDIA_LOG(ERROR, log_cb_) << "Got a block before cluster timecode.";
     return false;
   }
 
   // TODO(acolwell): Should relative negative timecode offsets be rejected?  Or
   // only when the absolute timecode is negative?  See http://crbug.com/271794
   if (timecode < 0) {
-    MEDIA_LOG(log_cb_) << "Got a block with negative timecode offset "
-                       << timecode;
+    MEDIA_LOG(ERROR, log_cb_) << "Got a block with negative timecode offset "
+                              << timecode;
     return false;
   }
 
   if (last_block_timecode_ != -1 && timecode < last_block_timecode_) {
-    MEDIA_LOG(log_cb_)
+    MEDIA_LOG(ERROR, log_cb_)
         << "Got a block with a timecode before the previous block.";
     return false;
   }
 
   Track* track = NULL;
   StreamParserBuffer::Type buffer_type = DemuxerStream::AUDIO;
   std::string encryption_key_id;
   base::TimeDelta encoded_duration = kNoTimestamp();
   if (track_num == audio_.track_num()) {
     track = &audio_;
     encryption_key_id = audio_encryption_key_id_;
     if (encryption_key_id.empty()) {
       encoded_duration = TryGetEncodedAudioDuration(data, size);
     }
   } else if (track_num == video_.track_num()) {
     track = &video_;
     encryption_key_id = video_encryption_key_id_;
     buffer_type = DemuxerStream::VIDEO;
   } else if (ignored_tracks_.find(track_num) != ignored_tracks_.end()) {
     return true;
   } else if (Track* const text_track = FindTextTrack(track_num)) {
     if (is_simple_block)  // BlockGroup is required for WebVTT cues
       return false;
     if (block_duration < 0)  // not specified
       return false;
     track = text_track;
     buffer_type = DemuxerStream::TEXT;
   } else {
-    MEDIA_LOG(log_cb_) << "Unexpected track number " << track_num;
+    MEDIA_LOG(ERROR, log_cb_) << "Unexpected track number " << track_num;
     return false;
   }
 
   last_block_timecode_ = timecode;
 
   base::TimeDelta timestamp = base::TimeDelta::FromMicroseconds(
       (cluster_timecode_ + timecode) * timecode_multiplier_);
 
   scoped_refptr<StreamParserBuffer> buffer;
   if (buffer_type != DemuxerStream::TEXT) {
@@ skipping 77 matching lines @@
     DVLOG(3) << __FUNCTION__ << " : "
              << "Using encoded duration " << encoded_duration.InSecondsF();
 
     if (block_duration_time_delta != kNoTimestamp()) {
       base::TimeDelta duration_difference =
           block_duration_time_delta - encoded_duration;
 
       const auto kWarnDurationDiff =
           base::TimeDelta::FromMicroseconds(timecode_multiplier_ * 2);
       if (duration_difference.magnitude() > kWarnDurationDiff) {
-        LIMITED_MEDIA_LOG(log_cb_, num_duration_errors_, kMaxDurationLogs)
+        LIMITED_MEDIA_LOG(DEBUG, log_cb_, num_duration_errors_,
+                          kMaxDurationLogs)
             << "BlockDuration "
             << "(" << block_duration_time_delta << ") "
             << "differs significantly from encoded duration "
             << "(" << encoded_duration << ").";
       }
     }
   } else if (block_duration_time_delta != kNoTimestamp()) {
     buffer->set_duration(block_duration_time_delta);
   } else {
     DCHECK_NE(buffer_type, DemuxerStream::TEXT);
@@ skipping 163 matching lines @@
 
   // WebMClusterParser::OnBlock() gives MEDIA_LOG and parse error on decreasing
   // block timecode detection within a cluster. Therefore, we should not see
   // those here.
   DecodeTimestamp previous_buffers_timestamp = buffers_.empty() ?
       DecodeTimestamp() : buffers_.back()->GetDecodeTimestamp();
   CHECK(previous_buffers_timestamp <= buffer->GetDecodeTimestamp());
 
   base::TimeDelta duration = buffer->duration();
   if (duration < base::TimeDelta() || duration == kNoTimestamp()) {
-    MEDIA_LOG(log_cb_) << "Invalid buffer duration: " << duration.InSecondsF();
+    MEDIA_LOG(ERROR, log_cb_)
+        << "Invalid buffer duration: " << duration.InSecondsF();
     return false;
   }
 
   // The estimated frame duration is the minimum non-zero duration since the
   // last initialization segment.  The minimum is used to ensure frame durations
   // aren't overestimated.
   if (duration > base::TimeDelta()) {
     if (estimated_next_frame_duration_ == kNoTimestamp()) {
       estimated_next_frame_duration_ = duration;
     } else {
@@ skipping 79 matching lines @@
 WebMClusterParser::FindTextTrack(int track_num) {
   const TextTrackMap::iterator it = text_track_map_.find(track_num);
 
   if (it == text_track_map_.end())
     return NULL;
 
   return &it->second;
 }
 
 }  // namespace media