misc: rx thread activate #2828

cspiel1 · 2023-12-12T12:40:32Z

The last part for the audio RX "real-time" thread.

Enables RX thread via config, uses worker for passing work to the main thread and adds tests to ensure thread safety.

stream,rtprecv: activate RX thread via config
test: run call tests with RX_MODE_THREAD
test: main - init async workers
rtprecv: detach from RTP/RTCP sockets before re_cancel
stream,rtprecv: detach from RTP/RTCP also in RECEIVE_MODE_MAIN
test: call - add AUDIO_MODE_THREAD for test_call_aufilt
test: call - reset to RECEIVE_MODE_MAIN
rtprecv: use enable flag to prevent data race on stream termination
test: call - do not test unsupported combination
test: call - failure debug for test_media_base()
rtprecv: detach sockets before attach
rtprecv: warnings for UDP thread attach
aur: add mutex locks
aur: add aubuf_mtx

cspiel1 · 2023-12-12T12:42:00Z

When everything is green the commit ee740e3 will be reverted.

cspiel1 · 2023-12-13T14:31:00Z

This can be tested by enabling the RX thread with this line in your ~/.baresip/config:

rtp_rxmode		thread

@juha-h Please could you test this with the Android App?

@larsimmisch Please could you test this with the vad filter?

You will notice the line

rtp_receiver: RTP RX thread started

in stdout of the baresip process.

larsimmisch · 2023-12-13T22:47:48Z

I saw a problem on main yesterday with fvad and my application. I play a file using audio_set_source("aufile", filename) and then start a recording with audio_set_player("aufile", "record.wav"). Starting the recording returns 0, but the file is empty. Looking into it a bit, I saw that in aurecv_start_player, aurecv_codec(ar); returns NULL, so it exits early.

On v.3.7.0, the recording is created successfully. I don't understand why I didn't see that earlier.

Any hints what to look for? Creating a minimal test application would obviously be good, but I wouldn't get to it before the weekend.

larsimmisch · 2023-12-13T23:52:53Z

Ah, it can be reproduced through the debug interface.

Something like:

/insmod menu
/uanew <sip:test@immisch-macbook-pro.local>

Then place an incoming call, accept it and:

/auplay aufile,record.wav

My config has:

audio_path		/usr/local/share/baresip
audio_player		aufile,/dev/null
audio_source		aufile,/usr/local/share/baresip/ringback_s16.wav
module			fvad.so

juha-h · 2023-12-14T00:46:24Z

@cspiel1 I tried the PR in my Android app and receiving audio worked OK. I saw these in the log:

12-14 09:43:05.870 25379 25426 D Baresip Lib: rtp_receiver: RTP RX thread started
...
12-14 09:43:06.388 25379 25426 D Baresip Lib: audio_recv: create audio buffer [20 - 300 ms] [640 - 9600 bytes]

cspiel1 · 2023-12-14T08:10:24Z

Thanks @juha-h for the test. The log is exactly what I would expect.

@larsimmisch I understood that this problem is in main branch HEAD. So not directly related to this PR. I will try to analyse+solve this immediately. Thanks!

cspiel1 · 2023-12-14T10:04:18Z

@larsimmisch The issue you found has nothing to do with fvad. Here is the fix: #2830

larsimmisch · 2023-12-14T11:08:02Z

Thanks for the speedy fix on main!

I've now tested this branch (with the fix cherry-picked) with the config rtp_rxmode thread and I did see rtp_receiver: RTP RX thread started.

The test was fine.

cspiel1 · 2023-12-14T13:13:23Z

Thanks for the test!

alfredh · 2023-12-28T12:03:21Z

src/aureceiver.c

@@ -722,16 +746,19 @@ int aurecv_debug(struct re_printf *pf, const struct audio_recv *ar)
 		err |= mbuf_printf(mb, "       time = (not started)\n");
 	}

-	err |= re_hprintf(pf, "       player: %s,%s %s\n",
+	err |= mbuf_printf(mb, "       player: %s,%s %s\n",


this looks like a separate bugfix ? perhaps a separate PR for this ?

alfredh · 2023-12-28T12:04:34Z

src/config.c

+			cfg->avt.rxmode = RECEIVE_MODE_THREAD;
+			warning("rtp_rxmode thread is currently "
+				"experimental\n");
+		}


please compare all values, and print a warning if it matches none

alfredh · 2023-12-28T12:05:19Z

src/config.c

@@ -633,6 +644,8 @@ int config_print(struct re_printf *pf, const struct config *cfg)
 			 cfg->avt.rtp_stats ? "yes" : "no",
 			 cfg->avt.rtp_timeout,
 			 cfg->avt.bundle ? "yes" : "no",
+			 cfg->avt.rxmode == RECEIVE_MODE_THREAD ? "thread" :
+								  "main",


What if someone adds a new mode called e.g. "foo" ?

I added rtp_receive_mode_str().

alfredh · 2023-12-28T12:09:09Z

test/call.c

@@ -853,11 +853,12 @@ static void event_handler(struct ua *ua, enum ua_event ev,
 }


-int test_call_answer(void)
+static int test_call_answer_base(enum rtp_receive_mode rxmode)


adding the explicit rxmode is a good solution.

please note that it should also be possible to add new arguments to the selftest binary,
that can set the rxmode. This will make it possible to run the test with these options:

$ ./selftest -r main $ ./selftest -r thread

juha-h · 2023-12-28T12:21:34Z

I have not seen a rational for rx thread. What are its advantages/disadvantages? In which situations it should he activated? Why is it not the default mode?

cspiel1 · 2023-12-28T13:24:30Z

I have not seen a rational for rx thread. What are its advantages/disadvantages? In which situations it should he activated? Why is it not the default mode?

We had this discussion earlyer in this year. To sum it up: Audio processing should be done in an independent thread. The main thread handles everything from SIP signaling, parts of video processing and also processing of arbitrary baresip modules.

In the meanwhile we already have test results that show that the RX thread reduces the maximum deviation from the packet time that is caused by long blocking calls at the beginning of a call. For our products we already switched to rtp_rxmode thread.

For now rtp_rxmode main will be the default mode which will not change the behavior. In the future we could make rtp_rxmode thread to the default or maybe the only supported mode.

edit:
Processing of incoming RTP audio in a separate thread is also proposed by this book: https://csperkins.org/standards/rtp-book.html

cspiel1 · 2023-12-28T13:39:01Z

Resolved the conflicts right now.

still TODO:

$ ./selftest -r main
$ ./selftest -r thread

cspiel1 · 2023-12-28T15:27:03Z

TODO:

check if new selftest command arguments work
check if github actions run both RX modes
no sanitizer warnings

juha-h · 2023-12-29T00:05:05Z

@cspiel1 Thanks for the explanation.

cspiel1 · 2023-12-29T07:19:44Z

Now test_call_rtcp produces a sanitizer warning (not in single test mode).

In re/src/rtp/sess.c when the sender report is created in mk_sr() which runs in the main thread.

cspiel1 · 2023-12-29T07:56:14Z

It is a mystery to me why this didn't appear earlier. The output of sanitizer is:

./test/selftest -r thread
...
Write of size 8 at 0x7b4c00034428 by thread T59 (mutexes: write M0):
    #0 handle_incoming_sr /home/cspiel/src/baresip/re/src/rtp/sess.c:181
    ...
Previous read of size 8 at 0x7b4c00034428 by main thread (mutexes: write M1):
    #0 sender_apply_handler /home/cspiel/src/baresip/re/src/rtp/sess.c:400

@sreimers solutions that I can think of

(A) Run the RTCP sender report timer in the RX thread.
(B) Add a mutex to struct rtp_source.

(A) most likely would produce new concurrency problems that would have to be solved.
While with (B) we have to be careful to hold lock time short and don't forget any r/w cases.

edit: Just realized that this should not occur, because the write to the struct rtp_source fields should be done also in main thread. So the correct solution is to ensure that both read and write is done in main thread.

edit 2: Last edit was not correct. The RTCP call back handler in baresip passes RTCP work to the main thread. But in re there are write operations to struct rtp_source done by rtcp_recv_handler() and rtcp_sess_rx_rtp() which run in the RX thread. Thus we need to handle this somehow. Solution (B)?

cspiel1 · 2023-12-29T09:44:50Z

Most of the RTCP work in re is done from RX thread if activated.
These functions are called from main thread:

rtcp_debug()
rtcp_stats()
send_rtcp_report(), but this could be changed with solution (A)

cspiel1 · 2024-01-02T13:42:05Z

Last commit implements solution (A).

TODO:

lock rtcp_debug()
lock rtcp_stats()

Edit: Done with this PR in re: baresip/re#1037

cspiel1 · 2024-01-03T10:26:50Z

Rebased and dropped the reverted changes in tests.

The following commit will add delayed calls to audio_debug(). There are further concurrency problems with RTCP.

Fixes the sanitizer warning "unlock of an unlocked mutex"

This reverts commit ee740e3.

adds command arguments for selecting rx mode

This solves concurrency failures with RX thread for RTCP.

cspiel1 · 2024-01-09T14:56:55Z

Rebased after merge of aur: a mutex for aubuf allocation #2867.
made test_call_rtcp more stable and faster with https://github.com/baresip/baresip/compare/26136d611b10227b01cbf71438336c2e5bf4cf17..a5f8af44e73a3e75802b52dc91d314a37b9a0d45

When waiting on multiple different events with valgrind it showed that 2ms timers lead to a faster test finish than 1ms timers.

alfredh · 2024-01-11T08:03:35Z

it should be ok to merge this now..

cspiel1 · 2024-01-11T08:49:50Z

Thank you for your support, reviews and interest on this work!

cspiel1 added the RX thread RX real-time thread label Dec 12, 2023

cspiel1 mentioned this pull request Dec 18, 2023

Rx thread with separate audio activate cspiel1/baresip#2

Closed

alfredh added this to the v3.9.0 milestone Dec 22, 2023

alfredh reviewed Dec 28, 2023

View reviewed changes

cspiel1 force-pushed the rx_thread_activate branch from 5851e48 to 1121860 Compare December 28, 2023 13:37

alfredh removed this from the v3.9.0 milestone Jan 1, 2024

cspiel1 force-pushed the rx_thread_activate branch from bc82df7 to a16aff0 Compare January 3, 2024 09:34

cspiel1 mentioned this pull request Jan 4, 2024

rtp: lock more fields from rtcp_sess baresip/re#1039

Merged

cspiel1 added 10 commits January 9, 2024 13:15

stream,rtprecv: activate RX thread via config

4d753f8

test: main - init async workers

f2ec602

rtprecv: detach from RTP/RTCP sockets before re_cancel

c9cb9fb

stream,rtprecv: detach from RTP/RTCP also in RECEIVE_MODE_MAIN

a8954e2

rtprecv: use enable flag to prevent data race on stream termination

1714cc7

test: call - failure debug for test_media_base()

6d10b2e

[TMP] ci: activate verbose logging for valgrind workflow

8b4586a

rtprecv: detach sockets before attach

54cb68a

rtprecv: warnings for UDP thread attach

c24251b

aur: add mutex locks

8028ee0

cspiel1 force-pushed the rx_thread_activate branch 2 times, most recently from 26136d6 to a5f8af4 Compare January 9, 2024 14:11

cspiel1 added 8 commits January 9, 2024 15:48

aur: correct err handling in aurecv_receive()

7c2d61b

Fixes the sanitizer warning "unlock of an unlocked mutex"

Revert "[TMP] ci: activate verbose logging for valgrind workflow"

047ab5e

This reverts commit ee740e3.

rtprecv: print info when RX thread is started

3b2081c

config: match all values of rtp_rxmode

71cf6a0

config: use switch for RTP receive mode

feda0dd

test: run all tests in both RTP rx modes

4c5b0ba

adds command arguments for selecting rx mode

stream,rtprecv: move send RTCP to rtprecv

39188b5

This solves concurrency failures with RX thread for RTCP.

test: call - do not unsupported combination bundle with RX thread

82cfed3

cspiel1 force-pushed the rx_thread_activate branch from a5f8af4 to e42bf7d Compare January 9, 2024 14:51

cspiel1 added 2 commits January 9, 2024 15:59

rtprecv: avoid concurrent r/w of rtcp_peer and cname

2e75744

test: call - accelerate valgrind test

a17e198

When waiting on multiple different events with valgrind it showed that 2ms timers lead to a faster test finish than 1ms timers.

cspiel1 force-pushed the rx_thread_activate branch from e42bf7d to a17e198 Compare January 9, 2024 14:59

sreimers changed the title ~~rx thread activate~~ misc: rx thread activate Jan 11, 2024

sreimers merged commit 66ee75e into baresip:main Jan 11, 2024
16 checks passed

cspiel1 deleted the rx_thread_activate branch January 11, 2024 08:48

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

misc: rx thread activate #2828

misc: rx thread activate #2828

cspiel1 commented Dec 12, 2023 •

edited

cspiel1 commented Dec 12, 2023

cspiel1 commented Dec 13, 2023 •

edited

larsimmisch commented Dec 13, 2023 •

edited

larsimmisch commented Dec 13, 2023

juha-h commented Dec 14, 2023

cspiel1 commented Dec 14, 2023

cspiel1 commented Dec 14, 2023

larsimmisch commented Dec 14, 2023

cspiel1 commented Dec 14, 2023

alfredh Dec 28, 2023

cspiel1 Dec 28, 2023

alfredh Dec 28, 2023

alfredh Dec 28, 2023

cspiel1 Dec 28, 2023

alfredh Dec 28, 2023

juha-h commented Dec 28, 2023

cspiel1 commented Dec 28, 2023 •

edited

cspiel1 commented Dec 28, 2023 •

edited

cspiel1 commented Dec 28, 2023 •

edited

juha-h commented Dec 29, 2023

cspiel1 commented Dec 29, 2023

cspiel1 commented Dec 29, 2023 •

edited

cspiel1 commented Dec 29, 2023

cspiel1 commented Jan 2, 2024 •

edited

cspiel1 commented Jan 3, 2024

cspiel1 commented Jan 9, 2024

alfredh commented Jan 11, 2024

cspiel1 commented Jan 11, 2024

misc: rx thread activate #2828

misc: rx thread activate #2828

Conversation

cspiel1 commented Dec 12, 2023 • edited

cspiel1 commented Dec 12, 2023

cspiel1 commented Dec 13, 2023 • edited

larsimmisch commented Dec 13, 2023 • edited

larsimmisch commented Dec 13, 2023

juha-h commented Dec 14, 2023

cspiel1 commented Dec 14, 2023

cspiel1 commented Dec 14, 2023

larsimmisch commented Dec 14, 2023

cspiel1 commented Dec 14, 2023

alfredh Dec 28, 2023

Choose a reason for hiding this comment

cspiel1 Dec 28, 2023

Choose a reason for hiding this comment

alfredh Dec 28, 2023

Choose a reason for hiding this comment

alfredh Dec 28, 2023

Choose a reason for hiding this comment

cspiel1 Dec 28, 2023

Choose a reason for hiding this comment

alfredh Dec 28, 2023

Choose a reason for hiding this comment

juha-h commented Dec 28, 2023

cspiel1 commented Dec 28, 2023 • edited

cspiel1 commented Dec 28, 2023 • edited

cspiel1 commented Dec 28, 2023 • edited

juha-h commented Dec 29, 2023

cspiel1 commented Dec 29, 2023

cspiel1 commented Dec 29, 2023 • edited

cspiel1 commented Dec 29, 2023

cspiel1 commented Jan 2, 2024 • edited

cspiel1 commented Jan 3, 2024

cspiel1 commented Jan 9, 2024

alfredh commented Jan 11, 2024

cspiel1 commented Jan 11, 2024

cspiel1 commented Dec 12, 2023 •

edited

cspiel1 commented Dec 13, 2023 •

edited

larsimmisch commented Dec 13, 2023 •

edited

cspiel1 commented Dec 28, 2023 •

edited

cspiel1 commented Dec 28, 2023 •

edited

cspiel1 commented Dec 28, 2023 •

edited

cspiel1 commented Dec 29, 2023 •

edited

cspiel1 commented Jan 2, 2024 •

edited