TRY THIS HylaFax IAXmodem Logging

[lrosenman]

in 11.12-1 on Raspi, with the fax stuff, faxgetty is VERY chatty, and the iax_registration whines constantly.

to fix the latter:

root@incrediblepbx:/etc/asterisk $ cat iax_registrations_custom.conf
minregexpire=60
maxregexpire=600
defaultexpire=300
WARNING: Always run Incredible PBX VM behind a secure hardware-based firewall.
root@incrediblepbx:/etc/asterisk $

for the former, here's just one set from one of the 4 FaxGetty's

Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: <-- [9:AT+FRM=?\r]
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: --> [39:24,48,72,73,74,96,97,98,121,122,145,146]
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: MODEM WWW.SOFT-SWITCH.ORG spandsp/
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: <-- [5:ATM0\r]
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: <-- [9:AT+FAR=1\r]
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:31:45 incrediblepbx FaxGetty[3796]: STATE CHANGE: LOCKWAIT -> RUNNING (timeout 30)
Aug 27 08:32:15 incrediblepbx FaxGetty[3796]: STATE CHANGE: RUNNING -> LOCKWAIT (timeout 30)
Aug 27 08:32:15 incrediblepbx FaxGetty[3796]: MODEM input buffering enabled
Aug 27 08:32:20 incrediblepbx FaxGetty[3796]: ANSWER: Can not lock modem device
Aug 27 08:33:51 incrediblepbx FaxGetty[3796]: MODEM set DTR OFF
Aug 27 08:33:51 incrediblepbx FaxGetty[3796]: MODEM set baud rate: 0 baud (flow control unchanged)
Aug 27 08:33:51 incrediblepbx FaxGetty[3796]: DELAY 75 ms
Aug 27 08:33:51 incrediblepbx FaxGetty[3796]: MODEM set DTR ON
Aug 27 08:33:51 incrediblepbx FaxGetty[3796]: DELAY 2600 ms
Aug 27 08:33:55 incrediblepbx FaxGetty[3796]: MODEM set baud rate: 19200 baud, input flow XON/XOFF, output flow XON/XOFF
Aug 27 08:33:55 incrediblepbx FaxGetty[3796]: DELAY 10 ms
Aug 27 08:33:55 incrediblepbx FaxGetty[3796]: MODEM flush i/o
Aug 27 08:33:55 incrediblepbx FaxGetty[3796]: <-- [4:ATZ\r]
Aug 27 08:33:55 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:55 incrediblepbx FaxGetty[3796]: DELAY 3000 ms
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: MODEM flush i/o
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [10:AT+VCID=1\r]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [9:AT+VCID=1]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [7:ATS0=0\r]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [6:ATS0=0]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [5:ATE0\r]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [4:ATE0]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [5:ATV1\r]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [5:ATQ0\r]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [7:ATS8=2\r]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [8:ATS7=60\r]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:58 incrediblepbx FaxGetty[3796]: <-- [12:AT+FCLASS=?\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [7:0,1,1.0]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports "Data"
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports "Class 1"
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports "Class 1.0"
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: <-- [12:AT+FCLASS=1\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: <-- [5:ATI3\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [19:www.soft-switch.org]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM: Mfr www.soft-switch.org
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: <-- [5:ATI0\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [7:spandsp]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM: Model spandsp
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: <-- [9:AT+FTM=?\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [39:24,48,72,73,74,96,97,98,121,122,145,146]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 3.85 line/mm
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 7.7 line/mm
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 15.4 line/mm
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports R16 x 15.4 line/mm
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 200 x 100 dpi
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 200 x 200 dpi
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 200 x 400 dpi
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 300 x 300 dpi
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 2400 bit/s
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 4800 bit/s
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 7200 bit/s
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 9600 bit/s
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 12000 bit/s
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 14400 bit/s
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports A4 page width (215 mm)
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports B4 page width (255 mm)
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports A3 page width (303 mm)
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports A4 page length (297 mm)
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports B4 page length (364 mm)
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports unlimited page length
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 1-D MH
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 2-D MR
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 2-D MMR
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports no ECM
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports T.30 Annex A, 64-byte ECM
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports T.30 Annex A, 256-byte ECM
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 0 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 5 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 10 ms, 5 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 10 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 20 ms, 10 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 20 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 40 ms, 20 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM Supports 40 ms/scanline
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: <-- [9:AT+FRM=?\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [39:24,48,72,73,74,96,97,98,121,122,145,146]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM WWW.SOFT-SWITCH.ORG spandsp/
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: <-- [5:ATM0\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: <-- [9:AT+FAR=1\r]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: --> [2:OK]
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: STATE CHANGE: LOCKWAIT -> RUNNING (timeout 30)
Aug 27 08:33:59 incrediblepbx FaxGetty[3796]: MODEM input buffering disabled
Aug 27 08:34:29 incrediblepbx FaxGetty[3796]: STATE CHANGE: RUNNING -> LOCKWAIT (timeout 30)
Aug 27 08:34:29 incrediblepbx FaxGetty[3796]: MODEM input buffering enabled
Aug 27 08:34:36 incrediblepbx FaxGetty[3796]: ANSWER: Can not lock modem device
WARNING: Always run Incredible PBX VM behind a secure hardware-based firewall.
root@incrediblepbx:/etc/asterisk $

Is there anything we can do to silence some of this?

 

[wardmundy]

lrosenman No idea. Probably want to start with section 3.5 pertaining to HylaFax logging. Might also try adding SessionTracing 0xFFF to each of the IAXmodem config files in /etc/iaxmodem. Then I'd try adding SessionTracing: 0xFFF to /etc/hylafax/hfaxd.conf. Probably have to reboot after each modification to test it properly.

 

[lrosenman]

I found it.....
the default configuration had two versions of faxgetty fighting with each other

the fix:
# try to check for the correct USE_FAXGETTY value
if grep -E '^[^#]*:respawn:/usr/sbin/fax(getty|modem).*$' /etc/inittab >/dev/null 2>&1 || grep -E '^exec[ \t]*/usr/sbin/fax(getty|modem)' /etc/init/*.conf >/dev/null 2>&1 || grep -E '^[^#]*:respawn:/usr/local/sbin/fax(getty|modem).*$' /etc/inittab >/dev/null 2>&1
then
USE_FAXGETTY=init
else
USE_FAXGETTY=yes
fi

the last piece of the if is what's needed in /etc/default/faxgetty as we (PIAF/IPBX) add:
t0:23:respawn:/usr/local/sbin/faxgetty ttyIAX0 > /var/log/iaxmodem/iaxmodem.log


t1:23:respawn:/usr/local/sbin/faxgetty ttyIAX1 > /var/log/iaxmodem/iaxmodem.log


t2:23:respawn:/usr/local/sbin/faxgetty ttyIAX2 > /var/log/iaxmodem/iaxmodem.log


t3:23:respawn:/usr/local/sbin/faxgetty ttyIAX3 > /var/log/iaxmodem/iaxmodem.log

to /etc/inittab, and the original coding didn't look for /usr/local/sbin/faxgetty.

I'm wondering if those redirects should be >> to APPEND to the log.....

 

[lrosenman]

there still seems(!) to be a race in the init scripts that start up /usr/local/sbin/faxgetty -D ttyIAX[0-3] in addition to the
inittab ones.

I'll try(!) and find it later, but with those killed off, and the above change, the syslog is MUCH quieter from the faxgetty.

 

[lrosenman]

it's /etc/default/hylafax (the editor is giving me grief)

 

[wardmundy]

Look in /etc/rc.d/rc.local or /etc/rc.local and see if there are duplicate entries.

 

[lrosenman]

bingo -- the /usr/local/sbin/faxgetty -D ttyIAX[0-3] lines were in /etc/rc.local (now removed), as well as 4(!) iptables-restart

 

[lrosenman]

also, /root/iaxmodem-restart has the 4 lines for faxgetty as well -- commented out on my RPI2.

 

[lrosenman]

so, with ONE version of faxgetty running, and the timeouts fixed, the logs are nice and clean.

can we get these fixes integrated at some point?

 

[wardmundy]

Duplicate entries meant within the same file, not in multiple files. Some platforms have /etc/rc.local while others have /etc/rc.d/rc.local while others have one or the other with a symlink to the other. These ARE NOT duplicates! As for /root/iaxmodem-restart, that is a script to let an administrator manually restart iaxmodem and the faxgetty apps without having to reboot. It IS NOT a duplicate. What duplicate entries meant was an rc.local file that looked like this with two of everything:

/usr/local/sbin/faxgetty -D ttyIAX0
/usr/local/sbin/faxgetty -D ttyIAX1
/usr/local/sbin/faxgetty -D ttyIAX2
/usr/local/sbin/faxgetty -D ttyIAX3
/usr/local/sbin/faxgetty -D ttyIAX0
/usr/local/sbin/faxgetty -D ttyIAX1
/usr/local/sbin/faxgetty -D ttyIAX2
/usr/local/sbin/faxgetty -D ttyIAX3
exit 0

 

[lrosenman]

IF you have the starts in /etc/inittab, you do NOT need the lines (AT ALL) in /etc/rc.local.

Else, you wind up with fighting getty's.....

 

[lrosenman]

basically, we need to decide if we use /etc/inittab or rc.local/iaxmodem-restart to deal with the faxgetty process.