[SR-Users] insufficient ports returned from mediaproxy

Morten Isaksen misak at misak.dk
Thu May 15 14:45:50 CEST 2014


We have a periodic problem with the communication between mediaproxy
(kamailio module) <-> media-dispatcher <-> media-relay

The problems seems to be that media-dispatcher mixes the requests and
answers, so kamailio get a wrong answer to its request.

Kamailio 3.1.1
Mediaproxy 2.4.4

I know they are old versions, but I have checket the new releases, and it
does not look like anything related to this has been changed.

This log snippet illustrates the problem well. We have added a few extra
debug information:

PID 3433 sends a update request to dispatcher
dispatcher sends request to relay 10.253.253.32
relay 10.253.253.32 answers dispatcher
PID 5214 sends a remove request to dispatcher
dispatcher sends request to relay 10.253.253.32
relay 10.253.253.32 answers dispatcher
dispatcher answer PID 3433 with the answer for PID 5214

The answer for PID 3433 is newer received by kamailio.


May 15 08:02:33 sip-3-1 /usr/local/sbin/kamailio[5211]: WARNING: <script>:
new request M=INVITE RURI=sip:40804XXX at 76752XXX.example.com F=
sip:40804XXX at 76752XXX.example.com T=sip:40804XXX at 172.16.9.20 IP=172.16.9.20
ID=738ce06b2a507610599b767b6b164657 at hpbxout.one-connect.dk
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: Command update
Headers ['type: request', 'call_id:
738ce06b2a507610599b767b6b164657 at hpbxout.one-connect.dk', 'cseq: 102',
'from_uri: 40804XXX at 76752XXX.example.com', 'to_uri: 40804XXX at 172.16.9.20',
'from_tag: as35017b2b', 'user_agent: one-connect', 'signaling_ip:
172.16.9.20', 'media: audio:172.16.9.18:50934:sendrecv:ice=no']
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: Issuing "update"
command to relay at 10.253.253.32
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: To relay update
7529;type: request;call_id:
738ce06b2a507610599b767b6b164657 at hpbxout.one-connect.dk;cseq: 102;from_uri:
40804XXX at 76752XXX.example.com;to_uri: 40804XXX at 172.16.9.20;from_tag:
as35017b2b;user_agent: one-connect;signaling_ip: 172.16.9.20;media:
audio:172.16.9.18:50934:sendrecv:ice=no;;
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: line received 7529
172.16.8.32 63730
May 15 08:02:33 sip-3-1 /usr/local/sbin/kamailio[5214]: WARNING: <script>:
new request M=BYE RURI=sip:65981002 at 172.16.9.21:5060 F=
sip:65982380 at 172.16.8.37 T=sip:65981002 at 172.16.8.8 IP=172.16.8.8 ID=
24b6995108fc59946c0222084a79e1a7 at 172.16.8.37:5060
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: Command remove
Headers ['call_id: 24b6995108fc59946c0222084a79e1a7 at 172.16.8.37:5060',
'from_tag: as792f4baa', 'to_tag: as798301b8']
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: Issuing "remove"
command to relay at 10.253.253.32
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: To relay remove
7530;call_id: 24b6995108fc59946c0222084a79e1a7 at 172.16.8.37:5060;from_tag:
as792f4baa;to_tag: as798301b8;;
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: line received 7530
{"from_tag": "as792f4baa", "start_time": 1400133626.74, "call_id": "
24b6995108fc59946c0222084a79e1a7 at 172.16.8.37:5060", "duration": 126,
"streams": [{"status": "closed", "caller_codec": "G711a",
"post_dial_delay": 0.175052881241, "callee_codec": "G711a", "caller_bytes":
1269200, "start_time": 0, "callee_packets": 6088, "callee_bytes": 1217600,
"caller_packets": 6346, "callee_remote": "172.16.9.18:58756", "end_time":
126, "caller_remote": "172.16.8.37:13014", "media_type": "audio",
"callee_local": "172.16.8.32:61298", "timeout_wait": 0, "caller_local": "
172.16.8.32:61296"}], "to_tag": "as798301b8", "to_uri": "65981002 at 172.16.8.8",
"caller_ua": "Asterisk PBX 1.8.12.0", "callee_ua": "one-connect",
"from_uri": "65982380 at 172.16.8.37"}
May 15 08:02:33 sip-3-1 media-dispatcher[3433]: debug: Got statistics:
{'from_tag': 'as792f4baa', 'dialog_id': None, 'start_time': 1400133626.74,
'timed_out': False, 'call_id': '
24b6995108fc59946c0222084a79e1a7 at 172.16.8.37:5060', 'to_tag': 'as798301b8',
'streams': [{'status': 'closed', 'caller_codec': 'G711a',
'post_dial_delay': 0.17505288124099999, 'callee_codec': 'G711a',
'start_time': 0, 'caller_bytes': 1269200, 'callee_bytes': 1217600,
'caller_packets': 6346, 'end_time': 126, 'callee_remote': '172.16.9.18:58756',
'caller_remote': '172.16.8.37:13014', 'media_type': 'audio',
'callee_local': '172.16.8.32:61298', 'timeout_wait': 0, 'caller_local': '
172.16.8.32:61296', 'callee_packets': 6088}], 'duration': 126, 'to_uri': '
65981002 at 172.16.8.8', 'from_uri': '65982380 at 172.16.8.37', 'callee_ua':
'one-connect', 'caller_ua': 'Asterisk PBX 1.8.12.0'}
May 15 08:02:33 sip-3-1 /usr/local/sbin/kamailio[5211]: ERROR: mediaproxy
[mediaproxy.c:1689]: mediaproxy response removed^M
May 15 08:02:33 sip-3-1 /usr/local/sbin/kamailio[5211]: ERROR: mediaproxy
[mediaproxy.c:1702]: Len of tokens: 1
May 15 08:02:33 sip-3-1 /usr/local/sbin/kamailio[5211]: ERROR: mediaproxy
[mediaproxy.c:1713]: insufficient ports returned from mediaproxy: got 0,
expected 1 callid: 738ce06b2a507610599b767b6b164657 at hpbxout.one-connect.dk
May 15 08:02:33 sip-3-1 /usr/local/sbin/kamailio[5211]: ERROR: <script>:
RTPPROXY: use_media_proxy failed bm: 4326 Code=1 M=INVITE
RURI=sip:40804XXX at sip-core.uni-tel.local F=sip:40804XXX at 76752600.example.comT=
sip:40804XXX at 172.16.9.20 IP=172.16.9.20 ID=
738ce06b2a507610599b767b6b164657 at hpbxout.one-connect.dk
May 15 08:02:33 sip-3-1 /usr/local/sbin/kamailio[5214]: NOTICE: acc
[acc.c:275]: ACC: transaction answered:
timestamp=1400133753;method=BYE;from_tag=as04fb28c3;to_tag=367167352;call_id=
51654c57361b47d0751b3d1c33d19a4d at 172.16.8.34;code=200;reason=OK



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


More information about the sr-users mailing list