collect more media metrics around audio
am: 84e84a5dd3

Change-Id: I3403aa6ec0f4bfd53a7ec80c8c45d28267797763
diff --git a/media/libaudioclient/AudioRecord.cpp b/media/libaudioclient/AudioRecord.cpp
index a8369c2..f9df5b1 100644
--- a/media/libaudioclient/AudioRecord.cpp
+++ b/media/libaudioclient/AudioRecord.cpp
@@ -99,6 +99,11 @@
     static constexpr char kAudioRecordLatency[] = "android.media.audiorecord.latency";
     static constexpr char kAudioRecordSampleRate[] = "android.media.audiorecord.samplerate";
     static constexpr char kAudioRecordChannelCount[] = "android.media.audiorecord.channels";
+    static constexpr char kAudioRecordCreated[] = "android.media.audiorecord.createdMs";
+    static constexpr char kAudioRecordDuration[] = "android.media.audiorecord.durationMs";
+    static constexpr char kAudioRecordCount[] = "android.media.audiorecord.n";
+    static constexpr char kAudioRecordError[] = "android.media.audiorecord.errcode";
+    static constexpr char kAudioRecordErrorFunction[] = "android.media.audiorecord.errfunc";
 
     // constructor guarantees mAnalyticsItem is valid
 
@@ -109,6 +114,24 @@
                                audioFormatTypeString(record->mFormat).c_str());
     mAnalyticsItem->setCString(kAudioRecordSource,
                                audioSourceString(record->mAttributes.source).c_str());
+
+    // log total duration recording, including anything currently running [and count].
+    nsecs_t active = 0;
+    if (mStartedNs != 0) {
+        active = systemTime() - mStartedNs;
+    }
+    mAnalyticsItem->setInt64(kAudioRecordDuration, (mDurationNs + active) / (1000 * 1000));
+    mAnalyticsItem->setInt32(kAudioRecordCount, mCount);
+
+    // XXX I don't know that this adds a lot of value, long term
+    if (mCreatedNs != 0) {
+        mAnalyticsItem->setInt64(kAudioRecordCreated, mCreatedNs / (1000 * 1000));
+    }
+
+    if (mLastError != NO_ERROR) {
+        mAnalyticsItem->setInt32(kAudioRecordError, mLastError);
+        mAnalyticsItem->setCString(kAudioRecordErrorFunction, mLastErrorFunc.c_str());
+    }
 }
 
 // hand the user a snapshot of the metrics.
@@ -354,6 +377,9 @@
 
 exit:
     mStatus = status;
+    if (status != NO_ERROR) {
+        mMediaMetrics.markError(status, __FUNCTION__);
+    }
     return status;
 }
 
@@ -412,8 +438,14 @@
             get_sched_policy(0, &mPreviousSchedulingGroup);
             androidSetThreadPriority(0, ANDROID_PRIORITY_AUDIO);
         }
+
+        // we've successfully started, log that time
+        mMediaMetrics.logStart(systemTime());
     }
 
+    if (status != NO_ERROR) {
+        mMediaMetrics.markError(status, __FUNCTION__);
+    }
     return status;
 }
 
@@ -438,6 +470,9 @@
         setpriority(PRIO_PROCESS, 0, mPreviousPriority);
         set_sched_policy(0, mPreviousSchedulingGroup);
     }
+
+    // we've successfully started, log that time
+    mMediaMetrics.logStop(systemTime());
 }
 
 bool AudioRecord::stopped() const
diff --git a/media/libaudioclient/include/media/AudioRecord.h b/media/libaudioclient/include/media/AudioRecord.h
index c07c397..cf446a5 100644
--- a/media/libaudioclient/include/media/AudioRecord.h
+++ b/media/libaudioclient/include/media/AudioRecord.h
@@ -704,7 +704,10 @@
 private:
     class MediaMetrics {
       public:
-        MediaMetrics() : mAnalyticsItem(new MediaAnalyticsItem("audiorecord")) {
+        MediaMetrics() : mAnalyticsItem(new MediaAnalyticsItem("audiorecord")),
+                         mCreatedNs(systemTime(SYSTEM_TIME_REALTIME)),
+                         mStartedNs(0), mDurationNs(0), mCount(0),
+                         mLastError(NO_ERROR) {
         }
         ~MediaMetrics() {
             // mAnalyticsItem alloc failure will be flagged in the constructor
@@ -715,8 +718,20 @@
         }
         void gather(const AudioRecord *record);
         MediaAnalyticsItem *dup() { return mAnalyticsItem->dup(); }
+
+        void logStart(nsecs_t when) { mStartedNs = when; mCount++; }
+        void logStop(nsecs_t when) { mDurationNs += (when-mStartedNs); mStartedNs = 0;}
+        void markError(status_t errcode, const char *func)
+                 { mLastError = errcode; mLastErrorFunc = func;}
       private:
         std::unique_ptr<MediaAnalyticsItem> mAnalyticsItem;
+        nsecs_t mCreatedNs;     // XXX: perhaps not worth it in production
+        nsecs_t mStartedNs;
+        nsecs_t mDurationNs;
+        int32_t mCount;
+
+        status_t mLastError;
+        std::string mLastErrorFunc;
     };
     MediaMetrics mMediaMetrics;
 };
diff --git a/services/audiopolicy/Android.mk b/services/audiopolicy/Android.mk
index 65571f9..d29cae1 100644
--- a/services/audiopolicy/Android.mk
+++ b/services/audiopolicy/Android.mk
@@ -25,6 +25,7 @@
     libserviceutility \
     libaudiopolicymanager \
     libmedia_helper \
+    libmediametrics \
     libeffectsconfig
 
 LOCAL_STATIC_LIBRARIES := \
@@ -60,6 +61,7 @@
     audio_policy_criteria.conf \
 
 LOCAL_C_INCLUDES += frameworks/av/services/audiopolicy/engineconfigurable/include
+LOCAL_C_INCLUDES += frameworks/av/include
 
 LOCAL_SHARED_LIBRARIES += libaudiopolicyengineconfigurable
 
@@ -78,6 +80,7 @@
     libaudiopolicycomponents
 
 LOCAL_SHARED_LIBRARIES += libmedia_helper
+LOCAL_SHARED_LIBRARIES += libmediametrics
 
 ifeq ($(USE_XML_AUDIO_POLICY_CONF), 1)
 LOCAL_SHARED_LIBRARIES += libicuuc libxml2
diff --git a/services/audiopolicy/AudioPolicyInterface.h b/services/audiopolicy/AudioPolicyInterface.h
index 7f09e9b..923c091 100644
--- a/services/audiopolicy/AudioPolicyInterface.h
+++ b/services/audiopolicy/AudioPolicyInterface.h
@@ -69,8 +69,12 @@
         API_INPUT_CONCURRENCY_NONE = 0,
         API_INPUT_CONCURRENCY_CALL = (1 << 0),      // Concurrency with a call
         API_INPUT_CONCURRENCY_CAPTURE = (1 << 1),   // Concurrency with another capture
+        API_INPUT_CONCURRENCY_HOTWORD = (1 << 2),   // Concurrency with a hotword
+        API_INPUT_CONCURRENCY_PREEMPT = (1 << 3),   // pre-empted someone
+                // NB: preempt is marked on a successful return, others are on failing calls
+        API_INPUT_CONCURRENCY_LAST = (1 << 4),
 
-        API_INPUT_CONCURRENCY_ALL = (API_INPUT_CONCURRENCY_CALL | API_INPUT_CONCURRENCY_CAPTURE),
+        API_INPUT_CONCURRENCY_ALL = (API_INPUT_CONCURRENCY_LAST - 1),
     };
 
     typedef uint32_t concurrency_type__mask_t;
diff --git a/services/audiopolicy/managerdefault/AudioPolicyManager.cpp b/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
index 4f565e4..08a143b 100644
--- a/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
+++ b/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
@@ -1883,6 +1883,7 @@
         if (mCallTxPatch != 0 &&
             inputDesc->getModuleHandle() == mCallTxPatch->mPatch.sources[0].ext.device.hw_module) {
             ALOGW("startInput(%d) failed: call in progress", input);
+            *concurrency |= API_INPUT_CONCURRENCY_CALL;
             return INVALID_OPERATION;
         }
 
@@ -1925,17 +1926,20 @@
                         ALOGW("startInput(%d) failed for HOTWORD: "
                                 "other input %d already started for HOTWORD",
                               input, activeDesc->mIoHandle);
+                        *concurrency |= API_INPUT_CONCURRENCY_HOTWORD;
                         return INVALID_OPERATION;
                     }
                 } else {
                     ALOGV("startInput(%d) failed for HOTWORD: other input %d already started",
                           input, activeDesc->mIoHandle);
+                    *concurrency |= API_INPUT_CONCURRENCY_CAPTURE;
                     return INVALID_OPERATION;
                 }
             } else {
                 if (activeSource != AUDIO_SOURCE_HOTWORD) {
                     ALOGW("startInput(%d) failed: other input %d already started",
                           input, activeDesc->mIoHandle);
+                    *concurrency |= API_INPUT_CONCURRENCY_CAPTURE;
                     return INVALID_OPERATION;
                 }
             }
@@ -1960,6 +1964,7 @@
                 audio_session_t activeSession = activeSessions.keyAt(0);
                 audio_io_handle_t activeHandle = activeDesc->mIoHandle;
                 SortedVector<audio_session_t> sessions = activeDesc->getPreemptedSessions();
+                *concurrency |= API_INPUT_CONCURRENCY_PREEMPT;
                 sessions.add(activeSession);
                 inputDesc->setPreemptedSessions(sessions);
                 stopInput(activeHandle, activeSession);
diff --git a/services/audiopolicy/service/AudioPolicyInterfaceImpl.cpp b/services/audiopolicy/service/AudioPolicyInterfaceImpl.cpp
index cf24c13..008d655 100644
--- a/services/audiopolicy/service/AudioPolicyInterfaceImpl.cpp
+++ b/services/audiopolicy/service/AudioPolicyInterfaceImpl.cpp
@@ -18,8 +18,11 @@
 //#define LOG_NDEBUG 0
 
 #include <utils/Log.h>
+#include <media/MediaAnalyticsItem.h>
+
 #include "AudioPolicyService.h"
 #include "ServiceUtilities.h"
+#include "TypeConverter.h"
 
 namespace android {
 
@@ -409,6 +412,35 @@
     return NO_ERROR;
 }
 
+// this is replicated from frameworks/av/media/libaudioclient/AudioRecord.cpp
+// XXX -- figure out how to put it into a common, shared location
+
+static std::string audioSourceString(audio_source_t value) {
+    std::string source;
+    if (SourceTypeConverter::toString(value, source)) {
+        return source;
+    }
+    char rawbuffer[16];  // room for "%d"
+    snprintf(rawbuffer, sizeof(rawbuffer), "%d", value);
+    return rawbuffer;
+}
+
+static std::string audioConcurrencyString(AudioPolicyInterface::concurrency_type__mask_t concurrency)
+{
+    char buffer[64]; // oversized
+    if (concurrency & AudioPolicyInterface::API_INPUT_CONCURRENCY_ALL) {
+        snprintf(buffer, sizeof(buffer), "%s%s%s%s",
+            (concurrency & AudioPolicyInterface::API_INPUT_CONCURRENCY_CALL)? ",call":"",
+            (concurrency & AudioPolicyInterface::API_INPUT_CONCURRENCY_CAPTURE)? ",capture":"",
+            (concurrency & AudioPolicyInterface::API_INPUT_CONCURRENCY_HOTWORD)? ",hotword":"",
+            (concurrency & AudioPolicyInterface::API_INPUT_CONCURRENCY_PREEMPT)? ",preempt":"");
+    } else {
+        snprintf(buffer, sizeof(buffer), ",none");
+    }
+
+    return &buffer[1];
+}
+
 status_t AudioPolicyService::startInput(audio_port_handle_t portId, bool *silenced)
 {
     if (mAudioPolicyManager == NULL) {
@@ -444,6 +476,57 @@
         AutoCallerClear acc;
         status = mAudioPolicyManager->startInput(
                     client->input, client->session, *silenced, &concurrency);
+
+    }
+
+    // XXX log them all for a while, during some dogfooding.
+    if (1 || status != NO_ERROR) {
+
+        static constexpr char kAudioPolicy[] = "audiopolicy";
+
+        static constexpr char kAudioPolicyReason[] = "android.media.audiopolicy.reason";
+        static constexpr char kAudioPolicyStatus[] = "android.media.audiopolicy.status";
+        static constexpr char kAudioPolicyRqstSrc[] = "android.media.audiopolicy.rqst.src";
+        static constexpr char kAudioPolicyRqstPkg[] = "android.media.audiopolicy.rqst.pkg";
+        static constexpr char kAudioPolicyRqstSession[] = "android.media.audiopolicy.rqst.session";
+        static constexpr char kAudioPolicyActiveSrc[] = "android.media.audiopolicy.active.src";
+        static constexpr char kAudioPolicyActivePkg[] = "android.media.audiopolicy.active.pkg";
+        static constexpr char kAudioPolicyActiveSession[] = "android.media.audiopolicy.active.session";
+
+        MediaAnalyticsItem *item = new MediaAnalyticsItem(kAudioPolicy);
+        if (item != NULL) {
+
+            item->setCString(kAudioPolicyReason, audioConcurrencyString(concurrency).c_str());
+            item->setInt32(kAudioPolicyStatus, status);
+
+            item->setCString(kAudioPolicyRqstSrc, audioSourceString(client->attributes.source).c_str());
+            item->setCString(kAudioPolicyRqstPkg, std::string(String8(client->opPackageName).string()).c_str());
+            item->setInt32(kAudioPolicyRqstSession, client->session);
+
+            // figure out who is active
+            // NB: might the other party have given up the microphone since then? how sure.
+            // perhaps could have given up on it.
+            // we hold mLock, so perhaps we're safe for this looping
+            if (concurrency != AudioPolicyInterface::API_INPUT_CONCURRENCY_NONE) {
+                int count = mAudioRecordClients.size();
+                for (int i = 0; i<count ; i++) {
+                    if (portId == mAudioRecordClients.keyAt(i)) {
+                        continue;
+                    }
+                    sp<AudioRecordClient> other = mAudioRecordClients.valueAt(i);
+                    if (other->active) {
+                        // keeps the last of the clients marked active
+                        item->setCString(kAudioPolicyActiveSrc,
+                                         audioSourceString(other->attributes.source).c_str());
+                        item->setCString(kAudioPolicyActivePkg, std::string(String8(other->opPackageName).string()).c_str());
+                        item->setInt32(kAudioPolicyActiveSession, other->session);
+                    }
+                }
+            }
+            item->selfrecord();
+            delete item;
+            item = NULL;
+        }
     }
 
     if (status == NO_ERROR) {
@@ -457,6 +540,8 @@
         if (concurrency & AudioPolicyInterface::API_INPUT_CONCURRENCY_CAPTURE) {
             //TODO: check concurrent capture permission
         }
+
+        client->active = true;
     } else {
         finishRecording(client->opPackageName, client->uid);
     }
@@ -477,6 +562,8 @@
     }
     sp<AudioRecordClient> client = mAudioRecordClients.valueAt(index);
 
+    client->active = false;
+
     // finish the recording app op
     finishRecording(client->opPackageName, client->uid);
     AutoCallerClear acc;
diff --git a/services/mediaanalytics/MediaAnalyticsService.cpp b/services/mediaanalytics/MediaAnalyticsService.cpp
index 6d84a42..4b05395 100644
--- a/services/mediaanalytics/MediaAnalyticsService.cpp
+++ b/services/mediaanalytics/MediaAnalyticsService.cpp
@@ -481,6 +481,7 @@
 
 static std::string allowedKeys[] =
 {
+    "audiopolicy",
     "audiorecord",
     "audiotrack",
     "codec",