[Freeswitch-users] Git v1.2.17 ca447fe 2014-01-02 - Polycom IP-330 outbound calls hang on answer

[Francis]

Debian Wheezy 7.3 32bit
Version 1.2.17 -n20140102T213421Z-1~wheezy+1git ca447fe 2014-01-02 
11:34:22Z 32bit
Phone firmware: 3.3.5
Configured as EXT 1000

Incoming calls work fine, but outgoing calls, either to local extensions 
or though a gateway hang up the instant the call is answered by the 
remote party. The IP-330 shows the call as answered and in progress and 
there is a split second of audio before it drops, but the actual call 
has dropped and the other party is idle.

Calling three different endpoints has the same effect:

Grandstream GXP2124 (extension 1002)
Zoiper communicator on Android
Sip trunk to PSTN

A capture in wireshark shows the following sequence immediately after 
the call is established:

3963	8.986119000	10.0.0.124	10.0.0.119	SIP/SDP	1017	Request: UPDATE 
sip:1000 at 10.0.0.119:5060, with session description
3963	8.986119000	10.0.0.124	10.0.0.119	SIP/SDP	1017	Request: UPDATE 
sip:1000 at 10.0.0.119:5060, with session description
3994	9.002869000	10.0.0.119	10.0.0.124	SIP	443	Status: 481 Call 
Leg/Transaction Does Not Exist
3996	9.003466000	10.0.0.124	10.0.0.119	SIP	687	Request: BYE 
sip:1000 at 10.0.0.119:5060
4029	9.019642000	10.0.0.119	10.0.0.124	SIP	440	Status: 481 Call 
Leg/Transaction Does Not Exist

.... at which point, a BYE is sent to the b leg and the call terminates, 
with the IP-330 left dangling with an empty call leg, not realizing that 
nobody is listening anymore.

This is what I gleaned from fs_cli:

2014-01-05 18:13:08.904735 [DEBUG] sofia.c:5779 Channel 
sofia/internal/1000 at hpbx.nest entering state [calling][0]
2014-01-05 18:13:08.904735 [DEBUG] switch_rtp.c:927  [  zrtp utils]: 
Send <HELLO> ssrc=1538954628 seq=54771 size=144. Stream 40:CLEAR:START
2014-01-05 18:13:08.924723 [DEBUG] switch_core_session.c:1016 Send 
signal sofia/internal/1000 at hpbx.nest [BREAK]
2014-01-05 18:13:08.924723 [DEBUG] switch_core_session.c:1016 Send 
signal sofia/internal/1000 at hpbx.nest [BREAK]
2014-01-05 18:13:08.924723 [DEBUG] switch_core_session.c:1016 Send 
signal sofia/internal/1000 at hpbx.nest [BREAK]
2014-01-05 18:13:08.924723 [DEBUG] switch_core_session.c:1016 Send 
signal sofia/internal/1000 at hpbx.nest [BREAK]
2014-01-05 18:13:08.924723 [DEBUG] switch_core_session.c:1016 Send 
signal sofia/internal/1000 at hpbx.nest [BREAK]
2014-01-05 18:13:08.944752 [DEBUG] sofia.c:5779 Channel 
sofia/internal/1000 at hpbx.nest entering state [terminating][487]
2014-01-05 18:13:08.944752 [NOTICE] sofia.c:6623 Hangup 
sofia/internal/1000 at hpbx.nest [CS_EXECUTE] [ORIGINATOR_CANCEL]
2014-01-05 18:13:08.944752 [DEBUG] switch_channel.c:3183 Send signal 
sofia/internal/1000 at hpbx.nest [KILL]
2014-01-05 18:13:08.944752 [DEBUG] switch_core_session.c:1351 Send 
signal sofia/internal/1000 at hpbx.nest [BREAK]
2014-01-05 18:13:08.944752 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD 
DONE [sofia/internal/1000 at hpbx.nest]
2014-01-05 18:13:08.944752 [DEBUG] switch_ivr_bridge.c:658 Send signal 
sofia/internal/sip:1002 at 10.0.0.120:5060 [BREAK]
2014-01-05 18:13:08.964735 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD 
DONE [sofia/internal/sip:1002 at 10.0.0.120:5060]
2014-01-05 18:13:08.964735 [DEBUG] switch_ivr_bridge.c:658 Send signal 
sofia/internal/1000 at hpbx.nest [BREAK]
2014-01-05 18:13:08.964735 [NOTICE] switch_ivr_bridge.c:721 Hangup 
sofia/internal/sip:1002 at 10.0.0.120:5060 [CS_EXCHANGE_MEDIA] 
[NORMAL_CLEARING]
2014-01-05 18:13:08.964735 [DEBUG] switch_channel.c:3183 Send signal 
sofia/internal/sip:1002 at 10.0.0.120:5060 [KILL]
2014-01-05 18:13:08.964735 [DEBUG] switch_core_session.c:1351 Send 
signal sofia/internal/sip:1002 at 10.0.0.120:5060 [BREAK]
2014-01-05 18:13:08.964735 [DEBUG] switch_core_state_machine.c:481 
(sofia/internal/sip:1002 at 10.0.0.120:5060) State EXCHANGE_MEDIA going to 
sleep
2014-01-05 18:13:08.964735 [DEBUG] switch_core_state_machine.c:415 
(sofia/internal/sip:1002 at 10.0.0.120:5060) Running State Change CS_HANGUP
2014-01-05 18:13:08.964735 [DEBUG] switch_core_state_machine.c:679 
(sofia/internal/sip:1002 at 10.0.0.120:5060) State HANGUP
2014-01-05 18:13:08.964735 [DEBUG] mod_sofia.c:500 
sofia/internal/sip:1002 at 10.0.0.120:5060 Overriding SIP cause 480 with 
487 from the other leg
2014-01-05 18:13:08.964735 [DEBUG] mod_sofia.c:506 Channel 
sofia/internal/sip:1002 at 10.0.0.120:5060 hanging up, cause: NORMAL_CLEARING
2014-01-05 18:13:08.964735 [DEBUG] switch_ivr_bridge.c:1524 
sofia/internal/sip:1002 at 10.0.0.120:5060 skip receive message [UNBRIDGE] 
(channel is hungup already) 
 

2014-01-05 18:13:08.964735 [DEBUG] switch_ivr_bridge.c:1527 
sofia/internal/1000 at hpbx.nest skip receive message [UNBRIDGE] (channel 
is hungup already) 
 

2014-01-05 18:13:08.964735 [DEBUG] switch_core_session.c:2810 
sofia/internal/1000 at hpbx.nest skip receive message 
[APPLICATION_EXEC_COMPLETE] (channel is hungup already) 
 

2014-01-05 18:13:08.964735 [DEBUG] switch_core_state_machine.c:478 
(sofia/internal/1000 at hpbx.nest) State EXECUTE going to sleep
2014-01-05 18:13:08.964735 [DEBUG] switch_core_state_machine.c:415 
(sofia/internal/1000 at hpbx.nest) Running State Change CS_HANGUP
2014-01-05 18:13:08.964735 [DEBUG] mod_sofia.c:558 Sending BYE to 
sofia/internal/sip:1002 at 10.0.0.120:5060
2014-01-05 18:13:08.964735 [DEBUG] switch_core_state_machine.c:48 
sofia/internal/sip:1002 at 10.0.0.120:5060 Standard HANGUP, cause: 
NORMAL_CLEARING


Version 1.2.17 git 7712626 2013-12-27 20:52:28Z 64bit works fine.