[SR-Users] rtpengine does not send RTP packets out

Sat Nov 1 20:39:47 CET 2014

Hi, I have kamilio-4.2 and rtpengine running on the same machine.I have this scenario:
softphone --> Kamailio with Rtpengine --> AsteriskThe softphone initiates the call, it is sent to the Asterisk. I can see the SDPs being re-written with the new IP/Ports provided by rtpengine:
Invite from Kamailio to Asterisk200 Ok from Kamailio to Softphone
However,  I take a signaling/media capture on the server where the kamailio/rtpengine are running and see the RTP coming from both endpoints (softphone and asterisk) to the correct ports but there is no packets coming out from the proxy to either direction.
I see these 2 lines on the rtpengine log and make me think that something prevents the rtpengine to stream out to the 2 endpoints:

Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] Write error on RTP socket
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] Final packet stats:

this is the log from the rtpengine:
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: Got valid command from 127.0.0.1:46686: offer - { "sdp": "v=0#015#012o=- 314474204173996793 6663595733338147866 IN IP4 99.153.161.148#015#012s=-#015#012c=IN IP4 99.153.161.148#015#012t=0 0#015#012m=audio 16386 RTP/AVP 114 0 8 101#015#012a=rtpmap:114 ilbc/8000#015#012a=fmtp:114 mode=30#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#012", "direction": [ "pub", "pub" ], "replace": [ "origin", "session-connection" ], "call-id": "0866b358-dc9c-1232-1399-3767db69b8dd", "received-from": [ "IP4", " ...
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: ... 99.153.161.148" ], "from-tag": "73rH43p60NeKm", "command": "offer" }
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd] Creating new call
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd] Opened ports 35022..35023 for media relay
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd] Opened ports 35038..35039 for media relay
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd] Returning to SIP proxy: d3:sdp529:v=0#015#012o=- 314474204173996793 6663595733338147866 IN IP4 54.173.60.13#015#012s=-#015#012c=IN IP4 54.173.60.13#015#012t=0 0#015#012a=ice-lite#015#012m=audio 35022 RTP/AVP 114 0 8 101#015#012a=rtpmap:114 ilbc/8000#015#012a=fmtp:114 mode=30#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=rtcp:35023#015#012a=ice-ufrag:oPm3I7OE#015#012a=ice-pwd:WjZnh7dnhfdkfoXDoqDbnCLLr7N7#015#012a=candidate:NZ1IXXQHYxOora9j 1 UDP 2130706431 54.173.60.13 35022 typ host#015#012a=candidate: ...
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd] ... NZ1IXXQHYxOora9j 2 UDP 2130706430 54.173.60.13 35023 typ host#015#0126:result2:oke
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: Got valid command from 127.0.0.1:46686: answer - { "sdp": "v=0#015#012o=root 439969655 439969655 IN IP4 205.10.248.62#015#012s=Asterisk PBX 1.8.10.0#015#012c=IN IP4 205.10.248.62#015#012t=0 0#015#012m=audio 11142 RTP/AVP 0 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=silenceSupp:off - - - -#015#012a=ptime:20#015#012a=sendrecv#015#012", "direction": [ "pub", "pub" ], "replace": [ "origin", "session-connection" ], "call-id": "0866b358-dc9c-1232-1399-3767db69b8dd", "received-from": [ "IP4", "205.10.248.62" ], "fr ...
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: ... om-tag": "73rH43p60NeKm", "to-tag": "as57e7b8e3", "command": "answer" }
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd] Returning to SIP proxy: d3:sdp500:v=0#015#012o=root 439969655 439969655 IN IP4 54.173.60.13#015#012s=Asterisk PBX 1.8.10.0#015#012c=IN IP4 54.173.60.13#015#012t=0 0#015#012a=ice-lite#015#012m=audio 35038 RTP/AVP 0 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=silenceSupp:off - - - -#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:35039#015#012a=ice-ufrag:cBL9SIw9#015#012a=ice-pwd:QHw7VHp83nMsLpD8ZoSqtDxGchN4#015#012a=candidate:NZ1IXXQHYxOora9j 1 UDP 2130706431 54.173.60.13 35038 typ host#015#012a=candidate:NZ1IXXQHYxOora9j 2 UDP 213070 ...
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd] ... 6430 54.173.60.13 35039 typ host#015#0126:result2:oke
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] Write error on RTP socket
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] Final packet stats:
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] --- Tag 'as57e7b8e3', created 0:00 ago, in dialogue with '73rH43p60NeKm'
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] ------ Media #1, port 35022 <>    205.10.248.62:11142, 0 p, 0 b, 0 e
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] ------ Media #1, port 35023 <>    205.10.248.62:11143 (RTCP), 0 p, 0 b, 0 e
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] --- Tag '73rH43p60NeKm', created 0:00 ago, in dialogue with 'as57e7b8e3'
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] ------ Media #1, port 35038 <>  99.153.161.148:16386, 0 p, 0 b, 1 e
Nov  1 18:59:26 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] ------ Media #1, port 35039 <>  99.153.161.148:16387 (RTCP), 0 p, 0 b, 0 e
Nov  1 18:59:36 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] Got valid command from 127.0.0.1:46686: delete - { "call-id": "0866b358-dc9c-1232-1399-3767db69b8dd", "received-from": [ "IP4", "205.10.248.62" ], "from-tag": "as57e7b8e3", "command": "delete" }
Nov  1 18:59:36 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] [0866b358-dc9c-1232-1399-3767db69b8dd] Call-ID to delete not found
Nov  1 18:59:36 ip-10-0-2-68 rtpengine[27764]: [0866b358-dc9c-1232-1399-3767db69b8dd port 35038] Returning to SIP proxy: d7:warning38:Call-ID not found or tags didn't match6:result2:oke

this is the log from kamailio (showing only the lines that include the word rtpengine):
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: INFO: <script>: mylog: TO_FS: Starting rtpengine session. Invite
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: exec: *** cfgtrace:request_route=[TO_FS] c=[/usr/local/kamailio-install-dir//etc/kamailio//kamailio.cfg] l=441 a=25 n=rtpengine_offer
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: DEBUG: rtpengine [rtpengine_funcs.c:148]: check_content_type(): type <application/sdp> found valid
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: DEBUG: rtpengine [rtpengine.c:1448]: rtpp_function_call(): proxy reply: d3:sdp529:v=0#015#012o=- 314474204173996793 6663595733338147866 IN IP4 54.173.60.13#015#012s=-#015#012c=IN IP4 54.173.60.13#015#012t=0 0#015#012a=ice-lite#015#012m=audio 35022 RTP/AVP 114 0 8 101#015#012a=rtpmap:114 ilbc/8000#015#012a=fmtp:114 mode=30#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=rtcp:35023#015#012a=ice-ufrag:oPm3I7OE#015#012a=ice-pwd:WjZnh7dnhfdkfoXDoqDbnCLLr7N7#015#012a=candidate:NZ1IXXQHYxOora9j 1 UDP 2130706431 54.173.60.13 35022 typ host#015#012a=candidate:NZ1IXXQHYxOora9j 2 UDP 2130706430 54.173.60.13 35023 typ host#015#0126:result2:oke
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: INFO: <script>: mylog: Starting rtpengine session. Answer
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: exec: *** cfgtrace:onreply_route=[TO_FS] c=[/usr/local/kamailio-install-dir//etc/kamailio//kamailio.cfg] l=476 a=25 n=rtpengine_answer
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: DEBUG: rtpengine [rtpengine_funcs.c:148]: check_content_type(): type <application/sdp> found valid
Nov  1 18:59:26 ip-10-0-2-68 ./kamailio[28001]: DEBUG: rtpengine [rtpengine.c:1448]: rtpp_function_call(): proxy reply: d3:sdp500:v=0#015#012o=root 439969655 439969655 IN IP4 54.173.60.13#015#012s=Asterisk PBX 1.8.10.0#015#012c=IN IP4 54.173.60.13#015#012t=0 0#015#012a=ice-lite#015#012m=audio 35038 RTP/AVP 0 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=silenceSupp:off - - - -#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:35039#015#012a=ice-ufrag:cBL9SIw9#015#012a=ice-pwd:QHw7VHp83nMsLpD8ZoSqtDxGchN4#015#012a=candidate:NZ1IXXQHYxOora9j 1 UDP 2130706431 54.173.60.13 35038 typ host#015#012a=candidate:NZ1IXXQHYxOora9j 2 UDP 2130706430 54.173.60.13 35039 typ host#015#0126:result2:oke
Nov  1 18:59:36 ip-10-0-2-68 ./kamailio[28001]: exec: *** cfgtrace:request_route=[LOOSE_ROUTE] c=[/usr/local/kamailio-install-dir//etc/kamailio//kamailio.cfg] l=488 a=24 n=rtpengine_delete
Nov  1 18:59:36 ip-10-0-2-68 ./kamailio[28001]: DEBUG: rtpengine [rtpengine.c:1448]: rtpp_function_call(): proxy reply: d7:warning38:Call-ID not found or tags didn't match6:result2:oke

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20141101/be9daa46/attachment.html>