Reported by @juha-h You can view, comment on, or merge this pull request online at:
https://github.com/kamailio/kamailio/pull/505
-- Commit Summary --
* rtpengine: Fix node selection for branching cases * rtpengine: LM_NOTICE to LM_DBG
-- File Changes --
M modules/rtpengine/rtpengine.c (27) M modules/rtpengine/rtpengine.h (10) M modules/rtpengine/rtpengine_hash.c (23) M modules/rtpengine/rtpengine_hash.h (4)
-- Patch Links --
https://github.com/kamailio/kamailio/pull/505.patch https://github.com/kamailio/kamailio/pull/505.diff
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505
@juha-h can you try a basic call with DBG mode enable? You should see a log like "rtpengine hash table lookup *find* ..." for the rtpengine_delete(); no corner case scenarios can happen now.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-181869308
Stefan Mititelu writes:
@juha-h can you try a basic call with DBG mode enable? You should see a log like "rtpengine hash table lookup *find* ..." for the rtpengine_delete(); no corner case scenarios can happen now.
Thanks. I tried by setting rtpengine-deamon log level to 7 and basic call looked fine (below). Do you still want me to try with DBG mode enabled in sip proxy?
-- Juha
Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] Received command 'offer' from 127.0.0.1:49451 Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] Dump for 'offer' from 127.0.0.1:49451: { "sdp": "v=0#015#012o=- 2334591646 33598050 IN IP4 192.168.43.192#015#012s=-#015#012c=IN IP4 192.168.43.192#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 10048 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=28000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:16163482 ... Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] ... 40 cname:sip:test@test.tutpro.com#015#012a=ptime:20#015#012", "ICE": "force", "replace": [ "session-connection", "origin" ], "rtcp-mux": [ "demux" ], "call-id": "7d8ec027d2946082", "via-branch": "z9hG4bK57e0626a25057f600", "received-from": [ "IP4", "192.98.102.10" ], "from-tag": "f689633ed9bd0645", "command": "offer" } Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] Creating new call Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] set FILLED flag for stream 192.168.43.192:10048 Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] set FILLED flag for stream 192.168.43.192:10049 Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] Replying to 'offer' from 127.0.0.1:49451 Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] Response dump for 'offer' to 127.0.0.1:49451: { "sdp": "v=0#015#012o=- 2334591646 33598050 IN IP4 192.98.102.10#015#012s=-#015#012c=IN IP4 192.98.102.10#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 50166 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=28000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:1616348240 cnam ... Feb 9 21:42:20 lohi rtpengine[8740]: [7d8ec027d2946082] ... e:sip:test@test.tutpro.com#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:50167#015#012a=ice-ufrag:5SR7PDNn#015#012a=ice-pwd:VfSLqwyH9CdXbfpQTZSRHDmKve#015#012a=candidate:mUYmXd5Zbyf38MFb 1 UDP 2130706431 192.98.102.10 50166 typ host#015#012a=candidate:mUYmXd5Zbyf38MFb 2 UDP 2130706430 192.98.102.10 50167 typ host#015#012", "result": "ok" } Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] Received command 'answer' from 127.0.0.1:43744 Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] Dump for 'answer' from 127.0.0.1:43744: { "sdp": "v=0#015#012o=- 1380191758 160992788 IN IP4 192.168.43.192#015#012s=-#015#012c=IN IP4 192.168.43.192#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 10490 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=38000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:844455 ... Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] ... 395 cname:sip:jh@test.tutpro.com#015#012a=ptime:20#015#012", "ICE": "force", "replace": [ "session-connection", "origin" ], "call-id": "7d8ec027d2946082", "via-branch": "z9hG4bK57e0626a25057f600", "received-from": [ "IP4", "192.98.102.10" ], "from-tag": "f689633ed9bd0645", "to-tag": "24962b8b5e9563f0", "command": "answer" } Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] set FILLED flag for stream 192.168.43.192:10490 Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] set FILLED flag for stream 192.168.43.192:10491 Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] Shutting down ICE agent (nothing to do) Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] Replying to 'answer' from 127.0.0.1:43744 Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] Response dump for 'answer' to 127.0.0.1:43744: { "sdp": "v=0#015#012o=- 1380191758 160992788 IN IP4 192.98.102.10#015#012s=-#015#012c=IN IP4 192.98.102.10#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 50184 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=38000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:844455395 cna ... Feb 9 21:42:24 lohi rtpengine[8740]: [7d8ec027d2946082] ... me:sip:jh@test.tutpro.com#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:50185#015#012a=candidate:mUYmXd5Zbyf38MFb 1 UDP 2130706431 192.98.102.10 50184 typ host#015#012a=candidate:mUYmXd5Zbyf38MFb 2 UDP 2130706430 192.98.102.10 50185 typ host#015#012", "result": "ok" } Feb 9 21:42:27 lohi /usr/bin/sip-proxy[13530]: INFO: ===== rtpengine_delete() Feb 9 21:42:27 lohi rtpengine[8740]: [7d8ec027d2946082] Received command 'delete' from 127.0.0.1:43744 Feb 9 21:42:27 lohi rtpengine[8740]: [7d8ec027d2946082] Dump for 'delete' from 127.0.0.1:43744: { "call-id": "7d8ec027d2946082", "received-from": [ "IP4", "192.98.102.10" ], "from-tag": "24962b8b5e9563f0", "command": "delete" } Feb 9 21:42:27 lohi rtpengine[8740]: [7d8ec027d2946082] Scheduling deletion of call branch '24962b8b5e9563f0' (via-branch '') in 30 seconds Feb 9 21:42:27 lohi rtpengine[8740]: [7d8ec027d2946082] Replying to 'delete' from 127.0.0.1:43744 Feb 9 21:42:27 lohi rtpengine[8740]: [7d8ec027d2946082] Response dump for 'delete' to 127.0.0.1:43744: { "created": 1455046940, "last signal": 1455046944, "tags": { "24962b8b5e9563f0": { "tag": "24962b8b5e9563f0", "via-branch": "z9hG4bK57e0626a25057f600", "created": 1455046940, "in dialogue with": "f689633ed9bd0645", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 50166, "endpoint": { "family": "IPv4", "address": "192.98.102.10", "port": 10490 }, "advertised endpoint": { "family": "IPv4", "address": "192 ...
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-182030839
Do you still want me to try with DBG mode enabled in sip proxy?
If it's not much fuss to do it, try it. You should **not** see that "failed to" log anymore, after rtpengine_delete(): ``` rtpengine [rtpengine.c:2792]: select_rtpp_node_old(): rtpengine hash table lookup **failed to** find node for calllen=16 callid=d2016dd39cf7e31c viabranch= ```
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-182047863
Stefan Mititelu writes:
Do you still want me to try with DBG mode enabled in sip proxy?
If it's not much fuss to do it, try it. You should **not** see that "failed to" log anymore, after rtpengine_delete():
rtpengine [rtpengine.c:2792]: select_rtpp_node_old(): rtpengine hash table lookup **failed to** find node for calllen=16 callid=d2016dd39cf7e31c viabranch=
Yes, delete now found the node.
-- Juha
----------------------------------------------------------------
offer:
Feb 10 10:04:06 lohi /usr/bin/sip-proxy[13522]: DEBUG: rtpengine [rtpengine_funcs.c:140]: check_content_type(): type <application/sdp> found valid Feb 10 10:04:06 lohi /usr/bin/sip-proxy[13522]: DEBUG: rtpengine [rtpengine.c:2783]: select_rtpp_node_old(): rtpengine hash table lookup failed to find node for calllen=16 callid=aadd929dff468052 viabranch=z9hG4bK229e3f7bc66b04600 Feb 10 10:04:06 lohi /usr/bin/sip-proxy[13522]: DEBUG: rtpengine [rtpengine.c:2764]: select_rtpp_node_new(): rtpengine hash table insert node=udp:127.0.0.1:6050 for calllen=16 callid=aadd929dff468052 viabranch=z9hG4bK229e3f7bc66b04600 Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] Received command 'offer' from 127.0.0.1:34087 Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] Dump for 'offer' from 127.0.0.1:34087: { "sdp": "v=0#015#012o=- 3463663724 1174218402 IN IP4 192.168.43.192#015#012s=-#015#012c=IN IP4 192.168.43.192#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 10738 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=28000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:499419 ... Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] ... 868 cname:sip:test@test.tutpro.com#015#012a=ptime:20#015#012", "ICE": "force", "replace": [ "session-connection", "origin" ], "rtcp-mux": [ "demux" ], "call-id": "aadd929dff468052", "via-branch": "z9hG4bK229e3f7bc66b04600", "received-from": [ "IP4", "192.98.102.10" ], "from-tag": "871eb715d6da4e97", "command": "offer" } Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] Creating new call Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] set FILLED flag for stream 192.168.43.192:10738 Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] set FILLED flag for stream 192.168.43.192:10739 Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] Replying to 'offer' from 127.0.0.1:34087 Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] Response dump for 'offer' to 127.0.0.1:34087: { "sdp": "v=0#015#012o=- 3463663724 1174218402 IN IP4 192.98.102.10#015#012s=-#015#012c=IN IP4 192.98.102.10#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 50198 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=28000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:499419868 cna ... Feb 10 10:04:06 lohi rtpengine[8740]: [aadd929dff468052] ... me:sip:test@test.tutpro.com#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:50199#015#012a=ice-ufrag:RDELRwuh#015#012a=ice-pwd:12WaCa7OnvEgux6basWDEMUunw#015#012a=candidate:mUYmXd5Zbyf38MFb 1 UDP 2130706431 192.98.102.10 50198 typ host#015#012a=candidate:mUYmXd5Zbyf38MFb 2 UDP 2130706430 192.98.102.10 50199 typ host#015#012", "result": "ok" } Feb 10 10:04:06 lohi /usr/bin/sip-proxy[13522]: DEBUG: rtpengine [rtpengine.c:2346]: rtpp_function_call(): proxy reply: d3:sdp723:v=0#015#012o=- 3463663724 1174218402 IN IP4 192.98.102.10#015#012s=-#015#012c=IN IP4 192.98.102.10#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 50198 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=28000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:499419868 cname:sip:test@test.tutpro.com#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:50199#015#012a=ice-ufrag:RDELRwuh#015#012a=ice-pwd:12WaCa7OnvEgux6basWDEMUunw#015#012a=candidate:mUYmXd5Zbyf38MFb 1 UDP 2130706431 192.98.102.10 50198 typ host#015#012a=candidate:mUYmXd5Zbyf38MFb 2 UDP 2130706430 192.98.102.10 50199 typ h ost#015#0126:result2:oke
answer:
Feb 10 10:04:10 lohi /usr/bin/sip-proxy[13534]: DEBUG: rtpengine [rtpengine_funcs.c:140]: check_content_type(): type <application/sdp> found valid Feb 10 10:04:10 lohi /usr/bin/sip-proxy[13534]: DEBUG: rtpengine [rtpengine.c:2787]: select_rtpp_node_old(): rtpengine hash table lookup find node=udp:127.0.0.1:6050 for calllen=16 callid=aadd929dff468052 viabranch=z9hG4bK229e3f7bc66b04600 Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] Received command 'answer' from 127.0.0.1:54308 Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] Dump for 'answer' from 127.0.0.1:54308: { "sdp": "v=0#015#012o=- 4165365918 185414601 IN IP4 192.168.43.192#015#012s=-#015#012c=IN IP4 192.168.43.192#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 10584 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=38000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:735932 ... Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] ... 903 cname:sip:jh@test.tutpro.com#015#012a=ptime:20#015#012", "ICE": "force", "replace": [ "session-connection", "origin" ], "call-id": "aadd929dff468052", "via-branch": "z9hG4bK229e3f7bc66b04600", "received-from": [ "IP4", "192.98.102.10" ], "from-tag": "871eb715d6da4e97", "to-tag": "0602e3186d2a65d5", "command": "answer" } Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] set FILLED flag for stream 192.168.43.192:10584 Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] set FILLED flag for stream 192.168.43.192:10585 Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] Shutting down ICE agent (nothing to do) Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] Replying to 'answer' from 127.0.0.1:54308 Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] Response dump for 'answer' to 127.0.0.1:54308: { "sdp": "v=0#015#012o=- 4165365918 185414601 IN IP4 192.98.102.10#015#012s=-#015#012c=IN IP4 192.98.102.10#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 50206 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=38000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:735932903 cna ... Feb 10 10:04:10 lohi rtpengine[8740]: [aadd929dff468052] ... me:sip:jh@test.tutpro.com#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:50207#015#012a=candidate:mUYmXd5Zbyf38MFb 1 UDP 2130706431 192.98.102.10 50206 typ host#015#012a=candidate:mUYmXd5Zbyf38MFb 2 UDP 2130706430 192.98.102.10 50207 typ host#015#012", "result": "ok" } Feb 10 10:04:10 lohi /usr/bin/sip-proxy[13534]: DEBUG: rtpengine [rtpengine.c:2346]: rtpp_function_call(): proxy reply: d3:sdp660:v=0#015#012o=- 4165365918 185414601 IN IP4 192.98.102.10#015#012s=-#015#012c=IN IP4 192.98.102.10#015#012t=0 0#015#012a=tool:baresip 0.4.17#015#012m=audio 50206 RTP/AVP 96 97 0 8 101#015#012b=AS:128#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1;maxaveragebitrate=38000#015#012a=rtpmap:97 speex/8000#015#012a=fmtp:97 mode="3";vbr=off;cng=on#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:735932903 cname:sip:jh@test.tutpro.com#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:50207#015#012a=candidate:mUYmXd5Zbyf38MFb 1 UDP 2130706431 192.98.102.10 50206 typ host#015#012a=candidate:mUYmXd5Zbyf38MFb 2 UDP 2130706430 192.98.102.10 50207 typ host#015#0126:result2:oke Feb 10 10:04:14 lohi rtpengine[8740]: [aadd929dff468052 port 50206] Confirmed peer address as 192.98.102.10:10738 Feb 10 10:04:14 lohi rtpengine[8740]: [aadd929dff468052 port 50198] Confirmed peer address as 192.98.102.10:10584 Feb 10 10:04:14 lohi rtpengine[8740]: [aadd929dff468052 port 50198] Kernelizing media stream: 192.98.102.10:10584 Feb 10 10:04:14 lohi rtpengine[8740]: [aadd929dff468052 port 50206] Kernelizing media stream: 192.98.102.10:10738 Feb 10 10:04:15 lohi rtpengine[8740]: [aadd929dff468052 port 50199] Confirmed peer address as 192.98.102.10:10585 Feb 10 10:04:15 lohi rtpengine[8740]: [aadd929dff468052 port 50207] Confirmed peer address as 192.98.102.10:10739
delete:
Feb 10 10:04:16 lohi /usr/bin/sip-proxy[13534]: DEBUG: rtpengine [rtpengine.c:2787]: select_rtpp_node_old(): rtpengine hash table lookup find node=udp:127.0.0.1:6050 for calllen=16 callid=aadd929dff468052 viabranch= Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] Received command 'delete' from 127.0.0.1:54308 Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] Dump for 'delete' from 127.0.0.1:54308: { "call-id": "aadd929dff468052", "received-from": [ "IP4", "192.98.102.10" ], "from-tag": "0602e3186d2a65d5", "command": "delete" } Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] Scheduling deletion of call branch '0602e3186d2a65d5' (via-branch '') in 30 seconds Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] Replying to 'delete' from 127.0.0.1:54308 Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] Response dump for 'delete' to 127.0.0.1:54308: { "created": 1455091446, "last signal": 1455091450, "tags": { "0602e3186d2a65d5": { "tag": "0602e3186d2a65d5", "via-branch": "z9hG4bK229e3f7bc66b04600", "created": 1455091446, "in dialogue with": "871eb715d6da4e97", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 50198, "endpoint": { "family": "IPv4", "address": "192.98.102.10", "port": 10584 }, "advertised endpoint": { "family": "IPv4", "address": "192 ... Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] ... .168.43.192", "port": 10584 }, "last packet": 1455091456, "flags": [ "RTP", "filled", "confirmed", "kernelized" ], "stats": { "packets": 269, "bytes": 20350, "errors": 0 } }, { "local port": 50199, "endpoint": { "family": "IPv4", "address": "192.98.102.10", "port": 10585 }, "advertised endpoint": { "family": "IPv4", "address": "192.168.43.192", "port": 10585 }, "last packet": 1455091455, "flags": [ "RTCP", "filled", "confirmed" ], "stats": { "packets": 1, "bytes": 88, "errors": 0 } } ], "flags": ... Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] ... [ "initialized", "send", "recv" ] } ] }, "871eb715d6da4e97": { "tag": "871eb715d6da4e97", "created": 1455091446, "in dialogue with": "0602e3186d2a65d5", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 50206, "endpoint": { "family": "IPv4", "address": "192.98.102.10", "port": 10738 }, "advertised endpoint": { "family": "IPv4", "address": "192.168.43.192", "port": 10738 }, "last packet": 1455091456, "flags": [ "RTP", "filled", "confirmed", "kernelize ... Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] ... d" ], "stats": { "packets": 267, "bytes": 20388, "errors": 0 } }, { "local port": 50207, "endpoint": { "family": "IPv4", "address": "192.98.102.10", "port": 10739 }, "advertised endpoint": { "family": "IPv4", "address": "192.168.43.192", "port": 10739 }, "last packet": 1455091455, "flags": [ "RTCP", "filled", "confirmed", "kernelized", "no kernel support" ], "stats": { "packets": 1, "bytes": 88, "errors": 0 } } ], "flags": [ "initialized", "send", "recv" ] } ] } }, "totals": { "RTP": { "packets" ... Feb 10 10:04:16 lohi rtpengine[8740]: [aadd929dff468052] ... : 536, "bytes": 40738, "errors": 0 }, "RTCP": { "packets": 2, "bytes": 176, "errors": 0 } }, "result": "ok" } Feb 10 10:04:16 lohi /usr/bin/sip-proxy[13534]: DEBUG: rtpengine [rtpengine.c:2346]: rtpp_function_call(): proxy reply: d7:createdi1455091446e11:last signali1455091450e4:tagsd16:0602e3186d2a65d5d3:tag16:0602e3186d2a65d510:via-branch24:z9hG4bK229e3f7bc66b046007:createdi1455091446e16:in dialogue with16:871eb715d6da4e976:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local porti50198e8:endpointd6:family4:IPv47:address13:192.98.102.104:porti10584ee19:advertised endpointd6:family4:IPv47:address14:192.168.43.1924:porti10584ee11:last packeti1455091456e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi269e5:bytesi20350e6:errorsi0eeed10:local porti50199e8:endpointd6:family4:IPv47:address13:192.98.102.104:porti10585ee19:advertised endpointd6:family4:IPv47:address14:192.168.43.1924:porti10585ee11:last packeti1455091455e5:flagsl4:RTCP6:filled9:confirmede5:statsd7:packetsi1e5:bytesi88e6:errorsi0eeee5:flagsl11:initialized4:send4:recveeee16:871eb715d6da4e97d3:tag16:87 1eb715d6da4e977:createdi1455091446e16:in dialogue with16:0602e3186d2a65d56:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local porti50206e8:endpointd6:family4:IPv47:address13:192.98.102.104:porti10738ee19:advertised endpointd6:family4:IPv47:address14:192.168.43.1924:porti10738ee11:last packeti1455091456e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi267e5:bytesi20388e6:errorsi0eeed10:local porti50207e8:endpointd6:family4:IPv47:address13:192.98.102.104:porti10739ee19:advertised endpointd6:family4:IPv47:address14:192.168.43.1924:porti10739ee11:last packeti1455091455e5:flagsl4:RTCP6:filled9:confirmed10:kernelized17:no kernel supporte5:statsd7:packetsi1e5:bytesi88e6:errorsi0eeee5:flagsl11:initialized4:send4:recveeeee6:totalsd3:RTPd7:packetsi536e5:bytesi40738e6:errorsi0ee4:RTCPd7:packetsi2e5:bytesi176e6:errorsi0eee6:result2:oke Feb 10 10:04:16 lohi /usr/bin/sip-proxy[13534]: DEBUG: rtpengine [rtpengine.c:2383]: rtpp_function_call(): rtpengine hash table remove entry for callen=16 callid=aadd929dff468052 viabranch= Feb 10 10:04:35 lohi rtpengine[8740]: min_sessions:0 max_sessions:1, call_dur_per_interval:28.944547 at time 1455091475 Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] Call branch '0602e3186d2a65d5' (via-branch 'z9hG4bK229e3f7bc66b04600') deleted, no more branches remaining Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] Final packet stats: Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] --- Tag '871eb715d6da4e97', created 0:40 ago for branch '', in dialogue with '0602e3186d2a65d5' Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] ------ Media #1 (audio over RTP/AVP) using opus/48000/2 Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] --------- Port 50206 <> 192.98.102.10:10738, 287 p, 22051 b, 0 e, 1455091457 last_packet Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] --------- Port 50207 <> 192.98.102.10:10739 (RTCP), 2 p, 140 b, 0 e, 1455091456 last_packet Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] --- Tag '0602e3186d2a65d5', created 0:40 ago for branch 'z9hG4bK229e3f7bc66b04600', in dialogue with '871eb715d6da4e97' Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] ------ Media #1 (audio over RTP/AVP) using opus/48000/2 Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] --------- Port 50198 <> 192.98.102.10:10584, 289 p, 22011 b, 0 e, 1455091457 last_packet Feb 10 10:04:46 lohi rtpengine[8740]: [aadd929dff468052] --------- Port 50199 <> 192.98.102.10:10585 (RTCP), 2 p, 140 b, 0 e, 1455091456 last_packet Feb 10 10:05:35 lohi rtpengine[8740]: min_sessions:0 max_sessions:1, call_dur_per_interval:10.908616 at time 1455091535
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-182248387
Yes, delete now found the node.
Thank you for your input.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-182290336
Merged #505.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#event-561482039
Hi !
With this patch applied, I got a problem, let me explain this: - ua1 makes a first call - ua1 holds the first call to make a second call - ua1 hangups the second call and keep the first call on hold - when the TIMEOUT=60 will be reached, rptengine will removed the second call from memory, that's ok - now ua1 comes back to first call and rtpengine closes the call saying "Closing call due to timeout". But it's not the same call as the one previously destroyed, the callid/from/to tags are different.
in kamailio, for SIP request I'm using rtpengine_manage("replace-origin replace-session-connection RTP/AVP"); and for REPLY I'm using rtpengine_manage("replace-origin replace-session-connection RTP/SAVP");
Before this patch, all is fine for me.
Thanks.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-189346870
What happens in a scenario where no second call is made i.e.:
Ua1 makes call, places call on hold, waits for TIMEOUT=60 and comes back to the call?! On Feb 26, 2016 6:11 PM, "GG" notifications@github.com wrote:
Hi !
With this patch applied, I got a problem, let me explain this:
- ua1 makes a first call
- ua1 holds the first call to make a second call
- ua1 hangups the second call and keep the first call on hold
- when the TIMEOUT=60 will be reached, rptengine will removed the
second call from memory, that's ok
- now ua1 comes back to first call and rtpengine closes the call
saying "Closing call due to timeout". But it's not the same call as the one previously destroyed, the callid/from/to tags are different.
in kamailio, for SIP request I'm using rtpengine_manage("replace-origin replace-session-connection RTP/AVP"); and for REPLY I'm using rtpengine_manage("replace-origin replace-session-connection RTP/SAVP");
Before this patch, all is fine for me.
Thanks.
— Reply to this email directly or view it on GitHub https://github.com/kamailio/kamailio/pull/505#issuecomment-189346870.
sr-dev mailing list sr-dev@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
In this case, the call session is not destroyed, all is fine.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-189427197
The two calls have nothing in common i. e. Call id / viabranch?! On Feb 26, 2016 9:04 PM, "GG" notifications@github.com wrote:
In this case, the call session is not destroyed, all is fine.
— Reply to this email directly or view it on GitHub https://github.com/kamailio/kamailio/pull/505#issuecomment-189427197.
sr-dev mailing list sr-dev@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
I forgot to call rtpengine_manage for BYE request...
I dont' know if it's could explain my problem, but I will make some more tests. Sorry.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/505#issuecomment-189487455