Merge "Add event logger to BroadcastRadio Service" into tm-qpr-dev

services/core/java/com/android/server/broadcastradio/hal2/RadioEventLogger.java

@@ -0,0 +1,44 @@
+/**
+ * Copyright (C) 2022 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/LICENSE-2.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.broadcastradio.hal2;
+
+import android.util.IndentingPrintWriter;
+import android.util.LocalLog;
+import android.util.Log;
+import android.util.Slog;
+
+final class RadioEventLogger {
+    private final String mTag;
+    private final LocalLog mEventLogger;
+
+    RadioEventLogger(String tag, int loggerQueueSize) {
+        mTag = tag;
+        mEventLogger = new LocalLog(loggerQueueSize);
+    }
+
+    void logRadioEvent(String logFormat, Object... args) {
+        String log = String.format(logFormat, args);
+        mEventLogger.log(log);
+        if (Log.isLoggable(mTag, Log.DEBUG)) {
+            Slog.d(mTag, log);
+        }
+    }
+
+    void dump(IndentingPrintWriter pw) {
+        mEventLogger.dump(pw);
+    }
+}

services/core/java/com/android/server/broadcastradio/hal2/RadioModule.java

@@ -55,12 +55,14 @@ import java.util.stream.Collectors;
 
 class RadioModule {
     private static final String TAG = "BcRadio2Srv.module";
+    private static final int RADIO_EVENT_LOGGER_QUEUE_SIZE = 25;
 
     @NonNull private final IBroadcastRadio mService;
     @NonNull public final RadioManager.ModuleProperties mProperties;
 
     private final Object mLock;
     @NonNull private final Handler mHandler;
+    @NonNull private final RadioEventLogger mEventLogger;
 
     @GuardedBy("mLock")
     private ITunerSession mHalTunerSession;
@@ -138,6 +140,7 @@ class RadioModule {
         mService = Objects.requireNonNull(service);
         mLock = Objects.requireNonNull(lock);
         mHandler = new Handler(Looper.getMainLooper());
+        mEventLogger = new RadioEventLogger(TAG, RADIO_EVENT_LOGGER_QUEUE_SIZE);
     }
 
     public static @Nullable RadioModule tryLoadingModule(int idx, @NonNull String fqName,
@@ -176,13 +179,14 @@ class RadioModule {
 
     public @NonNull TunerSession openSession(@NonNull android.hardware.radio.ITunerCallback userCb)
             throws RemoteException {
-        Slog.i(TAG, "Open TunerSession");
+        mEventLogger.logRadioEvent("Open TunerSession");
         synchronized (mLock) {
             if (mHalTunerSession == null) {
                 Mutable<ITunerSession> hwSession = new Mutable<>();
                 mService.openSession(mHalTunerCallback, (result, session) -> {
                     Convert.throwOnError("openSession", result);
                     hwSession.value = session;
+                    mEventLogger.logRadioEvent("New HIDL 2.0 tuner session is opened");
                 });
                 mHalTunerSession = Objects.requireNonNull(hwSession.value);
             }
@@ -207,7 +211,7 @@ class RadioModule {
         // Copy the contents of mAidlTunerSessions into a local array because TunerSession.close()
         // must be called without mAidlTunerSessions locked because it can call
         // onTunerSessionClosed().
-        Slog.i(TAG, "Close TunerSessions");
+        mEventLogger.logRadioEvent("Close TunerSessions");
         TunerSession[] tunerSessions;
         synchronized (mLock) {
             tunerSessions = new TunerSession[mAidlTunerSessions.size()];
@@ -320,7 +324,7 @@ class RadioModule {
         }
         onTunerSessionProgramListFilterChanged(null);
         if (mAidlTunerSessions.isEmpty() && mHalTunerSession != null) {
-            Slog.i(TAG, "Closing HAL tuner session");
+            mEventLogger.logRadioEvent("Closing HAL tuner session");
             try {
                 mHalTunerSession.close();
             } catch (RemoteException ex) {
@@ -372,7 +376,7 @@ class RadioModule {
 
     public android.hardware.radio.ICloseHandle addAnnouncementListener(@NonNull int[] enabledTypes,
             @NonNull android.hardware.radio.IAnnouncementListener listener) throws RemoteException {
-        Slog.i(TAG, "Add AnnouncementListener");
+        mEventLogger.logRadioEvent("Add AnnouncementListener");
         ArrayList<Byte> enabledList = new ArrayList<>();
         for (int type : enabledTypes) {
             enabledList.add((byte)type);
@@ -409,7 +413,7 @@ class RadioModule {
     }
 
     Bitmap getImage(int id) {
-        Slog.i(TAG, "Get image for id " + id);
+        mEventLogger.logRadioEvent("Get image for id %d", id);
         if (id == 0) throw new IllegalArgumentException("Image ID is missing");
 
         byte[] rawImage;
@@ -449,6 +453,10 @@ class RadioModule {
             }
             pw.decreaseIndent();
         }
+        pw.printf("Radio module events:\n");
+        pw.increaseIndent();
+        mEventLogger.dump(pw);
+        pw.decreaseIndent();
         pw.decreaseIndent();
     }
 }

services/core/java/com/android/server/broadcastradio/hal2/TunerSession.java

@@ -28,7 +28,6 @@ import android.hardware.radio.ProgramSelector;
 import android.hardware.radio.RadioManager;
 import android.os.RemoteException;
 import android.util.IndentingPrintWriter;
-import android.util.Log;
 import android.util.MutableBoolean;
 import android.util.MutableInt;
 import android.util.Slog;
@@ -41,8 +40,10 @@ import java.util.Objects;
 class TunerSession extends ITuner.Stub {
     private static final String TAG = "BcRadio2Srv.session";
     private static final String kAudioDeviceName = "Radio tuner source";
+    private static final int TUNER_EVENT_LOGGER_QUEUE_SIZE = 25;
 
     private final Object mLock;
+    @NonNull private final RadioEventLogger mEventLogger;
 
     private final RadioModule mModule;
     private final ITunerSession mHwSession;
@@ -61,15 +62,12 @@ class TunerSession extends ITuner.Stub {
         mHwSession = Objects.requireNonNull(hwSession);
         mCallback = Objects.requireNonNull(callback);
         mLock = Objects.requireNonNull(lock);
-    }
+        mEventLogger = new RadioEventLogger(TAG, TUNER_EVENT_LOGGER_QUEUE_SIZE);
-
-    private boolean isDebugEnabled() {
-        return Log.isLoggable(TAG, Log.DEBUG);
     }
 
     @Override
     public void close() {
-        if (isDebugEnabled()) Slog.d(TAG, "Close");
+        mEventLogger.logRadioEvent("Close");
         close(null);
     }
 
@@ -81,7 +79,7 @@ class TunerSession extends ITuner.Stub {
      * @param error Optional error to send to client before session is closed.
      */
     public void close(@Nullable Integer error) {
-        if (isDebugEnabled()) Slog.d(TAG, "Close on error " + error);
+        mEventLogger.logRadioEvent("Close on error %d", error);
         synchronized (mLock) {
             if (mIsClosed) return;
             if (error != null) {
@@ -145,10 +143,8 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public void step(boolean directionDown, boolean skipSubChannel) throws RemoteException {
-        if (isDebugEnabled()) {
+        mEventLogger.logRadioEvent("Step with direction %s, skipSubChannel?  %s",
-            Slog.d(TAG, "Step with directionDown " + directionDown
+                directionDown ? "down" : "up", skipSubChannel ? "yes" : "no");
-                    + " skipSubChannel " + skipSubChannel);
-        }
         synchronized (mLock) {
             checkNotClosedLocked();
             int halResult = mHwSession.step(!directionDown);
@@ -158,10 +154,8 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public void scan(boolean directionDown, boolean skipSubChannel) throws RemoteException {
-        if (isDebugEnabled()) {
+        mEventLogger.logRadioEvent("Scan with direction %s, skipSubChannel? %s",
-            Slog.d(TAG, "Scan with directionDown " + directionDown
+                directionDown ? "down" : "up", skipSubChannel ? "yes" : "no");
-                    + " skipSubChannel " + skipSubChannel);
-        }
         synchronized (mLock) {
             checkNotClosedLocked();
             int halResult = mHwSession.scan(!directionDown, skipSubChannel);
@@ -171,7 +165,7 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public void tune(ProgramSelector selector) throws RemoteException {
-        if (isDebugEnabled()) Slog.d(TAG, "Tune with selector " + selector);
+        mEventLogger.logRadioEvent("Tune with selector %s", selector);
         synchronized (mLock) {
             checkNotClosedLocked();
             int halResult = mHwSession.tune(Convert.programSelectorToHal(selector));
@@ -195,7 +189,7 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public Bitmap getImage(int id) {
-        if (isDebugEnabled()) Slog.d(TAG, "Get image for " + id);
+        mEventLogger.logRadioEvent("Get image for %d", id);
         return mModule.getImage(id);
     }
 
@@ -208,7 +202,7 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public void startProgramListUpdates(ProgramList.Filter filter) throws RemoteException {
-        if (isDebugEnabled()) Slog.d(TAG, "start programList updates " + filter);
+        mEventLogger.logRadioEvent("start programList updates %s", filter);
         // If the AIDL client provides a null filter, it wants all updates, so use the most broad
         // filter.
         if (filter == null) {
@@ -267,7 +261,7 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public void stopProgramListUpdates() throws RemoteException {
-        if (isDebugEnabled()) Slog.d(TAG, "Stop programList updates");
+        mEventLogger.logRadioEvent("Stop programList updates");
         synchronized (mLock) {
             checkNotClosedLocked();
             mProgramInfoCache = null;
@@ -291,7 +285,7 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public boolean isConfigFlagSet(int flag) {
-        if (isDebugEnabled()) Slog.d(TAG, "Is ConfigFlagSet for " + ConfigFlag.toString(flag));
+        mEventLogger.logRadioEvent("Is ConfigFlagSet for %s", ConfigFlag.toString(flag));
         synchronized (mLock) {
             checkNotClosedLocked();
 
@@ -313,9 +307,7 @@ class TunerSession extends ITuner.Stub {
 
     @Override
     public void setConfigFlag(int flag, boolean value) throws RemoteException {
-        if (isDebugEnabled()) {
+        mEventLogger.logRadioEvent("Set ConfigFlag  %s = %b", ConfigFlag.toString(flag), value);
-            Slog.d(TAG, "Set ConfigFlag " + ConfigFlag.toString(flag) + " = " + value);
-        }
         synchronized (mLock) {
             checkNotClosedLocked();
             int halResult = mHwSession.setConfigFlag(flag, value);
@@ -351,6 +343,10 @@ class TunerSession extends ITuner.Stub {
             pw.printf("ProgramInfoCache: %s\n", mProgramInfoCache);
             pw.printf("Config: %s\n", mDummyConfig);
         }
+        pw.printf("Tuner session events:\n");
+        pw.increaseIndent();
+        mEventLogger.dump(pw);
+        pw.decreaseIndent();
         pw.decreaseIndent();
     }
 }