[Freeswitch-users] Dropped calls

Sat Jan 2 16:09:23 PST 2010

Hi!

I just got a couple of dropped calls.  Unfortunately I lost the sip
traces, but I do have the debug logs... in both cases FS shows a
Duplicate SDP received.  I'm not sure if this is a cause - do these
show anything to anyone as to why the calls dropped?

FS version is FreeSWITCH Version 1.0.trunk (15490)

Drop 1:
2010-01-02 17:18:50.806686 [DEBUG] switch_core_io.c:234
sofia/internal/2001 at myddns.dydns.org:442 receive message
[TRANSCODING_NECESSARY]
2010-01-02 17:18:50.826355 [DEBUG] switch_rtp.c:1972 Correct ip/port confirmed.
2010-01-02 17:18:51.645569 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [ready][200]
2010-01-02 17:18:51.666115 [DEBUG] switch_core_session.c:704 Send
signal sofia/internal/sip:1000 at 192.168.1.121:5060 [BREAK]
2010-01-02 17:18:51.666115 [DEBUG] switch_core_session.c:704 Send
signal sofia/internal/2001 at myddns.dydns.org:442 [BREAK]
2010-01-02 17:18:51.685576 [DEBUG] switch_ivr_bridge.c:122
sofia/internal/2001 at myddns.dydns.org:442 receive message [DISPLAY]
2010-01-02 17:18:51.685576 [DEBUG] switch_ivr_bridge.c:122
sofia/internal/sip:1000 at 192.168.1.121:5060 receive message [DISPLAY]
2010-01-02 17:19:40.169692 [DEBUG] switch_rtp.c:2344 RTP RECV DTMF 1:404
2010-01-02 17:19:40.189926 [DEBUG] switch_rtp.c:1641 Send start packet
for [1] ts=24065640 dur=160/160/404 seq=15337
2010-01-02 17:19:40.205843 [DEBUG] switch_rtp.c:1577 Send middle
packet for [1] ts=24065640 dur=320/320/404 seq=15338
2010-01-02 17:19:40.225669 [DEBUG] switch_rtp.c:1577 Send end packet
for [1] ts=24065640 dur=480/480/404 seq=15339
2010-01-02 17:19:40.225669 [DEBUG] switch_rtp.c:1577 Send end packet
for [1] ts=24065640 dur=480/480/404 seq=15340
2010-01-02 17:19:40.225669 [DEBUG] switch_rtp.c:1577 Send end packet
for [1] ts=24065640 dur=480/480/404 seq=15341
2010-01-02 17:19:48.942440 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [calling][0]
2010-01-02 17:19:52.093594 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [ready][200]
2010-01-02 17:19:52.093594 [DEBUG] sofia.c:3654 Duplicate SDP
v=0
o=- 238296 238296 IN IP4 192.168.1.3
s=-
c=IN IP4 192.168.1.3
t=0 0
m=audio 19428 RTP/AVP 2 0 8 4 96 97 98 100 101
a=rtpmap:2 G726-32/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2010-01-02 17:19:59.713933 [DEBUG] switch_rtp.c:2344 RTP RECV DTMF 1:404
2010-01-02 17:19:59.725822 [DEBUG] switch_rtp.c:1641 Send start packet
for [1] ts=24225880 dur=160/160/404 seq=16315
2010-01-02 17:19:59.745728 [DEBUG] switch_rtp.c:1577 Send middle
packet for [1] ts=24225880 dur=320/320/404 seq=16316
2010-01-02 17:19:59.765676 [DEBUG] switch_rtp.c:1577 Send end packet
for [1] ts=24225880 dur=480/480/404 seq=16317
2010-01-02 17:19:59.765676 [DEBUG] switch_rtp.c:1577 Send end packet
for [1] ts=24225880 dur=480/480/404 seq=16318
2010-01-02 17:19:59.765676 [DEBUG] switch_rtp.c:1577 Send end packet
for [1] ts=24225880 dur=480/480/404 seq=16319
2010-01-02 17:20:49.969621 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [calling][0]
2010-01-02 17:20:54.036198 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state
[terminating][503]
2010-01-02 17:20:54.036198 [NOTICE] sofia.c:4247 Hangup
sofia/internal/2001 at myddns.dydns.org:442 [CS_EXECUTE]
[NORMAL_TEMPORARY_FAILURE]
2010-01-02 17:20:54.040419 [DEBUG] switch_channel.c:1912 Send signal
sofia/internal/2001 at myddns.dydns.org:442 [KILL]
2010-01-02 17:20:54.040419 [DEBUG] switch_core_session.c:982 Send
signal sofia/internal/2001 at myddns.dydns.org:442 [BREAK]

Drop 2:
2010-01-02 17:10:42.177817 [DEBUG] switch_core_session.c:704 Send
signal sofia/internal/sip:1000 at 192.168.1.121:5060 [BREAK]
2010-01-02 17:10:42.177817 [DEBUG] sofia.c:411
sofia/internal/sip:1000 at 192.168.1.121:5060 receive message [DISPLAY]
2010-01-02 17:10:42.177817 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state
[completed][200]
2010-01-02 17:10:42.185735 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/2001 at myddns.dydns.org:442 [BREAK]
2010-01-02 17:10:42.189574 [NOTICE] switch_ivr_originate.c:2836
Channel [sofia/internal/2001 at myddns.dydns.org:442] has been answered
2010-01-02 17:10:42.193802 [DEBUG] switch_channel.c:182
sofia/internal/2001 at myddns.dydns.org:442 receive message [AUDIO_SYNC]
2010-01-02 17:10:42.193802 [DEBUG] switch_ivr_originate.c:2881
Originate Resulted in Success:
[sofia/internal/sip:1000 at 192.168.1.121:5060]
2010-01-02 17:10:42.197882 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000 at 192.168.1.121:5060 receive message
[AUDIO_SYNC]
2010-01-02 17:10:42.201876 [DEBUG] switch_channel.c:182
sofia/internal/2001 at myddns.dydns.org:442 receive message [AUDIO_SYNC]
2010-01-02 17:10:42.217738 [DEBUG] switch_ivr_originate.c:2881
Originate Resulted in Success:
[sofia/internal/sip:1000 at 192.168.1.121:5060]
2010-01-02 17:10:42.221921 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000 at 192.168.1.121:5060 receive message
[AUDIO_SYNC]
2010-01-02 17:10:42.221921 [DEBUG] switch_channel.c:182
sofia/internal/2001 at myddns.dydns.org:442 receive message [AUDIO_SYNC]
2010-01-02 17:10:42.237732 [DEBUG] switch_ivr_bridge.c:1004
sofia/internal/sip:1000 at 192.168.1.121:5060 receive message [BRIDGE]
2010-01-02 17:10:42.237732 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/sip:1000 at 192.168.1.121:5060 [BREAK]
2010-01-02 17:10:42.241599 [DEBUG] switch_ivr_bridge.c:1011
sofia/internal/2001 at myddns.dydns.org:442 receive message [BRIDGE]
2010-01-02 17:10:42.241599 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/2001 at myddns.dydns.org:442 [BREAK]
2010-01-02 17:10:42.241599 [DEBUG] switch_ivr_bridge.c:1055
(sofia/internal/sip:1000 at 192.168.1.121:5060) State Change
CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2010-01-02 17:10:42.246345 [DEBUG] switch_core_session.c:982 Send
signal sofia/internal/sip:1000 at 192.168.1.121:5060 [BREAK]
2010-01-02 17:10:42.246345 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1000 at 192.168.1.121:5060) Running State Change
CS_EXCHANGE_MEDIA
2010-01-02 17:10:42.249596 [DEBUG] switch_core_state_machine.c:351
(sofia/internal/sip:1000 at 192.168.1.121:5060) State EXCHANGE_MEDIA
2010-01-02 17:10:42.249596 [DEBUG] mod_sofia.c:464 SOFIA LOOPBACK
2010-01-02 17:10:42.265702 [DEBUG] switch_core_io.c:234
sofia/internal/2001 at myddns.dydns.org:442 receive message
[TRANSCODING_NECESSARY]
2010-01-02 17:10:42.285925 [DEBUG] switch_rtp.c:1972 Correct ip/port confirmed.
2010-01-02 17:10:44.402422 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [ready][200]
2010-01-02 17:10:44.413899 [DEBUG] switch_core_session.c:704 Send
signal sofia/internal/sip:1000 at 192.168.1.121:5060 [BREAK]
2010-01-02 17:10:44.419743 [DEBUG] switch_core_session.c:704 Send
signal sofia/internal/2001 at myddns.dydns.org:442 [BREAK]
2010-01-02 17:10:44.425721 [DEBUG] switch_ivr_bridge.c:122
sofia/internal/sip:1000 at 192.168.1.121:5060 receive message [DISPLAY]
2010-01-02 17:10:44.433714 [DEBUG] switch_ivr_bridge.c:122
sofia/internal/2001 at myddns.dydns.org:442 receive message [DISPLAY]
2010-01-02 17:11:44.822897 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [calling][0]
2010-01-02 17:11:45.353266 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [ready][200]
2010-01-02 17:11:45.353266 [DEBUG] sofia.c:3654 Duplicate SDP
v=0
o=- 188941 188941 IN IP4 192.168.1.3
s=-
c=IN IP4 192.168.1.3
t=0 0
m=audio 19424 RTP/AVP 2 0 8 4 96 97 98 100 101
a=rtpmap:2 G726-32/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2010-01-02 17:12:44.834908 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state [calling][0]
2010-01-02 17:12:45.125887 [DEBUG] sofia.c:3646 Channel
sofia/internal/2001 at myddns.dydns.org:442 entering state
[terminating][503]
2010-01-02 17:12:45.125887 [NOTICE] sofia.c:4247 Hangup
sofia/internal/2001 at myddns.dydns.org:442 [CS_EXECUTE]
[NORMAL_TEMPORARY_FAILURE]
2010-01-02 17:12:45.125887 [DEBUG] switch_channel.c:1912 Send signal
sofia/internal/2001 at myddns.dydns.org:442 [KILL]
2010-01-02 17:12:45.125887 [DEBUG] switch_core_session.c:982 Send
signal sofia/internal/2001 at myddns.dydns.org:442 [BREAK]