[Smtk-developers] Attribute callback benchmarks

[David Thompson]

Hi all,

For today's followup, I've got... more exciting timings! This go-round uses the TestBit.eu simple::Signal object to track observers for each signal. Observers are called with a pointer to an smtk::attribute::EventData subclass.

b. No callbacks registered:       41 ns/call
c. With 1000 empty callbacks:   3854 ns/call
d. With 1 trivial callback:       46 ns/call
e. 1000 per-instance callbacks: 5203 ns/call

Note that there is a new time: per-instance callback (e). By specific request, I am now testing how expensive it is to use the static (per class) signal objects to invoke callbacks when an event occurs on just a single instance instead of on all instances of an Item. This also adds some syntactic sugar to make registering a callback on a single instance simple:

  // This will be called every time *any* double-item value changes:
  ItemValueChangedEvent<double>::responses() +=
    [](const ItemValueValueChangeEvent<double>*) {
      std::cout << "Message A: Something changed.\n";
    };

  // Now register a callback for one specific double-item:
  DoubleItem* itm = attribute1->findDouble("stuff");
  itm->connect(
    [attribute1](const ItemValueChangeEvent<double>*) {
      std::cout
        << "Message B: Stuff changed on attribute "
        << attribute1->name() << "\n";
    });
  itm->setValue(0, 3.1415); // Prints message A and B.

  itm = attribute2->findDouble("stuff");
  itm->setValue(0, 2.71828); // Prints only message A.

Timing (e) above creates a single attribute definition that owns 1000 items. Then, each item is given its own per-instance callback (like message B above, except that it just increments a counter instead of printing a message). Each of the 1000 items then has its value changed 1000 times (for a total of 1 million setValue calls and 1 billion callback invocations).

While registering per-instance callbacks adds a per-event cost, it is not terribly expensive and it does save us from having to store a list of observers per-instance+per-event. Which would be unsanity.

The new code is now up on the attribute-callbacks branch of https://github.com/vibraphone/SMTK.git . At some point soon, I'll write a little bit more about how we can trigger high-level events when each low-level event occurs.

	David


On Aug 17, 2015, at 2:40 PM, David Thompson <david.thompson at kitware.com> wrote:

> Hi all,
> 
> Not content with 2 followups, I have now simplified and adapted the callbacks to use the SimpleSignal header from (here)[https://testbit.eu/cpp11-signal-system-performance/].
> 
> Instead of callbacks like this:
> 
>  [](const ValueChangeEvent& event) { ... do stuff with event.item(), event.newValue(), ... }
> 
> this version expects callbacks like
> 
>  [](Item* item, int index, const double& newValue) { ... do stuff with itm, newValue, ... }
> 
> It is faster than anything else in the case where there are 0 or 1 observers, most probably because it does not construct an event object. It takes longer in the case of 1000 callbacks, most probably for the same reason. With few callbacks, the cost of constructing the event object is not amortized over enough invocations to make it worthwhile. But as more observers are added, the cost of calling each with multiple arguments containing all the callback info (thus requiring more pushes/pops to/from the stack) exceeds the cost of constructing the event:
> 
> 
> With TestBit's SimpleSignal callback code added:
> b. No callbacks registered:      34.3 +/-  0.5 nsec per setValue() call.
> c. With 1000 empty callbacks:  4124   +/- 49  nsec per setValue() call.
> d. With 1 trivial callback:      67.8 +/-  0.3 nsec per setValue() call.
> 
> In any case, it would be wise to stick with event objects so that "high-level" callbacks can accept pointers to a base event object and cast to subclasses as required.
> 
> However, I recommend using the SimpleSignal header as it provides some nice syntactic sugar and features like collectors (aggregating return values from multiple observers) and early termination based on observer return values.
> 
> The test code for these benchmarks is in the attribute-callbacks-with-simplesignal of https://github.com/vibraphone/SMTK.git .
> 
>  https://github.com/vibraphone/smtk/commits/attribute-callbacks-with-simplesignal
> 
> Please let me know if you have any comments.
> 
> I have yet to play around with shiboken wrapping for observers (so that Python observers can be registered). If I can get that working, I plan to adapt the attribute-callbacks branch to use SimpleSignals whose observers take a single pointer to a callback event object. I'll also adapt the model-system callbacks to use SimpleSignal for consistency.
> 
> 	David
> 
> On Aug 11, 2015, at 5:03 PM, David Thompson <david.thompson at kitware.com> wrote:
> 
>> Hi all,
>> 
>> In a continuing series of followups, I've been able to reduce the initial overhead of a callback to within a few nanoseconds of nothing by eliminating overhead from the construction of the event object and (following the SimpleSignal design) moving the trigger method to the event object (which then passes itself by reference to each event responder).
>> 
>> Without any changes to SMTK:
>> a. Baseline:                     131 +/-  7 nsec per setValue() call.
>> With callback code added:
>> b. No callbacks registered:      134 +/-  3 nsec per setValue() call.
>> c. With 1000 empty callbacks:   2317 +/- 17 nsec per setValue() call.
>> d. With 1 trivial callback:      142 +/-  7 nsec per setValue() call.
>> 
>> Given that I've only instrumented 3 or 4 of the 61 different events so far, there is still plenty of work to do. However, this seems to be a reasonable design.
>> 
>> The only issues left to address before working on the remaining events are
>> 
>> 1. Should we investigate a signal-slot library? This seems redundant given the low overhead of the current design.
>> 
>> 2. What is required to provide callback access to Python? Ben suggested writing a special callback that invokes a Python function (I'm guessing we would need one of these for each event type), but it's not clear to me how to integrate this with shiboken.
>> 
>> 	David
>> 
>>> On Aug 11, 2015, at 2:29 PM, David Thompson <david.thompson at kitware.com> wrote:
>>> 
>>> To follow up,
>>> 
>>> 1. The timings in my original message were from a debug build (doh!). For a release build, the ratio of time spent is similar but the times are smaller (nanoseconds not microseconds):
>>> 
>>> Without any changes to SMTK:
>>> a. Baseline:                     131 +/-  7 nsec per setValue() call.
>>> With callback code added:
>>> b. No callbacks registered:      340 +/-  6 nsec per setValue() call.
>>> c. With 1000 empty callbacks:   2533 +/- 22 nsec per setValue() call.
>>> d. With 1 trivial callback:      342 +/-  7 nsec per setValue() call.
>>> 
>>> So, subtracting the apparent per-setValue cost (340 nsec) from the 1000-empty-callback version and dividing by 1000, it looks like 2.2 nsec per callback.
>>> 
>>> 2. At least one signal-slot library I wanted to consider was SimpleSignal:
>>>  https://testbit.eu/cpp11-signal-system-performance/
>>> 
>>> 	David
>>> 
>>> On Aug 11, 2015, at 11:38 AM, David Thompson <david.thompson at kitware.com> wrote:
>>> 
>>>> Hi all,
>>>> 
>>>> I am working on adding callbacks to notify applications when attributes are changed. One of the concerns has been the overhead of callbacks on value change events, since these could conceivably happen frequently. I've done some preliminary benchmarking to quantify the cost of calling C++ lambdas each time an attribute value changes. The results are below.
>>>> 
>>>> To benchmark the timing, I create an attribute with a single DoubleItem and repeatedly change the value of the DoubleItem to a random number. The timings were done on my MacBookPro running Mac OS X 10.9.
>>>> 
>>>> Without any changes to SMTK:
>>>> 1. Baseline:                   0.355 +/- 0.01 usec per setValue() call.
>>>> With callback code added:
>>>> 2. No callbacks registered:    1.238 +/- 0.01 usec per setValue() call.
>>>> 3. With 1000 empty callbacks: 21.32  +/- 0.20 usec per setValue() call.
>>>> 4. With 1 trivial callback:    1.281 +/- 0.02 usec per setValue() call.
>>>> 
>>>> These times were averaged over 5-6 runs, with each run consisting of 1-million setValue calls (except for the version with 1000 callbacks registered, which used 100,000 setValue calls per run).
>>>> 
>>>> I have not evaluated signal/slot libraries; the callback code uses smtk::function<void(const EventType&)> to hold references to callbacks.
>>>> 
>>>> 	David
>>> 
>> 
>