better playback time tracking in nuplayer
Fixes problem where playback time was being cleared as part of
a reset before media.metrics stats were logged.
Added code so that getMetrics() calls will return proper in-progress
playback time (previously, playback time was added to the metrics data
only at the end).
Added initialization of timestamp tracking pauses for rebuffering.
Bug: 74008613
Test: dumpsys media.metrics observation
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
index d1e5d45..dce3e0a 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
@@ -183,6 +183,7 @@
mVideoDecoderGeneration(0),
mRendererGeneration(0),
mLastStartedPlayingTimeNs(0),
+ mLastStartedRebufferingTimeNs(0),
mPreviousSeekTimeUs(0),
mAudioEOS(false),
mVideoEOS(false),
@@ -1310,8 +1311,8 @@
ALOGV("kWhatReset");
mResetting = true;
- stopPlaybackTimer("kWhatReset");
- stopRebufferingTimer(true);
+ updatePlaybackTimer(true /* stopping */, "kWhatReset");
+ updateRebufferingTimer(true /* stopping */, true /* exiting */);
mDeferredActions.push_back(
new FlushDecoderAction(
@@ -1585,23 +1586,28 @@
}
}
-void NuPlayer::stopPlaybackTimer(const char *where) {
+void NuPlayer::updatePlaybackTimer(bool stopping, const char *where) {
Mutex::Autolock autoLock(mPlayingTimeLock);
- ALOGV("stopPlaybackTimer() time %20" PRId64 " (%s)", mLastStartedPlayingTimeNs, where);
+ ALOGV("updatePlaybackTimer(%s) time %20" PRId64 " (%s)",
+ stopping ? "stop" : "snap", mLastStartedPlayingTimeNs, where);
if (mLastStartedPlayingTimeNs != 0) {
sp<NuPlayerDriver> driver = mDriver.promote();
+ int64_t now = systemTime();
if (driver != NULL) {
- int64_t now = systemTime();
int64_t played = now - mLastStartedPlayingTimeNs;
- ALOGV("stopPlaybackTimer() log %20" PRId64 "", played);
+ ALOGV("updatePlaybackTimer() log %20" PRId64 "", played);
if (played > 0) {
driver->notifyMorePlayingTimeUs((played+500)/1000);
}
}
- mLastStartedPlayingTimeNs = 0;
+ if (stopping) {
+ mLastStartedPlayingTimeNs = 0;
+ } else {
+ mLastStartedPlayingTimeNs = now;
+ }
}
}
@@ -1613,17 +1619,18 @@
}
}
-void NuPlayer::stopRebufferingTimer(bool exitingPlayback) {
+void NuPlayer::updateRebufferingTimer(bool stopping, bool exitingPlayback) {
Mutex::Autolock autoLock(mPlayingTimeLock);
- ALOGV("stopRebufferTimer() time %20" PRId64 " (exiting %d)", mLastStartedRebufferingTimeNs, exitingPlayback);
+ ALOGV("updateRebufferingTimer(%s) time %20" PRId64 " (exiting %d)",
+ stopping ? "stop" : "snap", mLastStartedRebufferingTimeNs, exitingPlayback);
if (mLastStartedRebufferingTimeNs != 0) {
sp<NuPlayerDriver> driver = mDriver.promote();
+ int64_t now = systemTime();
if (driver != NULL) {
- int64_t now = systemTime();
int64_t rebuffered = now - mLastStartedRebufferingTimeNs;
- ALOGV("stopRebufferingTimer() log %20" PRId64 "", rebuffered);
+ ALOGV("updateRebufferingTimer() log %20" PRId64 "", rebuffered);
if (rebuffered > 0) {
driver->notifyMoreRebufferingTimeUs((rebuffered+500)/1000);
@@ -1632,13 +1639,24 @@
}
}
}
- mLastStartedRebufferingTimeNs = 0;
+ if (stopping) {
+ mLastStartedRebufferingTimeNs = 0;
+ } else {
+ mLastStartedRebufferingTimeNs = now;
+ }
}
}
+void NuPlayer::updateInternalTimers() {
+ // update values, but ticking clocks keep ticking
+ ALOGV("updateInternalTimers()");
+ updatePlaybackTimer(false /* stopping */, "updateInternalTimers");
+ updateRebufferingTimer(false /* stopping */, false /* exiting */);
+}
+
void NuPlayer::onPause() {
- stopPlaybackTimer("onPause");
+ updatePlaybackTimer(true /* stopping */, "onPause");
if (mPaused) {
return;
@@ -2281,8 +2299,8 @@
CHECK(mAudioDecoder == NULL);
CHECK(mVideoDecoder == NULL);
- stopPlaybackTimer("performReset");
- stopRebufferingTimer(true);
+ updatePlaybackTimer(true /* stopping */, "performReset");
+ updateRebufferingTimer(true /* stopping */, true /* exiting */);
cancelPollDuration();
@@ -2550,7 +2568,7 @@
if (mStarted) {
ALOGI("buffer ready, resuming...");
- stopRebufferingTimer(false);
+ updateRebufferingTimer(true /* stopping */, false /* exiting */);
mPausedForBuffering = false;
// do not resume yet if client didn't unpause
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayer.h b/media/libmediaplayerservice/nuplayer/NuPlayer.h
index fda69e8..9481234 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayer.h
+++ b/media/libmediaplayerservice/nuplayer/NuPlayer.h
@@ -99,6 +99,8 @@
const char *getDataSourceType();
+ void updateInternalTimers();
+
protected:
virtual ~NuPlayer();
@@ -180,12 +182,12 @@
Mutex mPlayingTimeLock;
int64_t mLastStartedPlayingTimeNs;
- void stopPlaybackTimer(const char *where);
+ void updatePlaybackTimer(bool stopping, const char *where);
void startPlaybackTimer(const char *where);
int64_t mLastStartedRebufferingTimeNs;
void startRebufferingTimer();
- void stopRebufferingTimer(bool exitingPlayback);
+ void updateRebufferingTimer(bool stopping, bool exitingPlayback);
int64_t mPreviousSeekTimeUs;
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
index c455951..731fdba 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
@@ -535,6 +535,7 @@
}
void NuPlayerDriver::updateMetrics(const char *where) {
+
if (where == NULL) {
where = "unknown";
}
@@ -592,6 +593,8 @@
getDuration(&duration_ms);
mAnalyticsItem->setInt64(kPlayerDuration, duration_ms);
+ mPlayer->updateInternalTimers();
+
mAnalyticsItem->setInt64(kPlayerPlaying, (mPlayingTimeUs+500)/1000 );
if (mRebufferingEvents != 0) {
@@ -630,7 +633,7 @@
mAnalyticsItem->setUid(mClientUid);
}
} else {
- ALOGV("did not have anything to record");
+ ALOGV("nothing to record (only %d fields)", mAnalyticsItem->count());
}
}