audio forking problem

[spointer]

Hi, Dave.

Sometimes, websocket 'message' event is not received from freeswitch side even though i called uuid_audio_fork api(actually, drachtio-fsmrf forkAudioStart function).

So, i added some debugging code to eventcallback function of lws_glue.cpp and found bug pointer is null and user data is not sent to ws server even though the ws connection is successful.
I think this happens when CPU load is high or race condition.

Could you guess?
Any suggestion is appreciated.

freeswitch log is as follows:

7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.491887 [DEBUG] sofia.c:7290 Channel sofia/drachtio_mrf/nobody@172.26.0.2:5500 entering state [ready][200]
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.491887 [DEBUG] switch_ivr_async.c:1636 No silence detection configured; assuming start of speech
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.531887 [DEBUG] switch_ivr.c:632 sofia/drachtio_mrf/nobody@172.26.0.2:5500 Command Execute [depth=1] answer()
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 EXECUTE [depth=1] sofia/drachtio_mrf/nobody@172.26.0.2:5500 answer()
2021-09-29 10:28:06.571890 [DEBUG] mod_audio_fork.c:166 mod_audio_fork cmd: 7ef84a0c-20c4-11ec-a8b7-cd49a3992550 start http://192.168.10.69:3440/a97f0e7e-200f-11ec-8f5e-537098f85be9 mono 8000 '{"event":"start","data":{"startTime":"2021-09-29T01:28:05.907Z","projectId":"09a16296-9f9d-441c-b233-aed8092c0021","callingNumber":"2400","calledNumber":"3500","direction":"inbound","tid":"dDhKjM2hzeKy17SQMFZs","mediaUuid":"7ef84a0c-20c4-11ec-a8b7-cd49a3992550","wsEndpoint":"ws://localhost:3391/call/socket/09a16296-9f9d-441c-b233-aed8092c0021?callId=a97f0e7e-200f-11ec-8f5e-537098f85be9","ttl":1200,"connectionTimeout":10,"payload":{}}}'
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [INFO] mod_audio_fork.c:73 mod_audio_fork: streaming 8000 sampling to 192.168.10.69 path /a97f0e7e-200f-11ec-8f5e-537098f85be9 port 3440 tls: no.
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [DEBUG] mod_audio_fork.c:89 calling fork_session_init.
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [DEBUG] lws_glue.cpp:266 (6) no resampling needed for this call
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [DEBUG] lws_glue.cpp:269 (6) fork_data_init
2021-09-29 10:28:06.571890 [NOTICE] lws_glue.cpp:296 7ef84a0c-20c4-11ec-a8b7-cd49a3992550 after adding connect there are 1 pending connects

2021-09-29 10:28:06.571890 [NOTICE] lws_glue.cpp:296 7ef84a0c-20c4-11ec-a8b7-cd49a3992550 attempting connection, wsi is 0x7f21b4021790

7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [DEBUG] mod_audio_fork.c:95 adding bug.
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to sofia/drachtio_mrf/nobody@172.26.0.2:5500



**_7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [ERR] lws_glue.cpp:205 no bug_**



7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [DEBUG] mod_audio_fork.c:99 setting bug private data.
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.571890 [DEBUG] mod_audio_fork.c:102 exiting start_capture.
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.631910 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMA:8
7ef84a0c-20c4-11ec-a8b7-cd49a3992550 2021-09-29 10:28:06.811871 [INFO] switch_rtp.c:7680 Auto Changing audio port from 12.124.21.249:20206 to 172.26.0.1:57549

[spointer]

I'm guessing with freeswitch log that eventcallback is called before adding bug in start_capture function.

[davehorton]

yes it looks to me like a race condition at the start of the call..