Fax Problem

Discussion in 'General' started by marinblu, Sep 3, 2009.

  1. marinblu

    Joined:
    Oct 20, 2008
    Messages:
    3
    Likes Received:
    0
    I had installed elastix 1.4 (freepbx 2.4.1.2, asterisk 1.4.19) a year ago and now configured it for incoming fax (hardware Digium T205E). The problem is that when there is an incoming fax the handshake just rejected. But, if I call the fax line from a regular phone proceed and faxstat -s returns receiving! Any idea ?

    tail -f /var/log/messages
    --------------------------------------------------------------------------------
    STATE CHANGE: RUNNING -> LISTENING
    Sep 3 11:33:50 callserver FaxGetty[31008]: --> [9:DATE=0903]
    Sep 3 11:33:50 callserver FaxGetty[31008]: --> [9:TIME=1133]
    Sep 3 11:33:50 callserver FaxGetty[31008]: --> [5:NAME=]
    Sep 3 11:33:50 callserver FaxGetty[31008]: --> [15:NMBR=2104177846]
    Sep 3 11:33:50 callserver FaxGetty[31008]: --> [11:ANID=<NONE>]
    Sep 3 11:33:50 callserver FaxGetty[31008]: --> [6:NDID=s]
    Sep 3 11:33:50 callserver FaxGetty[31008]: --> [4]
    Sep 3 11:33:50 callserver FaxGetty[31008]: ANSWER: Call ID 1 "2104177846"
    Sep 3 11:33:50 callserver FaxGetty[31008]: ANSWER: Call ID 2 ""
    Sep 3 11:33:50 callserver FaxGetty[31008]: ANSWER: Call ID 3 "<NONE>"
    Sep 3 11:33:50 callserver FaxGetty[31008]: ANSWER: Call ID 4 "s"
    Sep 3 11:33:50 callserver FaxGetty[31008]: STATE CHANGE: LISTENING -> ANSWERING
    Sep 3 11:33:52 callserver FaxGetty[31008]: ANSWER: Ring detected without successful handshake
    Sep 3 11:33:52 callserver FaxGetty[31008]: <-- [5:ATH0\r]
    Sep 3 11:33:52 callserver FaxGetty[31008]: --> [2]
    Sep 3 11:33:52 callserver FaxGetty[31008]: MODEM set DTR OFF
    Sep 3 11:33:52 callserver FaxGetty[31008]: MODEM set baud rate: 0 baud (flow control unchanged)
    Sep 3 11:33:53 callserver FaxGetty[31008]: MODEM set DTR OFF
    Sep 3 11:33:53 callserver FaxGetty[31008]: MODEM set baud rate: 0 baud (flow control unchanged)
    Sep 3 11:33:53 callserver FaxGetty[31008]: DELAY 75 ms
    Sep 3 11:33:53 callserver FaxGetty[31008]: MODEM set DTR ON
    Sep 3 11:33:53 callserver FaxGetty[31008]: DELAY 2600 ms
    Sep 3 11:33:57 callserver FaxGetty[31008]: MODEM set baud rate: 19200 baud, input flow XON/XOFF, output flow XON/XOFF
    Sep 3 11:33:57 callserver FaxGetty[31008]: DELAY 10 ms
    Sep 3 11:33:57 callserver FaxGetty[31008]: MODEM flush i/o
    Sep 3 11:33:57 callserver FaxGetty[31008]: <-- [4:ATZ\r]
    Sep 3 11:33:57 callserver FaxGetty[31008]: --> [2]
    Sep 3 11:33:57 callserver FaxGetty[31008]: DELAY 3000 ms
    --------------------------------------------------------------------------------

    asterisk
    (410 is the freepbx extension: call waiting=disabled. zapata: faxdetect=incoming, inbound route: fax extension=410, fax detection=zaptel, pause after=7, set destination extension = 410)
    --------------------------------------------------------------------------------
    -- Accepting call from '2104177846' to '410' on channel 0/6, span 1
    -- Executing [410@from-pstn:1] Macro("Zap/6-1", "exten-vm|novm|410") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("Zap/6-1", "user-callerid") in new stack
    -- Executing [s@macro-user-callerid:1] NoOp("Zap/6-1", "user-callerid: 2104177846") in new stack
    -- Executing [s@macro-user-callerid:2] Set("Zap/6-1", "AMPUSER=2104177846") in new stack
    -- Executing [s@macro-user-callerid:3] GotoIf("Zap/6-1", "0?report") in new stack
    -- Executing [s@macro-user-callerid:4] ExecIf("Zap/6-1", "1|Set|REALCALLERIDNUM=2104177846") in new stack
    -- Executing [s@macro-user-callerid:5] NoOp("Zap/6-1", "REALCALLERIDNUM is 2104177846") in new stack
    -- Executing [s@macro-user-callerid:6] Set("Zap/6-1", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:7] Set("Zap/6-1", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:8] GotoIf("Zap/6-1", "1?report") in new stack
    -- Goto (macro-user-callerid,s,13)
    -- Executing [s@macro-user-callerid:13] NoOp("Zap/6-1", "TTL: ARG1: novm") in new stack
    -- Executing [s@macro-user-callerid:14] GotoIf("Zap/6-1", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:15] Set("Zap/6-1", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:16] GotoIf("Zap/6-1", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,23)
    -- Executing [s@macro-user-callerid:23] NoOp("Zap/6-1", "Using CallerID "" <2104177846>") in new stack
    -- Executing [s@macro-exten-vm:2] Set("Zap/6-1", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("Zap/6-1", "VMBOX=novm") in new stack
    -- Executing [s@macro-exten-vm:4] Set("Zap/6-1", "EXTTOCALL=410") in new stack
    -- Executing [s@macro-exten-vm:5] Set("Zap/6-1", "CFUEXT=") in new stack
    -- Executing [s@macro-exten-vm:6] Set("Zap/6-1", "CFBEXT=") in new stack
    -- Executing [s@macro-exten-vm:7] Set("Zap/6-1", "RT=""") in new stack
    -- Executing [s@macro-exten-vm:8] Macro("Zap/6-1", "record-enable|410|IN") in new stack
    -- Executing [s@macro-record-enable:1] GotoIf("Zap/6-1", "0?2:4") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing [s@macro-record-enable:4] AGI("Zap/6-1", "recordingcheck|20090903-113724|1251967044.1082") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
    recordingcheck|20090903-113724|1251967044.1082: Inbound recording not enabled
    -- AGI Script recordingcheck completed, returning 0
    -- Executing [s@macro-record-enable:5] NoOp("Zap/6-1", "No recording needed") in new stack
    -- Executing [s@macro-exten-vm:9] Macro("Zap/6-1", "dial||tr|410") in new stack
    -- Executing [s@macro-dial:1] GotoIf("Zap/6-1", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing [s@macro-dial:3] AGI("Zap/6-1", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
    dialparties.agi: Starting New Dialparties.agi
    == Parsing '/etc/asterisk/manager.conf': Found
    == Parsing '/etc/asterisk/manager_additional.conf': Found
    == Parsing '/etc/asterisk/manager_custom.conf': Found
    == Manager 'admin' logged on from 127.0.0.1
    dialparties.agi: Caller ID name is 'unknown' number is '2104177846'
    dialparties.agi: USE_CONFIRMATION: 'FALSE'
    dialparties.agi: RINGGROUP_INDEX: ''
    dialparties.agi: Methodology of ring is 'none'
    -- dialparties.agi: Added extension 410 to extension map
    -- dialparties.agi: Extension 410 cf is disabled
    -- dialparties.agi: Extension 410 do not disturb is disabled
    > dialparties.agi: extnum 410 has: cw: 0; hascfb: 0 [] hascfu: 0 []
    > dialparties.agi: ExtensionState: 0
    dialparties.agi: Extension 410 has ExtensionState: 0
    -- dialparties.agi: Checking CW and CFB status for extension 410
    -- dialparties.agi: dbset CALLTRACE/410 to 2104177846
    -- dialparties.agi: Filtered ARG3: 410
    == Manager 'admin' logged off from 127.0.0.1
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] Dial("Zap/6-1", "IAX2/410||tr") in new stack
    -- Called 410
    -- Call accepted by 127.0.0.1 (format alaw)
    -- Format for call is alaw
    -- IAX2/410-5 is ringing
    -- IAX2/410-5 answered Zap/6-1
    -- Redirecting Zap/6-1 to fax extension
    -- Hungup 'IAX2/410-5'
    == Spawn extension (from-pstn, fax, 0) exited non-zero on 'Zap/6-1' in macro 'dial'
    == Spawn extension (from-pstn, fax, 0) exited non-zero on 'Zap/6-1' in macro 'exten-vm'
    == Spawn extension (from-pstn, fax, 0) exited non-zero on 'Zap/6-1'
    -- Executing [fax@from-pstn:1] Goto("Zap/6-1", "ext-fax|in_fax|1") in new stack
    -- Goto (ext-fax,in_fax,1)
    -- Executing [in_fax@ext-fax:1] StopPlayTones("Zap/6-1", "") in new stack
    -- Executing [in_fax@ext-fax:2] GotoIf("Zap/6-1", "0?3:analog_fax|1") in new stack
    -- Goto (ext-fax,analog_fax,1)
    -- Executing [analog_fax@ext-fax:1] GotoIf("Zap/6-1", "1?4:2") in new stack
    -- Goto (ext-fax,analog_fax,4)
    -- Executing [analog_fax@ext-fax:4] Hangup("Zap/6-1", "") in new stack
    == Spawn extension (ext-fax, analog_fax, 4) exited non-zero on 'Zap/6-1'
    -- Executing [h@ext-fax:1] System("Zap/6-1", "/var/lib/asterisk/bin/fax-process.pl --to --from freepbx@gmail.com --subject "Fax from 2104177846 " --attachment fax_2104177846.pdf --type application/pdf --file ") in new stack
    -- Executing [h@ext-fax:2] Hangup("Zap/6-1", "") in new stack
    == Spawn extension (ext-fax, h, 2) exited non-zero on 'Zap/6-1'
    -- Hungup 'Zap/6-1'
    --------------------------------------------------------------------------------

    iaxmodem version 0.1.14 - /etc/iaxmodem/iaxmodem-cfg.ttyIAX1
    --------------------------------------------------------------------------------
    device /dev/ttyIAX1
    owner uucp:uucp
    mode 660
    port 4570
    refresh 300
    server 127.0.0.1
    peername 410
    secret 410
    cidname
    cidnumber
    codec slinear
    --------------------------------------------------------------------------------

    hylafax verison 4.3.3 - /var/spool/hylafax/etc/config.ttyIAX1
    --------------------------------------------------------------------------------
    CountryCode: 0030
    AreaCode: 210
    FAXNumber:
    LongDistancePrefix: 1
    InternationalPrefix: 011
    DialStringRules: etc/dialrules
    ServerTracing: 0xFFF
    SessionTracing: 0xFFF
    RecvFileMode: 0600
    LogFileMode: 0600
    DeviceMode: 0600
    RingsBeforeAnswer: 1
    SpeakerVolume: off
    GettyArgs: "-h %l dx_%s"
    LocalIdentifier: ""
    TagLineFont: etc/lutRS18.pcf
    TagLineFormat: "From %%l|%c|Page %%P of %%T"
    MaxRecvPages: 200
    #
    # Modem-related stuff: should reflect modem command interface
    # and hardware connection/cabling (e.g. flow control).
    #
    ModemType: Class1 # use this to supply a hint

    #
    # Enabling this will use the hfaxd-protocol to set Caller*ID
    #
    #ModemSetOriginCmd: AT+VSID="%s","%d"

    #
    # If "glare" during initialization becomes a problem then take
    # the modem off-hook during initialization, and then place it
    # back on-hook when done.
    #
    #ModemResetCmds: "ATH1\nAT+VCID=1" # enables CallID display
    #ModemReadyCmds: ATH0
    Class1AdaptRecvCmd: AT+FAR=1
    Class1TMConnectDelay: 400 # counteract quick CONNECT response

    Class1RMQueryCmd: "!24,48,72,96" # enable this to disable V.17

    #
    # You'll likely want Caller*ID display (also displays DID) enabled.
    #
    ModemResetCmds: AT+VCID=1 # enables CallID display

    #
    # If you are "missing" Caller*ID data on some calls (but not all)
    # and if you do not have adequate glare protection you may want to
    # not answer based on RINGs, but rather enable the CallIDAnswerLength
    # for NDID, disable AT+VCID=1 and do this:
    #
    #RingsBeforeAnswer: 0
    #ModemRingResponse: AT+VRID=1

    CallIDPattern: "NMBR="
    CallIDPattern: "NAME="
    CallIDPattern: "ANID="
    CallIDPattern: "NDID="
    #CallIDAnswerLength: 4
    # Uncomment these if you really want them, but you probably don't.
    #CallIDPattern: "DATE="
    #CallIDPattern: "TIME="
    --------------------------------------------------------------------------------
     
  2. ramoncio

    Joined:
    May 12, 2010
    Messages:
    1,663
    Likes Received:
    0
    Hi marinblu, wellcome to the Elastix community!

    Have a look at the hylafax logs into the /var/spool/hylafax/log directory. Maybe there you'll have some more info than in the /var/log/messages file.
    Fax detection seems to be working fine and the asterisk part too.
    Just a guess, maybe you need to use ulaw instead of alaw?
    I have also noticed there is a problem negotiating the baud rate, some times you get
    MODEM set baud rate: 0 baud (flow control unchanged), and some others 19200 baud rate.
    I think You'll need to somehow force a lower baud rate.
     
  3. marinblu

    Joined:
    Oct 20, 2008
    Messages:
    3
    Likes Received:
    0
    Hi,

    I changed the codec to ulaw but the same results.
    Also, I had a successful receiving with another fax machine (HP).

    /var/spool/hylafax/log for HP
    ---------------------------------------------------------------------------------------------
    Sep 04 12:18:01.25: [23823]: SESSION BEGIN 000000076
    Sep 04 12:18:01.25: [23823]: HylaFAX (tm) Version 4.3.3
    Sep 04 12:18:01.25: [23823]: CallID: "2111206650" "" "<NONE>" "s"
    Sep 04 12:18:01.25: [23823]: MODEM set XON/XOFF/FLUSH: input ignored, output disabled
    Sep 04 12:18:01.25: [23823]: <-- [4:ATA\r]
    Sep 04 12:18:04.97: [23823]: --> [7]
    Sep 04 12:18:04.97: [23823]: ANSWER: FAX CONNECTION DEVICE '/dev/ttyIAX1'
    Sep 04 12:18:04.97: [23823]: STATE CHANGE: ANSWERING -> RECEIVING
    Sep 04 12:18:04.97: [23823]: RECV FAX: begin
    Sep 04 12:18:04.97: [23823]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F676 04 2C 74 CC 74 CC>
    Sep 04 12:18:04.97: [23823]: <-- data [32]
    Sep 04 12:18:04.97: [23823]: <-- data [2]
    Sep 04 12:18:05.93: [23823]: --> [7]
    Sep 04 12:18:05.93: [23823]: <-- HDLC<23:FF C0 02 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04>
    Sep 04 12:18:05.93: [23823]: <-- data [23]
    Sep 04 12:18:05.93: [23823]: <-- data [2]
    Sep 04 12:18:06.67: [23823]: --> [7]
    Sep 04 12:18:06.67: [23823]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
    Sep 04 12:18:06.67: [23823]: <-- data [13]
    Sep 04 12:18:06.67: [23823]: <-- data [2]
    Sep 04 12:18:07.25: [23823]: --> [2]
    Sep 04 12:18:07.25: [23823]: <-- [9:AT+FRH=3\r]
    Sep 04 12:18:08.05: [23823]: --> [7]
    Sep 04 12:18:09.63: [23823]: --> HDLC<25:FF C0 C2 0C AC 6C 6C 0C 4C 8C 8C 8C 4C 04 04 04 04 04 04 04 04 04 04 23 D0>
    Sep 04 12:18:09.63: [23823]: --> [2]
    Sep 04 12:18:09.63: [23823]: REMOTE TSI "2111206650"
    Sep 04 12:18:09.63: [23823]: <-- [9:AT+FRH=3\r]
    Sep 04 12:18:10.07: [23823]: --> [7]
    Sep 04 12:18:10.07: [23823]: --> HDLC<15:FF C8 C1 00 62 1F 23 01 01 01 01 01 00 4A 76>
    Sep 04 12:18:10.21: [23823]: --> [2]
    Sep 04 12:18:10.21: [23823]: REMOTE wants 9600 bit/s
    Sep 04 12:18:10.21: [23823]: REMOTE wants A4 page width (215 mm)
    Sep 04 12:18:10.21: [23823]: REMOTE wants unlimited page length
    Sep 04 12:18:10.21: [23823]: REMOTE wants 7.7 line/mm
    Sep 04 12:18:10.21: [23823]: REMOTE wants 2-D MMR
    Sep 04 12:18:10.21: [23823]: REMOTE wants T.30 Annex A, 256-byte ECM
    Sep 04 12:18:10.21: [23823]: RECV training at v.29 9600 bit/s
    Sep 04 12:18:10.21: [23823]: MODEM set XON/XOFF/DRAIN: input ignored, output generated
    Sep 04 12:18:10.21: [23823]: <-- [10:AT+FRM=96\r]
    Sep 04 12:18:10.51: [23823]: --> [7]
    Sep 04 12:18:12.03: [23823]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
    Sep 04 12:18:12.03: [23823]: RECV: TCF 1813 bytes, 1% non-zero, 1784 zero-run
    Sep 04 12:18:12.03: [23823]: --> [10:NO CARRIER]
    Sep 04 12:18:12.03: [23823]: <-- [9:AT+FRS=7\r]
    Sep 04 12:18:12.09: [23823]: --> [2]
    Sep 04 12:18:12.09: [23823]: TRAINING succeeded
    Sep 04 12:18:12.09: [23823]: <-- [9:AT+FTH=3\r]
    Sep 04 12:18:12.11: [23823]: --> [7]
    Sep 04 12:18:12.11: [23823]: <-- HDLC<3:FF C8 21>
    Sep 04 12:18:12.11: [23823]: <-- data [3]
    Sep 04 12:18:12.11: [23823]: <-- data [2]
    Sep 04 12:18:13.19: [23823]: --> [2]
    Sep 04 12:18:13.19: [23823]: <-- [10:AT+FRM=96\r]
    Sep 04 12:18:14.17: [23823]: --> [7]
    Sep 04 12:18:14.17: [23823]: MODEM input buffering enabled
    Sep 04 12:18:14.17: [23823]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
    Sep 04 12:18:14.79: [23823]: RECV received frame number 0
    Sep 04 12:18:14.99: [23823]: RECV received frame number 1
    Sep 04 12:18:19.17: [23823]: RECV received frame number 2
    Sep 04 12:18:28.13: [23823]: RECV received frame number 3
    Sep 04 12:18:28.13: [23823]: RECV received RCP frame
    Sep 04 12:18:28.13: [23823]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
    Sep 04 12:18:28.13: [23823]: MODEM input buffering disabled
    Sep 04 12:18:28.15: [23823]: --> [10:NO CARRIER]
    Sep 04 12:18:28.15: [23823]: <-- [9:AT+FRH=3\r]
    Sep 04 12:18:28.35: [23823]: --> [7]
    Sep 04 12:18:29.51: [23823]: --> HDLC<9:FF C8 FD F4 00 00 C0 8A EE>
    Sep 04 12:18:29.65: [23823]: --> [2]
    Sep 04 12:18:29.65: [23823]: RECV recv PPS (partial page signal)
    Sep 04 12:18:29.65: [23823]: RECV recv EOP (no more pages or documents)
    Sep 04 12:18:29.65: [23823]: RECV received 4 frames of block 1 of page 1
    Sep 04 12:18:29.65: [23823]: RECV/CQ: Adjusting for EOFB at row 2304
    Sep 04 12:18:29.66: [23823]: RECV: 912 bytes of data, 2304 total lines
    Sep 04 12:18:29.66: [23823]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
    Sep 04 12:18:29.66: [23823]: <-- [9:AT+FRS=7\r]
    Sep 04 12:18:29.71: [23823]: --> [2]
    Sep 04 12:18:29.71: [23823]: <-- [9:AT+FTH=3\r]
    Sep 04 12:18:29.73: [23823]: --> [7]
    Sep 04 12:18:29.73: [23823]: <-- HDLC<3:FF C8 31>
    Sep 04 12:18:29.73: [23823]: <-- data [3]
    Sep 04 12:18:29.73: [23823]: <-- data [2]
    Sep 04 12:18:30.81: [23823]: --> [2]
    Sep 04 12:18:30.81: [23823]: RECV send MCF (message confirmation)
    Sep 04 12:18:30.81: [23823]: RECV FAX (000000076): from 2111206650, page 1 in 0:25, INF, 7.7 line/mm, 2-D MMR, 9600bit/s
    Sep 04 12:18:30.81: [23823]: RECV FAX (000000076): recvq/fax000000025.tif from 2111206650, route to <unspecified>, 1 pages in 0:26
    Sep 04 12:18:30.81: [23823]: <-- [9:AT+FRH=3\r]
    Sep 04 12:18:31.17: [23823]: --> [7]
    Sep 04 12:18:32.23: [23823]: --> HDLC<5:FF C8 DF 59 6F>
    Sep 04 12:18:32.39: [23823]: --> [2]
    Sep 04 12:18:32.39: [23823]: RECV recv DCN (disconnect)
    Sep 04 12:18:32.39: [23823]: MODEM input buffering enabled
    Sep 04 12:18:32.39: [23823]: RECV FAX: bin/faxrcvd "recvq/fax000000025.tif" "ttyIAX1" "000000076" "" "2111206650" "" "<NONE>" "s"
    Sep 04 12:18:32.39: [23823]: RECV FAX: end
    Sep 04 12:18:32.39: [23823]: SESSION END
    ---------------------------------------------------------------------------------------------

    With Samsung or Canon that the handshake always rejected
    ---------------------------------------------------------------------------------------------
    Sep 04 12:19:34.53: [23828]: SESSION BEGIN 000000077
    Sep 04 12:19:34.53: [23828]: HylaFAX (tm) Version 4.3.3
    Sep 04 12:19:34.53: [23828]: CallID: "2111206659" "" "<NONE>" "s"
    Sep 04 12:19:34.53: [23828]: MODEM set XON/XOFF/FLUSH: input ignored, output disabled
    Sep 04 12:19:34.53: [23828]: <-- [4:ATA\r]
    Sep 04 12:19:35.23: [23828]: --> [10:NO CARRIER]
    Sep 04 12:19:35.23: [23828]: ANSWER: Ring detected without successful handshake
    Sep 04 12:19:35.23: [23828]: SESSION END
    ---------------------------------------------------------------------------------------------

    How I can set the baud rate to be 9600 ?
    At /var/spool/hylafax/etc/config.ttyIAX1 there is the line
    Class1RMQueryCmd: "!24,48,72,96"

    What else I should check/change ?
     

Share This Page