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
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