thr3ads.net - asterisk users - [asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax [Jul 2013]

If this information is useful, please help other people find it:
Share via:

Gianni Fioretta

2013-Jul-04 15:49 UTC

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

Hi, we have a faxserver with Asterisk, IAXModem and Hylafax.
Faxes come from a SIP trunk to Asterisk, then are forwarded throught 5 IAXModems
managed with Hylafax.
Hylafax users can also send faxes to these modems and Asterisk send them
throught the SIP trunk.
We also have a dedicated modem used only for sending faxes coming from an
Hylafax dedicated user.

Sometimes Hylafax reports that a modem is wedged and this modem remain wedged
until we restart IAXModem daemon. When all modems becames wedged the server
can't send and receive any fax.

We have enabled iax2debug, but no errors appears anyway.

Here's an example of the faxstat hylafax command, modem4 is reported as
wedged:
$faxstat -as
HylaFAX scheduler on srv-faxserver.comune.local: Running
Modem ttyIAX4 (): Waiting for modem to come ready
Modem ttyIAX99 (): Running and idlem
Modem ttyIAX3 (): Running and idle0
Modem ttyIAX2 (): Running and idleS
Modem ttyIAX5 (): Running and idlem
Modem ttyIAX1 (): Running and idleS

...but Asterisk reports the modem as ready to work (I think):
srv-faxserver*CLI> iax2 show peers
Name/Username    Host                 Mask             Port          Status    
modem3/modem3    127.0.0.1       (D)  255.255.255.255  4573          OK (3 ms) 
modem2/modem2    127.0.0.1       (D)  255.255.255.255  4572          OK (3 ms) 
modem1/modem1    127.0.0.1       (D)  255.255.255.255  4571          OK (3 ms) 
modem5/modem5    127.0.0.1       (D)  255.255.255.255  4575          OK (3 ms) 
modem4/modem4    127.0.0.1       (D)  255.255.255.255  4574          OK (1 ms) 
modem99/modem99  127.0.0.1       (D)  255.255.255.255  4599          OK (3 ms) 
6 iax2 peers [6 online, 0 offline, 0 unmonitored]

Last call for the modem4 in asterisk log:
[Jul  4 16:49:00] NOTICE[22999]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem1' to 60 seconds (requested 300)
[Jul  4 16:49:06] NOTICE[22991]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem2' to 60 seconds (requested 300)
[Jul  4 16:49:07] NOTICE[22995]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem99' to 60 seconds (requested 300)
[Jul  4 16:49:07] NOTICE[23000]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem3' to 60 seconds (requested 300)
[Jul  4 16:49:10] NOTICE[22995]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem5' to 60 seconds (requested 300)
    -- Hungup 'IAX2/modem1-11301'
  == Spawn extension (default, 224966905, 1) exited non-zero on
'SIP/centralino-00000282'
[Jul  4 16:49:15] NOTICE[22998]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem4' to 60 seconds (requested 300)
    -- Accepting AUTHENTICATED call from 127.0.0.1:
       > requested format = alaw,
       > requested prefs = (),
       > actual format = alaw,
       > host prefs = (alaw),
       > priority = mine
    -- Executing [022483278 at fax:1] Dial("IAX2/modem4-8449",
"SIP/centralino/022483278") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/centralino/022483278
    -- Accepting AUTHENTICATED call from 127.0.0.1:
       > requested format = alaw,
       > requested prefs = (),
       > actual format = alaw,
       > host prefs = (alaw),
       > priority = mine
    -- Executing [0224300258 at fax:1] Dial("IAX2/modem2-3460",
"SIP/centralino/0224300258") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/centralino/0224300258
    -- SIP/centralino-00000284 is making progress passing it to IAX2/modem2-3460
    -- SIP/centralino-00000284 is ringing
    -- SIP/centralino-00000284 is making progress passing it to IAX2/modem2-3460
    -- SIP/centralino-00000283 is making progress passing it to IAX2/modem4-8449
    -- SIP/centralino-00000283 is ringing
    -- SIP/centralino-00000283 is making progress passing it to IAX2/modem4-8449
    -- SIP/centralino-00000284 answered IAX2/modem2-3460
[Jul  4 16:49:55] WARNING[22988]: chan_sip.c:9123 process_sdp: Failing due to no
acceptable offer found
[Jul  4 16:49:55] NOTICE[22991]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem1' to 60 seconds (requested 300)
[Jul  4 16:50:01] NOTICE[22995]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem2' to 60 seconds (requested 300)
[Jul  4 16:50:02] NOTICE[23000]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem99' to 60 seconds (requested 300)
[Jul  4 16:50:02] NOTICE[22994]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem3' to 60 seconds (requested 300)
[Jul  4 16:50:05] NOTICE[22995]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem5' to 60 seconds (requested 300)
[Jul  4 16:50:10] NOTICE[23000]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem4' to 60 seconds (requested 300)

I hope you can help me to understand if the problem is Asterisk or something
else.
I'm not an Asterisk expert, so I can't read every log row... for
example: Asterisk log is always full of:
[Jul  4 17:44:08] NOTICE[22998]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem2' to 60 seconds (requested 300)
[Jul  4 17:44:08] NOTICE[22992]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem99' to 60 seconds (requested 300)
[Jul  4 17:44:09] NOTICE[22997]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem3' to 60 seconds (requested 300)
[Jul  4 17:44:11] NOTICE[22994]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem5' to 60 seconds (requested 300)
[Jul  4 17:44:16] NOTICE[22998]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem4' to 60 seconds (requested 300)
[Jul  4 17:44:56] NOTICE[22999]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem1' to 60 seconds (requested 300)
[Jul  4 17:45:03] NOTICE[22993]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem2' to 60 seconds (requested 300)
[Jul  4 17:45:03] NOTICE[22995]: chan_iax2.c:8775 update_registry: Restricting
registration for peer 'modem99' to 60 seconds (requested 300)

is that right?

Let me know if you need more details.


Any help would be appreciated.
Thanks in advance.

-- 
Gianni Fioretta - gianni.fioretta at yetopen.it

YetOpen S.r.l. - http://www.yetopen.it/
via Carlo Torri Tarelli 19 - 23900 Lecco - ITALY -
Tel 0341 220 205 - Fax 178 6070 222

-------- D.Lgs. 196/2003 --------

Si avverte che tutte le informazioni contenute in questo messaggio sono
riservate ed a uso esclusivo del destinatario. Nel caso in cui questo
messaggio Le fosse pervenuto per errore, La invitiamo ad eliminarlo
senza copiarlo, a non inoltrarlo a terzi e ad avvertirci non appena
possibile.
Grazie.

James Cloos

2013-Jul-04 20:53 UTC

head link

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

>>>>> "GF" == Gianni Fioretta <gianni.fioretta at
yetopen.it> writes:
GF> [Jul  4 17:45:03] NOTICE[22995]: chan_iax2.c:8775 update_registry:
Restricting registration for peer 'modem99' to 60 seconds (requested
300)

GF> is that right?

When iaxmodem registers with asterisk, it defaults to asking that the
registration last 300 seconds.  Asterisk defaults to permiting only 60
seconds per registration.

You can eliminate that notice by configuring both sides with the same
duration.

In the iaxmodem config files, add a line:

refresh 60

to make iaxmodem ask for 60 seconds.

Alternatively, change the maxregexpire setting in asterisk's iax.conf
(in the [general] section) topermit values at least as large as 300 seconds.

-JimC
-- 
James Cloos <cloos at jhcloos.com>         OpenPGP: 1024D/ED7DAEA6

James Cloos

2013-Jul-04 21:16 UTC

head link

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

>>>>> "GF" == Gianni Fioretta <gianni.fioretta at
yetopen.it> writes:
GF>     -- Executing [0224300258 at fax:1] Dial("IAX2/modem2-3460",
"SIP/centralino/0224300258") in new stack
GF>   == Using SIP RTP CoS mark 5
GF>     -- Called SIP/centralino/0224300258
GF>     -- SIP/centralino-00000284 is making progress passing it to
IAX2/modem2-3460
GF>     -- SIP/centralino-00000284 is ringing
GF>     -- SIP/centralino-00000284 is making progress passing it to
IAX2/modem2-3460
GF>     -- SIP/centralino-00000283 is making progress passing it to
IAX2/modem4-8449
GF>     -- SIP/centralino-00000283 is ringing
GF>     -- SIP/centralino-00000283 is making progress passing it to
IAX2/modem4-8449
GF>     -- SIP/centralino-00000284 answered IAX2/modem2-3460
GF> [Jul  4 16:49:55] WARNING[22988]: chan_sip.c:9123 process_sdp: Failing
due to no acceptable offer found

That last line above shows that an outgoing fax attempt failed because
the sip end wasn't able to negotaiate a codec for that part of the call.

It looks like it was modem2's call which failed; modem4's call seems not
yet to have been answered.

I don't know whether that is what triggers the wedge, but the failure to
negotiate a codec for the sip/rtp leg probably is a configuration bug.

Which version of asterisk?  Self compiled or a distribution's version?

The sip.conf and iax.conf might help debug it.  (Elide passwords, of course.)

If you run the conf files through something like:

:; egrep -v '^[[:blank:]]*;' iax.conf|egrep -v '^$'
>/tmp/short-iax.conf

before editing the password lines it will be easier to read them.

-JimC
-- 
James Cloos <cloos at jhcloos.com>         OpenPGP: 1024D/ED7DAEA6

Lee Howard

2013-Jul-09 19:51 UTC

head link

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

On 07/04/2013 08:49 AM, Gianni Fioretta wrote:> Hi, we have a faxserver with Asterisk, IAXModem and Hylafax.
> Faxes come from a SIP trunk to Asterisk, then are forwarded throught 5
IAXModems managed with Hylafax.
> Hylafax users can also send faxes to these modems and Asterisk send them
throught the SIP trunk.
> We also have a dedicated modem used only for sending faxes coming from an
Hylafax dedicated user.
>
> Sometimes Hylafax reports that a modem is wedged and this modem remain
wedged until we restart IAXModem daemon. When all modems becames wedged the
server can't send and receive any fax.
IAXmodems do wedge sometimes, and I currently advise users to develop a 
"resetmodem" (see 'man wedged') to automatically reset the
iaxmodem.

It's not clear to me why the iaxmodems sometimes wedge.  It essentially 
means that somewhere the iaxmodem code is either stuck in an endless 
loop, blocking on a read somewhere that shouldn't block, or something of 
that nature.  If you could capture the gdb or strace of an iaxmodem as 
it gets wedged, then that would be most-helpful.

However, I can tell you that the wedging occurs more-frequently in cases 
where there are other problems such as line audio quality issues or lots 
of non-fax numbers being used accidentally.  So your use of SIP (VoIP) 
for what should be a lossless data channel is probably a factor there.

Thanks,

Lee.

Apparently Analagous Threads

Search for more reasonably related threads

asterisk users - Jul 2013 - Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

[asterisk-users] Asterisk + iaxmodem + hylafax makes sometimes wedged for hylafax

Apparently Analagous Threads