freeswitch txfax

It worked when under the private network.

but when it fax via the PSTN, everytime fax machine answer the call, 

FreeSwitch immediately crash without any message or warning, I cant find the problem.

FreeSwitch : 192.168.1.24

Voip Gateway (Wellgate 2644) : 192.168.1.200

Traditional Fax Machine ( Panasonic KX-F126 )

here is the command:

originate sofia/gateway/voipgw/12345678 &txfax(test.tif)

under private network it worked:

  FREESWITCH-----ip network-----VOIP GATEWAY--fxs----FAX MACHINE

But when it via the PSTN, it will crash:

  FREESWITCH-----ip network-----VOIP GATEWAY--fxo----PSTN----FAX MACHINE (tel number: 12345678)

the log file:

2010-07-28 18:38:56.734375 [DEBUG] sofia.c:5999 IP 192.168.1.24 Rejected by acl "domains". Falling back to Digest auth.

2010-07-28 18:38:56.843750 [DEBUG] sofia.c:5999 IP 192.168.1.24 Rejected by acl "domains". Falling back to Digest auth.

2010-07-28 18:38:56.921875 [NOTICE] switch_channel.c:776 New Channel sofia/internal/[hidden email] [bbb8b3fd-73bd-461c-9558-23242c58bce7]

2010-07-28 18:38:56.921875 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/[hidden email]) Running State Change CS_NEW

2010-07-28 18:38:56.921875 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/[hidden email]) State NEW

2010-07-28 18:38:57.031250 [DEBUG] sofia.c:4317 Channel sofia/internal/[hidden email] entering state [received][100]

2010-07-28 18:38:57.031250 [DEBUG] sofia.c:4328 Remote SDP:

v=0

o=- 6 2 IN IP4 192.168.1.24

s=CounterPath X-Lite 3.0

c=IN IP4 192.168.1.24

t=0 0

m=audio 23260 RTP/AVP 107 0 8 101

a=rtpmap:107 BV32/16000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=alt:1 2 : vyr71tjd uA0nYpAb 192.168.1.24 23260

a=alt:2 1 : MiwEZ8b+ c79RnVwq 192.168.56.1 23260

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [BV32:107:16000:20]/[G7221:115:32000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [BV32:107:16000:20]/[G7221:107:16000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [BV32:107:16000:20]/[G722:9:8000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [BV32:107:16000:20]/[PCMU:0:8000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [BV32:107:16000:20]/[PCMA:8:8000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [BV32:107:16000:20]/[GSM:3:8000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMU:0:8000:20]/[G7221:115:32000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMU:0:8000:20]/[G7221:107:16000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMU:0:8000:20]/[G722:9:8000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:2442 Set Codec sofia/internal/[hidden email] PCMU/8000 20 ms 160 samples

2010-07-28 18:38:57.031250 [DEBUG] sofia_glue.c:3941 Set 2833 dtmf send/recv payload to 101

2010-07-28 18:38:57.031250 [DEBUG] sofia.c:4475 (sofia/internal/[hidden email]) State Change CS_NEW -> CS_INIT

2010-07-28 18:38:57.031250 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/[hidden email] [BREAK]

2010-07-28 18:38:57.031250 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/[hidden email]) Running State Change CS_INIT

2010-07-28 18:38:57.031250 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/[hidden email]) State INIT

2010-07-28 18:38:57.031250 [DEBUG] mod_sofia.c:83 sofia/internal/[hidden email] SOFIA INIT

2010-07-28 18:38:57.031250 [DEBUG] mod_sofia.c:119 (sofia/internal/[hidden email]) State Change CS_INIT -> CS_ROUTING

2010-07-28 18:38:57.031250 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/[hidden email] [BREAK]

2010-07-28 18:38:57.031250 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/[hidden email]) State INIT going to sleep

2010-07-28 18:38:57.031250 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/[hidden email]) Running State Change CS_ROUTING

2010-07-28 18:38:57.031250 [DEBUG] switch_channel.c:1471 (sofia/internal/[hidden email]) Callstate Change DOWN -> RINGING

2010-07-28 18:38:57.031250 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/[hidden email]) State ROUTING

2010-07-28 18:38:57.031250 [DEBUG] mod_sofia.c:142 sofia/internal/[hidden email] SOFIA ROUTING

2010-07-28 18:38:57.031250 [DEBUG] switch_core_state_machine.c:77 sofia/internal/[hidden email] Standard ROUTING

2010-07-28 18:38:57.031250 [INFO] mod_dialplan_xml.c:331 Processing 1->0014 in context default

Dialplan: sofia/internal/[hidden email] parsing [default->test_txfax_stream] continue=false

Dialplan: sofia/internal/[hidden email] Regex (PASS) [test_txfax_stream] destination_number(0014) =~ /^0014$/ break=on-false

Dialplan: sofia/internal/[hidden email] Action log(ALERT ${api_result}) 

Dialplan: sofia/internal/[hidden email] Action lua(test.lua) 

Dialplan: sofia/internal/[hidden email] Action sleep(30000) 

2010-07-28 18:38:57.046875 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/[hidden email]) State Change CS_ROUTING -> CS_EXECUTE

2010-07-28 18:38:57.046875 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/[hidden email] [BREAK]

2010-07-28 18:38:57.046875 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/[hidden email]) State ROUTING going to sleep

2010-07-28 18:38:57.046875 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/[hidden email]) Running State Change CS_EXECUTE

2010-07-28 18:38:57.046875 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/[hidden email]) State EXECUTE

2010-07-28 18:38:57.046875 [DEBUG] mod_sofia.c:235 sofia/internal/[hidden email] SOFIA EXECUTE

2010-07-28 18:38:57.046875 [DEBUG] switch_core_state_machine.c:157 sofia/internal/[hidden email] Standard EXECUTE

EXECUTE sofia/internal/[hidden email] log(ALERT )

2010-07-28 18:38:57.046875 [ALERT] mod_dptools.c:984 

EXECUTE sofia/internal/[hidden email] lua(test.lua)

2010-07-28 18:38:57.093750 [NOTICE] switch_channel.c:776 New Channel sofia/external/23649136 [69e9d03f-535b-483c-893a-a3bfebe427ad]

2010-07-28 18:38:57.093750 [DEBUG] mod_sofia.c:3892 (sofia/external/23649136) State Change CS_NEW -> CS_INIT

2010-07-28 18:38:57.093750 [DEBUG] switch_core_session.c:1027 Send signal sofia/external/23649136 [BREAK]

2010-07-28 18:38:57.093750 [DEBUG] switch_core_state_machine.c:314 (sofia/external/23649136) Running State Change CS_INIT

2010-07-28 18:38:57.093750 [DEBUG] switch_core_state_machine.c:338 (sofia/external/23649136) State INIT

2010-07-28 18:38:57.093750 [DEBUG] mod_sofia.c:83 sofia/external/23649136 SOFIA INIT

2010-07-28 18:38:57.093750 [DEBUG] mod_sofia.c:119 (sofia/external/23649136) State Change CS_INIT -> CS_ROUTING

2010-07-28 18:38:57.093750 [DEBUG] switch_core_session.c:1027 Send signal sofia/external/23649136 [BREAK]

2010-07-28 18:38:57.093750 [DEBUG] switch_core_state_machine.c:338 (sofia/external/23649136) State INIT going to sleep

2010-07-28 18:38:57.093750 [DEBUG] switch_core_state_machine.c:314 (sofia/external/23649136) Running State Change CS_ROUTING

2010-07-28 18:38:57.093750 [DEBUG] switch_channel.c:1471 (sofia/external/23649136) Callstate Change DOWN -> RINGING

2010-07-28 18:38:57.093750 [DEBUG] sofia.c:4317 Channel sofia/external/23649136 entering state [calling][0]

2010-07-28 18:38:57.093750 [DEBUG] switch_core_state_machine.c:341 (sofia/external/23649136) State ROUTING

2010-07-28 18:38:57.093750 [DEBUG] mod_sofia.c:142 sofia/external/23649136 SOFIA ROUTING

2010-07-28 18:38:57.109375 [DEBUG] switch_ivr_originate.c:64 (sofia/external/23649136) State Change CS_ROUTING -> CS_CONSUME_MEDIA

2010-07-28 18:38:57.109375 [DEBUG] switch_core_session.c:1027 Send signal sofia/external/23649136 [BREAK]

2010-07-28 18:38:57.109375 [DEBUG] switch_core_state_machine.c:341 (sofia/external/23649136) State ROUTING going to sleep

2010-07-28 18:38:57.109375 [DEBUG] switch_core_state_machine.c:314 (sofia/external/23649136) Running State Change CS_CONSUME_MEDIA

2010-07-28 18:38:57.109375 [DEBUG] switch_core_state_machine.c:360 (sofia/external/23649136) State CONSUME_MEDIA

2010-07-28 18:38:57.109375 [DEBUG] switch_core_state_machine.c:360 (sofia/external/23649136) State CONSUME_MEDIA going to sleep

2010-07-28 18:38:59.093750 [INFO] sofia.c:662 sofia/external/23649136 Update Callee ID to "23649136" <23649136>

2010-07-28 18:38:59.093750 [DEBUG] sofia.c:4317 Channel sofia/external/23649136 entering state [proceeding][183]

2010-07-28 18:38:59.093750 [DEBUG] sofia.c:4328 Remote SDP:

v=0

o=2dsp_4fxs_4fxo_108 16384 0 IN IP4 192.168.1.200

s=SIP CALL

i=Audio Session

c=IN IP4 192.168.1.200

t=0 0

m=audio 16384 RTP/AVP 0 101

a=rtpmap:0 PCMU/8000/1

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

2010-07-28 18:38:59.093750 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]

2010-07-28 18:38:59.093750 [DEBUG] sofia_glue.c:2442 Set Codec sofia/external/23649136 PCMU/8000 20 ms 160 samples

2010-07-28 18:38:59.093750 [DEBUG] sofia_glue.c:3935 Set 2833 dtmf send payload to 101

2010-07-28 18:38:59.093750 [DEBUG] sofia_glue.c:2682 AUDIO RTP [sofia/external/23649136] 192.168.1.24 port 23668 -> 192.168.1.200 port 16384 codec: 0 ms: 20

2010-07-28 18:38:59.093750 [DEBUG] switch_rtp.c:1413 Starting timer [soft] 160 bytes per 20ms

2010-07-28 18:38:59.093750 [DEBUG] sofia_glue.c:2892 Set 2833 dtmf send payload to 101

2010-07-28 18:38:59.093750 [DEBUG] sofia_glue.c:2897 Set 2833 dtmf receive payload to 101

2010-07-28 18:38:59.093750 [NOTICE] sofia_glue.c:3290 Pre-Answer sofia/external/23649136!

2010-07-28 18:38:59.093750 [DEBUG] switch_channel.c:2349 (sofia/external/23649136) Callstate Change RINGING -> EARLY

2010-07-28 18:38:59.093750 [DEBUG] switch_ivr_originate.c:3328 Originate Resulted in Success: [sofia/external/23649136]

2010-07-28 18:38:59.093750 [DEBUG] mod_commands.c:2936 (sofia/external/23649136) State Change CS_CONSUME_MEDIA -> CS_EXECUTE

2010-07-28 18:38:59.093750 [DEBUG] switch_core_session.c:1027 Send signal sofia/external/23649136 [BREAK]

2010-07-28 18:38:59.093750 [DEBUG] switch_core_state_machine.c:314 (sofia/external/23649136) Running State Change CS_EXECUTE

2010-07-28 18:38:59.093750 [DEBUG] switch_core_state_machine.c:348 (sofia/external/23649136) State EXECUTE

2010-07-28 18:38:59.093750 [DEBUG] mod_sofia.c:235 sofia/external/23649136 SOFIA EXECUTE

2010-07-28 18:38:59.093750 [DEBUG] switch_core_state_machine.c:157 sofia/external/23649136 Standard EXECUTE

EXECUTE sofia/external/23649136 txfax(zzz.tif)

2010-07-28 18:38:59.109375 [DEBUG] switch_cpp.cpp:968 sofia/internal/[hidden email] destroy/unlink session from object

EXECUTE sofia/internal/[hidden email] sleep(30000)

2010-07-28 18:38:59.125000 [DEBUG] mod_spandsp_fax.c:1051 Raw read codec activation Success L16 20000

2010-07-28 18:38:59.125000 [DEBUG] switch_core_codec.c:116 sofia/external/23649136 Push codec L16:10

2010-07-28 18:38:59.125000 [DEBUG] mod_spandsp_fax.c:1067 Raw write codec activation Success L16

2010-07-28 18:38:59.156250 [DEBUG] switch_rtp.c:2517 Correct ip/port confirmed.

2010-07-28 18:38:59.390625 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.468750 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.468750 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.500000 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.500000 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.515625 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.531250 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.562500 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.562500 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.578125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.578125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.593750 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.593750 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.609375 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.640625 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.656250 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:38:59.656250 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:38:59.656250 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:39:00.078125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:39:01.078125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:39:02.953125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:39:02.953125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:39:03.093750 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:39:04.078125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:39:06.453125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier up (-2) in state 18

2010-07-28 18:39:06.453125 [DEBUG] mod_spandsp_fax.c:271 FLOW T.30 HDLC signal status is Carrier down (-1) in state 18

2010-07-28 18:39:07.062500 [DEBUG] sofia.c:4317 Channel sofia/external/23649136 entering state [completing][200]

2010-07-28 18:39:07.062500 [DEBUG] sofia.c:4325 Duplicate SDP

v=0

o=2dsp_4fxs_4fxo_108 16384 0 IN IP4 192.168.1.200

s=SIP CALL

i=Audio Session

c=IN IP4 192.168.1.200

t=0 0

m=audio 16384 RTP/AVP 0 101

a=rtpmap:0 PCMU/8000/1

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

2010-07-28 18:39:07.062500 [DEBUG] sofia.c:4317 Channel sofia/external/23649136 entering state [ready][200]

2010-07-28 18:39:07.062500 [DEBUG] switch_channel.c:2494 (sofia/external/23649136) Callstate Change EARLY -> ACTIVE

2010-07-28 18:39:07.062500 [NOTICE] sofia.c:4826 Channel [sofia/external/23649136] has been answered

-- 
Best regards,
Ted