blob: f212d44363798611851f27fe1ea8a718c90259ab [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="/extras/importer/linux_perf/parser.html">
<script>
'use strict';
/**
* @fileoverview Parses Binder events
*/
tr.exportTo('tr.e.importer.linux_perf', function() {
var Parser = tr.e.importer.linux_perf.Parser;
// Matches binder transactions:
// transaction=%d dest_node=%d dest_proc=%d dest_thread=%d reply=%d flags=0x%x
// code=0x%x
var binderTransRE = new RegExp('transaction=(\\d+) dest_node=(\\d+) ' +
'dest_proc=(\\d+) dest_thread=(\\d+) ' +
'reply=(\\d+) flags=(0x[0-9a-fA-F]+) ' +
'code=(0x[0-9a-fA-F]+)');
var binderTransReceivedRE = /transaction=(\d+)/;
function isBinderThread(name) {
return (name.indexOf('Binder') > -1);
}
// Taken from kernel source: include/uapi/linux/android/binder.h.
var TF_ONE_WAY = 0x01;
var TF_ROOT_OBJECT = 0x04;
var TF_STATUS_CODE = 0x08;
var TF_ACCEPT_FDS = 0x10;
var NO_FLAGS = 0;
function binderFlagsToHuman(num) {
var flag = parseInt(num, 16);
var str = '';
if (flag & TF_ONE_WAY)
str += 'this is a one-way call: async, no return; ';
if (flag & TF_ROOT_OBJECT)
str += 'contents are the components root object; ';
if (flag & TF_STATUS_CODE)
str += 'contents are a 32-bit status code; ';
if (flag & TF_ACCEPT_FDS)
str += 'allow replies with file descriptors; ';
if (flag === NO_FLAGS)
str += 'No Flags Set';
return str;
}
function isReplyToOrigin(calling, called) {
return (called.dest_proc === calling.calling_pid ||
called.dest_thread === calling.calling_pid);
}
function binderCodeToHuman(code) {
return 'Java Layer Dependent';
}
function doInternalSlice(trans, slice, ts) {
if (slice.subSlices.length !== 0) {
/* We want to make sure we keep moving the small slice to the end of
the big slice or else the arrows will not point to the end.
*/
slice.subSlices[0].start = ts;
return slice.subSlices[0];
}
var kthread = trans.calling_kthread.thread;
var internal_slice = kthread.sliceGroup.pushCompleteSlice('binder',
slice.title,
ts, .001, 0, 0,
slice.args);
internal_slice.title = slice.title;
internal_slice.id = slice.id;
internal_slice.colorId = slice.colorId;
slice.subSlices.push(internal_slice);
return internal_slice;
}
function generateBinderArgsForSlice(trans, c_threadName) {
return {
'Transaction Id': trans.transaction_key,
'Destination Node': trans.dest_node,
'Destination Process': trans.dest_proc,
'Destination Thread': trans.dest_thread,
'Destination Name': c_threadName,
'Reply transaction?': trans.is_reply_transaction,
'Flags': trans.flags + ' ' +
binderFlagsToHuman(trans.flags),
'Code': trans.code + ' ' +
binderCodeToHuman(trans.code),
'Calling PID': trans.calling_pid,
'Calling tgid': trans.calling_kthread.thread.parent.pid
};
}
/** @constructor */
function BinderTransaction(events, calling_pid, calling_ts, calling_kthread) {
this.transaction_key = parseInt(events[1]);
this.dest_node = parseInt(events[2]);
this.dest_proc = parseInt(events[3]);
this.dest_thread = parseInt(events[4]);
this.is_reply_transaction = parseInt(events[5]) === 1 ? true : false;
this.expect_reply = ((this.is_reply_transaction === false) &&
(parseInt(events[6], 16) & TF_ONE_WAY) === 0);
this.flags = events[6];
this.code = events[7];
this.calling_pid = calling_pid;
this.calling_ts = calling_ts;
this.calling_kthread = calling_kthread;
}
/** @constructor */
function BinderParser(importer) {
Parser.call(this, importer);
importer.registerEventHandler('binder_locked',
BinderParser.prototype.
binderLocked.bind(this));
importer.registerEventHandler('binder_unlock',
BinderParser.prototype.
binderUnlock.bind(this));
importer.registerEventHandler('binder_lock',
BinderParser.prototype.binderLock.bind(this));
importer.registerEventHandler('binder_transaction',
BinderParser.prototype.
binderTransaction.bind(this));
importer.registerEventHandler('binder_transaction_received',
BinderParser.prototype.
binderTransactionReceived.bind(this));
this.model_ = importer.model;
this.kthreadlookup = {};
this.importer_ = importer;
this.transWaitingRecv = {};
this.syncTransWaitingCompletion = {};
this.recursiveSyncTransWaitingCompletion_ByPID = {};
this.receivedTransWaitingConversion = {};
}
BinderParser.prototype = {
__proto__: Parser.prototype,
binderLock: function(eventName, cpuNumber, pid, ts, eventBase) {
var tgid = parseInt(eventBase.tgid);
this.doNameMappings(pid, tgid, eventName.threadName);
var kthread = this.importer_.
getOrCreateBinderKernelThread(eventBase.threadName, tgid, pid);
kthread.binderAttemptLockTS = ts;
kthread.binderOpenTsA = ts;
return true;
},
binderLocked: function(eventName, cpuNumber, pid, ts, eventBase) {
var binder_thread = isBinderThread(eventBase.threadName);
var tgid, name;
var as_slice;
var need_push = false;
var kthread, rthread;
tgid = parseInt(eventBase.tgid);
name = eventBase.threadName;
kthread = this.importer_.
getOrCreateBinderKernelThread(eventBase.threadName, tgid, pid);
this.doNameMappings(pid, tgid, name);
rthread = kthread.thread;
kthread.binderLockAquiredTS = ts;
if (kthread.binderAttemptLockTS === undefined)
return false;
var args = this.generateArgsForSlice(tgid, pid, name, kthread);
rthread.sliceGroup.pushCompleteSlice('binder', 'binder lock waiting',
kthread.binderAttemptLockTS,
ts - kthread.binderAttemptLockTS,
0, 0, args);
kthread.binderAttemptLockTS = undefined;
return true;
},
binderUnlock: function(eventName, cpuNumber, pid, ts, eventBase) {
var tgid = parseInt(eventBase.tgid);
var kthread = this.importer_.
getOrCreateBinderKernelThread(
eventBase.threadName, tgid, pid);
if (kthread.binderLockAquiredTS === undefined)
return false;
args = this.generateArgsForSlice(tgid, pid, eventBase.threadName,
kthread);
kthread.thread.sliceGroup.pushCompleteSlice(
'binder',
'binder lock held',
kthread.binderLockAquiredTS,
ts - kthread.binderLockAquiredTS,
0, 0, args);
kthread.binderLockAquiredTS = undefined;
return true;
},
/** There are a few transaction status changes that signify
* progress through a binder transaction:
*
* Case One: Sync transaction.
* Thread A calls a blocking function on Thread B. We receive a
* binder_transaction msg From thread A stating that it is going to Call
* thread B. We create a slice and a binder object for this transaction and
* add it to addTransactionWaitingForRecv(transaction key, binder object)
* This notifies thread B and passes the slice, binder object and time
* stamp.
*
* Case Two: Async transaction.
* Thread A calls an async function on Thread B. Like above we receive a
* binder_transaction message, but the flags differ from above. The
* TF_ONEWAY flags are set so we know that when Thread B gets the
* binder_transaction_received with the same transaciton key the total
* transaction is complete.
*
* Case Three: 'Prior_receive'
* Prior_receive occurs when the thread being called (think A calls B),
* receives a binder_transaction_received message, but cannot correlate it
* to any current outstanding recursive transactions. That means the
* message it just received is the start of some communication, not some
* ongoing communication.
* Once the execution flow has been passed to thread B, from A:
* Thread B enters binder_transaction_received() we see that Thread A
* had notified us that it sent us a message by calling
* getTransactionWaitingForRecv(transaction key);
* What can happen now is either this was a simple Call reply,
* or this is a call -> recursion -> reply. We call modelPriorReceive()
* which sets up the slices accordingly.
* If this is a call -> recursion -> reply
* we will go to case 4 by calling addRecursiveSyncTransNeedingCompletion()
* The function takes B's PID, the binder object from A and the current
* binder object from B. This function adds outstanding non-complete
* transactions to a stack on thread B.
*
* Case Four: 'recursive_trans'
* This case follows Like above:
* A sent binder_transaction
* B got binder_transaction_received
* B instead of replying to A can Call C or call 'into' A, ie recursion
* Case four also deals with setting up a large slice to 'contain'
* all the recursive transactions that happen until B finally replies to
* A.
*
*
* An example: A-> B-> C-> B-> A
*
* (1) A starts a synchronous transaction to B.
* (2) A enters binderTransaction() event handler, hits the else statement
* (3) A calls addTransactionWaitingForRecv(trans key, object) to notify
* Thread B.
* (4) B Enters binderTransactionReceived().
* (5) B hits the second if after calling
* getTransactionWaitingForRecv(trans key)
* This function returns us the object set up in step (3).
* (6) This is not an async transaction, B calls
* setCurrentReceiveOnPID(B's PID, [ts for (4), object from (3)]).
*
* (7) B enters binderTransaction() event handler, first if triggers after
* calling getPriorReceiveOnPID(B's PID) the tuple from (6) is returned.
*
* (8) Execution enters modelPriorReceive().
* (8a) A slice is setup for this binder transaction in B's timeline.
* (9) This is not a reply to thread A, B is going to call Thread C.
* (10) else statement is hit.
* (11) We set the tile from (8a) to be binder_reply this is the
* 'containg slice' for the recursion
* (12) We create a new slice 'binder_transaction' this slice is the
* recursive slice that will have arrows to Thread C's slice.
* (13) addRecursiveSyncTransNeedingCompletion(B's PID,
* [obj from (3), obj from 7])
* this sets up notification that B's pid has outstanding recursive
* transactions that need to be completed.
* (14) B notifies C that a transaction is waiting for it by calling
* addTransactionWaitingForRecv like in step (3).
* (15) C enters binderTransactionReceived() step 5 6 7 8 8a happen, but in
* the context of Thread C.
* (16) C is in modelPriorReceive(), it hits the first if statement,
* this transaction _IS_ a reply, and it is a reply to B.
* (17) C calls addSyncTransNeedingCompletion(trans key,
* [object from(3), object from 15-5])
* (18) B enters binderTransactionReceived() hits the first if after calling
* getSyncTransNeedingCompletion(trans key from (17)) the tuple from
* (17) gets returned.
*
* (19) B scales up the slice created in (12) and sets up flows from 15-8a
* slice.
* (20) B enters BinderTransaction() event handler and the second if is hit
* after calling getRecursiveTransactionNeedingCompletion(B's pid).
* (21) modelRecursiveTransactions() gets called, first if executes.
* (22) slice durations are fixed up.
* (23) B notifies A via
* addSyncTransNeedingCompletion(trans key, binder obj from 8a).
* (24) B deletes the outstanding asynctrans via
( removeRecursiveTransaction(B's pid).
* (25) A enters binderTransactionReceived() event handler and finishes up
* some flows, and slices.
*/
binderTransaction: function(eventName, cpuNumber, pid, ts, eventBase) {
var event = binderTransRE.exec(eventBase.details);
if (event === undefined)
return false;
var tgid = parseInt(eventBase.tgid);
this.doNameMappings(pid, tgid, eventBase.threadName);
var kthread;
kthread = this.importer_.
getOrCreateBinderKernelThread(eventBase.threadName, tgid, pid);
var trans = new BinderTransaction(event, pid, ts, kthread);
var args = generateBinderArgsForSlice(trans, eventBase.threadName);
/**
* This thread previously ack'd the transaction with a
* transaction_received. That means someone sent us a message we processed
* it and are now sending a transaction.
* The transaction could be a response, or it could be recursive.
*/
var prior_receive = this.getPriorReceiveOnPID(pid);
if (prior_receive !== false) {
return this.modelPriorReceive(prior_receive, ts, pid, tgid, kthread,
trans, args, event);
}
/**
* This Thread has an already established recursive slice. We will now
* either complete the entire transaction, OR do more recursive calls.
*/
var recursive_trans = this.getRecursiveTransactionNeedingCompletion(pid);
if (recursive_trans !== false)
return this.modelRecursiveTransactions(recursive_trans, ts, pid,
kthread, trans, args);
/**
* Start of a Transaction. This thread is the initiator of either a call
* response, an async call -> ack, or a call -> recursion -> response.
* Note, we put a fake duration into this slice and patch it up later.
*/
var slice = kthread.thread.sliceGroup.pushCompleteSlice('binder',
'', ts, .03, 0, 0, args);
slice.colorId = tr.ui.b.
getColorIdForGeneralPurposeString(ts.toString());
trans.slice = slice;
if (trans.expect_reply)
slice.title = 'binder transaction';
else
slice.title = 'binder transaction async';
this.addTransactionWaitingForRecv(trans.transaction_key, trans);
return true;
},
binderTransactionReceived: function(eventName, cpuNumber, pid, ts,
eventBase) {
var event = binderTransReceivedRE.exec(eventBase.details);
if (event === undefined)
return false;
var transactionkey = parseInt(event[1]);
var tgid = parseInt(eventBase.tgid);
var kthread;
kthread = this.importer_.
getOrCreateBinderKernelThread(eventBase.threadName, tgid, pid);
var syncComplete = this.getSyncTransNeedsCompletion(transactionkey);
if (syncComplete !== false) {
/* This recv is the completion of a synchronous transaction.
* We need to scale the slice up to the current ts and finish
* creating some flows.
*/
var sync_trans = syncComplete[0];
var sync_slice = sync_trans.slice;
var response_trans = syncComplete[1];
var response_slice = response_trans.slice;
sync_slice.duration = ts - sync_slice.start;
/** These calls are a little hack that places a very small slice at
* the end of the sync slice and the response slice. This allows us
* to hook flow events (arrows) from the start to the end of the
* slices.
*/
var sync_internal = doInternalSlice(sync_trans, sync_slice, ts);
var response_ts = response_slice.start + response_slice.duration;
var response_internal = doInternalSlice(response_trans,
response_slice, response_ts);
if (response_slice.outFlowEvents.length === 0 ||
sync_slice.inFlowEvents.length === 0) {
var flow = this.generateFlow(response_internal, sync_internal,
response_trans, sync_trans);
sync_slice.inFlowEvents.push(flow);
response_slice.outFlowEvents.push(flow);
this.model_.flowEvents.push(flow);
}
// Move flow arrows -- but not the first one.
for (var i = 1; i < sync_slice.inFlowEvents.length; i++) {
sync_slice.inFlowEvents[i].duration =
ts - sync_slice.inFlowEvents[i].start;
}
return true;
}
var tr_for_recv = this.getTransactionWaitingForRecv(transactionkey);
if (tr_for_recv !== false) {
if (!tr_for_recv.expect_reply) {
// This is an async call place an Async slice.
var args = generateBinderArgsForSlice(tr_for_recv,
eventBase.threadName);
var slice = kthread.thread.sliceGroup.
pushCompleteSlice('binder',
'binder Async recv',
ts, .03, 0, 0,
args);
var fake_event = [0, 0, 0, 0, 0, 0, 0];
var fake_trans = new BinderTransaction(fake_event, pid, ts, kthread);
var flow = this.generateFlow(tr_for_recv.slice, slice,
tr_for_recv, fake_trans);
this.model_.flowEvents.push(flow);
tr_for_recv.slice.title = 'binder transaction async';
tr_for_recv.slice.duration = .03;
return true;
}
// Setup prior receive.
tr_for_recv.slice.title = 'binder transaction';
this.setCurrentReceiveOnPID(pid, [ts, tr_for_recv]);
return true;
}
/** This case is when we received an ack for a transaction we have
* never seen before. This usually happens at the start of a trace.
* We will get incomplete transactions that started before started
* tracing. Just discard them.
*/
return false;
},
// helper functions
modelRecursiveTransactions: function(recursive_trans, ts, pid, kthread,
trans, args) {
var recursive_slice = recursive_trans[1].slice;
var orig_slice = recursive_trans[0].slice;
recursive_slice.duration = ts - recursive_slice.start;
trans.slice = recursive_slice;
if (trans.is_reply_transaction) {
/* Case one:
* This transaction is finally the reply of the recursion.
*/
orig_slice.duration = ts - orig_slice.start;
this.addSyncTransNeedingCompletion(trans.transaction_key,
recursive_trans);
if (isReplyToOrigin(recursive_trans[0], trans))
this.removeRecursiveTransaction(pid);
} else {
/**
* Case two:
* This transaction is more recursive calls.
* This is a nested call within an already started transaction,
* it can either be a async or a normal sync transaction.
*/
var slice = kthread.thread.sliceGroup.pushCompleteSlice('binder',
'' , ts, .03, 0,
0, args);
trans.slice = slice;
this.addTransactionWaitingForRecv(trans.transaction_key, trans);
}
return true;
},
modelPriorReceive: function(prior_receive, ts, pid, tgid, kthread, trans,
args, event) {
var callee_slice = prior_receive[1].slice;
var callee_trans = prior_receive[1];
var recv_ts = prior_receive[0];
var slice = kthread.thread.sliceGroup.pushCompleteSlice('binder',
'', recv_ts, ts - recv_ts, 0, 0, args);
var flow = this.generateFlow(callee_slice, slice, callee_trans, trans);
this.model_.flowEvents.push(flow);
trans.slice = slice;
if (trans.is_reply_transaction) {
/* This is a response to a synchronous or a recursive sync
* transaction.
*/
slice.title = 'binder reply';
/* Notify this transaction key that when it recv's it is completing
* a sync transaction.
*/
this.addSyncTransNeedingCompletion(trans.transaction_key,
[callee_trans, trans]);
} else {
/**
* Recursive calls and or calls around, either way it's not
* going to complete a transaction.
*/
slice.title = 'binder reply';
/* Since this is a recursive transaction we want to create the main
* large slice which will contain all these recursive transactions.
* For that we created the main slice above and this is a recursive
* transaction that will be placed right below it. Note, that this
* is only for the first recursive transaction. If more come they will
* be handled below in the getRecursiveTransactionNeedingCompletion
*/
var trans1 = new BinderTransaction(event, pid, ts, kthread);
slice = kthread.thread.sliceGroup.
pushCompleteSlice('binder',
'binder transaction',
recv_ts,
(ts - recv_ts), 0,
0, args);
/* could be a async trans if so set the length to be a small one */
if (!trans.expect_reply) {
slice.title = 'binder transaction async';
slice.duration = .03;
} else {
/* stupid hack to stop merging of AIDL slices and
* this slice. This is currently disabled, if AIDL tracing is on we
* will see merging of this slice and the AIDL slice. Once upstream
* has a solution for flow events to be placed in the middle of
* slices this part can be fixed.
*
* This is commented out because AIDL tracing doesn't exit yet.
*/
//slice.start += .15;
}
trans1.slice = slice;
this.addRecursiveSyncTransNeedingCompletion(pid,
[callee_trans, trans]);
this.addTransactionWaitingForRecv(trans.transaction_key, trans1);
}
return true;
},
getRecursiveTransactionNeedingCompletion: function(pid) {
if (this.recursiveSyncTransWaitingCompletion_ByPID[pid] === undefined)
return false;
var len = this.recursiveSyncTransWaitingCompletion_ByPID[pid].length;
if (len === 0)
return false;
return this.recursiveSyncTransWaitingCompletion_ByPID[pid][len - 1];
},
addRecursiveSyncTransNeedingCompletion: function(pid, tuple) {
if (this.recursiveSyncTransWaitingCompletion_ByPID[pid] === undefined)
this.recursiveSyncTransWaitingCompletion_ByPID[pid] = [];
this.recursiveSyncTransWaitingCompletion_ByPID[pid].push(tuple);
},
removeRecursiveTransaction: function(pid) {
var len = this.recursiveSyncTransWaitingCompletion_ByPID[pid].length;
if (len === 0) {
delete this.recursiveSyncTransWaitingCompletion_ByPID[pid];
return;
}
this.recursiveSyncTransWaitingCompletion_ByPID[pid].splice(len - 1, 1);
},
setCurrentReceiveOnPID: function(pid, tuple) {
if (this.receivedTransWaitingConversion[pid] === undefined) {
this.receivedTransWaitingConversion[pid] = [];
}
this.receivedTransWaitingConversion[pid].push(tuple);
},
getPriorReceiveOnPID: function(pid) {
if (this.receivedTransWaitingConversion[pid] === undefined)
return false;
var len = this.receivedTransWaitingConversion[pid].length;
if (len === 0)
return false;
return this.receivedTransWaitingConversion[pid].splice(len - 1, 1)[0];
},
addSyncTransNeedingCompletion: function(transactionkey, tuple) {
var dict = this.syncTransWaitingCompletion;
dict[transactionkey] = tuple;
},
getSyncTransNeedsCompletion: function(transactionkey) {
var ret = this.syncTransWaitingCompletion[transactionkey];
if (ret === undefined)
return false;
delete this.syncTransWaitingCompletion[transactionkey];
return ret;
},
getTransactionWaitingForRecv: function(transactionkey) {
var ret = this.transWaitingRecv[transactionkey];
if (ret === undefined)
return false;
delete this.transWaitingRecv[transactionkey];
return ret;
},
addTransactionWaitingForRecv: function(transactionkey, transaction) {
this.transWaitingRecv[transactionkey] = transaction;
},
generateFlow: function(from, to, from_trans, to_trans) {
var title = 'Transaction from : ' +
this.pid2name(from_trans.calling_pid) +
' From PID: ' + from_trans.calling_pid + ' to pid: ' +
to_trans.calling_pid +
' Thread Name: ' + this.pid2name(to_trans.calling_pid);
var ts = from.start;
var flow = new tr.model.FlowEvent('binder', ts, title, 1, ts, []);
flow.startSlice = from;
flow.endSlice = to;
flow.start = from.start;
flow.duration = to.start - ts;
flow.colorId = 1;
from.outFlowEvents.push(flow);
to.inFlowEvents.push(flow);
return flow;
},
generateArgsForSlice: function(tgid, pid, name, kthread) {
return {
'Thread Name': name,
'pid': pid,
'gid': tgid
};
},
pid2name: function(pid) {
return this.kthreadlookup[pid];
},
doNameMappings: function(pid, tgid, name) {
this.registerPidName(pid, name);
this.registerPidName(tgid, name);
},
registerPidName: function(pid, name) {
if (this.pid2name(pid) === undefined)
this.kthreadlookup[pid] = name;
}
};
Parser.register(BinderParser);
return {
BinderParser: BinderParser
};
});
</script>