login as: pi
pi@bsnl.myn2p.com's password:

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the

+OK log level  [7]
2016-06-15 13:04:44.329977 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/21@192.168.30.36 [a112ccda-32cb-11e6-b33c-811a74d51aac]
2016-06-15 13:04:44.329977 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_NEW
2016-06-15 13:04:44.349998 [DEBUG] sofia.c:9402 sofia/internal/21@192.168.30.36 receiving invite from 192.168.30.64:61782 version: 1.7.0 git 9d7fe24 2016-06-06 15:09:02Z 32bit
2016-06-15 13:04:44.349998 [DEBUG] sofia.c:9514 IP 192.168.30.64 Approved by acl "domains[]". Access Granted.
2016-06-15 13:04:44.349998 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [received][100]
2016-06-15 13:04:44.349998 [DEBUG] sofia.c:6893 Remote SDP:
v=0
o=Zoiper 0 0 IN IP4 192.168.30.64
s=Zoiper
c=IN IP4 192.168.30.64
t=0 0
m=audio 33646 RTP/AVP 106 18 0 101
a=rtpmap:106 opus/48000/2
a=fmtp:106 maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=20; cbr=1; maxaveragebitrate=20000; useinbandfec=1
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

2016-06-15 13:04:44.349998 [DEBUG] sofia.c:7253 (sofia/internal/21@192.168.30.36) State Change CS_NEW -> CS_INIT
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/21@192.168.30.36) State NEW
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_INIT
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/21@192.168.30.36) State INIT
2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:89 sofia/internal/21@192.168.30.36 SOFIA INIT
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:40 sofia/internal/21@192.168.30.36 Standard INIT
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/21@192.168.30.36) State Change CS_INIT -> CS_ROUTING
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/21@192.168.30.36) State INIT going to sleep
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_ROUTING
2016-06-15 13:04:44.349998 [DEBUG] switch_channel.c:2249 (sofia/internal/21@192.168.30.36) Callstate Change DOWN -> RINGING
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/21@192.168.30.36) State ROUTING
2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:142 sofia/internal/21@192.168.30.36 SOFIA ROUTING
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:236 sofia/internal/21@192.168.30.36 Standard ROUTING
2016-06-15 13:04:44.349998 [INFO] mod_dialplan_xml.c:637 Processing Mufaddal <21>->29 in context lanusersdialout
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->unloop] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->general_stuff1] continue=true
Dialplan: sofia/internal/21@192.168.30.36 Absolute Condition [general_stuff1]
Dialplan: sofia/internal/21@192.168.30.36 Action set(rtp_negotiate_near_match=true)
Dialplan: sofia/internal/21@192.168.30.36 Action set(inherit_codec=true)
Dialplan: sofia/internal/21@192.168.30.36 Action set(suppress_cng=true)
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_inbound] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_inbound] destination_number(29) =~ /^9997$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->myn2p_outbound] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [myn2p_outbound] destination_number(29) =~ /^(00.*)$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_outbound4] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_outbound4] destination_number(29) =~ /^0(1.*)$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_outbound5] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_outbound5] destination_number(29) =~ /^\+91(.*)$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_outbound] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_outbound] destination_number(29) =~ /^(0.*)$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->group_dial_support] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [group_dial_support] destination_number(29) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->local_user_calling] continue=false
Dialplan: sofia/internal/21@192.168.30.36 Regex (PASS) [local_user_calling] destination_number(29) =~ /^(.*)$/ break=on-false
Dialplan: sofia/internal/21@192.168.30.36 Action bind_meta_app(3 b s execute_extension::att_xfer XML features)
Dialplan: sofia/internal/21@192.168.30.36 Action set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/21@192.168.30.36 Action set(call_timeout=30)
Dialplan: sofia/internal/21@192.168.30.36 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/21@192.168.30.36 Action bridge(sofia/internal/29%${domain})
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/21@192.168.30.36) State Change CS_ROUTING -> CS_EXECUTE
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/21@192.168.30.36) State ROUTING going to sleep
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_EXECUTE
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/21@192.168.30.36) State EXECUTE
2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:197 sofia/internal/21@192.168.30.36 SOFIA EXECUTE
2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:328 sofia/internal/21@192.168.30.36 Standard EXECUTE
EXECUTE sofia/internal/21@192.168.30.36 set(rtp_negotiate_near_match=true)
2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [rtp_negotiate_near_match]=[true]
EXECUTE sofia/internal/21@192.168.30.36 set(inherit_codec=true)
2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [inherit_codec]=[true]
EXECUTE sofia/internal/21@192.168.30.36 set(suppress_cng=true)
2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [suppress_cng]=[true]
EXECUTE sofia/internal/21@192.168.30.36 bind_meta_app(3 b s execute_extension::att_xfer XML features)
2016-06-15 13:04:44.349998 [INFO] switch_ivr_async.c:4166 Bound B-Leg: *3 execute_extension::att_xfer XML features
EXECUTE sofia/internal/21@192.168.30.36 set(transfer_ringback=local_stream://moh)
2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/21@192.168.30.36 set(call_timeout=30)
2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [call_timeout]=[30]
EXECUTE sofia/internal/21@192.168.30.36 set(hangup_after_bridge=true)
2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/21@192.168.30.36 bridge(sofia/internal/29%192.168.30.36)
2016-06-15 13:04:44.349998 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
2016-06-15 13:04:44.349998 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/29 [a115aa18-32cb-11e6-b348-811a74d51aac]
2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:4816 (sofia/internal/29) State Change CS_NEW -> CS_INIT
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_INIT
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/29) State INIT
2016-06-15 13:04:44.369992 [DEBUG] mod_sofia.c:89 sofia/internal/29 SOFIA INIT
2016-06-15 13:04:44.369992 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 1028 pass
2016-06-15 13:04:44.369992 [DEBUG] sofia_glue.c:1257 sofia/internal/29 sending invite version: 1.7.0 git 9d7fe24 2016-06-06 15:09:02Z 32bit
Local SDP:
v=0
o=Talkycom 1465975056 1465975057 IN IP4 192.168.30.36
s=Talkycom
c=IN IP4 192.168.30.36
t=0 0
m=audio 1028 RTP/AVP 102 18 0 103 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; usedtx=1; cbr=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:40 sofia/internal/29 Standard INIT
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/29) State Change CS_INIT -> CS_ROUTING
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/29) State INIT going to sleep
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_ROUTING
2016-06-15 13:04:44.369992 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [calling][0]
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/29) State ROUTING
2016-06-15 13:04:44.369992 [DEBUG] mod_sofia.c:142 sofia/internal/29 SOFIA ROUTING
2016-06-15 13:04:44.369992 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/29) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/29) State ROUTING going to sleep
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_CONSUME_MEDIA
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/29) State CONSUME_MEDIA
2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/29) State CONSUME_MEDIA going to sleep
2016-06-15 13:04:44.549980 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [proceeding][180]
2016-06-15 13:04:44.549980 [NOTICE] sofia.c:6986 Ring-Ready sofia/internal/29!
2016-06-15 13:04:44.549980 [DEBUG] switch_channel.c:3343 (sofia/internal/29) Callstate Change DOWN -> RINGING
2016-06-15 13:04:44.569979 [NOTICE] mod_sofia.c:2201 Ring-Ready sofia/internal/21@192.168.30.36!
2016-06-15 13:04:44.569979 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [early][180]
2016-06-15 13:04:44.569979 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/21@192.168.30.36!
2016-06-15 13:04:47.369977 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [completing][200]
2016-06-15 13:04:47.369977 [DEBUG] sofia.c:6893 Remote SDP:
v=0
o=Zoiper 0 1 IN IP4 192.168.30.171
s=Zoiper
c=IN IP4 192.168.30.171
t=0 0
m=audio 44524 RTP/AVP 106 18 0 101
a=rtpmap:106 opus/48000/2
a=fmtp:106 maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=20; cbr=1; maxaveragebitrate=20000; useinbandfec=1
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

2016-06-15 13:04:47.369977 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [ready][200]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:2]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[G729:18:8000:20:8000:1]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:2]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4281 Set telephone-event payload to 101@8000
2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:3091 Set Codec sofia/internal/29 opus/48000 20 ms 960 samples 0 bits 1 channels
2016-06-15 13:04:47.369977 [DEBUG] switch_core_codec.c:111 sofia/internal/29 Original read codec set to opus:116
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4692 sofia/internal/29 Set 2833 dtmf send payload to 101 recv payload to 101
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6495 AUDIO RTP [sofia/internal/29] 192.168.30.36 port 1028 -> 192.168.30.171 port 44524 codec: 106 ms: 20
2016-06-15 13:04:47.369977 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 960 bytes per 20ms
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6794 sofia/internal/29 Set 2833 dtmf send payload to 101
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6801 sofia/internal/29 Set 2833 dtmf receive payload to 101
2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6824 sofia/internal/29 Set rtp dtmf delay to 40
2016-06-15 13:04:47.389984 [NOTICE] sofia.c:7852 Channel [sofia/internal/29] has been answered
2016-06-15 13:04:47.389984 [DEBUG] switch_channel.c:3770 (sofia/internal/29) Callstate Change RINGING -> ACTIVE
2016-06-15 13:04:47.389984 [DEBUG] switch_ivr_originate.c:410 Setting codec string on sofia/internal/21@192.168.30.36 to opus@48000h@20i
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:1]
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4281 Set telephone-event payload to 101@8000
2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:3091 Set Codec sofia/internal/21@192.168.30.36 opus/48000 20 ms 960 samples 0 bits 1 channels
2016-06-15 13:04:47.389984 [DEBUG] switch_core_codec.c:111 sofia/internal/21@192.168.30.36 Original read codec set to opus:116
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4692 sofia/internal/21@192.168.30.36 Set 2833 dtmf send payload to 101 recv payload to 101
2016-06-15 13:04:47.389984 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 1026 pass
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6495 AUDIO RTP [sofia/internal/21@192.168.30.36] 192.168.30.36 port 1026 -> 192.168.30.64 port 33646 codec: 106 ms: 20
2016-06-15 13:04:47.389984 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 960 bytes per 20ms
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6794 sofia/internal/21@192.168.30.36 Set 2833 dtmf send payload to 101
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6801 sofia/internal/21@192.168.30.36 Set 2833 dtmf receive payload to 101
2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6824 sofia/internal/21@192.168.30.36 Set rtp dtmf delay to 40
2016-06-15 13:04:47.389984 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/21@192.168.30.36!
2016-06-15 13:04:47.409994 [DEBUG] switch_channel.c:3471 (sofia/internal/21@192.168.30.36) Callstate Change RINGING -> EARLY
2016-06-15 13:04:47.409994 [DEBUG] mod_sofia.c:816 Local SDP sofia/internal/21@192.168.30.36:
v=0
o=Talkycom 1465975061 1465975062 IN IP4 192.168.30.36
s=Talkycom
c=IN IP4 192.168.30.36
t=0 0
m=audio 1026 RTP/AVP 106 101
a=rtpmap:106 opus/48000/2
a=fmtp:106 useinbandfec=1; usedtx=1; cbr=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2016-06-15 13:04:47.409994 [NOTICE] switch_ivr_originate.c:3549 Channel [sofia/internal/21@192.168.30.36] has been answered
2016-06-15 13:04:47.409994 [DEBUG] switch_channel.c:3770 (sofia/internal/21@192.168.30.36) Callstate Change EARLY -> ACTIVE
2016-06-15 13:04:47.409994 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [completed][200]
2016-06-15 13:04:47.409994 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/29]
2016-06-15 13:04:47.409994 [DEBUG] switch_ivr_bridge.c:1594 (sofia/internal/29) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2016-06-15 13:04:47.409994 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_EXCHANGE_MEDIA
2016-06-15 13:04:47.409994 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/29) State EXCHANGE_MEDIA
2016-06-15 13:04:47.409994 [DEBUG] mod_sofia.c:630 SOFIA EXCHANGE_MEDIA
2016-06-15 13:04:47.469979 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [ready][200]
2016-06-15 13:04:47.749979 [DEBUG] switch_rtp.c:6707 Correct audio ip/port confirmed.
2016-06-15 13:04:58.509979 [NOTICE] sofia_reg.c:448 Registering myn2p
2016-06-15 13:04:58.729981 [DEBUG] sofia_reg.c:2429 Changing expire time to 240 by request of proxy sip:72.55.165.151
2016-06-15 13:05:24.389980 [NOTICE] sofia.c:988 Hangup sofia/internal/21@192.168.30.36 [CS_EXECUTE] [NORMAL_CLEARING]
2016-06-15 13:05:24.389980 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/21@192.168.30.36]
2016-06-15 13:05:24.389980 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/29]
2016-06-15 13:05:24.389980 [NOTICE] switch_ivr_bridge.c:884 Hangup sofia/internal/29 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2016-06-15 13:05:24.389980 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/29) State EXCHANGE_MEDIA going to sleep
2016-06-15 13:05:24.389980 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_HANGUP
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/29) Callstate Change ACTIVE -> HANGUP
2016-06-15 13:05:24.409995 [DEBUG] switch_ivr_bridge.c:1692 sofia/internal/29 skip receive message [UNBRIDGE] (channel is hungup already)
2016-06-15 13:05:24.409995 [DEBUG] switch_ivr_bridge.c:1695 sofia/internal/21@192.168.30.36 skip receive message [UNBRIDGE] (channel is hungup already)
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/29) State HANGUP
2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:431 sofia/internal/29 Overriding SIP cause 480 with 200 from the other leg
2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:437 Channel sofia/internal/29 hanging up, cause: NORMAL_CLEARING
2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:490 Sending BYE to sofia/internal/29
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:60 sofia/internal/29 Standard HANGUP, cause: NORMAL_CLEARING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/29) State HANGUP going to sleep
2016-06-15 13:05:24.409995 [DEBUG] switch_core_session.c:2796 sofia/internal/21@192.168.30.36 skip receive message [PHONE_EVENT] (channel is hungup already)
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/21@192.168.30.36) State EXECUTE going to sleep
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_HANGUP
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/29) State Change CS_HANGUP -> CS_REPORTING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_REPORTING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/29) State REPORTING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:174 sofia/internal/29 Standard REPORTING, cause: NORMAL_CLEARING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/29) State REPORTING going to sleep
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/21@192.168.30.36) Callstate Change ACTIVE -> HANGUP
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/21@192.168.30.36) State HANGUP
2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:437 Channel sofia/internal/21@192.168.30.36 hanging up, cause: NORMAL_CLEARING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:60 sofia/internal/21@192.168.30.36 Standard HANGUP, cause: NORMAL_CLEARING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/21@192.168.30.36) State HANGUP going to sleep
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/29) State Change CS_REPORTING -> CS_DESTROY
2016-06-15 13:05:24.409995 [DEBUG] switch_core_session.c:1646 Session 2 (sofia/internal/29) Locked, Waiting on external entities
2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1664 Session 2 (sofia/internal/29) Ended
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/21@192.168.30.36) State Change CS_HANGUP -> CS_REPORTING
2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/29 [CS_DESTROY]
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_REPORTING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/21@192.168.30.36) State REPORTING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:174 sofia/internal/21@192.168.30.36 Standard REPORTING, cause: NORMAL_CLEARING
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/21@192.168.30.36) State REPORTING going to sleep
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/29) Running State Change CS_DESTROY
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/29) State DESTROY
2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:342 sofia/internal/29 SOFIA DESTROY
2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/21@192.168.30.36) State Change CS_REPORTING -> CS_DESTROY
2016-06-15 13:05:24.409995 [DEBUG] switch_core_session.c:1646 Session 1 (sofia/internal/21@192.168.30.36) Locked, Waiting on external entities
2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1664 Session 1 (sofia/internal/21@192.168.30.36) Ended
2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/21@192.168.30.36 [CS_DESTROY]
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:181 sofia/internal/29 Standard DESTROY
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/29) State DESTROY going to sleep
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/21@192.168.30.36) Running State Change CS_DESTROY
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/21@192.168.30.36) State DESTROY
2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:342 sofia/internal/21@192.168.30.36 SOFIA DESTROY
2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:181 sofia/internal/21@192.168.30.36 Standard DESTROY
2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/21@192.168.30.36) State DESTROY going to sleep
2016-06-15 13:05:45.649982 [NOTICE] sofia_reg.c:448 Registering myn2p
2016-06-15 13:05:45.849978 [DEBUG] sofia_reg.c:2429 Changing expire time to 240 by request of proxy sip:72.55.165.151