blob: ff2e22e16a23833ecf9ce13b2fcdf3838e677807 [file] [log] [blame]
<!DOCTYPE html>
<!--
Copyright (c) 2015 The Chromium Authors. All rights reserved.
Use of this source code is governed by a BSD-style license that can be
found in the LICENSE file.
-->
<link rel="import" href="/tracing/importer/importer.html">
<link rel="import" href="/tracing/importer/simple_line_reader.html">
<link rel="import" href="/tracing/model/activity.html">
<link rel="import" href="/tracing/model/model.html">
<script>
/**
* @fileoverview Imports android event log data into the trace model.
* Android event log data contains information about activities that
* are launched/paused, processes that are started, memory usage, etc.
*
* The current implementation only parses activity events, with the goal of
* determining which Activity is running in the foreground for a process.
*
* This importer assumes the events arrive as a string. The unit tests provide
* examples of the trace format.
*/
'use strict';
tr.exportTo('tr.e.importer.android', function() {
var Importer = tr.importer.Importer;
var ACTIVITY_STATE = {
NONE: 'none',
CREATED: 'created',
STARTED: 'started',
RESUMED: 'resumed',
PAUSED: 'paused',
STOPPED: 'stopped',
DESTROYED: 'destroyed'
};
var activityMap = {};
/**
* Imports android event log data (adb logcat -b events)
* @constructor
*/
function EventLogImporter(model, events) {
this.model_ = model;
this.events_ = events;
this.importPriority = 3;
}
// Generic format of event log entries.
// Sample event log entry that this matches (split over 2 lines):
// 08-11 13:12:31.405 880 2645 I am_focused_activity: [0,com.google.android.googlequicksearchbox/com.google.android.launcher.GEL] // @suppress longLineCheck
var eventLogActivityRE = new RegExp(
'(\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}.\\d+)' +
'\\s+(\\d+)\\s+(\\d+)\\s+([A-Z])\\s*' +
'(am_\\w+)\\s*:(.*)');
// 08-28 03:58:21.834 888 3177 I am_create_activity: [0,5972200,30,com.nxp.taginfolite/.activities.MainView,android.intent.action.MAIN,NULL,NULL,270532608] // @suppress longLineCheck
// Store the name of the created activity only
var amCreateRE = new RegExp('\s*\\[.*,.*,.*,(.*),.*,.*,.*,.*\\]');
// 07-22 12:22:19.504 920 2504 I am_focused_activity: [0,com.android.systemui/.recents.RecentsActivity] // @suppress longLineCheck
//Store the name of the focused activity only
var amFocusedRE = new RegExp('\s*\\[\\d+,(.*)\\]');
// 07-21 19:56:12.315 920 2261 I am_proc_start: [0,19942,10062,com.google.android.talk,broadcast,com.google.android.talk/com.google.android.apps.hangouts.realtimechat.RealTimeChatService$AlarmReceiver] // @suppress longLineCheck
// We care about proc starts on behalf of activities, and store the activity
var amProcStartRE = new RegExp('\s*\\[\\d+,\\d+,\\d+,.*,activity,(.*)\\]');
// 07-22 12:21:43.490 2893 2893 I am_on_resume_called: [0,com.google.android.launcher.GEL] // @suppress longLineCheck
// Store the activity name only
var amOnResumeRE = new RegExp('\s*\\[\\d+,(.*)\\]');
// 07-22 12:22:19.545 2893 2893 I am_on_paused_called: [0,com.google.android.launcher.GEL] // @suppress longLineCheck
// Store the activity name only
var amOnPauseRE = new RegExp('\s*\\[\\d+,(.*)\\]');
// 08-28 03:51:54.456 888 907 I am_activity_launch_time: [0,185307115,com.google.android.googlequicksearchbox/com.google.android.launcher.GEL,1174,1174] // @suppress longLineCheck
// Store the activity name and launch times
var amLaunchTimeRE = new RegExp('\s*\\[\\d+,\\d+,(.*),(\\d+),(\\d+)');
// 08-28 03:58:15.854 888 902 I am_destroy_activity: [0,203516597,29,com.android.chrome/com.google.android.apps.chrome.Main,finish-idle] // @suppress longLineCheck
// Store the activity name only
var amDestroyRE = new RegExp('\s*\\[\\d+,\\d+,\\d+,(.*)\\]');
/**
* @return {boolean} True when events is an android event log array.
*/
EventLogImporter.canImport = function(events) {
if (!(typeof(events) === 'string' || events instanceof String))
return false;
// Prevent the importer from matching this file in vulcanized traces.
if (/^<!DOCTYPE html>/.test(events))
return false;
return eventLogActivityRE.test(events);
};
EventLogImporter.prototype = {
__proto__: Importer.prototype,
get importerName() {
return 'EventLogImporter';
},
get model() {
return this.model_;
},
/**
* @return {string} the full activity name (including package) from
* a component
*/
getFullActivityName: function(component) {
var componentSplit = component.split('/');
if (componentSplit[1].startsWith('.'))
return componentSplit[0] + componentSplit[1];
return componentSplit[1];
},
/**
* @return {string} the process name of a component
*/
getProcName: function(component) {
var componentSplit = component.split('/');
return componentSplit[0];
},
findOrCreateActivity: function(activityName) {
if (activityName in activityMap)
return activityMap[activityName];
var activity = {
state: ACTIVITY_STATE.NONE,
name: activityName
};
activityMap[activityName] = activity;
return activity;
},
deleteActivity: function(activityName) {
delete activityMap[activityName];
},
handleCreateActivity: function(ts, activityName) {
var activity = this.findOrCreateActivity(activityName);
activity.state = ACTIVITY_STATE.CREATED;
activity.createdTs = ts;
},
handleFocusActivity: function(ts, procName, activityName) {
var activity = this.findOrCreateActivity(activityName);
activity.lastFocusedTs = ts;
},
handleProcStartForActivity: function(ts, activityName) {
var activity = this.findOrCreateActivity(activityName);
activity.procStartTs = ts;
},
handleOnResumeCalled: function(ts, pid, activityName) {
var activity = this.findOrCreateActivity(activityName);
activity.state = ACTIVITY_STATE.RESUMED;
activity.lastResumeTs = ts;
// on_resume_called shows the actual PID; use this
// to link the activity up with a process later
activity.pid = pid;
},
handleOnPauseCalled: function(ts, activityName) {
var activity = this.findOrCreateActivity(activityName);
activity.state = ACTIVITY_STATE.PAUSED;
activity.lastPauseTs = ts;
// Create a new AndroidActivity representing the foreground state,
// but only if the pause happened within the model bounds
if (ts > this.model_.bounds.min && ts < this.model_.bounds.max)
this.addActivityToProcess(activity);
},
handleLaunchTime: function(ts, activityName, launchTime) {
var activity = this.findOrCreateActivity(activityName);
activity.launchTime = launchTime;
},
handleDestroyActivity: function(ts, activityName) {
this.deleteActivity(activityName);
},
addActivityToProcess: function(activity) {
if (activity.pid === undefined)
return;
var process = this.model_.getOrCreateProcess(activity.pid);
// The range of the activity is the time from resume to time
// of pause; limit the start time to the beginning of the model
var range = tr.b.Range.fromExplicitRange(
Math.max(this.model_.bounds.min, activity.lastResumeTs),
activity.lastPauseTs);
var newActivity = new tr.model.Activity(activity.name,
'Android Activity', range,
{created: activity.createdTs,
procstart: activity.procStartTs,
lastfocus: activity.lastFocusedTs});
process.activities.push(newActivity);
},
parseAmLine_: function(line) {
var match = eventLogActivityRE.exec(line);
if (!match)
return;
// Possible activity life-cycles:
// 1) Launch from scratch:
// - am_create_activity
// - am_focused_activity
// - am_proc_start
// - am_proc_bound
// - am_restart_activity
// - am_on_resume_called
// 2) Re-open existing activity
// - am_focused_activity
// - am_on_resume_called
// HACK: event log date format is "MM-DD" and doesn't contain the year;
// to figure out the year, take the min bound of the model, convert
// to real-time and use that as the year.
// The Android event log will eventually contain the year once this
// CL is in a release:
// https://android-review.googlesource.com/#/c/168900
var first_realtime_ts = this.model_.bounds.min -
this.model_.realtime_to_monotonic_offset_ms;
var year = new Date(first_realtime_ts).getFullYear();
var ts = match[1].substring(0, 5) + '-' + year + ' ' +
match[1].substring(5, match[1].length);
var monotonic_ts = Date.parse(ts) +
this.model_.realtime_to_monotonic_offset_ms;
var pid = match[2];
var action = match[5];
var data = match[6];
if (action === 'am_create_activity') {
match = amCreateRE.exec(data);
if (match && match.length >= 2) {
this.handleCreateActivity(monotonic_ts,
this.getFullActivityName(match[1]));
}
} else if (action === 'am_focused_activity') {
match = amFocusedRE.exec(data);
if (match && match.length >= 2) {
this.handleFocusActivity(monotonic_ts,
this.getProcName(match[1]), this.getFullActivityName(match[1]));
}
} else if (action === 'am_proc_start') {
match = amProcStartRE.exec(data);
if (match && match.length >= 2) {
this.handleProcStartForActivity(monotonic_ts,
this.getFullActivityName(match[1]));
}
} else if (action === 'am_on_resume_called') {
match = amOnResumeRE.exec(data);
if (match && match.length >= 2)
this.handleOnResumeCalled(monotonic_ts, pid, match[1]);
} else if (action === 'am_on_paused_called') {
match = amOnPauseRE.exec(data);
if (match && match.length >= 2)
this.handleOnPauseCalled(monotonic_ts, match[1]);
} else if (action === 'am_activity_launch_time') {
match = amLaunchTimeRE.exec(data);
this.handleLaunchTime(monotonic_ts,
this.getFullActivityName(match[1]), match[2]);
} else if (action === 'am_destroy_activity') {
match = amDestroyRE.exec(data);
if (match && match.length == 2) {
this.handleDestroyActivity(monotonic_ts,
this.getFullActivityName(match[1]));
}
}
},
importEvents: function() {
// Check if we have a mapping from real-time to CLOCK_MONOTONIC
if (isNaN(this.model_.realtime_to_monotonic_offset_ms)) {
this.model_.importWarning({
type: 'eveng_log_clock_sync',
message: 'Need a trace_event_clock_sync to map realtime to import.'
});
return;
}
// Since the event log typically spans a much larger timeframe
// than the ftrace data, we want to calculate the bounds of the existing
// model, and dump all event log data outside of those bounds
this.model_.updateBounds();
var lines = this.events_.split('\n');
lines.forEach(this.parseAmLine_, this);
// Iterate over all created activities that are not destroyed yet
for (var activityName in activityMap) {
var activity = activityMap[activityName];
// If we're still in the foreground, store the activity anyway
if (activity.state == ACTIVITY_STATE.RESUMED) {
// Set the pause timestamp to the end of the model bounds
activity.lastPauseTs = this.model_.bounds.max;
this.addActivityToProcess(activity);
}
}
}
};
Importer.register(EventLogImporter);
return {
EventLogImporter: EventLogImporter
};
});
</script>