Merge "Update NTP outside locks, log large trim events." into ics-mr1

3 files changed, 64 insertions, 19 deletions

diff --git a/services/java/com/android/server/EventLogTags.logtags b/services/java/com/android/server/EventLogTags.logtags
index a7eff93..5408436 100644
--- a/services/java/com/android/server/EventLogTags.logtags
+++ b/services/java/com/android/server/EventLogTags.logtags
@@ -142,5 +142,5 @@ option java_package com.android.server
 # ---------------------------
 # NetworkStatsService.java
 # ---------------------------
-51100 netstats_mobile_sample (dev_rx_bytes|2|2),(dev_tx_bytes|2|2),(dev_rx_pkts|2|1),(dev_tx_pkts|2|1),(xt_rx_bytes|2|2),(xt_tx_bytes|2|2),(xt_rx_pkts|2|1),(xt_tx_pkts|2|1),(uid_rx_bytes|2|2),(uid_tx_bytes|2|2),(uid_rx_pkts|2|1),(uid_tx_pkts|2|1),(trusted_time|2|3)
-51101 netstats_wifi_sample (dev_rx_bytes|2|2),(dev_tx_bytes|2|2),(dev_rx_pkts|2|1),(dev_tx_pkts|2|1),(xt_rx_bytes|2|2),(xt_tx_bytes|2|2),(xt_rx_pkts|2|1),(xt_tx_pkts|2|1),(uid_rx_bytes|2|2),(uid_tx_bytes|2|2),(uid_rx_pkts|2|1),(uid_tx_pkts|2|1),(trusted_time|2|3)
+51100 netstats_mobile_sample (dev_rx_bytes|2|2),(dev_tx_bytes|2|2),(dev_rx_pkts|2|1),(dev_tx_pkts|2|1),(xt_rx_bytes|2|2),(xt_tx_bytes|2|2),(xt_rx_pkts|2|1),(xt_tx_pkts|2|1),(uid_rx_bytes|2|2),(uid_tx_bytes|2|2),(uid_rx_pkts|2|1),(uid_tx_pkts|2|1),(trusted_time|2|3),(dev_history_start|2|3)
+51101 netstats_wifi_sample (dev_rx_bytes|2|2),(dev_tx_bytes|2|2),(dev_rx_pkts|2|1),(dev_tx_pkts|2|1),(xt_rx_bytes|2|2),(xt_tx_bytes|2|2),(xt_rx_pkts|2|1),(xt_tx_pkts|2|1),(uid_rx_bytes|2|2),(uid_tx_bytes|2|2),(uid_rx_pkts|2|1),(uid_tx_pkts|2|1),(trusted_time|2|3),(dev_history_start|2|3)
diff --git a/services/java/com/android/server/net/NetworkPolicyManagerService.java b/services/java/com/android/server/net/NetworkPolicyManagerService.java
index 2a1b1db..8c0f1e0 100644
--- a/services/java/com/android/server/net/NetworkPolicyManagerService.java
+++ b/services/java/com/android/server/net/NetworkPolicyManagerService.java
@@ -393,6 +393,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
             // on background handler thread, and verified
             // READ_NETWORK_USAGE_HISTORY permission above.
 
+            maybeRefreshTrustedTime();
             synchronized (mRulesLock) {
                 updateNetworkEnabledLocked();
                 updateNotificationsLocked();
@@ -445,7 +446,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
         // cycle boundary to recompute notifications.
 
         // examine stats for each active policy
-        final long currentTime = currentTimeMillis(true);
+        final long currentTime = currentTimeMillis();
         for (NetworkPolicy policy : mNetworkPolicy.values()) {
             // ignore policies that aren't relevant to user
             if (!isTemplateRelevant(policy.template)) continue;
@@ -683,6 +684,8 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
         public void onReceive(Context context, Intent intent) {
             // on background handler thread, and verified CONNECTIVITY_INTERNAL
             // permission above.
+
+            maybeRefreshTrustedTime();
             synchronized (mRulesLock) {
                 ensureActiveMobilePolicyLocked();
                 updateNetworkEnabledLocked();
@@ -702,7 +705,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
         // TODO: reset any policy-disabled networks when any policy is removed
         // completely, which is currently rare case.
 
-        final long currentTime = currentTimeMillis(true);
+        final long currentTime = currentTimeMillis();
         for (NetworkPolicy policy : mNetworkPolicy.values()) {
             // shortcut when policy has no limit
             if (policy.limitBytes == LIMIT_DISABLED) {
@@ -802,7 +805,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
 
         // apply each policy that we found ifaces for; compute remaining data
         // based on current cycle and historical stats, and push to kernel.
-        final long currentTime = currentTimeMillis(true);
+        final long currentTime = currentTimeMillis();
         for (NetworkPolicy policy : mNetworkRules.keySet()) {
             final String[] ifaces = mNetworkRules.get(policy);
 
@@ -1092,6 +1095,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
     public void setNetworkPolicies(NetworkPolicy[] policies) {
         mContext.enforceCallingOrSelfPermission(MANAGE_NETWORK_POLICY, TAG);
 
+        maybeRefreshTrustedTime();
         synchronized (mRulesLock) {
             mNetworkPolicy.clear();
             for (NetworkPolicy policy : policies) {
@@ -1119,7 +1123,8 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
     public void snoozePolicy(NetworkTemplate template) {
         mContext.enforceCallingOrSelfPermission(MANAGE_NETWORK_POLICY, TAG);
 
-        final long currentTime = currentTimeMillis(true);
+        maybeRefreshTrustedTime();
+        final long currentTime = currentTimeMillis();
         synchronized (mRulesLock) {
             // find and snooze local policy that matches
             final NetworkPolicy policy = mNetworkPolicy.get(template);
@@ -1140,6 +1145,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
     public void setRestrictBackground(boolean restrictBackground) {
         mContext.enforceCallingOrSelfPermission(MANAGE_NETWORK_POLICY, TAG);
 
+        maybeRefreshTrustedTime();
         synchronized (mRulesLock) {
             mRestrictBackground = restrictBackground;
             updateRulesForRestrictBackgroundLocked();
@@ -1193,7 +1199,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
             return null;
         }
 
-        final long currentTime = currentTimeMillis(false);
+        final long currentTime = currentTimeMillis();
 
         // find total bytes used under policy
         final long start = computeLastCycleBoundary(currentTime, policy);
@@ -1472,6 +1478,7 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
                 case MSG_LIMIT_REACHED: {
                     final String iface = (String) msg.obj;
 
+                    maybeRefreshTrustedTime();
                     synchronized (mRulesLock) {
                         if (mMeteredIfaces.contains(iface)) {
                             try {
@@ -1551,12 +1558,16 @@ public class NetworkPolicyManagerService extends INetworkPolicyManager.Stub {
         }
     }
 
-    private long currentTimeMillis(boolean allowRefresh) {
-        // try refreshing time source when stale
-        if (mTime.getCacheAge() > TIME_CACHE_MAX_AGE && allowRefresh) {
+    /**
+     * Try refreshing {@link #mTime} when stale.
+     */
+    private void maybeRefreshTrustedTime() {
+        if (mTime.getCacheAge() > TIME_CACHE_MAX_AGE) {
             mTime.forceRefresh();
         }
+    }
 
+    private long currentTimeMillis() {
         return mTime.hasCache() ? mTime.currentTimeMillis() : System.currentTimeMillis();
     }
 
diff --git a/services/java/com/android/server/net/NetworkStatsService.java b/services/java/com/android/server/net/NetworkStatsService.java
index 28cb983..b77e67e 100644
--- a/services/java/com/android/server/net/NetworkStatsService.java
+++ b/services/java/com/android/server/net/NetworkStatsService.java
@@ -472,6 +472,18 @@ public class NetworkStatsService extends INetworkStatsService.Stub {
         }
     }
 
+    private long getHistoryStartLocked(
+            NetworkTemplate template, HashMap<NetworkIdentitySet, NetworkStatsHistory> source) {
+        long start = Long.MAX_VALUE;
+        for (NetworkIdentitySet ident : source.keySet()) {
+            if (templateMatches(template, ident)) {
+                final NetworkStatsHistory history = source.get(ident);
+                start = Math.min(start, history.getStart());
+            }
+        }
+        return start;
+    }
+
     @Override
     public NetworkStats getSummaryForAllUid(
             NetworkTemplate template, long start, long end, boolean includeTags) {
@@ -771,6 +783,12 @@ public class NetworkStatsService extends INetworkStatsService.Stub {
     private void performPoll(int flags) {
         synchronized (mStatsLock) {
             mWakeLock.acquire();
+
+            // try refreshing time source when stale
+            if (mTime.getCacheAge() > mSettings.getTimeCacheMaxAge()) {
+                mTime.forceRefresh();
+            }
+
             try {
                 performPollLocked(flags);
             } finally {
@@ -791,11 +809,6 @@ public class NetworkStatsService extends INetworkStatsService.Stub {
         final boolean persistUid = (flags & FLAG_PERSIST_UID) != 0;
         final boolean persistForce = (flags & FLAG_PERSIST_FORCE) != 0;
 
-        // try refreshing time source when stale
-        if (mTime.getCacheAge() > mSettings.getTimeCacheMaxAge()) {
-            mTime.forceRefresh();
-        }
-
         // TODO: consider marking "untrusted" times in historical stats
         final long currentTime = mTime.hasCache() ? mTime.currentTimeMillis()
                 : System.currentTimeMillis();
@@ -981,6 +994,7 @@ public class NetworkStatsService extends INetworkStatsService.Stub {
         final long start = end - largestBucketSize;
 
         final long trustedTime = mTime.hasCache() ? mTime.currentTimeMillis() : -1;
+        long devHistoryStart = Long.MAX_VALUE;
 
         NetworkTemplate template = null;
         NetworkStats.Entry devTotal = null;
@@ -990,24 +1004,27 @@ public class NetworkStatsService extends INetworkStatsService.Stub {
         // collect mobile sample
         template = buildTemplateMobileAll(getActiveSubscriberId(mContext));
         devTotal = getSummaryForNetworkDev(template, start, end).getTotal(devTotal);
+        devHistoryStart = getHistoryStartLocked(template, mNetworkDevStats);
         xtTotal = getSummaryForNetworkXt(template, start, end).getTotal(xtTotal);
         uidTotal = getSummaryForAllUid(template, start, end, false).getTotal(uidTotal);
+
         EventLogTags.writeNetstatsMobileSample(
                 devTotal.rxBytes, devTotal.rxPackets, devTotal.txBytes, devTotal.txPackets,
                 xtTotal.rxBytes, xtTotal.rxPackets, xtTotal.txBytes, xtTotal.txPackets,
                 uidTotal.rxBytes, uidTotal.rxPackets, uidTotal.txBytes, uidTotal.txPackets,
-                trustedTime);
+                trustedTime, devHistoryStart);
 
         // collect wifi sample
         template = buildTemplateWifi();
         devTotal = getSummaryForNetworkDev(template, start, end).getTotal(devTotal);
+        devHistoryStart = getHistoryStartLocked(template, mNetworkDevStats);
         xtTotal = getSummaryForNetworkXt(template, start, end).getTotal(xtTotal);
         uidTotal = getSummaryForAllUid(template, start, end, false).getTotal(uidTotal);
         EventLogTags.writeNetstatsWifiSample(
                 devTotal.rxBytes, devTotal.rxPackets, devTotal.txBytes, devTotal.txPackets,
                 xtTotal.rxBytes, xtTotal.rxPackets, xtTotal.txBytes, xtTotal.txPackets,
                 uidTotal.rxBytes, uidTotal.rxPackets, uidTotal.txBytes, uidTotal.txPackets,
-                trustedTime);
+                trustedTime, devHistoryStart);
     }
 
     /**
@@ -1243,11 +1260,28 @@ public class NetworkStatsService extends INetworkStatsService.Stub {
 
         // trim any history beyond max
         if (mTime.hasCache()) {
-            final long currentTime = Math.min(
-                    System.currentTimeMillis(), mTime.currentTimeMillis());
+            final long systemCurrentTime = System.currentTimeMillis();
+            final long trustedCurrentTime = mTime.currentTimeMillis();
+
+            final long currentTime = Math.min(systemCurrentTime, trustedCurrentTime);
             final long maxHistory = mSettings.getNetworkMaxHistory();
+
             for (NetworkStatsHistory history : input.values()) {
+                final int beforeSize = history.size();
                 history.removeBucketsBefore(currentTime - maxHistory);
+                final int afterSize = history.size();
+
+                if (beforeSize > 24 && afterSize < beforeSize / 2) {
+                    // yikes, dropping more than half of significant history
+                    final StringBuilder builder = new StringBuilder();
+                    builder.append("yikes, dropping more than half of history").append('\n');
+                    builder.append("systemCurrentTime=").append(systemCurrentTime).append('\n');
+                    builder.append("trustedCurrentTime=").append(trustedCurrentTime).append('\n');
+                    builder.append("maxHistory=").append(maxHistory).append('\n');
+                    builder.append("beforeSize=").append(beforeSize).append('\n');
+                    builder.append("afterSize=").append(afterSize).append('\n');
+                    mDropBox.addText(TAG_NETSTATS_ERROR, builder.toString());
+                }
             }
         }