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

Commit f45e22b4 authored by Hakjun Choi's avatar Hakjun Choi
Browse files

Fix wrong time logging for satellite connection time

1. Introduce a data class to match start time log and end time log, if on
connectionEnd() is not invoked, session start time info will be dropped
2. use SystemClock.elapsedRealtime() instead of System.currentTimeMillis() as this is used for logging difference between start and end
3. in case connection is less than 2, return empty session gap list

Bug: 403572038
Bug: 404344425
Flag: EXEMPT Bug fix
Test: atest ControllerMetricsStatsTest CarrierRoamingSatelliteControllerStatsTest SatelliteControllerTest
Test: manually run E2E Starlink and VZW P2P test then verify DB is logged as inteded
Change-Id: I5239e5f61babe69f3a4a9edb5ddb53be33eb3d46
parent b17e9b53
Loading
Loading
Loading
Loading
+7 −7
Original line number Diff line number Diff line
@@ -1567,7 +1567,7 @@ public class SatelliteController extends Handler {
                    mSessionMetricsStats.setInitializationResult(error)
                            .setSatelliteTechnology(getSupportedNtnRadioTechnology())
                            .setInitializationProcessingTime(
                                    System.currentTimeMillis() - mSessionProcessingTimeStamp)
                                    getElapsedRealtime() - mSessionProcessingTimeStamp)
                            .setIsDemoMode(mIsDemoModeEnabled)
                            .setCarrierId(getSatelliteCarrierId())
                            .setIsEmergency(argument.isEmergency);
@@ -1583,7 +1583,7 @@ public class SatelliteController extends Handler {
                    }
                } else {
                    mSessionMetricsStats.setTerminationResult(error)
                            .setTerminationProcessingTime(System.currentTimeMillis()
                            .setTerminationProcessingTime(getElapsedRealtime()
                                    - mSessionProcessingTimeStamp)
                            .setSessionDurationSec(calculateSessionDurationTimeSec())
                            .reportSessionMetrics();
@@ -4664,9 +4664,9 @@ public class SatelliteController extends Handler {
        startWaitForSatelliteEnablingResponseTimer(argument);
        // Logs satellite session timestamps for session metrics
        if (argument.enableSatellite) {
            mSessionStartTimeStamp = System.currentTimeMillis();
            mSessionStartTimeStamp = getElapsedRealtime();
        }
        mSessionProcessingTimeStamp = System.currentTimeMillis();
        mSessionProcessingTimeStamp = getElapsedRealtime();
    }

    /** Get the request attributes that modem needs to enable/disable satellite */
@@ -6813,7 +6813,7 @@ public class SatelliteController extends Handler {
            mSessionMetricsStats.setInitializationResult(SATELLITE_RESULT_MODEM_TIMEOUT)
                    .setSatelliteTechnology(getSupportedNtnRadioTechnology())
                    .setInitializationProcessingTime(
                            System.currentTimeMillis() - mSessionProcessingTimeStamp)
                            getElapsedRealtime() - mSessionProcessingTimeStamp)
                    .setIsDemoMode(mIsDemoModeEnabled)
                    .setCarrierId(getSatelliteCarrierId())
                    .reportSessionMetrics();
@@ -6823,7 +6823,7 @@ public class SatelliteController extends Handler {
            mSessionMetricsStats.setTerminationResult(SATELLITE_RESULT_MODEM_TIMEOUT)
                    .setSatelliteTechnology(getSupportedNtnRadioTechnology())
                    .setTerminationProcessingTime(
                            System.currentTimeMillis() - mSessionProcessingTimeStamp)
                            getElapsedRealtime() - mSessionProcessingTimeStamp)
                    .setSessionDurationSec(calculateSessionDurationTimeSec())
                    .reportSessionMetrics();
        }
@@ -7183,7 +7183,7 @@ public class SatelliteController extends Handler {
    // Should be invoked only when session termination done or session termination failed.
    private int calculateSessionDurationTimeSec() {
        return (int) (
                (System.currentTimeMillis() - mSessionStartTimeStamp
                (getElapsedRealtime() - mSessionStartTimeStamp
                - mSessionMetricsStats.getSessionInitializationProcessingTimeMillis()
                - mSessionMetricsStats.getSessionTerminationProcessingTimeMillis()) / 1000);
    }
+5 −4
Original line number Diff line number Diff line
@@ -17,6 +17,7 @@
package com.android.internal.telephony.satellite.metrics;

import android.annotation.NonNull;
import android.os.SystemClock;
import android.telephony.SubscriptionManager;
import android.telephony.TelephonyManager;
import android.util.Log;
@@ -128,7 +129,7 @@ public class CarrierRoamingSatelliteControllerStats {
    public void onSessionStart(int subId) {
        List<Long> sessionStartTimeListForSubscription = mSessionStartTimeMap.getOrDefault(subId,
                new ArrayList<>());
        sessionStartTimeListForSubscription.add(getCurrentTime());
        sessionStartTimeListForSubscription.add(getElapsedRealtime());
        mSessionStartTimeMap.put(subId, sessionStartTimeListForSubscription);

        mSatelliteStats.onCarrierRoamingSatelliteControllerStatsMetrics(
@@ -142,7 +143,7 @@ public class CarrierRoamingSatelliteControllerStats {
    public void onSessionEnd(int subId) {
        List<Long> sessionEndTimeListForSubscription = mSessionEndTimeMap.getOrDefault(subId,
                new ArrayList<>());
        sessionEndTimeListForSubscription.add(getCurrentTime());
        sessionEndTimeListForSubscription.add(getElapsedRealtime());
        mSessionEndTimeMap.put(subId, sessionEndTimeListForSubscription);

        int numberOfSatelliteSessions = getNumberOfSatelliteSessions(subId);
@@ -209,8 +210,8 @@ public class CarrierRoamingSatelliteControllerStats {
    }

    @VisibleForTesting(visibility = VisibleForTesting.Visibility.PRIVATE)
    protected long getCurrentTime() {
        return System.currentTimeMillis();
    protected long getElapsedRealtime() {
        return SystemClock.elapsedRealtime();
    }

    @VisibleForTesting(visibility = VisibleForTesting.Visibility.PRIVATE)
+75 −35
Original line number Diff line number Diff line
@@ -21,6 +21,7 @@ import android.app.usage.NetworkStats;
import android.app.usage.NetworkStatsManager;
import android.content.Context;
import android.net.NetworkTemplate;
import android.os.SystemClock;
import android.telephony.CellInfo;
import android.telephony.CellSignalStrength;
import android.telephony.CellSignalStrengthLte;
@@ -43,6 +44,7 @@ import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collections;
import java.util.List;
import java.util.OptionalDouble;
import java.util.Set;

public class CarrierRoamingSatelliteSessionStats {
@@ -58,8 +60,8 @@ public class CarrierRoamingSatelliteSessionStats {
    private int mCountOfOutgoingMms;
    private long mIncomingMessageId;
    private int mSessionStartTimeSec;
    private List<Long> mConnectionStartTimeList;
    private List<Long> mConnectionEndTimeList;
    private SatelliteConnectionTimes mSatelliteConnectionTimes;
    private List<SatelliteConnectionTimes> mSatelliteConnectionTimesList;
    private List<Integer> mRsrpList;
    private List<Integer> mRssnrList;
    private int[] mSupportedSatelliteServices;
@@ -94,7 +96,7 @@ public class CarrierRoamingSatelliteSessionStats {
        mCarrierId = carrierId;
        mSupportedSatelliteServices = supportedServices;
        mServiceDataPolicy = serviceDataPolicy;
        mSessionStartTimeSec = getCurrentTimeInSec();
        mSessionStartTimeSec = getElapsedRealtimeInSec();
        mIsNtnRoamingInHomeCountry = false;
        onConnectionStart(mPhone);
        mDataUsageOnSessionStartBytes = getDataUsage();
@@ -103,7 +105,7 @@ public class CarrierRoamingSatelliteSessionStats {

    /** Log carrier roaming satellite connection start */
    public void onConnectionStart(Phone phone) {
        mConnectionStartTimeList.add(getCurrentTime());
        mSatelliteConnectionTimes = new SatelliteConnectionTimes(getElapsedRealtime());
        updateNtnRoamingInHomeCountry(phone);
    }

@@ -156,7 +158,13 @@ public class CarrierRoamingSatelliteSessionStats {

    /** Log carrier roaming satellite connection end */
    public void onConnectionEnd() {
        mConnectionEndTimeList.add(getCurrentTime());
        if (mSatelliteConnectionTimes != null) {
            mSatelliteConnectionTimes.setEndTime(getElapsedRealtime());
            mSatelliteConnectionTimesList.add(mSatelliteConnectionTimes);
            mSatelliteConnectionTimes = null;
        } else {
            loge("onConnectionEnd: mSatelliteConnectionTimes is null");
        }
    }

    /** Log rsrp and rssnr when occurred the service state change with NTN is connected. */
@@ -217,10 +225,8 @@ public class CarrierRoamingSatelliteSessionStats {

    private void reportMetrics() {
        int totalSatelliteModeTimeSec = mSessionStartTimeSec > 0
                ? getCurrentTimeInSec() - mSessionStartTimeSec : 0;
                ? getElapsedRealtimeInSec() - mSessionStartTimeSec : 0;
        int numberOfSatelliteConnections = getNumberOfSatelliteConnections();
        int avgDurationOfSatelliteConnectionSec = getAvgDurationOfSatelliteConnection(
                numberOfSatelliteConnections);

        List<Integer> connectionGapList = getSatelliteConnectionGapList(
                numberOfSatelliteConnections);
@@ -238,7 +244,8 @@ public class CarrierRoamingSatelliteSessionStats {
                        .setIsNtnRoamingInHomeCountry(mIsNtnRoamingInHomeCountry)
                        .setTotalSatelliteModeTimeSec(totalSatelliteModeTimeSec)
                        .setNumberOfSatelliteConnections(numberOfSatelliteConnections)
                        .setAvgDurationOfSatelliteConnectionSec(avgDurationOfSatelliteConnectionSec)
                        .setAvgDurationOfSatelliteConnectionSec(
                                getAvgDurationOfSatelliteConnection())
                        .setSatelliteConnectionGapMinSec(satelliteConnectionGapMinSec)
                        .setSatelliteConnectionGapAvgSec(getAvg(connectionGapList))
                        .setSatelliteConnectionGapMaxSec(satelliteConnectionGapMaxSec)
@@ -271,8 +278,8 @@ public class CarrierRoamingSatelliteSessionStats {
        mIncomingMessageId = 0;

        mSessionStartTimeSec = 0;
        mConnectionStartTimeList = new ArrayList<>();
        mConnectionEndTimeList = new ArrayList<>();
        mSatelliteConnectionTimes = null;
        mSatelliteConnectionTimesList = new ArrayList<>();
        mRsrpList = new ArrayList<>();
        mRssnrList = new ArrayList<>();
        logd("initializeParams");
@@ -291,39 +298,39 @@ public class CarrierRoamingSatelliteSessionStats {
    }

    private int getNumberOfSatelliteConnections() {
        return Math.min(mConnectionStartTimeList.size(), mConnectionEndTimeList.size());
        return mSatelliteConnectionTimesList.size();
    }

    private int getAvgDurationOfSatelliteConnection(int numberOfSatelliteConnections) {
        if (numberOfSatelliteConnections == 0) {
    private int getAvgDurationOfSatelliteConnection() {
        if (mSatelliteConnectionTimesList.isEmpty()) {
            return 0;
        }

        long totalConnectionsDuration = 0;
        for (int i = 0; i < numberOfSatelliteConnections; i++) {
            long endTime = mConnectionEndTimeList.get(i);
            long startTime = mConnectionStartTimeList.get(i);
            if (endTime >= startTime && startTime > 0) {
                totalConnectionsDuration += endTime - startTime;
            }
        }
        OptionalDouble averageDuration = mSatelliteConnectionTimesList.stream()
                .filter(SatelliteConnectionTimes::isValid)
                .mapToLong(SatelliteConnectionTimes::getDuration)
                .average();

        long avgConnectionDuration = totalConnectionsDuration / numberOfSatelliteConnections;
        return (int) (avgConnectionDuration / 1000L);
        return (int) (averageDuration.isPresent() ? averageDuration.getAsDouble() / 1000 : 0);
    }

    private List<Integer> getSatelliteConnectionGapList(int numberOfSatelliteConnections) {
        if (numberOfSatelliteConnections == 0) {
        if (mSatelliteConnectionTimesList.size() < 2) {
            return new ArrayList<>();
        }

        List<Integer> connectionGapList = new ArrayList<>();
        for (int i = 1; i < numberOfSatelliteConnections; i++) {
            long prevConnectionEndTime = mConnectionEndTimeList.get(i - 1);
            long currentConnectionStartTime = mConnectionStartTimeList.get(i);
            if (currentConnectionStartTime > prevConnectionEndTime && prevConnectionEndTime > 0) {
                connectionGapList.add((int) (
                        (currentConnectionStartTime - prevConnectionEndTime) / 1000));
        for (int i = 1; i < mSatelliteConnectionTimesList.size(); i++) {
            SatelliteConnectionTimes prevConnection =
                    mSatelliteConnectionTimesList.get(i - 1);
            SatelliteConnectionTimes currentConnection =
                    mSatelliteConnectionTimesList.get(i);

            if (prevConnection.getEndTime() > 0
                    && currentConnection.getStartTime() > prevConnection.getEndTime()) {
                int gap = (int) ((currentConnection.getStartTime() - prevConnection.getEndTime())
                        / 1000);
                connectionGapList.add(gap);
            }
        }
        return connectionGapList;
@@ -356,12 +363,12 @@ public class CarrierRoamingSatelliteSessionStats {
                : list.get(size / 2);
    }

    private int getCurrentTimeInSec() {
        return (int) (System.currentTimeMillis() / 1000);
    private int getElapsedRealtimeInSec() {
        return (int) (getElapsedRealtime() / 1000);
    }

    private long getCurrentTime() {
        return System.currentTimeMillis();
    private long getElapsedRealtime() {
        return SystemClock.elapsedRealtime();
    }

    private boolean isNtnConnected() {
@@ -408,6 +415,39 @@ public class CarrierRoamingSatelliteSessionStats {
                + mIsNtnRoamingInHomeCountry);
    }

    private static class SatelliteConnectionTimes {
        private final long mStartTime;
        private long mEndTime;

        SatelliteConnectionTimes(long startTime) {
            this.mStartTime = startTime;
            this.mEndTime = 0;
        }

        public void setEndTime(long endTime) {
            this.mEndTime = endTime;
        }

        public long getStartTime() {
            return mStartTime;
        }

        public long getEndTime() {
            return mEndTime;
        }

        public long getDuration() {
            if (isValid()) {
                return mEndTime - mStartTime;
            }
            return 0;
        }

        public boolean isValid() {
            return mEndTime > mStartTime && mStartTime > 0;
        }
    }

    private void logd(@NonNull String log) {
        Log.d(TAG, log);
    }
+12 −12
Original line number Diff line number Diff line
@@ -22,6 +22,7 @@ import android.content.Context;
import android.content.Intent;
import android.content.IntentFilter;
import android.os.BatteryManager;
import android.os.SystemClock;
import android.telephony.satellite.SatelliteManager;
import android.util.Log;

@@ -45,7 +46,7 @@ public class ControllerMetricsStats {
    private int mBatteryLevelWhenServiceOn;
    private boolean mIsSatelliteModemOn;
    private Boolean mIsBatteryCharged = null;
    private int mBatteryChargedStartTimeSec;
    private long mBatteryChargedStartTime;
    private int mTotalBatteryChargeTimeSec;

    /**
@@ -291,7 +292,7 @@ public class ControllerMetricsStats {
    /** Return the total service up time for satellite service */
    @VisibleForTesting
    public int captureTotalServiceUpTimeSec() {
        long totalTimeMillis = getCurrentTime() - mSatelliteOnTimeMillis;
        long totalTimeMillis = getElapsedRealtime() - mSatelliteOnTimeMillis;
        mSatelliteOnTimeMillis = 0;
        return (int) (totalTimeMillis / 1000);
    }
@@ -312,7 +313,7 @@ public class ControllerMetricsStats {
            startCaptureBatteryLevel();

            // log the timestamp of the satellite modem power on
            mSatelliteOnTimeMillis = getCurrentTime();
            mSatelliteOnTimeMillis = getElapsedRealtime();

            // register broadcast receiver for monitoring battery status change
            IntentFilter filter = new IntentFilter(Intent.ACTION_BATTERY_CHANGED);
@@ -355,13 +356,12 @@ public class ControllerMetricsStats {

            // When charged, log the start time of battery charging
            if (isCharged) {
                mBatteryChargedStartTimeSec = (int) (getCurrentTime() / 1000);
                mBatteryChargedStartTime = getElapsedRealtime();
                // When discharged, log the accumulated total battery charging time.
            } else {
                mTotalBatteryChargeTimeSec +=
                        (int) (getCurrentTime() / 1000)
                                - mBatteryChargedStartTimeSec;
                mBatteryChargedStartTimeSec = 0;
                        (int) ((getElapsedRealtime() - mBatteryChargedStartTime) / 1000);
                mBatteryChargedStartTime = 0;
            }
        }
    }
@@ -485,9 +485,9 @@ public class ControllerMetricsStats {

        @Override
        public void onReceive(Context context, Intent intent) {
            long currentTime = getCurrentTime();
            if (currentTime - mLastUpdatedTime > UPDATE_INTERVAL) {
                mLastUpdatedTime = currentTime;
            long elapsedTimeSinceBoot = getElapsedRealtime();
            if (elapsedTimeSinceBoot - mLastUpdatedTime > UPDATE_INTERVAL) {
                mLastUpdatedTime = elapsedTimeSinceBoot;
                int status = intent.getIntExtra(BatteryManager.EXTRA_STATUS, -1);
                boolean isCharged = (status == BatteryManager.BATTERY_STATUS_CHARGING);
                logd("Battery is charged(" + isCharged + ")");
@@ -502,8 +502,8 @@ public class ControllerMetricsStats {
    }

    @VisibleForTesting
    public long getCurrentTime() {
        return System.currentTimeMillis();
    public long getElapsedRealtime() {
        return SystemClock.elapsedRealtime();
    }

    private static void logd(@NonNull String log) {
+1 −1
Original line number Diff line number Diff line
@@ -580,7 +580,7 @@ public class CarrierRoamingSatelliteControllerStatsTest extends TelephonyTest {
        }

        @Override
        public long getCurrentTime() {
        public long getElapsedRealtime() {
            return mCurrentTime;
        }

Loading