[Freeswitch-users] Problems with rxfax (doesn't work)

Stefano Marinelli postnet at dragas.dyndns.org
Thu Jul 30 07:15:53 PDT 2009 

Hi.
I'm trying to receive a fax using Freeswitch. It's a SIP channel. I know
there's no T38 support (yet) but I think I can get decent result with
G711 (as I got with Asterisk and Callweaver on non-T38 providers).
In FS, all fails just some seconds after the channel has been answered.

Here's the log:
  recv 1080 bytes from udp/[83.211.227.21]:5060 at 09:23:03.446391:
    ------------------------------------------------------------------------
    INVITE sip:gw+eutelia-MYPHONENUMBER at MYSERVERIP:5080;transport=udp
SIP/2.0
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bK23d3.d38ffb01.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6C891C4A
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    User-Agent: Cisco-SIPGateway/IOS-12.x
    CSeq: 101 INVITE
    Max-Forwards:  9
    Contact: <sip:83.211.2.218:5060>
    Expires: 180
    Allow-Events: telephone-event
    Content-Type: application/sdp
    Content-Length: 419
    P-hint: 2 Niente 2

    v=0
    o=CiscoSystemsSIP-GW-UserAgent 6035 7635 IN IP4 83.211.2.218
    s=SIP Call
    c=IN IP4 83.211.223.198
    t=0 0
    m=audio 64720 RTP/AVP 18 8 0 4 3 125 101
    c=IN IP4 83.211.223.198
    a=rtpmap:18 G729/8000
    a=fmtp:18 annexb=yes
    a=rtpmap:8 PCMA/8000
    a=rtpmap:0 PCMU/8000
    a=rtpmap:4 G723/8000
    a=fmtp:4 bitrate=5.3;annexa=no
    a=rtpmap:3 GSM/8000
    a=rtpmap:125 X-CCD/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    ------------------------------------------------------------------------
send 469 bytes to udp/[83.211.227.21]:5060 at 09:23:03.446769:
    ------------------------------------------------------------------------
    SIP/2.0 100 Trying
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bK23d3.d38ffb01.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6C891C4A
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    CSeq: 101 INVITE
    User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14423
    Content-Length: 0

    ------------------------------------------------------------------------
2009-07-30 11:23:03.522325 [NOTICE] switch_channel.c:602 New Channel
sofia/external/nobody at 83.211.2.218 [952a66b0-7cea-11de-8429-253fe7587d86]
2009-07-30 11:23:03.522325 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [received][100]
2009-07-30 11:23:03.522325 [DEBUG] sofia.c:3296 Remote SDP:
v=0
o=CiscoSystemsSIP-GW-UserAgent 6035 7635 IN IP4 83.211.2.218
s=SIP Call
c=IN IP4 83.211.223.198
t=0 0
m=audio 64720 RTP/AVP 18 8 0 4 3 125 101
c=IN IP4 83.211.223.198
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:4 G723/8000
a=fmtp:4 bitrate=5.3;annexa=no
a=rtpmap:3 GSM/8000
a=rtpmap:125 X-CCD/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:2811 Activate Buggy
RFC2833 Mode!
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
[G729:18:8000:0]/[PCMU:0:8000:20]
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
[G729:18:8000:0]/[PCMA:8:8000:20]
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
[G729:18:8000:0]/[GSM:3:8000:20]
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
[PCMA:8:8000:0]/[PCMU:0:8000:20]
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
[PCMA:8:8000:0]/[PCMA:8:8000:20]
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:2029 Set Codec
sofia/external/nobody at 83.211.2.218 PCMA/8000 20 ms 160 samples
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:3031 Set 2833 dtmf
payload to 101
2009-07-30 11:23:03.522325 [DEBUG] sofia.c:3455
(sofia/external/nobody at 83.211.2.218) State Change CS_NEW -> CS_INIT
2009-07-30 11:23:03.522325 [DEBUG] switch_core_session.c:932 Send signal
sofia/external/nobody at 83.211.2.218 [BREAK]
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:398
(sofia/external/nobody at 83.211.2.218) Running State Change CS_INIT
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:481
(sofia/external/nobody at 83.211.2.218) State INIT
2009-07-30 11:23:03.522325 [DEBUG] mod_sofia.c:83
sofia/external/nobody at 83.211.2.218 SOFIA INIT
2009-07-30 11:23:03.522325 [DEBUG] mod_sofia.c:111
(sofia/external/nobody at 83.211.2.218) State Change CS_INIT -> CS_ROUTING
2009-07-30 11:23:03.522325 [DEBUG] switch_core_session.c:932 Send signal
sofia/external/nobody at 83.211.2.218 [BREAK]
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:481
(sofia/external/nobody at 83.211.2.218) State INIT going to sleep
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:398
(sofia/external/nobody at 83.211.2.218) Running State Change CS_ROUTING
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:484
(sofia/external/nobody at 83.211.2.218) State ROUTING
2009-07-30 11:23:03.522325 [DEBUG] mod_sofia.c:130
sofia/external/nobody at 83.211.2.218 SOFIA ROUTING
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:78
sofia/external/nobody at 83.211.2.218 Standard ROUTING
2009-07-30 11:23:03.522325 [INFO] mod_dialplan_xml.c:315 Processing
unknown->MYPHONENUMBER in context public
Dialplan: sofia/external/nobody at 83.211.2.218 parsing [public->unloop]
continue=false
Dialplan: sofia/external/nobody at 83.211.2.218 Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/nobody at 83.211.2.218 Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/nobody at 83.211.2.218 parsing
[public->outside_call] continue=true
Dialplan: sofia/external/nobody at 83.211.2.218 Absolute Condition
[outside_call]
Dialplan: sofia/external/nobody at 83.211.2.218 Action set(outside_call=true)
Dialplan: sofia/external/nobody at 83.211.2.218 parsing
[public->call_debug] continue=true
Dialplan: sofia/external/nobody at 83.211.2.218 Regex (FAIL) [call_debug]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/nobody at 83.211.2.218 parsing
[public->public_extensions] continue=false
Dialplan: sofia/external/nobody at 83.211.2.218 Regex (FAIL)
[public_extensions] destination_number(MYPHONENUMBER) =~
/^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/nobody at 83.211.2.218 parsing
[public->MYPHONENUMBER] continue=false
Dialplan: sofia/external/nobody at 83.211.2.218 Regex (PASS)
[MYPHONENUMBER] destination_number(MYPHONENUMBER) =~ /^(MYPHONENUMBER)$/
break=on-false
Dialplan: sofia/external/nobody at 83.211.2.218 Action
set(domain_name=MYSERVERIP)
Dialplan: sofia/external/nobody at 83.211.2.218 Action answer()
Dialplan: sofia/external/nobody at 83.211.2.218 Action
playback(silence_stream://2000)
Dialplan: sofia/external/nobody at 83.211.2.218 Action rxfax(/tmp/rxfax.tiff)
Dialplan: sofia/external/nobody at 83.211.2.218 Action hangup()
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:114
(sofia/external/nobody at 83.211.2.218) State Change CS_ROUTING -> CS_EXECUTE
2009-07-30 11:23:03.522325 [DEBUG] switch_core_session.c:932 Send signal
sofia/external/nobody at 83.211.2.218 [BREAK]
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:484
(sofia/external/nobody at 83.211.2.218) State ROUTING going to sleep
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:398
(sofia/external/nobody at 83.211.2.218) Running State Change CS_EXECUTE
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:491
(sofia/external/nobody at 83.211.2.218) State EXECUTE
2009-07-30 11:23:03.522325 [DEBUG] mod_sofia.c:173
sofia/external/nobody at 83.211.2.218 SOFIA EXECUTE
2009-07-30 11:23:03.522325 [DEBUG] switch_core_state_machine.c:151
sofia/external/nobody at 83.211.2.218 Standard EXECUTE
EXECUTE sofia/external/nobody at 83.211.2.218 set(outside_call=true)
2009-07-30 11:23:03.522325 [DEBUG] mod_dptools.c:748
sofia/external/nobody at 83.211.2.218 SET [outside_call]=[true]
EXECUTE sofia/external/nobody at 83.211.2.218 set(domain_name=MYSERVERIP)
2009-07-30 11:23:03.522325 [DEBUG] mod_dptools.c:748
sofia/external/nobody at 83.211.2.218 SET [domain_name]=[MYSERVERIP]
EXECUTE sofia/external/nobody at 83.211.2.218 answer()
2009-07-30 11:23:03.522325 [DEBUG] mod_dptools.c:649
sofia/external/nobody at 83.211.2.218 receive message [ANSWER]
2009-07-30 11:23:03.522325 [DEBUG] sofia_glue.c:2263 AUDIO RTP
[sofia/external/nobody at 83.211.2.218] MYSERVERIP port 23414 ->
83.211.223.198 port 64720 codec: 8 ms: 20
2009-07-30 11:23:03.522325 [DEBUG] switch_rtp.c:1138 Starting timer
[soft] 160 bytes per 20ms
2009-07-30 11:23:03.522325 [DEBUG] mod_sofia.c:552 Local SDP
sofia/external/nobody at 83.211.2.218:
v=0
o=FreeSWITCH 1248922369 1248922370 IN IP4 MYSERVERIP
s=FreeSWITCH
c=IN IP4 MYSERVERIP
t=0 0
m=audio 23414 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2009-07-30 11:23:03.522325 [DEBUG] switch_core_session.c:630 Send signal
sofia/external/nobody at 83.211.2.218 [BREAK]
2009-07-30 11:23:03.522325 [NOTICE] mod_dptools.c:649 Channel
[sofia/external/nobody at 83.211.2.218] has been answered
2009-07-30 11:23:03.522325 [DEBUG] switch_channel.c:182
sofia/external/nobody at 83.211.2.218 receive message [AUDIO_SYNC]
EXECUTE sofia/external/nobody at 83.211.2.218 playback(silence_stream://2000)
2009-07-30 11:23:03.522325 [DEBUG] switch_ivr_play_say.c:1097 Codec
Activated L16 at 8000hz 1 channels 20ms
2009-07-30 11:23:03.522325 [DEBUG] switch_core_io.c:649
sofia/external/nobody at 83.211.2.218 receive message [TRANSCODING_NECESSARY]
send 1057 bytes to udp/[83.211.227.21]:5060 at 09:23:03.456354:
    ------------------------------------------------------------------------
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bK23d3.d38ffb01.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6C891C4A
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    CSeq: 101 INVITE
    Contact: <sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp>
    User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14423
    Accept: application/sdp
    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO
    Supported: timer, precondition, path, replaces
    Allow-Events: talk, refer
    Content-Type: application/sdp
    Content-Disposition: session
    Content-Length: 245

    v=0
    o=FreeSWITCH 1248922369 1248922370 IN IP4 MYSERVERIP
    s=FreeSWITCH
    c=IN IP4 MYSERVERIP
    t=0 0
    m=audio 23414 RTP/AVP 8 101
    a=rtpmap:8 PCMA/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    a=silenceSupp:off - - - -
    a=ptime:20
    ------------------------------------------------------------------------
2009-07-30 11:23:03.522325 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [completed][200]
recv 490 bytes from udp/[83.211.227.21]:5060 at 09:23:03.546934:
    ------------------------------------------------------------------------
    ACK sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp SIP/2.0
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    Via: SIP/2.0/UDP 83.211.227.21;branch=0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6C8B3B5
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    Max-Forwards:  9
    CSeq: 101 ACK
    Content-Length: 0
    P-hint: rr-enforced

    ------------------------------------------------------------------------
2009-07-30 11:23:03.622342 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [ready][200]
2009-07-30 11:23:05.534318 [DEBUG] switch_ivr_play_say.c:1391 done
playing file
EXECUTE sofia/external/nobody at 83.211.2.218 rxfax(/tmp/rxfax.tiff)
2009-07-30 11:23:05.534318 [DEBUG] mod_fax.c:591 Raw read codec
activation Success L16 20000
2009-07-30 11:23:05.534318 [DEBUG] mod_fax.c:607 Raw write codec
activation Success L16
2009-07-30 11:23:05.534318 [DEBUG] switch_channel.c:182
sofia/external/nobody at 83.211.2.218 receive message [AUDIO_SYNC]
2009-07-30 11:23:05.574318 [DEBUG] switch_core_io.c:232
sofia/external/nobody at 83.211.2.218 receive message [TRANSCODING_NECESSARY]
recv 1065 bytes from udp/[83.211.227.21]:5060 at 09:23:17.425349:
    ------------------------------------------------------------------------
    INVITE sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp SIP/2.0
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bKf2d3.3af41733.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6CB02556
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    User-Agent: Cisco-SIPGateway/IOS-12.x
    CSeq: 102 INVITE
    Max-Forwards:  9
    Contact: <sip:83.211.2.218:5060>
    Expires: 180
    Allow-Events: telephone-event
    Content-Type: application/sdp
    Content-Length: 396
    P-hint: rr-enforced

    v=0
    o=CiscoSystemsSIP-GW-UserAgent 6035 7636 IN IP4 83.211.2.218
    s=SIP Call
    c=IN IP4 83.211.2.219
    t=0 0
    m=image 16962 udptl t38
    c=IN IP4 83.211.2.219
    a=T38FaxVersion:0
    a=T38MaxBitRate:14400
    a=T38FaxFillBitRemoval:0
    a=T38FaxTranscodingMMR:0
    a=T38FaxTranscodingJBIG:0
    a=T38FaxRateManagement:transferredTCF
    a=T38FaxMaxBuffer:200
    a=T38FaxMaxDatagram:72
    a=T38FaxUdpEC:t38UDPRedundancy
    ------------------------------------------------------------------------
send 487 bytes to udp/[83.211.227.21]:5060 at 09:23:17.425685:
    ------------------------------------------------------------------------
    SIP/2.0 100 Trying
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bKf2d3.3af41733.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6CB02556
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    CSeq: 102 INVITE
    User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14423
    Content-Length: 0

    ------------------------------------------------------------------------
2009-07-30 11:23:17.502330 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [received][100]
2009-07-30 11:23:17.502330 [DEBUG] sofia.c:3296 Remote SDP:
v=0
o=CiscoSystemsSIP-GW-UserAgent 6035 7636 IN IP4 83.211.2.218
s=SIP Call
c=IN IP4 83.211.2.219
t=0 0
m=image 16962 udptl t38
c=IN IP4 83.211.2.219
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:72
a=T38FaxUdpEC:t38UDPRedundancy

2009-07-30 11:23:17.502330 [DEBUG] sofia_glue.c:2811 Activate Buggy
RFC2833 Mode!
2009-07-30 11:23:17.502330 [ERR] sofia.c:3657 Reinvite Codec Error!
send 622 bytes to udp/[83.211.227.21]:5060 at 09:23:17.425932:
    ------------------------------------------------------------------------
    SIP/2.0 488 Not Acceptable Here
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bKf2d3.3af41733.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6CB02556
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    CSeq: 102 INVITE
    User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14423
    Accept: application/sdp
    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO
    Supported: timer, precondition, path, replaces
    Content-Length: 0

    ------------------------------------------------------------------------
2009-07-30 11:23:17.502330 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [ready][488]
recv 418 bytes from udp/[83.211.227.21]:5060 at 09:23:17.483358:
    ------------------------------------------------------------------------
    ACK sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp SIP/2.0
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bKf2d3.3af41733.0
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    CSeq: 102 ACK
    Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    User-Agent: SPS EUT RM GW 01 (0.9.6 (i386/linux))
    Content-Length: 0

    ------------------------------------------------------------------------
recv 851 bytes from udp/[83.211.227.21]:5060 at 09:23:17.521157:
    ------------------------------------------------------------------------
    INVITE sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp SIP/2.0
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bK03d3.99198e36.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6CB16EB
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    User-Agent: Cisco-SIPGateway/IOS-12.x
    CSeq: 103 INVITE
    Max-Forwards:  9
    Contact: <sip:83.211.2.218:5060>
    Expires: 180
    Allow-Events: telephone-event
    Content-Type: application/sdp
    Content-Length: 183
    P-hint: rr-enforced

    v=0
    o=CiscoSystemsSIP-GW-UserAgent 6035 7637 IN IP4 83.211.2.218
    s=SIP Call
    c=IN IP4 83.211.2.219
    t=0 0
    m=audio 16962 RTP/AVP 8
    a=rtpmap:8 PCMA/8000
    a=silenceSupp:off - - - -
    ------------------------------------------------------------------------
send 486 bytes to udp/[83.211.227.21]:5060 at 09:23:17.521462:
    ------------------------------------------------------------------------
    SIP/2.0 100 Trying
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bK03d3.99198e36.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6CB16EB
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    CSeq: 103 INVITE
    User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14423
    Content-Length: 0

    ------------------------------------------------------------------------
2009-07-30 11:23:17.598335 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [received][100]
2009-07-30 11:23:17.598335 [DEBUG] sofia.c:3296 Remote SDP:
v=0
o=CiscoSystemsSIP-GW-UserAgent 6035 7637 IN IP4 83.211.2.218
s=SIP Call
c=IN IP4 83.211.2.219
t=0 0
m=audio 16962 RTP/AVP 8
a=rtpmap:8 PCMA/8000
a=silenceSupp:off - - - -

2009-07-30 11:23:17.598335 [DEBUG] sofia_glue.c:2811 Activate Buggy
RFC2833 Mode!
2009-07-30 11:23:17.598335 [DEBUG] sofia_glue.c:2253 Audio params are
unchanged for sofia/external/nobody at 83.211.2.218.
2009-07-30 11:23:17.598335 [DEBUG] sofia.c:3655 Processing Reinvite
send 1029 bytes to udp/[83.211.227.21]:5060 at 09:23:17.521790:
    ------------------------------------------------------------------------
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bK03d3.99198e36.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6CB16EB
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    CSeq: 103 INVITE
    Contact: <sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp>
    User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14423
    Accept: application/sdp
    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO
    Supported: timer, precondition, path, replaces
    Content-Type: application/sdp
    Content-Disposition: session
    Content-Length: 245

    v=0
    o=FreeSWITCH 1248922369 1248922370 IN IP4 MYSERVERIP
    s=FreeSWITCH
    c=IN IP4 MYSERVERIP
    t=0 0
    m=audio 23414 RTP/AVP 8 101
    a=rtpmap:8 PCMA/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16
    a=silenceSupp:off - - - -
    a=ptime:20
    ------------------------------------------------------------------------
2009-07-30 11:23:17.598335 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [completed][200]
recv 491 bytes from udp/[83.211.227.21]:5060 at 09:23:17.587996:
    ------------------------------------------------------------------------
    ACK sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp SIP/2.0
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    Via: SIP/2.0/UDP 83.211.227.21;branch=0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6CB21B82
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    Max-Forwards:  9
    CSeq: 103 ACK
    Content-Length: 0
    P-hint: rr-enforced

    ------------------------------------------------------------------------
2009-07-30 11:23:17.666336 [DEBUG] sofia.c:3289 Channel
sofia/external/nobody at 83.211.2.218 entering state [ready][200]
recv 575 bytes from udp/[83.211.227.21]:5060 at 09:24:12.888160:
    ------------------------------------------------------------------------
    BYE sip:MYPHONENUMBER at MYSERVERIP:5080;transport=udp SIP/2.0
    Record-Route: <sip:83.211.227.21;ftag=B4CC80D8-658;lr=on>
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bKd2d3.e46ab944.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6D231283
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    User-Agent: Cisco-SIPGateway/IOS-12.x
    Max-Forwards:  9
    CSeq: 104 BYE
    Reason: Q.850;cause=16
    Content-Length: 0
    P-hint: rr-enforced

    ------------------------------------------------------------------------
2009-07-30 11:24:12.966321 [NOTICE] sofia.c:322 Hangup
sofia/external/nobody at 83.211.2.218 [CS_EXECUTE] [NORMAL_CLEARING]
2009-07-30 11:24:12.966321 [DEBUG] switch_channel.c:1683 Send signal
sofia/external/nobody at 83.211.2.218 [KILL]
2009-07-30 11:24:12.966321 [DEBUG] switch_core_session.c:932 Send signal
sofia/external/nobody at 83.211.2.218 [BREAK]
send 577 bytes to udp/[83.211.227.21]:5060 at 09:24:12.888613:
    ------------------------------------------------------------------------
    SIP/2.0 200 OK
    Via: SIP/2.0/UDP 83.211.227.21;branch=z9hG4bKd2d3.e46ab944.0
    Via: SIP/2.0/UDP
83.211.2.218:5060;rport=56225;x-route-tag="tgrp:Slot6";branch=z9hG4bK1D6D231283
    From: <sip:83.211.2.218>;tag=B4CC80D8-658
    To: <sip:MYPHONENUMBER at voip.eutelia.it>;tag=Q62jtZFSj1vXD
    Call-ID: 6AB06A2F-7C2111DE-AC2B92F2-3F8F6970 at 83.211.2.218
    CSeq: 104 BYE
    User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14423
    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO
    Supported: timer, precondition, path, replaces
    Content-Length: 0

    ------------------------------------------------------------------------
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:167
==============================================================================
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:180 Fax processing not
successful - result (49) The call dropped prematurely.
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:185 Remote station id: 12345
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:186 Local station id:
SpanDSP Fax Ident
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:187 Pages transferred: 0
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:189 Total fax pages:   0
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:190 Image resolution:
8031x3850
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:191 Transfer Rate:     4800
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:193 ECM status         on
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:194 remote country:
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:195 remote vendor:
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:196 remote model:
2009-07-30 11:24:12.974320 [DEBUG] mod_fax.c:198
==============================================================================
2009-07-30 11:24:12.974320 [DEBUG] switch_core_codec.c:122 Restore
original codec.
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:491
(sofia/external/nobody at 83.211.2.218) State EXECUTE going to sleep
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:398
(sofia/external/nobody at 83.211.2.218) Running State Change CS_HANGUP
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:434
(sofia/external/nobody at 83.211.2.218) State HANGUP
2009-07-30 11:24:12.974320 [DEBUG] mod_sofia.c:338 Channel
sofia/external/nobody at 83.211.2.218 hanging up, cause: NORMAL_CLEARING
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:46
sofia/external/nobody at 83.211.2.218 Standard HANGUP, cause: NORMAL_CLEARING
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:434
(sofia/external/nobody at 83.211.2.218) State HANGUP going to sleep
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:476
(sofia/external/nobody at 83.211.2.218) State Change CS_HANGUP -> CS_REPORTING
2009-07-30 11:24:12.974320 [DEBUG] switch_core_session.c:932 Send signal
sofia/external/nobody at 83.211.2.218 [BREAK]
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:398
(sofia/external/nobody at 83.211.2.218) Running State Change CS_REPORTING
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:612
(sofia/external/nobody at 83.211.2.218) State REPORTING
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:53
sofia/external/nobody at 83.211.2.218 Standard REPORTING, cause:
NORMAL_CLEARING
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:612
(sofia/external/nobody at 83.211.2.218) State REPORTING going to sleep
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:411
(sofia/external/nobody at 83.211.2.218) State Change CS_REPORTING -> CS_DESTROY
2009-07-30 11:24:12.974320 [DEBUG] switch_core_session.c:1066 Session 3
(sofia/external/nobody at 83.211.2.218) Locked, Waiting on external entities
2009-07-30 11:24:12.974320 [NOTICE] switch_core_session.c:1084 Session 3
(sofia/external/nobody at 83.211.2.218) Ended
2009-07-30 11:24:12.974320 [NOTICE] switch_core_session.c:1086 Close
Channel sofia/external/nobody at 83.211.2.218 [CS_DESTROY]
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:564
(sofia/external/nobody at 83.211.2.218) State DESTROY
2009-07-30 11:24:12.974320 [DEBUG] mod_sofia.c:255
sofia/external/nobody at 83.211.2.218 SOFIA DESTROY
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:60
sofia/external/nobody at 83.211.2.218 Standard DESTROY
2009-07-30 11:24:12.974320 [DEBUG] switch_core_state_machine.c:564
(sofia/external/nobody at 83.211.2.218) State DESTROY going to sleep


Any idea?
Thank you.
Stefano

More information about the FreeSWITCH-users mailing list