[sr-dev] [kamailio] Fix node selection when rtpengine_delete(), for branching scenarios (#505)

juha-h notifications at github.com
Wed Feb 10 09:14:30 CET 2016


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 at 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 at 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 at 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 at 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 at 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 at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-dev/attachments/20160210/c8e9c492/attachment-0001.html>


More information about the sr-dev mailing list