search

sipwise / rtpengine

The Sipwise media proxy for Kamailio
GNU General Public License v3.0
763 stars 360 forks source link

`silent-timeout` not working #1818

Closed teamwcp closed 2 months ago

teamwcp commented 2 months ago

rtpengine version the issue has been seen with

12.3.1.2+0~mr12.3.1.2 git-mr12.3.1-6bbc2827

Used distribution and its version

Debian 11

Linux kernel version used

5.10.0-28-amd64

CPU architecture issue was seen on (see uname -m)

x86_64

Expected behaviour you didn't see

RTPEngine must detect a one-way media call and timeout a call using b2b-url. 

timeout = 30
silent-timeout = 30
tos = 184
delete-delay = 5
final-timeout = 3600
b2b-url = http://192.168.0.133:5060/RPC
xmlrpc-format = 2

Unexpected behaviour you saw

RTPEngine does not detect one-way media and call keep connected with kamailio server till user send a hang up (delete).

Steps to reproduce the problem

I am using two android devices (posrtSIP). Make call and turn off internet from one device. wait for 30 seconds so that silent-timeout can occur.

Additional program output to the terminal or logs illustrating the issue

I have followed the instructions provided in #1695, Thread kill calls show logs only after hangup. no logs during a call

$ pe -eLc | grep `pidof rtpengine`
 119063  119063 TS   19 ?        00:00:00 rtpengine
 119063  119064 TS   19 ?        00:00:00 signals
 119063  119066 TS   19 ?        00:00:00 release socks
 119063  119067 TS   19 ?        00:00:00 call stats
 119063  119068 TS   19 ?        00:00:00 kernel stats
 119063  119069 TS   19 ?        00:00:00 ICE slow
 119063  119070 TS   19 ?        00:00:00 kill calls
 119063  119071 TS   19 ?        00:00:00 DTLS refresh
 119063  119072 TS   19 ?        00:00:00 ICE
 119063  119073 TS   19 ?        00:00:00 websocket
$ strace -p 119070 
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 61) = 61
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 92) = 92
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 94) = 94
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 176) = 176
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 175) = 175
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 59) = 59
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 124) = 124
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 167) = 167
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 92) = 92
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 94) = 94
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 177) = 177
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 175) = 175
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 59) = 59
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 124) = 124
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 170) = 170
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 123) = 123
read(4, "\f\0\0\0\2\0\0\0\300\250\0\205\0\0\0\0\0\0\0\0\0\0\0\0\330\221\0\0\0\0\0\0"..., 1232) = 1232
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 123) = 123
read(4, "\f\0\0\0\2\0\0\0\300\250\0\205\0\0\0\0\0\0\0\0\0\0\0\0\331\221\0\0\0\0\0\0"..., 1232) = 1232
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 123) = 123
read(4, "\f\0\0\0\2\0\0\0\300\250\0\205\0\0\0\0\0\0\0\0\0\0\0\0\6\216\0\0\0\0\0\0"..., 1232) = 1232
write(2, "INFO: [gtGlhv77_tWcNEaOrWFtzA..]"..., 123) = 123
read(4, "\f\0\0\0\2\0\0\0\300\250\0\205\0\0\0\0\0\0\0\0\0\0\0\0\7\216\0\0\0\0\0\0"..., 1232) = 1232
epoll_ctl(5, EPOLL_CTL_DEL, 14, NULL)   = 0
epoll_ctl(5, EPOLL_CTL_DEL, 15, NULL)   = 0
epoll_ctl(5, EPOLL_CTL_DEL, 16, NULL)   = 0
epoll_ctl(5, EPOLL_CTL_DEL, 17, NULL)   = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7fb927354f50) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, ^Cstrace: Process 118389 detached
 <detached ...>

while rtpengine logs are like this

Apr 25 10:19:34 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [control] Received command 'offer' from 127.0.0.1:57489
Apr 25 10:19:34 debian11 rtpengine[118382]: NOTICE: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Creating new call
Apr 25 10:19:34 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [control] Replying to 'offer' from 127.0.0.1:57489 (elapsed time 0.003972 sec)
Apr 25 10:19:48 debian11 rtpengine[118382]: WARNING: [gtGlhv77_tWcNEaOrWFtzA..//1 port 37336]: [core] RTP packet with unknown payload type 126 received from 192.168.0.181:10100
Apr 25 10:19:48 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..//1 port 37337]: [rtcp] Ignoring unknown RTCP packet type 254
Apr 25 10:19:48 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [control] Received command 'offer' from 127.0.0.1:53336
Apr 25 10:19:48 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [control] Replying to 'offer' from 127.0.0.1:53336 (elapsed time 0.000169 sec)
Apr 25 10:19:49 debian11 rtpengine[118382]: WARNING: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36358]: [core] RTP packet with unknown payload type 126 received from 192.168.0.157:10300
Apr 25 10:19:49 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36359]: [rtcp] Ignoring unknown RTCP packet type 254
Apr 25 10:19:49 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../ce33db28/1 port 37337]: [rtcp] Ignoring unknown RTCP packet type 254
Apr 25 10:19:50 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36359]: [rtcp] Ignoring unknown RTCP packet type 254
Apr 25 10:19:50 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../ce33db28/1 port 37337]: [rtcp] Ignoring unknown RTCP packet type 254
Apr 25 10:19:50 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36359]: [rtcp] Ignoring unknown RTCP packet type 254
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36358]: [core] Confirmed peer address as 192.168.0.157:10300
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36358]: [core] Kernelizing media stream: 192.168.0.157:10300 -> 192.168.0.133:36358 | 192.168.0.133:37336 -> 192.168.0.181:10100
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../ce33db28/1 port 37336]: [core] Confirmed peer address as 192.168.0.181:10100
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../ce33db28/1 port 37336]: [core] Kernelizing media stream: 192.168.0.181:10100 -> 192.168.0.133:37336 | 192.168.0.133:36358 -> 192.168.0.157:10300
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36359]: [core] Confirmed peer address as 192.168.0.157:10301
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../036b3c67/1 port 36359]: [core] Kernelizing media stream: 192.168.0.157:10301 -> 192.168.0.133:36359 | 192.168.0.133:37337 -> 192.168.0.181:10101
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../ce33db28/1 port 37337]: [core] Confirmed peer address as 192.168.0.181:10101
Apr 25 10:19:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA../ce33db28/1 port 37337]: [core] Kernelizing media stream: 192.168.0.181:10101 -> 192.168.0.133:37337 | 192.168.0.133:36359 -> 192.168.0.157:10301

#### Switch off internet from one device

Apr 25 10:21:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [control] Received command 'delete' from 127.0.0.1:35958
Apr 25 10:21:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Scheduling deletion of call branch '036b3c67' (via-branch '') in 5 seconds
Apr 25 10:21:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Scheduling deletion of call branch 'ce33db28' (via-branch '') in 5 seconds
Apr 25 10:21:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Scheduling deletion of entire call in 5 seconds
Apr 25 10:21:52 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [control] Replying to 'delete' from 127.0.0.1:35958 (elapsed time 0.002466 sec)
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Final packet stats:
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --- Tag '036b3c67', created 2:23 ago for branch ''
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] ------ Media #1 (audio over RTP/AVP) using G729/8000
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --------- Port   192.168.0.133:36358 <>   192.168.0.157:10300, SSRC 4fee99ea, in 6169 p, 197392 b, 1 e, 4 ts, out 3050 p, 97584 b, 0 e
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --------- Port   192.168.0.133:36359 <>   192.168.0.157:10301 (RTCP), SSRC 4fee99ea, in 114 p, 4064 b, 0 e, 4 ts, out 5 p, 136 b, 0 e
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --- SSRC 4fee99ea
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] ------ Average MOS 4.2, lowest MOS 4.1 (at 1:00), highest MOS 4.3 (at 0:24) lost:0
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] ------ respective (avg/min/max) jitter 16/17/17 ms, RTT-e2e 60.9/184.3/32.7 ms, RTT-dsct 13.3/7.4/18.3 ms, packet loss 0/0/0%
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --- Tag 'ce33db28', created 2:23 ago for branch ''
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] ------ Media #1 (audio over RTP/AVP) using G729/8000
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --------- Port   192.168.0.133:37336 <>   192.168.0.181:10100, SSRC d3219fca, in 3050 p, 97584 b, 1 e, 67 ts, out 6169 p, 197392 b, 0 e
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --------- Port   192.168.0.133:37337 <>   192.168.0.181:10101 (RTCP), SSRC d3219fca, in 64 p, 2440 b, 1 e, 67 ts, out 6 p, 152 b, 0 e
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] --- SSRC d3219fca
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] ------ Average MOS 4.2, lowest MOS 4.1 (at 0:59), highest MOS 4.3 (at 0:18) lost:2
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] ------ respective (avg/min/max) jitter 17/16/17 ms, RTT-e2e 79.5/187.5/107.5 ms, RTT-dsct 66.0/176.9/96.8 ms, packet loss 0/0/0%
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Removing media stream from kernel: local 192.168.0.133:37336 (final call cleanup)
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Removing media stream from kernel: local 192.168.0.133:37337 (final call cleanup)
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Removing media stream from kernel: local 192.168.0.133:36358 (final call cleanup)
Apr 25 10:21:57 debian11 rtpengine[118382]: INFO: [gtGlhv77_tWcNEaOrWFtzA..]: [core] Removing media stream from kernel: local 192.168.0.133:36359 (final call cleanup)

Anything else?

if set final-timeout to 30 seconds then timeout is working fine and calling b2b-url as well.

Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] Closing call due to final timeout
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] Final packet stats:
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --- Tag 'c5b05652', created 0:30 ago for branch ''
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] ------ Media #1 (audio over RTP/AVP) using G729/8000
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --------- Port   192.168.0.133:30518 <>   192.168.0.157:10501, SSRC 3b64f432, in 1301 p, 41616 b, 1 e, 0 ts, out 1301 p, 41616 b, 0 e
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --------- Port   192.168.0.133:30519 <>   192.168.0.157:10502 (RTCP), SSRC 3b64f432, in 34 p, 1088 b, 0 e, 1 ts, out 6 p, 136 b, 0 e
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --- SSRC 3b64f432
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] ------ Average MOS 4.3, lowest MOS 4.3 (at 0:11), highest MOS 4.3 (at 0:11) lost:0
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] ------ respective (avg/min/max) jitter 10/10/10 ms, RTT-e2e 15.4/19.3/19.3 ms, RTT-dsct 8.8/12.2/12.2 ms, packet loss 0/0/0%
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --- Tag 'fc59a72c', created 0:30 ago for branch ''
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] ------ Media #1 (audio over RTP/AVP) using G729/8000
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --------- Port   192.168.0.133:37634 <>   192.168.0.129:10200, SSRC 86840326, in 1301 p, 41616 b, 1 e, 0 ts, out 1301 p, 41616 b, 0 e
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --------- Port   192.168.0.133:37635 <>   192.168.0.129:10201 (RTCP), SSRC 86840326, in 35 p, 1160 b, 1 e, 1 ts, out 6 p, 112 b, 0 e
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] --- SSRC 86840326
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] ------ Average MOS 4.3, lowest MOS 4.3 (at 0:07), highest MOS 4.3 (at 0:07) lost:0
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] ------ respective (avg/min/max) jitter 11/10/10 ms, RTT-e2e 21.2/31.9/31.9 ms, RTT-dsct 6.6/6.7/6.7 ms, packet loss 0/0/0%
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] Removing media stream from kernel: local 192.168.0.133:37634 (final call cleanup)
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] Removing media stream from kernel: local 192.168.0.133:37635 (final call cleanup)
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] Removing media stream from kernel: local 192.168.0.133:30518 (final call cleanup)
Apr 25 10:42:56 debian11 rtpengine[119063]: INFO: [LzrcFICeqXLkp3FcxnAAtw..]: [core] Removing media stream from kernel: local 192.168.0.133:30519 (final call cleanup)

and If turn off internet from both devices caller and callee then timeout is also working

Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] Closing call due to timeout
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] Final packet stats:
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --- Tag '1c6d8d39', created 1:15 ago for branch ''
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] ------ Media #1 (audio over RTP/AVP) using G729/8000
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --------- Port   192.168.0.133:35472 <>   192.168.0.157:10600, SSRC 4ae39cce, in 2091 p, 66896 b, 1 e, 30 ts, out 1775 p, 56784 b, 0 e
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --------- Port   192.168.0.133:35473 <>   192.168.0.157:10601 (RTCP), SSRC 4ae39cce, in 47 p, 1584 b, 1 e, 34 ts, out 7 p, 168 b, 0 e
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --- SSRC 4ae39cce
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] ------ Average MOS 4.2, lowest MOS 4.2 (at 0:11), highest MOS 4.3 (at 0:16) lost:0
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] ------ respective (avg/min/max) jitter 14/14/13 ms, RTT-e2e 80.6/158.6/17.1 ms, RTT-dsct 7.5/6.9/7.3 ms, packet loss 0/0/0%
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --- Tag 'b3e48f51', created 1:15 ago for branch ''
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] ------ Media #1 (audio over RTP/AVP) using G729/8000
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --------- Port   192.168.0.133:34180 <>   192.168.0.181:10300, SSRC a00639b2, in 1775 p, 56784 b, 1 e, 36 ts, out 2091 p, 66896 b, 0 e
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --------- Port   192.168.0.133:34181 <>   192.168.0.181:10301 (RTCP), SSRC a00639b2, in 40 p, 1368 b, 1 e, 38 ts, out 4 p, 80 b, 0 e
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] --- SSRC a00639b2
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] ------ Average MOS 4.2, lowest MOS 4.2 (at 0:08), highest MOS 4.3 (at 0:12) lost:0
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] ------ respective (avg/min/max) jitter 17/15/21 ms, RTT-e2e 73.9/158.0/16.7 ms, RTT-dsct 67.1/151.7/9.7 ms, packet loss 0/0/0%
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] Removing media stream from kernel: local 192.168.0.133:34180 (final call cleanup)
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] Removing media stream from kernel: local 192.168.0.133:34181 (final call cleanup)
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] Removing media stream from kernel: local 192.168.0.133:35472 (final call cleanup)
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [csmz_uQ7k2wrHX0Z3orLKQ..]: [core] Removing media stream from kernel: local 192.168.0.133:35473 (final call cleanup)
Apr 25 10:56:30 debian11 rtpengine[119119]: INFO: [core] Forking child to close call with tag csmz_uQ7k2wrHX0Z3orLKQ.. via XMLRPC call to http://192.168.0.133:5060/RPC
Apr 25 10:56:30 debian11 rtpengine[119148]: INFO: [core] Initiating XMLRPC call for tag csmz_uQ7k2wrHX0Z3orLKQ..
rfuchs commented 2 months ago

This is working as intended. silent-timeout is not meant to detect one-way audio and currently there is no mechanism to do so. Closing as this is not a bug, but rather a feature request.