Add logs to identify more virtual display error states and media projection stop states

Bug: 290540247
Test: N/A
Change-Id: Ic3cc9ecff0d27e973925addb7cf4a87a430c2666
diff --git a/data/etc/services.core.protolog.json b/data/etc/services.core.protolog.json
index 94e23e7..71e9263 100644
--- a/data/etc/services.core.protolog.json
+++ b/data/etc/services.core.protolog.json
@@ -427,12 +427,6 @@
       "group": "WM_DEBUG_BACK_PREVIEW",
       "at": "com\/android\/server\/wm\/BackNavigationController.java"
     },
-    "-1715268616": {
-      "message": "Last window, removing starting window %s",
-      "level": "VERBOSE",
-      "group": "WM_DEBUG_STARTING_WINDOW",
-      "at": "com\/android\/server\/wm\/ActivityRecord.java"
-    },
     "-1710206702": {
       "message": "Display id=%d is frozen while keyguard locked, return %d",
       "level": "VERBOSE",
@@ -691,6 +685,12 @@
       "group": "WM_DEBUG_WINDOW_TRANSITIONS",
       "at": "com\/android\/server\/wm\/Transition.java"
     },
+    "-1449515133": {
+      "message": "Content Recording: stopping active projection for display %d",
+      "level": "ERROR",
+      "group": "WM_DEBUG_CONTENT_RECORDING",
+      "at": "com\/android\/server\/wm\/ContentRecorder.java"
+    },
     "-1443029505": {
       "message": "SAFE MODE ENABLED (menu=%d s=%d dpad=%d trackball=%d)",
       "level": "INFO",
@@ -1279,6 +1279,12 @@
       "group": "WM_DEBUG_STATES",
       "at": "com\/android\/server\/wm\/ActivityRecord.java"
     },
+    "-921346089": {
+      "message": "Content Recording: Unable to tell MediaProjectionManagerService to stop the active projection for display %d: %s",
+      "level": "ERROR",
+      "group": "WM_DEBUG_CONTENT_RECORDING",
+      "at": "com\/android\/server\/wm\/ContentRecorder.java"
+    },
     "-917215012": {
       "message": "%s: caller %d is using old GET_TASKS but privileged; allowing",
       "level": "WARN",
@@ -2227,12 +2233,6 @@
       "group": "WM_DEBUG_CONFIGURATION",
       "at": "com\/android\/server\/wm\/ActivityRecord.java"
     },
-    "-88873335": {
-      "message": "Content Recording: Unable to tell MediaProjectionManagerService to stop the active projection: %s",
-      "level": "ERROR",
-      "group": "WM_DEBUG_CONTENT_RECORDING",
-      "at": "com\/android\/server\/wm\/ContentRecorder.java"
-    },
     "-87705714": {
       "message": "findFocusedWindow: focusedApp=null using new focus @ %s",
       "level": "VERBOSE",
@@ -4057,12 +4057,6 @@
       "group": "WM_DEBUG_WINDOW_TRANSITIONS",
       "at": "com\/android\/server\/wm\/Transition.java"
     },
-    "1671994402": {
-      "message": "Nulling last startingData",
-      "level": "VERBOSE",
-      "group": "WM_DEBUG_STARTING_WINDOW",
-      "at": "com\/android\/server\/wm\/ActivityRecord.java"
-    },
     "1674747211": {
       "message": "%s forcing orientation to %d for display id=%d",
       "level": "VERBOSE",
@@ -4243,12 +4237,6 @@
       "group": "WM_DEBUG_ORIENTATION",
       "at": "com\/android\/server\/wm\/ActivityRecord.java"
     },
-    "1853793312": {
-      "message": "Notify removed startingWindow %s",
-      "level": "VERBOSE",
-      "group": "WM_DEBUG_STARTING_WINDOW",
-      "at": "com\/android\/server\/wm\/ActivityRecord.java"
-    },
     "1856783490": {
       "message": "resumeTopActivity: Restarting %s",
       "level": "DEBUG",
diff --git a/media/java/android/media/projection/MediaProjection.java b/media/java/android/media/projection/MediaProjection.java
index fb72c7b..223b432c 100644
--- a/media/java/android/media/projection/MediaProjection.java
+++ b/media/java/android/media/projection/MediaProjection.java
@@ -83,6 +83,7 @@
         try {
             mImpl.start(new MediaProjectionCallback());
         } catch (RemoteException e) {
+            Log.e(TAG, "Content Recording: Failed to start media projection", e);
             throw new RuntimeException("Failed to start media projection", e);
         }
         mDisplayManager = displayManager;
@@ -105,11 +106,18 @@
      * @see #unregisterCallback
      */
     public void registerCallback(@NonNull Callback callback, @Nullable Handler handler) {
-        final Callback c = Objects.requireNonNull(callback);
-        if (handler == null) {
-            handler = new Handler();
+        try {
+            final Callback c = Objects.requireNonNull(callback);
+            if (handler == null) {
+                handler = new Handler();
+            }
+            mCallbacks.put(c, new CallbackRecord(c, handler));
+        } catch (NullPointerException e) {
+            Log.e(TAG, "Content Recording: cannot register null Callback", e);
+            throw e;
+        } catch (RuntimeException e) {
+            Log.e(TAG, "Content Recording: failed to create new Handler to register Callback", e);
         }
-        mCallbacks.put(c, new CallbackRecord(c, handler));
     }
 
     /**
@@ -120,8 +128,13 @@
      * @see #registerCallback
      */
     public void unregisterCallback(@NonNull Callback callback) {
-        final Callback c = Objects.requireNonNull(callback);
-        mCallbacks.remove(c);
+        try {
+            final Callback c = Objects.requireNonNull(callback);
+            mCallbacks.remove(c);
+        } catch (NullPointerException e) {
+            Log.d(TAG, "Content Recording: cannot unregister null Callback", e);
+            throw e;
+        }
     }
 
     /**
@@ -203,9 +216,11 @@
             @Nullable VirtualDisplay.Callback callback, @Nullable Handler handler) {
         if (shouldMediaProjectionRequireCallback()) {
             if (mCallbacks.isEmpty()) {
-                throw new IllegalStateException(
+                final IllegalStateException e = new IllegalStateException(
                         "Must register a callback before starting capture, to manage resources in"
                                 + " response to MediaProjection states.");
+                Log.e(TAG, "Content Recording: no callback registered for virtual display", e);
+                throw e;
             }
         }
         final VirtualDisplayConfig.Builder builder = new VirtualDisplayConfig.Builder(name, width,
@@ -272,6 +287,7 @@
      */
     public void stop() {
         try {
+            Log.d(TAG, "Content Recording: stopping projection");
             mImpl.stop();
         } catch (RemoteException e) {
             Log.e(TAG, "Unable to stop projection", e);
diff --git a/media/java/android/media/projection/MediaProjectionManager.java b/media/java/android/media/projection/MediaProjectionManager.java
index 5a68c53..9790d02 100644
--- a/media/java/android/media/projection/MediaProjectionManager.java
+++ b/media/java/android/media/projection/MediaProjectionManager.java
@@ -256,6 +256,7 @@
      */
     public void stopActiveProjection() {
         try {
+            Log.d(TAG, "Content Recording: stopping active projection");
             mService.stopActiveProjection();
         } catch (RemoteException e) {
             Log.e(TAG, "Unable to stop the currently active media projection", e);
@@ -269,6 +270,7 @@
      */
     public void addCallback(@NonNull Callback callback, @Nullable Handler handler) {
         if (callback == null) {
+            Log.w(TAG, "Content Recording: cannot add null callback");
             throw new IllegalArgumentException("callback must not be null");
         }
         CallbackDelegate delegate = new CallbackDelegate(callback, handler);
@@ -286,6 +288,7 @@
      */
     public void removeCallback(@NonNull Callback callback) {
         if (callback == null) {
+            Log.w(TAG, "ContentRecording: cannot remove null callback");
             throw new IllegalArgumentException("callback must not be null");
         }
         CallbackDelegate delegate = mCallbacks.remove(callback);
diff --git a/services/core/java/com/android/server/display/DisplayManagerService.java b/services/core/java/com/android/server/display/DisplayManagerService.java
index 626502e..898a3c4 100644
--- a/services/core/java/com/android/server/display/DisplayManagerService.java
+++ b/services/core/java/com/android/server/display/DisplayManagerService.java
@@ -1546,6 +1546,7 @@
                 if (displayId != Display.INVALID_DISPLAY && virtualDevice != null && dwpc != null) {
                     mDisplayWindowPolicyControllers.put(
                             displayId, Pair.create(virtualDevice, dwpc));
+                    Slog.d(TAG, "Virtual Display: successfully created virtual display");
                 }
             }
 
@@ -1592,19 +1593,25 @@
                     if (!getProjectionService().setContentRecordingSession(session, projection)) {
                         // Unable to start mirroring, so release VirtualDisplay. Projection service
                         // handles stopping the projection.
+                        Slog.w(TAG, "Content Recording: failed to start mirroring - "
+                                + "releasing virtual display " + displayId);
                         releaseVirtualDisplayInternal(callback.asBinder());
                         return Display.INVALID_DISPLAY;
                     } else if (projection != null) {
                         // Indicate that this projection has been used to record, and can't be used
                         // again.
+                        Slog.d(TAG, "Content Recording: notifying MediaProjection of successful"
+                                + " VirtualDisplay creation.");
                         projection.notifyVirtualDisplayCreated(displayId);
                     }
                 } catch (RemoteException e) {
                     Slog.e(TAG, "Unable to tell MediaProjectionManagerService to set the "
                             + "content recording session", e);
+                    return displayId;
                 }
+                Slog.d(TAG, "Virtual Display: successfully set up virtual display "
+                        + displayId);
             }
-
             return displayId;
         } finally {
             Binder.restoreCallingIdentity(secondToken);
@@ -1628,10 +1635,13 @@
             return -1;
         }
 
+
+        Slog.d(TAG, "Virtual Display: creating DisplayDevice with VirtualDisplayAdapter");
         DisplayDevice device = mVirtualDisplayAdapter.createVirtualDisplayLocked(
                 callback, projection, callingUid, packageName, surface, flags,
                 virtualDisplayConfig);
         if (device == null) {
+            Slog.w(TAG, "Virtual Display: VirtualDisplayAdapter failed to create DisplayDevice");
             return -1;
         }
 
@@ -1709,6 +1719,7 @@
 
             DisplayDevice device =
                     mVirtualDisplayAdapter.releaseVirtualDisplayLocked(appToken);
+            Slog.d(TAG, "Virtual Display: Display Device released");
             if (device != null) {
                 // TODO: multi-display - handle virtual displays the same as other display adapters.
                 mDisplayDeviceRepo.onDisplayDeviceEvent(device,
diff --git a/services/core/java/com/android/server/display/VirtualDisplayAdapter.java b/services/core/java/com/android/server/display/VirtualDisplayAdapter.java
index 4f7a2ba..9f480b6 100644
--- a/services/core/java/com/android/server/display/VirtualDisplayAdapter.java
+++ b/services/core/java/com/android/server/display/VirtualDisplayAdapter.java
@@ -141,9 +141,12 @@
         try {
             if (projection != null) {
                 projection.registerCallback(mediaProjectionCallback);
+                Slog.d(TAG, "Virtual Display: registered media projection callback for new "
+                        + "VirtualDisplayDevice");
             }
             appToken.linkToDeath(device, 0);
         } catch (RemoteException ex) {
+            Slog.e(TAG, "Virtual Display: error while setting up VirtualDisplayDevice", ex);
             mVirtualDisplayDevices.remove(appToken);
             device.destroyLocked(false);
             return null;
@@ -439,6 +442,7 @@
         }
 
         public void stopLocked() {
+            Slog.d(TAG, "Virtual Display: stopping device " + mName);
             setSurfaceLocked(null);
             mStopped = true;
         }
diff --git a/services/core/java/com/android/server/media/projection/MediaProjectionManagerService.java b/services/core/java/com/android/server/media/projection/MediaProjectionManagerService.java
index fb3f0b3..802a7f2 100644
--- a/services/core/java/com/android/server/media/projection/MediaProjectionManagerService.java
+++ b/services/core/java/com/android/server/media/projection/MediaProjectionManagerService.java
@@ -225,6 +225,7 @@
         mMediaRouter.rebindAsUser(to.getUserIdentifier());
         synchronized (mLock) {
             if (mProjectionGrant != null) {
+                Slog.d(TAG, "Content Recording: Stopped MediaProjection due to user switching");
                 mProjectionGrant.stop();
             }
         }
@@ -260,6 +261,8 @@
         }
 
         synchronized (mLock) {
+            Slog.d(TAG,
+                    "Content Recording: Stopped MediaProjection due to foreground service change");
             if (mProjectionGrant != null) {
                 mProjectionGrant.stop();
             }
@@ -268,6 +271,8 @@
 
     private void startProjectionLocked(final MediaProjection projection) {
         if (mProjectionGrant != null) {
+            Slog.d(TAG, "Content Recording: Stopped MediaProjection to start new "
+                    + "incoming projection");
             mProjectionGrant.stop();
         }
         if (mMediaRouteInfo != null) {
@@ -279,6 +284,8 @@
     }
 
     private void stopProjectionLocked(final MediaProjection projection) {
+        Slog.d(TAG, "Content Recording: Stopped active MediaProjection and "
+                + "dispatching stop to callbacks");
         mProjectionToken = null;
         mProjectionGrant = null;
         dispatchStop(projection);
@@ -351,6 +358,13 @@
             if (!setSessionSucceeded) {
                 // Unable to start mirroring, so tear down this projection.
                 if (mProjectionGrant != null) {
+                    String projectionType = incomingSession != null
+                            ? ContentRecordingSession.recordContentToString(
+                                    incomingSession.getContentToRecord()) : "none";
+                    Slog.w(TAG, "Content Recording: Stopped MediaProjection due to failing to set "
+                            + "ContentRecordingSession - id= "
+                            + mProjectionGrant.getVirtualDisplayId() + "type=" + projectionType);
+
                     mProjectionGrant.stop();
                 }
                 return false;
@@ -464,6 +478,9 @@
                     // The grant may now be null if setting the session failed.
                     if (mProjectionGrant != null) {
                         // Always stop the projection.
+                        Slog.w(TAG, "Content Recording: Stopped MediaProjection due to user "
+                                + "consent result of CANCEL - "
+                                + "id= " + mProjectionGrant.getVirtualDisplayId());
                         mProjectionGrant.stop();
                     }
                     break;
@@ -672,6 +689,7 @@
             try {
                 synchronized (mLock) {
                     if (mProjectionGrant != null) {
+                        Slog.d(TAG, "Content Recording: Stopping active projection");
                         mProjectionGrant.stop();
                     }
                 }
@@ -882,6 +900,10 @@
                     MEDIA_PROJECTION_TOKEN_EVENT_CREATED);
         }
 
+        int getVirtualDisplayId() {
+            return mVirtualDisplayId;
+        }
+
         @Override // Binder call
         public boolean canProjectVideo() {
             return mType == MediaProjectionManager.TYPE_MIRRORING ||
@@ -958,12 +980,11 @@
                 registerCallback(mCallback);
                 try {
                     mToken = callback.asBinder();
-                    mDeathEater = new IBinder.DeathRecipient() {
-                        @Override
-                        public void binderDied() {
-                            mCallbackDelegate.remove(callback);
-                            stop();
-                        }
+                    mDeathEater = () -> {
+                        Slog.d(TAG, "Content Recording: MediaProjection stopped by Binder death - "
+                                + "id= " + mVirtualDisplayId);
+                        mCallbackDelegate.remove(callback);
+                        stop();
                     };
                     mToken.linkToDeath(mDeathEater, 0);
                 } catch (RemoteException e) {
@@ -1033,6 +1054,9 @@
                         Binder.restoreCallingIdentity(token);
                     }
                 }
+                Slog.d(TAG, "Content Recording: handling stopping this projection token"
+                        + " createTime= " + mCreateTimeMs
+                        + " countStarts= " + mCountStarts);
                 stopProjectionLocked(this);
                 mToken.unlinkToDeath(mDeathEater, 0);
                 mToken = null;
@@ -1158,6 +1182,8 @@
                 if ((type & MediaRouter.ROUTE_TYPE_REMOTE_DISPLAY) != 0) {
                     mMediaRouteInfo = info;
                     if (mProjectionGrant != null) {
+                        Slog.d(TAG, "Content Recording: Stopped MediaProjection due to "
+                                + "route type of REMOTE_DISPLAY not selected");
                         mProjectionGrant.stop();
                     }
                 }
@@ -1329,7 +1355,7 @@
             try {
                 mCallback.onStart(mInfo);
             } catch (RemoteException e) {
-                Slog.w(TAG, "Failed to notify media projection has stopped", e);
+                Slog.w(TAG, "Failed to notify media projection has started", e);
             }
         }
     }
@@ -1403,7 +1429,8 @@
                 return "TYPE_MIRRORING";
             case MediaProjectionManager.TYPE_PRESENTATION:
                 return "TYPE_PRESENTATION";
+            default:
+                return Integer.toString(type);
         }
-        return Integer.toString(type);
     }
 }
diff --git a/services/core/java/com/android/server/wm/ContentRecorder.java b/services/core/java/com/android/server/wm/ContentRecorder.java
index 2ecbf8a..5aa7c97 100644
--- a/services/core/java/com/android/server/wm/ContentRecorder.java
+++ b/services/core/java/com/android/server/wm/ContentRecorder.java
@@ -87,7 +87,7 @@
     private int mLastOrientation = ORIENTATION_UNDEFINED;
 
     ContentRecorder(@NonNull DisplayContent displayContent) {
-        this(displayContent, new RemoteMediaProjectionManagerWrapper());
+        this(displayContent, new RemoteMediaProjectionManagerWrapper(displayContent.mDisplayId));
     }
 
     @VisibleForTesting
@@ -556,8 +556,14 @@
 
     private static final class RemoteMediaProjectionManagerWrapper implements
             MediaProjectionManagerWrapper {
+
+        private final int mDisplayId;
         @Nullable private IMediaProjectionManager mIMediaProjectionManager = null;
 
+        RemoteMediaProjectionManagerWrapper(int displayId) {
+            mDisplayId = displayId;
+        }
+
         @Override
         public void stopActiveProjection() {
             fetchMediaProjectionManager();
@@ -565,12 +571,15 @@
                 return;
             }
             try {
+                ProtoLog.e(WM_DEBUG_CONTENT_RECORDING,
+                        "Content Recording: stopping active projection for display %d",
+                        mDisplayId);
                 mIMediaProjectionManager.stopActiveProjection();
             } catch (RemoteException e) {
                 ProtoLog.e(WM_DEBUG_CONTENT_RECORDING,
                         "Content Recording: Unable to tell MediaProjectionManagerService to stop "
-                                + "the active projection: %s",
-                        e);
+                                + "the active projection for display %d: %s",
+                        mDisplayId, e);
             }
         }