#1 Hylafax - (rfe: swapbytes)

closed-fixed
None
5
2005-11-15
2005-10-21
No

Asterisk CVS several months old, but working.
Centos 4
iaxmodem-0.0.5
spandsp-0.0.3pre4

Asterisk is connected to the PSTN through a BRI
interface, not analog. We have a fax machine connected
to a FXS port on a TDM11b, and we've had no problems
with sending and receiving.

We've tried iaxmodem from 3 different fax machines, 1
local, and to remote ones, through the PSTN.

A copy of the recordings for the following log can be
found here:
http://www.maxosystem.net/asterisk/iaxmodem/311-iax.raw
http://www.maxosystem.net/asterisk/iaxmodem/311-dsp.raw

I keep getting "MODEM TIMEOUT: waiting for v.21
carrier" in hylafax logs:

======

Oct 21 14:14:54.80: [30241]: SESSION BEGIN 000000008
34928928858952
Oct 21 14:14:54.80: [30241]: HylaFAX (tm) Version 4.2.2
Oct 21 14:14:54.80: [30241]: MODEM set XON/XOFF/FLUSH:
input ignored, output disabled
Oct 21 14:14:54.80: [30241]: <-- [4:ATA\r]
Oct 21 14:14:58.90: [30241]: --> [7:CONNECT]
Oct 21 14:14:58.90: [30241]: ANSWER: FAX CONNECTION
DEVICE '/dev/ttyIAX'
Oct 21 14:14:58.90: [30241]: STATE CHANGE: ANSWERING ->
RECEIVING
Oct 21 14:14:58.90: [30241]: RECV FAX: begin
Oct 21 14:14:58.90: [30241]: <-- HDLC<32:FF C0 04 AD 00
55 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE
96 F6 76 04 2C 7
4 4C 74 4C>
Oct 21 14:14:58.90: [30241]: <-- data [32]
Oct 21 14:14:58.90: [30241]: <-- data [2]
Oct 21 14:14:59.96: [30241]: --> [7:CONNECT]
Oct 21 14:14:59.96: [30241]: <-- 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>
Oct 21 14:14:59.96: [30241]: <-- data [23]
Oct 21 14:14:59.96: [30241]: <-- data [2]
Oct 21 14:15:00.78: [30241]: --> [7:CONNECT]
Oct 21 14:15:00.78: [30241]: <-- HDLC<10:FF C8 01 00 73
5F 23 01 FB C0>
Oct 21 14:15:00.78: [30241]: <-- data [10]
Oct 21 14:15:00.78: [30241]: <-- data [2]
Oct 21 14:15:01.30: [30241]: --> [2:OK]
Oct 21 14:15:01.30: [30241]: <-- [9:AT+FRH=3\r]
Oct 21 14:15:08.30: [30241]: --> [0:]
Oct 21 14:15:08.30: [30241]: MODEM <Empty line>
Oct 21 14:15:08.30: [30241]: MODEM TIMEOUT: waiting for
v.21 carrier
Oct 21 14:15:08.30: [30241]: <-- data [1]
Oct 21 14:15:08.30: [30241]: --> [2:OK]
Oct 21 14:15:08.30: [30241]: DELAY 1500 ms
Oct 21 14:15:09.80: [30241]: <-- [9:AT+FTH=3\r]
Oct 21 14:15:09.82: [30241]: --> [7:CONNECT]
Oct 21 14:15:09.82: [30241]: <-- HDLC<32:FF C0 04 AD 00
55 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE
96 F6 76 04 2C 7
4 4C 74 4C>
Oct 21 14:15:09.82: [30241]: <-- data [32]
Oct 21 14:15:09.82: [30241]: <-- data [2]
Oct 21 14:15:12.08: [30241]: --> [7:CONNECT]
Oct 21 14:15:12.08: [30241]: <-- 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>
Oct 21 14:15:12.08: [30241]: <-- data [23]
Oct 21 14:15:12.08: [30241]: <-- data [2]
Oct 21 14:15:12.90: [30241]: --> [7:CONNECT]
Oct 21 14:15:12.90: [30241]: <-- HDLC<10:FF C8 01 00 73
5F 23 01 FB C0>
Oct 21 14:15:12.90: [30241]: <-- data [10]
Oct 21 14:15:12.90: [30241]: <-- data [2]
Oct 21 14:15:13.40: [30241]: --> [2:OK]
Oct 21 14:15:13.40: [30241]: <-- [9:AT+FRH=3\r]
Oct 21 14:15:20.40: [30241]: --> [0:]
Oct 21 14:15:20.40: [30241]: MODEM <Empty line>
Oct 21 14:15:20.40: [30241]: MODEM TIMEOUT: waiting for
v.21 carrier
Oct 21 14:15:20.40: [30241]: <-- data [1]
Oct 21 14:15:20.40: [30241]: --> [2:OK]
Oct 21 14:15:20.40: [30241]: DELAY 1500 ms
Oct 21 14:15:21.90: [30241]: <-- [9:AT+FTH=3\r]
Oct 21 14:15:21.92: [30241]: --> [7:CONNECT]
Oct 21 14:15:21.92: [30241]: <-- HDLC<32:FF C0 04 AD 00
55 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE
96 F6 76 04 2C 7
4 4C 74 4C>
Oct 21 14:15:21.92: [30241]: <-- data [32]
Oct 21 14:15:21.92: [30241]: <-- data [2]
Oct 21 14:15:24.18: [30241]: --> [7:CONNECT]
Oct 21 14:15:24.18: [30241]: <-- 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>
Oct 21 14:15:24.18: [30241]: <-- data [23]
Oct 21 14:15:24.18: [30241]: <-- data [2]
Oct 21 14:15:25.00: [30241]: --> [7:CONNECT]
Oct 21 14:15:25.00: [30241]: <-- HDLC<10:FF C8 01 00 73
5F 23 01 FB C0>
Oct 21 14:15:25.00: [30241]: <-- data [10]
Oct 21 14:15:25.00: [30241]: <-- data [2]
Oct 21 14:15:25.50: [30241]: --> [2:OK]
Oct 21 14:15:25.50: [30241]: <-- [9:AT+FRH=3\r]
Oct 21 14:15:32.50: [30241]: --> [0:]
Oct 21 14:15:32.50: [30241]: MODEM <Empty line>
Oct 21 14:15:32.50: [30241]: MODEM TIMEOUT: waiting for
v.21 carrier
Oct 21 14:15:32.50: [30241]: <-- data [1]
Oct 21 14:15:32.50: [30241]: --> [2:OK]
Oct 21 14:15:32.50: [30241]: DELAY 1500 ms
Oct 21 14:15:34.00: [30241]: <-- [9:AT+FTH=3\r]
Oct 21 14:15:34.01: [30241]: --> [7:CONNECT]
Oct 21 14:15:34.01: [30241]: <-- HDLC<32:FF C0 04 AD 00
55 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE
96 F6 76 04 2C 7
4 4C 74 4C>
Oct 21 14:15:34.01: [30241]: <-- data [32]
Oct 21 14:15:34.01: [30241]: <-- data [2]
Oct 21 14:15:36.26: [30241]: --> [7:CONNECT]
Oct 21 14:15:36.26: [30241]: <-- 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>
Oct 21 14:15:36.26: [30241]: <-- data [23]
Oct 21 14:15:36.26: [30241]: <-- data [2]
Oct 21 14:15:37.08: [30241]: --> [7:CONNECT]
Oct 21 14:15:37.08: [30241]: <-- HDLC<10:FF C8 01 00 73
5F 23 01 FB C0>
Oct 21 14:15:37.08: [30241]: <-- data [10]
Oct 21 14:15:37.08: [30241]: <-- data [2]
Oct 21 14:15:37.58: [30241]: --> [2:OK]
Oct 21 14:15:37.58: [30241]: <-- [9:AT+FRH=3\r]
Oct 21 14:15:44.58: [30241]: --> [0:]
Oct 21 14:15:44.58: [30241]: MODEM <Empty line>
Oct 21 14:15:44.58: [30241]: MODEM TIMEOUT: waiting for
v.21 carrier
Oct 21 14:15:44.58: [30241]: <-- data [1]
Oct 21 14:15:44.59: [30241]: --> [2:OK]
Oct 21 14:15:44.59: [30241]: RECV FAX: No answer (T.30
T1 timeout)
Oct 21 14:15:44.59: [30241]: RECV FAX: end
Oct 21 14:15:44.59: [30241]: SESSION END

=====

Any idea of what can be wrong?

Julian J. M.

Discussion

  • Lee Howard

    Lee Howard - 2005-10-22

    Logged In: YES
    user_id=627618

    This here means that IAXmodem's V.21 receive modem (in
    spandsp, of course), is unable to "hear" the V.21 carrier
    signal from the sender.

    Oct 21 14:15:37.58: [30241]: <-- [9:AT+FRH=3\r]
    Oct 21 14:15:44.58: [30241]: --> [0:]
    Oct 21 14:15:44.58: [30241]: MODEM <Empty line>
    Oct 21 14:15:44.58: [30241]: MODEM TIMEOUT: waiting for v.21
    carrier
    Oct 21 14:15:44.58: [30241]: <-- data [1]
    Oct 21 14:15:44.59: [30241]: --> [2:OK]

    If you listen to the IAX audio (which is messed-up) and then
    compare it to the DSP audio (which is clean) then you'll get
    an idea why. You *should* hear warbles in the IAX audio
    like you do in the DSP audio, but instead all you'll hear is
    periods of static mixed with the periods of silence.

    What kind of platform is this? I'm guessing that it's a
    dual-core CPU or a SMP system and that the byte-swapping
    should not be done on your system. Please try the attached
    patch against iaxmodem.c and let me know how you fare.

     
  • Lee Howard

    Lee Howard - 2005-10-22

    disables the calls to swapbytes

     
  • Julian J. M.

    Julian J. M. - 2005-10-23

    Logged In: YES
    user_id=1223657

    Hello Lee, thanks for your response..

    First of all, i've not tried the patch yet.

    The system where asterisk and iaxmodem run, is not a SMP nor
    dual core... it's a PentiumIV 2.8Ghz, with an Intel 865
    based motherboard (Asus), runing Centos4.

    Anyway, i'll try the patch and reply to this thread with the
    results.

    Julian J. M.

     
  • Lee Howard

    Lee Howard - 2005-10-23

    Logged In: YES
    user_id=627618

    The issue is this: sometimes Asterisk uses a different
    byteorder for slinear than at other times - and I *thought*
    that it was a matter of the platform being SMP or not. I'll
    have to go in and read the Asterisk code again, I guess to
    know for certain.

    In any case, try the patch. It disables the byteswapping
    (which was required on my Pentium II and Athlon deployments).

    A quick test will probably help, too. The audio coming from
    spandsp is not byteswapped before it is written to file.
    That file sounds fine, however it is byteswapped before it
    is sent via IAX. So call with your phone to IAXmodem and if
    it sounds like static then most assuredly the byteswapping
    needs to be disabled on your system.

    If this works for you then I'm going to just add a
    configuration file option to enable or disable the
    byteswapping until someone comes along who can tell me how
    to know automatically when byteswapping is or isn't appropriate.

     
  • Julian J. M.

    Julian J. M. - 2005-10-23

    Logged In: YES
    user_id=1223657

    Ok, just tested it and works perfectly!

    I've sent and received several (about 10) multipage faxes,
    and none of them failed... I know it's not enough for saying
    "it works 100%", but i'll assign iaxmodem to a spare DID for
    deeper testing.

    Thanks for this great work. Now I can use both asterisk and
    hylafax without having to add another FXS port and a
    hardware modem.

    Julian J. M.

     
  • Lee Howard

    Lee Howard - 2005-10-24
    • status: open --> closed
     
  • Lee Howard

    Lee Howard - 2005-10-24
    • summary: Hylafax --> Hylafax - (rfe: swapbytes)
    • assigned_to: nobody --> faxguy
    • status: closed --> closed-fixed
     
  • Lee Howard

    Lee Howard - 2005-10-24

    Logged In: YES
    user_id=627618

    In the next release (0.0.6) there will be a configuration
    option "swapbytes". The default is "true". You will need
    to set it to "false".

    I've also opened a bug ticket for Asterisk with Digium at:

    http://bugs.digium.com/view.php?id=5506

    ... for whatever that's worth.

     
  • Lee Howard

    Lee Howard - 2005-10-31

    Logged In: YES
    user_id=627618

    Julian, can you please try the attached version of
    iaxmodem.c. It follows drumkilla's suggestion to use ntohs.

     
  • Lee Howard

    Lee Howard - 2005-10-31

    iaxmodem.c with ntohs instead of swapbytes

     
  • Lee Howard

    Lee Howard - 2005-10-31
    • status: closed-fixed --> open
     
  • Lee Howard

    Lee Howard - 2005-10-31
    • status: open --> pending-fixed
     
  • SourceForge Robot

    • status: pending-fixed --> closed-fixed
     
  • SourceForge Robot

    Logged In: YES
    user_id=1312539

    This Tracker item was closed automatically by the system. It was
    previously set to a Pending status, and the original submitter
    did not respond within 14 days (the time period specified by
    the administrator of this Tracker).