[Freeswitch-users] unable to send fax using txfax on LAN

[arun sethi]

I am trying to send fax to a local fax machine (Canon MX 512) on my LAN
using freeswitch. The machine is connected via linksys pap2 (ATA) on LAN to
freeswitch.

the command I am using on freeswitch console is:
/usr/local/freeswitch/bin/fs_cli -x  "originate
{fax_verbose=true,ignore_early_media=true,absolute_codec_string='PCMU'}user/1006
&txfax(/tmp/txfax.tiff)"

The machine in question is Canon Mx 512 in fax only mode. Note that I am
able to send out fax from this machine and receive it in freeswitch using
rxfax. The problem is only in sending fax to this machine using txfax.

The complete error log is at paste http://pastebin.freeswitch.org/21151
Here are some relevant snippets from error log

2013-07-04 21:23:09.215751 [DEBUG] mod_sofia.c:243 sofia/internal/
sip:1006 at 10.2.2.159:8081 SOFIA EXECUTE
2013-07-04 21:23:09.215751 [DEBUG] switch_core_state_machine.c:209
sofia/internal/sip:1006 at 10.2.2.159:8081 Standard EXECUTE
EXECUTE sofia/internal/sip:1006 at 10.2.2.159:8081 txfax(/tmp/txfax.tiff)
2013-07-04 21:23:09.215751 [DEBUG] mod_spandsp_fax.c:1387 Raw read codec
activation Success L16 30000
2013-07-04 21:23:09.215751 [DEBUG] switch_core_codec.c:219 sofia/internal/
sip:1006 at 10.2.2.159:8081 Push codec L16:70
2013-07-04 21:23:09.215751 [DEBUG] mod_spandsp_fax.c:1403 Raw write codec
activation Success L16
2013-07-04 21:23:09.265748 [DEBUG] switch_rtp.c:3706 Correct ip/port
confirmed.
2013-07-04 21:23:09.265748 [DEBUG] switch_core_io.c:759 Engaging Read
Buffer at 480 bytes vs 160
2013-07-04 21:23:09.475748 [WARNING] mod_sofia.c:1279 Asynchronous PTIME
not supported, changing our end from 30 to 20
2013-07-04 21:23:09.475748 [DEBUG] sofia_glue.c:3037 Changing Codec from
PCMU at 30ms@8000hz to PCMU at 20ms@8000hz
2013-07-04 21:23:09.535748 [DEBUG] switch_rtp.c:1873 RE-Starting timer
[soft] 160 bytes per 20ms
2013-07-04 21:23:09.535748 [DEBUG] sofia_glue.c:3124 Set Codec
sofia/internal/sip:1006 at 10.2.2.159:8081 PCMU/8000 20 ms 160 samples 64000
bits
2013-07-04 21:23:09.555751 [DEBUG] switch_core_io.c:1365 Engaging Write
Buffer at 320 bytes to accommodate 480->320
2013-07-04 21:23:12.095748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Carrier up (-2) in state T
2013-07-04 21:23:15.095748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Carrier down (-1) in state T
2013-07-04 21:23:15.155748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Carrier up (-2) in state T
2013-07-04 21:23:15.195750 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.235749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.275748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.315750 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.355748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.395748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.635748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.715751 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.795749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:15.915751 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal s

**** repeats many times ****

2013-07-04 21:23:47.035750 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:48.115755 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Abort (-8) in state T
2013-07-04 21:23:48.135749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC
signal status is Carrier down (-1) in state T
2013-07-04 21:23:49.535749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 T0
expired in state T
2013-07-04 21:23:49.535749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Status
changing to 'Timed out waiting for initial communication'
2013-07-04 21:23:49.535749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30
Disconnecting
2013-07-04 21:23:49.535749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing
from phase A_CNG to E
2013-07-04 21:23:49.535749 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx
type 0
2013-07-04 21:23:49.535749 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx
type 1
2013-07-04 21:23:49.535749 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing
from state T to B
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send
complete in phase E, state B
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:511
==============================================================================
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:524 Fax processing not
successful - result (2) Timed out waiting for initial communication.
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:529 Remote station id:
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:530 Local station id:
 SpanDSP Fax Ident
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:531 Pages transferred:
0
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:533 Total fax pages:
0
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:534 Image resolution:
 0x0
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:535 Transfer Rate:
14400
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:537 ECM status
off
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:538 remote country:
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:539 remote vendor:
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:540 remote model:
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:542
==============================================================================
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing
from state B to CALL_FINISHED
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing
from phase E to CALL_FINISHED
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx
type 9
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX FAX
exchange complete
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx
type 9
2013-07-04 21:23:50.195748 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX FAX
exchange complete
2013-07-04 21:23:50.215748 [DEBUG] switch_core_codec.c:244 sofia/internal/
sip:1006 at 10.2.2.159:8081 Restore previous codec PCMU:0.
2013-07-04 21:23:50.215748 [NOTICE] switch_core_state_machine.c:262
sofia/internal/sip:1006 at 10.2.2.159:8081 has executed the last dialplan
instruction, hanging up.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130704/2899ee2e/attachment.html