27
Jan 15

examples of poor API design, 1/N – pldhash functions

The other day in the #content IRC channel:

<bz> I have learned so many things about how to not define APIs in my work with Mozilla code ;)
<bz> (probably lots more to learn, though)

I, too, am still learning a lot about what makes a good API. Like a lot of other things, it’s easier to point out poor API design than to describe examples of good API design, and that’s what this blog post is about. In particular, the venerable XPCOM datastructure PLDHashTable has been undergoing a number of changes lately, all aimed at bringing it up to date. (The question of why we have our own implementations of things that exist in the C++ standard library is for a separate blog post.)

The whole effort started with noticing that PL_DHashTableOperate is not a well-structured API. It’s necessary to quote some more of the API surface to fully understand what’s going on here:

typedef enum PLDHashOperator {
    PL_DHASH_LOOKUP = 0,        /* lookup entry */
    PL_DHASH_ADD = 1,           /* add entry */
    PL_DHASH_REMOVE = 2,        /* remove entry, or enumerator says remove */
    PL_DHASH_NEXT = 0,          /* enumerator says continue */
    PL_DHASH_STOP = 1           /* enumerator says stop */
} PLDHashOperator;

typedef PLDHashOperator
(* PLDHashEnumerator)(PLDHashTable *table, PLDHashEntryHdr *hdr, uint32_t number,
                      void *arg);

uint32_t
PL_DHashTableEnumerate(PLDHashTable *table, PLDHashEnumerator etor, void *arg);

PLDHashEntryHdr*
PL_DHashTableOperate(PLDHashTable* table, const void* key, PLDHashOperator op);

(PL_DHashTableOperate no longer exists in the tree due to other cleanup bugs; the above is approximately what it looked like at the end of 2014.)

There are several problems with the above slice of the API:

  • PL_DHashTableOperate(table, key, PL_DHASH_ADD) is a long way to spell what should have been named PL_DHashTableAdd(table, key)
  • There’s another problem with the above: it’s making a runtime decision (based on the value of op) about what should have been a compile-time decision: this particular call will always and forever be an add operation. We shouldn’t have the (admittedly small) runtime overhead of dispatching on op. It’s worth noting that compiling with LTO and a quality inliner will remove that runtime overhead, but we might as well structure the code so non-LTO compiles benefit and the code at callsites reads better.
  • Given the above definitions, you can say PL_DHashTableOperate(table, key, PL_DHASH_STOP) and nothing will complain. The PL_DHASH_NEXT and PL_DHASH_STOP values are really only for a function of type PLDHashEnumerator to return, but nothing about the above definition enforces that in any way. Similarly, you can return PL_DHASH_LOOKUP from a PLDHashEnumerator function, which is nonsensical.
  • The requirement to always return a PLDHashEntryHdr* from PL_DHashTableOperate means doing a PL_DHASH_REMOVE has to return something; it happens to return nullptr always, but it really should return void. In a similar fashion, PL_DHASH_LOOKUP always returns a non-nullptr pointer (!); one has to check PL_DHASH_ENTRY_IS_{FREE,BUSY} on the returned value. The typical style for an API like this would be to return nullptr if an entry for the given key didn’t exist, and a non-nullptr pointer if such an entry did. The free-ness or busy-ness of a given entry should be a property entirely internal to the hashtable implementation (it’s possible that some scenarios could be slightly more efficient with direct access to the busy-ness of an entry).

We might infer corresponding properties of a good API from each of the above issues:

  • Entry points for the API produce readable code.
  • The API doesn’t enforce unnecessary overhead.
  • The API makes it impossible to talk about nonsensical things.
  • It is always reasonably clear what return values from API functions describe.

Fixing the first two bulleted issues, above, was the subject of bug 1118024, done by Michael Pruett. Once that was done, we really didn’t need PL_DHashTableOperate, and removing PL_DHashTableOperate and related code was done in bug 1121202 and bug 1124920 by Michael Pruett and Nicholas Nethercote, respectively. Fixing the unusual return convention of PL_DHashTableLookup is being done in bug 1124973 by Nicholas Nethercote. Maybe once all this gets done, we can move away from C-style PL_DHashTable* functions to C++ methods on PLDHashTable itself!

Next time we’ll talk about the actual contents of a PL_DHashTable and how improvements have been made there, too.


07
Jan 15

profiling for wakeups on osx

One of my Q1 goals is to investigate what can be done for cross-platform power profiling, in service of the Firefox Platform’s Project Candle.  Roberto Vitillo already did a bit of exploration in this space last year.  Ideally, what would come out of my research would be some sort of event counter that we could hook into the Gecko Profiler.  Failing that, it would at least be good to document what is possible for power profiling on each of our supported platforms.

The only power profiling tool I was at all familiar with was powertop. I thought I’d start by figuring out if there was any rough equivalent on OS X.  Turns out there is; it’s called powermetrics.  You can simply run:

$ sudo powermetrics

at a Terminal prompt and you will periodically (every five seconds by default) see a large amount of information concerning power usage printed.  The default data sources that powermetrics draws from includes things like detailed C-state usage for all available processors.  For my purposes, I’m just interested in what applications are waking up most frequently.  powermetrics supports limiting its data sources with the –samplers switch:

$ sudo powermetrics --samplers tasks

will just display interesting information on all currently running tasks in the system.  You might think of it as a more detailed version of Activity Monitor’s Energy tab, and indeed, you can convince powermetrics to output the “Energy Impact” number found in Activity Monitor:

$ sudo powermetrics --samplers tasks --show-process-energy

The numbers from powermetrics don’t match up exactly with the numbers from Activity Monitor; I’m guessing that the impact of kernel_task (seen in powermetrics) is somehow spread among applications calling into the kernel by Activity Monitor. Or Activity Monitor is aggregating energy usage over a longer time period than every five seconds.

Knowing that your application is waking up rather often is helpful (Firefox is waking up ~once a second while I’m writing this), but even more helpful is where the wakeups are coming from.  The easiest way I know of for finding that information is to use dtrace:

$ sudo dtrace -n 'mach_kernel::wakeup { @[ustack()] = count(); }'

It’s worth breaking down what’s going on in the above.

  1. The mach_kernel::wakeup bit selects a probe point in dtrace parlance.  mach_kernel is the “module name” and wakeup is the “probe name”.  You can see a complete list of probes by running sudo dtrace -l.
  2. The bits between the braces are the actions to run when the probe point is hit.  In our example, we’re counting unique stack traces when wakeups occur; ustack is short for “user stack”, i.e. the stack of the userspace program executing.

(dtrace is a pretty snazzy tool; it’s worth checking out Brendan Gregg’s DTrace Tools or FreeBSD’s DTrace tutorial if you’re at all interested by the above script.)

Running the above on my system for several seconds gives stack traces like the following:

              libsystem_kernel.dylib`mach_msg_trap+0xa
              CoreFoundation`CFRunLoopWakeUp+0xab
              XUL`nsAppShell::ScheduleNativeEventCallback()+0x3c
              XUL`non-virtual thunk to nsBaseAppShell::OnDispatchedEvent(nsIThreadInternal*)+0x26
              XUL`nsThread::PutEvent(nsIRunnable*, nsThread::nsNestedEventTarget*)+0x95
              XUL`nsTimerImpl::PostTimerEvent(already_AddRefed)+0x229
              XUL`TimerThread::Run()+0x283
              XUL`nsThread::ProcessNextEvent(bool, bool*)+0x3d8
              XUL`NS_ProcessNextEvent(nsIThread*, bool)+0x35
              XUL`mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*)+0x11b
              XUL`MessageLoop::Run()+0x4d
              XUL`nsThread::ThreadFunc(void*)+0x15b
              libnss3.dylib`_pt_root+0xda
              libsystem_pthread.dylib`_pthread_body+0x83
              libsystem_pthread.dylib`_pthread_body
              libsystem_pthread.dylib`thread_start+0xd
               90

              libsystem_kernel.dylib`__psynch_cvsignal+0xa
              libnss3.dylib`pt_PostNotifies+0xb8
              libnss3.dylib`PR_Unlock+0x4e
              XUL`nsTimerImpl::InitCommon(unsigned int, unsigned int)+0x1f7
              XUL`mozilla::PreciseRefreshDriverTimer::ScheduleNextTick(mozilla::TimeStamp)+0x215
              XUL`mozilla::RefreshDriverTimer::Tick()+0x35
              XUL`nsTimerImpl::Fire()+0x3e5
              XUL`nsTimerEvent::Run()+0xf9
              XUL`nsThread::ProcessNextEvent(bool, bool*)+0x3d8
              XUL`NS_ProcessPendingEvents(nsIThread*, unsigned int)+0x51
              XUL`nsBaseAppShell::NativeEventCallback()+0x77
              XUL`nsAppShell::ProcessGeckoEvents(void*)+0x132
              CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__+0x11
              CoreFoundation`__CFRunLoopDoSources0+0x10d
              CoreFoundation`__CFRunLoopRun+0x39f
              CoreFoundation`CFRunLoopRunSpecific+0x128
              HIToolbox`RunCurrentEventLoopInMode+0xeb
              HIToolbox`ReceiveNextEventCommon+0x1af
              HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter+0x47
              AppKit`_DPSNextEvent+0x3c4
              154

              libsystem_kernel.dylib`mach_msg_trap+0xa
              CoreGraphics`_CGSEventAppUnresponsiveStatus+0x79
              CoreGraphics`CGSEventAppUnresponsiveStatus+0x38
              CoreGraphics`CGSEventIsAppUnresponsive+0x13
              Activity Monitor`0x000000010e918bd1+0xa76
              Activity Monitor`0x000000010e9038c8+0x141
              libsysmon.dylib`sysmon_table_apply+0x28
              Activity Monitor`0x000000010e9032df+0x231
              Activity Monitor`0x000000010e90a156+0x192
              libdispatch.dylib`_dispatch_client_callout+0x8
              libdispatch.dylib`_dispatch_barrier_sync_f_invoke+0x39
              Activity Monitor`0x000000010e90a09b+0x91
              libsysmon.dylib`__sysmon_request_execute_block_invoke_2+0xe0
              libxpc.dylib`_xpc_connection_call_event_handler+0x3a
              libxpc.dylib`_xpc_connection_mach_event+0x76d
              libdispatch.dylib`_dispatch_client_callout4+0x9
              libdispatch.dylib`_dispatch_mach_msg_invoke+0x1bd
              libdispatch.dylib`_dispatch_queue_drain+0x23b
              libdispatch.dylib`_dispatch_mach_invoke+0xe8
              libdispatch.dylib`_dispatch_queue_drain+0x23b
              176

              libsystem_kernel.dylib`mach_msg_trap+0xa
              CoreFoundation`CFRunLoopWakeUp+0xab
              XUL`nsAppShell::ScheduleNativeEventCallback()+0x3c
              XUL`non-virtual thunk to nsBaseAppShell::OnDispatchedEvent(nsIThreadInternal*)+0x26
              XUL`nsThread::PutEvent(nsIRunnable*, nsThread::nsNestedEventTarget*)+0x95
              XUL`nsTimerImpl::PostTimerEvent(already_AddRefed)+0x229
              XUL`TimerThread::Run()+0x283
              XUL`nsThread::ProcessNextEvent(bool, bool*)+0x3d8
              XUL`NS_ProcessNextEvent(nsIThread*, bool)+0x35
              XUL`mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*)+0xac
              XUL`MessageLoop::Run()+0x4d
              XUL`nsThread::ThreadFunc(void*)+0x15b
              libnss3.dylib`_pt_root+0xda
              libsystem_pthread.dylib`_pthread_body+0x83
              libsystem_pthread.dylib`_pthread_body
              libsystem_pthread.dylib`thread_start+0xd
              177

              libsystem_kernel.dylib`__psynch_cvbroad+0xa
              libnss3.dylib`PR_Interrupt+0x37
              XUL`mozilla::HangMonitor::NotifyActivity(mozilla::HangMonitor::ActivityType)+0xe0
              XUL`nsThread::ProcessNextEvent(bool, bool*)+0x3ce
              XUL`NS_ProcessPendingEvents(nsIThread*, unsigned int)+0x51
              XUL`nsBaseAppShell::NativeEventCallback()+0x77
              XUL`nsAppShell::ProcessGeckoEvents(void*)+0x132
              CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__+0x11
              CoreFoundation`__CFRunLoopDoSources0+0x10d
              CoreFoundation`__CFRunLoopRun+0x39f
              CoreFoundation`CFRunLoopRunSpecific+0x128
              HIToolbox`RunCurrentEventLoopInMode+0xeb
              HIToolbox`ReceiveNextEventCommon+0x1af
              HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter+0x47
              AppKit`_DPSNextEvent+0x3c4
              AppKit`-[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]+0xc2
              XUL`-[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]+0x56
              AppKit`-[NSApplication run]+0x252
              XUL`nsAppShell::Run()+0xfd
              XUL`nsAppStartup::Run()+0x29
              201

              libsystem_kernel.dylib`mach_msg_overwrite_trap+0xa
              CoreGraphics`CGXRunOneServicesPass+0x282
              CoreGraphics`CGXServer+0x347
              WindowServer`DYLD-STUB$$CGXServer
              libdyld.dylib`start+0x1
              WindowServer`0x2
              219

You can see that timers going off in Firefox are a major source of wakeups (those are the stacks with TimerThread::Run() in them).

Even with stacks causing wakeups, it’s not always obvious what sequence of events leads to those wakeups; this is especially true in the e10s era, where a particular stack ending in an IPC message send might only give you half of the picture.  Figuring that puzzle out will help solve problems like frequently waking up when animating images with CSS.