Menu ▾ ▴

MODEM TIMEOUT: waiting for v.21 carrier

Help
cms
2006-06-23
2014-09-30

  • cms

    cms - 2006-06-23

    I am having a problem getting iaxmodem/hylafax to recv faxes.  I am faxing from a fax machine on a pots line to our * server which has a digium T1 card with hylafax/iaxmodem running on it

    Here is the log from hylafax

    Jun 23 15:04:51.39: [ 1919]: SESSION BEGIN 000000011 19169259049
    Jun 23 15:04:51.39: [ 1919]: HylaFAX (tm) Version 4.3.0
    Jun 23 15:04:51.39: [ 1919]: CallID: "4259741033" "<NONE>" "<NONE>" "4189337"
    Jun 23 15:04:51.39: [ 1919]: MODEM set XON/XOFF/FLUSH: input ignored, output dis
    abled
    Jun 23 15:04:51.39: [ 1919]: <-- [4:ATA\r]
    Jun 23 15:04:55.50: [ 1919]: --> [7:CONNECT]
    Jun 23 15:04:55.50: [ 1919]: ANSWER: FAX CONNECTION  DEVICE '/dev/ttyIAX'
    Jun 23 15:04:55.50: [ 1919]: STATE CHANGE: ANSWERING -> RECEIVING
    Jun 23 15:04:55.51: [ 1919]: RECV FAX: begin
    Jun 23 15:04:55.51: [ 1919]: <-- 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 F6 76 04 2C 74 CC 74 0C>
    Jun 23 15:04:55.51: [ 1919]: <-- data [32]
    Jun 23 15:04:55.51: [ 1919]: <-- data [2]
    Jun 23 15:04:56.58: [ 1919]: --> [7:CONNECT]
    Jun 23 15:04:56.58: [ 1919]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04
    04 04 04 04 04 04 04 04 04 04>
    Jun 23 15:04:56.58: [ 1919]: <-- data [23]
    Jun 23 15:04:56.58: [ 1919]: <-- data [2]
    Jun 23 15:04:57.42: [ 1919]: --> [7:CONNECT]
    Jun 23 15:04:57.42: [ 1919]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
    Jun 23 15:04:57.42: [ 1919]: <-- data [13]
    Jun 23 15:04:57.42: [ 1919]: <-- data [2]
    Jun 23 15:04:58.02: [ 1919]: --> [2:OK]
    Jun 23 15:04:58.02: [ 1919]: <-- [9:AT+FRH=3\r]
    Jun 23 15:05:05.02: [ 1919]: --> [0:]
    Jun 23 15:05:05.02: [ 1919]: MODEM <Empty line>
    Jun 23 15:05:05.02: [ 1919]: MODEM TIMEOUT: waiting for v.21 carrier
    Jun 23 15:05:05.02: [ 1919]: <-- data [1]
    Jun 23 15:05:05.02: [ 1919]: --> [2:OK]
    Jun 23 15:05:05.02: [ 1919]: DELAY 1500 ms
    Jun 23 15:05:06.52: [ 1919]: <-- [9:AT+FTH=3\r]
    Jun 23 15:05:06.52: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:06.52: [ 1919]: <-- 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 F6 76 04 2C 74 CC 74 0C>
    Jun 23 15:05:06.52: [ 1919]: <-- data [32]
    Jun 23 15:05:06.52: [ 1919]: <-- data [2]
    Jun 23 15:05:08.78: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:08.78: [ 1919]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04
    04 04 04 04 04 04 04 04 04 04>
    Jun 23 15:05:08.78: [ 1919]: <-- data [23]
    Jun 23 15:05:08.78: [ 1919]: <-- data [2]
    Jun 23 15:05:09.62: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:09.62: [ 1919]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
    Jun 23 15:05:09.62: [ 1919]: <-- data [13]
    Jun 23 15:05:09.62: [ 1919]: <-- data [2]
    Jun 23 15:05:10.22: [ 1919]: --> [2:OK]
    Jun 23 15:05:10.22: [ 1919]: <-- [9:AT+FRH=3\r]
    Jun 23 15:05:17.22: [ 1919]: --> [0:]
    Jun 23 15:05:17.22: [ 1919]: MODEM <Empty line>
    Jun 23 15:05:17.22: [ 1919]: MODEM TIMEOUT: waiting for v.21 carrier
    Jun 23 15:05:17.22: [ 1919]: <-- data [1]
    Jun 23 15:05:17.22: [ 1919]: --> [2:OK]
    Jun 23 15:05:17.22: [ 1919]: DELAY 1500 ms
    Jun 23 15:05:18.72: [ 1919]: <-- [9:AT+FTH=3\r]
    Jun 23 15:05:18.72: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:18.72: [ 1919]: <-- 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 F6 76 04 2C 74 CC 74 0C>
    Jun 23 15:05:18.72: [ 1919]: <-- data [32]
    Jun 23 15:05:18.72: [ 1919]: <-- data [2]
    Jun 23 15:05:20.99: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:20.99: [ 1919]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04
    04 04 04 04 04 04 04 04 04 04>
    Jun 23 15:05:20.99: [ 1919]: <-- data [23]
    Jun 23 15:05:20.99: [ 1919]: <-- data [2]
    Jun 23 15:05:21.83: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:21.83: [ 1919]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
    Jun 23 15:05:21.83: [ 1919]: <-- data [13]
    Jun 23 15:05:21.83: [ 1919]: <-- data [2]
    Jun 23 15:05:22.43: [ 1919]: --> [2:OK]
    Jun 23 15:05:22.43: [ 1919]: <-- [9:AT+FRH=3\r]
    Jun 23 15:05:29.43: [ 1919]: --> [0:]
    Jun 23 15:05:29.43: [ 1919]: MODEM <Empty line>
    Jun 23 15:05:29.43: [ 1919]: MODEM TIMEOUT: waiting for v.21 carrier
    Jun 23 15:05:29.43: [ 1919]: <-- data [1]
    Jun 23 15:05:29.43: [ 1919]: --> [2:OK]
    Jun 23 15:05:29.43: [ 1919]: DELAY 1500 ms
    Jun 23 15:05:30.93: [ 1919]: <-- [9:AT+FTH=3\r]
    Jun 23 15:05:30.93: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:30.93: [ 1919]: <-- 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 F6 76 04 2C 74 CC 74 0C>
    Jun 23 15:05:30.93: [ 1919]: <-- data [32]
    Jun 23 15:05:30.94: [ 1919]: <-- data [2]
    Jun 23 15:05:33.19: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:33.19: [ 1919]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04
    04 04 04 04 04 04 04 04 04 04>
    Jun 23 15:05:33.19: [ 1919]: <-- data [23]
    Jun 23 15:05:33.19: [ 1919]: <-- data [2]
    Jun 23 15:05:34.03: [ 1919]: --> [7:CONNECT]
    Jun 23 15:05:34.03: [ 1919]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
    Jun 23 15:05:34.03: [ 1919]: <-- data [13]
    Jun 23 15:05:34.03: [ 1919]: <-- data [2]
    Jun 23 15:05:34.63: [ 1919]: --> [2:OK]
    Jun 23 15:05:34.63: [ 1919]: <-- [9:AT+FRH=3\r]
    Jun 23 15:05:37.87: [ 1919]: --> [10:NO CARRIER]
    Jun 23 15:05:37.87: [ 1919]: MODEM No carrier
    Jun 23 15:05:37.87: [ 1919]: RECV FAX: No answer (T.30 T1 timeout)
    Jun 23 15:05:37.87: [ 1919]: RECV FAX: end
    Jun 23 15:05:37.87: [ 1919]: SESSION END

    And the log from faxgetty

    Jun 23 15:04:51 pbx FaxGetty[1919]: STATE CHANGE: RUNNING -> LISTENING
    Jun 23 15:04:51 pbx FaxGetty[1919]: --> [9:DATE=0623]
    Jun 23 15:04:51 pbx FaxGetty[1919]: --> [9:TIME=1504]
    Jun 23 15:04:51 pbx FaxGetty[1919]: --> [11:NAME=<NONE>]
    Jun 23 15:04:51 pbx FaxGetty[1919]: --> [15:NMBR=4259741033]
    Jun 23 15:04:51 pbx FaxGetty[1919]: --> [11:ANID=<NONE>]
    Jun 23 15:04:51 pbx FaxGetty[1919]: --> [12:NDID=4189337]
    Jun 23 15:04:51 pbx FaxGetty[1919]: --> [4:RING]
    Jun 23 15:04:51 pbx FaxGetty[1919]: ANSWER: Call ID 1 "4259741033"
    Jun 23 15:04:51 pbx FaxGetty[1919]: ANSWER: Call ID 2 "<NONE>"
    Jun 23 15:04:51 pbx FaxGetty[1919]: ANSWER: Call ID 3 "<NONE>"
    Jun 23 15:04:51 pbx FaxGetty[1919]: ANSWER: Call ID 4 "4189337"
    Jun 23 15:04:51 pbx FaxGetty[1919]: STATE CHANGE: LISTENING -> ANSWERING
    Jun 23 15:04:55 pbx FaxGetty[1919]: ANSWER: FAX CONNECTION  DEVICE '/dev/ttyIAX'
    Jun 23 15:05:37 pbx FaxGetty[1919]: <-- [5:ATH0\r]
    Jun 23 15:05:37 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:37 pbx FaxGetty[1919]: MODEM set DTR OFF
    Jun 23 15:05:37 pbx FaxGetty[1919]: MODEM set baud rate: 0 baud (flow control unchanged)
    Jun 23 15:05:38 pbx FaxGetty[1919]: MODEM set DTR OFF
    Jun 23 15:05:38 pbx FaxGetty[1919]: MODEM set baud rate: 0 baud (flow control unchanged)
    Jun 23 15:05:38 pbx FaxGetty[1919]: DELAY 75 ms
    Jun 23 15:05:38 pbx FaxGetty[1919]: MODEM set DTR ON
    Jun 23 15:05:38 pbx FaxGetty[1919]: DELAY 2600 ms
    Jun 23 15:05:42 pbx FaxGetty[1919]: MODEM set baud rate: 19200 baud, input flow XON/XOFF, output flow XON/XOFF
    Jun 23 15:05:42 pbx FaxGetty[1919]: DELAY 10 ms
    Jun 23 15:05:42 pbx FaxGetty[1919]: MODEM flush i/o
    Jun 23 15:05:42 pbx FaxGetty[1919]: <-- [4:ATZ\r]
    Jun 23 15:05:42 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:42 pbx FaxGetty[1919]: DELAY 3000 ms
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM flush i/o
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATH1\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [4:ATH1]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [10:AT+VCID=1\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [9:AT+VCID=1]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [7:ATS0=0\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [6:ATS0=0]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATE0\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [4:ATE0]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATV1\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATQ0\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [7:ATS8=2\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [8:ATS7=60\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [12:AT+FCLASS=?\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [7:0,1,1.0]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports "Data"
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports "Class 1"
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports "Class 1.0"
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [12:AT+FCLASS=1\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATI3\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [19:www.soft-switch.org]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM: Mfr www.soft-switch.org
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATI0\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [7:spandsp]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM: Model spandsp
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [9:AT+FTM=?\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [39:24,48,72,73,74,96,97,98,121,122,145,146]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 3.85 line/mm
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 7.7 line/mm
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 15.4 line/mm
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports R16 x 15.4 line/mm
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 200 x 100 dpi
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 200 x 200 dpi
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 200 x 400 dpi
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 300 x 300 dpi
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 2400 bit/s
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 4800 bit/s
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 7200 bit/s
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 9600 bit/s
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 12000 bit/s
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 14400 bit/s
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports A4 page width (215 mm)
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports B4 page width (255 mm)
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports A3 page width (303 mm)
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports A4 page length (297 mm)
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports B4 page length (364 mm)
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports unlimited page length
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 1-D MH
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 2-D MR
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 2-D MMR
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports no ECM
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports T.30 Annex A, 64-byte ECM
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports T.30 Annex A, 256-byte ECM
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 0 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 5 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 10 ms, 5 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 10 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 20 ms, 10 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 20 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 40 ms, 20 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM Supports 40 ms/scanline
    Jun 23 15:05:45 pbx FaxGetty[1919]: MODEM WWW.SOFT-SWITCH.ORG spandsp/
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATM0\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [9:AT+FAR=1\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: <-- [5:ATH0\r]
    Jun 23 15:05:45 pbx FaxGetty[1919]: --> [2:OK]
    Jun 23 15:05:45 pbx FaxGetty[1919]: STATE CHANGE: RECEIVING -> RUNNING (timeout 30)

    and the iax debug

        -- Accepting call from '9169259049' to '4189337' on channel 0/1, span 1
        -- Executing Dial("Zap/1-1", "IAX2/iaxmodem/4189337") in new stack
        -- Called iaxmodem/4189337
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: NEW   
       Timestamp: 00015ms  SCall: 16385  DCall: 00000 [127.0.0.1:4570]
       VERSION         : 2
       CALLED NUMBER   : 4189337
       CODEC_PREFS     : (slin)
       CALLING NUMBER  : 9169259049
       CALLING PRESNTN : 3
       CALLING TYPEOFN : 33
       CALLING TRANSIT : 0
       LANGUAGE        : en
       USERNAME        : iaxmodem
       FORMAT          : 64
       CAPABILITY      : 63552
       ADSICPE         : 2
       DATE TIME       : 2006-06-23  15:21:24
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 00015ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass: ACCEPT
       Timestamp: 00004ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
       FORMAT          : 64
    pbx*CLI>
        -- Call accepted by 127.0.0.1 (format slin)
        -- Format for call is slin
    Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 00004ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: VOICE   Subclass: 64
       Timestamp: 00060ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: CONTROL Subclass: RINGING
       Timestamp: 00003ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 002 Type: IAX     Subclass: ACK   
       Timestamp: 00003ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
        -- IAX2/iaxmodem-16385 is ringing
    Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 001 Type: CONTROL Subclass: ANSWER
       Timestamp: 00006ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 003 Type: IAX     Subclass: ACK   
       Timestamp: 00006ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
        -- IAX2/iaxmodem-16385 answered Zap/1-1
    Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 001 Type: VOICE   Subclass: 64
       Timestamp: 00040ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 004 Type: IAX     Subclass: ACK   
       Timestamp: 00040ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX     Subclass: ACK   
       Timestamp: 00060ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 002 Type: IAX     Subclass: PING  
       Timestamp: 02004ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 005 Type: IAX     Subclass: PONG  
       Timestamp: 02004ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 003 Type: IAX     Subclass: ACK   
       Timestamp: 02004ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 250 Type: IAX     Subclass: PING  
       Timestamp: 4059919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 250 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4059922ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 250 ISeqno: 002 Type: IAX     Subclass: PONG  
       Timestamp: 4059919ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0
    pbx*CLI>
    Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 251 Type: IAX     Subclass: ACK   
       Timestamp: 4059919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 251 ISeqno: 003 Type: IAX     Subclass: LAGRP 
       Timestamp: 4059922ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 252 Type: IAX     Subclass: ACK   
       Timestamp: 4059922ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 252 ISeqno: 003 Type: IAX     Subclass: PING  
       Timestamp: 4059674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 253 Type: IAX     Subclass: PONG  
       Timestamp: 4059674ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 253 ISeqno: 003 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4059677ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 254 Type: IAX     Subclass: LAGRP 
       Timestamp: 4059677ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 253 ISeqno: 004 Type: IAX     Subclass: ACK   
       Timestamp: 4059674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 254 ISeqno: 005 Type: IAX     Subclass: ACK   
       Timestamp: 4059677ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass: LAGRQ 
       Timestamp: 10022ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX     Subclass: ACK   
       Timestamp: 10022ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX     Subclass: LAGRP 
       Timestamp: 10022ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 006 Type: IAX     Subclass: ACK   
       Timestamp: 10022ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 254 Type: VOICE   Subclass: 4
       Timestamp: 4063240ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 254 ISeqno: 006 Type: IAX     Subclass: ACK   
       Timestamp: 4063240ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 254 ISeqno: 006 Type: VOICE   Subclass: 4
       Timestamp: 4063251ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[-01] -- OSeqno: 006 ISeqno: 255 Type: IAX     Subclass: ACK   
       Timestamp: 4063251ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 004 Type: IAX     Subclass: PING  
       Timestamp: 12014ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 007 Type: IAX     Subclass: PONG  
       Timestamp: 12014ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 005 Type: IAX     Subclass: ACK   
       Timestamp: 12014ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: REGREQ
       Timestamp: 00003ms  SCall: 04238  DCall: 00000 [127.0.0.1:4570]
       USERNAME        : iaxmodem
       REFRESH         : 300
    pbx*CLI>
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass: REGAUTH
       Timestamp: 00006ms  SCall: 00001  DCall: 04238 [127.0.0.1:4570]
       AUTHMETHODS     : 1
       USERNAME        : iaxmodem
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: REGREQ
       Timestamp: 00019ms  SCall: 04238  DCall: 00001 [127.0.0.1:4570]
       USERNAME        : iaxmodem
       PASSWORD        : password
       REFRESH         : 300
    pbx*CLI>
    Jun 23 15:21:41 NOTICE[6470]: chan_iax2.c:5676 update_registry: Restricting registration for peer 'iaxmodem' to 60 seconds (requested 300)
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX     Subclass: REGACK
       Timestamp: 00028ms  SCall: 00001  DCall: 04238 [127.0.0.1:4570]
       USERNAME        : iaxmodem
       DATE TIME       : 2006-06-23  15:21:40
       REFRESH         : 60
       APPARENT ADDRES : IPV4 127.0.0.1:4570
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX     Subclass: ACK   
       Timestamp: 00028ms  SCall: 04238  DCall: 00001 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 255 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 255 ISeqno: 006 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[001] -- OSeqno: 006 ISeqno: 000 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 000 Type: IAX     Subclass: LAGRP 
       Timestamp: 4069674ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 007 Type: IAX     Subclass: LAGRP 
       Timestamp: 4069919ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[-01] -- OSeqno: 007 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 4069919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[Yes] -- OSeqno: 255 ISeqno: 007 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: VNAK  
       Timestamp: 4070119ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Tx-Frame Retry[001] -- OSeqno: 007 ISeqno: 001 Type: IAX     Subclass: LAGRP 
       Timestamp: 4069674ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 007 Type: IAX     Subclass: ACK   
       Timestamp: 4069919ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 008 Type: IAX     Subclass: ACK   
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Rx-Frame Retry[Yes] -- OSeqno: 000 ISeqno: 008 Type: IAX     Subclass: LAGRP 
       Timestamp: 4069919ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[-01] -- OSeqno: 008 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 4069919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[Yes] -- OSeqno: 255 ISeqno: 007 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: VNAK  
       Timestamp: 4070241ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 008 Type: IAX     Subclass: ACK   
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Rx-Frame Retry[Yes] -- OSeqno: 255 ISeqno: 007 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: VNAK  
       Timestamp: 4070408ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[Yes] -- OSeqno: 255 ISeqno: 007 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: VNAK  
       Timestamp: 4070559ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[Yes] -- OSeqno: 255 ISeqno: 007 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4069674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: VNAK  
       Timestamp: 4070684ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 007 Type: IAX     Subclass: PING  
       Timestamp: 20022ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 007 Type: IAX     Subclass: LAGRQ 
       Timestamp: 20025ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 006 Type: IAX     Subclass: ACK   
       Timestamp: 20022ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 006 Type: IAX     Subclass: PONG  
       Timestamp: 20022ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
       RR_JITTER       : 26
    pbx*CLI>
    Tx-Frame Retry[-01] -- OSeqno: 006 ISeqno: 008 Type: IAX     Subclass: ACK   
       Timestamp: 20022ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 007 Type: IAX     Subclass: ACK   
       Timestamp: 20025ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 007 Type: IAX     Subclass: LAGRP 
       Timestamp: 20025ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[-01] -- OSeqno: 007 ISeqno: 009 Type: IAX     Subclass: ACK   
       Timestamp: 20025ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 009 ISeqno: 007 Type: IAX     Subclass: PING  
       Timestamp: 22024ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 010 Type: IAX     Subclass: PONG  
       Timestamp: 22024ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 008 Type: IAX     Subclass: ACK   
       Timestamp: 22024ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 001 Type: IAX     Subclass: PING  
       Timestamp: 4079919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 009 ISeqno: 001 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4079922ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 009 Type: IAX     Subclass: PONG  
       Timestamp: 4079919ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0
    pbx*CLI>
    Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 002 Type: IAX     Subclass: ACK   
       Timestamp: 4079919ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 010 Type: IAX     Subclass: LAGRP 
       Timestamp: 4079922ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[-01] -- OSeqno: 010 ISeqno: 003 Type: IAX     Subclass: ACK   
       Timestamp: 4079922ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 010 Type: IAX     Subclass: PING  
       Timestamp: 4079674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 010 ISeqno: 004 Type: IAX     Subclass: PONG  
       Timestamp: 4079674ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 010 Type: IAX     Subclass: LAGRQ 
       Timestamp: 4079677ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Tx-Frame Retry[000] -- OSeqno: 011 ISeqno: 005 Type: IAX     Subclass: LAGRP 
       Timestamp: 4079677ms  SCall: 00002  DCall: 00005 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 011 Type: IAX     Subclass: ACK   
       Timestamp: 4079674ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
    Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 012 Type: IAX     Subclass: ACK   
       Timestamp: 4079677ms  SCall: 00005  DCall: 00002 [209.107.188.20:4569]
        -- Channel 0/1, span 1 got hangup request
        -- Hungup 'IAX2/iaxmodem-16385'
        -- Hungup 'Zap/1-1'
    Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 010 Type: IAX     Subclass: HANGUP
       Timestamp: 29120ms  SCall: 16385  DCall: 04237 [127.0.0.1:4570]
       CAUSE CODE      : 16
    pbx*CLI>
    Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 009 Type: IAX     Subclass: ACK   
       Timestamp: 29120ms  SCall: 04237  DCall: 16385 [127.0.0.1:4570]

     

    • Lee Howard

      Lee Howard - 2006-06-24

      I'm going to need audio recordings of the calls.

      Please set "record" in your iaxmodem config file and then re-produce the error.  Then send me the two *.raw files that are in /tmp/ that iaxmodem produces.

      You can post here or you can send to faxguy@howardsilvan.com

       

      • Christophe PEREZ

        Christophe PEREZ - 2007-03-03

        I have the same problem and I just sent my files to you.

         

        • Lee Howard

          Lee Howard - 2007-03-04

          Examining the iax-side of that audio it's clear that there were two instances of jitter while V.21 audio was being heard.  That was the catalyst for the problem.

          First off, was this HylaFAX on both ends?  If so, please send me both the sending and the receiving session logs (/var/spool/hylafax/log/...).

          Secondly, something is corrupting the audio, causing jitter.  Are you running iaxmodem on the same system as Asterisk?  Is iaxmodem communicating with Asterisk via 127.0.0.1 ?  What does zttest say?  If zttest after 1 minute says less than 99.98% then your hardware configuration is inadequate.

           

  • frank

    frank - 2014-07-01

    I have the same problem. What can I do?
    in which log can I retrieve the problem?
    MODEM TIMEOUT: waiting for v.21 carrier
    Thanks

     

    • Maxxer

      Maxxer - 2014-09-30

      Same here. Did you solve? thanks

       

Log in to post a comment.