Optimization coding pass over AudioMixerSlavePool and AvatarMixerSlavePool pt. 2. #1361

odysseus654 · 2021-09-24T04:56:33Z

This is an optimization pass over the mutex logic in AudioMixerSlavePool and AvatarMixerSlavePool (which is effectively the same code).

This is a continuation of the changes in #1358 , with more of a focus on contracts and invariants and effectively no use of mutexes. This should (almost by definition) have reduced lock contention, but "thread-safety through the use of code comments" may have negative side effects. I don't know which of these PRs will end up being used (perhaps a mixture of both?)

Additional changes made to this PR:

Removed all use of "friend" by factoring out shared variables into a private class that the slaves can see but pool users cannot
A number of counters have been changed from "int" to "std::atomic"
Much documentation of invariants and code contracts

Testing is almost identical to #1358 :

Smoketesting: make sure that audio and avatars still work on a server built with this (requires a server with multiple users)
Race conditions: exercise a server long enough to know whether there are any lockups or crashes that occur in these two areas
Profile: see if this improves the profiling numbers that have been described in issue High CPU usage of assignment client when idle on Linux High CPU usage of assignment client when idle on Linux #1355

…educe spurious wakes

…mutexes to reduce lock contention.

…n managing slaves and shared data

…which hopefully stays up just from handshake agreements?)

odysseus654 · 2021-09-24T05:01:12Z

Hey, if anyone wants to use std::shared_mutex, there's a polyfill in the commits (that was later yanked out) ;-)

assignment-client/src/avatars/AvatarMixerSlavePool.cpp

assignment-client/src/avatars/AvatarMixerSlavePool.h

vircadia-build-notifier · 2021-09-24T06:47:42Z

The following links are available:
build (macOS-latest, client)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-Interface-PR1361-ba09d2a-_536b1ed1.dmg

build (macOS-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-ba09d2a-_536b1ed1.dmg

build (ubuntu-18.04, full)

build (windows-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-ba09d2a-_536b1ed1.exe

- changed "slave" to "worker" when dealing with classes in this file - moved the "data" struct to be a private member instead of a base class

odysseus654 · 2021-09-24T07:36:19Z

Made suggested changes to this PR:

changed "slave" to "worker" when dealing with classes in this file
moved the "data" struct to be a private member instead of a base class

Attempted to factor out common code to a template base class but... can't do that and still use Qt

vircadia-build-notifier · 2021-09-24T09:25:09Z

The following links are available:
build (ubuntu-18.04, full)

build (macOS-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-2dff102-_aa2c3074.dmg

build (windows-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-2dff102-_aa2c3074.exe

build (macOS-latest, client)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-Interface-PR1361-2dff102-_aa2c3074.dmg

vircadia-build-notifier · 2021-09-24T19:41:20Z

The following links are available:
build (ubuntu-18.04, full)

build (macOS-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-5c42466-_569afb18.dmg

build (windows-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-5c42466-_569afb18.exe

build (macOS-latest, client)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-Interface-PR1361-5c42466-_569afb18.dmg

assignment-client/src/audio/AudioMixerSlavePool.h

HifiExperiments · 2021-09-24T23:04:46Z

assignment-client/src/avatars/AvatarMixerSlavePool.cpp

+            {
+                Lock poolLock(_data.poolMutex);
+                if (_data.numFinished < _data.numThreads) {
+                    _data.poolCondition.wait(poolLock, [&] {


hm…is it possible that all the threads will finish and notify between line 188 above and here? so this wait would never finish?

Heh, I thought about that this morning. The most recent commit now has all "condition.notify" calls holding the corresponding lock when calling it (thus forcing the notify to be before line 192 or after line 194) and the "if" statement wrapping all "condition.wait" calls bypasses it if the conditions for it to be notified already exist.

odysseus654 · 2021-09-25T03:15:58Z

Added commit: renamed _pool to _data as suggested.

vircadia-build-notifier · 2021-09-25T04:51:03Z

The following links are available:
build (macOS-latest, client)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-Interface-PR1361-3dd0fb4-_bc5d9de4.dmg

build (macOS-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-3dd0fb4-_bc5d9de4.dmg

build (ubuntu-18.04, full)

build (windows-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-3dd0fb4-_bc5d9de4.exe

HifiExperiments

looks good to me, definitely want to stress test this with a bunch of people on a server and do another perf analysis to see if this made a difference

… as expected and verify the invariants

odysseus654 · 2021-11-08T03:59:29Z

I managed to piece together a linux debugging environment and debugged it enough to no longer assert (note to self: deleting assert commands is a great way to remove those pesky asserts).

Anyhow, really hoping this is the last patch necessary in order to successfully smoketest this. Also hoping to have a chance to flatten these test commits (there's an awful lot of them) although I understand if that doesn't happen.

vircadia-build-notifier · 2021-11-08T05:39:15Z

The following links are available:
build (macOS-10.15, client)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-Interface-PR1361-555443a-_f7e61b8a.dmg

build (macOS-10.15, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-555443a-_f7e61b8a.dmg

build (ubuntu-18.04, full)

build (windows-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-555443a-_f7e61b8a.exe

build (self-hosted_debian-11_aarch64, full)

ksuprynowicz · 2021-11-11T14:17:38Z

I just gave it a try, and nothing is crashing right now, I'm able to connect, but only audio mixer starts. Other types of assignment clients don't start.

ksuprynowicz · 2021-11-11T18:40:52Z

I'm sorry. I ran assignment server with wrong command line parameters. Everything seems to work correctly now, but CPU usage is still very high even when no client is connected.

odysseus654 · 2021-11-12T01:33:03Z

Heh, finally got it! So I guess the question is what the profiler is saying about this now.

ksuprynowicz · 2021-11-12T10:48:38Z

Congratulations!
I will do a profiler run today when I finish work and see what is shows :)

ksuprynowicz · 2021-11-13T16:55:14Z

CPU use seems to be significantly lower now compared to master when built with the same compiler flags - it drops almost 2 times when no user is logged in.
Here are the profiling results for audio mixer:

-   83.79%     0.55%  AudioMixerWorke  [kernel.kallsyms]            [k] entry_SYSCALL_64_after_hwframe
   - 83.24% entry_SYSCALL_64_after_hwframe
      - do_syscall_64
         - 81.87% __x64_sys_futex
            - do_futex
               - 60.03% futex_wait
                  - 44.78% futex_wait_queue_me
                     - 43.66% schedule
                        - __schedule
                           - 27.91% pick_next_task_fair
                              - 27.66% newidle_balance
                                 - 24.60% load_balance
                                    - 16.37% find_busiest_group
                                       - update_sd_lb_stats.constprop.0
                                          - 2.43% cpumask_next_and
                                               _find_next_bit
                                            1.51% idle_cpu
                                    + 5.40% raw_spin_rq_lock_nested
                                   1.18% update_blocked_averages
                           - 6.39% finish_task_switch.isra.0
                              - 5.11% __perf_event_task_sched_in
                                 + 3.33% ctx_sched_in
                                 + 0.59% perf_event_sched_in
                           + 3.25% dequeue_task_fair
                           + 2.46% psi_task_switch
                           + 1.04% __perf_event_task_sched_out
                       0.74% plist_add
                  + 14.39% futex_wait_setup
               + 20.80% futex_wake
         + 1.04% syscall_exit_to_user_mode

And for avatar mixer:

-   82.22%     0.52%  AvatarMixerWork  [kernel.kallsyms]        [k] entry_SYSCALL_64_after_hwframe
   - 81.69% entry_SYSCALL_64_after_hwframe
      - do_syscall_64
         - 80.28% __x64_sys_futex
            - do_futex
               - 55.44% futex_wait
                  + 36.85% futex_wait_queue_me
                  + 17.69% futex_wait_setup
               - 23.86% futex_wake
                  + 16.12% _raw_spin_lock
                  + 5.26% wake_up_q
                  + 0.96% mark_wake_futex
         + 1.01% syscall_exit_to_user_mode

ksuprynowicz · 2021-11-13T16:57:31Z

Audio mixer uses about 32% of a core right now when no one is logged in, and avatar mixer uses about 15% with compiler flags as in PR 1424. I suggest pulling changes from master to make comparisons easier.

ksuprynowicz · 2021-11-13T17:54:24Z

The weird thing is that high CPU usage disappears completely on PR 1429. I have no idea why.

ksuprynowicz · 2021-11-13T18:57:01Z

We tested it with Kalila and PR 1429 indeed seems to solve high CPU usage completely. It dropped to 3% for audio mixer and 3% for avatar mixer when nobody is logged in.

odysseus654 · 2021-11-13T19:07:22Z

Okay kewl! I'm gonna want to flatten all those commits I made while testing this (because ew), but other than that it sounds like we've cleared the "at least as good as master" bar.

odysseus654 · 2021-11-13T19:17:27Z

Okay I looked at the history and... it may not be as bad as I thought it was. I'll squish it if it makes sense to others, otherwise I'll say this is good to merge.

HifiExperiments · 2021-11-13T22:07:33Z

sorry if I’m missing it in the above comments: did this PR have a measurable difference then? if this isn’t an improvement, maybe we don’t need to merge it?

ksuprynowicz · 2021-11-13T22:10:13Z

sorry if I’m missing it in the above comments: did this PR have a measurable difference then? if this isn’t an improvement, maybe we don’t need to merge it?

With current version it does have a measurable improvement, but I suggest to wait with testing it until PR 1429 is merged. I will benchmark it again then and see if it also improves things or not.

…ondition2

vircadia-build-notifier · 2021-12-05T04:03:34Z

The following links are available:
build (macOS-10.15, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-4848d86-_1f9347d5.dmg

build (ubuntu-18.04, full)

build (macOS-10.15, client)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-Interface-PR1361-4848d86-_1f9347d5.dmg

build (windows-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-4848d86-_1f9347d5.exe

build (self-hosted_debian-11_aarch64, full)

…ondition2

vircadia-build-notifier · 2022-01-26T15:36:49Z

The following links are available:
build (macOS-10.15, client)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-Interface-PR1361-8397fd6-_20df505e.dmg

build (ubuntu-18.04, full)

build (macOS-10.15, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-8397fd6-_20df505e.dmg

build (windows-latest, full)

https://athena-public.s3.eu-west-3.amazonaws.com/builds/PR/vircadia_vircadia/PR1361/Vircadia-PR1361-8397fd6-_20df505e.exe

digisomni · 2022-01-29T19:17:27Z

Needs another QA pass to confirm whether or not it performs better than current master.

namark · 2022-02-04T22:42:48Z

I tried to test audio mixer locally, just idling as suggested, and couldn't really find any significant performance difference between this and the master branch. Here is what the CPU utilization looks like for me:

I tried a profiler as well, and it does seem that this version spends a bit less time in the run and wait functions of the two classes, but it's just by a few percent and not very consistent between runs, so nothing conclusive there either.

Since the high CPU usage when idle is fixed now on master, I guess it would make more sense to try some sort of a stress test, but I don't fully understand the changes so not sure what would be a good way to do it. I could maybe try using the web sdk to connect a bunch of dummy clients and send some random audio samples, if that's something we expect to be improved here.

stale · 2022-08-04T00:06:07Z

Hello! Is this still an issue?

odysseus654 added 5 commits September 22, 2021 21:49

copy the wait predicate into a test before waking the condition, to r…

5a9abf5

…educe spurious wakes

breaking the pool _mutex into two smaller _slaveMutex and _poolMutex …

e839857

…mutexes to reduce lock contention.

pull out data shared between threads / remove "friend" declarations

0c35b43

add shared_mutex in an attempt to reduce the number of mutexes used i…

e60db78

…n managing slaves and shared data

stripping out the shared_mutex for a contract-based threading model (…

536b1ed

…which hopefully stays up just from handshake agreements?)

digisomni changed the title ~~Optimization coding pass over AudioMixerSlavePool and AvatarMixerSlavePool (again!)~~ Optimization coding pass over AudioMixerSlavePool and AvatarMixerSlavePool pt. 2. Sep 24, 2021

digisomni added allow-build-upload Allows the upload of a build for non white-listed users domain-server Issues related to the domain server in general enhancement New feature or request threading/deadlock (beware) needs CR (code review) labels Sep 24, 2021

HifiExperiments reviewed Sep 24, 2021

View reviewed changes

assignment-client/src/avatars/AvatarMixerSlavePool.cpp Outdated Show resolved Hide resolved

HifiExperiments reviewed Sep 24, 2021

View reviewed changes

assignment-client/src/avatars/AvatarMixerSlavePool.h Outdated Show resolved Hide resolved

suggested changes:

aa2c307

- changed "slave" to "worker" when dealing with classes in this file - moved the "data" struct to be a private member instead of a base class

resolve potential race condition

569afb1

digisomni added this to In progress in 2022.1.0 Selene Release via automation Sep 24, 2021

digisomni added this to the 2021.2.0 Selene Release milestone Sep 24, 2021

HifiExperiments reviewed Sep 24, 2021

View reviewed changes

assignment-client/src/audio/AudioMixerSlavePool.h Outdated Show resolved Hide resolved

HifiExperiments reviewed Sep 24, 2021

View reviewed changes

assignment-client/src/audio/AudioMixerSlavePool.h Show resolved Hide resolved

HifiExperiments reviewed Sep 24, 2021

View reviewed changes

renamed _pool to _data, to bring it more in line with other users

bc5d9de

2022.1.0 Selene Release automation moved this from In progress to Reviewer approved Sep 25, 2021

HifiExperiments approved these changes Sep 25, 2021

View reviewed changes

digisomni removed this from Reviewer approved in 2022.1.0 Selene Release Oct 30, 2021

digisomni added this to In progress in 2022.1.1 Selene Release via automation Oct 30, 2021

digisomni modified the milestones: 2021.2.0 Selene Release, 2021.2.1 Selene Release Oct 30, 2021

results of linux debugging, trying to get the wait conditions working…

f7e61b8

… as expected and verify the invariants

digisomni requested a review from HifiExperiments November 13, 2021 19:19

Merge remote-tracking branch 'remotes/vircadia/master' into pr/pool-c…

1f9347d

…ondition2

Merge remote-tracking branch 'remotes/vircadia/master' into pr/pool-c…

20df505

…ondition2

digisomni requested review from namark and removed request for HifiExperiments February 2, 2022 07:52

stale bot added the stale Issue / PR has not had activity label Aug 4, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Optimization coding pass over AudioMixerSlavePool and AvatarMixerSlavePool pt. 2. #1361

Optimization coding pass over AudioMixerSlavePool and AvatarMixerSlavePool pt. 2. #1361

odysseus654 commented Sep 24, 2021

odysseus654 commented Sep 24, 2021

vircadia-build-notifier commented Sep 24, 2021

odysseus654 commented Sep 24, 2021

vircadia-build-notifier commented Sep 24, 2021

vircadia-build-notifier commented Sep 24, 2021

HifiExperiments Sep 24, 2021

odysseus654 Sep 25, 2021

odysseus654 commented Sep 25, 2021

vircadia-build-notifier commented Sep 25, 2021

HifiExperiments left a comment

odysseus654 commented Nov 8, 2021

vircadia-build-notifier commented Nov 8, 2021

ksuprynowicz commented Nov 11, 2021

ksuprynowicz commented Nov 11, 2021

odysseus654 commented Nov 12, 2021

ksuprynowicz commented Nov 12, 2021

ksuprynowicz commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

odysseus654 commented Nov 13, 2021

odysseus654 commented Nov 13, 2021

HifiExperiments commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

vircadia-build-notifier commented Dec 5, 2021

vircadia-build-notifier commented Jan 26, 2022

digisomni commented Jan 29, 2022

namark commented Feb 4, 2022

stale bot commented Aug 4, 2022

Optimization coding pass over AudioMixerSlavePool and AvatarMixerSlavePool pt. 2. #1361

Are you sure you want to change the base?

Optimization coding pass over AudioMixerSlavePool and AvatarMixerSlavePool pt. 2. #1361

Conversation

odysseus654 commented Sep 24, 2021

odysseus654 commented Sep 24, 2021

vircadia-build-notifier commented Sep 24, 2021

odysseus654 commented Sep 24, 2021

vircadia-build-notifier commented Sep 24, 2021

vircadia-build-notifier commented Sep 24, 2021

HifiExperiments Sep 24, 2021

Choose a reason for hiding this comment

odysseus654 Sep 25, 2021

Choose a reason for hiding this comment

odysseus654 commented Sep 25, 2021

vircadia-build-notifier commented Sep 25, 2021

HifiExperiments left a comment

Choose a reason for hiding this comment

odysseus654 commented Nov 8, 2021

vircadia-build-notifier commented Nov 8, 2021

ksuprynowicz commented Nov 11, 2021

ksuprynowicz commented Nov 11, 2021

odysseus654 commented Nov 12, 2021

ksuprynowicz commented Nov 12, 2021

ksuprynowicz commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

odysseus654 commented Nov 13, 2021

odysseus654 commented Nov 13, 2021

HifiExperiments commented Nov 13, 2021

ksuprynowicz commented Nov 13, 2021

vircadia-build-notifier commented Dec 5, 2021

vircadia-build-notifier commented Jan 26, 2022

digisomni commented Jan 29, 2022

namark commented Feb 4, 2022

stale bot commented Aug 4, 2022