From 504fe27b8602e6ea85fc18f36f34a60f7ab2f8ef Mon Sep 17 00:00:00 2001 From: Motomu Utsumi Date: Fri, 11 Jul 2025 14:11:57 +0900 Subject: [PATCH] Add metrics for QUIC connection close Test: QuicConnectionCloserTest Flag: EXEMPT mainline Bug: 311792075 Change-Id: I2bd9108c1f8af89824bf48767fcca9a1e1d57831 --- .../connectivity/QuicConnectionCloser.java | 90 +++++++++++++++-- .../connectivity/QuicConnectionCloserTest.kt | 99 +++++++++++++++++++ 2 files changed, 182 insertions(+), 7 deletions(-) diff --git a/service/src/com/android/server/connectivity/QuicConnectionCloser.java b/service/src/com/android/server/connectivity/QuicConnectionCloser.java index c4fe5b8621..981bc6d196 100644 --- a/service/src/com/android/server/connectivity/QuicConnectionCloser.java +++ b/service/src/com/android/server/connectivity/QuicConnectionCloser.java @@ -20,6 +20,10 @@ import static android.system.OsConstants.ENOENT; import static android.system.OsConstants.SOL_SOCKET; import static android.system.OsConstants.SO_SNDTIMEO; +import static com.android.server.ConnectivityStatsLog.CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED; +import static com.android.server.ConnectivityStatsLog.CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_LOST_ACCESS; +import static com.android.server.ConnectivityStatsLog.CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_SOCKET_DESTROY; + import android.annotation.NonNull; import android.annotation.TargetApi; import android.net.Network; @@ -27,6 +31,8 @@ import android.net.NetworkUtils; import android.os.Build; import android.os.Handler; import android.os.ParcelFileDescriptor; +import android.os.Process; +import android.os.SystemClock; import android.system.ErrnoException; import android.system.Os; import android.system.StructTimeval; @@ -41,6 +47,7 @@ import com.android.net.module.util.HandlerUtils; import com.android.net.module.util.SharedLog; import com.android.net.module.util.SkDestroyListener; import com.android.net.module.util.netlink.InetDiagMessage; +import com.android.server.ConnectivityStatsLog; import libcore.io.IoUtils; @@ -69,6 +76,11 @@ public class QuicConnectionCloser { // concurrently. private static final int MAX_REGISTERED_QUIC_CONNECTION_CLOSE_INFO = 1000; + // Minimum interval to report metrics. + // This is to avoid generating an excessive amount of stats. An arbitrary number + // between a few seconds and a few minutes would be reasonable. + private static final int METRICS_INTERVAL_MS = 60_000; // 1 min + private final Handler mHandler; // Reference to ConnectivityService#mNetworkForNetId, must be synchronized on itself. @@ -81,6 +93,14 @@ public class QuicConnectionCloser { @NonNull private final Dependencies mDeps; + // Counts QUIC connection close due to lost network access + private int mLostAccessCloseCount; + // Counts QUIC connection close due to socket destroy + private int mSocketDestroyCloseCount; + // Last timestamp when connection close metrics were reported + // -1 if never reported + private long mLastMetricsReportTimeMs; + /** * Class to store the necessary information for closing a QUIC connection. */ @@ -182,6 +202,24 @@ public class QuicConnectionCloser { public InetSocketAddress getpeername(final FileDescriptor fd) throws ErrnoException { return (InetSocketAddress) Os.getpeername(fd); } + + /** + * Call {@link SystemClock#elapsedRealtime} + */ + public long getElapsedRealtime() { + return SystemClock.elapsedRealtime(); + } + + /** + * Write CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED metrics + */ + public void writeStats(final int eventType, final int eventCount) { + ConnectivityStatsLog.write_non_chained(CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED, + Process.SYSTEM_UID, + null, + eventType, + eventCount); + } } public QuicConnectionCloser(final SparseArray networkForNetId, @@ -196,6 +234,10 @@ public class QuicConnectionCloser { mHandler = handler; mDeps = deps; + mLostAccessCloseCount = 0; + mSocketDestroyCloseCount = 0; + mLastMetricsReportTimeMs = -1; + // handleUdpSocketDestroy must be posted to the thread to avoid racing with // handleUnregisterQuicConnectionCloseInfo, even though they both run on the same thread. // Specifically, the following can happen: @@ -224,6 +266,29 @@ public class QuicConnectionCloser { HandlerUtils.ensureRunningOnHandlerThread(mHandler); } + private void maybeReportMetricsAndReset() { + if (mLostAccessCloseCount == 0 && mSocketDestroyCloseCount == 0) { + return; + } + final long now = mDeps.getElapsedRealtime(); + // Report metrics if the interval has passed, or if this is the first time. + if (mLastMetricsReportTimeMs == -1 || + now - mLastMetricsReportTimeMs >= METRICS_INTERVAL_MS) { + if (mLostAccessCloseCount != 0) { + mDeps.writeStats( + CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_LOST_ACCESS, + mLostAccessCloseCount); + mLostAccessCloseCount = 0; + } + if (mSocketDestroyCloseCount != 0) { + mDeps.writeStats(CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_SOCKET_DESTROY, + mSocketDestroyCloseCount); + mSocketDestroyCloseCount = 0; + } + mLastMetricsReportTimeMs = now; + } + } + /** * Close registered QUIC connection by uids * @@ -236,10 +301,13 @@ public class QuicConnectionCloser { mRegisteredQuicConnectionCloseInfos.entrySet().iterator(); it.hasNext();) { final QuicConnectionCloseInfo info = it.next().getValue(); if (uids.contains(info.uid)) { - closeQuicConnection(info, true /* destroySocket */); + if (closeQuicConnection(info, true /* destroySocket */)) { + mLostAccessCloseCount++; + } it.remove(); } } + maybeReportMetricsAndReset(); } private NetworkAgentInfo getNetworkAgentInfoForNetId(int netId) { @@ -248,13 +316,16 @@ public class QuicConnectionCloser { } } - private void closeQuicConnection(final QuicConnectionCloseInfo info, + /** + * Returns true if the QUIC connection is successfully closed, otherwise false + */ + private boolean closeQuicConnection(final QuicConnectionCloseInfo info, final boolean destroySocket) { ensureRunningOnHandlerThread(); Log.d(TAG, "Close QUIC socket for " + info + ", destroySocket=" + destroySocket); final NetworkAgentInfo nai = getNetworkAgentInfoForNetId(info.netId); - if (nai == null) return; // The network has gone away already + if (nai == null) return false; // The network has gone away already final boolean isLoopbackConnection = info.dst.getAddress().isLoopbackAddress(); final boolean lpContainsSourceAddress = @@ -262,7 +333,7 @@ public class QuicConnectionCloser { if (!isLoopbackConnection && !lpContainsSourceAddress) { // The device should not send a packet with an unused source address. // Loopback connections are closed exceptionally to simplify device local testing. - return; + return false; } if (destroySocket) { @@ -272,10 +343,10 @@ public class QuicConnectionCloser { if (e instanceof ErrnoException && ((ErrnoException) e).errno == ENOENT) { // This can happen if the socket is already closed, but unregister message is // not processed yet. - return; + return false; } Log.e(TAG, "Failed to destroy QUIC socket for " + info + ": " + e); - return; + return false; } } @@ -284,7 +355,9 @@ public class QuicConnectionCloser { } catch (ErrnoException | IOException e) { Log.e(TAG, "Failed to send registered QUIC connection close payload for " + info + ": " + e); + return false; } + return true; } /** @@ -305,7 +378,10 @@ public class QuicConnectionCloser { // App registered a QUIC connection close payload and this socket, but the socket was // closed before the socket was unregistered. // This can happen if the app crashes or is killed. - closeQuicConnection(info, false /* destroySocket */); + if (closeQuicConnection(info, false /* destroySocket */)) { + mSocketDestroyCloseCount++; + } + maybeReportMetricsAndReset(); } /** diff --git a/tests/unit/java/com/android/server/connectivity/QuicConnectionCloserTest.kt b/tests/unit/java/com/android/server/connectivity/QuicConnectionCloserTest.kt index eb82ab4b83..569dbe5d1e 100644 --- a/tests/unit/java/com/android/server/connectivity/QuicConnectionCloserTest.kt +++ b/tests/unit/java/com/android/server/connectivity/QuicConnectionCloserTest.kt @@ -27,6 +27,8 @@ import android.os.Looper import android.os.ParcelFileDescriptor import android.system.OsConstants.SOL_SOCKET import android.util.SparseArray +import com.android.net.module.util.FrameworkConnectivityStatsLog.CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_LOST_ACCESS +import com.android.net.module.util.FrameworkConnectivityStatsLog.CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_SOCKET_DESTROY import com.android.net.module.util.SkDestroyListener import com.android.net.module.util.netlink.InetDiagMessage import com.android.net.module.util.netlink.StructInetDiagSockId @@ -41,6 +43,7 @@ import org.junit.runner.RunWith import org.mockito.ArgumentCaptor import org.mockito.InOrder import org.mockito.Mockito.any +import org.mockito.Mockito.anyInt import org.mockito.Mockito.anyLong import org.mockito.Mockito.doReturn import org.mockito.Mockito.eq @@ -191,6 +194,52 @@ class QuicConnectionCloserTest { inOrder.assertNoSendQuicConnectionClosePayload() } + private fun closeConnectionByUids() { + mQuicConnectionCloser.registerQuicConnectionClosePayload(TEST_UID, pfd, TEST_PAYLOAD) + visibleOnHandlerThread(handler) { + mQuicConnectionCloser.closeQuicConnectionByUids(setOf(TEST_UID)) + } + } + + @Test + fun testCloseQuicConnectionByUids_reportMetrics() { + val inOrder = inOrder(mDeps) + doReturn(0L).`when`(mDeps).getElapsedRealtime() + + closeConnectionByUids() + inOrder.expectDestroyUdpSocket() + inOrder.expectSendQuicConnectionClosePayload() + inOrder.verify( + mDeps, + timeout(TIMEOUT_MS) + ).writeStats( + CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_LOST_ACCESS, + 1 + ) + + repeat(4) { + closeConnectionByUids() + inOrder.expectDestroyUdpSocket() + inOrder.expectSendQuicConnectionClosePayload() + } + + // No metrics are reported because the clock has not advanced. + inOrder.verify(mDeps, never()).writeStats(anyInt(), anyInt()) + + // Advance the clock. + doReturn(60_000L).`when`(mDeps).getElapsedRealtime() + closeConnectionByUids() + inOrder.expectDestroyUdpSocket() + inOrder.expectSendQuicConnectionClosePayload() + inOrder.verify( + mDeps, + timeout(TIMEOUT_MS) + ).writeStats( + CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_LOST_ACCESS, + 5 + ) + } + private fun getSkDestroyListenerCallback(): Consumer { val captor = ArgumentCaptor.forClass(Consumer::class.java) as ArgumentCaptor> @@ -237,4 +286,54 @@ class QuicConnectionCloserTest { inOrder.assertNoDestroyUdpSocket(SHORT_TIMEOUT_MS) inOrder.assertNoSendQuicConnectionClosePayload() } + + private fun destroySocketAndCloseConnection(destroyListenerCallback: Consumer) { + mQuicConnectionCloser.registerQuicConnectionClosePayload(TEST_UID, pfd, TEST_PAYLOAD) + + val inetDiagMessage = InetDiagMessage(StructNlMsgHdr()) + inetDiagMessage.inetDiagMsg.id = StructInetDiagSockId( + TEST_SRC_SOCKET_ADDRESS, + TEST_DST_SOCKET_ADDRESS, + 0 /* ifindex */, + TEST_SOCKET_COOKIE + ) + destroyListenerCallback.accept(inetDiagMessage) + } + + @Test + fun testSocketDestroy_reportMetrics() { + val destroyListenerCallback = getSkDestroyListenerCallback() + val inOrder = inOrder(mDeps) + doReturn(0L).`when`(mDeps).getElapsedRealtime() + + destroySocketAndCloseConnection(destroyListenerCallback) + inOrder.expectSendQuicConnectionClosePayload(TIMEOUT_MS) + inOrder.verify( + mDeps, + timeout(TIMEOUT_MS) + ).writeStats( + CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_SOCKET_DESTROY, + 1 + ) + + repeat(4) { + destroySocketAndCloseConnection(destroyListenerCallback) + inOrder.expectSendQuicConnectionClosePayload(TIMEOUT_MS) + } + + // No metrics are reported because the clock has not advanced. + inOrder.verify(mDeps, never()).writeStats(anyInt(), anyInt()) + + // Advance the clock. + doReturn(60_000L).`when`(mDeps).getElapsedRealtime() + destroySocketAndCloseConnection(destroyListenerCallback) + inOrder.expectSendQuicConnectionClosePayload(TIMEOUT_MS) + inOrder.verify( + mDeps, + timeout(TIMEOUT_MS) + ).writeStats( + CORE_NETWORKING_CRITICAL_COUNTS_EVENT_OCCURRED__EVENT_TYPE__CRITICAL_COUNTS_EVENT_TYPE_QUIC_CONNECTION_CLOSE_SOCKET_DESTROY, + 5 + ) + } }