Server performance & optimization

[WolfganP]

Follows from #339 (comment) for better focus of the discussion.

So, as the previous issue started to explore multi-threading on the server for better use of resources, I first run a profiling of the app on debian.

Special build with:
qmake "CONFIG+=nosound headless noupcasename debug" "QMAKE_CXXFLAGS+=-pg" "QMAKE_LFLAGS+=-pg" -config debug Jamulus.pro && make clean && make -j

Then run as below, and connecting a couple of clients for a few seconds:
./jamulus --nogui --server --fastupdate

Once disconnecting the clients I gracefully killed the server
pkill -sigterm jamulus

And finally run gprof, with the results posted below:
gprof ./jamulus > gprof.txt

https://gist.github.com/WolfganP/46094fd993906321f1336494f8a5faed

It would be interesting to see those who observed high cpu usage run test sessions and collect profiling information as well to detect bottlenecks and potential code optimizations, before embarking on multi-threading analysis that may require major rewrites.

[dingodoppelt]

Hi,
I don't know if this is of much help since I don't know what I'm doing here ;) but I generated the data as instructed on my private cloud server.

https://gist.github.com/dingodoppelt/802c40b1cb13c75d96f38b9604fa22df

cheers, nils

[WolfganP]

Thanks @dingodoppelt Could you please describe the test session/environment? (ie, how many clients connected, which hardware/Operating System you were running the server on, whatever you feel noticeable)

[WolfganP]

@sthenos you mentioned in https://www.facebook.com/groups/507047599870191/?post_id=564455474129403&comment_id=564816464093304 that you're running the server in linux now.
Would it be possible for you to run a profiling session in any of the casual/preparation jam sessions with multiple clients to measure REAL server stress? (obviously not during the WJN main event :-)

[dingodoppelt]

I tested with 12 clients connected from my machine with small network buffers enabled on 64 samples buffersize.
the server is a cloud hosted kvm virtual rootserver (1fire.hosting) with 2 vcpus, 1 gig of ram on ubuntu 20.04 lowlatency.
If i get the opportunity I'll repeat the test on my other server in a real life scenario.
cheers, nils

[storeilly]

Are you still interested in these data? I can run a few tests on ubuntu over the weekend.
Is there a particular release or tag we should checkout as I tried last week to compile but it froze my server.

[pljones]

One quick comment @WolfganP -- for some reason you build command line (rather than a simple qmake) causes the TARGET = jamulus line to trigger... I don't understand why!

EDIT Dawn strikes... Yes, it does have noupcase in the CONFIG+=... I just couldn't see it...

So if you're on anything but Windows, you'll probably want to mv it back again, otherwise start up scripts, etc, won't work.

Final edit to note: jamulus.drealm.info is running with profiling. I'll leave it up over the weekend so it should amass a fair amount of data. I'll run the gprof on Monday. Obviously a bit more "real world", as I run with logging and recording enabled, so I'm expecting different number...

[pljones]

A different view should come from the Rock and Clasical/Folk/Choir genre servers that I've just updated to r3_5_9 with profiling.

make distclean
qmake "CONFIG+=nosound headless debug" "QMAKE_CXXFLAGS+=-pg" "QMAKE_LFLAGS+=-pg" -config debug Jamulus.pro
make -j
make clean

They probably won't show much OPUS usage but this should show anything that's "weird" with server list server behaviour (although they only have about 20 registering servers, until Default).

I wasn't sure what CONFIG+=debug and -config debug added -- the code appeared to have symbols regardless.

[WolfganP]

@pljones yes, I added debug flags to qmake just to make sure all symbols are included and no stripping is applied.
Anyways, a good way to check if symbols were included in the final exec and gprof instrumentation applied is objdump --syms jamulus | grep -i mcount (mcount* being the snippets of code added for profiling instrumentation)

[pljones]

Standard build:

peter@fs-peter:~$ objdump --syms git/Jamulus-wip/Jamulus | grep -i mcount
0000000000000000       F *UND*  0000000000000000              mcount@@GLIBC_2.2.5

This just changing the binary to "Jamulus", IIRC:

peter@fs-peter:~$ objdump --syms git/Jamulus/Jamulus | grep -i mcount
0000000000000000       F *UND*  0000000000000000              mcount@@GLIBC_2.2.5

This was
make distclean; qmake "CONFIG+=nosound headless debug" "QMAKE_CXXFLAGS+=-pg" "QMAKE_LFLAGS+=-pg" -config debug Jamulus.pro; make -j; make clean

peter@fs-peter:~$ objdump --syms git/Jamulus-stable/Jamulus | grep -i mcount
0000000000000000       F *UND*  0000000000000000              mcount@@GLIBC_2.2.5

---

Had a few people tonight noticing additional jitter. Not everyone... Those who noticed - myself included - had just upgraded to 3.5.9. No idea why... (I "fixed" it for the evening by upping my buffer size from 64 to 128.)

---

14 clients connected to the server and it's looking like this in top:

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
32704 Jamulus  -21   0  320.3m  28.6m   9.1m S 10.8  0.2  80:09.58 Jamulus-server
 1066 root     -51   0    0.0m   0.0m   0.0m S  0.2  0.0  10:15.69 irq/130-enp2s0-
 1070 root     -51   0    0.0m   0.0m   0.0m S  0.1  0.0   3:27.74 irq/132-enp2s0-
 1071 root     -51   0    0.0m   0.0m   0.0m S  0.1  0.0   4:00.96 irq/133-enp2s0-

Mmm, I guess those enp2s0 IRQ handlers are a bit busy as that's the network interface... There are actually five, it seems:

peter@fs-peter:~$ ps axlww -L | grep enp2s0
1     0  1063     2  1063 -51   -      0     0 -      S    ?          0:00 [irq/129-enp2s0]
1     0  1066     2  1066 -51   -      0     0 -      S    ?         10:06 [irq/130-enp2s0-]
1     0  1068     2  1068 -51   -      0     0 -      S    ?          0:01 [irq/131-enp2s0-]
1     0  1070     2  1070 -51   -      0     0 -      S    ?          3:22 [irq/132-enp2s0-]
1     0  1071     2  1071 -51   -      0     0 -      S    ?          3:56 [irq/133-enp2s0-]

but it copes with only three in heavy demand. 129 and 131 seem left out.

Let's see what the gprof looks like in the morning :).

[pljones]

OK, I decided to restart the central servers without profiling before I totally forget, so all the number are now in.
Jamulus-Central1 gprof.out
Jamulus-Central2 gprof.out
jamulus.drealm.info gprof.out

[WolfganP]

OK, I decided to restart the central servers without profiling before I totally forget, so all the number are now in.
Jamulus-Central1 gprof.out
Jamulus-Central2 gprof.out
jamulus.drealm.info gprof.out

Thx for the info @pljones, good to also have some performance info for the Central Server role.

Regarding the info on the audio server role, it seems it confirms the CPU impact of CServer::ProcessData and some Opus routines (I assume that as a result of the mix processing inside CServer::OnTimer), and that make sense (at least to me).
On the Opus codec front, I found this article worthy to read: https://freac.org/developer-blog-mainmenu-9/14-freac/257-introducing-superfast-conversions/ (code at https://github.com/enzo1982/superfast#superfast-codecs)

Another item I think needs some attention (or verify is already optimized) is the buffering of audio blocks to avoid unnecessary memcopies. But still reading the code :-)