Menu

iax_net_process: No session?

Help
2008-07-14
2013-04-05
  • confusion=growth

    Hi Lee,

    First of all, my acknowledgements to you: I've been a hylafax user for maybe 10 years, and have seen your name around for I think all or most of that time, and you consistently provide reasoned, constructive feedback - offering respect, patience and generosity of spirit.  I was thrilled to find that you were generating the iaxmodem and Hylafax+ contributions.  Thank you - sincerely!
     
    I've been beating my head against a wall on this...

    I have an Asterisk (1.4.21) + iaxmodem (1.1.0, statically built) + Hylafax+ (5.2.5) setup on Centos (8.04 2.6.24-19-generic x86_64).
    It has a single Digium TE207P with one PRI turned up.
    The system basically works great, with consistent zttest rates of 99.99+.

    I receive faxes fine, they route to Hylafax+ fine, etc.

    When I began to integrate OUTGOING faxes, however, the system fails, with faxes being processed seemingly fine by Hylafax+, but iaxmodem failing with seg_fault.  I subsequently have recompiled iaxmodem, and also "configure, make, make install"d the included spandsp and libiax2, and I have not yet progressed back to the point of attempting outgoing faxes, so I am not including that data...

    Hopefully with your assistance, I can re-emerge at that point and not actually reproduce that particular error...

    In troubleshooting this, I became aware that iaxmodem is not actually "registering" with Asterisk, though I do get "OK" in my "iax2 show peers".  "iax2 show registry" comes up blank (headers only).  Enabling debugging in my /etc/iaxmodem/ttyIAX<n> config files, and running iaxmodem in specific (non-daemon) mode never displays "registration successful" (or whatever - sure would like to know exactly what that will be...), instead producing:

    <SNIP>
    # /usr/bin/iaxmodem ttyIAX0
    [2008-07-13 21:33:44] Modem started
    [2008-07-13 21:33:44] Setting device = '/dev/ttyIAX0'
    [2008-07-13 21:33:44] Setting owner = 'uucp:uucp'
    [2008-07-13 21:33:44] Setting mode = '660'
    [2008-07-13 21:33:44] Setting port = 4570
    [2008-07-13 21:33:44] Setting refresh = 1800
    [2008-07-13 21:33:44] Setting peername = 'IAXMODEM0'
    [2008-07-13 21:33:44] Setting secret = 'IAXMODEM0'
    [2008-07-13 21:33:44] Setting cidname = 'IAXMODEM ttyIAX0'
    [2008-07-13 21:33:44] Setting cidnumber = '1234567890'
    [2008-07-13 21:33:44] Setting codec = slinear
    [2008-07-13 21:33:44] Enabling IAX2 debugging
    [2008-07-13 21:33:44] Opened pty, slave device: /dev/pts/1
    [2008-07-13 21:33:44] Created /dev/ttyIAX0 symbolic link
    iax.c line 2348 in iax_find_session: Making new session, peer callno 1978, our callno 20835
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE
       Timestamp: 00006ms  SCall: 01978  DCall: 00000 [127.0.0.1:4569]
    Tx-Frame Retry[-01] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 00006ms  SCall: 20835  DCall: 01978 [127.0.0.1:4569]
    Tx-Frame Retry[010] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass: PONG  
       Timestamp: 00006ms  SCall: 20835  DCall: 01978 [127.0.0.1:4569]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OOO          : 0

    iax.c line 2350 in iax_find_session: No session, peer = 1978, us = 20835
    iax.c line 3205 in iax_net_process: No session?
    </SNIP>

    Now, the /etc/iaxmodem/ttyIAX0 file is:

    # cat /etc/iaxmodem/ttyIAX0
    device /dev/ttyIAX0
    owner uucp:uucp
    mode 660
    port 4569
    refresh 1800
    peername IAXMODEM0
    secret IAXMODEM0
    cidname IAXMODEM ttyIAX0
    cidnumber 1234567890
    codec slinear
    spandspdebug
    iax2debug

    and the corresponding iax.conf is:

    [general]
    bindport=4569
    bindaddr=0.0.0.0
    disallow=all
    allow=slin

    [ttyIAX0]
    context=fax-out
    type=friend
    username=IAXMODEM0
    secret=IAXMODEM0
    qualify=yes
    host=127.0.0.1
    bindaddr=127.0.0.1
    port=4569
    disallow=all
    allow=slin

    [ttyIAX1]
    context=fax-out
    type=friend
    username=IAXMODEM1
    secret=IAXMODEM1
    qualify=yes
    host=127.0.0.1
    port=4571
    disallow=all
    allow=slin

    The asterisk CLI shows (with "iax2 set debug"):
    [Jul 13 21:33:46] NOTICE[31116]: chan_iax2.c:7891 socket_process: Peer 'ttyIAX0' is now REACHABLE! Time: 3
    Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 00006ms  SCall: 01978  DCall: 20835 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00006ms  SCall: 13414  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00006ms  SCall: 13414  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 05579  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 05579  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 02260  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 02260  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00007ms  SCall: 01178  DCall: 00000 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 00007ms  SCall: 20836  DCall: 01178 [127.0.0.1:4570]
    Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass: PONG  
       Timestamp: 00007ms  SCall: 20836  DCall: 01178 [127.0.0.1:4570]
       RR_JITTER       : 0
       RR_LOSS         : 0
       RR_PKTS         : 1
       RR_DELAY        : 40
       RR_DROPPED      : 0
       RR_OUTOFORDER   : 0

    Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass: ACK   
       Timestamp: 00007ms  SCall: 01178  DCall: 20836 [127.0.0.1:4570]
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 15775  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 15775  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 09211  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 09211  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 11013  DCall: 00000 [127.0.0.1:4571]
    Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass: POKE  
       Timestamp: 00005ms  SCall: 11013  DCall: 00000 [127.0.0.1:4571]

    BTW, there is also a ttyIAX1 at port 4571 at the same time as this, thus the presence of that port in the above trace...

    # asterisk -rx "iax2 show peers"
    Name/Username    Host                 Mask             Port          Status   
    ttyIAX1/IAXMODE  127.0.0.1       (S)  255.255.255.255  4571          UNREACHABLE
    ttyIAX0/IAXMODE  127.0.0.1       (S)  255.255.255.255  4570          OK (1 ms)
    2 iax2 peers [1 online, 1 offline, 0 unmonitored]

    # asterisk -rx "iax2 show registry"
    Host                  dnsmgr  Username    Perceived             Refresh  State

    So the above shows that despite generating a "No session?" I do get an OK status in "iax2 show peers".
    But, I also get nothing resembling "registration". 

    I know next to nothing about IAX2, so, please forgive me if I shouldn't be expecting anything in "iax2 show registry", but research indicates that I should at least be getting "registration" messages...

    Any ideas or suggestions?

    Regards,
    Confused

     
    • Lee Howard

      Lee Howard - 2008-07-14

      Thank you for your kind words.

      While iaxmodem shouldn't be segfaulting ever (in other words, it's a bug), it's probably happening due to the same reason as you don't have registrations occurring.

      Where is the "server" line in your iaxmodem configuration file?

      I've made a change for future iaxmodem releases to default to "127.0.0.1" if server is not specified.  However, I've not yet addressed the case where someone may configure a "blank" server name.

       
    • confusion=growth

      Thanks for your rapid response...

      The system at issue is already in production during the day, so I'm gentle with it during east coast business hours...

      In production mode, it is running 10 iaxmodems:  ttyIAX0-ttyIAX9.

      I added a server=localhost or server=127.0.0.1 (tried both) to /etc/iaxmodem/ttyIAX9, and waiting for non-busy intervals, restarted iaxmodem (daemon mode).  (Asterisk is configured so that incoming faxes always take the lower numbered iaxmodems first.)

      I received (through asterisk CLI): NOTICE[31110]: chan_iax2.c:5491 register_verify: Peer 'IAXMODEM9' is not dynamic (from 127.0.0.1)

      I then changed in the [ttyIAX9] section of iax.conf:

      host=127.0.0.1 to host=dynamic
      and I removed the line bindaddr=127.0.0.1

      I had found, weeks ago, through trial and error, that using "127.0.0.1" for both "host" and "bindaddr" relieved the message above, and somewhere in the same process, I had removed the "server" entry from my iaxmodem configuration file(s).

      Anyway, back to the present, restarting iaxmodem still showed no "registration" messages for ttyIAX9. 
      I removed the "auth=md5" line from the ttyIAX9 section of iax.conf, and restarted iaxmodem, and got:

          -- Unregistered IAX2 'IAXMODEM9' (UNAUTHENTICATED)
          -- Registered IAX2 'IAXMODEM9' (AUTHENTICATED) at 127.0.0.1:4579

      So, voila!, but still nothing shows in "iax2 show registry", however, "iax2 show peers" shows a "D" instead of an "S" for ttyIAX9, presumably for Dynamic instead of Static.

      I don't actually want to stop iaxmodem running in daemon mode, so that I can run it in debug mode, but I added "spandspdebug" and "iax2debug" to the iaxmodem config file, (and changed the refresh to 60 from 1800 to stop annoying message) and again restarted the iaxmodem daemon.

      In the CLI:

          -- Unregistered IAX2 'IAXMODEM9' (UNAUTHENTICATED)
          -- Registered IAX2 'IAXMODEM9' (AUTHENTICATED) at 127.0.0.1:4579

      In /var/log/iaxmodem/ttyIAX9:

      # tail -f /var/log/iaxmodem/ttyIAX9
      [2008-07-14 09:40:15] Terminating on signal 15...
      [2008-07-14 10:04:08] Terminating on signal 15...
      iax.c line 2617 in iax_header_to_event: Cancelling transmission of packet 0
      iax.c line 2348 in iax_find_session: Making new session, peer callno 13623, our callno 6015
      iax.c line 2617 in iax_header_to_event: Cancelling transmission of packet 1
      iax.c line 2350 in iax_find_session: No session, peer = 13623, us = 6015
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2348 in iax_find_session: Making new session, peer callno 8240, our callno 6016
      iax.c line 2350 in iax_find_session: No session, peer = 8240, us = 6016
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2348 in iax_find_session: Making new session, peer callno 9856, our callno 6017
      iax.c line 2350 in iax_find_session: No session, peer = 9856, us = 6017
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2617 in iax_header_to_event: Cancelling transmission of packet 0
      iax.c line 2348 in iax_find_session: Making new session, peer callno 5580, our callno 6019
      iax.c line 2350 in iax_find_session: No session, peer = 5580, us = 6019
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2348 in iax_find_session: Making new session, peer callno 9950, our callno 6020
      iax.c line 2350 in iax_find_session: No session, peer = 9950, us = 6020
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2348 in iax_find_session: Making new session, peer callno 6781, our callno 6021
      iax.c line 2350 in iax_find_session: No session, peer = 6781, us = 6021
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2617 in iax_header_to_event: Cancelling transmission of packet 0
      iax.c line 2348 in iax_find_session: Making new session, peer callno 4309, our callno 6023
      iax.c line 2350 in iax_find_session: No session, peer = 4309, us = 6023
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2348 in iax_find_session: Making new session, peer callno 7260, our callno 6024
      iax.c line 2350 in iax_find_session: No session, peer = 7260, us = 6024
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2348 in iax_find_session: Making new session, peer callno 211, our callno 6025
      iax.c line 2350 in iax_find_session: No session, peer = 211, us = 6025
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2617 in iax_header_to_event: Cancelling transmission of packet 0
      iax.c line 2348 in iax_find_session: Making new session, peer callno 3651, our callno 6027
      iax.c line 2350 in iax_find_session: No session, peer = 3651, us = 6027
      iax.c line 3205 in iax_net_process: No session?
      iax.c line 2348 in iax_find_session: Making new session, peer callno 7601, our callno 6028
      iax.c line 2350 in iax_find_session: No session, peer = 7601, us = 6028
      iax.c line 3205 in iax_net_process: No session?

      Any further suggestions?

      I suppose anything much more disruptive than this will have to wait until this evening, as the system is consistently busy during the day...

      Best regards,
      Confused, but hopeful...

       
      • Lee Howard

        Lee Howard - 2008-07-16

        As I don't know the immediate problem, I'd recommend going back to basics... starting the iaxmodem configuration again both in /etc/asterisk and /etc/iaxmodem.  Please refer to the examples here:

        http://iaxmodem.sourceforge.net/faq.php
        http://iaxmodem.sourceforge.net/howto.php

         

Log in to post a comment.