AidlUtils: update AUGMENT_LOG to support variable arguments

 - move logging macros to ConversionHelperAidl
 - replace LOG_ENTRY with AUGMENT_LOG

Flag: EXEMPT bugfix
Bug: 356310696
Test: atest CoreAudioHalAidlTest
Change-Id: I3f217913679f43a9db5cde032402c94e7c252fec
diff --git a/media/libaudiohal/impl/AidlUtils.h b/media/libaudiohal/impl/AidlUtils.h
index fcd7a01..97a5bba 100644
--- a/media/libaudiohal/impl/AidlUtils.h
+++ b/media/libaudiohal/impl/AidlUtils.h
@@ -25,32 +25,6 @@
 
 namespace android {
 
-/*
- * Helper macro to add instance name, function name in logs
- * classes should provide getInstanceName and getClassName API to use these macros.
- * print function names along with instance name.
- *
- * Usage:
- *  AUGMENT_LOG(I, "hello!");
- *  AUGMENT_LOG(W, "value: %d", value);
- *
- * AUGMENT_LOG_IF(D, value < 0, "negative");
- * AUGMENT_LOG_IF(E, value < 0, "bad value: %d", value);
- */
-
-#define AUGMENT_LOG(level, ...)                                                              \
-    ALOG##level("[%s] %s: " __android_second(0, __VA_ARGS__, ""), getInstanceName().c_str(), \
-                __func__ __android_rest(__VA_ARGS__))
-
-#define AUGMENT_LOG_IF(level, cond, ...)                                     \
-    ALOG##level##_IF(cond, "[%s] %s: " __android_second(0, __VA_ARGS__, ""), \
-                     getInstanceName().c_str(), __func__ __android_rest(__VA_ARGS__))
-// Used to register an entry into the function
-#define LOG_ENTRY() ALOGD("[%s] %s", getInstanceName().c_str(), __func__)
-
-// entry logging as verbose level
-#define LOG_ENTRY_V() ALOGV("[%s] %s", getInstanceName().c_str(), __func__)
-
 class HalDeathHandler {
   public:
     static HalDeathHandler& getInstance();
diff --git a/media/libaudiohal/impl/ConversionHelperAidl.h b/media/libaudiohal/impl/ConversionHelperAidl.h
index 2d19bee..fe00fb2 100644
--- a/media/libaudiohal/impl/ConversionHelperAidl.h
+++ b/media/libaudiohal/impl/ConversionHelperAidl.h
@@ -32,6 +32,28 @@
 
 namespace android {
 
+/*
+ * Helper macro to add instance name, function name in logs
+ * classes should provide getInstanceName API to use these macros.
+ * print function names along with instance name.
+ *
+ * Usage:
+ *  AUGMENT_LOG(D);
+ *  AUGMENT_LOG(I, "hello!");
+ *  AUGMENT_LOG(W, "value: %d", value);
+ *
+ *  AUGMENT_LOG_IF(D, value < 0, "negative");
+ *  AUGMENT_LOG_IF(E, value < 0, "bad value: %d", value);
+ */
+
+#define AUGMENT_LOG(level, ...)                                                  \
+    ALOG##level("[%s] %s" __VA_OPT__(": " __android_second(0, __VA_ARGS__, "")), \
+                getInstanceName().c_str(), __func__ __VA_OPT__(__android_rest(__VA_ARGS__)))
+
+#define AUGMENT_LOG_IF(level, cond, ...)                                                    \
+    ALOG##level##_IF(cond, "[%s] %s" __VA_OPT__(": " __android_second(0, __VA_ARGS__, "")), \
+                     getInstanceName().c_str(), __func__ __VA_OPT__(__android_rest(__VA_ARGS__)))
+
 class Args {
   public:
     explicit Args(const Vector<String16>& args)
diff --git a/media/libaudiohal/impl/DeviceHalAidl.cpp b/media/libaudiohal/impl/DeviceHalAidl.cpp
index f301a77..f279281 100644
--- a/media/libaudiohal/impl/DeviceHalAidl.cpp
+++ b/media/libaudiohal/impl/DeviceHalAidl.cpp
@@ -140,7 +140,7 @@
 }
 
 status_t DeviceHalAidl::getSupportedModes(std::vector<media::audio::common::AudioMode> *modes) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     RETURN_IF_TELEPHONY_NOT_INIT(INVALID_OPERATION);
@@ -164,7 +164,7 @@
 }
 
 status_t DeviceHalAidl::initCheck() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     std::lock_guard l(mLock);
@@ -196,7 +196,7 @@
 }
 
 status_t DeviceHalAidl::getMasterVolume(float *volume) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     if (volume == nullptr) {
@@ -227,7 +227,7 @@
 }
 
 status_t DeviceHalAidl::getMicMute(bool *state) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -247,7 +247,7 @@
 }
 
 status_t DeviceHalAidl::getMasterMute(bool *state) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -306,7 +306,7 @@
 }
 
 status_t DeviceHalAidl::getInputBufferSize(struct audio_config* config, size_t* size) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -462,6 +462,7 @@
         sp<StreamOutHalInterface>* outStream,
         const std::vector<playback_track_metadata_v7_t>& sourceMetadata) {
     AUGMENT_LOG(D, "handle: %d devices %0x flags %0x", handle, devices, flags);
+
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     if (outStream == nullptr || config == nullptr) {
@@ -611,7 +612,7 @@
 }
 
 status_t DeviceHalAidl::supportsAudioPatches(bool* supportsPatches) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     if (supportsPatches == nullptr) {
         AUGMENT_LOG(E, "uninitialized supportsPatches");
@@ -727,7 +728,7 @@
 }
 
 status_t DeviceHalAidl::getAudioPort(struct audio_port* port) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     if (port == nullptr) {
         AUGMENT_LOG(E, "port not initialized");
@@ -740,7 +741,7 @@
 }
 
 status_t DeviceHalAidl::getAudioPort(struct audio_port_v7 *port) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -772,7 +773,7 @@
 
 status_t DeviceHalAidl::getAudioMixPort(const struct audio_port_v7 *devicePort,
                                         struct audio_port_v7 *mixPort) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
 
@@ -796,7 +797,7 @@
 }
 
 status_t DeviceHalAidl::setAudioPortConfig(const struct audio_port_config* config) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -815,7 +816,7 @@
 }
 
 MicrophoneInfoProvider::Info const* DeviceHalAidl::getMicrophoneInfo() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT({});
@@ -842,7 +843,7 @@
 
 status_t DeviceHalAidl::getMicrophones(
         std::vector<audio_microphone_characteristic_t>* microphones) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -866,7 +867,7 @@
 
 status_t DeviceHalAidl::addDeviceEffect(
         const struct audio_port_config *device, sp<EffectHalInterface> effect) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -899,7 +900,7 @@
 }
 status_t DeviceHalAidl::removeDeviceEffect(
         const struct audio_port_config *device, sp<EffectHalInterface> effect) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     if (device == nullptr || effect == nullptr) {
@@ -931,7 +932,7 @@
 status_t DeviceHalAidl::getMmapPolicyInfos(
         media::audio::common::AudioMMapPolicyType policyType,
         std::vector<media::audio::common::AudioMMapPolicyInfo>* policyInfos) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -953,7 +954,7 @@
 }
 
 int32_t DeviceHalAidl::getAAudioMixerBurstCount() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -965,7 +966,7 @@
 }
 
 int32_t DeviceHalAidl::getAAudioHardwareBurstMinUsec() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -977,7 +978,7 @@
 }
 
 error::Result<audio_hw_sync_t> DeviceHalAidl::getHwAvSync() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -994,7 +995,7 @@
 }
 
 status_t DeviceHalAidl::supportsBluetoothVariableLatency(bool* supports) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
 
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
@@ -1006,7 +1007,7 @@
 
 status_t DeviceHalAidl::getSoundDoseInterface([[maybe_unused]] const std::string& module,
                                               ::ndk::SpAIBinder* soundDoseBinder) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
 
     if (soundDoseBinder == nullptr) {
@@ -1028,7 +1029,7 @@
 }
 
 status_t DeviceHalAidl::prepareToDisconnectExternalDevice(const struct audio_port_v7* port) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     if (port == nullptr) {
@@ -1067,7 +1068,7 @@
 }
 
 status_t DeviceHalAidl::setConnectedState(const struct audio_port_v7 *port, bool connected) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     if (port == nullptr) {
@@ -1099,7 +1100,7 @@
 }
 
 status_t DeviceHalAidl::setSimulateDeviceConnections(bool enabled) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     TIME_CHECK();
     RETURN_IF_MODULE_NOT_INIT(NO_INIT);
     {
diff --git a/media/libaudiohal/impl/StreamHalAidl.cpp b/media/libaudiohal/impl/StreamHalAidl.cpp
index 8a15e7a..01ebe1b 100644
--- a/media/libaudiohal/impl/StreamHalAidl.cpp
+++ b/media/libaudiohal/impl/StreamHalAidl.cpp
@@ -89,7 +89,7 @@
                            mContext.getBufferDurationMs(mConfig.sample_rate))
                   * NANOS_PER_MILLISECOND)
 {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     {
         std::lock_guard l(mLock);
         mLastReply.latencyMs = nominalLatency;
@@ -104,7 +104,7 @@
 }
 
 StreamHalAidl::~StreamHalAidl() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     if (mStream != nullptr) {
         ndk::ScopedAStatus status = mStream->close();
         AUGMENT_LOG_IF(E, !status.isOk(), "status %s", status.getDescription().c_str());
@@ -112,7 +112,7 @@
 }
 
 status_t StreamHalAidl::getBufferSize(size_t *size) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     if (size == nullptr) {
         return BAD_VALUE;
     }
@@ -126,7 +126,7 @@
 }
 
 status_t StreamHalAidl::getAudioProperties(audio_config_base_t *configBase) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     if (configBase == nullptr) {
         return BAD_VALUE;
     }
@@ -136,7 +136,7 @@
 }
 
 status_t StreamHalAidl::setParameters(const String8& kvPairs) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     AudioParameter parameters(kvPairs);
@@ -151,7 +151,7 @@
 }
 
 status_t StreamHalAidl::getParameters(const String8& keys __unused, String8 *values) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (values == nullptr) {
@@ -163,7 +163,7 @@
 }
 
 status_t StreamHalAidl::getFrameSize(size_t *size) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     if (size == nullptr) {
         return BAD_VALUE;
     }
@@ -175,7 +175,7 @@
 }
 
 status_t StreamHalAidl::addEffect(sp<EffectHalInterface> effect) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (effect == nullptr) {
@@ -186,7 +186,7 @@
 }
 
 status_t StreamHalAidl::removeEffect(sp<EffectHalInterface> effect) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (effect == nullptr) {
@@ -197,7 +197,7 @@
 }
 
 status_t StreamHalAidl::standby() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     const auto state = getState();
@@ -245,7 +245,7 @@
 }
 
 status_t StreamHalAidl::dump(int fd, const Vector<String16>& args) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     status_t status = mStream->dump(fd, Args(args).args(), args.size());
@@ -254,7 +254,7 @@
 }
 
 status_t StreamHalAidl::start() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (!mContext.isMmapped()) {
@@ -300,7 +300,7 @@
 }
 
 status_t StreamHalAidl::stop() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (!mContext.isMmapped()) {
@@ -325,7 +325,7 @@
 }
 
 status_t StreamHalAidl::getLatency(uint32_t *latency) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     if (!mStream) return NO_INIT;
     StreamDescriptor::Reply reply;
     RETURN_STATUS_IF_ERROR(updateCountersIfNeeded(&reply));
@@ -338,7 +338,7 @@
 
 status_t StreamHalAidl::getObservablePosition(int64_t* frames, int64_t* timestamp,
         StatePositions* statePositions) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     if (!mStream) return NO_INIT;
     StreamDescriptor::Reply reply;
     RETURN_STATUS_IF_ERROR(updateCountersIfNeeded(&reply, statePositions));
@@ -348,7 +348,7 @@
 }
 
 status_t StreamHalAidl::getHardwarePosition(int64_t *frames, int64_t *timestamp) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     if (!mStream) return NO_INIT;
     StreamDescriptor::Reply reply;
     RETURN_STATUS_IF_ERROR(updateCountersIfNeeded(&reply));
@@ -358,7 +358,7 @@
 }
 
 status_t StreamHalAidl::getXruns(int32_t *frames) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     if (!mStream) return NO_INIT;
     StreamDescriptor::Reply reply;
     RETURN_STATUS_IF_ERROR(updateCountersIfNeeded(&reply));
@@ -367,7 +367,7 @@
 }
 
 status_t StreamHalAidl::transfer(void *buffer, size_t bytes, size_t *transferred) {
-    LOG_ENTRY_V();
+    AUGMENT_LOG(V);
     // TIME_CHECK();  // TODO(b/243839867) reenable only when optimized.
     if (!mStream || mContext.getDataMQ() == nullptr) return NO_INIT;
     mWorkerTid.store(gettid(), std::memory_order_release);
@@ -418,7 +418,7 @@
 }
 
 status_t StreamHalAidl::pause(StreamDescriptor::Reply* reply) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
 
@@ -434,7 +434,7 @@
 }
 
 status_t StreamHalAidl::resume(StreamDescriptor::Reply* reply) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (mIsInput) {
@@ -471,7 +471,7 @@
 }
 
 status_t StreamHalAidl::drain(bool earlyNotify, StreamDescriptor::Reply* reply) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     return sendCommand(makeHalCommand<HalCommand::Tag::drain>(
@@ -482,7 +482,7 @@
 }
 
 status_t StreamHalAidl::flush(StreamDescriptor::Reply* reply) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
 
@@ -501,7 +501,7 @@
 }
 
 status_t StreamHalAidl::exit() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     return statusTFromBinderStatus(mStream->prepareToClose());
@@ -541,7 +541,7 @@
 
 status_t StreamHalAidl::createMmapBuffer(int32_t minSizeFrames __unused,
                                          struct audio_mmap_buffer_info *info) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (!mContext.isMmapped()) {
@@ -779,7 +779,7 @@
 }
 
 status_t StreamOutHalAidl::setCallback(wp<StreamOutHalInterfaceCallback> callback) {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     TIME_CHECK();
     if (!mStream) return NO_INIT;
     if (!mContext.isAsynchronous()) {
@@ -855,7 +855,7 @@
 }
 
 status_t StreamOutHalAidl::presentationComplete() {
-    LOG_ENTRY();
+    AUGMENT_LOG(D);
     return OK;
 }