TaskTracer

Introduction

TaskTracer remembers the correlation between Tasks and Runnables, across threads and processes.

By looking at a task, TaskTracer tells you:

• The “source events” of this task.
  • IO events: touch events, key events, wifi daemon signal
• Who, the other task, does create a task.
• The timing a task was dispatched, run, and stopped.

Get log files

Compile Gecko or Firefox with following line in mozconfig.

 ac_add_options --enable-tasktracer

Start logging with Gecko Profiler Addon. There is an option in the control panel of the addon to enable TaskTracer.

Attach gdb to Firefox process, the chrome process, and run following command in gdb.

 (gdb) call mozilla_sampler_save_profile_to_file_async(0.0, "/abs/to/logfile")
 (gdb) continue

Waiting for a couple seconds, the file would be created.

Dump log

 python dumplog.py /path/to/logfile

Task

A task is dispatched to a task queue at the time (in ms) given by |dispatchTime| attribute of the |Task| object. It is an array because of a runnable can be dispatched and ran for several times.

|begin| is the time that the runnable/task was started to run. |end| is the time where the task finish it's work.

 {'begin': [u'1472463888021'],
  'dispatchTime': [u'1472463888021'],
  'end': [u'1472463888021'],
  'label': [],
  'parent': u'0',
  'process': 22525,
  'sourceEventId': u'0',
  'sourceEventType': u'0',
  'taskId': u'96744138362318',
  'thread': 22525,
  'timeDuration': 0,
  'vptr': '??'},

Load log in python

 import tttools
 profileobject = tttools.loadRawProfile('/abs/to/logfile')

Parent tasks

Parent task of a task is the one create and dispatch the task. You can find the parent task, parent's parent, ... and all ancestors with the following Python instructions.

 taskIdsOfAncestors = profileobject.findAncestors(GivenTaskId)
 import pprint
 pprint.pprint(profileobject.findTasks(taskIdsOfAncestors))

Followers

Followers of a task are tasks that is created by the given task or it's followers.

 taskIdsOfFollowers = profileobject.findFollowers(GivenTaskId)
 import pprint
 pprint.pprint(profileobject.findTasks(taskIdsOfFollowers))

Blocker tasks

You can find what tasks are blocked by the different in time of |dispatchTime| and |begin|.

 tasks = profileobject.findTasks(profileobject.findAncestors(GivenTaskId))
 for task in tasks:
   queuingTIme = long(task.begin[0]) - long(task.dispatchTime[0])
   print 'task: %s, thread: %d, queuingTime: %d' % (task.taskId,
                                                    task.thread,

queuingTime)

The more time a task staying in the queue, the more time the task is blocked by other tasks. You can find what other tasks blocked a task with following instructions.

 task = profileobject.findTask(BlockedTaskId)
 blockerIds =
   profileobject.findTasksStartInTimeThread(int(task.dispatchTime[0]),
                                            int(task.begin[0]),

task.thread)

 blockers = profileobject.findTasks(blockerIds)
 pprint.pprint(blockers)

Labels

You may need to attach some information or strings on tasks and to see strings in the log to help you to identify specific tasks. Following C++ code in Gecko would add a label, i.e. a string, on the current running task of this thread.

 #ifdef MOZ_TASK_TRACER
 #include "GeckoTaskTracer.h"
 #endif
 ...
 mozilla::tasktracer::AddLabel("Event [%s] ...", str...);

Javascript adds labels with a special prefix.

 console.log("#tt# Log message"); // #tt# is the prefix.