/*  call is not recovered */

2012-10-31 09:31:37.495317 [NOTICE] switch_channel.c:941 New Channel sofia/internal/3429@10.1.3.50 [b6f8eb4d-19d0-46ee-983d-81175e7f222b]
2012-10-31 09:31:37.495317 [NOTICE] switch_channel.c:939 Rename Channel sofia/internal/3429@10.1.3.50->sofia/internal/3429@10.1.3.50 [b6f8eb4d-19d0-46ee-983d-81175e7f222b]
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3027 Set Codec sofia/internal/3429@10.1.3.50 PCMU/8000 20 ms 160 samples 64000 bits
2012-10-31 09:31:37.495317 [DEBUG] switch_core_codec.c:111 sofia/internal/3429@10.1.3.50 Original read codec set to PCMU:0
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/internal/3429@10.1.3.50] 10.1.3.50 port 25076 -> 10.1.45.148 port 4006 codec: 0 ms: 20
2012-10-31 09:31:37.495317 [DEBUG] switch_rtp.c:1935 Not using a timer
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3573 sofia/internal/3429@10.1.3.50 Set rtp dtmf delay to 40
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3579 Set comfort noise payload to 13
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:5965 (sofia/internal/3429@10.1.3.50) State Change CS_NEW -> CS_INIT
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.495317 [NOTICE] sofia_glue.c:5966 Resurrecting fallen channel sofia/internal/3429@10.1.3.50
2012-10-31 09:31:37.495317 [NOTICE] switch_channel.c:941 New Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 [048fd28b-765f-4444-9eb4-90487d72d191]
2012-10-31 09:31:37.495317 [NOTICE] switch_channel.c:939 Rename Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292->sofia/internal/sip:ukytvsci@10.1.19.195:1292 [048fd28b-765f-4444-9eb4-90487d72d191]
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3027 Set Codec sofia/internal/sip:ukytvsci@10.1.19.195:1292 PCMU/8000 20 ms 160 samples 64000 bits
2012-10-31 09:31:37.495317 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Original read codec set to PCMU:0
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_INIT
2012-10-31 09:31:37.495317 [DEBUG] switch_channel.c:1936 (sofia/internal/3429@10.1.3.50) Callstate Change DOWN -> ACTIVE
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/internal/sip:ukytvsci@10.1.19.195:1292] 10.1.3.50 port 26368 -> 10.1.19.195 port 50006 codec: 0 ms: 20
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/3429@10.1.3.50) State INIT
2012-10-31 09:31:37.495317 [DEBUG] mod_sofia.c:85 sofia/internal/3429@10.1.3.50 SOFIA INIT
2012-10-31 09:31:37.495317 [DEBUG] switch_rtp.c:1935 Not using a timer
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:2609 Local SDP:
v=0
o=FreeSWITCH 1351631021 1351631023 IN IP4 10.1.3.50
s=FreeSWITCH
c=IN IP4 10.1.3.50
t=0 0
m=audio 25076 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2012-10-31 09:31:37.495317 [DEBUG] mod_sofia.c:119 (sofia/internal/3429@10.1.3.50) State Change CS_INIT -> CS_RESET
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/3429@10.1.3.50) State INIT going to sleep
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_RESET
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3429@10.1.3.50) State RESET
2012-10-31 09:31:37.495317 [DEBUG] mod_sofia.c:166 sofia/internal/3429@10.1.3.50 SOFIA RESET
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3573 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Set rtp dtmf delay to 40
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:3579 Set comfort noise payload to 13
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:5965 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_NEW -> CS_INIT
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.495317 [NOTICE] sofia_glue.c:5966 Resurrecting fallen channel sofia/internal/sip:ukytvsci@10.1.19.195:1292
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_INIT
2012-10-31 09:31:37.495317 [DEBUG] switch_channel.c:1936 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Callstate Change DOWN -> ACTIVE
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State INIT
2012-10-31 09:31:37.495317 [DEBUG] mod_sofia.c:85 sofia/internal/sip:ukytvsci@10.1.19.195:1292 SOFIA INIT
2012-10-31 09:31:37.495317 [DEBUG] sofia_glue.c:2609 Local SDP:
v=0
o=FreeSWITCH 1351629729 1351629731 IN IP4 10.1.3.50
s=FreeSWITCH
c=IN IP4 10.1.3.50
t=0 0
m=audio 26368 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2012-10-31 09:31:37.495317 [DEBUG] mod_sofia.c:119 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_INIT -> CS_RESET
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State INIT going to sleep
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_RESET
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State RESET
2012-10-31 09:31:37.495317 [DEBUG] mod_sofia.c:166 sofia/internal/sip:ukytvsci@10.1.19.195:1292 SOFIA RESET
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:93 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Standard RESET
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State RESET going to sleep
2012-10-31 09:31:37.495317 [DEBUG] sofia.c:6045 Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 entering state [calling][0]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] sofia.c:6045 Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 entering state [terminated][500]
2012-10-31 09:31:37.495317 [DEBUG] switch_channel.c:2914 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Callstate Change ACTIVE -> HANGUP
2012-10-31 09:31:37.495317 [NOTICE] sofia.c:6837 Hangup sofia/internal/sip:ukytvsci@10.1.19.195:1292 [CS_RESET] [NORMAL_TEMPORARY_FAILURE]
2012-10-31 09:31:37.495317 [DEBUG] switch_channel.c:2937 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [KILL]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.495317 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_HANGUP
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State HANGUP
2012-10-31 09:31:37.515319 [DEBUG] mod_sofia.c:469 Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2012-10-31 09:31:37.515319 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.515319 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.515319 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:47 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State HANGUP going to sleep
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_HANGUP -> CS_REPORTING
2012-10-31 09:31:37.515319 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_REPORTING
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:685 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State REPORTING
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:79 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:685 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State REPORTING going to sleep
2012-10-31 09:31:37.515319 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_REPORTING -> CS_DESTROY
2012-10-31 09:31:37.515319 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:31:37.515319 [DEBUG] switch_core_session.c:1429 Session 2 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Locked, Waiting on external entities
2012-10-31 09:31:37.595338 [DEBUG] switch_ivr_bridge.c:1685 originatee uuid 048fd28b-765f-4444-9eb4-90487d72d191 is not present
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:93 sofia/internal/3429@10.1.3.50 Standard RESET
2012-10-31 09:31:37.595338 [NOTICE] switch_core_session.c:1447 Session 2 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Ended
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3429@10.1.3.50) State RESET going to sleep
2012-10-31 09:31:37.595338 [NOTICE] switch_core_session.c:1449 Close Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 [CS_DESTROY]
2012-10-31 09:31:37.595338 [DEBUG] sofia.c:6045 Channel sofia/internal/3429@10.1.3.50 entering state [calling][0]
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:514 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Callstate Change HANGUP -> DOWN
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:517 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_DESTROY
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State DESTROY
2012-10-31 09:31:37.595338 [DEBUG] mod_sofia.c:374 sofia/internal/sip:ukytvsci@10.1.19.195:1292 SOFIA DESTROY
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:86 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Standard DESTROY
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State DESTROY going to sleep
2012-10-31 09:31:37.595338 [DEBUG] sofia.c:6045 Channel sofia/internal/3429@10.1.3.50 entering state [terminated][500]
2012-10-31 09:31:37.595338 [DEBUG] switch_channel.c:2914 (sofia/internal/3429@10.1.3.50) Callstate Change ACTIVE -> HANGUP
2012-10-31 09:31:37.595338 [NOTICE] sofia.c:6837 Hangup sofia/internal/3429@10.1.3.50 [CS_RESET] [NORMAL_TEMPORARY_FAILURE]
2012-10-31 09:31:37.595338 [DEBUG] switch_channel.c:2937 Send signal sofia/internal/3429@10.1.3.50 [KILL]
2012-10-31 09:31:37.595338 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.595338 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_HANGUP
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/3429@10.1.3.50) State HANGUP
2012-10-31 09:31:37.615316 [DEBUG] mod_sofia.c:463 sofia/internal/3429@10.1.3.50 Overriding SIP cause 503 with 500 from the other leg
2012-10-31 09:31:37.615316 [DEBUG] mod_sofia.c:469 Channel sofia/internal/3429@10.1.3.50 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:47 sofia/internal/3429@10.1.3.50 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/3429@10.1.3.50) State HANGUP going to sleep
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/3429@10.1.3.50) State Change CS_HANGUP -> CS_REPORTING
2012-10-31 09:31:37.615316 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_REPORTING
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:685 (sofia/internal/3429@10.1.3.50) State REPORTING
2012-10-31 09:31:37.615316 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("3429","3429","3606","MobEx_IP","2012-10-31 09:31:37","2012-10-31 09:31:51","2012-10-31 09:31:37",0,-14,"NORMAL_TEMPORARY_FAILURE","b6f8eb4d-19d0-46ee-983d-81175e7f222b","","3429")
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:79 sofia/internal/3429@10.1.3.50 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:685 (sofia/internal/3429@10.1.3.50) State REPORTING going to sleep
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/3429@10.1.3.50) State Change CS_REPORTING -> CS_DESTROY
2012-10-31 09:31:37.615316 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:31:37.615316 [DEBUG] switch_core_session.c:1429 Session 1 (sofia/internal/3429@10.1.3.50) Locked, Waiting on external entities
2012-10-31 09:31:37.615316 [NOTICE] switch_core_session.c:1447 Session 1 (sofia/internal/3429@10.1.3.50) Ended
2012-10-31 09:31:37.615316 [NOTICE] switch_core_session.c:1449 Close Channel sofia/internal/3429@10.1.3.50 [CS_DESTROY]
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:514 (sofia/internal/3429@10.1.3.50) Callstate Change HANGUP -> DOWN
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:517 (sofia/internal/3429@10.1.3.50) Running State Change CS_DESTROY
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/3429@10.1.3.50) State DESTROY
2012-10-31 09:31:37.615316 [DEBUG] mod_sofia.c:374 sofia/internal/3429@10.1.3.50 SOFIA DESTROY
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:86 sofia/internal/3429@10.1.3.50 Standard DESTROY
2012-10-31 09:31:37.615316 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/3429@10.1.3.50) State DESTROY going to sleep