Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Added tron metrics for shutdown time" into oc-mr1-dev

Browse Source
This commit is contained in:
Fyodor Kupolov
2017-08-28 18:41:52 +00:00
committed by Android (Google) Code Review
parent 0fe2910c37 291f63bb54
commit 30c565d399
2 changed files with 130 additions and 12 deletions
Download Patch File Download Diff File Expand all files Collapse all files

49
core/java/com/android/server/BootReceiver.java
View File

@@ -31,13 +31,13 @@ import android.os.ServiceManager;
import android.os.SystemProperties;
import android.os.storage.StorageManager;
import android.provider.Downloads;
import android.text.TextUtils;
import android.util.AtomicFile;
import android.util.Slog;
import android.util.Xml;
import com.android.internal.annotations.VisibleForTesting;
import com.android.internal.logging.MetricsLogger;
import com.android.internal.util.ArrayUtils;
import com.android.internal.util.FastXmlSerializer;
import com.android.internal.util.XmlUtils;
@@ -106,6 +106,11 @@ public class BootReceiver extends BroadcastReceiver {
"powerctl_shutdown_time_ms:([0-9]+):([0-9]+)";
private static final int UMOUNT_STATUS_NOT_AVAILABLE = 4; // should match with init/reboot.h
// Location of file with metrics recorded during shutdown
private static final String SHUTDOWN_METRICS_FILE = "/data/system/shutdown-metrics.txt";
private static final String SHUTDOWN_TRON_METRICS_PREFIX = "shutdown_";
@Override
public void onReceive(final Context context, Intent intent) {
// Log boot events in the background to avoid blocking the main thread with I/O
@@ -232,6 +237,7 @@ public class BootReceiver extends BroadcastReceiver {
logFsShutdownTime();
logFsMountTime();
addFsckErrorsToDropBoxAndLogFsStat(db, timestamps, headers, -LOG_SIZE, "SYSTEM_FSCK");
logSystemServerShutdownTimeMetrics();
// Scan existing tombstones (in case any new ones appeared)
File[] tombstoneFiles = TOMBSTONE_DIR.listFiles();
@@ -380,6 +386,47 @@ public class BootReceiver extends BroadcastReceiver {
}
}
// TODO b/64815357 Move to bootstat.cpp and log AbsoluteRebootTime
private static void logSystemServerShutdownTimeMetrics() {
File metricsFile = new File(SHUTDOWN_METRICS_FILE);
String metricsStr = null;
if (metricsFile.exists()) {
try {
metricsStr = FileUtils.readTextFile(metricsFile, 0, null);
} catch (IOException e) {
Slog.e(TAG, "Problem reading " + metricsFile, e);
}
}
if (!TextUtils.isEmpty(metricsStr)) {
String[] array = metricsStr.split(",");
for (String keyValueStr : array) {
String[] keyValue = keyValueStr.split(":");
if (keyValue.length != 2) {
Slog.e(TAG, "Wrong format of shutdown metrics - " + metricsStr);
continue;
}
// Ignore keys that are not indended for tron
if (keyValue[0].startsWith(SHUTDOWN_TRON_METRICS_PREFIX)) {
logTronShutdownMetric(keyValue[0], keyValue[1]);
}
}
}
metricsFile.delete();
}
private static void logTronShutdownMetric(String metricName, String valueStr) {
int value;
try {
value = Integer.parseInt(valueStr);
} catch (NumberFormatException e) {
Slog.e(TAG, "Cannot parse metric " + metricName + " int value - " + valueStr);
return;
}
if (value >= 0) {
MetricsLogger.histogram(null, metricName, value);
}
}
private static void logFsShutdownTime() {
File f = null;
for (String fileName : LAST_KMSG_FILES) {

93
services/core/java/com/android/server/power/ShutdownThread.java
View File

@@ -51,6 +51,7 @@ import android.os.UserManager;
import android.os.Vibrator;
import android.os.storage.IStorageManager;
import android.os.storage.IStorageShutdownObserver;
import android.util.ArrayMap;
import android.util.Log;
import android.util.TimingsTraceLog;
import android.view.WindowManager;
@@ -62,7 +63,9 @@ import com.android.server.pm.PackageManagerService;
import com.android.server.statusbar.StatusBarManagerInternal;
import java.io.File;
import java.io.FileOutputStream;
import java.io.IOException;
import java.nio.charset.StandardCharsets;
public final class ShutdownThread extends Thread {
// constants
@@ -110,6 +113,23 @@ public final class ShutdownThread extends Thread {
private static final TimingsTraceLog SHUTDOWN_TIMINGS_LOG = new TimingsTraceLog(
"ShutdownTiming", Trace.TRACE_TAG_SYSTEM_SERVER);
// Metrics that will be reported to tron after reboot
private static final ArrayMap<String, Long> TRON_METRICS = new ArrayMap<>();
// File to use for save metrics
private static final String METRICS_FILE_BASENAME = "/data/system/shutdown-metrics";
// Metrics names to be persisted in shutdown-metrics file
private static String METRIC_SYSTEM_SERVER = "shutdown_system_server";
private static String METRIC_SEND_BROADCAST = "shutdown_send_shutdown_broadcast";
private static String METRIC_AM = "shutdown_activity_manager";
private static String METRIC_PM = "shutdown_package_manager";
private static String METRIC_RADIOS = "shutdown_radios";
private static String METRIC_BT = "shutdown_bt";
private static String METRIC_RADIO = "shutdown_radio";
private static String METRIC_NFC = "shutdown_nfc";
private static String METRIC_SM = "shutdown_storage_manager";
private final Object mActionDoneSync = new Object();
private boolean mActionDone;
private Context mContext;
@@ -349,6 +369,7 @@ public final class ShutdownThread extends Thread {
private static void beginShutdownSequence(Context context) {
SHUTDOWN_TIMINGS_LOG.traceBegin("SystemServerShutdown");
metricStarted(METRIC_SYSTEM_SERVER);
synchronized (sIsStartedGuard) {
if (sIsStarted) {
Log.d(TAG, "Shutdown sequence already running, returning.");
@@ -430,6 +451,7 @@ public final class ShutdownThread extends Thread {
SystemProperties.set(REBOOT_SAFEMODE_PROPERTY, "1");
}
metricStarted(METRIC_SEND_BROADCAST);
SHUTDOWN_TIMINGS_LOG.traceBegin("SendShutdownBroadcast");
Log.i(TAG, "Sending shutdown broadcast...");
@@ -463,9 +485,11 @@ public final class ShutdownThread extends Thread {
sInstance.setRebootProgress(BROADCAST_STOP_PERCENT, null);
}
SHUTDOWN_TIMINGS_LOG.traceEnd(); // SendShutdownBroadcast
metricEnded(METRIC_SEND_BROADCAST);
Log.i(TAG, "Shutting down activity manager...");
SHUTDOWN_TIMINGS_LOG.traceBegin("ShutdownActivityManager");
metricStarted(METRIC_AM);
final IActivityManager am =
IActivityManager.Stub.asInterface(ServiceManager.checkService("activity"));
@@ -478,10 +502,12 @@ public final class ShutdownThread extends Thread {
if (mRebootHasProgressBar) {
sInstance.setRebootProgress(ACTIVITY_MANAGER_STOP_PERCENT, null);
}
SHUTDOWN_TIMINGS_LOG.traceEnd(); // ShutdownActivityManager
SHUTDOWN_TIMINGS_LOG.traceEnd();// ShutdownActivityManager
metricEnded(METRIC_AM);
Log.i(TAG, "Shutting down package manager...");
SHUTDOWN_TIMINGS_LOG.traceBegin("ShutdownPackageManager");
metricStarted(METRIC_PM);
final PackageManagerService pm = (PackageManagerService)
ServiceManager.getService("package");
@@ -492,14 +518,17 @@ public final class ShutdownThread extends Thread {
sInstance.setRebootProgress(PACKAGE_MANAGER_STOP_PERCENT, null);
}
SHUTDOWN_TIMINGS_LOG.traceEnd(); // ShutdownPackageManager
metricEnded(METRIC_PM);
// Shutdown radios.
SHUTDOWN_TIMINGS_LOG.traceBegin("ShutdownRadios");
metricStarted(METRIC_RADIOS);
shutdownRadios(MAX_RADIO_WAIT_TIME);
if (mRebootHasProgressBar) {
sInstance.setRebootProgress(RADIO_STOP_PERCENT, null);
}
SHUTDOWN_TIMINGS_LOG.traceEnd(); // ShutdownRadios
metricEnded(METRIC_RADIOS);
// Shutdown StorageManagerService to ensure media is in a safe state
IStorageShutdownObserver observer = new IStorageShutdownObserver.Stub() {
@@ -511,6 +540,7 @@ public final class ShutdownThread extends Thread {
Log.i(TAG, "Shutting down StorageManagerService");
SHUTDOWN_TIMINGS_LOG.traceBegin("ShutdownStorageManager");
metricStarted(METRIC_SM);
// Set initial variables and time out time.
mActionDone = false;
@@ -546,6 +576,7 @@ public final class ShutdownThread extends Thread {
}
}
SHUTDOWN_TIMINGS_LOG.traceEnd(); // ShutdownStorageManager
metricEnded(METRIC_SM);
if (mRebootHasProgressBar) {
sInstance.setRebootProgress(MOUNT_SERVICE_STOP_PERCENT, null);
@@ -558,6 +589,14 @@ public final class ShutdownThread extends Thread {
rebootOrShutdown(mContext, mReboot, mReason);
}
private static void metricStarted(String metricKey) {
TRON_METRICS.put(metricKey, -1 * SystemClock.elapsedRealtime());
}
private static void metricEnded(String metricKey) {
TRON_METRICS.put(metricKey, SystemClock.elapsedRealtime() + TRON_METRICS.get(metricKey));
}
private void setRebootProgress(final int progress, final CharSequence message) {
mHandler.post(new Runnable() {
@Override
@@ -590,12 +629,12 @@ public final class ShutdownThread extends Thread {
final IBluetoothManager bluetooth =
IBluetoothManager.Stub.asInterface(ServiceManager.checkService(
BluetoothAdapter.BLUETOOTH_MANAGER_SERVICE));
final long nfcShutdownStarted = SystemClock.elapsedRealtime();
try {
nfcOff = nfc == null ||
nfc.getState() == NfcAdapter.STATE_OFF;
if (!nfcOff) {
Log.w(TAG, "Turning off NFC...");
metricStarted(METRIC_NFC);
nfc.disable(false); // Don't persist new state
}
} catch (RemoteException ex) {
@@ -603,12 +642,12 @@ public final class ShutdownThread extends Thread {
nfcOff = true;
}
final long btShutdownStarted = SystemClock.elapsedRealtime();
try {
bluetoothReadyForShutdown = bluetooth == null ||
bluetooth.getState() == BluetoothAdapter.STATE_OFF;
if (!bluetoothReadyForShutdown) {
Log.w(TAG, "Disabling Bluetooth...");
metricStarted(METRIC_BT);
bluetooth.disable(mContext.getPackageName(), false); // disable but don't persist new state
}
} catch (RemoteException ex) {
@@ -616,11 +655,11 @@ public final class ShutdownThread extends Thread {
bluetoothReadyForShutdown = true;
}
final long radioShutdownStarted = SystemClock.elapsedRealtime();
try {
radioOff = phone == null || !phone.needMobileRadioShutdown();
if (!radioOff) {
Log.w(TAG, "Turning off cellular radios...");
metricStarted(METRIC_RADIO);
phone.shutdownMobileRadios();
}
} catch (RemoteException ex) {
@@ -653,8 +692,9 @@ public final class ShutdownThread extends Thread {
}
if (bluetoothReadyForShutdown) {
Log.i(TAG, "Bluetooth turned off.");
SHUTDOWN_TIMINGS_LOG.logDuration("ShutdownBt",
SystemClock.elapsedRealtime() - btShutdownStarted);
metricEnded(METRIC_BT);
SHUTDOWN_TIMINGS_LOG
.logDuration("ShutdownBt", TRON_METRICS.get(METRIC_BT));
}
}
if (!radioOff) {
@@ -666,8 +706,9 @@ public final class ShutdownThread extends Thread {
}
if (radioOff) {
Log.i(TAG, "Radio turned off.");
SHUTDOWN_TIMINGS_LOG.logDuration("ShutdownRadio",
SystemClock.elapsedRealtime() - radioShutdownStarted);
metricEnded(METRIC_RADIO);
SHUTDOWN_TIMINGS_LOG
.logDuration("ShutdownRadio", TRON_METRICS.get(METRIC_RADIO));
}
}
if (!nfcOff) {
@@ -679,8 +720,9 @@ public final class ShutdownThread extends Thread {
}
if (nfcOff) {
Log.i(TAG, "NFC turned off.");
SHUTDOWN_TIMINGS_LOG.logDuration("ShutdownNfc",
SystemClock.elapsedRealtime() - nfcShutdownStarted);
metricEnded(METRIC_NFC);
SHUTDOWN_TIMINGS_LOG
.logDuration("ShutdownNfc", TRON_METRICS.get(METRIC_NFC));
}
}
@@ -708,7 +750,7 @@ public final class ShutdownThread extends Thread {
/**
* Do not call this directly. Use {@link #reboot(Context, String, boolean)}
* or {@link #shutdown(Context, boolean)} instead.
* or {@link #shutdown(Context, String, boolean)} instead.
*
* @param context Context used to vibrate or null without vibration
* @param reboot true to reboot or false to shutdown
@@ -716,6 +758,8 @@ public final class ShutdownThread extends Thread {
*/
public static void rebootOrShutdown(final Context context, boolean reboot, String reason) {
SHUTDOWN_TIMINGS_LOG.traceEnd(); // SystemServerShutdown
metricEnded(METRIC_SYSTEM_SERVER);
saveMetrics(reboot);
if (reboot) {
Log.i(TAG, "Rebooting, reason: " + reason);
PowerManagerService.lowLevelReboot(reason);
@@ -742,6 +786,33 @@ public final class ShutdownThread extends Thread {
PowerManagerService.lowLevelShutdown(reason);
}
private static void saveMetrics(boolean reboot) {
StringBuilder metricValue = new StringBuilder();
metricValue.append("reboot:");
metricValue.append(reboot ? "y" : "n");
final int metricsSize = TRON_METRICS.size();
for (int i = 0; i < metricsSize; i++) {
final String name = TRON_METRICS.keyAt(i);
final long value = TRON_METRICS.valueAt(i);
if (value < 0) {
Log.e(TAG, "metricEnded wasn't called for " + name);
continue;
}
metricValue.append(',').append(name).append(':').append(value);
}
File tmp = new File(METRICS_FILE_BASENAME + ".tmp");
boolean saved = false;
try (FileOutputStream fos = new FileOutputStream(tmp)) {
fos.write(metricValue.toString().getBytes(StandardCharsets.UTF_8));
saved = true;
} catch (IOException e) {
Log.e(TAG,"Cannot save shutdown metrics", e);
}
if (saved) {
tmp.renameTo(new File(METRICS_FILE_BASENAME + ".txt"));
}
}
private void uncrypt() {
Log.i(TAG, "Calling uncrypt and monitoring the progress...");