search

javitu / rt-n56u

Automatically exported from code.google.com/p/rt-n56u
0 stars 2 forks source link

Outbound SIP call RTP audio stream lost after approximately 2 minutes and 10 seconds #1413

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?
1. RT-N56U
2. Configure the gateway VGV7519 VDSL modem as bridge (RT-N56U gets external IP 
address on its WAN link)
3. install firmware revision RT-N56U_3.4.3.8-088 nano
4. make outbound SIP call using Snom370 8.7.3.25.5 device and Voipbuster service

What is the expected output?
Uninterrupted SIP RTP audio streams

What do you see instead?
The audio stream is lost on 8 consecutive outbound SIP calls after 
approximately 2 minutes and 10 seconds.
Inbound calls using a different SIP provider do not suffer from audio stream 
disconnect.

Original issue reported on code.google.com by c...@vakantieland.nl on 26 Jan 2015 at 3:52

GoogleCodeExporter commented 9 years ago 
A more precise audio stream connection moment is at 2 minutes and 5 seconds 
after the connection has been established (measured using the timer in the Snom 
display).

An example from the Snom370 log, at 17:12:07 the call is manually disconnected 
because of the lost audio connection:

26/1/2015 17:09:52 [INFO  ] PHN: sip::gui_connected(484, 0, 1)
26/1/2015 17:09:52 [DEBUG1] PHN: Goto Best State from 'Calling' (9), force 0
26/1/2015 17:09:57 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:01 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:05 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:09 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:13 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:17 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:21 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:25 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:29 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:33 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:37 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:41 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:45 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:49 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:53 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:10:57 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:01 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:05 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:09 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:13 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:17 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:21 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:25 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:29 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:29 [DEBUG1] PHN: SIP: remove pending packet: 1043479, all 11
26/1/2015 17:11:29 [DEBUG1] PHN: SIP: remove pending packet: 1043478, all 10
26/1/2015 17:11:29 [DEBUG1] PHN: SIP: remove pending packet: 1043481, all 9
26/1/2015 17:11:29 [DEBUG1] PHN: SIP: remove pending packet: 1043480, all 8
26/1/2015 17:11:33 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:37 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:41 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:41 [DEBUG1] PHN: SIP: remove pending packet: 1043482, all 7
26/1/2015 17:11:45 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:49 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:11:53 [DEBUG1] PHN: SIP: recv 200 INVITE (3: 
54c666bed05f-73pghv5cjc1d) <- udp:77.72.169.134:5060
26/1/2015 17:12:04 [DEBUG1] PHN: SIP: remove pending packet: 1043483, all 6
26/1/2015 17:12:07 [ALERT ] LID: inca360_handle_kb: key event: 2171208372
26/1/2015 17:12:07 [DEBUG1] LID: handle_next_key_events: key time: 2171208372 
last time: 2170689322
26/1/2015 17:12:07 [DEBUG1] LID: handle_next_key_events: play key
26/1/2015 17:12:07 [DEBUG1] LID: handle_next_key_events: set last key event 
time: 2171208372
26/1/2015 17:12:07 [ALERT ] LID: inca360_handle_kb: key event: 2171208422
26/1/2015 17:12:07 [DEBUG1] LID: handle_next_key_events: key time: 2171208422 
last time: 2171208372
26/1/2015 17:12:07 [DEBUG1] LID: handle_next_key_events: play key
26/1/2015 17:12:07 [ERROR ] LID: Unknown DTMF key code: 67
26/1/2015 17:12:07 [INFO  ] GUI: Deleting channel 484, identity 5, state 
connected, total connection count 1
26/1/2015 17:12:07 [INFO  ] PHN: RTP: set_audible(1/1 -> 0/0): RP1223 
changed=1, update_req=0, adr=77.72.168.12:31468
26/1/2015 17:12:07 [DEBUG0] PHN: SIP: requesting call stats: 13947141 in state 
confirmed
26/1/2015 17:12:07 [INFO  ] PHN: SIP: close stream 1, stats 1
26/1/2015 17:12:07 [INFO  ] PHN: SIP: Dialog 484/1223/4 going to terminated
26/1/2015 17:12:07 [DEBUG1] PHN: SIP: mark for deletion 
1223/54c666bed05f-73pghv5cjc1d, cbi 0, 0
26/1/2015 17:12:07 [INFO  ] PHN: SIP: packet 1043484 stopped retransmission
26/1/2015 17:12:07 [INFO  ] PHN: SIP: packet 1043486 stopped retransmission
26/1/2015 17:12:07 [INFO  ] PHN: SIP: packet 1043488 stopped retransmission
26/1/2015 17:12:07 [DEBUG1] GUI: Deleting connected_call

Original comment by c...@vakantieland.nl on 26 Jan 2015 at 4:17

GoogleCodeExporter commented 9 years ago 
This also happens with router RT-N56U firmware version 3.4.3.9-091

Original comment by c...@vakantieland.nl on 26 Jan 2015 at 4:18

GoogleCodeExporter commented 9 years ago 
The SIP log does not show lost audio packets:

Received from udp:77.72.169.134:5060 at 26/1/2015 17:11:45:298 (713 bytes):
CSeq: 3 INVITE

v=0
o=username 1422288594 1422288594 IN IP4 77.72.168.12
s=SIP Call
c=IN IP4 77.72.168.12
t=0 0
m=audio 31468 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=ptime:20

Received from udp:77.72.169.134:5060 at 26/1/2015 17:11:49:297 (713 bytes):
CSeq: 3 INVITE

...identical as above...

Received from udp:77.72.169.134:5060 at 26/1/2015 17:11:53:298 (713 bytes):
CSeq: 3 INVITE

...identical as above...

Sent to udp:77.72.169.134:5060 at 26/1/2015 17:12:07:735 (600 bytes):
CSeq: 4 BYE
RTP-RxStat: Total_Rx_Pkts=6868,Rx_Pkts=6863,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0
RTP-TxStat: Total_Tx_Pkts=7366,Tx_Pkts=7366,Remote_Tx_Pkts=0

Original comment by c...@vakantieland.nl on 26 Jan 2015 at 4:25