[Freeswitch-dev] FreeSWITCH erroneous RTP timestamps in front of sofsip_cli client?
Anthony Minessale
anthony.minessale at gmail.com
Sun Nov 24 04:31:38 MSK 2013
You should transfer this info to jira, http://jira.freeswitch.org it will
easily get lost in this mailing list. My inbox fills hundreds of
emails.....
Its the nest way to track issues.
On Fri, Nov 22, 2013 at 2:26 AM, Jean-Paul Iribarren <
jeanpaul.iribarren at free.fr> wrote:
> Hi Anthony, thank you for your message.
>
> Yes, I did try another client on my device; in my first message, I said:
>
> [quote]
> On the other hand, when I use linphonec in the very same conditions, I can
> see that FreeSWITCH sends 50 RTP packets per second on average. Each RTP
> packet contains 160 samples, and timestamps of consecutive packets are
> increased in 160 units steps, resulting in correct RX audio coming out of
> the loudspeaker of my device.
> [/quote]
>
> I performed yet another test yesterday evening: using sofsip_cli on caller
> side, I called a registered client (X-Lite registered as extension 1000),
> but after a few seconds I hit "Decline" button on X-Lite to refuse the
> incoming call. On sofsip_cli (caller side), the rx audio was good during
> the ringback phase (160 samples/pkt, timestamps growing by 160 units, 50
> pkts/s average), but turned loose as soon as the call was transfered by FS
> to the voicemail unit, as a consequence of the callee refusal (160
> samples/pkt, timestamps growing by 320 units, 25 pkts/s average -> slow /
> chopped rx audio). Looks like something is wrong regarding voicemail. But
> once again, why only in front of sofsip_cli???
>
> Regarding the capture, here it is (call initiated from sofsip_cli to an
> unregistered extension, triggering voicemail immediately, wait for end of
> (slow / chopped) voicemail message, hangup from caller side):
>
> [capture]
> freeswitch at XXX-xxxxxxxxx> recv 675 bytes from udp/[10.0.0.186]:5060 at
> 07:54:00.545012:
> ------------------------------------------------------------------------
> INVITE sip:1001 at 10.0.0.57 SIP/2.0
> Via: SIP/2.0/UDP 10.0.0.186;rport;branch=z9hG4bK0BaUp7Be94yKS
> Max-Forwards: 70
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571881 INVITE
> Contact: <sip:10.0.0.186>
> User-Agent: sofia-sip/1.12.10
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
> NOTIFY, REFER, UPDATE
> Supported: timer, 100rel
> Min-SE: 120
> Content-Type: application/sdp
> Content-Disposition: session
> Content-Length: 148
>
> v=0
> o=- 4844407640550486747 5665314394658789476 IN IP4 10.0.0.186
> s=-
> c=IN IP4 10.0.0.186
> t=0 0
> m=audio 16384 RTP/AVP 0
> a=rtpmap:0 PCMU/8000
> ------------------------------------------------------------------------
> send 326 bytes to udp/[10.0.0.186]:5060 at 07:54:00.545012:
> ------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 10.0.0.186;rport=5060;branch=z9hG4bK0BaUp7Be94yKS
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571881 INVITE
> User-Agent:
> FreeSWITCH-mod_sofia/1.5.6b+git~20131101T202135Z~2589bf7750~32bit
> Content-Length: 0
>
> ------------------------------------------------------------------------
> 2013-11-22 08:54:00.560624 [NOTICE] switch_channel.c:1055 New Channel
> sofia/internal/1009 at 10.0.0.57 [f28e1f66-1524-4ce5-9fe0-acf7bb929a1c]
> 2013-11-22 08:54:00.560624 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:00.560624 [DEBUG] switch_core_state_machine.c:467 (
> sofia/internal/1009 at 10.0.0.57) Running State Change CS_NEW
> 2013-11-22 08:54:00.560624 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:00.560624 [DEBUG] switch_core_state_machine.c:485 (
> sofia/internal/1009 at 10.0.0.57) State NEW
> 2013-11-22 08:54:00.591846 [DEBUG] sofia.c:8066 IP 10.0.0.186 Rejected by
> acl "domains". Falling back to Digest auth.
> send 840 bytes to udp/[10.0.0.186]:5060 at 07:54:00.591846:
> ------------------------------------------------------------------------
> SIP/2.0 407 Proxy Authentication Required
> Via: SIP/2.0/UDP 10.0.0.186;rport=5060;branch=z9hG4bK0BaUp7Be94yKS
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>;tag=29XpXm62B9N6r
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571881 INVITE
> User-Agent:
> FreeSWITCH-mod_sofia/1.5.6b+git~20131101T202135Z~2589bf7750~32bit
> Accept: application/sdp
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
> Supported: timer, precondition, path, replaces
> Allow-Events: talk, hold, conference, presence, as-feature-event,
> dialog, line-seize, call-info, sla, include-session-description,
> presence.winfo, message-su
> mmary, refer
> Proxy-Authenticate: Digest realm="10.0.0.57",
> nonce="598a20fb-5ab3-4ecf-af64-71388a03b2e6", algorithm=MD5, qop="auth"
> Content-Length: 0
>
> ------------------------------------------------------------------------
> 2013-11-22 08:54:00.591846 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:00.591846 [DEBUG] sofia.c:1816 detaching session
> f28e1f66-1524-4ce5-9fe0-acf7bb929a1c
> recv 287 bytes from udp/[10.0.0.186]:5060 at 07:54:00.607458:
> ------------------------------------------------------------------------
> ACK sip:1001 at 10.0.0.57 SIP/2.0
> Via: SIP/2.0/UDP 10.0.0.186;rport;branch=z9hG4bK0BaUp7Be94yKS
> Max-Forwards: 70
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>;tag=29XpXm62B9N6r
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571881 ACK
> Content-Length: 0
>
> ------------------------------------------------------------------------
> recv 927 bytes from udp/[10.0.0.186]:5060 at 07:54:03.386269:
> ------------------------------------------------------------------------
> INVITE sip:1001 at 10.0.0.57 SIP/2.0
> Via: SIP/2.0/UDP 10.0.0.186;rport;branch=z9hG4bK1m3Kr2vH6DN6m
> Max-Forwards: 70
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571882 INVITE
> Contact: <sip:10.0.0.186>
> User-Agent: sofia-sip/1.12.10
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
> NOTIFY, REFER, UPDATE
> Supported: timer, 100rel
> Proxy-Authorization: Digest username="1009", realm="10.0.0.57",
> nonce="598a20fb-5ab3-4ecf-af64-71388a03b2e6",
> cnonce="XIhwKMIwEjGCaQBQwtXdBw", algorithm=MD5,
> uri="sip:1001 at 10.0.0.57", response="df2df2940b0dd6f470f030d80fae7b08",
> qop=auth, nc=00000001
> Min-SE: 120
> Content-Type: application/sdp
> Content-Disposition: session
> Content-Length: 148
>
> v=0
> o=- 4844407640550486747 5665314394658789476 IN IP4 10.0.0.186
> s=-
> c=IN IP4 10.0.0.186
> t=0 0
> m=audio 16384 RTP/AVP 0
> a=rtpmap:0 PCMU/8000
> ------------------------------------------------------------------------
> send 326 bytes to udp/[10.0.0.186]:5060 at 07:54:03.386269:
> ------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 10.0.0.186;rport=5060;branch=z9hG4bK1m3Kr2vH6DN6m
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571882 INVITE
> User-Agent:
> FreeSWITCH-mod_sofia/1.5.6b+git~20131101T202135Z~2589bf7750~32bit
> Content-Length: 0
>
> ------------------------------------------------------------------------
> 2013-11-22 08:54:03.370658 [DEBUG] sofia.c:1908 Re-attaching to session
> f28e1f66-1524-4ce5-9fe0-acf7bb929a1c
> 2013-11-22 08:54:03.370658 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.370658 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.401880 [DEBUG] sofia.c:8066 IP 10.0.0.186 Rejected by
> acl "domains". Falling back to Digest auth.
> 2013-11-22 08:54:03.417492 [DEBUG] sofia.c:5863 Channel
> sofia/internal/1009 at 10.0.0.57 entering state [received][100]
> 2013-11-22 08:54:03.417492 [DEBUG] sofia.c:5873 Remote SDP:
> v=0
> o=- 4844407640550486747 5665314394658789476 IN IP4 10.0.0.186
> s=-
> c=IN IP4 10.0.0.186
> t=0 0
> m=audio 16384 RTP/AVP 0
> a=rtpmap:0 PCMU/8000
>
> 2013-11-22 08:54:03.417492 [DEBUG] sofia.c:6118 (
> sofia/internal/1009 at 10.0.0.57) State Change CS_NEW -> CS_INIT
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_session.c:1372 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:467 (
> sofia/internal/1009 at 10.0.0.57) Running State Change CS_INIT
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:506 (
> sofia/internal/1009 at 10.0.0.57) State INIT
> 2013-11-22 08:54:03.417492 [DEBUG] mod_sofia.c:87
> sofia/internal/1009 at 10.0.0.57 SOFIA INIT
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:40
> sofia/internal/1009 at 10.0.0.57 Standard INIT
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:48 (
> sofia/internal/1009 at 10.0.0.57) State Change CS_INIT -> CS_ROUTING
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_session.c:1372 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:506 (
> sofia/internal/1009 at 10.0.0.57) State INIT going to sleep
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:467 (
> sofia/internal/1009 at 10.0.0.57) Running State Change CS_ROUTING
> 2013-11-22 08:54:03.417492 [DEBUG] switch_channel.c:2178 (
> sofia/internal/1009 at 10.0.0.57) Callstate Change DOWN -> RINGING
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:522 (
> sofia/internal/1009 at 10.0.0.57) State ROUTING
> 2013-11-22 08:54:03.417492 [DEBUG] mod_sofia.c:123
> sofia/internal/1009 at 10.0.0.57 SOFIA ROUTING
> 2013-11-22 08:54:03.417492 [DEBUG] switch_core_state_machine.c:164
> sofia/internal/1009 at 10.0.0.57 Standard ROUTING
> 2013-11-22 08:54:03.417492 [INFO] mod_dialplan_xml.c:558 Processing 1009
> <1009>->1001 in context default
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->unloop]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->tod_example]
> continue=true
> Dialplan: sofia/internal/1009 at 10.0.0.57 Date/TimeMatch (FAIL)
> [tod_example] break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing
> [default->holiday_example] continue=true
> Dialplan: sofia/internal/1009 at 10.0.0.57 Date/TimeMatch (FAIL)
> [holiday_example] break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing
> [default->global-intercept] continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [global-intercept]
> destination_number(1001) =~ /^886$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing
> [default->group-intercept] continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [group-intercept]
> destination_number(1001) =~ /^\*8$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->intercept-ext]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [intercept-ext]
> destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->redial]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [redial]
> destination_number(1001) =~ /^(redial|870)$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->global]
> continue=true
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [global]
> ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [global]
> ${rtp_has_crypto}() =~
> /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (PASS) [global]
> ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/
> break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [global]
> ${switch_r_sdp}(v=0
> o=- 4844407640550486747 5665314394658789476 IN IP4 10.0.0.186
> s=-
> c=IN IP4 10.0.0.186
> t=0 0
> m=audio 16384 RTP/AVP 0
> a=rtpmap:0 PCMU/8000
> ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
> Dialplan: sofia/internal/1009 at 10.0.0.57 Absolute Condition [global]
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-last_dial/global/${uuid})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->snom-demo-2]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [snom-demo-2]
> destination_number(1001) =~ /^9001$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->snom-demo-1]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [snom-demo-1]
> destination_number(1001) =~ /^9000$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->eavesdrop]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [eavesdrop]
> destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->eavesdrop]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [eavesdrop]
> destination_number(1001) =~ /^779$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->call_return]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [call_return]
> destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->del-group]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [del-group]
> destination_number(1001) =~ /^80(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing [default->add-group]
> continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [add-group]
> destination_number(1001) =~ /^81(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing
> [default->call-group-simo] continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [call-group-simo]
> destination_number(1001) =~ /^82(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing
> [default->call-group-order] continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [call-group-order]
> destination_number(1001) =~ /^83(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing
> [default->extension-intercom] continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (FAIL) [extension-intercom]
> destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 parsing
> [default->Local_Extension] continue=false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Regex (PASS) [Local_Extension]
> destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> export(dialed_extension=1001)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action bind_meta_app(1 b s
> execute_extension::dx XML features)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action bind_meta_app(2 b s
> record_session::C:/Program
> Files/FreeSWITCH/recordings/${caller_id_number}.${strftime(%Y-%m-%
> d-%H-%M-%S)}.wav)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action bind_meta_app(3 b s
> execute_extension::cf XML features)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action bind_meta_app(4 b s
> execute_extension::att_xfer XML features)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> set(disable_rtp_auto_adjust=true)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> set(zrtp_secure_media=false)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action set(ringback=${us-ring})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> set(transfer_ringback=local_stream://moh)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action set(call_timeout=30)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> set(hangup_after_bridge=true)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action set(continue_on_fail=true)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
> var callgroup)})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-last_dial_ext/global/${uuid})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> bridge(user/${dialed_extension}@${domain_name})
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action answer()
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action sleep(1000)
> Dialplan: sofia/internal/1009 at 10.0.0.57 Action
> bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
> 2013-11-22 08:54:03.433103 [DEBUG] switch_core_state_machine.c:214 (
> sofia/internal/1009 at 10.0.0.57) State Change CS_ROUTING -> CS_EXECUTE
> 2013-11-22 08:54:03.433103 [DEBUG] switch_core_session.c:1372 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.433103 [DEBUG] switch_core_state_machine.c:522 (
> sofia/internal/1009 at 10.0.0.57) State ROUTING going to sleep
> 2013-11-22 08:54:03.433103 [DEBUG] switch_core_state_machine.c:467 (
> sofia/internal/1009 at 10.0.0.57) Running State Change CS_EXECUTE
> 2013-11-22 08:54:03.433103 [DEBUG] switch_core_state_machine.c:529 (
> sofia/internal/1009 at 10.0.0.57) State EXECUTE
> 2013-11-22 08:54:03.433103 [DEBUG] mod_sofia.c:178
> sofia/internal/1009 at 10.0.0.57 SOFIA EXECUTE
> 2013-11-22 08:54:03.433103 [DEBUG] switch_core_state_machine.c:256
> sofia/internal/1009 at 10.0.0.57 Standard EXECUTE
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-spymap/1009/f28e1f66-1524-4ce5-9fe0-acf7bb929a1c)
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-last_dial/1009/1001)
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-last_dial/global/f28e1f66-1524-4ce5-9fe0-acf7bb929a1c)
> EXECUTE sofia/internal/1009 at 10.0.0.57 export(RFC2822_DATE=Fri, 22 Nov
> 2013 08:54:03 Paris, Madrid)
> 2013-11-22 08:54:03.433103 [DEBUG] switch_channel.c:1247 EXPORT
> (export_vars) [RFC2822_DATE]=[Fri, 22 Nov 2013 08:54:03 Paris, Madrid]
> EXECUTE sofia/internal/1009 at 10.0.0.57 export(dialed_extension=1001)
> 2013-11-22 08:54:03.433103 [DEBUG] switch_channel.c:1247 EXPORT
> (export_vars) [dialed_extension]=[1001]
> EXECUTE sofia/internal/1009 at 10.0.0.57 bind_meta_app(1 b s
> execute_extension::dx XML features)
> 2013-11-22 08:54:03.479937 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *1
> execute_extension::dx XML features
> EXECUTE sofia/internal/1009 at 10.0.0.57 bind_meta_app(2 b s
> record_session::C:/Program
> Files/FreeSWITCH/recordings/1009.2013-11-22-08-54-03.wav)
> 2013-11-22 08:54:03.479937 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *2
> record_session::C:/Program
> Files/FreeSWITCH/recordings/1009.2013-11-22-08-54-03.wav
> EXECUTE sofia/internal/1009 at 10.0.0.57 bind_meta_app(3 b s
> execute_extension::cf XML features)
> 2013-11-22 08:54:03.479937 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *3
> execute_extension::cf XML features
> EXECUTE sofia/internal/1009 at 10.0.0.57 bind_meta_app(4 b s
> execute_extension::att_xfer XML features)
> 2013-11-22 08:54:03.479937 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *4
> execute_extension::att_xfer XML features
> EXECUTE sofia/internal/1009 at 10.0.0.57 set(disable_rtp_auto_adjust=true)
> 2013-11-22 08:54:03.479937 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [disable_rtp_auto_adjust]=[true]
> EXECUTE sofia/internal/1009 at 10.0.0.57 set(zrtp_secure_media=false)
> 2013-11-22 08:54:03.495548 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [zrtp_secure_media]=[false]
> EXECUTE sofia/internal/1009 at 10.0.0.57 set(ringback=%(2000,4000,440,480))
> 2013-11-22 08:54:03.495548 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [ringback]=[%(2000,4000,440,480)]
> EXECUTE sofia/internal/1009 at 10.0.0.57set(transfer_ringback=local_stream://moh)
> 2013-11-22 08:54:03.495548 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [transfer_ringback]=[local_stream://moh]
> EXECUTE sofia/internal/1009 at 10.0.0.57 set(call_timeout=30)
> 2013-11-22 08:54:03.495548 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [call_timeout]=[30]
> EXECUTE sofia/internal/1009 at 10.0.0.57 set(hangup_after_bridge=true)
> 2013-11-22 08:54:03.495548 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [hangup_after_bridge]=[true]
> EXECUTE sofia/internal/1009 at 10.0.0.57 set(continue_on_fail=true)
> 2013-11-22 08:54:03.495548 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [continue_on_fail]=[true]
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-call_return/1001/1009)
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-last_dial_ext/1001/f28e1f66-1524-4ce5-9fe0-acf7bb929a1c)
> EXECUTE sofia/internal/1009 at 10.0.0.57set(called_party_callgroup=techsupport)
> 2013-11-22 08:54:03.511159 [DEBUG] mod_dptools.c:1402
> sofia/internal/1009 at 10.0.0.57 SET [called_party_callgroup]=[techsupport]
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-last_dial_ext/techsupport/f28e1f66-1524-4ce5-9fe0-acf7bb929a1c)
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-last_dial_ext/global/f28e1f66-1524-4ce5-9fe0-acf7bb929a1c)
> EXECUTE sofia/internal/1009 at 10.0.0.57hash(insert/10.0.0.57-last_dial/techsupport/f28e1f66-1524-4ce5-9fe0-acf7bb929a1c)
> EXECUTE sofia/internal/1009 at 10.0.0.57 bridge(user/1001 at 10.0.0.57)
> 2013-11-22 08:54:03.511159 [DEBUG] switch_channel.c:1201
> sofia/internal/1009 at 10.0.0.57 EXPORTING[export_vars] [RFC2822_DATE]=[Fri,
> 22 Nov 2013 08:54:03 Paris, M
> adrid] to event
> 2013-11-22 08:54:03.511159 [DEBUG] switch_channel.c:1201
> sofia/internal/1009 at 10.0.0.57 EXPORTING[export_vars]
> [dialed_extension]=[1001] to event
> 2013-11-22 08:54:03.511159 [DEBUG] switch_ivr_originate.c:2070 Parsing
> global variables
> 2013-11-22 08:54:03.511159 [DEBUG] switch_channel.c:1201
> sofia/internal/1009 at 10.0.0.57 EXPORTING[export_vars] [RFC2822_DATE]=[Fri,
> 22 Nov 2013 08:54:03 Paris, M
> adrid] to event
> 2013-11-22 08:54:03.511159 [DEBUG] switch_channel.c:1201
> sofia/internal/1009 at 10.0.0.57 EXPORTING[export_vars]
> [dialed_extension]=[1001] to event
> 2013-11-22 08:54:03.511159 [DEBUG] switch_ivr_originate.c:2070 Parsing
> global variables
> 2013-11-22 08:54:03.511159 [DEBUG] switch_event.c:1680 Parsing variable
> [sip_invite_domain]=[10.0.0.57]
> 2013-11-22 08:54:03.511159 [DEBUG] switch_event.c:1680 Parsing variable
> [presence_id]=[1001 at 10.0.0.57]
> 2013-11-22 08:54:03.511159 [NOTICE] switch_ivr_originate.c:2699 Cannot
> create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
> 2013-11-22 08:54:03.511159 [DEBUG] switch_ivr_originate.c:3670 Originate
> Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
> 2013-11-22 08:54:03.511159 [NOTICE] switch_ivr_originate.c:2699 Cannot
> create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
>
> 2013-11-22 08:54:03.511159 [DEBUG] switch_ivr_originate.c:3670 Originate
> Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
> 2013-11-22 08:54:03.511159 [INFO] mod_dptools.c:3201 Originate Failed.
> Cause: USER_NOT_REGISTERED
>
> EXECUTE sofia/internal/1009 at 10.0.0.57 answer()
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_media.c:2994 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_media.c:2994 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_media.c:1956 Set Codec
> sofia/internal/1009 at 10.0.0.57 PCMU/8000 20 ms 160 samples 64000 bits
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_codec.c:111
> sofia/internal/1009 at 10.0.0.57 Original read codec set to PCMU:0
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_media.c:3197 No 2833 in
> SDP. Disable 2833 dtmf and switch to INFO
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_media.c:4321 AUDIO RTP [
> sofia/internal/1009 at 10.0.0.57] 10.0.0.57 port 22990 -> 10.0.0.186 port
> 16384 codec: 0 ms:
> 20
> 2013-11-22 08:54:03.542382 [DEBUG] switch_rtp.c:2995 Starting timer [soft]
> 160 bytes per 20ms
> 2013-11-22 08:54:03.542382 [NOTICE] sofia_media.c:92 Pre-Answer
> sofia/internal/1009 at 10.0.0.57!
> 2013-11-22 08:54:03.542382 [DEBUG] switch_channel.c:3404 (
> sofia/internal/1009 at 10.0.0.57) Callstate Change RINGING -> EARLY
> 2013-11-22 08:54:03.542382 [DEBUG] mod_sofia.c:772 Local SDP
> sofia/internal/1009 at 10.0.0.57:
> v=0
> o=FreeSWITCH 1385083853 1385083854 IN IP4 10.0.0.57
> s=FreeSWITCH
> c=IN IP4 10.0.0.57
> t=0 0
> m=audio 22990 RTP/AVP 0
> a=rtpmap:0 PCMU/8000
> a=ptime:20
> a=sendrecv
>
> send 1060 bytes to udp/[10.0.0.186]:5060 at 07:54:03.542382:
> ------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 10.0.0.186;rport=5060;branch=z9hG4bK1m3Kr2vH6DN6m
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>;tag=3jQFZFQ68HcSm
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571882 INVITE
> Contact: <sip:1001 at 10.0.0.57:5060;transport=udp>
> User-Agent:
> FreeSWITCH-mod_sofia/1.5.6b+git~20131101T202135Z~2589bf7750~32bit
> Accept: application/sdp
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
> Supported: timer, precondition, path, replaces
> Allow-Events: talk, hold, conference, presence, as-feature-event,
> dialog, line-seize, call-info, sla, include-session-description,
> presence.winfo, message-su
> mmary, refer
> Min-SE: 120
> Content-Type: application/sdp
> Content-Disposition: session
> Content-Length: 158
> Remote-Party-ID: "1001" <sip:1001 at 10.0.0.57>
> ;party=calling;privacy=off;screen=no
>
> v=0
> o=FreeSWITCH 1385083853 1385083854 IN IP4 10.0.0.57
> s=FreeSWITCH
> c=IN IP4 10.0.0.57
> t=0 0
> m=audio 22990 RTP/AVP 0
> a=rtpmap:0 PCMU/8000
> a=ptime:20
> ------------------------------------------------------------------------
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_session.c:892 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.542382 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.542382 [NOTICE] mod_dptools.c:1225 Channel [
> sofia/internal/1009 at 10.0.0.57] has been answered
> 2013-11-22 08:54:03.557993 [DEBUG] switch_channel.c:3685 (
> sofia/internal/1009 at 10.0.0.57) Callstate Change EARLY -> ACTIVE
> recv 558 bytes from udp/[10.0.0.186]:5060 at 07:54:03.557993:
> ------------------------------------------------------------------------
> ACK sip:1001 at 10.0.0.57:5060;transport=udp SIP/2.0
> Via: SIP/2.0/UDP 10.0.0.186;rport;branch=z9hG4bK2XvctXDN3pBSg
> Max-Forwards: 70
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>;tag=3jQFZFQ68HcSm
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571882 ACK
> Proxy-Authorization: Digest username="1009", realm="10.0.0.57",
> nonce="598a20fb-5ab3-4ecf-af64-71388a03b2e6",
> cnonce="XIhwKMIwEjGCaQBQwtXdBw", algorithm=MD5,
> uri="sip:1001 at 10.0.0.57", response="df2df2940b0dd6f470f030d80fae7b08",
> qop=auth, nc=00000001
> Content-Length: 0
>
> ------------------------------------------------------------------------
> 2013-11-22 08:54:03.557993 [DEBUG] sofia.c:5863 Channel
> sofia/internal/1009 at 10.0.0.57 entering state [completed][200]
> 2013-11-22 08:54:03.557993 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.557993 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:03.557993 [DEBUG] sofia.c:5863 Channel
> sofia/internal/1009 at 10.0.0.57 entering state [ready][200]
> 2013-11-22 08:54:03.557993 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> EXECUTE sofia/internal/1009 at 10.0.0.57 sleep(1000)
> EXECUTE sofia/internal/1009 at 10.0.0.57bridge(loopback/app=voicemail:default 10.0.0.57 1001)
> 2013-11-22 08:54:04.572728 [DEBUG] switch_channel.c:1768 (
> sofia/internal/1009 at 10.0.0.57) Callstate Change ACTIVE -> RING_WAIT
> 2013-11-22 08:54:04.572728 [DEBUG] switch_channel.c:1201
> sofia/internal/1009 at 10.0.0.57 EXPORTING[export_vars] [RFC2822_DATE]=[Fri,
> 22 Nov 2013 08:54:03 Paris, M
> adrid] to event
> 2013-11-22 08:54:04.572728 [DEBUG] switch_channel.c:1201
> sofia/internal/1009 at 10.0.0.57 EXPORTING[export_vars]
> [dialed_extension]=[1001] to event
> 2013-11-22 08:54:04.572728 [DEBUG] switch_ivr_originate.c:2070 Parsing
> global variables
> 2013-11-22 08:54:04.572728 [NOTICE] switch_channel.c:1055 New Channel
> loopback/app=voicemail:default 10.0.0.57 1001-a
> [ba43ba18-52aa-47b4-8311-daef490b5e73]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:157
> loopback/app=voicemail:default 10.0.0.57 1001-a setup codec PCMU/8000/20
> 2013-11-22 08:54:04.572728 [NOTICE] switch_channel.c:1053 Rename Channel
> loopback/app=voicemail:default 10.0.0.57 1001-a->loopback/voicemail-a
> [ba43ba18-52aa-47
> b4-8311-daef490b5e73]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:1160
> (loopback/voicemail-a) State Change CS_NEW -> CS_INIT
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-a) Running State Change CS_INIT
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:506
> (loopback/voicemail-a) State INIT
> 2013-11-22 08:54:04.572728 [NOTICE] switch_channel.c:1055 New Channel
> loopback/voicemail-b [d1b207bf-b400-40e9-985e-edffbe379887]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:157 loopback/voicemail-b
> setup codec PCMU/8000/20
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:273
> (loopback/voicemail-b) State Change CS_NEW -> CS_INIT
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:359
> (loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-b) Running State Change CS_INIT
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:506
> (loopback/voicemail-b) State INIT
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:506
> (loopback/voicemail-a) State INIT going to sleep
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:359
> (loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-a) Running State Change CS_ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:506
> (loopback/voicemail-b) State INIT going to sleep
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:522
> (loopback/voicemail-a) State ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:391 loopback/voicemail-a
> CHANNEL ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-b) Running State Change CS_ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] switch_ivr_originate.c:67
> (loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
> 2013-11-22 08:54:04.572728 [DEBUG] switch_channel.c:2178
> (loopback/voicemail-b) Callstate Change DOWN -> RINGING
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:522
> (loopback/voicemail-a) State ROUTING going to sleep
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:522
> (loopback/voicemail-b) State ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:391 loopback/voicemail-b
> CHANNEL ROUTING
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:410
> (loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:541
> (loopback/voicemail-a) State CONSUME_MEDIA
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:650 CHANNEL CONSUME_MEDIA
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:541
> (loopback/voicemail-a) State CONSUME_MEDIA going to sleep
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:522
> (loopback/voicemail-b) State ROUTING going to sleep
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-b) Running State Change CS_EXECUTE
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:529
> (loopback/voicemail-b) State EXECUTE
> 2013-11-22 08:54:04.572728 [DEBUG] mod_loopback.c:433 loopback/voicemail-b
> CHANNEL EXECUTE
> 2013-11-22 08:54:04.572728 [DEBUG] switch_core_state_machine.c:256
> loopback/voicemail-b Standard EXECUTE
> EXECUTE loopback/voicemail-b pre_answer()
> 2013-11-22 08:54:04.603950 [NOTICE] mod_loopback.c:947 Pre-Answer
> loopback/voicemail-a!
> 2013-11-22 08:54:04.603950 [DEBUG] switch_channel.c:3400 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:04.603950 [DEBUG] switch_channel.c:3404
> (loopback/voicemail-a) Callstate Change DOWN -> EARLY
> 2013-11-22 08:54:04.603950 [DEBUG] switch_core_session.c:892 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:04.603950 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:04.603950 [NOTICE] mod_dptools.c:1260 Pre-Answer
> loopback/voicemail-b!
> 2013-11-22 08:54:04.603950 [DEBUG] switch_channel.c:3404
> (loopback/voicemail-b) Callstate Change RINGING -> EARLY
> EXECUTE loopback/voicemail-b voicemail(default 10.0.0.57 1001)
> 2013-11-22 08:54:04.603950 [DEBUG] switch_ivr_originate.c:3532 Originate
> Resulted in Success: [loopback/voicemail-a]
> 2013-11-22 08:54:04.603950 [DEBUG] switch_channel.c:1977 (
> sofia/internal/1009 at 10.0.0.57) Callstate Change RING_WAIT -> ACTIVE
> 2013-11-22 08:54:04.603950 [DEBUG] switch_core_session.c:892 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:04.603950 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:04.619562 [DEBUG] switch_core_session.c:892 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:04.619562 [DEBUG] switch_ivr_bridge.c:1440
> (loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
> 2013-11-22 08:54:04.619562 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA
> 2013-11-22 08:54:04.619562 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:04.619562 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:04.619562 [DEBUG] switch_core_state_machine.c:532
> (loopback/voicemail-a) State EXCHANGE_MEDIA
> 2013-11-22 08:54:04.619562 [DEBUG] mod_loopback.c:612 CHANNEL LOOPBACK
> 2013-11-22 08:54:04.744452 [DEBUG] switch_ivr_play_say.c:70 No language
> specified - Using [en]
> 2013-11-22 08:54:04.760063 [DEBUG] switch_ivr_play_say.c:251 Handle
> play-file:[voicemail/vm-person.wav] (en:en)
> 2013-11-22 08:54:04.822509 [DEBUG] switch_ivr_play_say.c:1319 Codec
> Activated L16 at 8000hz 1 channels 20ms
> 2013-11-22 08:54:07.601320 [DEBUG] switch_ivr_play_say.c:1723 done playing
> file C:/Program Files/FreeSWITCH/sounds/en/us/callie/voicemail/vm-person.wav
> 2013-11-22 08:54:07.741822 [DEBUG] switch_ivr_play_say.c:251 Handle
> say:[1001] (en:en)
> 2013-11-22 08:54:07.773044 [DEBUG] switch_ivr_play_say.c:1319 Codec
> Activated L16 at 8000hz 1 channels 20ms
> 2013-11-22 08:54:12.440823 [DEBUG] switch_ivr_play_say.c:1723 done playing
> file file_string://digits/1.wav!digits/0.wav!digits/0.wav!digits/1.wav
> 2013-11-22 08:54:12.550102 [DEBUG] switch_ivr_play_say.c:251 Handle
> play-file:[voicemail/vm-not_available.wav] (en:en)
> 2013-11-22 08:54:12.596936 [DEBUG] switch_ivr_play_say.c:1319 Codec
> Activated L16 at 8000hz 1 channels 20ms
> 2013-11-22 08:54:14.532737 [DEBUG] switch_ivr_play_say.c:1723 done playing
> file C:/Program
> Files/FreeSWITCH/sounds/en/us/callie/voicemail/vm-not_available.wav
> 2013-11-22 08:54:14.657628 [DEBUG] switch_ivr_play_say.c:70 No language
> specified - Using [en]
> 2013-11-22 08:54:14.657628 [DEBUG] switch_ivr_play_say.c:251 Handle
> play-file:[voicemail/vm-record_message.wav] (en:en)
> 2013-11-22 08:54:14.673239 [DEBUG] switch_ivr_play_say.c:1319 Codec
> Activated L16 at 8000hz 1 channels 20ms
> 2013-11-22 08:54:23.852683 [DEBUG] switch_ivr_play_say.c:1723 done playing
> file C:/Program
> Files/FreeSWITCH/sounds/en/us/callie/voicemail/vm-record_message.wav
> 2013-11-22 08:54:26.459770 [DEBUG] switch_channel.c:3639 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:26.459770 [NOTICE] mod_loopback.c:942 Channel
> [loopback/voicemail-a] has been answered
> 2013-11-22 08:54:26.459770 [DEBUG] switch_channel.c:3685
> (loopback/voicemail-a) Callstate Change EARLY -> ACTIVE
> 2013-11-22 08:54:26.459770 [DEBUG] switch_core_session.c:892 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:26.459770 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:26.459770 [NOTICE] switch_ivr_play_say.c:409 Channel
> [loopback/voicemail-b] has been answered
> 2013-11-22 08:54:26.459770 [DEBUG] switch_channel.c:3685
> (loopback/voicemail-b) Callstate Change EARLY -> ACTIVE
> 2013-11-22 08:54:26.459770 [DEBUG] switch_ivr_play_say.c:599 Raw Codec
> Activated
> 2013-11-22 08:54:26.459770 [DEBUG] switch_core_codec.c:221
> loopback/voicemail-b Push codec L16:70
> 2013-11-22 08:54:26.475382 [DEBUG] switch_core_session.c:954 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:26.475382 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:26.475382 [DEBUG] switch_core_session.c:954 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> recv 726 bytes from udp/[10.0.0.186]:5060 at 07:54:28.270681:
> ------------------------------------------------------------------------
> BYE sip:1001 at 10.0.0.57:5060;transport=udp SIP/2.0
> Via: SIP/2.0/UDP 10.0.0.186;rport;branch=z9hG4bK36N5Uryr0Z1Bc
> Max-Forwards: 70
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>;tag=3jQFZFQ68HcSm
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571883 BYE
> User-Agent: sofia-sip/1.12.10
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
> NOTIFY, REFER, UPDATE
> Supported: timer, 100rel
> Proxy-Authorization: Digest username="1009", realm="10.0.0.57",
> nonce="598a20fb-5ab3-4ecf-af64-71388a03b2e6",
> cnonce="XIhwKMIwEjGCaQBQwtXdBw", algorithm=MD5,
> uri="sip:1001 at 10.0.0.57:5060;transport=udp",
> response="f3fac72314ac0ff146b8561734438dc5", qop=auth, nc=00000002
> Content-Length: 0
>
> ------------------------------------------------------------------------
> 2013-11-22 08:54:28.255070 [DEBUG] switch_core_session.c:1037 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:28.270681 [NOTICE] sofia.c:715 Hangup
> sofia/internal/1009 at 10.0.0.57 [CS_EXECUTE] [NORMAL_CLEARING]
> 2013-11-22 08:54:28.270681 [DEBUG] switch_channel.c:3211 Send signal
> sofia/internal/1009 at 10.0.0.57 [KILL]
> 2013-11-22 08:54:28.270681 [DEBUG] switch_core_session.c:1372 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> send 495 bytes to udp/[10.0.0.186]:5060 at 07:54:28.270681:
> ------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 10.0.0.186;rport=5060;branch=z9hG4bK36N5Uryr0Z1Bc
> From: <1009 at 10.0.0.57> <1009 at 10.0.0.57>;tag=08mryQ3v0DXtF
> To: <sip:1001 at 10.0.0.57>;tag=3jQFZFQ68HcSm
> Call-ID: 5c7dc01d-c230-1231-6982-0050c2d5dd07
> CSeq: 51571883 BYE
> User-Agent:
> FreeSWITCH-mod_sofia/1.5.6b+git~20131101T202135Z~2589bf7750~32bit
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
> Supported: timer, precondition, path, replaces
> Content-Length: 0
>
> ------------------------------------------------------------------------
> 2013-11-22 08:54:28.270681 [DEBUG] switch_ivr_bridge.c:647 BRIDGE THREAD
> DONE [sofia/internal/1009 at 10.0.0.57]
> 2013-11-22 08:54:28.270681 [DEBUG] switch_ivr_bridge.c:672 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:28.270681 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:28.301904 [DEBUG] switch_ivr_bridge.c:647 BRIDGE THREAD
> DONE [loopback/voicemail-a]
> 2013-11-22 08:54:28.301904 [DEBUG] switch_ivr_bridge.c:672 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:28.301904 [NOTICE] switch_ivr_bridge.c:735 Hangup
> loopback/voicemail-a [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
> 2013-11-22 08:54:28.301904 [DEBUG] switch_channel.c:3211 Send signal
> loopback/voicemail-a [KILL]
> 2013-11-22 08:54:28.301904 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:28.301904 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:28.301904 [DEBUG] switch_ivr_bridge.c:1538
> loopback/voicemail-a skip receive message [UNBRIDGE] (channel is hungup
> already)
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_state_machine.c:532
> (loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-a) Running State Change CS_HANGUP
> 2013-11-22 08:54:28.301904 [DEBUG] switch_ivr_bridge.c:1541
> sofia/internal/1009 at 10.0.0.57 skip receive message [UNBRIDGE] (channel is
> hungup already)
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_session.c:2841
> sofia/internal/1009 at 10.0.0.57 skip receive message
> [APPLICATION_EXEC_COMPLETE] (channel is hungup
> already)
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_state_machine.c:529 (
> sofia/internal/1009 at 10.0.0.57) State EXECUTE going to sleep
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_state_machine.c:467 (
> sofia/internal/1009 at 10.0.0.57) Running State Change CS_HANGUP
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_state_machine.c:730
> (loopback/voicemail-a) State HANGUP
> 2013-11-22 08:54:28.301904 [DEBUG] mod_loopback.c:537 loopback/voicemail-a
> CHANNEL HANGUP
> 2013-11-22 08:54:28.301904 [NOTICE] mod_loopback.c:553 Hangup
> loopback/voicemail-b [CS_EXECUTE] [NORMAL_CLEARING]
> 2013-11-22 08:54:28.301904 [DEBUG] switch_channel.c:3211 Send signal
> loopback/voicemail-b [KILL]
> 2013-11-22 08:54:28.301904 [DEBUG] switch_core_state_machine.c:730 (
> sofia/internal/1009 at 10.0.0.57) State HANGUP
> 2013-11-22 08:54:28.301904 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:28.317515 [DEBUG] mod_sofia.c:413 Channel
> sofia/internal/1009 at 10.0.0.57 hanging up, cause: NORMAL_CLEARING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:28.317515 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:58
> loopback/voicemail-a Standard HANGUP, cause: NORMAL_CLEARING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:730
> (loopback/voicemail-a) State HANGUP going to sleep
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:743
> (loopback/voicemail-a) Callstate Change ACTIVE -> HANGUP
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:498
> (loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:28.317515 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-a) Running State Change CS_REPORTING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_codec.c:246
> loopback/voicemail-b Restore previous codec PCMU:0.
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:815
> (loopback/voicemail-a) State REPORTING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:102
> loopback/voicemail-a Standard REPORTING, cause: NORMAL_CLEARING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:815
> (loopback/voicemail-a) State REPORTING going to sleep
> 2013-11-22 08:54:28.317515 [DEBUG] mod_voicemail.c:1237 Message is less
> than minimum record length: 3, discarding it.
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:492
> (loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-a [BREAK]
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_session.c:2841
> loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE]
> (channel is hungup already)
> 2013-11-22 08:54:28.317515 [DEBUG] mod_loopback.c:590 loopback/voicemail-a
> CHANNEL KILL
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:529
> (loopback/voicemail-b) State EXECUTE going to sleep
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_session.c:1580 Session 2
> (loopback/voicemail-a) Locked, Waiting on external entities
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-b) Running State Change CS_HANGUP
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:58
> sofia/internal/1009 at 10.0.0.57 Standard HANGUP, cause: NORMAL_CLEARING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:730 (
> sofia/internal/1009 at 10.0.0.57) State HANGUP going to sleep
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:743 (
> sofia/internal/1009 at 10.0.0.57) Callstate Change ACTIVE -> HANGUP
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:498 (
> sofia/internal/1009 at 10.0.0.57) State Change CS_HANGUP -> CS_REPORTING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:730
> (loopback/voicemail-b) State HANGUP
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_session.c:1372 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:28.317515 [DEBUG] mod_loopback.c:537 loopback/voicemail-b
> CHANNEL HANGUP
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:58
> loopback/voicemail-b Standard HANGUP, cause: NORMAL_CLEARING
> 2013-11-22 08:54:28.317515 [NOTICE] switch_core_session.c:1598 Session 2
> (loopback/voicemail-a) Ended
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:467 (
> sofia/internal/1009 at 10.0.0.57) Running State Change CS_REPORTING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:730
> (loopback/voicemail-b) State HANGUP going to sleep
> 2013-11-22 08:54:28.317515 [NOTICE] switch_core_session.c:1602 Close
> Channel loopback/voicemail-a [CS_DESTROY]
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:743
> (loopback/voicemail-b) Callstate Change ACTIVE -> HANGUP
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:815 (
> sofia/internal/1009 at 10.0.0.57) State REPORTING
> 2013-11-22 08:54:28.317515 [DEBUG] switch_core_state_machine.c:617
> (loopback/voicemail-a) Callstate Change HANGUP -> DOWN
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_state_machine.c:498
> (loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_state_machine.c:620
> (loopback/voicemail-a) Running State Change CS_DESTROY
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:28.333126 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_state_machine.c:630
> (loopback/voicemail-a) State DESTROY
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_state_machine.c:467
> (loopback/voicemail-b) Running State Change CS_REPORTING
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_state_machine.c:109
> loopback/voicemail-a Standard DESTROY
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_state_machine.c:630
> (loopback/voicemail-a) State DESTROY going to sleep
> 2013-11-22 08:54:28.333126 [DEBUG] switch_core_state_machine.c:815
> (loopback/voicemail-b) State REPORTING
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:102
> loopback/voicemail-b Standard REPORTING, cause: NORMAL_CLEARING
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:102
> sofia/internal/1009 at 10.0.0.57 Standard REPORTING, cause: NORMAL_CLEARING
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:815 (
> sofia/internal/1009 at 10.0.0.57) State REPORTING going to sleep
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:815
> (loopback/voicemail-b) State REPORTING going to sleep
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:492
> (loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:492 (
> sofia/internal/1009 at 10.0.0.57) State Change CS_REPORTING -> CS_DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_session.c:1372 Send signal
> loopback/voicemail-b [BREAK]
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_session.c:1372 Send signal
> sofia/internal/1009 at 10.0.0.57 [BREAK]
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_session.c:1580 Session 1 (
> sofia/internal/1009 at 10.0.0.57) Locked, Waiting on external entities
> 2013-11-22 08:54:28.379960 [DEBUG] mod_loopback.c:590 loopback/voicemail-b
> CHANNEL KILL
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_session.c:1580 Session 3
> (loopback/voicemail-b) Locked, Waiting on external entities
> 2013-11-22 08:54:28.379960 [NOTICE] switch_core_session.c:1598 Session 1 (
> sofia/internal/1009 at 10.0.0.57) Ended
> 2013-11-22 08:54:28.379960 [NOTICE] switch_core_session.c:1602 Close
> Channel sofia/internal/1009 at 10.0.0.57 [CS_DESTROY]
> 2013-11-22 08:54:28.379960 [NOTICE] switch_core_session.c:1598 Session 3
> (loopback/voicemail-b) Ended
> 2013-11-22 08:54:28.379960 [NOTICE] switch_core_session.c:1602 Close
> Channel loopback/voicemail-b [CS_DESTROY]
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:617 (
> sofia/internal/1009 at 10.0.0.57) Callstate Change HANGUP -> DOWN
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:617
> (loopback/voicemail-b) Callstate Change HANGUP -> DOWN
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:620 (
> sofia/internal/1009 at 10.0.0.57) Running State Change CS_DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:620
> (loopback/voicemail-b) Running State Change CS_DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:630 (
> sofia/internal/1009 at 10.0.0.57) State DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] mod_sofia.c:323
> sofia/internal/1009 at 10.0.0.57 SOFIA DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:630
> (loopback/voicemail-b) State DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:109
> loopback/voicemail-b Standard DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:109
> sofia/internal/1009 at 10.0.0.57 Standard DESTROY
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:630 (
> sofia/internal/1009 at 10.0.0.57) State DESTROY going to sleep
> 2013-11-22 08:54:28.379960 [DEBUG] switch_core_state_machine.c:630
> (loopback/voicemail-b) State DESTROY going to sleep
> [/capture]
>
> Can you see anything unusual in the trace above?
> --
> JPI
>
>
> Le 21/11/2013 22:06, Anthony Minessale a écrit :
>
> Do you get different results when you call it with some other phone in
> place of sofia_cli ?
>
> Can you get a full capture of the debug logs
>
> sofia global siptrace on
> console loglevel debug
> sofia tracelevel alert
>
> [... snip ...]
>
>
> --
> Anthony Minessale II
>
> FreeSWITCH http://www.freeswitch.org/
> ClueCon http://www.cluecon.com/
> Twitter: http://twitter.com/FreeSWITCH_wire
>
> AIM: anthm
> MSN:anthony_minessale at hotmail.com
> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
> IRC: irc.freenode.net #freeswitch
>
> FreeSWITCH Developer Conference
> sip:888 at conference.freeswitch.org
> googletalk:conf+888 at conference.freeswitch.org
> pstn:+19193869900
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:consulting at freeswitch.orghttp://www.freeswitchsolutions.com
>
> FreeSWITCH-powered IP PBX: The CudaTel Communication Server
>
> Official FreeSWITCH Siteshttp://www.freeswitch.orghttp://wiki.freeswitch.orghttp://www.cluecon.com
>
> FreeSWITCH-dev mailing listFreeSWITCH-dev at lists.freeswitch.orghttp://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-devhttp://www.freeswitch.org
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-dev mailing list
> FreeSWITCH-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>
>
--
Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/
ClueCon http://www.cluecon.com/
Twitter: http://twitter.com/FreeSWITCH_wire
AIM: anthm
MSN:anthony_minessale at hotmail.com
GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference
sip:888 at conference.freeswitch.org
googletalk:conf+888 at conference.freeswitch.org
pstn:+19193869900
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-dev/attachments/20131123/6e528207/attachment-0001.html
Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-dev
mailing list