Recent qrexec performance improvements

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Hi,

We've spent some time recently on improving qrexec performance,
specifically lower the overhead on making a qrexec call. To have some
visibility into effects, we started with adding simple performance
tests:
https://github.com/QubesOS/qubes-core-admin/pull/647

Here I'll focus on just one test that is making 500 calls and measure
the total time in seconds - the lower the better.

Here are the results:
baseline (qrexec 4.3.1): fedora-41-xfce_exec 53.047245962000034[1]
remove qubes-rpc-multiplexer[2] (qrexec 4.3.2): fedora-41-xfce_exec 21.449519581999994 [3]
cache system info for policy[4]: fedora-41-xfce_exec 9.012277056000016[5]

So, in total over 5x improvement :)
And also, now it can do over 50 calls per second, I'd say it's way more than
enough for its intended use.

[1] https://openqa.qubes-os.org/tests/127227/logfile?filename=system_tests-perf_test_results.txt
[2] https://github.com/QubesOS/qubes-issues/issues/9062
[3] https://openqa.qubes-os.org/tests/127864/logfile?filename=system_tests-perf_test_results.txt
[4] https://github.com/QubesOS/qubes-issues/issues/9362
[5] https://openqa.qubes-os.org/tests/128145/logfile?filename=system_tests-perf_test_results.txt

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAmenZh4ACgkQ24/THMrX
1yyvvggAiDkuuOwRbr18xaDB1T1kv0jAmXTKs5aBpofv2PeWrmtKaXxOttwBUXdz
hTTLg2cZ7NZwoIQ+rq1bNjUXHzEdK69LK5gz0xG935ir3IMM0odt+DuHEDqq4xfM
WD3H39Yasp/YD4kBDYHn04aNXjcY4Yen6HSvHKnRt7GSH1S2ukvE6P7nzU3/Yug1
oGykULvIVpnB5QcvJpc9jmjqOC1FAYCUuCahFvqxNu6RcNu9LtXl2huzslQYu+eB
EXJKy6dm/FCMAb7Bohwhfly4b8QHcPvwoUqvJxpr/Se9tuXw849TGp9JCmyY/x7X
7hun6F9xVRUeWyY91K9BpKS8r3pL9w==
=ouF4
-----END PGP SIGNATURE-----

[David Hobach]

On 2/8/25 15:11, Marek Marczykowski-Górecki wrote:
> Hi,
>
> We've spent some time recently on improving qrexec performance,
> specifically lower the overhead on making a qrexec call. To have some
> visibility into effects, we started with adding simple performance
> tests:
> https://github.com/QubesOS/qubes-core-admin/pull/647
>
> Here I'll focus on just one test that is making 500 calls and measure
> the total time in seconds - the lower the better.
>
> Here are the results:
> baseline (qrexec 4.3.1): fedora-41-xfce_exec 53.047245962000034[1]
> remove qubes-rpc-multiplexer[2] (qrexec 4.3.2): fedora-41-xfce_exec 21.449519581999994 [3]
> cache system info for policy[4]: fedora-41-xfce_exec 9.012277056000016[5]
>
> So, in total over 5x improvement :)

That sounds great and I look forward to that change. Thanks a lot in advance! :)

However for an overall improvement in user experience not only the qrexec speed is relevant, but also the time to get the qrexec service running inside a newly started VM.
For example on my machine a qrexec call on a running VM takes ~530ms (hopefully less in the future with the changes you mentioned) and one on a small non-running VM 6s, out of which the qubes-qrexec-agent.service takes 2,8s to start:
qubes-qrexec-agent.service +20ms
└─systemd-user-sessions.service @2.855s +18ms
└─network.target @2.852s
└─networking.service @2.750s +101ms
└─network-pre.target @2.732s
└─qubes-iptables.service @2.416s +315ms
└─qubes-antispoof.service @2.210s +205ms
└─basic.target @2.206s
└─sockets.target @2.206s
└─qubes-updates-proxy-forwarder.socket @2.206s
└─sysinit.target @2.187s
└─systemd-binfmt.service @1.860s +327ms
└─proc-sys-fs-binfmt_misc.mount @2.114s +69ms
└─systemd-journald.socket @1.015s
└─-.mount @984ms
└─-.slice @985ms

So improving the speed at which any of these services in the qubes-qrexec-agent.service critical chain start or possibly getting rid of dependencies entirely should improve the overall Qubes OS performance.
For example these numbers looked smaller in 4.1 on the same machine and a comparable VM [6].

[6] https://github.com/3hhh/qubes-performance/blob/master/samples/4.1/t530_debian-11_01.txt#L32-L40

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Sun, Feb 09, 2025 at 12:04:20PM +0100, David Hobach wrote:
> On 2/8/25 15:11, Marek Marczykowski-Górecki wrote:
> > Hi,
> >
> > We've spent some time recently on improving qrexec performance,
> > specifically lower the overhead on making a qrexec call. To have some
> > visibility into effects, we started with adding simple performance
> > tests:
> > https://github.com/QubesOS/qubes-core-admin/pull/647
> >
> > Here I'll focus on just one test that is making 500 calls and measure
> > the total time in seconds - the lower the better.
> >
> > Here are the results:
> > baseline (qrexec 4.3.1): fedora-41-xfce_exec 53.047245962000034[1]
> > remove qubes-rpc-multiplexer[2] (qrexec 4.3.2): fedora-41-xfce_exec 21.449519581999994 [3]
> > cache system info for policy[4]: fedora-41-xfce_exec 9.012277056000016[5]
> >
> > So, in total over 5x improvement :)
>
> That sounds great and I look forward to that change. Thanks a lot in advance! :)
>
> However for an overall improvement in user experience not only the qrexec speed is relevant, but also the time to get the qrexec service running inside a newly started VM.

The effort above is (almost) only about calls to already running VMs.

Yes, VM startup time is another thing that could use an optimization.
There are several areas that can be improved there, and indeed
systemd-analyze helps quite a bit in identifying them.

BTW for disposables specifically, we are going to cheat:
https://github.com/QubesOS/qubes-issues/issues/1512
this should get you new disposable "started" in single milliseconds
time, at the cost of some RAM.

> For example on my machine a qrexec call on a running VM takes ~530ms (hopefully less in the future with the changes you mentioned) and one on a small non-running VM 6s, out of which the qubes-qrexec-agent.service takes 2,8s to start:
> qubes-qrexec-agent.service +20ms
> └─systemd-user-sessions.service @2.855s +18ms
> └─network.target @2.852s
> └─networking.service @2.750s +101ms
> └─network-pre.target @2.732s
> └─qubes-iptables.service @2.416s +315ms
> └─qubes-antispoof.service @2.210s +205ms
> └─basic.target @2.206s
> └─sockets.target @2.206s
> └─qubes-updates-proxy-forwarder.socket @2.206s
> └─sysinit.target @2.187s
> └─systemd-binfmt.service @1.860s +327ms
> └─proc-sys-fs-binfmt_misc.mount @2.114s +69ms
> └─systemd-journald.socket @1.015s
> └─-.mount @984ms
> └─-.slice @985ms
>
> So improving the speed at which any of these services in the qubes-qrexec-agent.service critical chain start or possibly getting rid of dependencies entirely should improve the overall Qubes OS performance.

qubes-qrexec-agent.service intentionally is started rather late in the
boot process, so that user applications don't end up started in a
half-functioning system. But it also means several services are on
critical path...

> For example these numbers looked smaller in 4.1 on the same machine and a comparable VM [6].
>
> [6] https://github.com/3hhh/qubes-performance/blob/master/samples/4.1/t530_debian-11_01.txt#L32-L40
>
> > And also, now it can do over 50 calls per second, I'd say it's way more than
> > enough for its intended use.
> >
> > [1] https://openqa.qubes-os.org/tests/127227/logfile?filename=system_tests-perf_test_results.txt
> > [2] https://github.com/QubesOS/qubes-issues/issues/9062
> > [3] https://openqa.qubes-os.org/tests/127864/logfile?filename=system_tests-perf_test_results.txt
> > [4] https://github.com/QubesOS/qubes-issues/issues/9362
> > [5] https://openqa.qubes-os.org/tests/128145/logfile?filename=system_tests-perf_test_results.txt

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAmeorekACgkQ24/THMrX
1yzKdwgAiFWBXzjXLF54RArPHsb/7NbBddzZsvJo4Ov4ej7UmpiwTsHcRGIRfAyj
hal1zeDri9TbYI+xfS2TDE/WjGPrypV5LSTuZm1vorxWoilvy7LfsRuKYDOS20la
gUL66qgyXu/VlSGCLqx3T586tTlS+PXTPMWu3tWKtxylFeq5b5kZYgPq+BlTz0NE
vCo5q+pstOXgckJcZvIASqPNpNMh6BXO3xrskAGkivj9gl/WKBtYxCaFJ5bt2eO4
i7t3IIyplE2TqH8pamOIBoo9pZ6eZsQ40fhbejYQha2DCVIpmghdTDpIX0DXaxNA
YfVwGb0KO8kFA3GEVzvHYukbdVktow==
=YV/w
-----END PGP SIGNATURE-----

[Demi Marie Obenour]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Sun, Feb 09, 2025 at 12:04:20PM +0100, David Hobach wrote:

Ouch. 500sms to set up networking is way too slow, and it looks like
setting up the root filesystem is also slow. dev-mapper-dmroot.device
takes 1.310s to start up, which is nearly half of the 2.170s spent in
userspace on the VM I used to write this message. I suspect this is
largely a problem with the Xen toolstack, which is not optimized, to
put it mildly. Replacing it with an optimized toolstack like the one
Edera uses would make things much, much faster.

> > And also, now it can do over 50 calls per second, I'd say it's way more than
> > enough for its intended use.

_Not_ fast enough for an internet-facing qrexec-call-per-request
service, though, unless one checks authentication before the call to
revent denial of service attacks.
- --
Sincerely,
Demi Marie Obenour (she/her/hers)

Invisible Things Lab
-----BEGIN PGP SIGNATURE-----

iQIzBAEBCAAdFiEEopQtqVJW1aeuo9/sszaHOrMp8lMFAmepTjoACgkQszaHOrMp
8lNCXg/6AjQ2iX3D7GTiueNm5/59PzxR/YPgeFHr6ehSReTDRvXIYfUp6KudTE8h
Y5xjQY5tDkg6nogUshtdNdiHHNY3gniBG+XHTpNebpM9O4EVXUEadgxjBQErIhaM
Ua+ORHLnAYY9d60a4aUdgocOiygOTd3NDU39r3HfVimDdlX7Q0RbEBUzaNlqH2U6
gJ+iQ58OqxuKtV6+3XlQep/5Ea+2NNqO8g9TwsfRQ4m026NTJDGJIyP+HceZvkUl
hr+1quFjhDp+DJjzPpUsqX4EqsCrOKgDvlfF3cTmun9ydqvdM+kydInVHJT93jNN
E2XNlmghNdLx+UggcP/e4wosrcbjvZpkzXl9u2dZe4zF0Iuk1SGqGtJ3iyKIZW0q
IazvAEP3fySM8x0jQmJ654Sb0MyUTn+p74EL0VfgCa8jFg0nQVEuAtVfIqYoWr2b
93ATX7mCb2UKQnb3hUqW0pV1Wt2HWLf4ajEUwbp7keJZArvWg6zyIqCKE7Y9lyHz
+49hdBClYrzzVpWVtRbh1iW+1YyddEjV4LICdCryFiPG9l5+hhdfS47isUjDZ8wE
pdcBa4uBtXVxacgH/G6wFLYiltkViBeBYukeu5bx0O9xMy9i9X54zTUSQk/swsB3
gnql+EA6FT7YYKH1nF+iIImsXTjzQNuUHsg+DOVpPaRzyWNoeYY=
=3Vli
-----END PGP SIGNATURE-----

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Where did you get that from? I don't see dev-mapper-dmroot.device
mentioned in any of the above...

Anyway, even if that would be there, it would be interesting to learn
what that actually mean. If dom0-provided kernel is used, the initramfs
is _not_ using systemd, and so there is no time measurements of how long
it takes to actually construct that device (which, in any currently
supported Qubes version is simply a symlink to /dev/xvda3, not real
dm device).

> which is nearly half of the 2.170s spent in
> userspace on the VM I used to write this message. I suspect this is
> largely a problem with the Xen toolstack, which is not optimized, to
> put it mildly. Replacing it with an optimized toolstack like the one
> Edera uses would make things much, much faster.

I have no idea how you got to the Xen toolstack here. The above is a
from from within a VM, after the toolstack did all its job. It isn't
even installed in the VM...

> > > And also, now it can do over 50 calls per second, I'd say it's way more than
> > > enough for its intended use.
>
> _Not_ fast enough for an internet-facing qrexec-call-per-request
> service, though, unless one checks authentication before the call to
> revent denial of service attacks.

As I said, "for its intended use". Qubes OS is not a server operating
system.

- --
Best Regards,
Marek Marczykowski-Górecki

Invisible Things Lab
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAmepUUUACgkQ24/THMrX
1yxcrQf/ZHU8HEo0CBKx2WjOYrYLik0YxzOtiT8Xoco/Ef+rzNEqP3xrx4N2wpm3
AOAeqq3d58ZVZgyJizVZ5tJMCVf2pABVc9wW0MUsWkVPhWjj9GQUT9YhVGoFsv34
etGXJYqFN8/TpY2a5Xo8jY+ERt1ss1uNabO/xv5QPCAUZ3Ei1w08NZtQ8/CbcJD1
YTpCEFbrqRBMSqJ95+zyBDq8i/SyQI4T2bmMWleqJnaZt+f11NDt9iZeA+PKXBIH
ENFuBNsUFhSSalOFmv0BcPQ6F0DTE5k0qv8zyd1agl0ailHS8pYaTlToaLBcXyST
rpBDomAVzAkujQ4Xgwypv2Jvo5srLg==
=AIm8
-----END PGP SIGNATURE-----

[Demi Marie Obenour]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

systemd-analyze blame (output attached).

> Anyway, even if that would be there, it would be interesting to learn
> what that actually mean. If dom0-provided kernel is used, the initramfs
> is _not_ using systemd, and so there is no time measurements of how long
> it takes to actually construct that device (which, in any currently
> supported Qubes version is simply a symlink to /dev/xvda3, not real
> dm device).

It means that 1.310s elapses between the kernel transferring control to
systemd and systemd finding that /dev/mapper/dmroot is ready.

> > which is nearly half of the 2.170s spent in
> > userspace on the VM I used to write this message. I suspect this is
> > largely a problem with the Xen toolstack, which is not optimized, to
> > put it mildly. Replacing it with an optimized toolstack like the one
> > Edera uses would make things much, much faster.
>
> I have no idea how you got to the Xen toolstack here. The above is a
> from from within a VM, after the toolstack did all its job. It isn't
> even installed in the VM...

I assumed that the toolstack booted the VM and _then_ attached the
devices. That assumption is probably wrong.

> > > > And also, now it can do over 50 calls per second, I'd say it's way more than
> > > > enough for its intended use.
> >
> > _Not_ fast enough for an internet-facing qrexec-call-per-request
> > service, though, unless one checks authentication before the call to
> > revent denial of service attacks.
>
> As I said, "for its intended use". Qubes OS is not a server operating
> system.

The Qubes OS build servers run Qubes OS 🙂.

- --
Sincerely,
Demi Marie Obenour (she/her/hers)

Invisible Things Lab
-----BEGIN PGP SIGNATURE-----

iQIzBAEBCAAdFiEEopQtqVJW1aeuo9/sszaHOrMp8lMFAmepaI4ACgkQszaHOrMp
8lOvSQ/+Npxd3168FMhRCzDzofAUuxOuvzBUnhiWo1FMJmgwM8lF8wv9s2gLUdZA
XAZktBKUl3k7ReJ3gMzQfgvNTKQsG+LG+YgcPMzJ+odld0wvVFHygKTM8dZo8wt9
5YTUE+9aX1kSo7OR5MKutCNePXr4kY1RK+5I2N6bvbNGEL1J6/tjEqkrAjnUPPVZ
Q+R8xsZ4TcNMgoYcc/lJMm7xFA/0cUgYgxwfSjw3q1ScQNdPmy40tr1KF3HJ8TPH
4zrKVZ0jWYIeT7hjTdGai1nWP66Kpgau4WEBluG2OlP3tdQQOG/+WG0hOLOHKn8v
hBos5afm7SUUBxmBKIS1Chw9FfjjYBv2ndVbu0TtwRCu+muOvYRvnJIU/uhH33L0
8hcgsiaYrtFyDcpcS2FV7r99EDItoD9DivRsUdZcB8kTxPDez4z2JK/pSEVATQ7m
G9nz/CONic8h/0jMUu4fVR5Q4MRu9ZCvw2EJySMLHFlMt3mYvHuOB/+RrHcplcTo
6PD10MH9D4z9iH9b24bOdCB8Os172QTS5CTiqrtnIPTYkqodCaDKJJPza5+4dMN6
5ODp96vKamxoJPCQcCkiEDTA4JM1XsfWcDh3uyi1OySWv6XJPUF9EBB4HqC4chnG
PyXJ/3nQXxUANUs/JCMqi+OQCQRFYdBp00Cy9hOniCBGFH79Kt4=
=OxxG
-----END PGP SIGNATURE-----

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Interesting, since it exists there already literally before systemd gets
started... Maybe udev needs to enumerate it or something...

> > > which is nearly half of the 2.170s spent in
> > > userspace on the VM I used to write this message. I suspect this is
> > > largely a problem with the Xen toolstack, which is not optimized, to
> > > put it mildly. Replacing it with an optimized toolstack like the one
> > > Edera uses would make things much, much faster.
> >
> > I have no idea how you got to the Xen toolstack here. The above is a
> > from from within a VM, after the toolstack did all its job. It isn't
> > even installed in the VM...
>
> I assumed that the toolstack booted the VM and _then_ attached the
> devices. That assumption is probably wrong.

Yes, devices are setup before VM is started (and if setting up devices
fails, VM kernel isn't started at all).

> > > > > And also, now it can do over 50 calls per second, I'd say it's way more than
> > > > > enough for its intended use.
> > >
> > > _Not_ fast enough for an internet-facing qrexec-call-per-request
> > > service, though, unless one checks authentication before the call to
> > > revent denial of service attacks.
> >
> > As I said, "for its intended use". Qubes OS is not a server operating
> > system.
>
> The Qubes OS build servers run Qubes OS 🙂.

That's _very_ stretched definition...

- --
Best Regards,
Marek Marczykowski-Górecki

Invisible Things Lab
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAmep18oACgkQ24/THMrX
1yy5qwf/T05s9Q7+XH/LWKEAAaLKp1cj/EoRDHhjNVugw7WXs/p8OsHwbXJFtvGq
yDTG7caig8lv63QqM+Nb2LqzYAigEcALZpx68o28DcUG7fGDzbBZtYW+jrEQ1JAI
mvnrgTRuMVVgNh26iujqfbkJIcVRuyJXEzkTQT/oZb6jh21X9a7jbWMySUbJuWd3
z2j1jYjVZFWppq7GPA3gEI0pHdKitCo1RNB8dGhNHVQblDdW0JLIy3CbvLkVwqVE
6knFVEo0S6AYs8toBLiLTHq6xJ5RpTL+2xm6KC8OD9Nn7a8qXpM6T//rmnArYrsC
m7ZZz0t/yJVaHBWJyZCvFn2urSdL+w==
=xR6U
-----END PGP SIGNATURE-----

[Demi Marie Obenour]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

That is my current suspicion. systemd-udevd is started the device is
started, and I wonder if it is too slow to handle the flood of
kobject-uevent messages it gets at startup.

If so, then the problem is systemd-udevd itself, and the only solutions
are to either speed it up, replace it, or take it out of the critical
path. One option would be to move mounting to the (non-systemd-based)
initramfs.

> > > > which is nearly half of the 2.170s spent in
> > > > userspace on the VM I used to write this message. I suspect this is
> > > > largely a problem with the Xen toolstack, which is not optimized, to
> > > > put it mildly. Replacing it with an optimized toolstack like the one
> > > > Edera uses would make things much, much faster.
> > >
> > > I have no idea how you got to the Xen toolstack here. The above is a
> > > from from within a VM, after the toolstack did all its job. It isn't
> > > even installed in the VM...
> >
> > I assumed that the toolstack booted the VM and _then_ attached the
> > devices. That assumption is probably wrong.
>
> Yes, devices are setup before VM is started (and if setting up devices
> fails, VM kernel isn't started at all).

Yup, and /dev/xvda3 is where systemd is loaded from, so it must be
ready before systemd starts.

> > > > > > And also, now it can do over 50 calls per second, I'd say it's way more than
> > > > > > enough for its intended use.
> > > >
> > > > _Not_ fast enough for an internet-facing qrexec-call-per-request
> > > > service, though, unless one checks authentication before the call to
> > > > revent denial of service attacks.
> > >
> > > As I said, "for its intended use". Qubes OS is not a server operating
> > > system.
> >
> > The Qubes OS build servers run Qubes OS 🙂.
>
> That's _very_ stretched definition...

What I mean is that while Qubes OS is not designed to be a server OS,
people can (and do) run servers in the VMs that it manages. The above
comment was meant as a warning (and should probably have been a
documentation PR).

- --
Sincerely,
Demi Marie Obenour (she/her/hers)

Invisible Things Lab
-----BEGIN PGP SIGNATURE-----

iQIzBAEBCAAdFiEEopQtqVJW1aeuo9/sszaHOrMp8lMFAmeqaD8ACgkQszaHOrMp
8lMifRAAobCd9SDVSqaquvASGSrenZS03881aYMTW1CThNRhdNPjM6OiFnpFDLTA
1BjEe8j8w3a0TgeAHOoXumjhn7n9pVLvivteHEqjAbCj2UlvTLaN93hbYDPjVU9+
Pdh6+0zAm7gdhdwc8L/EOj9vkjFPEf5qXPApkF8bCG8xkuG03D68oKPgyTnz24Od
Pkib/bXbHsH5INrJ2Zy9paYAnkxCXrJcn1WO/p2+HSgGiJUbT/XQpPsCRzQCO96Z
gmET6lTqhSKV7rcFzAtHfM0miQGyGWqyCJ4prgdzGOrh3rFuozLItPJ8rZ0YRwwy
RZkQJ2eHAsxo4tqlxoHESULTkBxENoQk+f+zCbpsEb+aVGB3Q/jQSel0ae2h5UiN
oo1Xo4UZtC4TseT0eWlryC50kplqH7JbDoWEI73TuH7ZF63ced89xYso2E6SxfHG
+41khAUCxG8ge77/uxzTgDg9w6J/YxHCrfOHoqjv1ZlepSZ9Wj/vKAXqrbSPjkup
225coLWKT2dwYLp47fGpSCRuMNjiqmd7G5ZVYtD68T6J3uAtusT9ryu6I2egLzyH
r3VrhACQqPT5Z2P1dZxPogAu+MOh6Wi+qkB2MfRPvZp4mmNc70u+dFUOPhIP6oYC
+MfqbbUooGE9WCLLnsPh6SxRI7YdOVnjB+b6n8vEbm2+gvWXk80=
=GAx5
-----END PGP SIGNATURE-----