From a8ca9157d21510fbd474bd31748f4fe0d4635dd7 Mon Sep 17 00:00:00 2001 From: Ruben Brunk Date: Tue, 7 Apr 2015 14:23:40 -0700 Subject: camera: Update camera service logging and validation. - Expand the logging included by the camera service. - Update user validation checks in connect calls so that these can be correctly called from the camera service. Bug: 20063426 Change-Id: I0a8cbe1ea2c0a652298e6b70c89705da174a50e1 --- services/camera/libcameraservice/CameraService.cpp | 126 +++++++++++++++------ services/camera/libcameraservice/CameraService.h | 57 ++++++++-- 2 files changed, 138 insertions(+), 45 deletions(-) (limited to 'services') 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 @@ static void torch_mode_status_change( // 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 @@ void CameraService::onDeviceStatusChanged(camera_device_status_t cameraId, } if (newStatus == CAMERA_DEVICE_STATUS_NOT_PRESENT) { + logDeviceRemoved(id, String8::format("Device status changed from %d to %d", oldStatus, + newStatus)); sp clientToDisconnect; { // Don't do this in updateStatus to avoid deadlock over mServiceLock @@ -274,6 +276,10 @@ void CameraService::onDeviceStatusChanged(camera_device_status_t cameraId, } } else { + if (oldStatus == ICameraServiceListener::Status::STATUS_NOT_PRESENT) { + logDeviceAdded(id, String8::format("Device status changed from %d to %d", oldStatus, + newStatus)); + } updateStatus(static_cast(newStatus), id); } @@ -765,8 +771,8 @@ status_t CameraService::validateConnectLocked(const String8& cameraId, /*inout*/ } 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 @@ status_t CameraService::validateConnectLocked(const String8& cameraId, /*inout*/ 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 @@ status_t CameraService::handleEvictionsLocked(const String8& cameraId, int clien 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 @@ status_t CameraService::handleEvictionsLocked(const String8& cameraId, int clien } // Log the client's attempt + Mutex::Autolock l(mLogLock); mEventLog.add(msg); return -EBUSY; @@ -967,12 +976,10 @@ status_t CameraService::handleEvictionsLocked(const String8& cameraId, int clien 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 @@ status_t CameraService::connect( 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 @@ status_t CameraService::connectLegacy( /*out*/ sp& 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 @@ status_t CameraService::connectLegacy( */ 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 = nullptr; ret = connectHelper(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 @@ status_t CameraService::connectDevice( /*out*/client); if(ret != NO_ERROR) { + logRejected(id, getCallingPid(), String8(clientPackageName), + String8::format("%s (%d)", strerror(-ret), ret)); return ret; } @@ -1426,6 +1441,8 @@ void CameraService::doUserSwitch(int newUserId) { newUserId = DEFAULT_LAST_USER_ID; } + logUserSwitch(mLastUserId, newUserId); + mLastUserId = newUserId; // Current user has switched, evict all current clients. @@ -1444,12 +1461,12 @@ void CameraService::doUserSwitch(int newUserId) { 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 @@ void CameraService::doUserSwitch(int newUserId) { 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) { +void CameraService::logDisconnected(const char* cameraId, int clientPid, + const char* clientPackage) { + // Log the clients evicted + logEvent(String8::format("DISCONNECT device %s client for package %s (PID %d)", cameraId, + clientPackage, clientPid)); +} - String8 curTime = getFormattedCurrentTime(); +void CameraService::logConnected(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("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 @@ static bool tryLock(Mutex& mutex) } status_t CameraService::dump(int fd, const Vector& 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 @@ status_t CameraService::dump(int fd, const Vector& args) { 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 @@ void CameraService::handleTorchClientBinderDied(const wp &who) { /*virtual*/void CameraService::binderDied(const wp &who) { /** - * While tempting to promote the wp into a sp, - * it's actually not supported by the binder driver + * While tempting to promote the wp 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 @@ public: 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 @@ private: // Circular buffer for storing event logging for dumps RingBuffer mEventLog; + Mutex mLogLock; // UID of last user. int mLastUserId; @@ -546,14 +547,45 @@ private: 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 @@ status_t CameraService::connectHelper(const sp& cameraCb, const String 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(effectiveApiLevel)); + (halVersion == -1) ? "default" : std::to_string(halVersion).c_str(), + static_cast(effectiveApiLevel)); sp client = nullptr; { @@ -734,7 +767,15 @@ status_t CameraService::connectHelper(const sp& cameraCb, const String 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 -- cgit v1.1