Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit ebf1ad71 authored by Aaron Massey's avatar Aaron Massey
Browse files

stats: Add MainPrintUiLaunched event

We want to log when the main print UI is launched.

Log the main print UI and its found printers/printservices.

Bug: 390478410
Test: atest PrintSpoolerRobolectricTests
Test: m PrintSpooler
Test: validate logged events via adb and webui
Flag: com.android.printspooler.flags.printing_telemetry
Change-Id: I7dc3304ae255166882e794d228c09b8e6e62365b
parent 95699b3b
Loading
Loading
Loading
Loading
+38 −0
Original line number Diff line number Diff line
@@ -147,4 +147,42 @@ object StatsAsyncLogger {
        }
        return true
    }

    fun MainPrintUiLaunched(@UserIdInt printServiceIds: Set<Int>, printerCount: Int): Boolean {
        if (!logging) {
            return false
        }
        if (DEBUG) {
            Log.d(TAG, "Logging MainPrintUiLaunched event")
        }
        synchronized(semaphore) {
            if (!semaphore.tryAcquire()) {
                Log.w(TAG, "Logging too many events, dropping MainPrintUiLaunched event")
                return false
            }
            val result =
                eventHandler.postAtTime(
                    Runnable {
                        synchronized(semaphore) {
                            if (DEBUG) {
                                Log.d(TAG, "Async logging MainPrintUiLaunched event")
                            }
                            statsLogWrapper.internalMainPrintUiLaunched(
                                printServiceIds,
                                printerCount,
                            )
                            semaphore.release()
                        }
                    },
                    nextAvailableTimeMillis,
                )
            if (!result) {
                Log.e(TAG, "Could not log MainPrintUiLaunched event")
                semaphore.release()
                return false
            }
            nextAvailableTimeMillis = getNextAvailableTimeMillis()
        }
        return true
    }
}
+11 −0
Original line number Diff line number Diff line
@@ -38,4 +38,15 @@ open class StatsLogWrapper {
            printServiceId,
        )
    }

    open fun internalMainPrintUiLaunched(
        @UserIdInt printServiceIds: Set<Int>,
        printServiceCount: Int,
    ) {
        PrintSpoolerStatsLog.write(
            PrintSpoolerStatsLog.FRAMEWORK_MAIN_PRINT_UI_LAUNCHED,
            printServiceIds.toIntArray(),
            printServiceCount,
        )
    }
}
+28 −0
Original line number Diff line number Diff line
@@ -120,8 +120,10 @@ import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
import java.util.Collections;
import java.util.HashSet;
import java.util.List;
import java.util.Objects;
import java.util.Set;
import java.util.function.Consumer;

public class PrintActivity extends Activity implements RemotePrintDocument.UpdateResultCallbacks,
@@ -2205,6 +2207,32 @@ public class PrintActivity extends Activity implements RemotePrintDocument.Updat
            return;
        }

        if (Flags.printingTelemetry()) {
            // If this runs any earlier we double log when a printjob
            // is completed. If it gets called any later than it does
            // not get called when a user launches the printing UI
            // without printing anything or opening "All printers".

            // We record the MainPrintUilaunched event and recorded
            // printers/services at the end of the activity lifecycle
            // so there has been time for printers to be discovered.
            final List<PrinterInfo> printers = (mPrinterRegistry == null)
                    ? new ArrayList<>() :
                      mPrinterRegistry.getPrinters();
            final Set<Integer> printServiceUIds = new HashSet<>();
            for (final PrinterInfo printer : printers) {
                final String serviceName = printer.getId().getServiceName().getPackageName();
                try {
                    final int serviceUId =
                            getPackageManager().getApplicationInfo(serviceName, 0).uid;
                    printServiceUIds.add(serviceUId);
                } catch (NameNotFoundException e) {
                    Log.e(LOG_TAG, "Failed to get uid for service");
                }
            }
            StatsAsyncLogger.INSTANCE.MainPrintUiLaunched(printServiceUIds, printers.size());
        }

        if (mIsFinishing) {
            return;
        }
+46 −1
Original line number Diff line number Diff line
@@ -61,6 +61,48 @@ open class StatsAsyncLoggerTest {
        StatsAsyncLogger.stopLogging()
    }

    @Test
    fun mainPrintUiLaunchedSuccessfullyLoggedTest() {
        val logWrapperInOrder = inOrder(mStatsLogWrapper)
        val handlerInOrder = inOrder(mHandler)
        val semaphoreInOrder = inOrder(mSemaphore)
        val timeCaptor = argumentCaptor<Long>()
        val runnableCaptor = argumentCaptor<Runnable>()

        StatsAsyncLogger.startLogging()
        StatsAsyncLogger.testSetSemaphore(mSemaphore)
        StatsAsyncLogger.testSetHandler(mHandler)
        StatsAsyncLogger.testSetStatsLogWrapper(mStatsLogWrapper)

        // Arbitrary arguments
        assertThat(StatsAsyncLogger.MainPrintUiLaunched(setOf(1, 2, 3), 42)).isTrue()
        assertThat(StatsAsyncLogger.MainPrintUiLaunched(setOf(4, 5, 6), 1337)).isTrue()

        handlerInOrder
            .verify(mHandler, times(2))
            .postAtTime(runnableCaptor.capture(), timeCaptor.capture())
        handlerInOrder.verifyNoMoreInteractions()

        // Validate delay args
        val firstTime = timeCaptor.firstValue
        val secondTime = timeCaptor.secondValue
        assertThat(secondTime - firstTime)
            .isAtLeast(StatsAsyncLogger.EVENT_REPORTED_MIN_INTERVAL.inWholeMilliseconds)
        assertThat(secondTime - firstTime)
            .isAtMost(2 * StatsAsyncLogger.EVENT_REPORTED_MIN_INTERVAL.inWholeMilliseconds)

        // Validate Runnable logic
        runnableCaptor.firstValue.run()
        runnableCaptor.secondValue.run()
        logWrapperInOrder.verify(mStatsLogWrapper).internalMainPrintUiLaunched(setOf(1, 2, 3), 42)
        logWrapperInOrder.verify(mStatsLogWrapper).internalMainPrintUiLaunched(setOf(4, 5, 6), 1337)
        logWrapperInOrder.verifyNoMoreInteractions()

        // Validate Semaphore logic
        semaphoreInOrder.verify(mSemaphore, times(2)).tryAcquire()
        semaphoreInOrder.verify(mSemaphore, times(2)).release()
    }

    @Test
    fun advancedPrintUiLaunchedSuccessfullyLoggedTest() {
        val logWrapperInOrder = inOrder(mStatsLogWrapper)
@@ -112,6 +154,7 @@ open class StatsAsyncLoggerTest {
        whenever(mSemaphore.tryAcquire()).thenReturn(false)
        // Arbitrary Arguments
        assertThat(StatsAsyncLogger.AdvancedOptionsUiLaunched(42)).isFalse()
        assertThat(StatsAsyncLogger.MainPrintUiLaunched(setOf(1, 2, 3), 42)).isFalse()
        verifyNoInteractions(mHandler)
    }

@@ -124,7 +167,8 @@ open class StatsAsyncLoggerTest {
        whenever(mHandler.postAtTime(any(), any())).thenReturn(false)
        // Arbitrary Arguments
        assertThat(StatsAsyncLogger.AdvancedOptionsUiLaunched(42)).isFalse()
        verify(mSemaphore, times(1)).release()
        assertThat(StatsAsyncLogger.MainPrintUiLaunched(setOf(1, 2, 3), 42)).isFalse()
        verify(mSemaphore, times(2)).release()
    }

    @Test
@@ -156,6 +200,7 @@ open class StatsAsyncLoggerTest {

        // Arbitrary Arguments
        assertThat(StatsAsyncLogger.AdvancedOptionsUiLaunched(42)).isFalse()
        assertThat(StatsAsyncLogger.MainPrintUiLaunched(setOf(1, 2, 3), 42)).isFalse()
        verifyNoInteractions(mHandler)
        verifyNoInteractions(mSemaphore)
        verifyNoInteractions(mStatsLogWrapper)