Skip to content

Commit 684c54a

Browse files
committed
Update NTP outside locks, log large trim events.
Move NTP updates outside locks to avoid blocking ShutdownThread. Add logging around trim events that remove substantial history. Include history start in sample events. Bug: 5627247, 5584564 Change-Id: If9bbd93842c710efcdec94e68da87e9e42a5f961
1 parent e937da8 commit 684c54a

File tree

3 files changed

+64
-19
lines changed

3 files changed

+64
-19
lines changed

services/java/com/android/server/EventLogTags.logtags

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -142,5 +142,5 @@ option java_package com.android.server
142142
# ---------------------------
143143
# NetworkStatsService.java
144144
# ---------------------------
145-
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)
146-
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)
145+
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)
146+
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)

services/java/com/android/server/net/NetworkPolicyManagerService.java

Lines changed: 19 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -393,6 +393,7 @@ public void onReceive(Context context, Intent intent) {
393393
// on background handler thread, and verified
394394
// READ_NETWORK_USAGE_HISTORY permission above.
395395

396+
maybeRefreshTrustedTime();
396397
synchronized (mRulesLock) {
397398
updateNetworkEnabledLocked();
398399
updateNotificationsLocked();
@@ -445,7 +446,7 @@ private void updateNotificationsLocked() {
445446
// cycle boundary to recompute notifications.
446447

447448
// examine stats for each active policy
448-
final long currentTime = currentTimeMillis(true);
449+
final long currentTime = currentTimeMillis();
449450
for (NetworkPolicy policy : mNetworkPolicy.values()) {
450451
// ignore policies that aren't relevant to user
451452
if (!isTemplateRelevant(policy.template)) continue;
@@ -683,6 +684,8 @@ private void cancelNotification(String tag) {
683684
public void onReceive(Context context, Intent intent) {
684685
// on background handler thread, and verified CONNECTIVITY_INTERNAL
685686
// permission above.
687+
688+
maybeRefreshTrustedTime();
686689
synchronized (mRulesLock) {
687690
ensureActiveMobilePolicyLocked();
688691
updateNetworkEnabledLocked();
@@ -702,7 +705,7 @@ private void updateNetworkEnabledLocked() {
702705
// TODO: reset any policy-disabled networks when any policy is removed
703706
// completely, which is currently rare case.
704707

705-
final long currentTime = currentTimeMillis(true);
708+
final long currentTime = currentTimeMillis();
706709
for (NetworkPolicy policy : mNetworkPolicy.values()) {
707710
// shortcut when policy has no limit
708711
if (policy.limitBytes == LIMIT_DISABLED) {
@@ -802,7 +805,7 @@ private void updateNetworkRulesLocked() {
802805

803806
// apply each policy that we found ifaces for; compute remaining data
804807
// based on current cycle and historical stats, and push to kernel.
805-
final long currentTime = currentTimeMillis(true);
808+
final long currentTime = currentTimeMillis();
806809
for (NetworkPolicy policy : mNetworkRules.keySet()) {
807810
final String[] ifaces = mNetworkRules.get(policy);
808811

@@ -1092,6 +1095,7 @@ public void unregisterListener(INetworkPolicyListener listener) {
10921095
public void setNetworkPolicies(NetworkPolicy[] policies) {
10931096
mContext.enforceCallingOrSelfPermission(MANAGE_NETWORK_POLICY, TAG);
10941097

1098+
maybeRefreshTrustedTime();
10951099
synchronized (mRulesLock) {
10961100
mNetworkPolicy.clear();
10971101
for (NetworkPolicy policy : policies) {
@@ -1119,7 +1123,8 @@ public NetworkPolicy[] getNetworkPolicies() {
11191123
public void snoozePolicy(NetworkTemplate template) {
11201124
mContext.enforceCallingOrSelfPermission(MANAGE_NETWORK_POLICY, TAG);
11211125

1122-
final long currentTime = currentTimeMillis(true);
1126+
maybeRefreshTrustedTime();
1127+
final long currentTime = currentTimeMillis();
11231128
synchronized (mRulesLock) {
11241129
// find and snooze local policy that matches
11251130
final NetworkPolicy policy = mNetworkPolicy.get(template);
@@ -1140,6 +1145,7 @@ public void snoozePolicy(NetworkTemplate template) {
11401145
public void setRestrictBackground(boolean restrictBackground) {
11411146
mContext.enforceCallingOrSelfPermission(MANAGE_NETWORK_POLICY, TAG);
11421147

1148+
maybeRefreshTrustedTime();
11431149
synchronized (mRulesLock) {
11441150
mRestrictBackground = restrictBackground;
11451151
updateRulesForRestrictBackgroundLocked();
@@ -1193,7 +1199,7 @@ private NetworkQuotaInfo getNetworkQuotaInfoUnchecked(NetworkState state) {
11931199
return null;
11941200
}
11951201

1196-
final long currentTime = currentTimeMillis(false);
1202+
final long currentTime = currentTimeMillis();
11971203

11981204
// find total bytes used under policy
11991205
final long start = computeLastCycleBoundary(currentTime, policy);
@@ -1472,6 +1478,7 @@ public boolean handleMessage(Message msg) {
14721478
case MSG_LIMIT_REACHED: {
14731479
final String iface = (String) msg.obj;
14741480

1481+
maybeRefreshTrustedTime();
14751482
synchronized (mRulesLock) {
14761483
if (mMeteredIfaces.contains(iface)) {
14771484
try {
@@ -1551,12 +1558,16 @@ private long getTotalBytes(NetworkTemplate template, long start, long end) {
15511558
}
15521559
}
15531560

1554-
private long currentTimeMillis(boolean allowRefresh) {
1555-
// try refreshing time source when stale
1556-
if (mTime.getCacheAge() > TIME_CACHE_MAX_AGE && allowRefresh) {
1561+
/**
1562+
* Try refreshing {@link #mTime} when stale.
1563+
*/
1564+
private void maybeRefreshTrustedTime() {
1565+
if (mTime.getCacheAge() > TIME_CACHE_MAX_AGE) {
15571566
mTime.forceRefresh();
15581567
}
1568+
}
15591569

1570+
private long currentTimeMillis() {
15601571
return mTime.hasCache() ? mTime.currentTimeMillis() : System.currentTimeMillis();
15611572
}
15621573

services/java/com/android/server/net/NetworkStatsService.java

Lines changed: 43 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -472,6 +472,18 @@ private NetworkStats getSummaryForNetwork(NetworkTemplate template, long start,
472472
}
473473
}
474474

475+
private long getHistoryStartLocked(
476+
NetworkTemplate template, HashMap<NetworkIdentitySet, NetworkStatsHistory> source) {
477+
long start = Long.MAX_VALUE;
478+
for (NetworkIdentitySet ident : source.keySet()) {
479+
if (templateMatches(template, ident)) {
480+
final NetworkStatsHistory history = source.get(ident);
481+
start = Math.min(start, history.getStart());
482+
}
483+
}
484+
return start;
485+
}
486+
475487
@Override
476488
public NetworkStats getSummaryForAllUid(
477489
NetworkTemplate template, long start, long end, boolean includeTags) {
@@ -771,6 +783,12 @@ private void bootstrapStats() {
771783
private void performPoll(int flags) {
772784
synchronized (mStatsLock) {
773785
mWakeLock.acquire();
786+
787+
// try refreshing time source when stale
788+
if (mTime.getCacheAge() > mSettings.getTimeCacheMaxAge()) {
789+
mTime.forceRefresh();
790+
}
791+
774792
try {
775793
performPollLocked(flags);
776794
} finally {
@@ -791,11 +809,6 @@ private void performPollLocked(int flags) {
791809
final boolean persistUid = (flags & FLAG_PERSIST_UID) != 0;
792810
final boolean persistForce = (flags & FLAG_PERSIST_FORCE) != 0;
793811

794-
// try refreshing time source when stale
795-
if (mTime.getCacheAge() > mSettings.getTimeCacheMaxAge()) {
796-
mTime.forceRefresh();
797-
}
798-
799812
// TODO: consider marking "untrusted" times in historical stats
800813
final long currentTime = mTime.hasCache() ? mTime.currentTimeMillis()
801814
: System.currentTimeMillis();
@@ -981,6 +994,7 @@ private void performSample() {
981994
final long start = end - largestBucketSize;
982995

983996
final long trustedTime = mTime.hasCache() ? mTime.currentTimeMillis() : -1;
997+
long devHistoryStart = Long.MAX_VALUE;
984998

985999
NetworkTemplate template = null;
9861000
NetworkStats.Entry devTotal = null;
@@ -990,24 +1004,27 @@ private void performSample() {
9901004
// collect mobile sample
9911005
template = buildTemplateMobileAll(getActiveSubscriberId(mContext));
9921006
devTotal = getSummaryForNetworkDev(template, start, end).getTotal(devTotal);
1007+
devHistoryStart = getHistoryStartLocked(template, mNetworkDevStats);
9931008
xtTotal = getSummaryForNetworkXt(template, start, end).getTotal(xtTotal);
9941009
uidTotal = getSummaryForAllUid(template, start, end, false).getTotal(uidTotal);
1010+
9951011
EventLogTags.writeNetstatsMobileSample(
9961012
devTotal.rxBytes, devTotal.rxPackets, devTotal.txBytes, devTotal.txPackets,
9971013
xtTotal.rxBytes, xtTotal.rxPackets, xtTotal.txBytes, xtTotal.txPackets,
9981014
uidTotal.rxBytes, uidTotal.rxPackets, uidTotal.txBytes, uidTotal.txPackets,
999-
trustedTime);
1015+
trustedTime, devHistoryStart);
10001016

10011017
// collect wifi sample
10021018
template = buildTemplateWifi();
10031019
devTotal = getSummaryForNetworkDev(template, start, end).getTotal(devTotal);
1020+
devHistoryStart = getHistoryStartLocked(template, mNetworkDevStats);
10041021
xtTotal = getSummaryForNetworkXt(template, start, end).getTotal(xtTotal);
10051022
uidTotal = getSummaryForAllUid(template, start, end, false).getTotal(uidTotal);
10061023
EventLogTags.writeNetstatsWifiSample(
10071024
devTotal.rxBytes, devTotal.rxPackets, devTotal.txBytes, devTotal.txPackets,
10081025
xtTotal.rxBytes, xtTotal.rxPackets, xtTotal.txBytes, xtTotal.txPackets,
10091026
uidTotal.rxBytes, uidTotal.rxPackets, uidTotal.txBytes, uidTotal.txPackets,
1010-
trustedTime);
1027+
trustedTime, devHistoryStart);
10111028
}
10121029

10131030
/**
@@ -1243,11 +1260,28 @@ private void writeNetworkStats(
12431260

12441261
// trim any history beyond max
12451262
if (mTime.hasCache()) {
1246-
final long currentTime = Math.min(
1247-
System.currentTimeMillis(), mTime.currentTimeMillis());
1263+
final long systemCurrentTime = System.currentTimeMillis();
1264+
final long trustedCurrentTime = mTime.currentTimeMillis();
1265+
1266+
final long currentTime = Math.min(systemCurrentTime, trustedCurrentTime);
12481267
final long maxHistory = mSettings.getNetworkMaxHistory();
1268+
12491269
for (NetworkStatsHistory history : input.values()) {
1270+
final int beforeSize = history.size();
12501271
history.removeBucketsBefore(currentTime - maxHistory);
1272+
final int afterSize = history.size();
1273+
1274+
if (beforeSize > 24 && afterSize < beforeSize / 2) {
1275+
// yikes, dropping more than half of significant history
1276+
final StringBuilder builder = new StringBuilder();
1277+
builder.append("yikes, dropping more than half of history").append('\n');
1278+
builder.append("systemCurrentTime=").append(systemCurrentTime).append('\n');
1279+
builder.append("trustedCurrentTime=").append(trustedCurrentTime).append('\n');
1280+
builder.append("maxHistory=").append(maxHistory).append('\n');
1281+
builder.append("beforeSize=").append(beforeSize).append('\n');
1282+
builder.append("afterSize=").append(afterSize).append('\n');
1283+
mDropBox.addText(TAG_NETSTATS_ERROR, builder.toString());
1284+
}
12511285
}
12521286
}
12531287

0 commit comments

Comments
 (0)