[kamailio/kamailio] rtpengine -> send_rtpp_command(): mismatched cookie in websocket response (#2862)
### Description
Hi,
I've pushed some production traffic over latest 5.5.2 release on top of rtpengine connected over websocket ( jus ws://xxx.xx.xx.xx) .
`modparam("rtpengine", "wsapi", "lwsc")`
but from time to time I can see following error and rtpengine_manage fails
``` Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> lwsc [lwsc_mod.c:367]: ksr_lwsc_callback(): losing read buffer of 4096 bytes Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> rtpengine [rtpengine.c:3008]: send_rtpp_command(): mismatched cookie in websocket response Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> rtpengine [rtpengine.c:2678]: rtpp_function_call(): no available proxies
```
RTT towards rtpengine ~100-150ms
#### Debugging Data
#### Log Messages
``` Sep 24 19:42:58 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: New request - M=INVITE R=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain F=sip:+XXXXX@172.31.12.244 T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.136.115:5060) ID=bgfmx.localdomain_654888 Sep 24 19:42:58 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Add to rr sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain => c2lwOmNiMmU5NjRmLTFlYjctNDFmZS1hN2QzLTVmYWZlYmY0ZjNjOUBiZ2ZteC5jcmF6eWNhbGwuY29t Sep 24 19:42:58 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: RTPEngineID bgfmx.localdomain set from header to 3 ID=bgfmx.localdomain_654888 Sep 24 19:42:58 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Generated MOS A label for bgfmx.localdomain_654888 - a324492e-ea41-44c1-982e-8397799a08b1 Sep 24 19:42:58 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Generated MOS B label for bgfmx.localdomain_654888 - 8882300b-c07e-4f45-a864-1158b8412b60 Sep 24 19:42:58 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: SIP > WebRTC Sep 24 19:42:58 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: RTP Selected ws://xx.xx.xx.xx:22222 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Fix SDP BUNDLE for iOS devices Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15905]: INFO: [INVITE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: stored transaction [36958:1549764233] sip:+XXXXX@172.31.12.244 => sip:474tnvd1@15j11kooqfes.invalid;transport=ws Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15922]: INFO: [INVITE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply - S=100 - Trying M=INVITE IP=<null>:<null> (10.23.245.162:29794) ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15922]: INFO: [INVITE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply from websocket to SIP: 100 M=INVITE R=<null> F=sip:+XXXXX@bgfmx.localdomain T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.245.162:29794) ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15922]: INFO: [INVITE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply - S=180 - Ringing M=INVITE IP=<null>:<null> (10.23.245.162:29794) ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15922]: INFO: [INVITE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply from websocket to SIP: 180 M=INVITE R=<null> F=sip:+XXXXX@bgfmx.localdomain T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.245.162:29794) ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15922]: INFO: [INVITE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply - S=200 - OK M=INVITE IP=<null>:<null> (10.23.245.162:29794) ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15922]: INFO: [INVITE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply from websocket to SIP: 200 M=INVITE R=<null> F=sip:+XXXXX@bgfmx.localdomain T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.245.162:29794) ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15907]: INFO: [ACK bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: New request - M=ACK R=sip:474tnvd1@15j11kooqfes.invalid;alias=10.23.245.162~29794~5;transport=ws F=sip:+XXXXX@172.31.12.244 T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.136.115:5060) ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15907]: INFO: [ACK bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Desination WS - lookup sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15907]: INFO: [ACK bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Restored from RR header 15j11kooqfes.invalid -RTPEngineID 3 inst:<null> ID=bgfmx.localdomain_654888 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15907]: INFO: [ACK bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists A label for bgfmx.localdomain_654888 - a324492e-ea41-44c1-982e-8397799a08b1 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15907]: INFO: [ACK bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists B label for bgfmx.localdomain_654888 - 8882300b-c07e-4f45-a864-1158b8412b60 Sep 24 19:42:59 kamailio5 /usr/sbin/kamailio[15907]: INFO: [ACK bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: stored transaction [<null>:<null>] sip:+XXXXX@172.31.12.244 => sip:474tnvd1@15j11kooqfes.invalid;transport=ws Sep 24 19:43:13 kamailio5 /usr/sbin/kamailio[15908]: INFO: [INFO bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: New request - M=INFO R=sip:474tnvd1@15j11kooqfes.invalid;alias=10.23.245.162~29794~5;transport=ws F=sip:+XXXXX@172.31.12.244 T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.136.115:5060) ID=bgfmx.localdomain_654888 Sep 24 19:43:13 kamailio5 /usr/sbin/kamailio[15908]: INFO: [INFO bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Desination WS - lookup sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain ID=bgfmx.localdomain_654888 Sep 24 19:43:13 kamailio5 /usr/sbin/kamailio[15908]: INFO: [INFO bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Restored from RR header 15j11kooqfes.invalid -RTPEngineID 3 inst:<null> ID=bgfmx.localdomain_654888 Sep 24 19:43:13 kamailio5 /usr/sbin/kamailio[15908]: INFO: [INFO bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists A label for bgfmx.localdomain_654888 - a324492e-ea41-44c1-982e-8397799a08b1 Sep 24 19:43:13 kamailio5 /usr/sbin/kamailio[15908]: INFO: [INFO bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists B label for bgfmx.localdomain_654888 - 8882300b-c07e-4f45-a864-1158b8412b60 Sep 24 19:43:13 kamailio5 /usr/sbin/kamailio[15908]: INFO: [INFO bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: SIP-INFO received start recording ID=bgfmx.localdomain_654888 Sep 24 19:43:13 kamailio5 /usr/sbin/kamailio[15908]: INFO: [INFO bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: RTPENGINE STATS: mos_average/mos_average_packetloss/mos_average_jitter/mos_average_roundtrip 4.3/0/0/143763 Sep 24 19:44:16 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: New request - M=BYE R=sip:474tnvd1@15j11kooqfes.invalid;alias=10.23.245.162~29794~5;transport=ws F=sip:+XXXXX@172.31.12.244 T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.136.115:5060) ID=bgfmx.localdomain_654888 Sep 24 19:44:16 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Restored from RR header 15j11kooqfes.invalid -RTPEngineID 3 inst:<null> ID=bgfmx.localdomain_654888 Sep 24 19:44:16 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists A label for bgfmx.localdomain_654888 - 8882300b-c07e-4f45-a864-1158b8412b60 Sep 24 19:44:16 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists B label for bgfmx.localdomain_654888 - a324492e-ea41-44c1-982e-8397799a08b1 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> lwsc [lwsc_mod.c:367]: ksr_lwsc_callback(): losing read buffer of 4096 bytes Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> rtpengine [rtpengine.c:3008]: send_rtpp_command(): mismatched cookie in websocket response Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> rtpengine [rtpengine.c:2678]: rtpp_function_call(): no available proxies Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: RTPENGINE STATS: mos_average/mos_average_packetloss/mos_average_jitter/mos_average_roundtrip <null>/<null>/<null>/<null> Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Stop mediaproxy for all branches - R=sip:474tnvd1@15j11kooqfes.invalid;alias=10.23.245.162~29794~5;transport=ws ID=bgfmx.localdomain_654888 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> rtpengine [rtpengine.c:2678]: rtpp_function_call(): no available proxies Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> rtpengine [rtpengine.c:2678]: rtpp_function_call(): no available proxies Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Desination WS - lookup sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain ID=bgfmx.localdomain_654888 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Restored from RR header 15j11kooqfes.invalid -RTPEngineID 3 inst:<null> ID=bgfmx.localdomain_654888 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists A label for bgfmx.localdomain_654888 - 8882300b-c07e-4f45-a864-1158b8412b60 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: Exists B label for bgfmx.localdomain_654888 - a324492e-ea41-44c1-982e-8397799a08b1 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: SIP > WebRTC Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: ERROR: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> rtpengine [rtpengine.c:2678]: rtpp_function_call(): no available proxies Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: RTPEngine Failover no X-RTPEngineID-failover header failing to 1 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: post RTP Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: RTP Selected ws://52.209.63.240:22222 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15906]: INFO: [BYE bgfmx.localdomain_654888 10.23.136.115:5060@udp]--> <script>: stored transaction [36971:163653632] sip:+XXXXX@172.31.12.244 => sip:474tnvd1@15j11kooqfes.invalid;transport=ws Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15922]: INFO: [BYE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply - S=200 - OK M=BYE IP=<null>:<null> (10.23.245.162:29794) ID=bgfmx.localdomain_654888 Sep 24 19:44:17 kamailio5 /usr/sbin/kamailio[15922]: INFO: [BYE bgfmx.localdomain_654888 10.23.245.162:29794@ws]--> <script>: Reply from websocket to SIP: 200 M=BYE R=<null> F=sip:+XXXXX@bgfmx.localdomain T=sip:cb2e964f-1eb7-41fe-a7d3-5fafebf4f3c9@bgfmx.localdomain IP=10.23.136.115:5060 (10.23.245.162:29794) ID=bgfmx.localdomain_654888
``` RTPEngine log
``` Sep 24 19:42:58 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Received command 'offer' from 52.49.87.3:1816 Sep 24 19:42:58 ip-172-28-11-189 rtpengine[18874]: NOTICE: [bgfmx.localdomain_654888]: [core] Creating new call Sep 24 19:42:58 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Replying to 'offer' from 52.49.87.3:1816 (elapsed time 0.001349 sec) Sep 24 19:42:59 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888 port 32358]: [crypto] DTLS-SRTP successfully negotiated using AEAD_AES_256_GCM Sep 24 19:42:59 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888 port 32358]: [crypto] DTLS-SRTP successfully negotiated using AEAD_AES_256_GCM Sep 24 19:42:59 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Received command 'answer' from 52.49.87.3:2192 Sep 24 19:42:59 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [core] Received answer SDP with media ID ('audio') when no media ID was offered Sep 24 19:42:59 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [crypto] DTLS: Peer certificate accepted Sep 24 19:42:59 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Replying to 'answer' from 52.49.87.3:2192 (elapsed time 0.000811 sec) Sep 24 19:43:03 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888 port 32358]: [core] Confirmed peer address as 103.102.144.211:52093 Sep 24 19:43:03 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888 port 32380]: [core] Confirmed peer address as 52.209.63.245:56876 Sep 24 19:43:03 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888 port 32381]: [core] Confirmed peer address as 52.209.63.245:56877 Sep 24 19:43:13 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Received command 'start recording' from 52.49.87.3:30337 Sep 24 19:43:13 ip-172-28-11-189 rtpengine[18874]: ERR: [bgfmx.localdomain_654888]: [core] Call recording requested, but no spool directory configured Sep 24 19:43:13 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Replying to 'start recording' from 52.49.87.3:30337 (elapsed time 0.000009 sec) Sep 24 19:43:13 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Received command 'query' from 52.49.87.3:30337 Sep 24 19:43:13 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Replying to 'query' from 52.49.87.3:30337 (elapsed time 0.000131 sec) Sep 24 19:44:16 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Received command 'query' from 52.49.87.3:43726 Sep 24 19:44:16 ip-172-28-11-189 rtpengine[18874]: INFO: [bgfmx.localdomain_654888]: [control] Replying to 'query' from 52.49.87.3:43726 (elapsed time 0.000156 sec)
```
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
``` version: kamailio 5.5.2 (x86_64/linux) flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled with gcc 10.2.1
```
* **Operating System**:
``` root@kamailio5:~# kamailio -v version: kamailio 5.5.2 (x86_64/linux) flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled with gcc 10.2.1 root@kamailio5:~# uname -a Linux kamailio5 5.10.0-8-cloud-amd64 #1 SMP Debian 5.10.46-4 (2021-08-03) x86_64 GNU/Linux root@kamailio5:~# lsb_release -a No LSB modules are available. Distributor ID: Debian Description: Debian GNU/Linux 11 (bullseye) Release: 11 Codename: bullseye root@kamailio5:~#
``` rtpengine version on media proxy
``` ii ngcp-rtpengine 10.0.1.4+0~mr10.0.1.4 all NGCP RTP/media proxy - meta package ii ngcp-rtpengine-daemon 10.0.1.4+0~mr10.0.1.4 amd64 proxy for RTP and media streams used in NGCP, userspace part ii ngcp-rtpengine-iptables 10.0.1.4+0~mr10.0.1.4 amd64 IPtables extension module for the kernel-space NGCP media proxy ii ngcp-rtpengine-kernel-dkms 10.0.1.4+0~mr10.0.1.4 all IPtables kernel module for the NGCP media proxy - DKMS ii ngcp-rtpengine-kernel-source 10.0.1.4+0~mr10.0.1.4 all IPtables kernel module for the NGCP media proxy - source ii ngcp-rtpengine-recording-daemon 10.0.1.4+0~mr10.0.1.4 amd64 recording daemon for RTP and media streams ii ngcp-rtpengine-utils 10.0.1.4+0~mr10.0.1.4 all scripts and Perl modules for NGCP rtpengine
```
Hi @marcinkowalczyk , this doesn't appear to be a bug and I would encourage you to use the kamailio mailing list (or other forum such as matrix) for support. You may also want to look at https://github.com/sipwise/rtpengine for issues with rtpengine itself.
Closed #2862.
@fredposner in my opinion this is bug, as when kamailio rtpengine module works in udp mode (-ng protocol) everyting works like a charm. Problem is when kamailio rtpengine module uses ws connection towards rtpengine itself.
Reopened #2862.
Yes, it indeed looks like a bug. RTT 100-150ms sounds like a bit more than usual, do you have some kind of packet-loss if you debug e.g. with MTR to the rtpengine location for example?
Hi Henning,
After full night of production traffic I discovered this is not related to RTT, as happens to low-latency proxies too (~10ms no packet loss). Interesting part is that it hapens 99.9% in BYE so I think it may be related to rtpengine_delete() and fetching call stats like described in docs ``` 5.5. rtpengine_delete([flags]) Tears down the RTP proxy session for the current call. This populates the statistics pseudovariables (such “mos_min_pv” etc). ```
last night statistics - 83k calls:
``` root@kamailio5:~# grep -c 'ksr_lwsc_callback(): losing read buffer of 4096 bytes' /var/log/syslog 1433 root@kamailio5:~# ```
Thanks for the additional feedback. Maybe @rfuchs can comment. It would be probably a good idea to look with this information in the rtpengine issue tracker (link was posted already).
Looking at the code, I think this might be a bug in the `lwsc` module, triggered by more data coming in over the websocket than is being consumed by the lwsc receiver.
Can you test with master branch or the commit referenced above? If fixes it, then I will backport.
@marcinkowalczyk: have you had the chance to test with the patch referenced above?
Hi Daniel, I'm on holidays till Monday, I will check after weeeknd!
Hi @miconda I've just installed latest nightly build (deb version: kamailio 5.6.0-dev1). I will share results within couple of hours
@miconda seems issue is fixed. I've running traffic (50-50) with affected 5.5 and nightly 5.6 and it's ok with 5.6. Can you backport to 5.5 ? Thanks!
``` root@kamailio56:~# grep ksr_lwsc_callback /var/log/syslog root@kamailio56:~# ```
``` root@kamailio5:~# grep -c ksr_lwsc_callback /var/log/syslog 3709 root@kamailio5:~# ```
Closed #2862.
This got out of my sight -- just backported. Thanks for testing.
-
Daniel-Constantin Mierla -
Fred Posner
-
Henning Westerholt
-
marcinkowalczyk
-
Richard Fuchs