Bug 1330918 - Add VideoTrackEncoder::AppendVideoSegment logs. r=jesup
☠☠ backed out by 951b80d391e6 ☠ ☠
authorAndreas Pehrson <pehrsons@gmail.com>
Wed, 18 Jan 2017 19:28:32 +0100
changeset 377267 aedd9a68f2c013ca2df44e3f331b176a004d2341
parent 377266 b2d8a93a50a81b885abb8880547a0be604bd0be0
child 377268 5acfb0d242bf67957c52fbef3b9135ba0f4720d4
push id1419
push userjlund@mozilla.com
push dateMon, 10 Apr 2017 20:44:07 +0000
treeherdermozilla-release@5e6801b73ef6 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjesup
bugs1330918
milestone53.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1330918 - Add VideoTrackEncoder::AppendVideoSegment logs. r=jesup MozReview-Commit-ID: FwG0EHuaxpW
dom/media/encoder/TrackEncoder.cpp
--- a/dom/media/encoder/TrackEncoder.cpp
+++ b/dom/media/encoder/TrackEncoder.cpp
@@ -294,33 +294,45 @@ VideoTrackEncoder::AppendVideoSegment(co
       }
 
       // This is the first real chunk in the track. Use its timestamp as the
       // starting point for this track.
       MOZ_ASSERT(!chunk.mTimeStamp.IsNull());
       const StreamTime nullDuration = mLastChunk.mDuration;
       mLastChunk = chunk;
 
+      TRACK_LOG(LogLevel::Verbose,
+                ("[VideoTrackEncoder]: Got first video chunk after %lld ticks.",
+                 nullDuration));
       // Adapt to the time before the first frame. This extends the first frame
       // from [start, end] to [0, end], but it'll do for now.
       mLastChunk.mTimeStamp -=
         TimeDuration::FromMicroseconds(
           RateConvertTicksRoundUp(PR_USEC_PER_SEC, mTrackRate, nullDuration));
     }
 
     MOZ_ASSERT(!mLastChunk.IsNull());
     if (mLastChunk.CanCombineWithFollowing(chunk) || chunk.IsNull()) {
+      TRACK_LOG(LogLevel::Verbose,
+                ("[VideoTrackEncoder]: Got dupe or null chunk."));
       // This is the same frame as before (or null). We extend the last chunk
       // with its duration.
       mLastChunk.mDuration += chunk.mDuration;
 
       if (mLastChunk.mDuration < mTrackRate) {
+        TRACK_LOG(LogLevel::Verbose,
+                  ("[VideoTrackEncoder]: Ignoring dupe/null chunk of duration "
+                   "%lld", chunk.mDuration));
         continue;
       }
 
+      TRACK_LOG(LogLevel::Verbose,
+                ("[VideoTrackEncoder]: Chunk >1 second. duration=%lld, "
+                 "trackRate=%lld", mLastChunk.mDuration, mTrackRate));
+
       // If we have gotten dupes for over a second, we force send one
       // to the encoder to make sure there is some output.
       chunk.mTimeStamp = mLastChunk.mTimeStamp + TimeDuration::FromSeconds(1);
 
       if (chunk.IsNull()) {
         // Ensure that we don't pass null to the encoder by making mLastChunk
         // null later on.
         chunk.mFrame = mLastChunk.mFrame;
@@ -329,19 +341,25 @@ VideoTrackEncoder::AppendVideoSegment(co
 
     TimeDuration diff = chunk.mTimeStamp - mLastChunk.mTimeStamp;
     if (diff <= TimeDuration::FromSeconds(0)) {
       // The timestamp from mLastChunk is newer than from chunk.
       // This means the durations reported from MediaStreamGraph for mLastChunk
       // were larger than the timestamp diff - and durations were used to
       // trigger the 1-second frame above. This could happen due to drift or
       // underruns in the graph.
+      TRACK_LOG(LogLevel::Warning,
+                ("[VideoTrackEncoder]: Underrun detected. Diff=%.5fs",
+                 diff.ToSeconds()));
       chunk.mTimeStamp = mLastChunk.mTimeStamp;
     } else {
       RefPtr<layers::Image> lastImage = mLastChunk.mFrame.GetImage();
+      TRACK_LOG(LogLevel::Verbose,
+                ("[VideoTrackEncoder]: Appending video frame %p, duration=%.5f",
+                 lastImage.get(), diff.ToSeconds()));
       mRawSegment.AppendFrame(lastImage.forget(),
                               RateConvertTicksRoundUp(
                                   mTrackRate, PR_USEC_PER_SEC,
                                   diff.ToMicroseconds()),
                               mLastChunk.mFrame.GetIntrinsicSize(),
                               PRINCIPAL_HANDLE_NONE,
                               mLastChunk.mFrame.GetForceBlack(),
                               mLastChunk.mTimeStamp);