Merge "NuPlayerRenderer: adjust delay of posting drain audio message based on playback rate."
diff --git a/include/media/stagefright/MediaCodec.h b/include/media/stagefright/MediaCodec.h
index 0786fb9..3e3c276 100644
--- a/include/media/stagefright/MediaCodec.h
+++ b/include/media/stagefright/MediaCodec.h
@@ -135,6 +135,8 @@
     status_t getOutputFormat(sp<AMessage> *format) const;
     status_t getInputFormat(sp<AMessage> *format) const;
 
+    status_t getWidevineLegacyBuffers(Vector<sp<ABuffer> > *buffers) const;
+
     status_t getInputBuffers(Vector<sp<ABuffer> > *buffers) const;
     status_t getOutputBuffers(Vector<sp<ABuffer> > *buffers) const;
 
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
index 04ac699..3fff1e6 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.cpp
@@ -82,25 +82,69 @@
     switch (msg->what()) {
         case kWhatCodecNotify:
         {
-            if (!isStaleReply(msg)) {
-                int32_t numInput, numOutput;
-
-                if (!msg->findInt32("input-buffers", &numInput)) {
-                    numInput = INT32_MAX;
-                }
-
-                if (!msg->findInt32("output-buffers", &numOutput)) {
-                    numOutput = INT32_MAX;
-                }
-
-                if (!mPaused) {
-                    while (numInput-- > 0 && handleAnInputBuffer()) {}
-                }
-
-                while (numOutput-- > 0 && handleAnOutputBuffer()) {}
+            if (mPaused) {
+                break;
             }
 
-            requestCodecNotification();
+            int32_t cbID;
+            CHECK(msg->findInt32("callbackID", &cbID));
+
+            ALOGV("kWhatCodecNotify: cbID = %d", cbID);
+            switch (cbID) {
+                case MediaCodec::CB_INPUT_AVAILABLE:
+                {
+                    int32_t index;
+                    CHECK(msg->findInt32("index", &index));
+
+                    handleAnInputBuffer(index);
+                    break;
+                }
+
+                case MediaCodec::CB_OUTPUT_AVAILABLE:
+                {
+                    int32_t index;
+                    size_t offset;
+                    size_t size;
+                    int64_t timeUs;
+                    int32_t flags;
+
+                    CHECK(msg->findInt32("index", &index));
+                    CHECK(msg->findSize("offset", &offset));
+                    CHECK(msg->findSize("size", &size));
+                    CHECK(msg->findInt64("timeUs", &timeUs));
+                    CHECK(msg->findInt32("flags", &flags));
+
+                    handleAnOutputBuffer(index, offset, size, timeUs, flags);
+                    break;
+                }
+
+                case MediaCodec::CB_OUTPUT_FORMAT_CHANGED:
+                {
+                    sp<AMessage> format;
+                    CHECK(msg->findMessage("format", &format));
+
+                    handleOutputFormatChange(format);
+                    break;
+                }
+
+                case MediaCodec::CB_ERROR:
+                {
+                    status_t err;
+                    CHECK(msg->findInt32("err", &err));
+                    ALOGE("Decoder (%s) reported error : 0x%x",
+                            mIsAudio ? "audio" : "video", err);
+
+                    handleError(err);
+                    break;
+                }
+
+                default:
+                {
+                    TRESPASS();
+                    break;
+                }
+            }
+
             break;
         }
 
@@ -188,6 +232,9 @@
     CHECK_EQ((status_t)OK, mCodec->getOutputFormat(&mOutputFormat));
     CHECK_EQ((status_t)OK, mCodec->getInputFormat(&mInputFormat));
 
+    sp<AMessage> reply = new AMessage(kWhatCodecNotify, this);
+    mCodec->setCallback(reply);
+
     err = mCodec->start();
     if (err != OK) {
         ALOGE("Failed to start %s decoder (err=%d)", mComponentName.c_str(), err);
@@ -197,18 +244,8 @@
         return;
     }
 
-    // the following should work after start
-    CHECK_EQ((status_t)OK, mCodec->getInputBuffers(&mInputBuffers));
     releaseAndResetMediaBuffers();
-    CHECK_EQ((status_t)OK, mCodec->getOutputBuffers(&mOutputBuffers));
-    ALOGV("[%s] got %zu input and %zu output buffers",
-            mComponentName.c_str(),
-            mInputBuffers.size(),
-            mOutputBuffers.size());
 
-    if (mRenderer != NULL) {
-        requestCodecNotification();
-    }
     mPaused = false;
     mResumePending = false;
 }
@@ -217,16 +254,14 @@
     bool hadNoRenderer = (mRenderer == NULL);
     mRenderer = renderer;
     if (hadNoRenderer && mRenderer != NULL) {
-        requestCodecNotification();
+        // this means that the widevine legacy source is ready
+        onRequestInputBuffers();
     }
 }
 
 void NuPlayer::Decoder::onGetInputBuffers(
         Vector<sp<ABuffer> > *dstBuffers) {
-    dstBuffers->clear();
-    for (size_t i = 0; i < mInputBuffers.size(); i++) {
-        dstBuffers->push(mInputBuffers[i]);
-    }
+    CHECK_EQ((status_t)OK, mCodec->getWidevineLegacyBuffers(dstBuffers));
 }
 
 void NuPlayer::Decoder::onResume(bool notifyComplete) {
@@ -235,6 +270,7 @@
     if (notifyComplete) {
         mResumePending = true;
     }
+    mCodec->start();
 }
 
 void NuPlayer::Decoder::doFlush(bool notifyComplete) {
@@ -261,8 +297,10 @@
         // we attempt to release the buffers even if flush fails.
     }
     releaseAndResetMediaBuffers();
+    mPaused = true;
 }
 
+
 void NuPlayer::Decoder::onFlush() {
     doFlush(true);
 
@@ -276,7 +314,6 @@
     sp<AMessage> notify = mNotify->dup();
     notify->setInt32("what", kWhatFlushCompleted);
     notify->post();
-    mPaused = true;
 }
 
 void NuPlayer::Decoder::onShutdown(bool notifyComplete) {
@@ -320,7 +357,9 @@
 }
 
 void NuPlayer::Decoder::doRequestBuffers() {
-    if (isDiscontinuityPending()) {
+    // mRenderer is only NULL if we have a legacy widevine source that
+    // is not yet ready. In this case we must not fetch input.
+    if (isDiscontinuityPending() || mRenderer == NULL) {
         return;
     }
     status_t err = OK;
@@ -347,34 +386,50 @@
     }
 }
 
-bool NuPlayer::Decoder::handleAnInputBuffer() {
+void NuPlayer::Decoder::handleError(int32_t err)
+{
+    // We cannot immediately release the codec due to buffers still outstanding
+    // in the renderer.  We signal to the player the error so it can shutdown/release the
+    // decoder after flushing and increment the generation to discard unnecessary messages.
+
+    ++mBufferGeneration;
+
+    sp<AMessage> notify = mNotify->dup();
+    notify->setInt32("what", kWhatError);
+    notify->setInt32("err", err);
+    notify->post();
+}
+
+bool NuPlayer::Decoder::handleAnInputBuffer(size_t index) {
     if (isDiscontinuityPending()) {
         return false;
     }
-    size_t bufferIx = -1;
-    status_t res = mCodec->dequeueInputBuffer(&bufferIx);
-    ALOGV("[%s] dequeued input: %d",
-            mComponentName.c_str(), res == OK ? (int)bufferIx : res);
-    if (res != OK) {
-        if (res != -EAGAIN) {
-            ALOGE("Failed to dequeue input buffer for %s (err=%d)",
-                    mComponentName.c_str(), res);
-            handleError(res);
+
+    sp<ABuffer> buffer;
+    mCodec->getInputBuffer(index, &buffer);
+
+    if (index >= mInputBuffers.size()) {
+        for (size_t i = mInputBuffers.size(); i <= index; ++i) {
+            mInputBuffers.add();
+            mMediaBuffers.add();
+            mInputBufferIsDequeued.add();
+            mMediaBuffers.editItemAt(i) = NULL;
+            mInputBufferIsDequeued.editItemAt(i) = false;
         }
-        return false;
     }
+    mInputBuffers.editItemAt(index) = buffer;
 
-    CHECK_LT(bufferIx, mInputBuffers.size());
+    //CHECK_LT(bufferIx, mInputBuffers.size());
 
-    if (mMediaBuffers[bufferIx] != NULL) {
-        mMediaBuffers[bufferIx]->release();
-        mMediaBuffers.editItemAt(bufferIx) = NULL;
+    if (mMediaBuffers[index] != NULL) {
+        mMediaBuffers[index]->release();
+        mMediaBuffers.editItemAt(index) = NULL;
     }
-    mInputBufferIsDequeued.editItemAt(bufferIx) = true;
+    mInputBufferIsDequeued.editItemAt(index) = true;
 
     if (!mCSDsToSubmit.isEmpty()) {
         sp<AMessage> msg = new AMessage();
-        msg->setSize("buffer-ix", bufferIx);
+        msg->setSize("buffer-ix", index);
 
         sp<ABuffer> buffer = mCSDsToSubmit.itemAt(0);
         ALOGI("[%s] resubmitting CSD", mComponentName.c_str());
@@ -392,94 +447,38 @@
         mPendingInputMessages.erase(mPendingInputMessages.begin());
     }
 
-    if (!mInputBufferIsDequeued.editItemAt(bufferIx)) {
+    if (!mInputBufferIsDequeued.editItemAt(index)) {
         return true;
     }
 
-    mDequeuedInputBuffers.push_back(bufferIx);
+    mDequeuedInputBuffers.push_back(index);
 
     onRequestInputBuffers();
     return true;
 }
 
-bool NuPlayer::Decoder::handleAnOutputBuffer() {
-    size_t bufferIx = -1;
-    size_t offset;
-    size_t size;
-    int64_t timeUs;
-    uint32_t flags;
-    status_t res = mCodec->dequeueOutputBuffer(
-            &bufferIx, &offset, &size, &timeUs, &flags);
-
-    if (res != OK) {
-        ALOGV("[%s] dequeued output: %d", mComponentName.c_str(), res);
-    } else {
-        ALOGV("[%s] dequeued output: %d (time=%lld flags=%" PRIu32 ")",
-                mComponentName.c_str(), (int)bufferIx, timeUs, flags);
-    }
-
-    if (res == INFO_OUTPUT_BUFFERS_CHANGED) {
-        res = mCodec->getOutputBuffers(&mOutputBuffers);
-        if (res != OK) {
-            ALOGE("Failed to get output buffers for %s after INFO event (err=%d)",
-                    mComponentName.c_str(), res);
-            handleError(res);
-            return false;
-        }
-        // NuPlayer ignores this
-        return true;
-    } else if (res == INFO_FORMAT_CHANGED) {
-        sp<AMessage> format = new AMessage();
-        res = mCodec->getOutputFormat(&format);
-        if (res != OK) {
-            ALOGE("Failed to get output format for %s after INFO event (err=%d)",
-                    mComponentName.c_str(), res);
-            handleError(res);
-            return false;
-        }
-
-        if (!mIsAudio) {
-            sp<AMessage> notify = mNotify->dup();
-            notify->setInt32("what", kWhatVideoSizeChanged);
-            notify->setMessage("format", format);
-            notify->post();
-        } else if (mRenderer != NULL) {
-            uint32_t flags;
-            int64_t durationUs;
-            bool hasVideo = (mSource->getFormat(false /* audio */) != NULL);
-            if (!hasVideo &&
-                    mSource->getDuration(&durationUs) == OK &&
-                    durationUs
-                        > AUDIO_SINK_MIN_DEEP_BUFFER_DURATION_US) {
-                flags = AUDIO_OUTPUT_FLAG_DEEP_BUFFER;
-            } else {
-                flags = AUDIO_OUTPUT_FLAG_NONE;
-            }
-
-            res = mRenderer->openAudioSink(
-                    format, false /* offloadOnly */, hasVideo, flags, NULL /* isOffloaded */);
-            if (res != OK) {
-                ALOGE("Failed to open AudioSink on format change for %s (err=%d)",
-                        mComponentName.c_str(), res);
-                handleError(res);
-                return false;
-            }
-        }
-        return true;
-    } else if (res == INFO_DISCONTINUITY) {
-        // nothing to do
-        return true;
-    } else if (res != OK) {
-        if (res != -EAGAIN) {
-            ALOGE("Failed to dequeue output buffer for %s (err=%d)",
-                    mComponentName.c_str(), res);
-            handleError(res);
-        }
+bool NuPlayer::Decoder::handleAnOutputBuffer(
+        size_t index,
+        size_t offset,
+        size_t size,
+        int64_t timeUs,
+        int32_t flags) {
+    if (mFormatChangePending) {
         return false;
     }
 
-    CHECK_LT(bufferIx, mOutputBuffers.size());
-    sp<ABuffer> buffer = mOutputBuffers[bufferIx];
+//    CHECK_LT(bufferIx, mOutputBuffers.size());
+    sp<ABuffer> buffer;
+    mCodec->getOutputBuffer(index, &buffer);
+
+    if (index >= mOutputBuffers.size()) {
+        for (size_t i = mOutputBuffers.size(); i <= index; ++i) {
+            mOutputBuffers.add();
+        }
+    }
+
+    mOutputBuffers.editItemAt(index) = buffer;
+
     buffer->setRange(offset, size);
     buffer->meta()->clear();
     buffer->meta()->setInt64("timeUs", timeUs);
@@ -488,7 +487,7 @@
     // we do not expect CODECCONFIG or SYNCFRAME for decoder
 
     sp<AMessage> reply = new AMessage(kWhatRenderBuffer, this);
-    reply->setSize("buffer-ix", bufferIx);
+    reply->setSize("buffer-ix", index);
     reply->setInt32("generation", mBufferGeneration);
 
     if (eos) {
@@ -522,6 +521,29 @@
     return true;
 }
 
+void NuPlayer::Decoder::handleOutputFormatChange(const sp<AMessage> &format) {
+    if (!mIsAudio) {
+        sp<AMessage> notify = mNotify->dup();
+        notify->setInt32("what", kWhatVideoSizeChanged);
+        notify->setMessage("format", format);
+        notify->post();
+    } else if (mRenderer != NULL) {
+        uint32_t flags;
+        int64_t durationUs;
+        bool hasVideo = (mSource->getFormat(false /* audio */) != NULL);
+        if (!hasVideo &&
+                mSource->getDuration(&durationUs) == OK &&
+                durationUs > AUDIO_SINK_MIN_DEEP_BUFFER_DURATION_US) {
+            flags = AUDIO_OUTPUT_FLAG_DEEP_BUFFER;
+        } else {
+            flags = AUDIO_OUTPUT_FLAG_NONE;
+        }
+
+        mRenderer->openAudioSink(
+                format, false /* offloadOnly */, hasVideo, flags, NULL /* isOffloaed */);
+    }
+}
+
 void NuPlayer::Decoder::releaseAndResetMediaBuffers() {
     for (size_t i = 0; i < mMediaBuffers.size(); i++) {
         if (mMediaBuffers[i] != NULL) {
@@ -825,7 +847,8 @@
         mPaused = true;
     } else if (mTimeChangePending) {
         if (flushOnTimeChange) {
-            doFlush(false /*notifyComplete*/);
+            doFlush(false /* notifyComplete */);
+            signalResume(false /* notifyComplete */);
         }
 
         // restart fetching input
diff --git a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h
index 4aab2c6..0c0e90c 100644
--- a/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h
+++ b/media/libmediaplayerservice/nuplayer/NuPlayerDecoder.h
@@ -87,8 +87,15 @@
     bool mResumePending;
     AString mComponentName;
 
-    bool handleAnInputBuffer();
-    bool handleAnOutputBuffer();
+    void handleError(int32_t err);
+    bool handleAnInputBuffer(size_t index);
+    bool handleAnOutputBuffer(
+            size_t index,
+            size_t offset,
+            size_t size,
+            int64_t timeUs,
+            int32_t flags);
+    void handleOutputFormatChange(const sp<AMessage> &format);
 
     void releaseAndResetMediaBuffers();
     void requestCodecNotification();
diff --git a/media/libstagefright/MediaCodec.cpp b/media/libstagefright/MediaCodec.cpp
index 8186f63..85b1f6b 100644
--- a/media/libstagefright/MediaCodec.cpp
+++ b/media/libstagefright/MediaCodec.cpp
@@ -546,6 +546,16 @@
     return OK;
 }
 
+status_t MediaCodec::getWidevineLegacyBuffers(Vector<sp<ABuffer> > *buffers) const {
+    sp<AMessage> msg = new AMessage(kWhatGetBuffers, this);
+    msg->setInt32("portIndex", kPortIndexInput);
+    msg->setPointer("buffers", buffers);
+    msg->setInt32("widevine", true);
+
+    sp<AMessage> response;
+    return PostAndAwaitResponse(msg, &response);
+}
+
 status_t MediaCodec::getInputBuffers(Vector<sp<ABuffer> > *buffers) const {
     sp<AMessage> msg = new AMessage(kWhatGetBuffers, this);
     msg->setInt32("portIndex", kPortIndexInput);
@@ -1602,8 +1612,12 @@
         {
             sp<AReplyToken> replyID;
             CHECK(msg->senderAwaitsResponse(&replyID));
+            // Unfortunately widevine legacy source requires knowing all of the
+            // codec input buffers, so we have to provide them even in async mode.
+            int32_t widevine = 0;
+            msg->findInt32("widevine", &widevine);
 
-            if (!isExecuting() || (mFlags & kFlagIsAsync)) {
+            if (!isExecuting() || ((mFlags & kFlagIsAsync) && !widevine)) {
                 PostReplyWithError(replyID, INVALID_OPERATION);
                 break;
             } else if (mFlags & kFlagStickyError) {
diff --git a/media/libstagefright/MediaCodecSource.cpp b/media/libstagefright/MediaCodecSource.cpp
index b6fa810..6568d25 100644
--- a/media/libstagefright/MediaCodecSource.cpp
+++ b/media/libstagefright/MediaCodecSource.cpp
@@ -399,6 +399,9 @@
 
     ALOGV("output format is '%s'", mOutputFormat->debugString(0).c_str());
 
+    mEncoderActivityNotify = new AMessage(kWhatEncoderActivity, mReflector);
+    mEncoder->setCallback(mEncoderActivityNotify);
+
     status_t err = mEncoder->configure(
                 mOutputFormat,
                 NULL /* nativeWindow */,
@@ -422,9 +425,6 @@
         }
     }
 
-    mEncoderActivityNotify = new AMessage(kWhatEncoderActivity, mReflector);
-    mEncoder->setCallback(mEncoderActivityNotify);
-
     err = mEncoder->start();
 
     if (err != OK) {
diff --git a/services/camera/libcameraservice/CameraService.cpp b/services/camera/libcameraservice/CameraService.cpp
index e9c96c6..dabfafa 100644
--- a/services/camera/libcameraservice/CameraService.cpp
+++ b/services/camera/libcameraservice/CameraService.cpp
@@ -122,7 +122,7 @@
 // should be ok for now.
 static CameraService *gCameraService;
 
-CameraService::CameraService() : mEventLog(DEFAULT_EVICTION_LOG_LENGTH),
+CameraService::CameraService() : mEventLog(DEFAULT_EVENT_LOG_LENGTH),
         mLastUserId(DEFAULT_LAST_USER_ID), mSoundRef(0), mModule(0), mFlashlight(0) {
     ALOGI("CameraService started (pid=%d)", getpid());
     gCameraService = this;
@@ -242,6 +242,8 @@
     }
 
     if (newStatus == CAMERA_DEVICE_STATUS_NOT_PRESENT) {
+        logDeviceRemoved(id, String8::format("Device status changed from %d to %d", oldStatus,
+                newStatus));
         sp<BasicClient> clientToDisconnect;
         {
             // Don't do this in updateStatus to avoid deadlock over mServiceLock
@@ -274,6 +276,10 @@
         }
 
     } else {
+        if (oldStatus == ICameraServiceListener::Status::STATUS_NOT_PRESENT) {
+            logDeviceAdded(id, String8::format("Device status changed from %d to %d", oldStatus,
+                    newStatus));
+        }
         updateStatus(static_cast<ICameraServiceListener::Status>(newStatus), id);
     }
 
@@ -765,8 +771,8 @@
     } else {
         // We only trust our own process to forward client UIDs
         if (callingPid != getpid()) {
-            ALOGE("CameraService::connect X (PID %d) rejected (don't trust clientUid)",
-                    callingPid);
+            ALOGE("CameraService::connect X (PID %d) rejected (don't trust clientUid %d)",
+                    callingPid, clientUid);
             return PERMISSION_DENIED;
         }
     }
@@ -796,10 +802,12 @@
         return -EACCES;
     }
 
-    // Only allow clients who are being used by the current foreground device user.
-    if (mLastUserId != clientUserId && mLastUserId != DEFAULT_LAST_USER_ID) {
-        ALOGE("CameraService::connect X (PID %d) rejected (cannot connect from non-foreground "
-                "device user)", callingPid);
+    // Only allow clients who are being used by the current foreground device user, unless calling
+    // from our own process.
+    if (callingPid != getpid() &&
+            (mLastUserId != clientUserId && mLastUserId != DEFAULT_LAST_USER_ID)) {
+        ALOGE("CameraService::connect X (PID %d) rejected (cannot connect from previous "
+                "device user %d, current device user %d)", callingPid, clientUserId, mLastUserId);
         return PERMISSION_DENIED;
     }
 
@@ -934,7 +942,7 @@
                     mActiveClientManager.getIncompatibleClients(clientDescriptor);
 
             String8 msg = String8::format("%s : DENIED connect device %s client for package %s "
-                    "(PID %d, priority %d)", curTime.string(),
+                    "(PID %d, priority %d) due to eviction policy", curTime.string(),
                     cameraId.string(), packageName.string(), clientPid,
                     getCameraPriorityFromProcState(priorities[priorities.size() - 1]));
 
@@ -946,6 +954,7 @@
             }
 
             // Log the client's attempt
+            Mutex::Autolock l(mLogLock);
             mEventLog.add(msg);
 
             return -EBUSY;
@@ -967,12 +976,10 @@
                     i->getKey().string());
             evictedClients.push_back(clientSp);
 
-            String8 curTime = getFormattedCurrentTime();
-
             // Log the clients evicted
-            mEventLog.add(String8::format("%s : EVICT device %s client for package %s (PID %"
-                    PRId32 ", priority %" PRId32 ")\n   - Evicted by device %s client for "
-                    "package %s (PID %d, priority %" PRId32 ")", curTime.string(),
+            logEvent(String8::format("EVICT device %s client held by package %s (PID"
+                    " %" PRId32 ", priority %" PRId32 ")\n   - Evicted by device %s client for"
+                    " package %s (PID %d, priority %" PRId32 ")",
                     i->getKey().string(), String8{clientSp->getPackageName()}.string(),
                     i->getOwnerId(), i->getPriority(), cameraId.string(),
                     packageName.string(), clientPid,
@@ -1027,6 +1034,8 @@
             clientPackageName, clientUid, API_1, false, false, /*out*/client);
 
     if(ret != NO_ERROR) {
+        logRejected(id, getCallingPid(), String8(clientPackageName),
+                String8::format("%s (%d)", strerror(-ret), ret));
         return ret;
     }
 
@@ -1042,6 +1051,7 @@
         /*out*/
         sp<ICamera>& device) {
 
+    String8 id = String8::format("%d", cameraId);
     int apiVersion = mModule->getModuleApiVersion();
     if (halVersion != CAMERA_HAL_API_VERSION_UNSPECIFIED &&
             apiVersion < CAMERA_MODULE_API_VERSION_2_3) {
@@ -1053,16 +1063,19 @@
          */
         ALOGE("%s: camera HAL module version %x doesn't support connecting to legacy HAL devices!",
                 __FUNCTION__, apiVersion);
+        logRejected(id, getCallingPid(), String8(clientPackageName),
+                String8("HAL module version doesn't support legacy HAL connections"));
         return INVALID_OPERATION;
     }
 
     status_t ret = NO_ERROR;
-    String8 id = String8::format("%d", cameraId);
     sp<Client> client = nullptr;
     ret = connectHelper<ICameraClient,Client>(cameraClient, id, halVersion, clientPackageName,
             clientUid, API_1, true, false, /*out*/client);
 
     if(ret != NO_ERROR) {
+        logRejected(id, getCallingPid(), String8(clientPackageName),
+                String8::format("%s (%d)", strerror(-ret), ret));
         return ret;
     }
 
@@ -1086,6 +1099,8 @@
             /*out*/client);
 
     if(ret != NO_ERROR) {
+        logRejected(id, getCallingPid(), String8(clientPackageName),
+                String8::format("%s (%d)", strerror(-ret), ret));
         return ret;
     }
 
@@ -1426,6 +1441,8 @@
         newUserId = DEFAULT_LAST_USER_ID;
     }
 
+    logUserSwitch(mLastUserId, newUserId);
+
     mLastUserId = newUserId;
 
     // Current user has switched, evict all current clients.
@@ -1444,12 +1461,12 @@
 
         ALOGE("Evicting conflicting client for camera ID %s due to user change",
                 i->getKey().string());
+
         // Log the clients evicted
-        mEventLog.add(String8::format("%s : EVICT device %s client for package %s (PID %"
+        logEvent(String8::format("EVICT device %s client held by package %s (PID %"
                 PRId32 ", priority %" PRId32 ")\n   - Evicted due to user switch.",
-                curTime.string(), i->getKey().string(),
-                String8{clientSp->getPackageName()}.string(), i->getOwnerId(),
-                i->getPriority()));
+                i->getKey().string(), String8{clientSp->getPackageName()}.string(),
+                i->getOwnerId(), i->getPriority()));
 
     }
 
@@ -1470,22 +1487,52 @@
     mServiceLock.lock();
 }
 
-void CameraService::logDisconnected(const String8& cameraId, int clientPid,
-        const String8& clientPackage) {
-
+void CameraService::logEvent(const char* event) {
     String8 curTime = getFormattedCurrentTime();
-    // Log the clients evicted
-    mEventLog.add(String8::format("%s : DISCONNECT device %s client for package %s (PID %d)",
-            curTime.string(), cameraId.string(), clientPackage.string(), clientPid));
+    Mutex::Autolock l(mLogLock);
+    mEventLog.add(String8::format("%s : %s", curTime.string(), event));
 }
 
-void CameraService::logConnected(const String8& cameraId, int clientPid,
-        const String8& clientPackage) {
-
-    String8 curTime = getFormattedCurrentTime();
+void CameraService::logDisconnected(const char* cameraId, int clientPid,
+        const char* clientPackage) {
     // Log the clients evicted
-    mEventLog.add(String8::format("%s : CONNECT device %s client for package %s (PID %d)",
-            curTime.string(), cameraId.string(), clientPackage.string(), clientPid));
+    logEvent(String8::format("DISCONNECT device %s client for package %s (PID %d)", cameraId,
+            clientPackage, clientPid));
+}
+
+void CameraService::logConnected(const char* cameraId, int clientPid,
+        const char* clientPackage) {
+    // Log the clients evicted
+    logEvent(String8::format("CONNECT device %s client for package %s (PID %d)", cameraId,
+            clientPackage, clientPid));
+}
+
+void CameraService::logRejected(const char* cameraId, int clientPid,
+        const char* clientPackage, const char* reason) {
+    // Log the client rejected
+    logEvent(String8::format("REJECT device %s client for package %s (PID %d), reason: (%s)",
+            cameraId, clientPackage, clientPid, reason));
+}
+
+void CameraService::logUserSwitch(int oldUserId, int newUserId) {
+    // Log the new and old users
+    logEvent(String8::format("USER_SWITCH from old user: %d , to new user: %d", oldUserId,
+            newUserId));
+}
+
+void CameraService::logDeviceRemoved(const char* cameraId, const char* reason) {
+    // Log the device removal
+    logEvent(String8::format("REMOVE device %s, reason: (%s)", cameraId, reason));
+}
+
+void CameraService::logDeviceAdded(const char* cameraId, const char* reason) {
+    // Log the device removal
+    logEvent(String8::format("ADD device %s, reason: (%s)", cameraId, reason));
+}
+
+void CameraService::logClientDied(int clientPid, const char* reason) {
+    // Log the device removal
+    logEvent(String8::format("DIED client(s) with PID %d, reason: (%s)", clientPid, reason));
 }
 
 status_t CameraService::onTransact(uint32_t code, const Parcel& data, Parcel* reply,
@@ -1911,7 +1958,7 @@
 }
 
 status_t CameraService::dump(int fd, const Vector<String16>& args) {
-    String8 result;
+    String8 result("Dump of the Camera Service:\n");
     if (checkCallingPermission(String16("android.permission.DUMP")) == false) {
         result.appendFormat("Permission Denial: "
                 "can't dump CameraService from pid=%d, uid=%d\n",
@@ -1957,12 +2004,15 @@
 
         result = String8("Prior client events (most recent at top):\n");
 
-        for (const auto& msg : mEventLog) {
-            result.appendFormat("%s\n", msg.string());
-        }
+        {
+            Mutex::Autolock l(mLogLock);
+            for (const auto& msg : mEventLog) {
+                result.appendFormat("%s\n", msg.string());
+            }
 
-        if (mEventLog.size() == DEFAULT_EVICTION_LOG_LENGTH) {
-            result.append("...\n");
+            if (mEventLog.size() == DEFAULT_EVENT_LOG_LENGTH) {
+                result.append("...\n");
+            }
         }
 
         write(fd, result.string(), result.size());
@@ -2094,10 +2144,12 @@
 /*virtual*/void CameraService::binderDied(const wp<IBinder> &who) {
 
     /**
-      * While tempting to promote the wp<IBinder> into a sp,
-      * it's actually not supported by the binder driver
+      * While tempting to promote the wp<IBinder> into a sp, it's actually not supported by the
+      * binder driver
       */
 
+    logClientDied(getCallingPid(), String8("Binder died unexpectedly"));
+
     // check torch client
     handleTorchClientBinderDied(who);
 
diff --git a/services/camera/libcameraservice/CameraService.h b/services/camera/libcameraservice/CameraService.h
index ca1c504..9eda205 100644
--- a/services/camera/libcameraservice/CameraService.h
+++ b/services/camera/libcameraservice/CameraService.h
@@ -91,7 +91,7 @@
     static const nsecs_t DEFAULT_CONNECT_TIMEOUT_NS = 3000000000;
 
     // Default number of messages to store in eviction log
-    static const size_t DEFAULT_EVICTION_LOG_LENGTH = 50;
+    static const size_t DEFAULT_EVENT_LOG_LENGTH = 100;
 
     enum {
         // Default last user id
@@ -492,6 +492,7 @@
 
     // Circular buffer for storing event logging for dumps
     RingBuffer<String8> mEventLog;
+    Mutex mLogLock;
 
     // UID of last user.
     int mLastUserId;
@@ -546,14 +547,45 @@
     void doUserSwitch(int newUserId);
 
     /**
-     * Add a event log message that a client has been disconnected.
+     * Add an event log message.
      */
-    void logDisconnected(const String8& cameraId, int clientPid, const String8& clientPackage);
+    void logEvent(const char* event);
 
     /**
-     * Add a event log message that a client has been connected.
+     * Add an event log message that a client has been disconnected.
      */
-    void logConnected(const String8& cameraId, int clientPid, const String8& clientPackage);
+    void logDisconnected(const char* cameraId, int clientPid, const char* clientPackage);
+
+    /**
+     * Add an event log message that a client has been connected.
+     */
+    void logConnected(const char* cameraId, int clientPid, const char* clientPackage);
+
+    /**
+     * Add an event log message that a client's connect attempt has been rejected.
+     */
+    void logRejected(const char* cameraId, int clientPid, const char* clientPackage,
+            const char* reason);
+
+    /**
+     * Add an event log message that the current device user has been switched.
+     */
+    void logUserSwitch(int oldUserId, int newUserId);
+
+    /**
+     * Add an event log message that a device has been removed by the HAL
+     */
+    void logDeviceRemoved(const char* cameraId, const char* reason);
+
+    /**
+     * Add an event log message that a device has been added by the HAL
+     */
+    void logDeviceAdded(const char* cameraId, const char* reason);
+
+    /**
+     * Add an event log message that a client has unexpectedly died.
+     */
+    void logClientDied(int clientPid, const char* reason);
 
     int                 mNumberOfCameras;
 
@@ -714,9 +746,10 @@
     String8 clientName8(clientPackageName);
     int clientPid = getCallingPid();
 
-    ALOGI("CameraService::connect call E (PID %d \"%s\", camera ID %s) for HAL version %d and "
+    ALOGI("CameraService::connect call (PID %d \"%s\", camera ID %s) for HAL version %s and "
             "Camera API version %d", clientPid, clientName8.string(), cameraId.string(),
-            halVersion, static_cast<int>(effectiveApiLevel));
+            (halVersion == -1) ? "default" : std::to_string(halVersion).c_str(),
+            static_cast<int>(effectiveApiLevel));
 
     sp<CLIENT> client = nullptr;
     {
@@ -734,7 +767,15 @@
         if((ret = validateConnectLocked(cameraId, /*inout*/clientUid)) != NO_ERROR) {
             return ret;
         }
-        mLastUserId = multiuser_get_user_id(clientUid);
+        int userId = multiuser_get_user_id(clientUid);
+
+        if (userId != mLastUserId && clientPid != getpid() ) {
+            // If no previous user ID had been set, set to the user of the caller.
+            logUserSwitch(mLastUserId, userId);
+            LOG_ALWAYS_FATAL_IF(mLastUserId != DEFAULT_LAST_USER_ID,
+                    "Invalid state: Should never update user ID here unless was default");
+            mLastUserId = userId;
+        }
 
         // Check the shim parameters after acquiring lock, if they have already been updated and
         // we were doing a shim update, return immediately