Bug 1330918 - Add VideoTrackEncoder::AppendVideoSegment logs. r?jesup
MozReview-Commit-ID: FwG0EHuaxpW
--- a/dom/media/encoder/TrackEncoder.cpp
+++ b/dom/media/encoder/TrackEncoder.cpp
@@ -292,33 +292,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;
@@ -327,19 +339,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);