Skip to content

Using systemtap to figure what your mozilla app’s event loop is up to

====================                                             ms    #
----- Event Loop:
  nsTimerEvent                                                 1233   31
  nsProxyObjectCallInfo                                          19   44
  nsStreamCopierOB                                                1   48
  nsStreamCopierIB                                                0   18
  nsProxyCallCompletedEvent                                       0   44
  nsProxyReleaseEvent                                             0   27
  nsTransportStatusEvent                                          0   19
  nsSocketEvent                                                   0   18
  nsHttpConnectionMgr::nsConnEvent                                0    1
----- Timers:
  OnBiffTimer(...)                                             1129    3
  nsGlobalWindow::TimerCallback(...)                             70   10
  nsAutoSyncManager::TimerCallback(...)                          29    6
  nsExpirationTracker::TimerCallback(...)                         1    1
  nsIdleService::IdleTimerCallback(...)                           0    5
  nsExpirationTracker::TimerCallback(...)                         0    1
  nsHttpHandler                                                   0    1
  nsUITimerCallback                                               0    2
  imgContainer::sDiscardTimerCallback(...)                        0    1
  nsExpirationTracker::TimerCallback(...)                         0    1

That’s one of the periodic outputs (10 seconds currently) of this systemtap script filtered through this python script to translate addresses to useful symbol names in realtime.  It’s like top for mozilla.

Actual invocation looks like so:
sudo stap -v moz-event-loop.stp /path/to/thunderbird/objdir/mozilla/dist/lib/libxpcom_core.so | ../addrsymfilt.py `pgrep thunderbird-bin`

The giant caveat (and giant hooray for utrace and Fedora having kernels with the utrace patches built-in) is that the magic in here is done dynamically using utrace source line probes.  As such, the probes aren’t resilient in the face of changes to the underlying source files; the current line numbers are targeted at 1.9.2.  There are various in-tree and out-of-tree solutions possible.

{ 1 } Trackback

  1. […] with gloda activity, the usual scapegoat.  With some enhancements to my systemtap script from last time, I can now see that it apparently takes something like 13 seconds of dominating the event loop to […]