[Spce-user] sems needs 120s for rtp sessions..

Tue Sep 30 07:58:59 EDT 2014

Hi all,

after installing sipwise mr3.4.2 (ce) the sems didn't start beacuse the 
'language' was de - and there were no german (de) voice-files.. after 
correcting this, calls from A to B are connected by sip - but the rtp 
channels are 120s 'empty' - so you cannot hear anything.. after  120s, 
by the "Kernelizing media stream" comment in the rtp-log the channels 
comes up, and the call is working..

could anybody explain why this needs 120s?

Thanks
fry

ps. the clients are normal natted, the server of course not.. ;-)

***snip***

Sep 30 11:40:28 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0] Creating new call
Sep 30 11:40:28 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0] Returning to SIP 
proxy: d3:sdp882:v=0#015#012o=41442111003-jitsi.org 0 0 IN IP4 
<IP-ADDR-VOIP-GATEWAY>#015#012s=-#015#012c=IN IP4 
<IP-ADDR-VOIP-GATEWAY>#015#012t=0 0#015#012m=audio 30264 RTP/AVP 96 97 
98 9 100 102 0 8 103 3 104 101#015#012a=rtpmap:96 
opus/48000/2#015#012a=fmtp:96 usedtx=1#015#012a=rtpmap:97 
SILK/24000#015#012a=rtpmap:98 SILK/16000#015#012a=rtpmap:9 
G722/8000#015#012a=rtpmap:100 speex/32000#015#012a=rtpmap:102 
speex/16000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 
PCMA/8000#015#012a=rtpmap:103 iLBC/8000#015#012a=rtpmap:3 
GSM/8000#015#012a=rtpmap:104 speex/8000#015#012a=rtpmap:101 
telephone-event/8000#015#012a=rtcp-xr:voip-metrics#015#012a=direction:active#015#012a=sendrecv#015#012a=rtcp:30265#015#012m=video 
30268 RTP/AVP 105 99#015#012a=rtpmap:105 H264/90000#015#012a=fmtp:105 
profile-level-id=4DE01f;packetization-mode=1#015#012a=imageattr:105 send 
* recv [x=[0-1366],y=[0-768]]#015#012a=rtpmap:99 
H264/90000#015#012a=fmtp:99 
profile-level-id=4DE01f#015#012a=imageattr:99 send * recv 
[x=[0-1366],y=[0-768]]#015#012a=direction:active#015#012a=oldmediaip:10.1.1.20#015#012a=recvonly#015#012a=rtcp:30269#015#0126:result2:oke
Sep 30 11:40:33 sip rtpengine[4419]: Got valid command from 
127.0.0.1:34227: answer - { "sdp": "v=0#015#012o=- 3621058828 3621058829 
IN IP4 10.4.144.62#015#012s=cpc_med#015#012c=IN IP4 <IP-ADDR-CLIENT 
B>#015#012t=0 0#015#012m=audio 39404 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=sendrecv#015#012a=ptime:20#015#012a=direction:active#015#012m=video 
0 RTP/AVP 105 99#015#012a=rtpmap:105 H264/90000#015#012a=rtpmap:99 
H264/90000#015#012a=sendrecv#015#012a=oldmediaip:10.4.144.62#015#012a=direction:active#015#012", 
"ICE": "remove", "flags": [ "trust-address" ], "replace": [ "origin", 
"session-connection" ], "rtcp-mux": [ "demux" ], "call-id": 
"41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0", "via-branch": 
"z9hG4bK8bdf.2e5d87b56f06179737ae612bb439fca2.0", "received-from": [ 
"IP4", "127.0.0.1" ], "from-tag": "e55509a8", "to-tag": 
"0AE7A597-542A7A8C000BBCA7-E9FA2700", "command": "answer" }
Sep 30 11:40:33 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0] Returning to SIP 
proxy: d3:sdp377:v=0#015#012o=- 3621058828 3621058829 IN IP4 
<IP-ADDR-VOIP-GATEWAY>#015#012s=cpc_med#015#012c=IN IP4 
<IP-ADDR-VOIP-GATEWAY>#015#012t=0 0#015#012m=audio 30266 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=ptime:20#015#012a=direction:active#015#012a=sendrecv#015#012a=rtcp:30267#015#012m=video 
0 RTP/AVP 105 99#015#012a=rtpmap:105 H264/90000#015#012a=rtpmap:99 
H264/90000#015#012a=oldmediaip:10.4.144.62#015#012a=direction:active#015#0126:result2:oke
Sep 30 11:40:37 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0 port 30266] Confirmed 
peer address as <IP-ADDR-CLIENT A>:5327
Sep 30 11:40:39 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0 port 30267] Confirmed 
peer address as <IP-ADDR-CLIENT A>:5328
Sep 30 11:42:29 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0 port 30264] Confirmed 
peer address as <IP-ADDR-CLIENT B>:42815
Sep 30 11:42:29 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0 port 30264] 
Kernelizing media stream
Sep 30 11:42:29 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0 port 30266] 
Kernelizing media stream
Sep 30 11:42:29 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0 port 30265] Confirmed 
peer address as <IP-ADDR-CLIENT B>:52552
Sep 30 11:42:41 sip rtpengine[4419]: Got valid command from 
127.0.0.1:59340: delete - { "call-id": 
"41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0", "received-from": [ 
"IP4", "127.0.0.1" ], "from-tag": "0AE7A597-542A7A8C000BBCA7-E9FA2700", 
"to-tag": "e55509a8", "command": "delete" }
Sep 30 11:42:41 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0] Scheduling deletion 
of call branch 'e55509a8' in 30 seconds
Sep 30 11:42:41 sip rtpengine[4419]: 
[41c94c57187be071c8008cabe80020a2 at 0:0:0:0:0:0:0:0] Returning to SIP 
proxy: d7:createdi1412070028e11:last 
signali1412070033e4:tagsd8:e55509a8d3:tag8:e55509a87:createdi1412070028e16:in 
dialogue 
with34:0AE7A597-542A7A8C000BBCA7-E9FA27006:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local 
porti30264e8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
B>4:porti42815ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
B>4:porti39404ee11:last 
packeti1412070161e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi581e5:bytesi124292e6:errorsi0eeed10:local 
porti30265e8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
B>4:porti52552ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
B>4:porti39405ee11:last 
packeti1412070160e5:flagsl4:RTCP6:filled9:confirmed10:kernelized17:no 
kernel 
supporte5:statsd7:packetsi4e5:bytesi336e6:errorsi0eeee5:flagsl11:initializedeed5:indexi2e4:type5:video8:protocol7:RTP/AVP7:streamsld8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
B>4:porti0ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT B>4:porti0ee11:last 
packeti1412070028e5:flagsl3:RTP6:fillede5:statsd7:packetsi0e5:bytesi0e6:errorsi0eeed8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
B>4:porti1ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT B>4:porti1ee11:last 
packeti1412070028e5:flagsl4:RTCP6:fillede5:statsd7:packetsi0e5:bytesi0e6:errorsi0eeee5:flagsl11:initializedeeee34:0AE7A597-542A7A8C000BBCA7-E9FA2700d3:tag34:0AE7A597-542A7A8C000BBCA7-E9FA27007:createdi1412070028e16:in 
dialogue 
with8:e55509a86:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local 
porti30266e8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5327ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5327ee11:last 
packeti1412070161e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi6407e5:bytesi1125246e6:errorsi0eeed10:local 
porti30267e8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5328ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5328ee11:last 
packeti1412070159e5:flagsl4:RTCP6:filled9:confirmed10:kernelized17:no 
kernel 
supporte5:statsd7:packetsi26e5:bytesi1764e6:errorsi0eeee5:flagsl11:initializedeed5:indexi2e4:type5:video8:protocol7:RTP/AVP7:streamsld8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5329ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5329ee11:last 
packeti1412070028e5:flagsl3:RTP6:fillede5:statsd7:packetsi0e5:bytesi0e6:errorsi0eeed8:endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5330ee19:advertised 
endpointd6:family4:IPv47:address14:<IP-ADDR-CLIENT 
A>4:porti5330ee11:last 
packeti1412070028e5:flagsl4:RTCP6:fillede5:statsd7:packetsi0e5:bytesi0e6:errorsi0eeee5:flagsl11:initializedeeeee6:totalsd3:RTPd7:packetsi6988e5:bytesi1249538e6:errorsi0ee4:RTCPd7:packetsi30e5:bytesi2100e6:errorsi0eee6:result2:oke