Merge "nblog: split NBLog.cpp into multiple files"
diff --git a/camera/CameraMetadata.cpp b/camera/CameraMetadata.cpp
index e143e05..92fe84b 100644
--- a/camera/CameraMetadata.cpp
+++ b/camera/CameraMetadata.cpp
@@ -22,7 +22,6 @@
 
 #include <binder/Parcel.h>
 #include <camera/CameraMetadata.h>
-#include <camera/VendorTagDescriptor.h>
 
 namespace android {
 
@@ -409,6 +408,79 @@
     return res;
 }
 
+status_t CameraMetadata::removePermissionEntries(metadata_vendor_id_t vendorId,
+        std::vector<int32_t> *tagsRemoved) {
+    uint32_t tagCount = 0;
+    std::vector<uint32_t> tagsToRemove;
+
+    if (tagsRemoved == nullptr) {
+        return BAD_VALUE;
+    }
+
+    sp<VendorTagDescriptor> vTags = VendorTagDescriptor::getGlobalVendorTagDescriptor();
+    if ((nullptr == vTags.get()) || (0 >= vTags->getTagCount())) {
+        sp<VendorTagDescriptorCache> cache =
+            VendorTagDescriptorCache::getGlobalVendorTagCache();
+        if (cache.get()) {
+            cache->getVendorTagDescriptor(vendorId, &vTags);
+        }
+    }
+
+    if ((nullptr != vTags.get()) && (vTags->getTagCount() > 0)) {
+        tagCount = vTags->getTagCount();
+        uint32_t *vendorTags = new uint32_t[tagCount];
+        if (nullptr == vendorTags) {
+            return NO_MEMORY;
+        }
+        vTags->getTagArray(vendorTags);
+
+        tagsToRemove.reserve(tagCount);
+        tagsToRemove.insert(tagsToRemove.begin(), vendorTags, vendorTags + tagCount);
+
+        delete [] vendorTags;
+        tagCount = 0;
+    }
+
+    auto tagsNeedingPermission = get_camera_metadata_permission_needed(&tagCount);
+    if (tagCount > 0) {
+        tagsToRemove.reserve(tagsToRemove.capacity() + tagCount);
+        tagsToRemove.insert(tagsToRemove.end(), tagsNeedingPermission,
+                tagsNeedingPermission + tagCount);
+    }
+
+    tagsRemoved->reserve(tagsToRemove.size());
+    for (const auto &it : tagsToRemove) {
+        if (exists(it)) {
+            auto rc = erase(it);
+            if (NO_ERROR != rc) {
+                ALOGE("%s: Failed to erase tag: %x", __func__, it);
+                return rc;
+            }
+            tagsRemoved->push_back(it);
+        }
+    }
+
+    // Update the available characterstics accordingly
+    if (exists(ANDROID_REQUEST_AVAILABLE_CHARACTERISTICS_KEYS)) {
+        std::vector<uint32_t> currentKeys;
+
+        std::sort(tagsRemoved->begin(), tagsRemoved->end());
+        auto keys = find(ANDROID_REQUEST_AVAILABLE_CHARACTERISTICS_KEYS);
+        currentKeys.reserve(keys.count);
+        currentKeys.insert(currentKeys.end(), keys.data.i32, keys.data.i32 + keys.count);
+        std::sort(currentKeys.begin(), currentKeys.end());
+
+        std::vector<int32_t> newKeys(keys.count);
+        auto end = std::set_difference(currentKeys.begin(), currentKeys.end(), tagsRemoved->begin(),
+                tagsRemoved->end(), newKeys.begin());
+        newKeys.resize(end - newKeys.begin());
+
+        update(ANDROID_REQUEST_AVAILABLE_CHARACTERISTICS_KEYS, newKeys.data(), newKeys.size());
+    }
+
+    return NO_ERROR;
+}
+
 void CameraMetadata::dump(int fd, int verbosity, int indentation) const {
     dump_indented_camera_metadata(mBuffer, fd, verbosity, indentation);
 }
diff --git a/camera/aidl/android/hardware/ICameraService.aidl b/camera/aidl/android/hardware/ICameraService.aidl
index 9c0f28b..c038314 100644
--- a/camera/aidl/android/hardware/ICameraService.aidl
+++ b/camera/aidl/android/hardware/ICameraService.aidl
@@ -149,8 +149,10 @@
     const int API_VERSION_1 = 1;
     const int API_VERSION_2 = 2;
 
-    // Determines if a particular API version is supported directly
+    // Determines if a particular API version is supported directly for a cameraId.
     boolean supportsCameraApi(String cameraId, int apiVersion);
+    // Determines if a cameraId is a hidden physical camera of a logical multi-camera.
+    boolean isHiddenPhysicalCamera(String cameraId);
 
     void setTorchMode(String cameraId, boolean enabled, IBinder clientBinder);
 
diff --git a/camera/include/camera/CameraMetadata.h b/camera/include/camera/CameraMetadata.h
index d284477..844bb80 100644
--- a/camera/include/camera/CameraMetadata.h
+++ b/camera/include/camera/CameraMetadata.h
@@ -22,6 +22,7 @@
 #include <utils/String8.h>
 #include <utils/Vector.h>
 #include <binder/Parcelable.h>
+#include <camera/VendorTagDescriptor.h>
 
 namespace android {
 
@@ -170,6 +171,12 @@
     status_t erase(uint32_t tag);
 
     /**
+     * Remove metadata entries that need additional permissions.
+     */
+    status_t removePermissionEntries(metadata_vendor_id_t vendorId,
+            std::vector<int32_t> *tagsRemoved /*out*/);
+
+    /**
      * Swap the underlying camera metadata between this and the other
      * metadata object.
      */
diff --git a/camera/ndk/include/camera/NdkCameraMetadataTags.h b/camera/ndk/include/camera/NdkCameraMetadataTags.h
index c1f5ddc..6ebd850 100644
--- a/camera/ndk/include/camera/NdkCameraMetadataTags.h
+++ b/camera/ndk/include/camera/NdkCameraMetadataTags.h
@@ -7209,8 +7209,14 @@
     ACAMERA_REQUEST_AVAILABLE_CAPABILITIES_MOTION_TRACKING           = 10,
 
     /**
-     * <p>The camera device is a logical camera backed by two or more physical cameras that are
-     * also exposed to the application.</p>
+     * <p>The camera device is a logical camera backed by two or more physical cameras. In
+     * API level 28, the physical cameras must also be exposed to the application via
+     * <a href="https://developer.android.com/reference/android/hardware/camera2/CameraManager.html#getCameraIdList">CameraManager#getCameraIdList</a>. Starting from API
+     * level 29, some or all physical cameras may not be independently exposed to the
+     * application, in which case the physical camera IDs will not be available in
+     * <a href="https://developer.android.com/reference/android/hardware/camera2/CameraManager.html#getCameraIdList">CameraManager#getCameraIdList</a>. But the application
+     * can still query the physical cameras' characteristics by calling
+     * <a href="https://developer.android.com/reference/android/hardware/camera2/CameraManager.html#getCameraCharacteristics">CameraManager#getCameraCharacteristics</a>.</p>
      * <p>Camera application shouldn't assume that there are at most 1 rear camera and 1 front
      * camera in the system. For an application that switches between front and back cameras,
      * the recommendation is to switch between the first rear camera and the first front
diff --git a/camera/tests/Android.mk b/camera/tests/Android.mk
index 659484f..e5c1631 100644
--- a/camera/tests/Android.mk
+++ b/camera/tests/Android.mk
@@ -19,7 +19,8 @@
 LOCAL_SRC_FILES:= \
 	VendorTagDescriptorTests.cpp \
 	CameraBinderTests.cpp \
-	CameraZSLTests.cpp
+	CameraZSLTests.cpp \
+	CameraCharacteristicsPermission.cpp
 
 LOCAL_SHARED_LIBRARIES := \
 	liblog \
diff --git a/camera/tests/CameraCharacteristicsPermission.cpp b/camera/tests/CameraCharacteristicsPermission.cpp
new file mode 100644
index 0000000..135d2a3
--- /dev/null
+++ b/camera/tests/CameraCharacteristicsPermission.cpp
@@ -0,0 +1,96 @@
+/*
+ * Copyright (C) 2018 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#define LOG_NDEBUG 0
+#define LOG_TAG "CameraCharacteristicsPermission"
+
+#include <gtest/gtest.h>
+
+#include <binder/ProcessState.h>
+#include <utils/Errors.h>
+#include <utils/Log.h>
+#include <camera/CameraMetadata.h>
+#include <camera/Camera.h>
+#include <android/hardware/ICameraService.h>
+
+using namespace android;
+using namespace android::hardware;
+
+class CameraCharacteristicsPermission : public ::testing::Test {
+protected:
+
+    CameraCharacteristicsPermission() : numCameras(0){}
+    //Gtest interface
+    void SetUp() override;
+    void TearDown() override;
+
+    int32_t numCameras;
+    sp<ICameraService> mCameraService;
+};
+
+void CameraCharacteristicsPermission::SetUp() {
+    ::android::binder::Status rc;
+    ProcessState::self()->startThreadPool();
+    sp<IServiceManager> sm = defaultServiceManager();
+    sp<IBinder> binder = sm->getService(String16("media.camera"));
+    mCameraService = interface_cast<ICameraService>(binder);
+    rc = mCameraService->getNumberOfCameras(
+            hardware::ICameraService::CAMERA_TYPE_ALL, &numCameras);
+    EXPECT_TRUE(rc.isOk());
+}
+
+void CameraCharacteristicsPermission::TearDown() {
+    mCameraService.clear();
+}
+
+// Revoking and acquiring permissions automatically might not be possible.
+// Test the functionality for removal of camera characteristics needing
+// a camera permission.
+TEST_F(CameraCharacteristicsPermission, TestCameraPermission) {
+    for (int32_t cameraId = 0; cameraId < numCameras; cameraId++) {
+
+        String16 cameraIdStr = String16(String8::format("%d", cameraId));
+        bool isSupported = false;
+        auto rc = mCameraService->supportsCameraApi(cameraIdStr,
+                hardware::ICameraService::API_VERSION_2, &isSupported);
+        EXPECT_TRUE(rc.isOk());
+        if (!isSupported) {
+            continue;
+        }
+
+        CameraMetadata metadata;
+        std::vector<int32_t> tagsNeedingPermission;
+        rc = mCameraService->getCameraCharacteristics(cameraIdStr, &metadata);
+        ASSERT_TRUE(rc.isOk());
+        EXPECT_FALSE(metadata.isEmpty());
+        EXPECT_EQ(metadata.removePermissionEntries(CAMERA_METADATA_INVALID_VENDOR_ID,
+                    &tagsNeedingPermission), NO_ERROR);
+        camera_metadata_entry_t availableCharacteristics =
+                metadata.find(ANDROID_REQUEST_AVAILABLE_CHARACTERISTICS_KEYS);
+        EXPECT_TRUE(0 < availableCharacteristics.count);
+
+        std::vector<uint32_t> availableKeys;
+        availableKeys.reserve(availableCharacteristics.count);
+        availableKeys.insert(availableKeys.begin(), availableCharacteristics.data.i32,
+                availableCharacteristics.data.i32 + availableCharacteristics.count);
+
+        for (const auto &key : tagsNeedingPermission) {
+            ASSERT_FALSE(metadata.exists(key));
+            auto it = std::find(availableKeys.begin(), availableKeys.end(), key);
+            ASSERT_TRUE(it == availableKeys.end());
+        }
+    }
+}
diff --git a/media/libaudioclient/AudioRecord.cpp b/media/libaudioclient/AudioRecord.cpp
index e2de8e7..17f17a3 100644
--- a/media/libaudioclient/AudioRecord.cpp
+++ b/media/libaudioclient/AudioRecord.cpp
@@ -48,8 +48,9 @@
     size_t size;
     status_t status = AudioSystem::getInputBufferSize(sampleRate, format, channelMask, &size);
     if (status != NO_ERROR) {
-        ALOGE("AudioSystem could not query the input buffer size for sampleRate %u, format %#x, "
-              "channelMask %#x; status %d", sampleRate, format, channelMask, status);
+        ALOGE("%s(): AudioSystem could not query the input buffer size for"
+              " sampleRate %u, format %#x, channelMask %#x; status %d",
+               __func__, sampleRate, format, channelMask, status);
         return status;
     }
 
@@ -57,8 +58,8 @@
     // Assumes audio_is_linear_pcm(format)
     if ((*frameCount = (size * 2) / (audio_channel_count_from_in_mask(channelMask) *
             audio_bytes_per_sample(format))) == 0) {
-        ALOGE("Unsupported configuration: sampleRate %u, format %#x, channelMask %#x",
-            sampleRate, format, channelMask);
+        ALOGE("%s(): Unsupported configuration: sampleRate %u, format %#x, channelMask %#x",
+                __func__, sampleRate, format, channelMask);
         return BAD_VALUE;
     }
 
@@ -208,8 +209,8 @@
         mCblkMemory.clear();
         mBufferMemory.clear();
         IPCThreadState::self()->flushCommands();
-        ALOGV("~AudioRecord, releasing session id %d",
-                mSessionId);
+        ALOGV("%s(%d): releasing session id %d",
+                __func__, mId, mSessionId);
         AudioSystem::releaseAudioSessionId(mSessionId, -1 /*pid*/);
     }
 }
@@ -237,9 +238,11 @@
     pid_t callingPid;
     pid_t myPid;
 
-    ALOGV("set(): inputSource %d, sampleRate %u, format %#x, channelMask %#x, frameCount %zu, "
+    // Note mId is not valid until the track is created, so omit mId in ALOG for set.
+    ALOGV("%s(): inputSource %d, sampleRate %u, format %#x, channelMask %#x, frameCount %zu, "
           "notificationFrames %u, sessionId %d, transferType %d, flags %#x, opPackageName %s "
           "uid %d, pid %d",
+          __func__,
           inputSource, sampleRate, format, channelMask, frameCount, notificationFrames,
           sessionId, transferType, flags, String8(mOpPackageName).string(), uid, pid);
 
@@ -255,7 +258,7 @@
         break;
     case TRANSFER_CALLBACK:
         if (cbf == NULL) {
-            ALOGE("Transfer type TRANSFER_CALLBACK but cbf == NULL");
+            ALOGE("%s(): Transfer type TRANSFER_CALLBACK but cbf == NULL", __func__);
             status = BAD_VALUE;
             goto exit;
         }
@@ -264,7 +267,7 @@
     case TRANSFER_SYNC:
         break;
     default:
-        ALOGE("Invalid transfer type %d", transferType);
+        ALOGE("%s(): Invalid transfer type %d", __func__, transferType);
         status = BAD_VALUE;
         goto exit;
     }
@@ -272,7 +275,7 @@
 
     // invariant that mAudioRecord != 0 is true only after set() returns successfully
     if (mAudioRecord != 0) {
-        ALOGE("Track already in use");
+        ALOGE("%s(): Track already in use", __func__);
         status = INVALID_OPERATION;
         goto exit;
     }
@@ -283,8 +286,8 @@
     } else {
         // stream type shouldn't be looked at, this track has audio attributes
         memcpy(&mAttributes, pAttributes, sizeof(audio_attributes_t));
-        ALOGV("Building AudioRecord with attributes: source=%d flags=0x%x tags=[%s]",
-              mAttributes.source, mAttributes.flags, mAttributes.tags);
+        ALOGV("%s(): Building AudioRecord with attributes: source=%d flags=0x%x tags=[%s]",
+                __func__, mAttributes.source, mAttributes.flags, mAttributes.tags);
     }
 
     mSampleRate = sampleRate;
@@ -297,14 +300,14 @@
     // validate parameters
     // AudioFlinger capture only supports linear PCM
     if (!audio_is_valid_format(format) || !audio_is_linear_pcm(format)) {
-        ALOGE("Format %#x is not linear pcm", format);
+        ALOGE("%s(): Format %#x is not linear pcm", __func__, format);
         status = BAD_VALUE;
         goto exit;
     }
     mFormat = format;
 
     if (!audio_is_input_channel(channelMask)) {
-        ALOGE("Invalid channel mask %#x", channelMask);
+        ALOGE("%s(): Invalid channel mask %#x", __func__, channelMask);
         status = BAD_VALUE;
         goto exit;
     }
@@ -325,7 +328,7 @@
     // mNotificationFramesAct is initialized in createRecord_l
 
     mSessionId = sessionId;
-    ALOGV("set(): mSessionId %d", mSessionId);
+    ALOGV("%s(): mSessionId %d", __func__, mSessionId);
 
     callingPid = IPCThreadState::self()->getCallingPid();
     myPid = getpid();
@@ -352,6 +355,8 @@
     // create the IAudioRecord
     status = createRecord_l(0 /*epoch*/, mOpPackageName);
 
+    ALOGV("%s(%d): status %d", __func__, mId, status);
+
     if (status != NO_ERROR) {
         if (mAudioRecordThread != 0) {
             mAudioRecordThread->requestExit();   // see comment in AudioRecord.h
@@ -387,7 +392,7 @@
 
 status_t AudioRecord::start(AudioSystem::sync_event_t event, audio_session_t triggerSession)
 {
-    ALOGV("start, sync event %d trigger session %d", event, triggerSession);
+    ALOGV("%s(%d): sync event %d trigger session %d", __func__, mId, event, triggerSession);
 
     AutoMutex lock(mLock);
     if (mActive) {
@@ -428,7 +433,7 @@
 
     if (status != NO_ERROR) {
         mActive = false;
-        ALOGE("start() status %d", status);
+        ALOGE("%s(%d): status %d", __func__, mId, status);
     } else {
         sp<AudioRecordThread> t = mAudioRecordThread;
         if (t != 0) {
@@ -452,6 +457,7 @@
 void AudioRecord::stop()
 {
     AutoMutex lock(mLock);
+    ALOGV("%s(%d): mActive:%d\n", __func__, mId, mActive);
     if (!mActive) {
         return;
     }
@@ -630,8 +636,8 @@
     String8 result;
 
     result.append(" AudioRecord::dump\n");
-    result.appendFormat("  status(%d), active(%d), session Id(%d)\n",
-                        mStatus, mActive, mSessionId);
+    result.appendFormat("  id(%d) status(%d), active(%d), session Id(%d)\n",
+                        mId, mStatus, mActive, mSessionId);
     result.appendFormat("  flags(%#x), req. flags(%#x), audio source(%d)\n",
                         mFlags, mOrigFlags, mAttributes.source);
     result.appendFormat("  format(%#x), channel mask(%#x), channel count(%u), sample rate(%u)\n",
@@ -673,7 +679,7 @@
     status_t status;
 
     if (audioFlinger == 0) {
-        ALOGE("Could not get audioflinger");
+        ALOGE("%s(%d): Could not get audioflinger", __func__, mId);
         status = NO_INIT;
         goto exit;
     }
@@ -700,7 +706,8 @@
             // use case 3: obtain/release mode
             (mTransfer == TRANSFER_OBTAIN);
         if (!useCaseAllowed) {
-            ALOGW("AUDIO_INPUT_FLAG_FAST denied, incompatible transfer = %s",
+            ALOGW("%s(%d): AUDIO_INPUT_FLAG_FAST denied, incompatible transfer = %s",
+                  __func__, mId,
                   convertTransferToText(mTransfer));
             mFlags = (audio_input_flags_t) (mFlags & ~(AUDIO_INPUT_FLAG_FAST |
                     AUDIO_INPUT_FLAG_RAW));
@@ -735,7 +742,8 @@
                                                               &status);
 
     if (status != NO_ERROR) {
-        ALOGE("AudioFlinger could not create record track, status: %d", status);
+        ALOGE("%s(%d): AudioFlinger could not create record track, status: %d",
+              __func__, mId, status);
         goto exit;
     }
     ALOG_ASSERT(record != 0);
@@ -745,7 +753,8 @@
 
     mAwaitBoost = false;
     if (output.flags & AUDIO_INPUT_FLAG_FAST) {
-        ALOGI("AUDIO_INPUT_FLAG_FAST successful; frameCount %zu -> %zu",
+        ALOGI("%s(%d): AUDIO_INPUT_FLAG_FAST successful; frameCount %zu -> %zu",
+              __func__, mId,
               mReqFrameCount, output.frameCount);
         mAwaitBoost = true;
     }
@@ -755,13 +764,13 @@
     mSampleRate = output.sampleRate;
 
     if (output.cblk == 0) {
-        ALOGE("Could not get control block");
+        ALOGE("%s(%d): Could not get control block", __func__, mId);
         status = NO_INIT;
         goto exit;
     }
     iMemPointer = output.cblk ->pointer();
     if (iMemPointer == NULL) {
-        ALOGE("Could not get control block pointer");
+        ALOGE("%s(%d): Could not get control block pointer", __func__, mId);
         status = NO_INIT;
         goto exit;
     }
@@ -776,7 +785,7 @@
     } else {
         buffers = output.buffers->pointer();
         if (buffers == NULL) {
-            ALOGE("Could not get buffer pointer");
+            ALOGE("%s(%d): Could not get buffer pointer", __func__, mId);
             status = NO_INIT;
             goto exit;
         }
@@ -790,19 +799,22 @@
     mAudioRecord = record;
     mCblkMemory = output.cblk;
     mBufferMemory = output.buffers;
+    mId = output.trackId;
     IPCThreadState::self()->flushCommands();
 
     mCblk = cblk;
     // note that output.frameCount is the (possibly revised) value of mReqFrameCount
     if (output.frameCount < mReqFrameCount || (mReqFrameCount == 0 && output.frameCount == 0)) {
-        ALOGW("Requested frameCount %zu but received frameCount %zu",
+        ALOGW("%s(%d): Requested frameCount %zu but received frameCount %zu",
+              __func__, mId,
               mReqFrameCount,  output.frameCount);
     }
 
     // Make sure that application is notified with sufficient margin before overrun.
     // The computation is done on server side.
     if (mNotificationFramesReq > 0 && output.notificationFrameCount != mNotificationFramesReq) {
-        ALOGW("Server adjusted notificationFrames from %u to %zu for frameCount %zu",
+        ALOGW("%s(%d): Server adjusted notificationFrames from %u to %zu for frameCount %zu",
+                __func__, mId,
                 mNotificationFramesReq, output.notificationFrameCount, output.frameCount);
     }
     mNotificationFramesAct = (uint32_t)output.notificationFrameCount;
@@ -870,7 +882,7 @@
         timeout.tv_nsec = (long) (ms % 1000) * 1000000;
         requested = &timeout;
     } else {
-        ALOGE("%s invalid waitCount %d", __func__, waitCount);
+        ALOGE("%s(%d): invalid waitCount %d", __func__, mId, waitCount);
         requested = NULL;
     }
     return obtainBuffer(audioBuffer, requested, NULL /*elapsed*/, nonContig);
@@ -979,7 +991,8 @@
     if (ssize_t(userSize) < 0 || (buffer == NULL && userSize != 0)) {
         // sanity-check. user is most-likely passing an error code, and it would
         // make the return value ambiguous (actualSize vs error).
-        ALOGE("AudioRecord::read(buffer=%p, size=%zu (%zu)", buffer, userSize, userSize);
+        ALOGE("%s(%d) (buffer=%p, size=%zu (%zu)",
+                __func__, mId, buffer, userSize, userSize);
         return BAD_VALUE;
     }
 
@@ -1036,7 +1049,7 @@
             pollUs <<= 1;
         } while (tryCounter-- > 0);
         if (tryCounter < 0) {
-            ALOGE("did not receive expected priority boost on time");
+            ALOGE("%s(%d): did not receive expected priority boost on time", __func__, mId);
         }
         // Run again immediately
         return 0;
@@ -1159,7 +1172,8 @@
     if (ns != NS_WHENEVER) {
         timeout.tv_sec = ns / 1000000000LL;
         timeout.tv_nsec = ns % 1000000000LL;
-        ALOGV("timeout %ld.%03d", timeout.tv_sec, (int) timeout.tv_nsec / 1000000);
+        ALOGV("%s(%d): timeout %ld.%03d",
+                __func__, mId, timeout.tv_sec, (int) timeout.tv_nsec / 1000000);
         requested = &timeout;
     }
 
@@ -1171,16 +1185,18 @@
         size_t nonContig;
         status_t err = obtainBuffer(&audioBuffer, requested, NULL, &nonContig);
         LOG_ALWAYS_FATAL_IF((err != NO_ERROR) != (audioBuffer.frameCount == 0),
-                "obtainBuffer() err=%d frameCount=%zu", err, audioBuffer.frameCount);
+                "%s(%d): obtainBuffer() err=%d frameCount=%zu",
+                __func__, mId, err, audioBuffer.frameCount);
         requested = &ClientProxy::kNonBlocking;
         size_t avail = audioBuffer.frameCount + nonContig;
-        ALOGV("obtainBuffer(%u) returned %zu = %zu + %zu err %d",
-                mRemainingFrames, avail, audioBuffer.frameCount, nonContig, err);
+        ALOGV("%s(%d): obtainBuffer(%u) returned %zu = %zu + %zu err %d",
+                __func__, mId, mRemainingFrames, avail, audioBuffer.frameCount, nonContig, err);
         if (err != NO_ERROR) {
             if (err == TIMED_OUT || err == WOULD_BLOCK || err == -EINTR) {
                 break;
             }
-            ALOGE("Error %d obtaining an audio buffer, giving up.", err);
+            ALOGE("%s(%d): Error %d obtaining an audio buffer, giving up.",
+                    __func__, mId, err);
             return NS_NEVER;
         }
 
@@ -1202,8 +1218,8 @@
 
         // Sanity check on returned size
         if (ssize_t(readSize) < 0 || readSize > reqSize) {
-            ALOGE("EVENT_MORE_DATA requested %zu bytes but callback returned %zd bytes",
-                    reqSize, ssize_t(readSize));
+            ALOGE("%s(%d):  EVENT_MORE_DATA requested %zu bytes but callback returned %zd bytes",
+                    __func__, mId, reqSize, ssize_t(readSize));
             return NS_NEVER;
         }
 
@@ -1263,7 +1279,7 @@
 
 status_t AudioRecord::restoreRecord_l(const char *from)
 {
-    ALOGW("dead IAudioRecord, creating a new one from %s()", from);
+    ALOGW("%s(%d): dead IAudioRecord, creating a new one from %s()", __func__, mId, from);
     ++mSequence;
 
     const int INITIAL_RETRIES = 3;
@@ -1284,7 +1300,7 @@
     status_t result = createRecord_l(position, mOpPackageName);
 
     if (result != NO_ERROR) {
-        ALOGW("%s(): createRecord_l failed, do not retry", __func__);
+        ALOGW("%s(%d): createRecord_l failed, do not retry", __func__, mId);
         retries = 0;
     } else {
         if (mActive) {
@@ -1297,14 +1313,14 @@
     }
 
     if (result != NO_ERROR) {
-        ALOGW("%s() failed status %d, retries %d", __func__, result, retries);
+        ALOGW("%s(%d): failed status %d, retries %d", __func__, mId, result, retries);
         if (--retries > 0) {
             goto retry;
         }
     }
 
     if (result != NO_ERROR) {
-        ALOGW("restoreRecord_l() failed status %d", result);
+        ALOGW("%s(%d): failed status %d", __func__, mId, result);
         mActive = false;
     }
 
@@ -1314,18 +1330,18 @@
 status_t AudioRecord::addAudioDeviceCallback(const sp<AudioSystem::AudioDeviceCallback>& callback)
 {
     if (callback == 0) {
-        ALOGW("%s adding NULL callback!", __FUNCTION__);
+        ALOGW("%s(%d): adding NULL callback!", __func__, mId);
         return BAD_VALUE;
     }
     AutoMutex lock(mLock);
     if (mDeviceCallback.unsafe_get() == callback.get()) {
-        ALOGW("%s adding same callback!", __FUNCTION__);
+        ALOGW("%s(%d): adding same callback!", __func__, mId);
         return INVALID_OPERATION;
     }
     status_t status = NO_ERROR;
     if (mInput != AUDIO_IO_HANDLE_NONE) {
         if (mDeviceCallback != 0) {
-            ALOGW("%s callback already present!", __FUNCTION__);
+            ALOGW("%s(%d): callback already present!", __func__, mId);
             AudioSystem::removeAudioDeviceCallback(this, mInput);
         }
         status = AudioSystem::addAudioDeviceCallback(this, mInput);
@@ -1338,12 +1354,12 @@
         const sp<AudioSystem::AudioDeviceCallback>& callback)
 {
     if (callback == 0) {
-        ALOGW("%s removing NULL callback!", __FUNCTION__);
+        ALOGW("%s(%d): removing NULL callback!", __func__, mId);
         return BAD_VALUE;
     }
     AutoMutex lock(mLock);
     if (mDeviceCallback.unsafe_get() != callback.get()) {
-        ALOGW("%s removing different callback!", __FUNCTION__);
+        ALOGW("%s(%d): removing different callback!", __func__, mId);
         return INVALID_OPERATION;
     }
     mDeviceCallback.clear();
@@ -1448,7 +1464,7 @@
         ns = INT64_MAX;
         // fall through
     default:
-        LOG_ALWAYS_FATAL_IF(ns < 0, "processAudioBuffer() returned %" PRId64, ns);
+        LOG_ALWAYS_FATAL_IF(ns < 0, "%s() returned %lld", __func__, (long long)ns);
         pauseInternal(ns);
         return true;
     }
diff --git a/media/libaudioclient/AudioTrack.cpp b/media/libaudioclient/AudioTrack.cpp
index 76c9bfb..4e39585 100644
--- a/media/libaudioclient/AudioTrack.cpp
+++ b/media/libaudioclient/AudioTrack.cpp
@@ -119,22 +119,22 @@
     status_t status;
     status = AudioSystem::getOutputSamplingRate(&afSampleRate, streamType);
     if (status != NO_ERROR) {
-        ALOGE("Unable to query output sample rate for stream type %d; status %d",
-                streamType, status);
+        ALOGE("%s(): Unable to query output sample rate for stream type %d; status %d",
+                __func__, streamType, status);
         return status;
     }
     size_t afFrameCount;
     status = AudioSystem::getOutputFrameCount(&afFrameCount, streamType);
     if (status != NO_ERROR) {
-        ALOGE("Unable to query output frame count for stream type %d; status %d",
-                streamType, status);
+        ALOGE("%s(): Unable to query output frame count for stream type %d; status %d",
+                __func__, streamType, status);
         return status;
     }
     uint32_t afLatency;
     status = AudioSystem::getOutputLatency(&afLatency, streamType);
     if (status != NO_ERROR) {
-        ALOGE("Unable to query output latency for stream type %d; status %d",
-                streamType, status);
+        ALOGE("%s(): Unable to query output latency for stream type %d; status %d",
+                __func__, streamType, status);
         return status;
     }
 
@@ -147,12 +147,12 @@
     // AudioTrack.SAMPLE_RATE_HZ_MIN <= sampleRate <= AudioTrack.SAMPLE_RATE_HZ_MAX.
     // Return error in the unlikely event that it does not, as that's part of the API contract.
     if (*frameCount == 0) {
-        ALOGE("AudioTrack::getMinFrameCount failed for streamType %d, sampleRate %u",
-                streamType, sampleRate);
+        ALOGE("%s(): failed for streamType %d, sampleRate %u",
+                __func__, streamType, sampleRate);
         return BAD_VALUE;
     }
-    ALOGV("getMinFrameCount=%zu: afFrameCount=%zu, afSampleRate=%u, afLatency=%u",
-            *frameCount, afFrameCount, afSampleRate, afLatency);
+    ALOGV("%s(): getMinFrameCount=%zu: afFrameCount=%zu, afSampleRate=%u, afLatency=%u",
+            __func__, *frameCount, afFrameCount, afSampleRate, afLatency);
     return NO_ERROR;
 }
 
@@ -200,7 +200,7 @@
     // XXX: shall we gather alternative info if failing?
     const status_t lstatus = track->initCheck();
     if (lstatus != NO_ERROR) {
-        ALOGD("no metrics gathered, track status=%d", (int) lstatus);
+        ALOGD("%s(): no metrics gathered, track status=%d", __func__, (int) lstatus);
         return;
     }
 
@@ -342,7 +342,8 @@
         mCblkMemory.clear();
         mSharedBuffer.clear();
         IPCThreadState::self()->flushCommands();
-        ALOGV("~AudioTrack, releasing session id %d from %d on behalf of %d",
+        ALOGV("%s(%d), releasing session id %d from %d on behalf of %d",
+                __func__, mId,
                 mSessionId, IPCThreadState::self()->getCallingPid(), mClientPid);
         AudioSystem::releaseAudioSessionId(mSessionId, mClientPid);
     }
@@ -375,8 +376,10 @@
     pid_t callingPid;
     pid_t myPid;
 
-    ALOGV("set(): streamType %d, sampleRate %u, format %#x, channelMask %#x, frameCount %zu, "
+    // Note mId is not valid until the track is created, so omit mId in ALOG for set.
+    ALOGV("%s(): streamType %d, sampleRate %u, format %#x, channelMask %#x, frameCount %zu, "
           "flags #%x, notificationFrames %d, sessionId %d, transferType %d, uid %d, pid %d",
+          __func__,
           streamType, sampleRate, format, channelMask, frameCount, flags, notificationFrames,
           sessionId, transferType, uid, pid);
 
@@ -396,7 +399,8 @@
         break;
     case TRANSFER_CALLBACK:
         if (cbf == NULL || sharedBuffer != 0) {
-            ALOGE("Transfer type TRANSFER_CALLBACK but cbf == NULL || sharedBuffer != 0");
+            ALOGE("%s(): Transfer type TRANSFER_CALLBACK but cbf == NULL || sharedBuffer != 0",
+                    __func__);
             status = BAD_VALUE;
             goto exit;
         }
@@ -404,20 +408,21 @@
     case TRANSFER_OBTAIN:
     case TRANSFER_SYNC:
         if (sharedBuffer != 0) {
-            ALOGE("Transfer type TRANSFER_OBTAIN but sharedBuffer != 0");
+            ALOGE("%s(): Transfer type TRANSFER_OBTAIN but sharedBuffer != 0", __func__);
             status = BAD_VALUE;
             goto exit;
         }
         break;
     case TRANSFER_SHARED:
         if (sharedBuffer == 0) {
-            ALOGE("Transfer type TRANSFER_SHARED but sharedBuffer == 0");
+            ALOGE("%s(): Transfer type TRANSFER_SHARED but sharedBuffer == 0", __func__);
             status = BAD_VALUE;
             goto exit;
         }
         break;
     default:
-        ALOGE("Invalid transfer type %d", transferType);
+        ALOGE("%s(): Invalid transfer type %d",
+                __func__, transferType);
         status = BAD_VALUE;
         goto exit;
     }
@@ -425,14 +430,15 @@
     mTransfer = transferType;
     mDoNotReconnect = doNotReconnect;
 
-    ALOGV_IF(sharedBuffer != 0, "sharedBuffer: %p, size: %zu", sharedBuffer->pointer(),
-            sharedBuffer->size());
+    ALOGV_IF(sharedBuffer != 0, "%s(): sharedBuffer: %p, size: %zu",
+            __func__, sharedBuffer->pointer(), sharedBuffer->size());
 
-    ALOGV("set() streamType %d frameCount %zu flags %04x", streamType, frameCount, flags);
+    ALOGV("%s(): streamType %d frameCount %zu flags %04x",
+            __func__, streamType, frameCount, flags);
 
     // invariant that mAudioTrack != 0 is true only after set() returns successfully
     if (mAudioTrack != 0) {
-        ALOGE("Track already in use");
+        ALOGE("%s(): Track already in use", __func__);
         status = INVALID_OPERATION;
         goto exit;
     }
@@ -443,7 +449,7 @@
     }
     if (pAttributes == NULL) {
         if (uint32_t(streamType) >= AUDIO_STREAM_PUBLIC_CNT) {
-            ALOGE("Invalid stream type %d", streamType);
+            ALOGE("%s(): Invalid stream type %d", __func__, streamType);
             status = BAD_VALUE;
             goto exit;
         }
@@ -452,8 +458,10 @@
     } else {
         // stream type shouldn't be looked at, this track has audio attributes
         memcpy(&mAttributes, pAttributes, sizeof(audio_attributes_t));
-        ALOGV("Building AudioTrack with attributes: usage=%d content=%d flags=0x%x tags=[%s]",
-                mAttributes.usage, mAttributes.content_type, mAttributes.flags, mAttributes.tags);
+        ALOGV("%s(): Building AudioTrack with attributes:"
+                " usage=%d content=%d flags=0x%x tags=[%s]",
+                __func__,
+                 mAttributes.usage, mAttributes.content_type, mAttributes.flags, mAttributes.tags);
         mStreamType = AUDIO_STREAM_DEFAULT;
         if ((mAttributes.flags & AUDIO_FLAG_HW_AV_SYNC) != 0) {
             flags = (audio_output_flags_t)(flags | AUDIO_OUTPUT_FLAG_HW_AV_SYNC);
@@ -476,14 +484,14 @@
 
     // validate parameters
     if (!audio_is_valid_format(format)) {
-        ALOGE("Invalid format %#x", format);
+        ALOGE("%s(): Invalid format %#x", __func__, format);
         status = BAD_VALUE;
         goto exit;
     }
     mFormat = format;
 
     if (!audio_is_output_channel(channelMask)) {
-        ALOGE("Invalid channel mask %#x", channelMask);
+        ALOGE("%s(): Invalid channel mask %#x",  __func__, channelMask);
         status = BAD_VALUE;
         goto exit;
     }
@@ -496,8 +504,9 @@
     if ((flags & AUDIO_OUTPUT_FLAG_COMPRESS_OFFLOAD)
             || !audio_is_linear_pcm(format)) {
         ALOGV( (flags & AUDIO_OUTPUT_FLAG_COMPRESS_OFFLOAD)
-                    ? "Offload request, forcing to Direct Output"
-                    : "Not linear PCM, forcing to Direct Output");
+                    ? "%s(): Offload request, forcing to Direct Output"
+                    : "%s(): Not linear PCM, forcing to Direct Output",
+                    __func__);
         flags = (audio_output_flags_t)
                 // FIXME why can't we allow direct AND fast?
                 ((flags | AUDIO_OUTPUT_FLAG_DIRECT) & ~AUDIO_OUTPUT_FLAG_FAST);
@@ -553,14 +562,14 @@
         mNotificationsPerBufferReq = 0;
     } else {
         if (!(flags & AUDIO_OUTPUT_FLAG_FAST)) {
-            ALOGE("notificationFrames=%d not permitted for non-fast track",
-                    notificationFrames);
+            ALOGE("%s(): notificationFrames=%d not permitted for non-fast track",
+                    __func__, notificationFrames);
             status = BAD_VALUE;
             goto exit;
         }
         if (frameCount > 0) {
-            ALOGE("notificationFrames=%d not permitted with non-zero frameCount=%zu",
-                    notificationFrames, frameCount);
+            ALOGE("%s(): notificationFrames=%d not permitted with non-zero frameCount=%zu",
+                    __func__, notificationFrames, frameCount);
             status = BAD_VALUE;
             goto exit;
         }
@@ -570,7 +579,8 @@
         mNotificationsPerBufferReq = min(maxNotificationsPerBuffer,
                 max((uint32_t) -notificationFrames, minNotificationsPerBuffer));
         ALOGW_IF(mNotificationsPerBufferReq != (uint32_t) -notificationFrames,
-                "notificationFrames=%d clamped to the range -%u to -%u",
+                "%s(): notificationFrames=%d clamped to the range -%u to -%u",
+                __func__,
                 notificationFrames, minNotificationsPerBuffer, maxNotificationsPerBuffer);
     }
     mNotificationFramesAct = 0;
@@ -646,6 +656,7 @@
 status_t AudioTrack::start()
 {
     AutoMutex lock(mLock);
+    ALOGV("%s(%d): prior state:%s", __func__, mId, stateToString(mState));
 
     if (mState == STATE_ACTIVE) {
         return INVALID_OPERATION;
@@ -685,7 +696,8 @@
             // Server side has consumed something, but is it finished consuming?
             // It is possible since flush and stop are asynchronous that the server
             // is still active at this point.
-            ALOGV("start: server read:%lld  cumulative flushed:%lld  client written:%lld",
+            ALOGV("%s(%d): server read:%lld  cumulative flushed:%lld  client written:%lld",
+                    __func__, mId,
                     (long long)(mFramesWrittenServerOffset
                             + mStartEts.mPosition[ExtendedTimestamp::LOCATION_SERVER]),
                     (long long)mStartEts.mFlushed,
@@ -746,7 +758,7 @@
         // Start our local VolumeHandler for restoration purposes.
         mVolumeHandler->setStarted();
     } else {
-        ALOGE("start() status %d", status);
+        ALOGE("%s(%d): status %d", __func__, mId, status);
         mState = previousState;
         if (t != 0) {
             if (previousState != STATE_STOPPING) {
@@ -764,6 +776,8 @@
 void AudioTrack::stop()
 {
     AutoMutex lock(mLock);
+    ALOGV("%s(%d): prior state:%s", __func__, mId, stateToString(mState));
+
     if (mState != STATE_ACTIVE && mState != STATE_PAUSED) {
         return;
     }
@@ -773,7 +787,7 @@
     } else {
         mState = STATE_STOPPED;
         ALOGD_IF(mSharedBuffer == nullptr,
-                "stop() called with %u frames delivered", mReleased.value());
+                "%s(%d): called with %u frames delivered", __func__, mId, mReleased.value());
         mReleased = 0;
     }
 
@@ -809,10 +823,12 @@
 
 void AudioTrack::flush()
 {
+    AutoMutex lock(mLock);
+    ALOGV("%s(%d): prior state:%s", __func__, mId, stateToString(mState));
+
     if (mSharedBuffer != 0) {
         return;
     }
-    AutoMutex lock(mLock);
     if (mState == STATE_ACTIVE) {
         return;
     }
@@ -841,6 +857,8 @@
 void AudioTrack::pause()
 {
     AutoMutex lock(mLock);
+    ALOGV("%s(%d): prior state:%s", __func__, mId, stateToString(mState));
+
     if (mState == STATE_ACTIVE) {
         mState = STATE_PAUSED;
     } else if (mState == STATE_STOPPING) {
@@ -866,7 +884,8 @@
 
             uint32_t halFrames;
             AudioSystem::getRenderPosition(mOutput, &halFrames, &mPausedPosition);
-            ALOGV("AudioTrack::pause for offload, cache current position %u", mPausedPosition);
+            ALOGV("%s(%d): for offload, cache current position %u",
+                    __func__, mId, mPausedPosition);
         }
     }
 }
@@ -920,6 +939,8 @@
 status_t AudioTrack::setSampleRate(uint32_t rate)
 {
     AutoMutex lock(mLock);
+    ALOGV("%s(%d): prior state:%s rate:%u", __func__, mId, stateToString(mState), rate);
+
     if (rate == mSampleRate) {
         return NO_ERROR;
     }
@@ -985,8 +1006,8 @@
         return INVALID_OPERATION;
     }
 
-    ALOGV("setPlaybackRate (input): mSampleRate:%u  mSpeed:%f  mPitch:%f",
-            mSampleRate, playbackRate.mSpeed, playbackRate.mPitch);
+    ALOGV("%s(%d): mSampleRate:%u  mSpeed:%f  mPitch:%f",
+            __func__, mId, mSampleRate, playbackRate.mSpeed, playbackRate.mPitch);
     // pitch is emulated by adjusting speed and sampleRate
     const uint32_t effectiveRate = adjustSampleRate(mSampleRate, playbackRate.mPitch);
     const float effectiveSpeed = adjustSpeed(playbackRate.mSpeed, playbackRate.mPitch);
@@ -995,32 +1016,32 @@
     playbackRateTemp.mSpeed = effectiveSpeed;
     playbackRateTemp.mPitch = effectivePitch;
 
-    ALOGV("setPlaybackRate (effective): mSampleRate:%u  mSpeed:%f  mPitch:%f",
-            effectiveRate, effectiveSpeed, effectivePitch);
+    ALOGV("%s(%d) (effective) mSampleRate:%u  mSpeed:%f  mPitch:%f",
+            __func__, mId, effectiveRate, effectiveSpeed, effectivePitch);
 
     if (!isAudioPlaybackRateValid(playbackRateTemp)) {
-        ALOGW("setPlaybackRate(%f, %f) failed (effective rate out of bounds)",
-                playbackRate.mSpeed, playbackRate.mPitch);
+        ALOGW("%s(%d) (%f, %f) failed (effective rate out of bounds)",
+                __func__, mId, playbackRate.mSpeed, playbackRate.mPitch);
         return BAD_VALUE;
     }
     // Check if the buffer size is compatible.
     if (!isSampleRateSpeedAllowed_l(effectiveRate, effectiveSpeed)) {
-        ALOGW("setPlaybackRate(%f, %f) failed (buffer size)",
-                playbackRate.mSpeed, playbackRate.mPitch);
+        ALOGW("%s(%d) (%f, %f) failed (buffer size)",
+                __func__, mId, playbackRate.mSpeed, playbackRate.mPitch);
         return BAD_VALUE;
     }
 
     // Check resampler ratios are within bounds
     if ((uint64_t)effectiveRate > (uint64_t)mSampleRate *
             (uint64_t)AUDIO_RESAMPLER_DOWN_RATIO_MAX) {
-        ALOGW("setPlaybackRate(%f, %f) failed. Resample rate exceeds max accepted value",
-                playbackRate.mSpeed, playbackRate.mPitch);
+        ALOGW("%s(%d) (%f, %f) failed. Resample rate exceeds max accepted value",
+                __func__, mId, playbackRate.mSpeed, playbackRate.mPitch);
         return BAD_VALUE;
     }
 
     if ((uint64_t)effectiveRate * (uint64_t)AUDIO_RESAMPLER_UP_RATIO_MAX < (uint64_t)mSampleRate) {
-        ALOGW("setPlaybackRate(%f, %f) failed. Resample rate below min accepted value",
-                        playbackRate.mSpeed, playbackRate.mPitch);
+        ALOGW("%s(%d) (%f, %f) failed. Resample rate below min accepted value",
+                __func__, mId, playbackRate.mSpeed, playbackRate.mPitch);
         return BAD_VALUE;
     }
     mPlaybackRate = playbackRate;
@@ -1221,7 +1242,8 @@
         uint32_t dspFrames = 0;
 
         if (isOffloaded_l() && ((mState == STATE_PAUSED) || (mState == STATE_PAUSED_STOPPING))) {
-            ALOGV("getPosition called in paused state, return cached position %u", mPausedPosition);
+            ALOGV("%s(%d): called in paused state, return cached position %u",
+                __func__, mId, mPausedPosition);
             *position = mPausedPosition;
             return NO_ERROR;
         }
@@ -1367,7 +1389,7 @@
 {
     status_t status = AudioSystem::getLatency(mOutput, &mAfLatency);
     if (status != NO_ERROR) {
-        ALOGW("getLatency(%d) failed status %d", mOutput, status);
+        ALOGW("%s(%d): getLatency(%d) failed status %d", __func__, mId, mOutput, status);
     } else {
         // FIXME don't believe this lie
         mLatency = mAfLatency + (1000LL * mFrameCount) / mSampleRate;
@@ -1395,7 +1417,8 @@
 
     const sp<IAudioFlinger>& audioFlinger = AudioSystem::get_audio_flinger();
     if (audioFlinger == 0) {
-        ALOGE("Could not get audioflinger");
+        ALOGE("%s(%d): Could not get audioflinger",
+                __func__, mId);
         status = NO_INIT;
         goto exit;
     }
@@ -1418,7 +1441,9 @@
 
         bool fastAllowed = sharedBuffer || transferAllowed;
         if (!fastAllowed) {
-            ALOGW("AUDIO_OUTPUT_FLAG_FAST denied by client, not shared buffer and transfer = %s",
+            ALOGW("%s(%d): AUDIO_OUTPUT_FLAG_FAST denied by client,"
+                  " not shared buffer and transfer = %s",
+                  __func__, mId,
                   convertTransferToText(mTransfer));
             mFlags = (audio_output_flags_t) (mFlags & ~AUDIO_OUTPUT_FLAG_FAST);
         }
@@ -1467,7 +1492,8 @@
                                                       &status);
 
     if (status != NO_ERROR || output.outputId == AUDIO_IO_HANDLE_NONE) {
-        ALOGE("AudioFlinger could not create track, status: %d output %d", status, output.outputId);
+        ALOGE("%s(%d): AudioFlinger could not create track, status: %d output %d",
+                __func__, mId, status, output.outputId);
         if (status == NO_ERROR) {
             status = NO_INIT;
         }
@@ -1488,6 +1514,7 @@
     mAfFrameCount = output.afFrameCount;
     mAfSampleRate = output.afSampleRate;
     mAfLatency = output.afLatencyMs;
+    mId = output.trackId;
 
     mLatency = mAfLatency + (1000LL * mFrameCount) / mSampleRate;
 
@@ -1497,13 +1524,13 @@
     // FIXME compare to AudioRecord
     sp<IMemory> iMem = track->getCblk();
     if (iMem == 0) {
-        ALOGE("Could not get control block");
+        ALOGE("%s(%d): Could not get control block", __func__, mId);
         status = NO_INIT;
         goto exit;
     }
     void *iMemPointer = iMem->pointer();
     if (iMemPointer == NULL) {
-        ALOGE("Could not get control block pointer");
+        ALOGE("%s(%d): Could not get control block pointer", __func__, mId);
         status = NO_INIT;
         goto exit;
     }
@@ -1522,14 +1549,14 @@
     mAwaitBoost = false;
     if (mFlags & AUDIO_OUTPUT_FLAG_FAST) {
         if (output.flags & AUDIO_OUTPUT_FLAG_FAST) {
-            ALOGI("AUDIO_OUTPUT_FLAG_FAST successful; frameCount %zu -> %zu",
-                  mReqFrameCount, mFrameCount);
+            ALOGI("%s(%d): AUDIO_OUTPUT_FLAG_FAST successful; frameCount %zu -> %zu",
+                  __func__, mId, mReqFrameCount, mFrameCount);
             if (!mThreadCanCallJava) {
                 mAwaitBoost = true;
             }
         } else {
-            ALOGW("AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount %zu -> %zu", mReqFrameCount,
-                  mFrameCount);
+            ALOGW("%s(%d): AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount %zu -> %zu",
+                  __func__, mId, mReqFrameCount, mFrameCount);
         }
     }
     mFlags = output.flags;
@@ -1557,7 +1584,7 @@
     } else {
         buffers = mSharedBuffer->pointer();
         if (buffers == NULL) {
-            ALOGE("Could not get buffer pointer");
+            ALOGE("%s(%d): Could not get buffer pointer", __func__, mId);
             status = NO_INIT;
             goto exit;
         }
@@ -1646,7 +1673,7 @@
         timeout.tv_nsec = (long) (ms % 1000) * 1000000;
         requested = &timeout;
     } else {
-        ALOGE("%s invalid waitCount %d", __func__, waitCount);
+        ALOGE("%s(%d): invalid waitCount %d", __func__, mId, waitCount);
         requested = NULL;
     }
     return obtainBuffer(audioBuffer, requested, NULL /*elapsed*/, nonContig);
@@ -1756,7 +1783,8 @@
 {
     int32_t flags = android_atomic_and(~CBLK_DISABLED, &mCblk->mFlags);
     if ((mState == STATE_ACTIVE) && (flags & CBLK_DISABLED)) {
-        ALOGW("releaseBuffer() track %p disabled due to previous underrun, restarting", this);
+        ALOGW("%s(%d): releaseBuffer() track %p disabled due to previous underrun, restarting",
+                __func__, mId, this);
         // FIXME ignoring status
         mAudioTrack->start();
     }
@@ -1783,7 +1811,8 @@
     if (ssize_t(userSize) < 0 || (buffer == NULL && userSize != 0)) {
         // Sanity-check: user is most-likely passing an error code, and it would
         // make the return value ambiguous (actualSize vs error).
-        ALOGE("AudioTrack::write(buffer=%p, size=%zu (%zd)", buffer, userSize, userSize);
+        ALOGE("%s(%d): AudioTrack::write(buffer=%p, size=%zu (%zd)",
+                __func__, mId, buffer, userSize, userSize);
         return BAD_VALUE;
     }
 
@@ -1845,7 +1874,8 @@
             pollUs <<= 1;
         } while (tryCounter-- > 0);
         if (tryCounter < 0) {
-            ALOGE("did not receive expected priority boost on time");
+            ALOGE("%s(%d): did not receive expected priority boost on time",
+                    __func__, mId);
         }
         // Run again immediately
         return 0;
@@ -2086,7 +2116,8 @@
     if (ns != NS_WHENEVER) {
         timeout.tv_sec = ns / 1000000000LL;
         timeout.tv_nsec = ns % 1000000000LL;
-        ALOGV("timeout %ld.%03d", timeout.tv_sec, (int) timeout.tv_nsec / 1000000);
+        ALOGV("%s(%d): timeout %ld.%03d",
+                __func__, mId, timeout.tv_sec, (int) timeout.tv_nsec / 1000000);
         requested = &timeout;
     }
 
@@ -2098,18 +2129,20 @@
         size_t nonContig;
         status_t err = obtainBuffer(&audioBuffer, requested, NULL, &nonContig);
         LOG_ALWAYS_FATAL_IF((err != NO_ERROR) != (audioBuffer.frameCount == 0),
-                "obtainBuffer() err=%d frameCount=%zu", err, audioBuffer.frameCount);
+                "%s(%d): obtainBuffer() err=%d frameCount=%zu",
+                 __func__, mId, err, audioBuffer.frameCount);
         requested = &ClientProxy::kNonBlocking;
         size_t avail = audioBuffer.frameCount + nonContig;
-        ALOGV("obtainBuffer(%u) returned %zu = %zu + %zu err %d",
-                mRemainingFrames, avail, audioBuffer.frameCount, nonContig, err);
+        ALOGV("%s(%d): obtainBuffer(%u) returned %zu = %zu + %zu err %d",
+                __func__, mId, mRemainingFrames, avail, audioBuffer.frameCount, nonContig, err);
         if (err != NO_ERROR) {
             if (err == TIMED_OUT || err == WOULD_BLOCK || err == -EINTR ||
                     (isOffloaded() && (err == DEAD_OBJECT))) {
                 // FIXME bug 25195759
                 return 1000000;
             }
-            ALOGE("Error %d obtaining an audio buffer, giving up.", err);
+            ALOGE("%s(%d): Error %d obtaining an audio buffer, giving up.",
+                    __func__, mId, err);
             return NS_NEVER;
         }
 
@@ -2134,8 +2167,8 @@
 
         // Sanity check on returned size
         if (ssize_t(writtenSize) < 0 || writtenSize > reqSize) {
-            ALOGE("EVENT_MORE_DATA requested %zu bytes but callback returned %zd bytes",
-                    reqSize, ssize_t(writtenSize));
+            ALOGE("%s(%d): EVENT_MORE_DATA requested %zu bytes but callback returned %zd bytes",
+                    __func__, mId, reqSize, ssize_t(writtenSize));
             return NS_NEVER;
         }
 
@@ -2230,8 +2263,8 @@
 
 status_t AudioTrack::restoreTrack_l(const char *from)
 {
-    ALOGW("dead IAudioTrack, %s, creating a new one from %s()",
-          isOffloadedOrDirect_l() ? "Offloaded or Direct" : "PCM", from);
+    ALOGW("%s(%d): dead IAudioTrack, %s, creating a new one from %s()",
+            __func__, mId, isOffloadedOrDirect_l() ? "Offloaded or Direct" : "PCM", from);
     ++mSequence;
 
     // refresh the audio configuration cache in this process to make sure we get new
@@ -2275,7 +2308,7 @@
     status_t result = createTrack_l();
 
     if (result != NO_ERROR) {
-        ALOGW("%s(): createTrack_l failed, do not retry", __func__);
+        ALOGW("%s(%d): createTrack_l failed, do not retry", __func__, mId);
         retries = 0;
     } else {
         // take the frames that will be lost by track recreation into account in saved position
@@ -2292,7 +2325,7 @@
             } else {
                 mStaticProxy->setBufferPosition(bufferPosition);
                 if (bufferPosition == mFrameCount) {
-                    ALOGD("restoring track at end of static buffer");
+                    ALOGD("%s(%d): restoring track at end of static buffer", __func__, mId);
                 }
             }
         }
@@ -2322,7 +2355,7 @@
         mFramesWrittenAtRestore = mFramesWrittenServerOffset;
     }
     if (result != NO_ERROR) {
-        ALOGW("%s() failed status %d, retries %d", __func__, result, retries);
+        ALOGW("%s(%d): failed status %d, retries %d", __func__, mId, result, retries);
         if (--retries > 0) {
             goto retry;
         }
@@ -2347,8 +2380,8 @@
     //      unless the server has more than 2^31 frames in its buffer,
     //      in which case the use of uint32_t for these counters has bigger issues.
     ALOGE_IF(delta < 0,
-            "detected illegal retrograde motion by the server: mServer advanced by %d",
-            delta);
+            "%s(%d): detected illegal retrograde motion by the server: mServer advanced by %d",
+            __func__, mId, delta);
     mServer = newServer;
     if (delta > 0) { // avoid retrograde
         mPosition += delta;
@@ -2368,9 +2401,10 @@
                                             sampleRate, speed /*, 0 mNotificationsPerBufferReq*/);
     const bool allowed = mFrameCount >= minFrameCount;
     ALOGD_IF(!allowed,
-            "isSampleRateSpeedAllowed_l denied "
+            "%s(%d): denied "
             "mAfLatency:%u  mAfFrameCount:%zu  mAfSampleRate:%u  sampleRate:%u  speed:%f "
             "mFrameCount:%zu < minFrameCount:%zu",
+            __func__, mId,
             mAfLatency, mAfFrameCount, mAfSampleRate, sampleRate, speed,
             mFrameCount, minFrameCount);
     return allowed;
@@ -2388,7 +2422,8 @@
     AudioParameter param = AudioParameter();
     param.addInt(String8(AudioParameter::keyPresentationId), presentationId);
     param.addInt(String8(AudioParameter::keyProgramId), programId);
-    ALOGV("PresentationId/ProgramId[%s]",param.toString().string());
+    ALOGV("%s(%d): PresentationId/ProgramId[%s]",
+            __func__, mId, param.toString().string());
 
     return mAudioTrack->setParameters(param.toString());
 }
@@ -2415,7 +2450,7 @@
     } else {
         // warn only if not an expected restore failure.
         ALOGW_IF(!((isOffloadedOrDirect_l() || mDoNotReconnect) && status == DEAD_OBJECT),
-                "applyVolumeShaper failed: %d", status);
+                "%s(%d): applyVolumeShaper failed: %d", __func__, mId, status);
     }
     return status;
 }
@@ -2456,7 +2491,8 @@
         return INVALID_OPERATION; // not supported
     }
     status_t status = mProxy->getTimestamp(timestamp);
-    LOG_ALWAYS_FATAL_IF(status != OK, "status %d not allowed from proxy getTimestamp", status);
+    LOG_ALWAYS_FATAL_IF(status != OK, "%s(%d): status %d not allowed from proxy getTimestamp",
+            __func__, mId, status);
     bool found = false;
     timestamp->mPosition[ExtendedTimestamp::LOCATION_CLIENT] = mFramesWritten;
     timestamp->mTimeNs[ExtendedTimestamp::LOCATION_CLIENT] = 0;
@@ -2499,7 +2535,8 @@
         }
         break; // offloaded tracks handled below
     default:
-        LOG_ALWAYS_FATAL("Invalid mState in getTimestamp(): %d", mState);
+        LOG_ALWAYS_FATAL("%s(%d): Invalid mState in getTimestamp(): %d",
+               __func__, mId, mState);
         break;
     }
 
@@ -2533,7 +2570,8 @@
                 // In this case we adjust the position from the previous computed latency.
                 if (location == ExtendedTimestamp::LOCATION_SERVER) {
                     ALOGW_IF(mPreviousLocation == ExtendedTimestamp::LOCATION_KERNEL,
-                            "getTimestamp() location moved from kernel to server");
+                            "%s(%d): location moved from kernel to server",
+                            __func__, mId);
                     // check that the last kernel OK time info exists and the positions
                     // are valid (if they predate the current track, the positions may
                     // be zero or negative).
@@ -2548,8 +2586,8 @@
                             :
                             (ets.mPosition[ExtendedTimestamp::LOCATION_SERVER_LASTKERNELOK]
                             - ets.mPosition[ExtendedTimestamp::LOCATION_KERNEL_LASTKERNELOK]);
-                    ALOGV("frame adjustment:%lld  timestamp:%s",
-                            (long long)frames, ets.toString().c_str());
+                    ALOGV("%s(%d): frame adjustment:%lld  timestamp:%s",
+                            __func__, mId, (long long)frames, ets.toString().c_str());
                     if (frames >= ets.mPosition[location]) {
                         timestamp.mPosition = 0;
                     } else {
@@ -2557,7 +2595,8 @@
                     }
                 } else if (location == ExtendedTimestamp::LOCATION_KERNEL) {
                     ALOGV_IF(mPreviousLocation == ExtendedTimestamp::LOCATION_SERVER,
-                            "getTimestamp() location moved from server to kernel");
+                            "%s(%d): location moved from server to kernel",
+                            __func__, mId);
                 }
 
                 // We update the timestamp time even when paused.
@@ -2581,7 +2620,7 @@
                 mPreviousLocation = location;
             } else {
                 // right after AudioTrack is started, one may not find a timestamp
-                ALOGV("getBestTimestamp did not find timestamp");
+                ALOGV("%s(%d): getBestTimestamp did not find timestamp", __func__, mId);
             }
         }
         if (status == INVALID_OPERATION) {
@@ -2591,7 +2630,8 @@
             // to be zero we convert this to WOULD_BLOCK (with the implicit meaning of
             // "zero" for NuPlayer).  We don't convert for track restoration as position
             // does not reset.
-            ALOGV("timestamp server offset:%lld restore frames:%lld",
+            ALOGV("%s(%d): timestamp server offset:%lld restore frames:%lld",
+                    __func__, mId,
                     (long long)mFramesWrittenServerOffset, (long long)mFramesWrittenAtRestore);
             if (mFramesWrittenServerOffset != mFramesWrittenAtRestore) {
                 status = WOULD_BLOCK;
@@ -2599,7 +2639,7 @@
         }
     }
     if (status != NO_ERROR) {
-        ALOGV_IF(status != WOULD_BLOCK, "getTimestamp error:%#x", status);
+        ALOGV_IF(status != WOULD_BLOCK, "%s(%d): getTimestamp error:%#x", __func__, mId, status);
         return status;
     }
     if (isOffloadedOrDirect_l()) {
@@ -2638,8 +2678,9 @@
                     // since the start time.  If greater, then that means we may have failed
                     // to completely flush or stop the previous playing track.
                     ALOGW_IF(!mTimestampStartupGlitchReported,
-                            "getTimestamp startup glitch detected"
+                            "%s(%d): startup glitch detected"
                             " deltaTimeUs(%lld) deltaPositionUs(%lld) tsmPosition(%u)",
+                            __func__, mId,
                             (long long)deltaTimeUs, (long long)deltaPositionByUs,
                             timestamp.mPosition);
                     mTimestampStartupGlitchReported = true;
@@ -2707,8 +2748,9 @@
             const int64_t lagNs = int64_t(mAfLatency * 1000000LL);
             const int64_t limitNs = mStartNs - lagNs;
             if (currentTimeNanos < limitNs) {
-                ALOGD("correcting timestamp time for pause, "
+                ALOGD("%s(%d): correcting timestamp time for pause, "
                         "currentTimeNanos: %lld < limitNs: %lld < mStartNs: %lld",
+                        __func__, mId,
                         (long long)currentTimeNanos, (long long)limitNs, (long long)mStartNs);
                 timestamp.mTime = convertNsToTimespec(limitNs);
                 currentTimeNanos = limitNs;
@@ -2716,7 +2758,8 @@
 
             // retrograde check
             if (currentTimeNanos < previousTimeNanos) {
-                ALOGW("retrograde timestamp time corrected, %lld < %lld",
+                ALOGW("%s(%d): retrograde timestamp time corrected, %lld < %lld",
+                        __func__, mId,
                         (long long)currentTimeNanos, (long long)previousTimeNanos);
                 timestamp.mTime = mPreviousTimestamp.mTime;
                 // currentTimeNanos not used below.
@@ -2729,7 +2772,8 @@
             if (deltaPosition < 0) {
                 // Only report once per position instead of spamming the log.
                 if (!mRetrogradeMotionReported) {
-                    ALOGW("retrograde timestamp position corrected, %d = %u - %u",
+                    ALOGW("%s(%d): retrograde timestamp position corrected, %d = %u - %u",
+                            __func__, mId,
                             deltaPosition,
                             timestamp.mPosition,
                             mPreviousTimestamp.mPosition);
@@ -2749,7 +2793,8 @@
             if (deltaTime != 0) {
                 const int64_t computedSampleRate =
                         deltaPosition * (long long)NANOS_PER_SECOND / deltaTime;
-                ALOGD("computedSampleRate:%u  sampleRate:%u",
+                ALOGD("%s(%d): computedSampleRate:%u  sampleRate:%u",
+                        __func__, mId,
                         (unsigned)computedSampleRate, mSampleRate);
             }
 #endif
@@ -2795,8 +2840,8 @@
     String8 result;
 
     result.append(" AudioTrack::dump\n");
-    result.appendFormat("  status(%d), state(%d), session Id(%d), flags(%#x)\n",
-                        mStatus, mState, mSessionId, mFlags);
+    result.appendFormat("  id(%d) status(%d), state(%d), session Id(%d), flags(%#x)\n",
+                        mId, mStatus, mState, mSessionId, mFlags);
     result.appendFormat("  stream type(%d), left - right volume(%f, %f)\n",
                         (mStreamType == AUDIO_STREAM_DEFAULT) ?
                                 audio_attributes_to_stream_type(&mAttributes) : mStreamType,
@@ -2838,18 +2883,18 @@
 status_t AudioTrack::addAudioDeviceCallback(const sp<AudioSystem::AudioDeviceCallback>& callback)
 {
     if (callback == 0) {
-        ALOGW("%s adding NULL callback!", __FUNCTION__);
+        ALOGW("%s(%d): adding NULL callback!", __func__, mId);
         return BAD_VALUE;
     }
     AutoMutex lock(mLock);
     if (mDeviceCallback.unsafe_get() == callback.get()) {
-        ALOGW("%s adding same callback!", __FUNCTION__);
+        ALOGW("%s(%d): adding same callback!", __func__, mId);
         return INVALID_OPERATION;
     }
     status_t status = NO_ERROR;
     if (mOutput != AUDIO_IO_HANDLE_NONE) {
         if (mDeviceCallback != 0) {
-            ALOGW("%s callback already present!", __FUNCTION__);
+            ALOGW("%s(%d): callback already present!", __func__, mId);
             AudioSystem::removeAudioDeviceCallback(this, mOutput);
         }
         status = AudioSystem::addAudioDeviceCallback(this, mOutput);
@@ -2862,12 +2907,12 @@
         const sp<AudioSystem::AudioDeviceCallback>& callback)
 {
     if (callback == 0) {
-        ALOGW("%s removing NULL callback!", __FUNCTION__);
+        ALOGW("%s(%d): removing NULL callback!", __func__, mId);
         return BAD_VALUE;
     }
     AutoMutex lock(mLock);
     if (mDeviceCallback.unsafe_get() != callback.get()) {
-        ALOGW("%s removing different callback!", __FUNCTION__);
+        ALOGW("%s(%d): removing different callback!", __func__, mId);
         return INVALID_OPERATION;
     }
     mDeviceCallback.clear();
@@ -2973,7 +3018,7 @@
     case STATE_FLUSHED:
         return false;  // we're not active
     default:
-        LOG_ALWAYS_FATAL("Invalid mState in hasStarted(): %d", mState);
+        LOG_ALWAYS_FATAL("%s(%d): Invalid mState in hasStarted(): %d", __func__, mId, mState);
         break;
     }
 
@@ -2989,7 +3034,8 @@
         } else if (status == OK) {
             wait = (ts.mPosition == 0 || ts.mPosition == mStartTs.mPosition);
         }
-        ALOGV("hasStarted wait:%d  ts:%u  start position:%lld",
+        ALOGV("%s(%d): hasStarted wait:%d  ts:%u  start position:%lld",
+                __func__, mId,
                 (int)wait,
                 ts.mPosition,
                 (long long)mStartTs.mPosition);
@@ -3010,7 +3056,8 @@
                 break;
             }
         }
-        ALOGV("hasStarted wait:%d  ets:%lld  start position:%lld",
+        ALOGV("%s(%d): hasStarted wait:%d  ets:%lld  start position:%lld",
+                __func__, mId,
                 (int)wait,
                 (long long)ets.mPosition[location],
                 (long long)mStartEts.mPosition[location]);
@@ -3085,7 +3132,8 @@
         ns = INT64_MAX;
         // fall through
     default:
-        LOG_ALWAYS_FATAL_IF(ns < 0, "processAudioBuffer() returned %" PRId64, ns);
+        LOG_ALWAYS_FATAL_IF(ns < 0, "%s(%d): processAudioBuffer() returned %lld",
+                __func__, mReceiver.mId, (long long)ns);
         pauseInternal(ns);
         return true;
     }
diff --git a/media/libaudioclient/include/media/AudioRecord.h b/media/libaudioclient/include/media/AudioRecord.h
index 806280a..c226557 100644
--- a/media/libaudioclient/include/media/AudioRecord.h
+++ b/media/libaudioclient/include/media/AudioRecord.h
@@ -654,6 +654,7 @@
     audio_input_flags_t     mOrigFlags;             // as specified in constructor or set(), const
 
     audio_session_t         mSessionId;
+    int                     mId;                    // Id from AudioFlinger
     transfer_type           mTransfer;
 
     // Next 5 fields may be changed if IAudioRecord is re-created, but always != 0
diff --git a/media/libaudioclient/include/media/AudioTrack.h b/media/libaudioclient/include/media/AudioTrack.h
index 59c6f4c..c5105af 100644
--- a/media/libaudioclient/include/media/AudioTrack.h
+++ b/media/libaudioclient/include/media/AudioTrack.h
@@ -1058,6 +1058,19 @@
         STATE_STOPPING,
     }                       mState;
 
+    static constexpr const char *stateToString(State state)
+    {
+        switch (state) {
+        case STATE_ACTIVE:          return "STATE_ACTIVE";
+        case STATE_STOPPED:         return "STATE_STOPPED";
+        case STATE_PAUSED:          return "STATE_PAUSED";
+        case STATE_PAUSED_STOPPING: return "STATE_PAUSED_STOPPING";
+        case STATE_FLUSHED:         return "STATE_FLUSHED";
+        case STATE_STOPPING:        return "STATE_STOPPING";
+        default:                    return "UNKNOWN";
+        }
+    }
+
     // for client callback handler
     callback_t              mCbf;                   // callback handler for events, or NULL
     void*                   mUserData;
@@ -1148,6 +1161,7 @@
 
     audio_session_t         mSessionId;
     int                     mAuxEffectId;
+    int                     mId;                    // Id from AudioFlinger.
 
     mutable Mutex           mLock;
 
diff --git a/media/libaudioclient/include/media/IAudioFlinger.h b/media/libaudioclient/include/media/IAudioFlinger.h
index 31326ab..52cc860 100644
--- a/media/libaudioclient/include/media/IAudioFlinger.h
+++ b/media/libaudioclient/include/media/IAudioFlinger.h
@@ -146,6 +146,7 @@
             afSampleRate = parcel->readInt64();
             afLatencyMs = parcel->readInt32();
             (void)parcel->read(&outputId, sizeof(audio_io_handle_t));
+            (void)parcel->readInt32(&trackId);
             return NO_ERROR;
         }
 
@@ -163,6 +164,7 @@
             (void)parcel->writeInt64(afSampleRate);
             (void)parcel->writeInt32(afLatencyMs);
             (void)parcel->write(&outputId, sizeof(audio_io_handle_t));
+            (void)parcel->writeInt32(trackId);
             return NO_ERROR;
         }
 
@@ -179,6 +181,7 @@
         uint32_t afSampleRate;
         uint32_t afLatencyMs;
         audio_io_handle_t outputId;
+        int32_t trackId;
     };
 
     /* CreateRecordInput contains all input arguments sent by AudioRecord to AudioFlinger
@@ -271,6 +274,7 @@
                     return BAD_VALUE;
                 }
             }
+            (void)parcel->readInt32(&trackId);
             return NO_ERROR;
         }
 
@@ -297,6 +301,7 @@
             } else {
                 (void)parcel->writeInt32(0);
             }
+            (void)parcel->writeInt32(trackId);
 
             return NO_ERROR;
         }
@@ -313,6 +318,7 @@
         audio_io_handle_t inputId;
         sp<IMemory> cblk;
         sp<IMemory> buffers;
+        int32_t trackId;
     };
 
     // invariant on exit for all APIs that return an sp<>:
diff --git a/media/libaudioprocessing/AudioResamplerFirProcess.h b/media/libaudioprocessing/AudioResamplerFirProcess.h
index a741677..9b70a1c 100644
--- a/media/libaudioprocessing/AudioResamplerFirProcess.h
+++ b/media/libaudioprocessing/AudioResamplerFirProcess.h
@@ -90,7 +90,7 @@
         Accumulator<CHANNELS-1, TO>::acc(coef, data);
     }
     inline void volume(TO*& out, TO gain) {
-        *out++ = volumeAdjust(value, gain);
+        *out++ += volumeAdjust(value, gain);
         Accumulator<CHANNELS-1, TO>::volume(out, gain);
     }
 
diff --git a/media/libmediaextractor/include/media/MediaTrack.h b/media/libmediaextractor/include/media/MediaTrack.h
index adea61a..94510a2 100644
--- a/media/libmediaextractor/include/media/MediaTrack.h
+++ b/media/libmediaextractor/include/media/MediaTrack.h
@@ -113,6 +113,12 @@
     virtual status_t read(
             MediaBufferBase **buffer, const ReadOptions *options = NULL) = 0;
 
+    // Returns true if |read| supports nonblocking option, otherwise false.
+    // |readMultiple| if supported, always allows the nonblocking option.
+    virtual bool supportNonblockingRead() {
+        return false;
+    }
+
     virtual ~MediaTrack();
 
 private:
diff --git a/media/libmediaplayer2/MediaPlayer2AudioOutput.cpp b/media/libmediaplayer2/MediaPlayer2AudioOutput.cpp
index a8e1d1f..eba78ed 100644
--- a/media/libmediaplayer2/MediaPlayer2AudioOutput.cpp
+++ b/media/libmediaplayer2/MediaPlayer2AudioOutput.cpp
@@ -559,7 +559,7 @@
 }
 
 status_t MediaPlayer2AudioOutput::getPlaybackRate(AudioPlaybackRate *rate) {
-    ALOGV("setPlaybackRate");
+    ALOGV("getPlaybackRate");
     Mutex::Autolock lock(mLock);
     if (mTrack == 0) {
         return NO_INIT;
diff --git a/media/libmediaplayer2/nuplayer2/Android.bp b/media/libmediaplayer2/nuplayer2/Android.bp
index dd91628..7cf4522 100644
--- a/media/libmediaplayer2/nuplayer2/Android.bp
+++ b/media/libmediaplayer2/nuplayer2/Android.bp
@@ -16,6 +16,7 @@
     ],
 
     header_libs: [
+        "libbase_headers",
         "libmediaplayer2_headers",
         "media_plugin_headers",
     ],
diff --git a/media/libmediaplayer2/nuplayer2/NuPlayer2Driver.cpp b/media/libmediaplayer2/nuplayer2/NuPlayer2Driver.cpp
index 4d799b8..d3be53a 100644
--- a/media/libmediaplayer2/nuplayer2/NuPlayer2Driver.cpp
+++ b/media/libmediaplayer2/nuplayer2/NuPlayer2Driver.cpp
@@ -17,6 +17,7 @@
 //#define LOG_NDEBUG 0
 #define LOG_TAG "NuPlayer2Driver"
 #include <inttypes.h>
+#include <android-base/macros.h>
 #include <utils/Log.h>
 #include <cutils/properties.h>
 
@@ -291,8 +292,7 @@
         case STATE_PREPARED:
         {
             mPlayer->start();
-
-            // fall through
+            FALLTHROUGH_INTENDED;
         }
 
         case STATE_RUNNING:
@@ -888,7 +888,7 @@
                     mPlayer->pause();
                     mState = STATE_PAUSED;
                 }
-                // fall through
+                FALLTHROUGH_INTENDED;
             }
 
             case MEDIA2_ERROR:
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
index 3e5bdd6..f2c8f64 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDriver.cpp
@@ -17,6 +17,7 @@
 //#define LOG_NDEBUG 0
 #define LOG_TAG "NuPlayerDriver"
 #include <inttypes.h>
+#include <android-base/macros.h>
 #include <utils/Log.h>
 #include <cutils/properties.h>
 
@@ -344,7 +345,7 @@
 
             CHECK_EQ(mState, STATE_PREPARED);
 
-            // fall through
+            FALLTHROUGH_INTENDED;
         }
 
         case STATE_PAUSED:
@@ -353,7 +354,7 @@
         {
             mPlayer->start();
 
-            // fall through
+            FALLTHROUGH_INTENDED;
         }
 
         case STATE_RUNNING:
@@ -382,7 +383,7 @@
     switch (mState) {
         case STATE_RUNNING:
             mPlayer->pause();
-            // fall through
+            FALLTHROUGH_INTENDED;
 
         case STATE_PAUSED:
             mState = STATE_STOPPED;
@@ -991,7 +992,7 @@
                 mPlayer->pause();
                 mState = STATE_PAUSED;
             }
-            // fall through
+            FALLTHROUGH_INTENDED;
         }
 
         case MEDIA_ERROR:
diff --git a/media/libnblog/PerformanceAnalysis.cpp b/media/libnblog/PerformanceAnalysis.cpp
index c6b5b3f..46912d3 100644
--- a/media/libnblog/PerformanceAnalysis.cpp
+++ b/media/libnblog/PerformanceAnalysis.cpp
@@ -79,7 +79,7 @@
 std::string Histogram::toString() const {
     std::stringstream ss;
     static constexpr char kDivider = '|';
-    ss << mBinSize << "," << mNumBins << "," << mLow << ",{";
+    ss << kVersion << "," << mBinSize << "," << mNumBins << "," << mLow << ",{";
     bool first = true;
     if (mLowCount != 0) {
         ss << "-1" << kDivider << mLowCount;
diff --git a/media/libnblog/include/media/nblog/PerformanceAnalysis.h b/media/libnblog/include/media/nblog/PerformanceAnalysis.h
index 6f284ea..983b28a 100644
--- a/media/libnblog/include/media/nblog/PerformanceAnalysis.h
+++ b/media/libnblog/include/media/nblog/PerformanceAnalysis.h
@@ -113,6 +113,9 @@
     std::string toString() const;
 
 private:
+    // Histogram version number.
+    static constexpr int kVersion = 1;
+
     const double mBinSize;      // Size of each bucket
     const size_t mNumBins;      // Number of buckets in histogram range
     const double mLow;          // Lower bound of values
diff --git a/media/libstagefright/RemoteMediaSource.cpp b/media/libstagefright/RemoteMediaSource.cpp
index d07afec..e549fcf 100644
--- a/media/libstagefright/RemoteMediaSource.cpp
+++ b/media/libstagefright/RemoteMediaSource.cpp
@@ -54,6 +54,10 @@
     return mSource->read(buffer, reinterpret_cast<const MediaSource::ReadOptions*>(options));
 }
 
+bool RemoteMediaSource::supportNonblockingRead() {
+    return mSource->supportNonblockingRead();
+}
+
 status_t RemoteMediaSource::pause() {
     return ERROR_UNSUPPORTED;
 }
diff --git a/media/libstagefright/StagefrightMetadataRetriever.cpp b/media/libstagefright/StagefrightMetadataRetriever.cpp
index f8dde79..be01a7d 100644
--- a/media/libstagefright/StagefrightMetadataRetriever.cpp
+++ b/media/libstagefright/StagefrightMetadataRetriever.cpp
@@ -20,6 +20,7 @@
 #include <inttypes.h>
 
 #include <utils/Log.h>
+#include <cutils/properties.h>
 
 #include "include/FrameDecoder.h"
 #include "include/StagefrightMetadataRetriever.h"
@@ -205,11 +206,14 @@
         trackMeta->setCString(kKeyMIMEType, mime);
     }
 
+    bool preferhw = property_get_bool(
+            "media.stagefright.thumbnail.prefer_hw_codecs", false);
+    uint32_t flags = preferhw ? 0 : MediaCodecList::kPreferSoftwareCodecs;
     Vector<AString> matchingCodecs;
     MediaCodecList::findMatchingCodecs(
             mime,
             false, /* encoder */
-            MediaCodecList::kPreferSoftwareCodecs,
+            flags,
             &matchingCodecs);
 
     for (size_t i = 0; i < matchingCodecs.size(); ++i) {
@@ -326,11 +330,14 @@
     const char *mime;
     CHECK(trackMeta->findCString(kKeyMIMEType, &mime));
 
+    bool preferhw = property_get_bool(
+            "media.stagefright.thumbnail.prefer_hw_codecs", false);
+    uint32_t flags = preferhw ? 0 : MediaCodecList::kPreferSoftwareCodecs;
     Vector<AString> matchingCodecs;
     MediaCodecList::findMatchingCodecs(
             mime,
             false, /* encoder */
-            MediaCodecList::kPreferSoftwareCodecs,
+            flags,
             &matchingCodecs);
 
     for (size_t i = 0; i < matchingCodecs.size(); ++i) {
diff --git a/media/libstagefright/codecs/mpeg2dec/Android.bp b/media/libstagefright/codecs/mpeg2dec/Android.bp
index fb0db8f..cd83db0 100644
--- a/media/libstagefright/codecs/mpeg2dec/Android.bp
+++ b/media/libstagefright/codecs/mpeg2dec/Android.bp
@@ -1,9 +1,6 @@
 cc_library_shared {
     name: "libstagefright_soft_mpeg2dec",
     vendor_available: true,
-    vndk: {
-        enabled: true,
-    },
 
     static_libs: ["libmpeg2dec"],
     srcs: ["SoftMPEG2.cpp"],
diff --git a/media/libstagefright/include/media/stagefright/RemoteMediaSource.h b/media/libstagefright/include/media/stagefright/RemoteMediaSource.h
index 1d720af..d1ec1ed 100644
--- a/media/libstagefright/include/media/stagefright/RemoteMediaSource.h
+++ b/media/libstagefright/include/media/stagefright/RemoteMediaSource.h
@@ -37,6 +37,7 @@
     virtual status_t read(
             MediaBufferBase **buffer,
             const MediaSource::ReadOptions *options = NULL);
+    virtual bool supportNonblockingRead();
     virtual status_t pause();
     virtual status_t setStopTimeUs(int64_t stopTimeUs);
 
diff --git a/services/audioflinger/AudioFlinger.cpp b/services/audioflinger/AudioFlinger.cpp
index 9e4d739..7db7d9f 100644
--- a/services/audioflinger/AudioFlinger.cpp
+++ b/services/audioflinger/AudioFlinger.cpp
@@ -788,6 +788,7 @@
         output.afFrameCount = thread->frameCount();
         output.afSampleRate = thread->sampleRate();
         output.afLatencyMs = thread->latency();
+        output.trackId = track->id();
 
         // move effect chain to this output thread if an effect on same session was waiting
         // for a track to be created
@@ -1807,6 +1808,7 @@
 
     output.cblk = recordTrack->getCblk();
     output.buffers = recordTrack->getBuffers();
+    output.trackId = recordTrack->id();
 
     // return handle to client
     recordHandle = new RecordHandle(recordTrack);
diff --git a/services/audioflinger/PatchPanel.cpp b/services/audioflinger/PatchPanel.cpp
index 7b165a1..538a0eb 100644
--- a/services/audioflinger/PatchPanel.cpp
+++ b/services/audioflinger/PatchPanel.cpp
@@ -598,7 +598,7 @@
     // add latency if it exists
     double latencyMs;
     if (getLatencyMs(&latencyMs) == OK) {
-        result.appendFormat("  latency: %.2lf", latencyMs);
+        result.appendFormat("  latency: %.2lf ms", latencyMs);
     }
     return result;
 }
diff --git a/services/audioflinger/PlaybackTracks.h b/services/audioflinger/PlaybackTracks.h
index 4d5f6b0..53ea9a4 100644
--- a/services/audioflinger/PlaybackTracks.h
+++ b/services/audioflinger/PlaybackTracks.h
@@ -51,18 +51,6 @@
 
             void        flush();
             void        destroy();
-            int         name() const { return mName; }
-            void        setName(int name) {
-                LOG_ALWAYS_FATAL_IF(mName >= 0 && name >= 0,
-                        "%s both old name %d and new name %d are valid", __func__, mName, name);
-                mName = name;
-#ifdef TEE_SINK
-                mTee.setId(std::string("_") + std::to_string(mThreadIoHandle)
-                        + "_" + std::to_string(mId)
-                        + "_" + std::to_string(mName)
-                        + "_T");
-#endif
-            }
 
     virtual uint32_t    sampleRate() const;
 
@@ -183,7 +171,6 @@
 
     bool                mResetDone;
     const audio_stream_type_t mStreamType;
-    int                 mName;
     effect_buffer_t     *mMainBuffer;
 
     int32_t             *mAuxBuffer;
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index ac8901c..811f09a 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -2221,48 +2221,17 @@
 }
 
 template<typename T>
-ssize_t AudioFlinger::PlaybackThread::Tracks<T>::add(const sp<T> &track)
-{
-    const ssize_t index = mTracks.add(track);
-    if (index >= 0) {
-        // set name for track when adding.
-        int name;
-        if (mUnusedTrackNames.empty()) {
-            name = mTracks.size() - 1; // new name {0 ... size-1}.
-        } else {
-            // reuse smallest name for deleted track.
-            auto it = mUnusedTrackNames.begin();
-            name = *it;
-            (void)mUnusedTrackNames.erase(it);
-        }
-        track->setName(name);
-    } else {
-        LOG_ALWAYS_FATAL("cannot add track");
-    }
-    return index;
-}
-
-template<typename T>
 ssize_t AudioFlinger::PlaybackThread::Tracks<T>::remove(const sp<T> &track)
 {
-    const int name = track->name();
+    const int trackId = track->id();
     const ssize_t index = mTracks.remove(track);
     if (index >= 0) {
-        // invalidate name when removing from mTracks.
-        LOG_ALWAYS_FATAL_IF(name < 0, "invalid name %d for track on mTracks", name);
-
-        if (mSaveDeletedTrackNames) {
+        if (mSaveDeletedTrackIds) {
             // We can't directly access mAudioMixer since the caller may be outside of threadLoop.
-            // Instead, we add to mDeletedTrackNames which is solely used for mAudioMixer update,
+            // Instead, we add to mDeletedTrackIds which is solely used for mAudioMixer update,
             // to be handled when MixerThread::prepareTracks_l() next changes mAudioMixer.
-            mDeletedTrackNames.emplace(name);
+            mDeletedTrackIds.emplace(trackId);
         }
-
-        mUnusedTrackNames.emplace(name);
-        track->setName(T::TRACK_NAME_PENDING);
-    } else {
-        LOG_ALWAYS_FATAL_IF(name >= 0,
-                "valid name %d for track not in mTracks (returned %zd)", name, index);
     }
     return index;
 }
@@ -4351,14 +4320,14 @@
 AudioFlinger::PlaybackThread::mixer_state AudioFlinger::MixerThread::prepareTracks_l(
         Vector< sp<Track> > *tracksToRemove)
 {
-    // clean up deleted track names in AudioMixer before allocating new tracks
-    (void)mTracks.processDeletedTrackNames([this](int name) {
-        // for each name, destroy it in the AudioMixer
-        if (mAudioMixer->exists(name)) {
-            mAudioMixer->destroy(name);
+    // clean up deleted track ids in AudioMixer before allocating new tracks
+    (void)mTracks.processDeletedTrackIds([this](int trackId) {
+        // for each trackId, destroy it in the AudioMixer
+        if (mAudioMixer->exists(trackId)) {
+            mAudioMixer->destroy(trackId);
         }
     });
-    mTracks.clearDeletedTrackNames();
+    mTracks.clearDeletedTrackIds();
 
     mixer_state mixerStatus = MIXER_IDLE;
     // find out which tracks need to be processed
@@ -4617,19 +4586,21 @@
 
         // The first time a track is added we wait
         // for all its buffers to be filled before processing it
-        int name = track->name();
+        const int trackId = track->id();
 
         // if an active track doesn't exist in the AudioMixer, create it.
-        if (!mAudioMixer->exists(name)) {
+        // use the trackId as the AudioMixer name.
+        if (!mAudioMixer->exists(trackId)) {
             status_t status = mAudioMixer->create(
-                    name,
+                    trackId,
                     track->mChannelMask,
                     track->mFormat,
                     track->mSessionId);
             if (status != OK) {
-                ALOGW("%s: cannot create track name"
-                        " %d, mask %#x, format %#x, sessionId %d in AudioMixer",
-                        __func__, name, track->mChannelMask, track->mFormat, track->mSessionId);
+                ALOGW("%s(): AudioMixer cannot create track(%d)"
+                        " mask %#x, format %#x, sessionId %d",
+                        __func__, trackId,
+                        track->mChannelMask, track->mFormat, track->mSessionId);
                 tracksToRemove->add(track);
                 track->invalidate(); // consider it dead.
                 continue;
@@ -4650,7 +4621,7 @@
         // TODO: ONLY USED FOR LEGACY RESAMPLERS, remove when they are removed.
         // add frames already consumed but not yet released by the resampler
         // because mAudioTrackServerProxy->framesReady() will include these frames
-        desiredFrames += mAudioMixer->getUnreleasedFrames(track->name());
+        desiredFrames += mAudioMixer->getUnreleasedFrames(trackId);
 
         uint32_t minFrames = 1;
         if ((track->sharedBuffer() == 0) && !track->isStopped() && !track->isPausing() &&
@@ -4662,13 +4633,13 @@
         if (ATRACE_ENABLED()) {
             // I wish we had formatted trace names
             std::string traceName("nRdy");
-            traceName += std::to_string(track->name());
+            traceName += std::to_string(trackId);
             ATRACE_INT(traceName.c_str(), framesReady);
         }
         if ((framesReady >= minFrames) && track->isReady() &&
                 !track->isPaused() && !track->isTerminated())
         {
-            ALOGVV("track %d s=%08x [OK] on thread %p", name, cblk->mServer, this);
+            ALOGVV("track(%d) s=%08x [OK] on thread %p", trackId, cblk->mServer, this);
 
             mixedTracks++;
 
@@ -4685,9 +4656,9 @@
                 if (chain != 0) {
                     tracksWithEffect++;
                 } else {
-                    ALOGW("prepareTracks_l(): track %d attached to effect but no chain found on "
+                    ALOGW("prepareTracks_l(): track(%d) attached to effect but no chain found on "
                             "session %d",
-                            name, track->sessionId());
+                            trackId, track->sessionId());
                 }
             }
 
@@ -4700,7 +4671,7 @@
                     track->mState = TrackBase::ACTIVE;
                     param = AudioMixer::RAMP_VOLUME;
                 }
-                mAudioMixer->setParameter(name, AudioMixer::RESAMPLE, AudioMixer::RESET, NULL);
+                mAudioMixer->setParameter(trackId, AudioMixer::RESAMPLE, AudioMixer::RESET, NULL);
                 mLeftVolFloat = -1.0;
             // FIXME should not make a decision based on mServer
             } else if (cblk->mServer != 0) {
@@ -4796,22 +4767,22 @@
                }
             }
             // XXX: these things DON'T need to be done each time
-            mAudioMixer->setBufferProvider(name, track);
-            mAudioMixer->enable(name);
+            mAudioMixer->setBufferProvider(trackId, track);
+            mAudioMixer->enable(trackId);
 
-            mAudioMixer->setParameter(name, param, AudioMixer::VOLUME0, &vlf);
-            mAudioMixer->setParameter(name, param, AudioMixer::VOLUME1, &vrf);
-            mAudioMixer->setParameter(name, param, AudioMixer::AUXLEVEL, &vaf);
+            mAudioMixer->setParameter(trackId, param, AudioMixer::VOLUME0, &vlf);
+            mAudioMixer->setParameter(trackId, param, AudioMixer::VOLUME1, &vrf);
+            mAudioMixer->setParameter(trackId, param, AudioMixer::AUXLEVEL, &vaf);
             mAudioMixer->setParameter(
-                name,
+                trackId,
                 AudioMixer::TRACK,
                 AudioMixer::FORMAT, (void *)track->format());
             mAudioMixer->setParameter(
-                name,
+                trackId,
                 AudioMixer::TRACK,
                 AudioMixer::CHANNEL_MASK, (void *)(uintptr_t)track->channelMask());
             mAudioMixer->setParameter(
-                name,
+                trackId,
                 AudioMixer::TRACK,
                 AudioMixer::MIXER_CHANNEL_MASK, (void *)(uintptr_t)mChannelMask);
             // limit track sample rate to 2 x output sample rate, which changes at re-configuration
@@ -4823,14 +4794,14 @@
                 reqSampleRate = maxSampleRate;
             }
             mAudioMixer->setParameter(
-                name,
+                trackId,
                 AudioMixer::RESAMPLE,
                 AudioMixer::SAMPLE_RATE,
                 (void *)(uintptr_t)reqSampleRate);
 
             AudioPlaybackRate playbackRate = track->mAudioTrackServerProxy->getPlaybackRate();
             mAudioMixer->setParameter(
-                name,
+                trackId,
                 AudioMixer::TIMESTRETCH,
                 AudioMixer::PLAYBACK_RATE,
                 &playbackRate);
@@ -4851,27 +4822,27 @@
                     && (track->mainBuffer() == mSinkBuffer
                             || track->mainBuffer() == mMixerBuffer)) {
                 mAudioMixer->setParameter(
-                        name,
+                        trackId,
                         AudioMixer::TRACK,
                         AudioMixer::MIXER_FORMAT, (void *)mMixerBufferFormat);
                 mAudioMixer->setParameter(
-                        name,
+                        trackId,
                         AudioMixer::TRACK,
                         AudioMixer::MAIN_BUFFER, (void *)mMixerBuffer);
                 // TODO: override track->mainBuffer()?
                 mMixerBufferValid = true;
             } else {
                 mAudioMixer->setParameter(
-                        name,
+                        trackId,
                         AudioMixer::TRACK,
                         AudioMixer::MIXER_FORMAT, (void *)EFFECT_BUFFER_FORMAT);
                 mAudioMixer->setParameter(
-                        name,
+                        trackId,
                         AudioMixer::TRACK,
                         AudioMixer::MAIN_BUFFER, (void *)track->mainBuffer());
             }
             mAudioMixer->setParameter(
-                name,
+                trackId,
                 AudioMixer::TRACK,
                 AudioMixer::AUX_BUFFER, (void *)track->auxBuffer());
 
@@ -4888,8 +4859,8 @@
         } else {
             size_t underrunFrames = 0;
             if (framesReady < desiredFrames && !track->isStopped() && !track->isPaused()) {
-                ALOGV("track(%p) underrun,  framesReady(%zu) < framesDesired(%zd)",
-                        track, framesReady, desiredFrames);
+                ALOGV("track(%d) underrun,  framesReady(%zu) < framesDesired(%zd)",
+                        trackId, framesReady, desiredFrames);
                 underrunFrames = desiredFrames;
             }
             deferredOperations.tallyUnderrunFrames(track, underrunFrames);
@@ -4901,7 +4872,7 @@
                 chain->clearInputBuffer();
             }
 
-            ALOGVV("track %d s=%08x [NOT READY] on thread %p", name, cblk->mServer, this);
+            ALOGVV("track(%d) s=%08x [NOT READY] on thread %p", trackId, cblk->mServer, this);
             if ((track->sharedBuffer() != 0) || track->isTerminated() ||
                     track->isStopped() || track->isPaused()) {
                 // We have consumed all the buffers of this track.
@@ -4920,7 +4891,8 @@
                 // No buffers for this track. Give it a few chances to
                 // fill a buffer, then remove it from active list.
                 if (--(track->mRetryCount) <= 0) {
-                    ALOGI("BUFFER TIMEOUT: remove(%d) from active list on thread %p", name, this);
+                    ALOGI("BUFFER TIMEOUT: remove(%d) from active list on thread %p",
+                            trackId, this);
                     tracksToRemove->add(track);
                     // indicate to client process that the track was disabled because of underrun;
                     // it will then automatically call start() when data is available
@@ -4933,7 +4905,7 @@
                     mixerStatus = MIXER_TRACKS_ENABLED;
                 }
             }
-            mAudioMixer->disable(name);
+            mAudioMixer->disable(trackId);
         }
 
         }   // local variable scope to avoid goto warning
@@ -4994,9 +4966,9 @@
     // of prepareTracks_l(); this releases any outstanding buffer back to the track.
     // See also the implementation of destroyTrack_l().
     for (const auto &track : *tracksToRemove) {
-        const int name = track->name();
-        if (mAudioMixer->exists(name)) { // Normal tracks here, fast tracks in FastMixer.
-            mAudioMixer->setBufferProvider(name, nullptr /* bufferProvider */);
+        const int trackId = track->id();
+        if (mAudioMixer->exists(trackId)) { // Normal tracks here, fast tracks in FastMixer.
+            mAudioMixer->setBufferProvider(trackId, nullptr /* bufferProvider */);
         }
     }
 
@@ -5165,17 +5137,17 @@
             delete mAudioMixer;
             mAudioMixer = new AudioMixer(mNormalFrameCount, mSampleRate);
             for (const auto &track : mTracks) {
-                const int name = track->name();
+                const int trackId = track->id();
                 status_t status = mAudioMixer->create(
-                        name,
+                        trackId,
                         track->mChannelMask,
                         track->mFormat,
                         track->mSessionId);
                 ALOGW_IF(status != NO_ERROR,
-                        "%s: cannot create track name"
-                        " %d, mask %#x, format %#x, sessionId %d in AudioMixer",
+                        "%s(): AudioMixer cannot create track(%d)"
+                        " mask %#x, format %#x, sessionId %d",
                         __func__,
-                        name, track->mChannelMask, track->mFormat, track->mSessionId);
+                        trackId, track->mChannelMask, track->mFormat, track->mSessionId);
             }
             sendIoConfigEvent_l(AUDIO_OUTPUT_CONFIG_CHANGED);
         }
@@ -5429,7 +5401,7 @@
         if ((track->framesReady() >= minFrames) && track->isReady() && !track->isPaused() &&
                 !track->isStopping_2() && !track->isStopped())
         {
-            ALOGVV("track %d s=%08x [OK]", track->name(), cblk->mServer);
+            ALOGVV("track(%d) s=%08x [OK]", track->id(), cblk->mServer);
 
             if (track->mFillingUpStatus == Track::FS_FILLED) {
                 track->mFillingUpStatus = Track::FS_ACTIVE;
@@ -5505,7 +5477,7 @@
                 // fill a buffer, then remove it from active list.
                 // Only consider last track started for mixer state control
                 if (--(track->mRetryCount) <= 0) {
-                    ALOGV("BUFFER TIMEOUT: remove(%d) from active list", track->name());
+                    ALOGV("BUFFER TIMEOUT: remove track(%d) from active list", track->id());
                     tracksToRemove->add(track);
                     // indicate to client process that the track was disabled because of underrun;
                     // it will then automatically call start() when data is available
@@ -5988,7 +5960,7 @@
             }
         }  else if (track->framesReady() && track->isReady() &&
                 !track->isPaused() && !track->isTerminated() && !track->isStopping_2()) {
-            ALOGVV("OffloadThread: track %d s=%08x [OK]", track->name(), cblk->mServer);
+            ALOGVV("OffloadThread: track(%d) s=%08x [OK]", track->id(), cblk->mServer);
             if (track->mFillingUpStatus == Track::FS_FILLED) {
                 track->mFillingUpStatus = Track::FS_ACTIVE;
                 if (last) {
@@ -6032,7 +6004,7 @@
                 mixerStatus = MIXER_TRACKS_READY;
             }
         } else {
-            ALOGVV("OffloadThread: track %d s=%08x [NOT READY]", track->name(), cblk->mServer);
+            ALOGVV("OffloadThread: track(%d) s=%08x [NOT READY]", track->id(), cblk->mServer);
             if (track->isStopping_1()) {
                 if (--(track->mRetryCount) <= 0) {
                     // Hardware buffer can hold a large amount of audio so we must
@@ -6108,8 +6080,8 @@
                     if (running) { // still running, give us more time.
                         track->mRetryCount = kMaxTrackRetriesOffload;
                     } else {
-                        ALOGV("OffloadThread: BUFFER TIMEOUT: remove(%d) from active list",
-                                track->name());
+                        ALOGV("OffloadThread: BUFFER TIMEOUT: remove track(%d) from active list",
+                                track->id());
                         tracksToRemove->add(track);
                         // tell client process that the track was disabled because of underrun;
                         // it will then automatically call start() when data is available
@@ -6292,7 +6264,7 @@
         ss << ":";
         for (const auto &track : mOutputTracks) {
             const sp<ThreadBase> thread = track->thread().promote();
-            ss << " (" << track->name() << " : ";
+            ss << " (" << track->id() << " : ";
             if (thread.get() != nullptr) {
                 ss << thread.get() << ", " << thread->id();
             } else {
diff --git a/services/audioflinger/Threads.h b/services/audioflinger/Threads.h
index dce3d2e..b6e8abf 100644
--- a/services/audioflinger/Threads.h
+++ b/services/audioflinger/Threads.h
@@ -962,16 +962,19 @@
     virtual void dumpInternals(int fd, const Vector<String16>& args);
     void        dumpTracks(int fd, const Vector<String16>& args);
 
-    // The Tracks class manages names for all tracks
-    // added and removed from the Thread.
+    // The Tracks class manages tracks added and removed from the Thread.
     template <typename T>
     class Tracks {
     public:
-        Tracks(bool saveDeletedTrackNames) :
-            mSaveDeletedTrackNames(saveDeletedTrackNames) { }
+        Tracks(bool saveDeletedTrackIds) :
+            mSaveDeletedTrackIds(saveDeletedTrackIds) { }
 
         // SortedVector methods
-        ssize_t         add(const sp<T> &track);
+        ssize_t         add(const sp<T> &track) {
+            const ssize_t index = mTracks.add(track);
+            LOG_ALWAYS_FATAL_IF(index < 0, "cannot add track");
+            return index;
+        }
         ssize_t         remove(const sp<T> &track);
         size_t          size() const {
             return mTracks.size();
@@ -992,28 +995,19 @@
             return mTracks.end();
         }
 
-        size_t          processDeletedTrackNames(std::function<void(int)> f) {
-            const size_t size = mDeletedTrackNames.size();
-            if (size > 0) {
-                for (const int name : mDeletedTrackNames) {
-                    f(name);
-                }
+        size_t          processDeletedTrackIds(std::function<void(int)> f) {
+            for (const int trackId : mDeletedTrackIds) {
+                f(trackId);
             }
-            return size;
+            return mDeletedTrackIds.size();
         }
 
-        void            clearDeletedTrackNames() { mDeletedTrackNames.clear(); }
+        void            clearDeletedTrackIds() { mDeletedTrackIds.clear(); }
 
     private:
-        // Track names pending deletion for MIXER type threads
-        const bool mSaveDeletedTrackNames; // true to enable tracking
-        std::set<int> mDeletedTrackNames;
-
-        // Fast lookup of previously deleted track names for reuse.
-        // This is an arbitrary decision (actually any non-negative
-        // integer that isn't in mTracks[*]->names() could be used) - we attempt
-        // to use the smallest possible available name.
-        std::set<int> mUnusedTrackNames;
+        // Tracks pending deletion for MIXER type threads
+        const bool mSaveDeletedTrackIds; // true to enable tracking
+        std::set<int> mDeletedTrackIds;
 
         SortedVector<sp<T>> mTracks; // wrapped SortedVector.
     };
diff --git a/services/audioflinger/TrackBase.h b/services/audioflinger/TrackBase.h
index a43cb75..92e79f2 100644
--- a/services/audioflinger/TrackBase.h
+++ b/services/audioflinger/TrackBase.h
@@ -54,11 +54,6 @@
         TYPE_PATCH,
     };
 
-    enum {
-        TRACK_NAME_PENDING = -1,
-        TRACK_NAME_FAILURE = -2,
-    };
-
                         TrackBase(ThreadBase *thread,
                                 const sp<Client>& client,
                                 const audio_attributes_t& mAttr,
@@ -199,6 +194,7 @@
                         }
 
            audio_format_t format() const { return mFormat; }
+           int id() const { return mId; }
 
 protected:
     DISALLOW_COPY_AND_ASSIGN(TrackBase);
diff --git a/services/audioflinger/Tracks.cpp b/services/audioflinger/Tracks.cpp
index 78e6c6c..6a3b06d 100644
--- a/services/audioflinger/Tracks.cpp
+++ b/services/audioflinger/Tracks.cpp
@@ -56,6 +56,8 @@
 // ----------------------------------------------------------------------------
 //      TrackBase
 // ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::TrackBase"
 
 static volatile int32_t nextTrackId = 55;
 
@@ -104,7 +106,8 @@
     const uid_t callingUid = IPCThreadState::self()->getCallingUid();
     if (!isAudioServerOrMediaServerUid(callingUid) || clientUid == AUDIO_UID_INVALID) {
         ALOGW_IF(clientUid != AUDIO_UID_INVALID && clientUid != callingUid,
-                "%s uid %d tried to pass itself off as %d", __FUNCTION__, callingUid, clientUid);
+                "%s(%d): uid %d tried to pass itself off as %d",
+                 __func__, mId, callingUid, clientUid);
         clientUid = callingUid;
     }
     // clientUid contains the uid of the app that is responsible for this track, so we can blame
@@ -144,7 +147,7 @@
         mCblkMemory = client->heap()->allocate(size);
         if (mCblkMemory == 0 ||
                 (mCblk = static_cast<audio_track_cblk_t *>(mCblkMemory->pointer())) == NULL) {
-            ALOGE("not enough memory for AudioTrack size=%zu", size);
+            ALOGE("%s(%d): not enough memory for AudioTrack size=%zu", __func__, mId, size);
             client->heap()->dump("AudioTrack");
             mCblkMemory.clear();
             return;
@@ -152,7 +155,7 @@
     } else {
         mCblk = (audio_track_cblk_t *) malloc(size);
         if (mCblk == NULL) {
-            ALOGE("not enough memory for AudioTrack size=%zu", size);
+            ALOGE("%s(%d): not enough memory for AudioTrack size=%zu", __func__, mId, size);
             return;
         }
     }
@@ -166,7 +169,8 @@
             if (roHeap == 0 ||
                     (mBufferMemory = roHeap->allocate(bufferSize)) == 0 ||
                     (mBuffer = mBufferMemory->pointer()) == NULL) {
-                ALOGE("not enough memory for read-only buffer size=%zu", bufferSize);
+                ALOGE("%s(%d): not enough memory for read-only buffer size=%zu",
+                        __func__, mId, bufferSize);
                 if (roHeap != 0) {
                     roHeap->dump("buffer");
                 }
@@ -205,7 +209,7 @@
             mBuffer = buffer;
             break;
         default:
-            LOG_ALWAYS_FATAL("invalid allocation type: %d", (int)alloc);
+            LOG_ALWAYS_FATAL("%s(%d): invalid allocation type: %d", __func__, mId, (int)alloc);
         }
         mBufferSize = bufferSize;
 
@@ -276,6 +280,8 @@
 // ----------------------------------------------------------------------------
 //      Playback
 // ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::TrackHandle"
 
 AudioFlinger::TrackHandle::TrackHandle(const sp<AudioFlinger::PlaybackThread::Track>& track)
     : BnAudioTrack(),
@@ -348,6 +354,8 @@
 }
 
 // ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::Track"
 
 // Track constructor must be called with AudioFlinger::mLock and ThreadBase::mLock held
 AudioFlinger::PlaybackThread::Track::Track(
@@ -377,7 +385,6 @@
     // mRetryCount initialized later when needed
     mSharedBuffer(sharedBuffer),
     mStreamType(streamType),
-    mName(TRACK_NAME_FAILURE),  // set to TRACK_NAME_PENDING on constructor success.
     mMainBuffer(thread->sinkBuffer()),
     mAuxBuffer(NULL),
     mAuxEffectId(0), mHasVolumeController(false),
@@ -397,8 +404,8 @@
     // client == 0 implies sharedBuffer == 0
     ALOG_ASSERT(!(client == 0 && sharedBuffer != 0));
 
-    ALOGV_IF(sharedBuffer != 0, "sharedBuffer: %p, size: %zu", sharedBuffer->pointer(),
-            sharedBuffer->size());
+    ALOGV_IF(sharedBuffer != 0, "%s(%d): sharedBuffer: %p, size: %zu",
+            __func__, mId, sharedBuffer->pointer(), sharedBuffer->size());
 
     if (mCblk == NULL) {
         return;
@@ -414,7 +421,7 @@
     mServerProxy = mAudioTrackServerProxy;
 
     if (!thread->isTrackAllowed_l(channelMask, format, sessionId, uid)) {
-        ALOGE("no more tracks available");
+        ALOGE("%s(%d): no more tracks available", __func__, mId);
         return;
     }
     // only allocate a fast track index if we were able to allocate a normal track name
@@ -433,20 +440,18 @@
         mFastIndex = i;
         thread->mFastTrackAvailMask &= ~(1 << i);
     }
-    mName = TRACK_NAME_PENDING;
 
     mServerLatencySupported = thread->type() == ThreadBase::MIXER
             || thread->type() == ThreadBase::DUPLICATING;
 #ifdef TEE_SINK
     mTee.setId(std::string("_") + std::to_string(mThreadIoHandle)
-            + "_" + std::to_string(mId) +
-            + "_PEND_T");
+            + "_" + std::to_string(mId));
 #endif
 }
 
 AudioFlinger::PlaybackThread::Track::~Track()
 {
-    ALOGV("PlaybackThread::Track destructor");
+    ALOGV("%s(%d)", __func__, mId);
 
     // The destructor would clear mSharedBuffer,
     // but it will not push the decremented reference count,
@@ -460,7 +465,7 @@
 status_t AudioFlinger::PlaybackThread::Track::initCheck() const
 {
     status_t status = TrackBase::initCheck();
-    if (status == NO_ERROR && mName == TRACK_NAME_FAILURE) {
+    if (status == NO_ERROR && mCblk == nullptr) {
         status = NO_MEMORY;
     }
     return status;
@@ -493,7 +498,7 @@
 
 void AudioFlinger::PlaybackThread::Track::appendDumpHeader(String8& result)
 {
-    result.appendFormat("T Name Active Client Session S  Flags "
+    result.appendFormat("Type     Id Active Client Session S  Flags "
                         "  Format Chn mask  SRate "
                         "ST Usg CT "
                         " G db  L dB  R dB  VS dB "
@@ -522,13 +527,9 @@
     }
 
     if (isFastTrack()) {
-        result.appendFormat("F%c %3d", trackType, mFastIndex);
-    } else if (mName == TRACK_NAME_PENDING) {
-        result.appendFormat("%c pend", trackType);
-    } else if (mName == TRACK_NAME_FAILURE) {
-        result.appendFormat("%c fail", trackType);
+        result.appendFormat("F%d %c %6d", mFastIndex, trackType, mId);
     } else {
-        result.appendFormat("%c %4d", trackType, mName);
+        result.appendFormat("   %c %6d", trackType, mId);
     }
 
     char nowInUnderrun;
@@ -647,8 +648,8 @@
     buffer->frameCount = buf.mFrameCount;
     buffer->raw = buf.mRaw;
     if (buf.mFrameCount == 0 && !isStopping() && !isStopped() && !isPaused()) {
-        ALOGV("underrun,  framesReady(%zu) < framesDesired(%zd), state: %d",
-                buf.mFrameCount, desiredFrames, mState);
+        ALOGV("%s(%d): underrun,  framesReady(%zu) < framesDesired(%zd), state: %d",
+                __func__, mId, buf.mFrameCount, desiredFrames, mState);
         mAudioTrackServerProxy->tallyUnderrunFrames(desiredFrames);
     } else {
         mAudioTrackServerProxy->tallyUnderrunFrames(0);
@@ -721,8 +722,8 @@
                                                     audio_session_t triggerSession __unused)
 {
     status_t status = NO_ERROR;
-    ALOGV("start(%d), calling pid %d session %d",
-            mName, IPCThreadState::self()->getCallingPid(), mSessionId);
+    ALOGV("%s(%d): calling pid %d session %d",
+            __func__, mId, IPCThreadState::self()->getCallingPid(), mSessionId);
 
     sp<ThreadBase> thread = mThread.promote();
     if (thread != 0) {
@@ -748,14 +749,17 @@
             if (mResumeToStopping) {
                 // happened we need to resume to STOPPING_1
                 mState = TrackBase::STOPPING_1;
-                ALOGV("PAUSED => STOPPING_1 (%d) on thread %p", mName, this);
+                ALOGV("%s(%d): PAUSED => STOPPING_1 on thread %d",
+                        __func__, mId, (int)mThreadIoHandle);
             } else {
                 mState = TrackBase::RESUMING;
-                ALOGV("PAUSED => RESUMING (%d) on thread %p", mName, this);
+                ALOGV("%s(%d): PAUSED => RESUMING on thread %d",
+                        __func__,  mId, (int)mThreadIoHandle);
             }
         } else {
             mState = TrackBase::ACTIVE;
-            ALOGV("? => ACTIVE (%d) on thread %p", mName, this);
+            ALOGV("%s(%d): ? => ACTIVE on thread %d",
+                    __func__, mId, (int)mThreadIoHandle);
         }
 
         // states to reset position info for non-offloaded/direct tracks
@@ -806,7 +810,7 @@
 
 void AudioFlinger::PlaybackThread::Track::stop()
 {
-    ALOGV("stop(%d), calling pid %d", mName, IPCThreadState::self()->getCallingPid());
+    ALOGV("%s(%d): calling pid %d", __func__, mId, IPCThreadState::self()->getCallingPid());
     sp<ThreadBase> thread = mThread.promote();
     if (thread != 0) {
         Mutex::Autolock _l(thread->mLock);
@@ -830,15 +834,15 @@
                 }
             }
             playbackThread->broadcast_l();
-            ALOGV("not stopping/stopped => stopping/stopped (%d) on thread %p", mName,
-                    playbackThread);
+            ALOGV("%s(%d): not stopping/stopped => stopping/stopped on thread %d",
+                    __func__, mId, (int)mThreadIoHandle);
         }
     }
 }
 
 void AudioFlinger::PlaybackThread::Track::pause()
 {
-    ALOGV("pause(%d), calling pid %d", mName, IPCThreadState::self()->getCallingPid());
+    ALOGV("%s(%d): calling pid %d", __func__, mId, IPCThreadState::self()->getCallingPid());
     sp<ThreadBase> thread = mThread.promote();
     if (thread != 0) {
         Mutex::Autolock _l(thread->mLock);
@@ -857,7 +861,8 @@
         case ACTIVE:
         case RESUMING:
             mState = PAUSING;
-            ALOGV("ACTIVE/RESUMING => PAUSING (%d) on thread %p", mName, thread.get());
+            ALOGV("%s(%d): ACTIVE/RESUMING => PAUSING on thread %d",
+                    __func__, mId, (int)mThreadIoHandle);
             playbackThread->broadcast_l();
             break;
 
@@ -869,7 +874,7 @@
 
 void AudioFlinger::PlaybackThread::Track::flush()
 {
-    ALOGV("flush(%d)", mName);
+    ALOGV("%s(%d)", __func__, mId);
     sp<ThreadBase> thread = mThread.promote();
     if (thread != 0) {
         Mutex::Autolock _l(thread->mLock);
@@ -891,11 +896,12 @@
                 return;
             }
 
-            ALOGV("flush: offload flush");
+            ALOGV("%s(%d): offload flush", __func__, mId);
             reset();
 
             if (mState == STOPPING_1 || mState == STOPPING_2) {
-                ALOGV("flushed in STOPPING_1 or 2 state, change state to ACTIVE");
+                ALOGV("%s(%d): flushed in STOPPING_1 or 2 state, change state to ACTIVE",
+                        __func__, mId);
                 mState = ACTIVE;
             }
 
@@ -960,7 +966,7 @@
 {
     sp<ThreadBase> thread = mThread.promote();
     if (thread == 0) {
-        ALOGE("thread is dead");
+        ALOGE("%s(%d): thread is dead", __func__, mId);
         return FAILED_TRANSACTION;
     } else if ((thread->type() == ThreadBase::DIRECT) ||
                     (thread->type() == ThreadBase::OFFLOAD)) {
@@ -980,8 +986,10 @@
         const VolumeShaper::Configuration::OptionFlag optionFlag
             = configuration->getOptionFlags();
         if ((optionFlag & VolumeShaper::Configuration::OPTION_FLAG_CLOCK_TIME) == 0) {
-            ALOGW("%s tracks do not support frame counted VolumeShaper,"
-                    " using clock time instead", isOffloaded() ? "Offload" : "Direct");
+            ALOGW("%s(%d): %s tracks do not support frame counted VolumeShaper,"
+                    " using clock time instead",
+                    __func__, mId,
+                    isOffloaded() ? "Offload" : "Direct");
             newConfiguration = new VolumeShaper::Configuration(*configuration);
             newConfiguration->setOptionFlags(
                 VolumeShaper::Configuration::OptionFlag(optionFlag
@@ -1116,11 +1124,14 @@
     // to detect when all frames have been played. In this case framesWritten isn't
     // useful because it doesn't always reflect whether there is data in the h/w
     // buffers, particularly if a track has been paused and resumed during draining
-    ALOGV("presentationComplete() mPresentationCompleteFrames %lld framesWritten %lld",
+    ALOGV("%s(%d): presentationComplete() mPresentationCompleteFrames %lld framesWritten %lld",
+            __func__, mId,
             (long long)mPresentationCompleteFrames, (long long)framesWritten);
     if (mPresentationCompleteFrames == 0) {
         mPresentationCompleteFrames = framesWritten + audioHalFrames;
-        ALOGV("presentationComplete() reset: mPresentationCompleteFrames %lld audioHalFrames %zu",
+        ALOGV("%s(%d): presentationComplete() reset:"
+                " mPresentationCompleteFrames %lld audioHalFrames %zu",
+                __func__, mId,
                 (long long)mPresentationCompleteFrames, audioHalFrames);
     }
 
@@ -1186,7 +1197,8 @@
     if (isTerminated() || mState == PAUSED ||
             ((framesReady() == 0) && ((mSharedBuffer != 0) ||
                                       (mState == STOPPED)))) {
-        ALOGW("Track::setSyncEvent() in invalid state %d on session %d %s mode, framesReady %zu",
+        ALOGW("%s(%d): in invalid state %d on session %d %s mode, framesReady %zu",
+              __func__, mId,
               mState, mSessionId, (mSharedBuffer != 0) ? "static" : "stream", framesReady());
         event->cancel();
         return INVALID_OPERATION;
@@ -1307,6 +1319,8 @@
 }
 
 // ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::OutputTrack"
 
 AudioFlinger::PlaybackThread::OutputTrack::OutputTrack(
             PlaybackThread *playbackThread,
@@ -1328,9 +1342,9 @@
     if (mCblk != NULL) {
         mOutBuffer.frameCount = 0;
         playbackThread->mTracks.add(this);
-        ALOGV("OutputTrack constructor mCblk %p, mBuffer %p, "
+        ALOGV("%s(): mCblk %p, mBuffer %p, "
                 "frameCount %zu, mChannelMask 0x%08x",
-                mCblk, mBuffer,
+                __func__, mCblk, mBuffer,
                 frameCount, mChannelMask);
         // since client and server are in the same process,
         // the buffer has the same virtual address on both sides
@@ -1340,7 +1354,8 @@
         mClientProxy->setSendLevel(0.0);
         mClientProxy->setSampleRate(sampleRate);
     } else {
-        ALOGW("Error creating output track on thread %p", playbackThread);
+        ALOGW("%s(%d): Error creating output track on thread %d",
+                __func__, mId, (int)mThreadIoHandle);
     }
 }
 
@@ -1402,8 +1417,9 @@
             nsecs_t startTime = systemTime();
             status_t status = obtainBuffer(&mOutBuffer, waitTimeLeftMs);
             if (status != NO_ERROR && status != NOT_ENOUGH_DATA) {
-                ALOGV("OutputTrack::write() %p thread %p no more output buffers; status %d", this,
-                        mThread.unsafe_get(), status);
+                ALOGV("%s(%d): thread %d no more output buffers; status %d",
+                        __func__, mId,
+                        (int)mThreadIoHandle, status);
                 outputBufferFull = true;
                 break;
             }
@@ -1439,8 +1455,9 @@
                 if (pInBuffer != &inBuffer) {
                     delete pInBuffer;
                 }
-                ALOGV("OutputTrack::write() %p thread %p released overflow buffer %zu", this,
-                        mThread.unsafe_get(), mBufferQueue.size());
+                ALOGV("%s(%d): thread %d released overflow buffer %zu",
+                        __func__, mId,
+                        (int)mThreadIoHandle, mBufferQueue.size());
             } else {
                 break;
             }
@@ -1458,13 +1475,13 @@
                 pInBuffer->raw = pInBuffer->mBuffer;
                 memcpy(pInBuffer->raw, inBuffer.raw, inBuffer.frameCount * mFrameSize);
                 mBufferQueue.add(pInBuffer);
-                ALOGV("OutputTrack::write() %p thread %p adding overflow buffer %zu", this,
-                        mThread.unsafe_get(), mBufferQueue.size());
+                ALOGV("%s(%d): thread %d adding overflow buffer %zu", __func__, mId,
+                        (int)mThreadIoHandle, mBufferQueue.size());
                 // audio data is consumed (stored locally); set frameCount to 0.
                 inBuffer.frameCount = 0;
             } else {
-                ALOGW("OutputTrack::write() %p thread %p no more overflow buffers",
-                        mThread.unsafe_get(), this);
+                ALOGW("%s(%d): thread %d no more overflow buffers",
+                        __func__, mId, (int)mThreadIoHandle);
                 // TODO: return error for this.
             }
         }
@@ -1528,6 +1545,10 @@
     }
 }
 
+// ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::PatchTrack"
+
 AudioFlinger::PlaybackThread::PatchTrack::PatchTrack(PlaybackThread *playbackThread,
                                                      audio_stream_type_t streamType,
                                                      uint32_t sampleRate,
@@ -1549,8 +1570,8 @@
     mPeerTimeout.tv_sec = mixBufferNs / 1000000000;
     mPeerTimeout.tv_nsec = (int) (mixBufferNs % 1000000000);
 
-    ALOGV("PatchTrack %p sampleRate %d mPeerTimeout %d.%03d sec",
-                                      this, sampleRate,
+    ALOGV("%s(%d): sampleRate %d mPeerTimeout %d.%03d sec",
+                                      __func__, mId, sampleRate,
                                       (int)mPeerTimeout.tv_sec,
                                       (int)(mPeerTimeout.tv_nsec / 1000000));
 }
@@ -1574,11 +1595,11 @@
 status_t AudioFlinger::PlaybackThread::PatchTrack::getNextBuffer(
         AudioBufferProvider::Buffer* buffer)
 {
-    ALOG_ASSERT(mPeerProxy != 0, "PatchTrack::getNextBuffer() called without peer proxy");
+    ALOG_ASSERT(mPeerProxy != 0, "%s(%d): called without peer proxy", __func__, mId);
     Proxy::Buffer buf;
     buf.mFrameCount = buffer->frameCount;
     status_t status = mPeerProxy->obtainBuffer(&buf, &mPeerTimeout);
-    ALOGV_IF(status != NO_ERROR, "PatchTrack() %p getNextBuffer status %d", this, status);
+    ALOGV_IF(status != NO_ERROR, "%s(%d): getNextBuffer status %d", __func__, mId, status);
     buffer->frameCount = buf.mFrameCount;
     if (buf.mFrameCount == 0) {
         return WOULD_BLOCK;
@@ -1589,7 +1610,7 @@
 
 void AudioFlinger::PlaybackThread::PatchTrack::releaseBuffer(AudioBufferProvider::Buffer* buffer)
 {
-    ALOG_ASSERT(mPeerProxy != 0, "PatchTrack::releaseBuffer() called without peer proxy");
+    ALOG_ASSERT(mPeerProxy != 0, "%s(%d): called without peer proxy", __func__, mId);
     Proxy::Buffer buf;
     buf.mFrameCount = buffer->frameCount;
     buf.mRaw = buffer->raw;
@@ -1624,7 +1645,7 @@
 void AudioFlinger::PlaybackThread::PatchTrack::restartIfDisabled()
 {
     if (android_atomic_and(~CBLK_DISABLED, &mCblk->mFlags) & CBLK_DISABLED) {
-        ALOGW("PatchTrack::releaseBuffer() disabled due to previous underrun, restarting");
+        ALOGW("%s(%d): disabled due to previous underrun, restarting", __func__, mId);
         start();
     }
 }
@@ -1632,6 +1653,8 @@
 // ----------------------------------------------------------------------------
 //      Record
 // ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::RecordHandle"
 
 AudioFlinger::RecordHandle::RecordHandle(
         const sp<AudioFlinger::RecordThread::RecordTrack>& recordTrack)
@@ -1647,7 +1670,7 @@
 
 binder::Status AudioFlinger::RecordHandle::start(int /*AudioSystem::sync_event_t*/ event,
         int /*audio_session_t*/ triggerSession) {
-    ALOGV("RecordHandle::start()");
+    ALOGV("%s()", __func__);
     return binder::Status::fromStatusT(
         mRecordTrack->start((AudioSystem::sync_event_t)event, (audio_session_t) triggerSession));
 }
@@ -1658,18 +1681,20 @@
 }
 
 void AudioFlinger::RecordHandle::stop_nonvirtual() {
-    ALOGV("RecordHandle::stop()");
+    ALOGV("%s()", __func__);
     mRecordTrack->stop();
 }
 
 binder::Status AudioFlinger::RecordHandle::getActiveMicrophones(
         std::vector<media::MicrophoneInfo>* activeMicrophones) {
-    ALOGV("RecordHandle::getActiveMicrophones()");
+    ALOGV("%s()", __func__);
     return binder::Status::fromStatusT(
             mRecordTrack->getActiveMicrophones(activeMicrophones));
 }
 
 // ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::RecordTrack"
 
 // RecordTrack constructor must be called with AudioFlinger::mLock and ThreadBase::mLock held
 AudioFlinger::RecordThread::RecordTrack::RecordTrack(
@@ -1715,7 +1740,7 @@
         // for the current device, but a pending or future device change would make
         // the record track configuration valid.
         if (mRecordBufferConverter->initCheck() != NO_ERROR) {
-            ALOGE("RecordTrack unable to create record buffer converter");
+            ALOGE("%s(%d): RecordTrack unable to create record buffer converter", __func__, mId);
             return;
         }
     }
@@ -1741,7 +1766,7 @@
 
 AudioFlinger::RecordThread::RecordTrack::~RecordTrack()
 {
-    ALOGV("%s", __func__);
+    ALOGV("%s()", __func__);
     delete mRecordBufferConverter;
     delete mResamplerBufferProvider;
 }
@@ -1827,19 +1852,20 @@
 
 void AudioFlinger::RecordThread::RecordTrack::appendDumpHeader(String8& result)
 {
-    result.appendFormat("Active Client Session S  Flags  "
-                        " Format Chn mask  SRate Source "
+    result.appendFormat("Active     Id Client Session S  Flags  "
+                        " Format Chn mask  SRate Source  "
                         " Server FrmCnt FrmRdy Sil%s\n",
                         isServerLatencySupported() ? "   Latency" : "");
 }
 
 void AudioFlinger::RecordThread::RecordTrack::appendDump(String8& result, bool active)
 {
-    result.appendFormat("%c%5s %6u %7u %2s 0x%03X "
+    result.appendFormat("%c%5s %6d %6u %7u %2s 0x%03X "
             "%08X %08X %6u %6X "
             "%08X %6zu %6zu %3c",
             isFastTrack() ? 'F' : ' ',
             active ? "yes" : "no",
+            mId,
             (mClient == 0) ? getpid() : mClient->pid(),
             mSessionId,
             getTrackStateString(),
@@ -1942,6 +1968,10 @@
     }
 }
 
+// ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::PatchRecord"
+
 AudioFlinger::RecordThread::PatchRecord::PatchRecord(RecordThread *recordThread,
                                                      uint32_t sampleRate,
                                                      audio_channel_mask_t channelMask,
@@ -1962,8 +1992,8 @@
     mPeerTimeout.tv_sec = mixBufferNs / 1000000000;
     mPeerTimeout.tv_nsec = (int) (mixBufferNs % 1000000000);
 
-    ALOGV("PatchRecord %p sampleRate %d mPeerTimeout %d.%03d sec",
-                                      this, sampleRate,
+    ALOGV("%s(%d): sampleRate %d mPeerTimeout %d.%03d sec",
+                                      __func__, mId, sampleRate,
                                       (int)mPeerTimeout.tv_sec,
                                       (int)(mPeerTimeout.tv_nsec / 1000000));
 }
@@ -1976,12 +2006,12 @@
 status_t AudioFlinger::RecordThread::PatchRecord::getNextBuffer(
                                                   AudioBufferProvider::Buffer* buffer)
 {
-    ALOG_ASSERT(mPeerProxy != 0, "PatchRecord::getNextBuffer() called without peer proxy");
+    ALOG_ASSERT(mPeerProxy != 0, "%s(%d): called without peer proxy", __func__, mId);
     Proxy::Buffer buf;
     buf.mFrameCount = buffer->frameCount;
     status_t status = mPeerProxy->obtainBuffer(&buf, &mPeerTimeout);
     ALOGV_IF(status != NO_ERROR,
-             "PatchRecord() %p mPeerProxy->obtainBuffer status %d", this, status);
+             "%s(%d): mPeerProxy->obtainBuffer status %d", __func__, mId, status);
     buffer->frameCount = buf.mFrameCount;
     if (buf.mFrameCount == 0) {
         return WOULD_BLOCK;
@@ -1992,7 +2022,7 @@
 
 void AudioFlinger::RecordThread::PatchRecord::releaseBuffer(AudioBufferProvider::Buffer* buffer)
 {
-    ALOG_ASSERT(mPeerProxy != 0, "PatchRecord::releaseBuffer() called without peer proxy");
+    ALOG_ASSERT(mPeerProxy != 0, "%s(%d): called without peer proxy", __func__, mId);
     Proxy::Buffer buf;
     buf.mFrameCount = buffer->frameCount;
     buf.mRaw = buffer->raw;
@@ -2011,7 +2041,9 @@
     mProxy->releaseBuffer(buffer);
 }
 
-
+// ----------------------------------------------------------------------------
+#undef LOG_TAG
+#define LOG_TAG "AF::MmapTrack"
 
 AudioFlinger::MmapThread::MmapTrack::MmapTrack(ThreadBase *thread,
         const audio_attributes_t& attr,
diff --git a/services/audiopolicy/common/include/Volume.h b/services/audiopolicy/common/include/Volume.h
index fc012a2..5ccc8fd 100644
--- a/services/audiopolicy/common/include/Volume.h
+++ b/services/audiopolicy/common/include/Volume.h
@@ -134,6 +134,7 @@
         case AUDIO_DEVICE_OUT_USB_DEVICE:
             return DEVICE_CATEGORY_EXT_MEDIA;
         case AUDIO_DEVICE_OUT_SPEAKER:
+        case AUDIO_DEVICE_OUT_SPEAKER_SAFE:
         case AUDIO_DEVICE_OUT_BLUETOOTH_SCO_CARKIT:
         case AUDIO_DEVICE_OUT_BLUETOOTH_A2DP_SPEAKER:
         case AUDIO_DEVICE_OUT_USB_ACCESSORY:
diff --git a/services/audiopolicy/managerdefault/AudioPolicyManager.cpp b/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
index 60bce9c..dd2158b 100644
--- a/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
+++ b/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
@@ -2696,6 +2696,19 @@
     mPolicyMixes.dump(fd);
     mAudioSources.dump(fd);
 
+    if (!mSurroundFormats.empty()) {
+        result = String8("\nManually Enabled Surround Formats:\n");
+        size_t i = 0;
+        for (const auto& fmt : mSurroundFormats) {
+            result.append(i++ == 0 ? "  " : ", ");
+            std::string sfmt;
+            FormatConverter::toString(fmt, sfmt);
+            result.appendFormat("%s", sfmt.c_str());
+        }
+        result.append("\n");
+        write(fd, result.string(), result.size());
+    }
+
     return NO_ERROR;
 }
 
@@ -3594,8 +3607,8 @@
             (surroundFormats == NULL || surroundFormatsEnabled == NULL))) {
         return BAD_VALUE;
     }
-    ALOGV("getSurroundFormats() numSurroundFormats %d surroundFormats %p surroundFormatsEnabled %p",
-            *numSurroundFormats, surroundFormats, surroundFormatsEnabled);
+    ALOGV("getSurroundFormats() numSurroundFormats %d surroundFormats %p surroundFormatsEnabled %p"
+            " reported %d", *numSurroundFormats, surroundFormats, surroundFormatsEnabled, reported);
 
     // Only return value if there is HDMI output.
     if ((mAvailableOutputDevices.types() & AUDIO_DEVICE_OUT_HDMI) == 0) {
@@ -3698,6 +3711,7 @@
 
 status_t AudioPolicyManager::setSurroundFormatEnabled(audio_format_t audioFormat, bool enabled)
 {
+    ALOGV("%s() format 0x%X enabled %d", __func__, audioFormat, enabled);
     // Check if audio format is a surround formats.
     bool isSurroundFormat = false;
     for (size_t i = 0; i < ARRAY_SIZE(SURROUND_FORMATS); i++) {
@@ -3707,6 +3721,7 @@
         }
     }
     if (!isSurroundFormat) {
+        ALOGW("%s() format 0x%X is not a known surround format", __func__, audioFormat);
         return BAD_VALUE;
     }
 
@@ -3714,6 +3729,7 @@
     audio_policy_forced_cfg_t forceUse = mEngine->getForceUse(
                 AUDIO_POLICY_FORCE_FOR_ENCODED_SURROUND);
     if (forceUse != AUDIO_POLICY_FORCE_ENCODED_SURROUND_MANUAL) {
+        ALOGW("%s() not in manual mode for surround sound format selection", __func__);
         return INVALID_OPERATION;
     }
 
@@ -3724,6 +3740,7 @@
 
     // The operation is valid only when there is HDMI output available.
     if ((mAvailableOutputDevices.types() & AUDIO_DEVICE_OUT_HDMI) == 0) {
+        ALOGW("%s() no HDMI out devices found", __func__);
         return INVALID_OPERATION;
     }
 
@@ -3788,6 +3805,7 @@
 
     // Undo the surround formats change due to no audio profiles updated.
     if (!profileUpdated) {
+        ALOGW("%s() no audio profiles updated, undoing surround formats change", __func__);
         if (enabled) {
             if (audioFormat == AUDIO_FORMAT_AAC_LC) {
                 for (size_t i = 0; i < ARRAY_SIZE(AAC_FORMATS); i++) {
diff --git a/services/camera/libcameraservice/Android.bp b/services/camera/libcameraservice/Android.bp
index eccbe54..706ce3a 100644
--- a/services/camera/libcameraservice/Android.bp
+++ b/services/camera/libcameraservice/Android.bp
@@ -82,6 +82,7 @@
         "android.hardware.camera.device@3.2",
         "android.hardware.camera.device@3.3",
         "android.hardware.camera.device@3.4",
+        "android.hardware.camera.device@3.5",
     ],
 
     export_shared_lib_headers: [
diff --git a/services/camera/libcameraservice/CameraService.cpp b/services/camera/libcameraservice/CameraService.cpp
index f9240db..fbd80e6 100644
--- a/services/camera/libcameraservice/CameraService.cpp
+++ b/services/camera/libcameraservice/CameraService.cpp
@@ -491,6 +491,34 @@
                 strerror(-res), res);
     }
 
+    int callingPid = getCallingPid();
+    int callingUid = getCallingUid();
+    std::vector<int32_t> tagsRemoved;
+    // If it's not calling from cameraserver, check the permission.
+    if ((callingPid != getpid()) &&
+            !checkPermission(String16("android.permission.CAMERA"), callingPid, callingUid)) {
+        res = cameraInfo->removePermissionEntries(
+                mCameraProviderManager->getProviderTagIdLocked(String8(cameraId).string()),
+                &tagsRemoved);
+        if (res != OK) {
+            cameraInfo->clear();
+            return STATUS_ERROR_FMT(ERROR_INVALID_OPERATION, "Failed to remove camera"
+                    " characteristics needing camera permission for device %s: %s (%d)",
+                    String8(cameraId).string(), strerror(-res), res);
+        }
+    }
+
+    if (!tagsRemoved.empty()) {
+        res = cameraInfo->update(ANDROID_REQUEST_CHARACTERISTIC_KEYS_NEEDING_PERMISSION,
+                tagsRemoved.data(), tagsRemoved.size());
+        if (res != OK) {
+            cameraInfo->clear();
+            return STATUS_ERROR_FMT(ERROR_INVALID_OPERATION, "Failed to insert camera "
+                    "keys needing permission for device %s: %s (%d)", String8(cameraId).string(),
+                    strerror(-res), res);
+        }
+    }
+
     return ret;
 }
 
@@ -607,6 +635,7 @@
           case CAMERA_DEVICE_API_VERSION_3_2:
           case CAMERA_DEVICE_API_VERSION_3_3:
           case CAMERA_DEVICE_API_VERSION_3_4:
+          case CAMERA_DEVICE_API_VERSION_3_5:
             if (effectiveApiLevel == API_1) { // Camera1 API route
                 sp<ICameraClient> tmp = static_cast<ICameraClient*>(cameraCb.get());
                 *client = new Camera2Client(cameraService, tmp, packageName,
@@ -1687,7 +1716,7 @@
     }
 
     int deviceVersion = getDeviceVersion(id);
-    switch(deviceVersion) {
+    switch (deviceVersion) {
         case CAMERA_DEVICE_API_VERSION_1_0:
         case CAMERA_DEVICE_API_VERSION_3_0:
         case CAMERA_DEVICE_API_VERSION_3_1:
@@ -1704,6 +1733,7 @@
         case CAMERA_DEVICE_API_VERSION_3_2:
         case CAMERA_DEVICE_API_VERSION_3_3:
         case CAMERA_DEVICE_API_VERSION_3_4:
+        case CAMERA_DEVICE_API_VERSION_3_5:
             ALOGV("%s: Camera id %s uses HAL3.2 or newer, supports api1/api2 directly",
                     __FUNCTION__, id.string());
             *isSupported = true;
@@ -1724,6 +1754,18 @@
     return Status::ok();
 }
 
+Status CameraService::isHiddenPhysicalCamera(const String16& cameraId,
+        /*out*/ bool *isSupported) {
+    ATRACE_CALL();
+
+    const String8 id = String8(cameraId);
+
+    ALOGV("%s: for camera ID = %s", __FUNCTION__, id.string());
+    *isSupported = mCameraProviderManager->isHiddenPhysicalCamera(id.string());
+
+    return Status::ok();
+}
+
 void CameraService::removeByClient(const BasicClient* client) {
     Mutex::Autolock lock(mServiceLock);
     for (auto& i : mActiveClientManager.getAll()) {
diff --git a/services/camera/libcameraservice/CameraService.h b/services/camera/libcameraservice/CameraService.h
index e4a18d3..47ad8af 100644
--- a/services/camera/libcameraservice/CameraService.h
+++ b/services/camera/libcameraservice/CameraService.h
@@ -159,6 +159,11 @@
             /*out*/
             bool *isSupported);
 
+    virtual binder::Status    isHiddenPhysicalCamera(
+            const String16& cameraId,
+            /*out*/
+            bool *isSupported);
+
     // Extra permissions checks
     virtual status_t    onTransact(uint32_t code, const Parcel& data,
                                    Parcel* reply, uint32_t flags);
diff --git a/services/camera/libcameraservice/common/CameraProviderManager.cpp b/services/camera/libcameraservice/common/CameraProviderManager.cpp
index 3be6399..c4944a6 100644
--- a/services/camera/libcameraservice/common/CameraProviderManager.cpp
+++ b/services/camera/libcameraservice/common/CameraProviderManager.cpp
@@ -20,9 +20,12 @@
 
 #include "CameraProviderManager.h"
 
+#include <android/hardware/camera/device/3.5/ICameraDevice.h>
+
 #include <algorithm>
 #include <chrono>
 #include <inttypes.h>
+#include <hardware/camera_common.h>
 #include <hidl/ServiceManagement.h>
 #include <functional>
 #include <camera_metadata_hidden.h>
@@ -424,6 +427,48 @@
     return true;
 }
 
+bool CameraProviderManager::isHiddenPhysicalCamera(const std::string& cameraId) {
+    for (auto& provider : mProviders) {
+        for (auto& deviceInfo : provider->mDevices) {
+            if (deviceInfo->mId == cameraId) {
+                // cameraId is found in public camera IDs advertised by the
+                // provider.
+                return false;
+            }
+        }
+    }
+
+    for (auto& provider : mProviders) {
+        for (auto& deviceInfo : provider->mDevices) {
+            CameraMetadata info;
+            status_t res = deviceInfo->getCameraCharacteristics(&info);
+            if (res != OK) {
+                ALOGE("%s: Failed to getCameraCharacteristics for id %s", __FUNCTION__,
+                        deviceInfo->mId.c_str());
+                return false;
+            }
+
+            std::vector<std::string> physicalIds;
+            if (isLogicalCamera(info, &physicalIds)) {
+                if (std::find(physicalIds.begin(), physicalIds.end(), cameraId) !=
+                        physicalIds.end()) {
+                    int deviceVersion = HARDWARE_DEVICE_API_VERSION(
+                            deviceInfo->mVersion.get_major(), deviceInfo->mVersion.get_minor());
+                    if (deviceVersion < CAMERA_DEVICE_API_VERSION_3_5) {
+                        ALOGE("%s: Wrong deviceVersion %x for hiddenPhysicalCameraId %s",
+                                __FUNCTION__, deviceVersion, cameraId.c_str());
+                        return false;
+                    } else {
+                        return true;
+                    }
+                }
+            }
+        }
+    }
+
+    return false;
+}
+
 status_t CameraProviderManager::addProviderLocked(const std::string& newProvider, bool expected) {
     for (const auto& providerInfo : mProviders) {
         if (providerInfo->mProviderName == newProvider) {
@@ -544,13 +589,22 @@
 
     // Get initial list of camera devices, if any
     std::vector<std::string> devices;
-    hardware::Return<void> ret = mInterface->getCameraIdList([&status, &devices](
+    hardware::Return<void> ret = mInterface->getCameraIdList([&status, this, &devices](
             Status idStatus,
             const hardware::hidl_vec<hardware::hidl_string>& cameraDeviceNames) {
         status = idStatus;
         if (status == Status::OK) {
-            for (size_t i = 0; i < cameraDeviceNames.size(); i++) {
-                devices.push_back(cameraDeviceNames[i]);
+            for (auto& name : cameraDeviceNames) {
+                uint16_t major, minor;
+                std::string type, id;
+                status_t res = parseDeviceName(name, &major, &minor, &type, &id);
+                if (res != OK) {
+                    ALOGE("%s: Error parsing deviceName: %s: %d", __FUNCTION__, name.c_str(), res);
+                    status = Status::INTERNAL_ERROR;
+                } else {
+                    devices.push_back(name);
+                    mProviderPublicCameraIds.push_back(id);
+                }
             }
         } });
     if (!ret.isOk()) {
@@ -705,6 +759,25 @@
             info2.dump(fd, /*verbosity*/ 2, /*indentation*/ 4);
         }
 
+        // Dump characteristics of non-standalone physical camera
+        std::vector<std::string> physicalIds;
+        if (isLogicalCamera(info2, &physicalIds)) {
+            for (auto& id : physicalIds) {
+                // Skip if physical id is an independent camera
+                if (std::find(mProviderPublicCameraIds.begin(), mProviderPublicCameraIds.end(), id)
+                        != mProviderPublicCameraIds.end()) {
+                    continue;
+                }
+
+                CameraMetadata physicalInfo;
+                status_t status = device->getPhysicalCameraCharacteristics(id, &physicalInfo);
+                if (status == OK) {
+                    dprintf(fd, "  Physical camera %s characteristics:\n", id.c_str());
+                    physicalInfo.dump(fd, /*verbosity*/ 2, /*indentation*/ 4);
+                }
+            }
+        }
+
         dprintf(fd, "== Camera HAL device %s (v%d.%d) dumpState: ==\n", device->mName.c_str(),
                 device->mVersion.get_major(), device->mVersion.get_minor());
         res = device->dumpState(fd);
@@ -838,7 +911,7 @@
 
     return std::unique_ptr<DeviceInfo>(
         new DeviceInfoT(name, tagId, id, minorVersion, resourceCost,
-                cameraInterface));
+                mProviderPublicCameraIds, cameraInterface));
 }
 
 template<class InterfaceT>
@@ -912,9 +985,10 @@
         const metadata_vendor_id_t tagId, const std::string &id,
         uint16_t minorVersion,
         const CameraResourceCost& resourceCost,
+        const std::vector<std::string>& publicCameraIds,
         sp<InterfaceT> interface) :
         DeviceInfo(name, tagId, id, hardware::hidl_version{1, minorVersion},
-                   resourceCost),
+                   publicCameraIds, resourceCost),
         mInterface(interface) {
     // Get default parameters and initialize flash unit availability
     // Requires powering on the camera device
@@ -1011,9 +1085,10 @@
         const metadata_vendor_id_t tagId, const std::string &id,
         uint16_t minorVersion,
         const CameraResourceCost& resourceCost,
+        const std::vector<std::string>& publicCameraIds,
         sp<InterfaceT> interface) :
         DeviceInfo(name, tagId, id, hardware::hidl_version{3, minorVersion},
-                   resourceCost),
+                   publicCameraIds, resourceCost),
         mInterface(interface) {
     // Get camera characteristics and initialize flash unit availability
     Status status;
@@ -1054,6 +1129,59 @@
     } else {
         mHasFlashUnit = false;
     }
+
+    // Get physical camera characteristics if applicable
+    auto castResult = device::V3_5::ICameraDevice::castFrom(mInterface);
+    if (!castResult.isOk()) {
+        ALOGV("%s: Unable to convert ICameraDevice instance to version 3.5", __FUNCTION__);
+        return;
+    }
+    sp<hardware::camera::device::V3_5::ICameraDevice> interface_3_5 = castResult;
+    if (interface_3_5 == nullptr) {
+        ALOGE("%s: Converted ICameraDevice instance to nullptr", __FUNCTION__);
+        return;
+    }
+
+    std::vector<std::string> physicalIds;
+    if (CameraProviderManager::isLogicalCamera(mCameraCharacteristics, &physicalIds)) {
+        for (auto& id : physicalIds) {
+            if (std::find(mPublicCameraIds.begin(), mPublicCameraIds.end(), id) !=
+                    mPublicCameraIds.end()) {
+                continue;
+            }
+
+            hardware::hidl_string hidlId(id);
+            ret = interface_3_5->getPhysicalCameraCharacteristics(hidlId,
+                    [&status, &id, this](Status s, device::V3_2::CameraMetadata metadata) {
+                status = s;
+                if (s == Status::OK) {
+                    camera_metadata_t *buffer =
+                            reinterpret_cast<camera_metadata_t*>(metadata.data());
+                    size_t expectedSize = metadata.size();
+                    int res = validate_camera_metadata_structure(buffer, &expectedSize);
+                    if (res == OK || res == CAMERA_METADATA_VALIDATION_SHIFTED) {
+                        set_camera_metadata_vendor_id(buffer, mProviderTagid);
+                        mPhysicalCameraCharacteristics[id] = buffer;
+                    } else {
+                        ALOGE("%s: Malformed camera metadata received from HAL", __FUNCTION__);
+                        status = Status::INTERNAL_ERROR;
+                    }
+                }
+            });
+
+            if (!ret.isOk()) {
+                ALOGE("%s: Transaction error getting physical camera %s characteristics for %s: %s",
+                        __FUNCTION__, id.c_str(), mId.c_str(), ret.description().c_str());
+                return;
+            }
+            if (status != Status::OK) {
+                ALOGE("%s: Unable to get physical camera %s characteristics for device %s: %s (%d)",
+                        __FUNCTION__, id.c_str(), mId.c_str(),
+                        CameraProviderManager::statusToString(status), status);
+                return;
+            }
+        }
+    }
 }
 
 CameraProviderManager::ProviderInfo::DeviceInfo3::~DeviceInfo3() {}
@@ -1129,6 +1257,18 @@
     return OK;
 }
 
+status_t CameraProviderManager::ProviderInfo::DeviceInfo3::getPhysicalCameraCharacteristics(
+        const std::string& physicalCameraId, CameraMetadata *characteristics) const {
+    if (characteristics == nullptr) return BAD_VALUE;
+    if (mPhysicalCameraCharacteristics.find(physicalCameraId) ==
+            mPhysicalCameraCharacteristics.end()) {
+        return NAME_NOT_FOUND;
+    }
+
+    *characteristics = mPhysicalCameraCharacteristics.at(physicalCameraId);
+    return OK;
+}
+
 status_t CameraProviderManager::ProviderInfo::parseProviderName(const std::string& name,
         std::string *type, uint32_t *id) {
     // Format must be "<type>/<id>"
@@ -1460,10 +1600,20 @@
 
 status_t CameraProviderManager::getCameraCharacteristicsLocked(const std::string &id,
         CameraMetadata* characteristics) const {
-    auto deviceInfo = findDeviceInfoLocked(id, /*minVersion*/ {3,0}, /*maxVersion*/ {4,0});
-    if (deviceInfo == nullptr) return NAME_NOT_FOUND;
+    auto deviceInfo = findDeviceInfoLocked(id, /*minVersion*/ {3,0}, /*maxVersion*/ {5,0});
+    if (deviceInfo != nullptr) {
+        return deviceInfo->getCameraCharacteristics(characteristics);
+    }
 
-    return deviceInfo->getCameraCharacteristics(characteristics);
+    // Find hidden physical camera characteristics
+    for (auto& provider : mProviders) {
+        for (auto& deviceInfo : provider->mDevices) {
+            status_t res = deviceInfo->getPhysicalCameraCharacteristics(id, characteristics);
+            if (res != NAME_NOT_FOUND) return res;
+        }
+    }
+
+    return NAME_NOT_FOUND;
 }
 
 void CameraProviderManager::filterLogicalCameraIdsLocked(
@@ -1482,7 +1632,7 @@
 
         // idCombo contains the ids of a logical camera and its physical cameras
         std::vector<std::string> idCombo;
-        bool logicalCamera = CameraProviderManager::isLogicalCamera(info, &idCombo);
+        bool logicalCamera = isLogicalCamera(info, &idCombo);
         if (!logicalCamera) {
             continue;
         }
diff --git a/services/camera/libcameraservice/common/CameraProviderManager.h b/services/camera/libcameraservice/common/CameraProviderManager.h
index c523c2d..61e21b4 100644
--- a/services/camera/libcameraservice/common/CameraProviderManager.h
+++ b/services/camera/libcameraservice/common/CameraProviderManager.h
@@ -237,6 +237,7 @@
     static bool isLogicalCamera(const CameraMetadata& staticInfo,
             std::vector<std::string>* physicalCameraIds);
 
+    bool isHiddenPhysicalCamera(const std::string& cameraId);
 private:
     // All private members, unless otherwise noted, expect mInterfaceMutex to be locked before use
     mutable std::mutex mInterfaceMutex;
@@ -306,17 +307,25 @@
                 (void) characteristics;
                 return INVALID_OPERATION;
             }
+            virtual status_t getPhysicalCameraCharacteristics(const std::string& physicalCameraId,
+                    CameraMetadata *characteristics) const {
+                (void) physicalCameraId;
+                (void) characteristics;
+                return INVALID_OPERATION;
+            }
 
             DeviceInfo(const std::string& name, const metadata_vendor_id_t tagId,
                     const std::string &id, const hardware::hidl_version& version,
+                    const std::vector<std::string>& publicCameraIds,
                     const hardware::camera::common::V1_0::CameraResourceCost& resourceCost) :
                     mName(name), mId(id), mVersion(version), mProviderTagid(tagId),
                     mResourceCost(resourceCost),
                     mStatus(hardware::camera::common::V1_0::CameraDeviceStatus::PRESENT),
-                    mHasFlashUnit(false) {}
+                    mHasFlashUnit(false), mPublicCameraIds(publicCameraIds) {}
             virtual ~DeviceInfo();
         protected:
             bool mHasFlashUnit;
+            const std::vector<std::string>& mPublicCameraIds;
 
             template<class InterfaceT>
             static status_t setTorchMode(InterfaceT& interface, bool enabled);
@@ -325,6 +334,12 @@
         std::unordered_set<std::string> mUniqueCameraIds;
         int mUniqueDeviceCount;
         std::vector<std::string> mUniqueAPI1CompatibleCameraIds;
+        // The initial public camera IDs published by the camera provider.
+        // Currently logical multi-camera is not supported for hot-plug camera.
+        // And we use this list to keep track of initial public camera IDs
+        // advertised by the provider, and to distinguish against "hidden"
+        // physical camera IDs.
+        std::vector<std::string> mProviderPublicCameraIds;
 
         // HALv1-specific camera fields, including the actual device interface
         struct DeviceInfo1 : public DeviceInfo {
@@ -339,6 +354,7 @@
             DeviceInfo1(const std::string& name, const metadata_vendor_id_t tagId,
                     const std::string &id, uint16_t minorVersion,
                     const hardware::camera::common::V1_0::CameraResourceCost& resourceCost,
+                    const std::vector<std::string>& publicCameraIds,
                     sp<InterfaceT> interface);
             virtual ~DeviceInfo1();
         private:
@@ -356,14 +372,17 @@
             virtual status_t dumpState(int fd) const override;
             virtual status_t getCameraCharacteristics(
                     CameraMetadata *characteristics) const override;
+            virtual status_t getPhysicalCameraCharacteristics(const std::string& physicalCameraId,
+                    CameraMetadata *characteristics) const override;
 
             DeviceInfo3(const std::string& name, const metadata_vendor_id_t tagId,
                     const std::string &id, uint16_t minorVersion,
                     const hardware::camera::common::V1_0::CameraResourceCost& resourceCost,
-                    sp<InterfaceT> interface);
+                    const std::vector<std::string>& publicCameraIds, sp<InterfaceT> interface);
             virtual ~DeviceInfo3();
         private:
             CameraMetadata mCameraCharacteristics;
+            std::unordered_map<std::string, CameraMetadata> mPhysicalCameraCharacteristics;
         };
 
     private:
diff --git a/services/camera/libcameraservice/device3/Camera3Device.cpp b/services/camera/libcameraservice/device3/Camera3Device.cpp
index cbcc85b..1bc5d33 100644
--- a/services/camera/libcameraservice/device3/Camera3Device.cpp
+++ b/services/camera/libcameraservice/device3/Camera3Device.cpp
@@ -2272,8 +2272,8 @@
                 return NULL;
             }
         }
-        // Check if stream is being prepared
-        if (mInputStream->isPreparing()) {
+        // Check if stream prepare is blocking requests.
+        if (mInputStream->isBlockedByPrepare()) {
             CLOGE("Request references an input stream that's being prepared!");
             return NULL;
         }
@@ -2323,8 +2323,8 @@
                 return NULL;
             }
         }
-        // Check if stream is being prepared
-        if (stream->isPreparing()) {
+        // Check if stream prepare is blocking requests.
+        if (stream->isBlockedByPrepare()) {
             CLOGE("Request references an output stream that's being prepared!");
             return NULL;
         }
@@ -4891,6 +4891,15 @@
                 captureRequest->mOutputStreams.size());
         halRequest->output_buffers = outputBuffers->array();
         std::set<String8> requestedPhysicalCameras;
+
+        sp<Camera3Device> parent = mParent.promote();
+        if (parent == NULL) {
+            // Should not happen, and nowhere to send errors to, so just log it
+            CLOGE("RequestThread: Parent is gone");
+            return INVALID_OPERATION;
+        }
+        nsecs_t waitDuration = kBaseGetBufferWait + parent->getExpectedInFlightDuration();
+
         for (size_t j = 0; j < captureRequest->mOutputStreams.size(); j++) {
             sp<Camera3OutputStreamInterface> outputStream = captureRequest->mOutputStreams.editItemAt(j);
 
@@ -4899,7 +4908,8 @@
                 // Only try to prepare video stream on the first video request.
                 mPrepareVideoStream = false;
 
-                res = outputStream->startPrepare(Camera3StreamInterface::ALLOCATE_PIPELINE_MAX);
+                res = outputStream->startPrepare(Camera3StreamInterface::ALLOCATE_PIPELINE_MAX,
+                        false /*blockRequest*/);
                 while (res == NOT_ENOUGH_DATA) {
                     res = outputStream->prepareNextBuffer();
                 }
@@ -4911,6 +4921,7 @@
             }
 
             res = outputStream->getBuffer(&outputBuffers->editItemAt(j),
+                    waitDuration,
                     captureRequest->mOutputSurfaces[j]);
             if (res != OK) {
                 // Can't get output buffer from gralloc queue - this could be due to
@@ -4937,13 +4948,6 @@
         totalNumBuffers += halRequest->num_output_buffers;
 
         // Log request in the in-flight queue
-        sp<Camera3Device> parent = mParent.promote();
-        if (parent == NULL) {
-            // Should not happen, and nowhere to send errors to, so just log it
-            CLOGE("RequestThread: Parent is gone");
-            return INVALID_OPERATION;
-        }
-
         // If this request list is for constrained high speed recording (not
         // preview), and the current request is not the last one in the batch,
         // do not send callback to the app.
@@ -5585,7 +5589,7 @@
     Mutex::Autolock l(mLock);
     sp<NotificationListener> listener = mListener.promote();
 
-    res = stream->startPrepare(maxCount);
+    res = stream->startPrepare(maxCount, true /*blockRequest*/);
     if (res == OK) {
         // No preparation needed, fire listener right off
         ALOGV("%s: Stream %d already prepared", __FUNCTION__, stream->getId());
@@ -5673,7 +5677,7 @@
 
     auto it = mPendingStreams.begin();
     for (; it != mPendingStreams.end();) {
-        res = it->second->startPrepare(it->first);
+        res = it->second->startPrepare(it->first, true /*blockRequest*/);
         if (res == OK) {
             if (listener != NULL) {
                 listener->notifyPrepared(it->second->getId());
diff --git a/services/camera/libcameraservice/device3/Camera3Device.h b/services/camera/libcameraservice/device3/Camera3Device.h
index 159f2ca..5e749b6 100644
--- a/services/camera/libcameraservice/device3/Camera3Device.h
+++ b/services/camera/libcameraservice/device3/Camera3Device.h
@@ -223,6 +223,7 @@
     static const size_t        kInFlightWarnLimitHighSpeed = 256; // batch size 32 * pipe depth 8
     static const nsecs_t       kDefaultExpectedDuration = 100000000; // 100 ms
     static const nsecs_t       kMinInflightDuration = 5000000000; // 5 s
+    static const nsecs_t       kBaseGetBufferWait = 3000000000; // 3 sec.
     // SCHED_FIFO priority for request submission thread in HFR mode
     static const int           kRequestThreadPriority = 1;
 
diff --git a/services/camera/libcameraservice/device3/Camera3Stream.cpp b/services/camera/libcameraservice/device3/Camera3Stream.cpp
index 9238590..ee989e1 100644
--- a/services/camera/libcameraservice/device3/Camera3Stream.cpp
+++ b/services/camera/libcameraservice/device3/Camera3Stream.cpp
@@ -61,6 +61,7 @@
     mOldUsage(0),
     mOldMaxBuffers(0),
     mPrepared(false),
+    mPrepareBlockRequest(true),
     mPreparedBufferIdx(0),
     mLastMaxCount(Camera3StreamInterface::ALLOCATE_PIPELINE_MAX),
     mBufferLimitLatency(kBufferLimitLatencyBinSize),
@@ -328,6 +329,7 @@
     // Reset prepared state, since buffer config has changed, and existing
     // allocations are no longer valid
     mPrepared = false;
+    mPrepareBlockRequest = true;
     mStreamUnpreparable = false;
 
     status_t res;
@@ -389,7 +391,7 @@
     return mStreamUnpreparable;
 }
 
-status_t Camera3Stream::startPrepare(int maxCount) {
+status_t Camera3Stream::startPrepare(int maxCount, bool blockRequest) {
     ATRACE_CALL();
 
     Mutex::Autolock l(mLock);
@@ -421,8 +423,6 @@
         return INVALID_OPERATION;
     }
 
-
-
     size_t pipelineMax = getBufferCountLocked();
     size_t clampedCount = (pipelineMax < static_cast<size_t>(maxCount)) ?
             pipelineMax : static_cast<size_t>(maxCount);
@@ -430,6 +430,7 @@
             pipelineMax : clampedCount;
 
     mPrepared = bufferCount <= mLastMaxCount;
+    mPrepareBlockRequest = blockRequest;
 
     if (mPrepared) return OK;
 
@@ -443,9 +444,9 @@
     return NOT_ENOUGH_DATA;
 }
 
-bool Camera3Stream::isPreparing() const {
+bool Camera3Stream::isBlockedByPrepare() const {
     Mutex::Autolock l(mLock);
-    return mState == STATE_PREPARING;
+    return mState == STATE_PREPARING && mPrepareBlockRequest;
 }
 
 bool Camera3Stream::isAbandoned() const {
@@ -577,6 +578,7 @@
 }
 
 status_t Camera3Stream::getBuffer(camera3_stream_buffer *buffer,
+        nsecs_t waitBufferTimeout,
         const std::vector<size_t>& surface_ids) {
     ATRACE_CALL();
     Mutex::Autolock l(mLock);
@@ -594,13 +596,16 @@
         ALOGV("%s: Already dequeued max output buffers (%d), wait for next returned one.",
                         __FUNCTION__, camera3_stream::max_buffers);
         nsecs_t waitStart = systemTime(SYSTEM_TIME_MONOTONIC);
-        res = mOutputBufferReturnedSignal.waitRelative(mLock, kWaitForBufferDuration);
+        if (waitBufferTimeout < kWaitForBufferDuration) {
+            waitBufferTimeout = kWaitForBufferDuration;
+        }
+        res = mOutputBufferReturnedSignal.waitRelative(mLock, waitBufferTimeout);
         nsecs_t waitEnd = systemTime(SYSTEM_TIME_MONOTONIC);
         mBufferLimitLatency.add(waitStart, waitEnd);
         if (res != OK) {
             if (res == TIMED_OUT) {
                 ALOGE("%s: wait for output buffer return timed out after %lldms (max_buffers %d)",
-                        __FUNCTION__, kWaitForBufferDuration / 1000000LL,
+                        __FUNCTION__, waitBufferTimeout / 1000000LL,
                         camera3_stream::max_buffers);
             }
             return res;
diff --git a/services/camera/libcameraservice/device3/Camera3Stream.h b/services/camera/libcameraservice/device3/Camera3Stream.h
index e30fc59..1c67fb2 100644
--- a/services/camera/libcameraservice/device3/Camera3Stream.h
+++ b/services/camera/libcameraservice/device3/Camera3Stream.h
@@ -232,6 +232,11 @@
      *
      * This call performs no allocation, so is quick to call.
      *
+     * blockRequest specifies whether prepare will block upcoming capture
+     * request. This flag should only be set to false if the caller guarantees
+     * the whole buffer preparation process is done before capture request
+     * comes in.
+     *
      * Returns:
      *    OK if no more buffers need to be preallocated
      *    NOT_ENOUGH_DATA if calls to prepareNextBuffer are needed to finish
@@ -240,12 +245,12 @@
      *    INVALID_OPERATION if called when not in CONFIGURED state, or a
      *        valid buffer has already been returned to this stream.
      */
-    status_t         startPrepare(int maxCount);
+    status_t         startPrepare(int maxCount, bool blockRequest);
 
     /**
-     * Check if the stream is mid-preparing.
+     * Check if the request on a stream is blocked by prepare.
      */
-    bool             isPreparing() const;
+    bool             isBlockedByPrepare() const;
 
     /**
      * Continue stream buffer preparation by allocating the next
@@ -311,6 +316,7 @@
      *
      */
     status_t         getBuffer(camera3_stream_buffer *buffer,
+            nsecs_t waitBufferTimeout,
             const std::vector<size_t>& surface_ids = std::vector<size_t>());
 
     /**
@@ -534,6 +540,7 @@
     // has been called sufficient number of times, or stream configuration
     // had to register buffers with the HAL
     bool mPrepared;
+    bool mPrepareBlockRequest;
 
     Vector<camera3_stream_buffer_t> mPreparedBuffers;
     size_t mPreparedBufferIdx;
diff --git a/services/camera/libcameraservice/device3/Camera3StreamInterface.h b/services/camera/libcameraservice/device3/Camera3StreamInterface.h
index bddd2e7..5758ac8 100644
--- a/services/camera/libcameraservice/device3/Camera3StreamInterface.h
+++ b/services/camera/libcameraservice/device3/Camera3StreamInterface.h
@@ -160,6 +160,11 @@
      * PREPARING state. Otherwise, returns NOT_ENOUGH_DATA and transitions
      * to PREPARING.
      *
+     * blockRequest specifies whether prepare will block upcoming capture
+     * request. This flag should only be set to false if the caller guarantees
+     * the whole buffer preparation process is done before capture request
+     * comes in.
+     *
      * Returns:
      *    OK if no more buffers need to be preallocated
      *    NOT_ENOUGH_DATA if calls to prepareNextBuffer are needed to finish
@@ -168,12 +173,12 @@
      *    INVALID_OPERATION if called when not in CONFIGURED state, or a
      *        valid buffer has already been returned to this stream.
      */
-    virtual status_t startPrepare(int maxCount) = 0;
+    virtual status_t startPrepare(int maxCount, bool blockRequest) = 0;
 
     /**
-     * Check if the stream is mid-preparing.
+     * Check if the request on a stream is blocked by prepare.
      */
-    virtual bool     isPreparing() const = 0;
+    virtual bool     isBlockedByPrepare() const = 0;
 
     /**
      * Continue stream buffer preparation by allocating the next
@@ -237,6 +242,7 @@
      *
      */
     virtual status_t getBuffer(camera3_stream_buffer *buffer,
+            nsecs_t waitBufferTimeout,
             const std::vector<size_t>& surface_ids = std::vector<size_t>()) = 0;
 
     /**