CameraServiceProxy: Add CameraStatsLoggingService, event dumping

- Collect camera usage events (facing, client, duration)
- Create a JobService that triggers roughly daily to dump events

Test: Verify that 'adb shell cmd jobscheduler run android 13254266'
   prints out all camera usage since last run
Bug: 32449509
Change-Id: I13172e6e68f5cdb94685a112c74d270d1dda45bf
diff --git a/core/res/AndroidManifest.xml b/core/res/AndroidManifest.xml
index 4059c30..ae115d3 100644
--- a/core/res/AndroidManifest.xml
+++ b/core/res/AndroidManifest.xml
@@ -3817,6 +3817,11 @@
         <service android:name="com.android.server.PreloadsFileCacheExpirationJobService"
                  android:permission="android.permission.BIND_JOB_SERVICE" >
         </service>
+
+        <service android:name="com.android.server.camera.CameraStatsJobService"
+                 android:permission="android.permission.BIND_JOB_SERVICE" >
+        </service>
+
     </application>
 
 </manifest>
diff --git a/services/core/java/com/android/server/camera/CameraServiceProxy.java b/services/core/java/com/android/server/camera/CameraServiceProxy.java
index 82b2566..4cb7729 100644
--- a/services/core/java/com/android/server/camera/CameraServiceProxy.java
+++ b/services/core/java/com/android/server/camera/CameraServiceProxy.java
@@ -28,15 +28,20 @@
 import android.os.Message;
 import android.os.Process;
 import android.os.RemoteException;
+import android.os.SystemClock;
 import android.os.SystemProperties;
 import android.os.UserManager;
+import android.util.ArrayMap;
 import android.util.ArraySet;
 import android.util.Slog;
 
+import com.android.server.LocalServices;
 import com.android.server.ServiceThread;
 import com.android.server.SystemService;
 
+import java.util.ArrayList;
 import java.util.Collection;
+import java.util.List;
 import java.util.Set;
 
 /**
@@ -76,14 +81,52 @@
 
     private ICameraService mCameraServiceRaw;
 
-    private final ArraySet<String> mActiveCameraIds = new ArraySet<>();
+    private final ArrayMap<String, CameraUsageEvent> mActiveCameraUsage = new ArrayMap<>();
+    private final List<CameraUsageEvent> mCameraUsageHistory = new ArrayList<>();
 
     private static final String NFC_NOTIFICATION_PROP = "ro.camera.notify_nfc";
     private static final String NFC_SERVICE_BINDER_NAME = "nfc";
     private static final IBinder nfcInterfaceToken = new Binder();
 
     private final boolean mNotifyNfc;
-    private int mActiveCameraCount = 0;
+
+    /**
+     * Structure to track camera usage
+     */
+    private static class CameraUsageEvent {
+        public final int mCameraFacing;
+        public final String mClientName;
+
+        private boolean mCompleted;
+        private long mDurationOrStartTimeMs;  // Either start time, or duration once completed
+
+        public CameraUsageEvent(int facing, String clientName) {
+            mCameraFacing = facing;
+            mClientName = clientName;
+            mDurationOrStartTimeMs = SystemClock.elapsedRealtime();
+            mCompleted = false;
+        }
+
+        public void markCompleted() {
+            if (mCompleted) {
+                return;
+            }
+            mCompleted = true;
+            mDurationOrStartTimeMs = SystemClock.elapsedRealtime() - mDurationOrStartTimeMs;
+            if (CameraServiceProxy.DEBUG) {
+                Slog.v(TAG, "A camera facing " + cameraFacingToString(mCameraFacing) +
+                        " was in use by " + mClientName + " for " +
+                        mDurationOrStartTimeMs + " ms");
+            }
+        }
+
+        /**
+         * Return duration of camera usage event, or 0 if the event is not done
+         */
+        public long getDuration() {
+            return mCompleted ? mDurationOrStartTimeMs : 0;
+        }
+    }
 
     private final BroadcastReceiver mIntentReceiver = new BroadcastReceiver() {
         @Override
@@ -120,10 +163,11 @@
         public void notifyCameraState(String cameraId, int newCameraState, int facing,
                 String clientName) {
             String state = cameraStateToString(newCameraState);
-            if (DEBUG) Slog.v(TAG, "Camera " + cameraId + " facing " + facing + " state now " +
+            String facingStr = cameraFacingToString(facing);
+            if (DEBUG) Slog.v(TAG, "Camera " + cameraId + " facing " + facingStr + " state now " +
                     state + " for client " + clientName);
 
-            updateActivityCount(cameraId, newCameraState);
+            updateActivityCount(cameraId, newCameraState, facing, clientName);
         }
     };
 
@@ -169,6 +213,9 @@
         mContext.registerReceiver(mIntentReceiver, filter);
 
         publishBinderService(CAMERA_SERVICE_PROXY_BINDER_NAME, mCameraServiceProxy);
+        publishLocalService(CameraServiceProxy.class, this);
+
+        CameraStatsJobService.schedule(mContext);
     }
 
     @Override
@@ -198,8 +245,8 @@
             mCameraServiceRaw = null;
 
             // All cameras reset to idle on camera service death
-            boolean wasEmpty = mActiveCameraIds.isEmpty();
-            mActiveCameraIds.clear();
+            boolean wasEmpty = mActiveCameraUsage.isEmpty();
+            mActiveCameraUsage.clear();
 
             if ( mNotifyNfc && !wasEmpty ) {
                 notifyNfcService(/*enablePolling*/ true);
@@ -207,6 +254,25 @@
         }
     }
 
+    /**
+     * Dump camera usage events to log.
+     * Package-private
+     */
+    void dumpUsageEvents() {
+        synchronized(mLock) {
+            for (CameraUsageEvent e : mCameraUsageHistory) {
+                if (DEBUG) {
+                    Slog.v(TAG, "Camera: " + e.mClientName + " used a camera facing " +
+                            cameraFacingToString(e.mCameraFacing) + " for " +
+                            e.getDuration() + " ms");
+                }
+                // TODO: Add event logging here
+            }
+            mCameraUsageHistory.clear();
+        }
+        CameraStatsJobService.schedule(mContext);
+    }
+
     private void switchUserLocked(int userHandle) {
         Set<Integer> currentUserHandles = getEnabledUserHandles(userHandle);
         mLastUser = userHandle;
@@ -274,21 +340,32 @@
         return true;
     }
 
-    private void updateActivityCount(String cameraId, int newCameraState) {
+    private void updateActivityCount(String cameraId, int newCameraState, int facing, String clientName) {
         synchronized(mLock) {
-            boolean wasEmpty = mActiveCameraIds.isEmpty();
+            // Update active camera list and notify NFC if necessary
+            boolean wasEmpty = mActiveCameraUsage.isEmpty();
             switch (newCameraState) {
                 case ICameraServiceProxy.CAMERA_STATE_OPEN:
                     break;
                 case ICameraServiceProxy.CAMERA_STATE_ACTIVE:
-                    mActiveCameraIds.add(cameraId);
+                    CameraUsageEvent newEvent = new CameraUsageEvent(facing, clientName);
+                    CameraUsageEvent oldEvent = mActiveCameraUsage.put(cameraId, newEvent);
+                    if (oldEvent != null) {
+                        Slog.w(TAG, "Camera " + cameraId + " was already marked as active");
+                        oldEvent.markCompleted();
+                        mCameraUsageHistory.add(oldEvent);
+                    }
                     break;
                 case ICameraServiceProxy.CAMERA_STATE_IDLE:
                 case ICameraServiceProxy.CAMERA_STATE_CLOSED:
-                    mActiveCameraIds.remove(cameraId);
+                    CameraUsageEvent doneEvent = mActiveCameraUsage.remove(cameraId);
+                    if (doneEvent != null) {
+                        doneEvent.markCompleted();
+                        mCameraUsageHistory.add(doneEvent);
+                    }
                     break;
             }
-            boolean isEmpty = mActiveCameraIds.isEmpty();
+            boolean isEmpty = mActiveCameraUsage.isEmpty();
             if ( mNotifyNfc && (wasEmpty != isEmpty) ) {
                 notifyNfcService(isEmpty);
             }
@@ -332,4 +409,15 @@
         }
         return "CAMERA_STATE_UNKNOWN";
     }
+
+    private static String cameraFacingToString(int cameraFacing) {
+        switch (cameraFacing) {
+            case ICameraServiceProxy.CAMERA_FACING_BACK: return "CAMERA_FACING_BACK";
+            case ICameraServiceProxy.CAMERA_FACING_FRONT: return "CAMERA_FACING_FRONT";
+            case ICameraServiceProxy.CAMERA_FACING_EXTERNAL: return "CAMERA_FACING_EXTERNAL";
+            default: break;
+        }
+        return "CAMERA_FACING_UNKNOWN";
+    }
+
 }
diff --git a/services/core/java/com/android/server/camera/CameraStatsJobService.java b/services/core/java/com/android/server/camera/CameraStatsJobService.java
new file mode 100644
index 0000000..b8a6846
--- /dev/null
+++ b/services/core/java/com/android/server/camera/CameraStatsJobService.java
@@ -0,0 +1,77 @@
+/*
+ * Copyright (C) 2017 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/LICENSE2.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.
+ */
+
+package com.android.server.camera;
+
+import android.app.job.JobInfo;
+import android.app.job.JobParameters;
+import android.app.job.JobScheduler;
+import android.app.job.JobService;
+import android.content.ComponentName;
+import android.content.ContentResolver;
+import android.content.Context;
+import android.util.Slog;
+
+import java.util.concurrent.TimeUnit;
+
+import com.android.server.LocalServices;
+
+/**
+ * A JobService to periodically collect camera usage stats.
+ */
+public class CameraStatsJobService extends JobService {
+    private static final String TAG = "CameraStatsJobService";
+
+    // Must be unique within UID (system service)
+    private static final int CAMERA_REPORTING_JOB_ID = 0xCA3E7A;
+
+    private static ComponentName sCameraStatsJobServiceName = new ComponentName(
+            "android",
+            CameraStatsJobService.class.getName());
+
+    @Override
+    public boolean onStartJob(JobParameters params) {
+        CameraServiceProxy serviceProxy = LocalServices.getService(CameraServiceProxy.class);
+        if (serviceProxy == null) {
+            Slog.w(TAG, "Can't collect camera usage stats - no camera service proxy found");
+            return false;
+        }
+
+        serviceProxy.dumpUsageEvents();
+        return false;
+    }
+
+    @Override
+    public boolean onStopJob(JobParameters params) {
+        // All work is done in onStartJob, so nothing to stop here
+        return false;
+    }
+
+    public static void schedule(Context context) {
+
+        JobScheduler js = (JobScheduler) context.getSystemService(Context.JOB_SCHEDULER_SERVICE);
+        if (js == null) {
+            Slog.e(TAG, "Can't collect camera usage stats - no Job Scheduler");
+            return;
+        }
+        js.schedule(new JobInfo.Builder(CAMERA_REPORTING_JOB_ID, sCameraStatsJobServiceName)
+                .setMinimumLatency(TimeUnit.DAYS.toMillis(1))
+                .setRequiresDeviceIdle(true)
+                .build());
+
+    }
+
+}
diff --git a/services/java/com/android/server/SystemServer.java b/services/java/com/android/server/SystemServer.java
index eca285a..c9be3a2 100644
--- a/services/java/com/android/server/SystemServer.java
+++ b/services/java/com/android/server/SystemServer.java
@@ -775,13 +775,6 @@
 
             mContentResolver = context.getContentResolver();
 
-            if (!disableCameraService) {
-                Slog.i(TAG, "Camera Service Proxy");
-                traceBeginAndSlog("StartCameraServiceProxy");
-                mSystemServiceManager.startService(CameraServiceProxy.class);
-                traceEnd();
-            }
-
             // The AccountManager must come before the ContentService
             traceBeginAndSlog("StartAccountManagerService");
             mSystemServiceManager.startService(ACCOUNT_SERVICE_CLASS);
@@ -1531,6 +1524,12 @@
             }
         }
 
+        if (!disableCameraService) {
+            traceBeginAndSlog("StartCameraServiceProxy");
+            mSystemServiceManager.startService(CameraServiceProxy.class);
+            traceEnd();
+        }
+
         // Before things start rolling, be sure we have decided whether
         // we are in safe mode.
         final boolean safeMode = wm.detectSafeMode();