Initial Metrics for Media.player
First round of logging metrics for media player. This marks
mime types, resolution, frames/time played, duration of media.
Expect more data in the future.
Bug: 33547820
Test: run player, observe captured log
Change-Id: I7bbfaf19e44113f4f285edb72f099b725beace72
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
index f8a6a4e..f2e3e7c 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayer.cpp
@@ -16,6 +16,9 @@
//#define LOG_NDEBUG 0
#define LOG_TAG "NuPlayer"
+
+#include <inttypes.h>
+
#include <utils/Log.h>
#include "NuPlayer.h"
@@ -1287,6 +1290,8 @@
} else {
ALOGW("resume called when renderer is gone or not set");
}
+
+ mLastStartedPlayingTimeNs = systemTime();
}
status_t NuPlayer::onInstantiateSecureDecoders() {
@@ -1396,6 +1401,8 @@
mAudioDecoder->setRenderer(mRenderer);
}
+ mLastStartedPlayingTimeNs = systemTime();
+
postScanSources();
}
@@ -1414,6 +1421,16 @@
} else {
ALOGW("pause called when renderer is gone or not set");
}
+
+ sp<NuPlayerDriver> driver = mDriver.promote();
+ if (driver != NULL) {
+ int64_t now = systemTime();
+ int64_t played = now - mLastStartedPlayingTimeNs;
+ ALOGD("played from %" PRId64 " to %" PRId64 " = %" PRId64 ,
+ mLastStartedPlayingTimeNs, now, played);
+
+ driver->notifyMorePlayingTimeUs((played+500)/1000);
+ }
}
bool NuPlayer::audioDecoderStillNeeded() {
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayer.h b/media/libmediaplayerservice/nuplayer/NuPlayer.h
index c8b0102..6f737bb 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayer.h
+++ b/media/libmediaplayerservice/nuplayer/NuPlayer.h
@@ -158,6 +158,8 @@
int32_t mVideoDecoderGeneration;
int32_t mRendererGeneration;
+ int64_t mLastStartedPlayingTimeNs;
+
int64_t mPreviousSeekTimeUs;
List<sp<Action> > mDeferredActions;
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
index 6ec79e6..e190d07 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
@@ -31,8 +31,11 @@
#include <media/stagefright/MetaData.h>
#include <media/stagefright/Utils.h>
+#include <media/IMediaAnalyticsService.h>
+
namespace android {
+
NuPlayerDriver::NuPlayerDriver(pid_t pid)
: mState(STATE_IDLE),
mIsAsyncPrepare(false),
@@ -41,14 +44,20 @@
mDurationUs(-1),
mPositionUs(-1),
mSeekInProgress(false),
+ mPlayingTimeUs(0),
mLooper(new ALooper),
mPlayerFlags(0),
+ mAnalyticsItem(NULL),
mAtEOS(false),
mLooping(false),
mAutoLoop(false) {
ALOGV("NuPlayerDriver(%p)", this);
mLooper->setName("NuPlayerDriver Looper");
+ // set up an analytics record
+ mAnalyticsItem = new MediaAnalyticsItem("nuplayer");
+ mAnalyticsItem->generateSessionID();
+
mLooper->start(
false, /* runOnCallingThread */
true, /* canCallJava */
@@ -63,6 +72,15 @@
NuPlayerDriver::~NuPlayerDriver() {
ALOGV("~NuPlayerDriver(%p)", this);
mLooper->stop();
+
+ // finalize any pending metrics, usually a no-op.
+ finalizeMetrics("destructor");
+ logMetrics("destructor");
+
+ if (mAnalyticsItem != NULL) {
+ delete mAnalyticsItem;
+ mAnalyticsItem = NULL;
+ }
}
status_t NuPlayerDriver::initCheck() {
@@ -450,8 +468,103 @@
return OK;
}
+void NuPlayerDriver::finalizeMetrics(const char *where) {
+ if (where == NULL) {
+ where = "unknown";
+ }
+ ALOGD("finalizeMetrics(%p) from %s at state %d", this, where, mState);
+
+ // gather the final stats for this record
+ Vector<sp<AMessage>> trackStats;
+ mPlayer->getStats(&trackStats);
+
+ if (trackStats.size() > 0) {
+ for (size_t i = 0; i < trackStats.size(); ++i) {
+ const sp<AMessage> &stats = trackStats.itemAt(i);
+
+ AString mime;
+ stats->findString("mime", &mime);
+
+ AString name;
+ stats->findString("component-name", &name);
+
+ if (mime.startsWith("video/")) {
+ int32_t width, height;
+ mAnalyticsItem->setCString("video/mime", mime.c_str());
+ if (!name.empty()) {
+ mAnalyticsItem->setCString("video/codec", name.c_str());
+ }
+
+ if (stats->findInt32("width", &width)
+ && stats->findInt32("height", &height)) {
+ mAnalyticsItem->setInt32("wid", width);
+ mAnalyticsItem->setInt32("ht", height);
+ }
+
+ int64_t numFramesTotal = 0;
+ int64_t numFramesDropped = 0;
+ stats->findInt64("frames-total", &numFramesTotal);
+ stats->findInt64("frames-dropped-output", &numFramesDropped);
+
+ mAnalyticsItem->setInt64("frames", numFramesTotal);
+ mAnalyticsItem->setInt64("dropped", numFramesDropped);
+
+
+ } else if (mime.startsWith("audio/")) {
+ mAnalyticsItem->setCString("audio/mime", mime.c_str());
+ if (!name.empty()) {
+ mAnalyticsItem->setCString("audio/codec", name.c_str());
+ }
+ }
+ }
+
+ // getDuration() uses mLock for mutex -- careful where we use it.
+ int duration_ms = -1;
+ getDuration(&duration_ms);
+ if (duration_ms != -1) {
+ mAnalyticsItem->setInt64("duration", duration_ms);
+ }
+
+ if (mPlayingTimeUs > 0) {
+ mAnalyticsItem->setInt64("playing", (mPlayingTimeUs+500)/1000 );
+ }
+ }
+}
+
+
+void NuPlayerDriver::logMetrics(const char *where) {
+ if (where == NULL) {
+ where = "unknown";
+ }
+ ALOGD("logMetrics(%p) from %s at state %d", this, where, mState);
+
+ if (mAnalyticsItem == NULL || mAnalyticsItem->isEnabled() == false) {
+ return;
+ }
+
+ // only bother to log non-empty records
+ if (mAnalyticsItem->count() > 0) {
+
+ mAnalyticsItem->setFinalized(true);
+ mAnalyticsItem->selfrecord();
+
+ // re-init in case we prepare() and start() again.
+ delete mAnalyticsItem ;
+ mAnalyticsItem = new MediaAnalyticsItem("nuplayer");
+ if (mAnalyticsItem) {
+ mAnalyticsItem->generateSessionID();
+ }
+ } else {
+ ALOGV("did not have anything to record");
+ }
+}
+
status_t NuPlayerDriver::reset() {
ALOGD("reset(%p) at state %d", this, mState);
+
+ finalizeMetrics("reset");
+ logMetrics("reset");
+
Mutex::Autolock autoLock(mLock);
switch (mState) {
@@ -493,6 +606,7 @@
mDurationUs = -1;
mPositionUs = -1;
mLooping = false;
+ mPlayingTimeUs = 0;
return OK;
}
@@ -624,6 +738,11 @@
mDurationUs = durationUs;
}
+void NuPlayerDriver::notifyMorePlayingTimeUs(int64_t playingUs) {
+ Mutex::Autolock autoLock(mLock);
+ mPlayingTimeUs += playingUs;
+}
+
void NuPlayerDriver::notifySeekComplete() {
ALOGV("notifySeekComplete(%p)", this);
Mutex::Autolock autoLock(mLock);
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.h b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.h
index 317b34c..9b784ae 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.h
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.h
@@ -16,6 +16,7 @@
#include <media/MediaPlayerInterface.h>
+#include <media/MediaAnalyticsItem.h>
#include <media/stagefright/foundation/ABase.h>
namespace android {
@@ -75,6 +76,7 @@
void notifyResetComplete();
void notifySetSurfaceComplete();
void notifyDuration(int64_t durationUs);
+ void notifyMorePlayingTimeUs(int64_t timeUs);
void notifySeekComplete();
void notifySeekComplete_l();
void notifyListener(int msg, int ext1 = 0, int ext2 = 0, const Parcel *in = NULL);
@@ -112,6 +114,7 @@
int64_t mDurationUs;
int64_t mPositionUs;
bool mSeekInProgress;
+ int64_t mPlayingTimeUs;
// <<<
sp<ALooper> mLooper;
@@ -119,10 +122,15 @@
sp<AudioSink> mAudioSink;
uint32_t mPlayerFlags;
+ MediaAnalyticsItem *mAnalyticsItem;
+
bool mAtEOS;
bool mLooping;
bool mAutoLoop;
+ void finalizeMetrics(const char *where);
+ void logMetrics(const char *where);
+
status_t prepare_l();
status_t start_l();
void notifyListener_l(int msg, int ext1 = 0, int ext2 = 0, const Parcel *in = NULL);