More than 36% overhead running tests for dbus interface in snap with devmode confinement

[Sergio Cazzolato]

I am running some performance tests in ubuntu classic, focused on dbus interface.

Those tests are generating 20000 signals using and spammer and calculating the time a handler takes to receive all of them. The tests don't involve any launch time due to it is calculated from the 1st signal arrives to the handler, up the the last one is received.

I am executing it in real hardware, and those are executed in python mode (running the tests with python3 command) and the same tests inside a snap (which has a wrapper to call the python tests).

The metrics retrieved is the number of messages by seconds.

The results obtained after more than 20 days of executions is that when the tests are called directly through python3 command, it is being sent in average more than the 35% of messages by second than the ones included in the snap.

These results are obtained installing the snap with --devmode. In case the --devmode is not used the overhead is in range (15-20%)

The last 4 run show the following numbers:
SNAP: 5.25K PYTHON: 6.9K ==> 31% overhead
SNAP: 5.16K PYTHON: 7.1K ==> 37% overhead
SNAP: 5.07K PYTHON: 6.9K ==> 38% overhead
SNAP: 5.88K PYTHON: 9.4K ==> 60% overhead

An extra analysis was done to see if python could produce part of this overhead, but the results have shown that python is not adding any overhead. See results in section Snap python plugin times section at: https://platform-qa-dashboard.canonical.com/dashboard/db/kpi-zesty-dashboard

See section "Snap dbus interface times section" at:
https://platform-qa-dashboard.canonical.com/dashboard/db/kpi-zesty-dashboard

The tests are here:
SNAP:
 - http://bazaar.launchpad.net/~sergio-j-cazzolato/ubuntu-performance-tests/trunk/files/head:/resources/apps/kpi-dbus-tests/
SCRIPTS:
 - http://bazaar.launchpad.net/~sergio-j-cazzolato/ubuntu-performance-tests/trunk/view/head:/resources/scripts/dbus_signal_handler.py
 - http://bazaar.launchpad.net/~sergio-j-cazzolato/ubuntu-performance-tests/trunk/view/head:/resources/scripts/dbus_signal_spammer.py
 - http://bazaar.launchpad.net/~sergio-j-cazzolato/ubuntu-performance-tests/trunk/view/head:/resources/scripts/dbus_signal_test.py

[Zygmunt Krynicki (zyga)]

I've assigned this to snapd but I think the real overhead is in the kernel apparmor stack.

[Oliver Grawert (ogra)]

this is very typical and has been seen before (i cant find the other older bugs though, but we had a few)

if you run an app in --devmode and do not connect the interfaces, journald produces a lot of load being busy to write ALLOWED messages to the log ... typically just connecting the interface (without dropping --devmode) solves this ...