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

Commit c5a6044a authored by Neil Fuller's avatar Neil Fuller
Browse files

Improve debug / bug report logging for time zones 

Pushing the local debug logging responsibility down to SystemTimeZone.
Now that all time zone changes go through system time zone, it makes
sense that the logging is moved there. This means that changes for any
reason, now including initial device initialization, and API / shell
command calls can be logged, which previously wasn't the case.

Bug: 236612872
Test: build / boot / factory reset / manual inspection of dumpsys
Test: treehugger
Change-Id: I1e7cf86ae89a73c31e036f68f32f99fae4d6392a
parent a6f585e1

apex/jobscheduler/service/java/com/android/server/alarm/AlarmManagerService.java

+6 −5
Original line number Diff line number Diff line
@@ -2153,7 +2153,7 @@ public class AlarmManagerService extends SystemService { 
        }

    }



    void setTimeZoneImpl(String tzId, @TimeZoneConfidence int confidence) {

    void setTimeZoneImpl(String tzId, @TimeZoneConfidence int confidence, String logInfo) {

        if (TextUtils.isEmpty(tzId)) {

            return;

        }
@@ -2166,7 +2166,7 @@ public class AlarmManagerService extends SystemService { 
            // TimeZone.getTimeZone() can return a time zone with a different ID (e.g. it can return

            // "GMT" if the ID is unrecognized). The parameter ID is used here rather than

            // newZone.getId(). It will be rejected if it is invalid.

            timeZoneWasChanged = SystemTimeZone.setTimeZoneId(tzId, confidence);

            timeZoneWasChanged = SystemTimeZone.setTimeZoneId(tzId, confidence, logInfo);



            if (KERNEL_TIME_ZONE_SYNC_ENABLED) {

                // Update the kernel timezone information
@@ -2706,8 +2706,9 @@ public class AlarmManagerService extends SystemService { 
        }



        @Override

        public void setTimeZone(String tzId, @TimeZoneConfidence int confidence) {

            setTimeZoneImpl(tzId, confidence);

        public void setTimeZone(String tzId, @TimeZoneConfidence int confidence,

                String logInfo) {

            setTimeZoneImpl(tzId, confidence, logInfo);

        }



        @Override
@@ -3010,7 +3011,7 @@ public class AlarmManagerService extends SystemService { 
                // of confidence, but since the time zone ID should come either from apps working on

                // behalf of the user or a developer, confidence is assumed "high".

                final int timeZoneConfidence = TIME_ZONE_CONFIDENCE_HIGH;

                setTimeZoneImpl(tz, timeZoneConfidence);

                setTimeZoneImpl(tz, timeZoneConfidence, "AlarmManager.setTimeZone() called");

            } finally {

                Binder.restoreCallingIdentity(oldId);

            }

services/core/java/com/android/server/AlarmManagerInternal.java

+2 −1
Original line number Diff line number Diff line
@@ -59,8 +59,9 @@ public interface AlarmManagerInternal { 
     * @param tzId the time zone ID

     * @param confidence the confidence that {@code tzId} is correct, see {@link TimeZoneConfidence}

     *     for details

     * @param logInfo the reason the time zone is being changed, for bug report logging

     */

    void setTimeZone(String tzId, @TimeZoneConfidence int confidence);

    void setTimeZone(String tzId, @TimeZoneConfidence int confidence, String logInfo);



    /**

     * Sets the device's current time and time confidence.

services/core/java/com/android/server/SystemTimeZone.java

+57 −13
Original line number Diff line number Diff line
@@ -19,12 +19,15 @@ import static java.lang.annotation.ElementType.TYPE_USE; 
import static java.lang.annotation.RetentionPolicy.SOURCE;



import android.annotation.IntDef;

import android.annotation.NonNull;

import android.os.SystemProperties;

import android.text.TextUtils;

import android.util.LocalLog;

import android.util.Slog;



import com.android.i18n.timezone.ZoneInfoDb;



import java.io.PrintWriter;

import java.lang.annotation.Retention;

import java.lang.annotation.Target;
@@ -70,6 +73,14 @@ public final class SystemTimeZone { 
     */

    public static final @TimeZoneConfidence int TIME_ZONE_CONFIDENCE_HIGH = 100;



    /**

     * An in-memory log that records the debug info related to the device's time zone setting.

     * This is logged in bug reports to assist with debugging time zone detection issues.

     */

    @NonNull

    private static final LocalLog sTimeZoneDebugLog =

            new LocalLog(30, false /* useLocalTimestamps */);



    private SystemTimeZone() {}



    /**
@@ -78,27 +89,44 @@ public final class SystemTimeZone { 
    public static void initializeTimeZoneSettingsIfRequired() {

        String timezoneProperty = SystemProperties.get(TIME_ZONE_SYSTEM_PROPERTY);

        if (!isValidTimeZoneId(timezoneProperty)) {

            Slog.w(TAG, TIME_ZONE_SYSTEM_PROPERTY + " is not valid (" + timezoneProperty

                    + "); setting to " + DEFAULT_TIME_ZONE_ID);

            setTimeZoneId(DEFAULT_TIME_ZONE_ID, TIME_ZONE_CONFIDENCE_LOW);

            String logInfo = "initializeTimeZoneSettingsIfRequired():" + TIME_ZONE_SYSTEM_PROPERTY

                    + " is not valid (" + timezoneProperty + "); setting to "

                    + DEFAULT_TIME_ZONE_ID;

            Slog.w(TAG, logInfo);

            setTimeZoneId(DEFAULT_TIME_ZONE_ID, TIME_ZONE_CONFIDENCE_LOW, logInfo);

        }

    }



    /**

     * Adds an entry to the system time zone debug log that is included in bug reports. This method

     * is intended to be used to record event that may lead to a time zone change, e.g. config or

     * mode changes.

     */

    public static void addDebugLogEntry(@NonNull String logMsg) {

        sTimeZoneDebugLog.log(logMsg);

    }



    /**

     * Updates the device's time zone system property and associated metadata. Returns {@code true}

     * if the device's time zone changed, {@code false} if the ID is invalid or the device is

     * already set to the supplied ID.

     * Updates the device's time zone system property, associated metadata and adds an entry to the

     * debug log. Returns {@code true} if the device's time zone changed, {@code false} if the ID is

     * invalid or the device is already set to the supplied ID.

     *

     * <p>This method ensures the confidence metadata is set to the supplied value if the supplied

     * time zone ID is considered valid.

     *

     * <p>This method is intended only for use by the AlarmManager. When changing the device's time

     * zone other system service components must use {@link

     * com.android.server.AlarmManagerInternal#setTimeZone(String, int)} to ensure that important

     * AlarmManagerInternal#setTimeZone(String, int, String)} to ensure that important

     * system-wide side effects occur.

     */

    public static boolean setTimeZoneId(String timeZoneId, @TimeZoneConfidence int confidence) {

    public static boolean setTimeZoneId(

            @NonNull String timeZoneId, @TimeZoneConfidence int confidence,

            @NonNull String logInfo) {

        if (TextUtils.isEmpty(timeZoneId) || !isValidTimeZoneId(timeZoneId)) {

            addDebugLogEntry("setTimeZoneId: Invalid time zone ID."

                    + " timeZoneId=" + timeZoneId

                    + ", confidence=" + confidence

                    + ", logInfo=" + logInfo);

            return false;

        }
@@ -112,7 +140,14 @@ public final class SystemTimeZone { 
                }

                timeZoneChanged = true;

            }

            setTimeZoneConfidence(confidence);

            boolean timeZoneConfidenceChanged = setTimeZoneConfidence(confidence);

            if (timeZoneChanged || timeZoneConfidenceChanged) {

                String logMsg = "Time zone or confidence set: "

                        + " (new) timeZoneId=" + timeZoneId

                        + ", (new) confidence=" + confidence

                        + ", logInfo=" + logInfo;

                addDebugLogEntry(logMsg);

            }

        }



        return timeZoneChanged;
@@ -121,16 +156,18 @@ public final class SystemTimeZone { 
    /**

     * Sets the time zone confidence value if required. See {@link TimeZoneConfidence} for details.

     */

    private static void setTimeZoneConfidence(@TimeZoneConfidence int confidence) {

    private static boolean setTimeZoneConfidence(@TimeZoneConfidence int newConfidence) {

        int currentConfidence = getTimeZoneConfidence();

        if (currentConfidence != confidence) {

        if (currentConfidence != newConfidence) {

            SystemProperties.set(

                    TIME_ZONE_CONFIDENCE_SYSTEM_PROPERTY, Integer.toString(confidence));

                    TIME_ZONE_CONFIDENCE_SYSTEM_PROPERTY, Integer.toString(newConfidence));

            if (DEBUG) {

                Slog.v(TAG, "Time zone confidence changed: old=" + currentConfidence

                        + ", new=" + confidence);

                        + ", newConfidence=" + newConfidence);

            }

            return true;

        }

        return false;

    }



    /** Returns the time zone confidence value. See {@link TimeZoneConfidence} for details. */
@@ -148,6 +185,13 @@ public final class SystemTimeZone { 
        return SystemProperties.get(TIME_ZONE_SYSTEM_PROPERTY);

    }



    /**

     * Dumps information about recent time zone decisions / changes to the supplied writer.

     */

    public static void dump(PrintWriter writer) {

        sTimeZoneDebugLog.dump(writer);

    }



    private static boolean isValidTimeZoneConfidence(@TimeZoneConfidence int confidence) {

        return confidence >= TIME_ZONE_CONFIDENCE_LOW && confidence <= TIME_ZONE_CONFIDENCE_HIGH;

    }

services/core/java/com/android/server/timezonedetector/EnvironmentImpl.java

+15 −2
Original line number Diff line number Diff line
@@ -28,6 +28,7 @@ import com.android.server.LocalServices; 
import com.android.server.SystemTimeZone;

import com.android.server.SystemTimeZone.TimeZoneConfidence;



import java.io.PrintWriter;

import java.util.Objects;



/**
@@ -57,6 +58,7 @@ final class EnvironmentImpl implements TimeZoneDetectorStrategyImpl.Environment 
    }



    @Override

    @NonNull

    public ConfigurationInternal getCurrentUserConfigurationInternal() {

        return mServiceConfigAccessor.getCurrentUserConfigurationInternal();

    }
@@ -74,14 +76,25 @@ final class EnvironmentImpl implements TimeZoneDetectorStrategyImpl.Environment 


    @Override

    public void setDeviceTimeZoneAndConfidence(

            @NonNull String zoneId, @TimeZoneConfidence int confidence) {

            @NonNull String zoneId, @TimeZoneConfidence int confidence,

            @NonNull String logInfo) {

        AlarmManagerInternal alarmManagerInternal =

                LocalServices.getService(AlarmManagerInternal.class);

        alarmManagerInternal.setTimeZone(zoneId, confidence);

        alarmManagerInternal.setTimeZone(zoneId, confidence, logInfo);

    }



    @Override

    public @ElapsedRealtimeLong long elapsedRealtimeMillis() {

        return SystemClock.elapsedRealtime();

    }



    @Override

    public void addDebugLogEntry(@NonNull String logMsg) {

        SystemTimeZone.addDebugLogEntry(logMsg);

    }



    @Override

    public void dumpDebugLog(@NonNull PrintWriter printWriter) {

        SystemTimeZone.dump(printWriter);

    }

}

services/core/java/com/android/server/timezonedetector/TimeZoneDetectorStrategyImpl.java

+38 −35
Original line number Diff line number Diff line
@@ -36,13 +36,13 @@ import android.content.Context; 
import android.os.Handler;

import android.os.TimestampedValue;

import android.util.IndentingPrintWriter;

import android.util.LocalLog;

import android.util.Slog;



import com.android.internal.annotations.GuardedBy;

import com.android.internal.annotations.VisibleForTesting;

import com.android.server.SystemTimeZone.TimeZoneConfidence;



import java.io.PrintWriter;

import java.time.Duration;

import java.util.List;

import java.util.Objects;
@@ -86,10 +86,11 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
        @TimeZoneConfidence int getDeviceTimeZoneConfidence();



        /**

         * Sets the device's time zone and associated confidence.

         * Sets the device's time zone, associated confidence, and records a debug log entry.

         */

        void setDeviceTimeZoneAndConfidence(

                @NonNull String zoneId, @TimeZoneConfidence int confidence);

                @NonNull String zoneId, @TimeZoneConfidence int confidence,

                @NonNull String logInfo);



        /**

         * Returns the time according to the elapsed realtime clock, the same as {@link
@@ -97,6 +98,16 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
         */

        @ElapsedRealtimeLong

        long elapsedRealtimeMillis();



        /**

         * Adds a standalone entry to the time zone debug log.

         */

        void addDebugLogEntry(@NonNull String logMsg);



        /**

         * Dumps the time zone debug log to the supplied {@link PrintWriter}.

         */

        void dumpDebugLog(PrintWriter printWriter);

    }



    private static final String LOG_TAG = TimeZoneDetectorService.TAG;
@@ -168,13 +179,6 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
    @NonNull

    private final Environment mEnvironment;



    /**

     * A log that records the decisions / decision metadata that affected the device's time zone.

     * This is logged in bug reports to assist with debugging issues with detection.

     */

    @NonNull

    private final LocalLog mTimeZoneChangesLog = new LocalLog(30, false /* useLocalTimestamps */);



    /**

     * A mapping from slotIndex to a telephony time zone suggestion. We typically expect one or two

     * mappings: devices will have a small number of telephony devices and slotIndexes are assumed
@@ -299,7 +303,7 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
        TimeZoneCapabilities capabilities = capabilitiesAndConfig.getCapabilities();

        if (capabilities.getSuggestManualTimeZoneCapability() != CAPABILITY_POSSESSED) {

            Slog.i(LOG_TAG, "User does not have the capability needed to set the time zone manually"

                    + ", capabilities=" + capabilities

                    + ": capabilities=" + capabilities

                    + ", timeZoneId=" + timeZoneId

                    + ", cause=" + cause);

            return false;
@@ -349,11 +353,11 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
            mTelephonyTimeZoneFallbackEnabled = new TimestampedValue<>(

                    mEnvironment.elapsedRealtimeMillis(), fallbackEnabled);



            String logMsg = "enableTelephonyTimeZoneFallbackMode"

                    + ": currentUserConfig=" + currentUserConfig

            String logMsg = "enableTelephonyTimeZoneFallbackMode: "

                    + " currentUserConfig=" + currentUserConfig

                    + ", mTelephonyTimeZoneFallbackEnabled="

                    + mTelephonyTimeZoneFallbackEnabled;

            logTimeZoneDetectorChange(logMsg);

            logTimeZoneDebugInfo(logMsg);



            // mTelephonyTimeZoneFallbackEnabled and mLatestGeoLocationSuggestion interact.

            // If there is currently a certain geolocation suggestion, then the telephony fallback
@@ -558,19 +562,18 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
                mTelephonyTimeZoneFallbackEnabled = new TimestampedValue<>(

                        mEnvironment.elapsedRealtimeMillis(), fallbackEnabled);



                String logMsg = "disableTelephonyFallbackIfNeeded"

                        + ": mTelephonyTimeZoneFallbackEnabled="

                        + mTelephonyTimeZoneFallbackEnabled;

                logTimeZoneDetectorChange(logMsg);

                String logMsg = "disableTelephonyFallbackIfNeeded:"

                        + " mTelephonyTimeZoneFallbackEnabled=" + mTelephonyTimeZoneFallbackEnabled;

                logTimeZoneDebugInfo(logMsg);

            }

        }

    }



    private void logTimeZoneDetectorChange(@NonNull String logMsg) {

    private void logTimeZoneDebugInfo(@NonNull String logMsg) {

        if (DBG) {

            Slog.d(LOG_TAG, logMsg);

        }

        mTimeZoneChangesLog.log(logMsg);

        mEnvironment.addDebugLogEntry(logMsg);

    }



    /**
@@ -598,7 +601,7 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
                bestTelephonySuggestion.score >= TELEPHONY_SCORE_USAGE_THRESHOLD;

        if (!suggestionGoodEnough) {

            if (DBG) {

                Slog.d(LOG_TAG, "Best suggestion not good enough."

                Slog.d(LOG_TAG, "Best suggestion not good enough:"

                        + " bestTelephonySuggestion=" + bestTelephonySuggestion

                        + ", detectionReason=" + detectionReason);

            }
@@ -611,12 +614,12 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
        if (zoneId == null) {

            Slog.w(LOG_TAG, "Empty zone suggestion scored higher than expected. This is an error:"

                    + " bestTelephonySuggestion=" + bestTelephonySuggestion

                    + " detectionReason=" + detectionReason);

                    + ", detectionReason=" + detectionReason);

            return;

        }



        String cause = "Found good suggestion."

                + ", bestTelephonySuggestion=" + bestTelephonySuggestion

        String cause = "Found good suggestion:"

                + " bestTelephonySuggestion=" + bestTelephonySuggestion

                + ", detectionReason=" + detectionReason;

        setDeviceTimeZoneIfRequired(zoneId, cause);

    }
@@ -634,9 +637,8 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
        if (newZoneId.equals(currentZoneId) && newConfidence <= currentConfidence) {

            // No need to modify the device time zone settings.

            if (DBG) {

                Slog.d(LOG_TAG, "No need to change the time zone;"

                        + " device is already set to newZoneId."

                        + ", newZoneId=" + newZoneId

                Slog.d(LOG_TAG, "No need to change the time zone device is already set to newZoneId"

                        + ": newZoneId=" + newZoneId

                        + ", cause=" + cause

                        + ", currentScore=" + currentConfidence

                        + ", newConfidence=" + newConfidence);
@@ -644,13 +646,14 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
            return;

        }



        mEnvironment.setDeviceTimeZoneAndConfidence(newZoneId, newConfidence);

        String logMsg = "Set device time zone or higher confidence."

                + ", currentZoneId=" + currentZoneId

                + ", newZoneId=" + newZoneId

        String logInfo = "Set device time zone or higher confidence:"

                + " newZoneId=" + newZoneId

                + ", cause=" + cause

                + ", newConfidence=" + newConfidence;

        logTimeZoneDetectorChange(logMsg);

        if (DBG) {

            Slog.d(LOG_TAG, logInfo);

        }

        mEnvironment.setDeviceTimeZoneAndConfidence(newZoneId, newConfidence, logInfo);

    }



    @GuardedBy("this")
@@ -702,7 +705,7 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
        String logMsg = "handleConfigurationInternalChanged:"

                + " oldConfiguration=" + mCurrentConfigurationInternal

                + ", newConfiguration=" + currentUserConfig;

        logTimeZoneDetectorChange(logMsg);

        logTimeZoneDebugInfo(logMsg);

        mCurrentConfigurationInternal = currentUserConfig;



        // The configuration change may have changed available suggestions or the way suggestions
@@ -731,9 +734,9 @@ public final class TimeZoneDetectorStrategyImpl implements TimeZoneDetectorStrat 
                + formatDebugString(mTelephonyTimeZoneFallbackEnabled));

        ipw.decreaseIndent(); // level 2



        ipw.println("Time zone change log:");

        ipw.println("Time zone debug log:");

        ipw.increaseIndent(); // level 2

        mTimeZoneChangesLog.dump(ipw);

        mEnvironment.dumpDebugLog(ipw);

        ipw.decreaseIndent(); // level 2



        ipw.println("Manual suggestion history:");