Failed fax receive

Ben Stuyts (benst@terminus.stuyts.nl)
Wed, 25 Feb 1998 22:52:41 +0100


Hi Gert,

I have a problem receiving a fax from Motorola's fax-back service 
(http://mot-sps.com/home2/fax_rqst.html). Their system tried to fax me a 
document about 3 times, without any luck. It just disconnects before sending 
any data. FreeBSD-Current, ZyXEL 2864I 2.11, mgetty 1.1.11. Here is the log.

02/25 22:43:26 aa2 mgetty: experimental test release 1.1.11-Dec16
02/25 22:43:26 aa2 check for lockfiles
02/25 22:43:26 aa2 checklock: stat failed, no file
02/25 22:43:26 aa2 locking the line
02/25 22:43:26 aa2 makelock(cuaa2) called
02/25 22:43:26 aa2 do_makelock: lock='/var/spool/lock/LCK..cuaa2'
02/25 22:43:26 aa2 lock made
02/25 22:43:27 aa2 tio_get_rs232_lines: status: RTS CTS DSR DTR
02/25 22:43:27 aa2 lowering DTR to reset Modem
02/25 22:43:27 aa2 tss: set speed to 115200 (341000)
02/25 22:43:27 aa2 tio_set_flow_control( HARD )
02/25 22:43:27 aa2 waiting for line to clear (VTIME), read:
02/25 22:43:28 aa2 send: \d\d\d+++\d\d\dAT&FS2=255[0d]
02/25 22:43:31 aa2 waiting for ``OK''
02/25 22:43:31 aa2 got: AT&FS2=255[0d]
02/25 22:43:31 aa2 CND: AT&FS2=255[0d][0a]OK ** found **
02/25 22:43:31 aa2 send: ATN3S0=0S13.2=1[0d]
02/25 22:43:31 aa2 waiting for ``OK''
02/25 22:43:31 aa2 got: [0d]
02/25 22:43:31 aa2 CND: OK[0a]ATN3S0=0S13.2=1[0d]
02/25 22:43:31 aa2 CND: ATN3S0=0S13.2=1[0d][0a]OK ** found **
02/25 22:43:31 aa2 send: AT[0d]
02/25 22:43:31 aa2 do_stat: expect 'OK' ** found **
02/25 22:43:31 aa2 send: ATI2[0d]
02/25 22:43:31 aa2 do_stat: expect 'OK' ** found **
02/25 22:43:31 aa2 mdm_send: 'ATI'
02/25 22:43:31 aa2 got:[0a]ATI[0d]
02/25 22:43:31 aa2 got:[0d][0a]28642[0d]
02/25 22:43:31 aa2 mdm_gis: string 1: '28642'
02/25 22:43:31 aa2 got:[0a][0d][0a]OK[0d]
02/25 22:43:31 aa2 mdm_identify: string '28642'
02/25 22:43:31 aa2 ZyXEL 2864I(D) detected
02/25 22:43:31 aa2 mdm_send: 'ATI1'
02/25 22:43:31 aa2 got:[0a]ATI1[0d]
02/25 22:43:31 aa2 got:[0d][0a][0d][0a]Elite 2864I DSS1: V 2.11 [0d]
02/25 22:43:31 aa2 mdm_gis: string 1: 'Elite 2864I DSS1: V 2.11 '
02/25 22:43:31 aa2 got:[0a]Internal fax/modem: V 1.16f[0d]
02/25 22:43:31 aa2 mdm_gis: string 2: 'Internal fax/modem: V 1.16f'
02/25 22:43:31 aa2 got:[0a]DFCC[0d]
02/25 22:43:31 aa2 mdm_gis: string 3: 'DFCC'
02/25 22:43:31 aa2 got:[0a][0d][0a]OK[0d]
02/25 22:43:31 aa2 additional info: 'Internal fax/modem: V 1.16f'
02/25 22:43:31 aa2 mdm_send: 'AT+FCLASS=2.0'
02/25 22:43:31 aa2 got:[0a]AT+FCLASS=2.0[0d]
02/25 22:43:31 aa2 mdm_command: string 'AT+FCLASS=2.0'
02/25 22:43:31 aa2 got:[0d][0a]OK[0d]
02/25 22:43:31 aa2 mdm_command: string 'OK' -> OK
02/25 22:43:31 aa2 mdm_send: 'AT+FAA=1;+FCR=1'
02/25 22:43:31 aa2 got:[0a]AT+FAA=1;+FCR=1[0d]
02/25 22:43:31 aa2 mdm_command: string 'AT+FAA=1;+FCR=1'
02/25 22:43:31 aa2 got:[0d][0a]OK[0d]
02/25 22:43:31 aa2 mdm_command: string 'OK' -> OK
02/25 22:43:31 aa2 mdm_send: 'AT+FBO=1'
02/25 22:43:31 aa2 got:[0a]AT+FBO=1[0d]
02/25 22:43:31 aa2 mdm_command: string 'AT+FBO=1'
02/25 22:43:31 aa2 got:[0d][0a]OK[0d]
02/25 22:43:31 aa2 mdm_command: string 'OK' -> OK
02/25 22:43:31 aa2 mdm_send: 'AT+FNR=1,1,1,0'
02/25 22:43:31 aa2 got:[0a]AT+FNR=1,1,1,0[0d]
02/25 22:43:31 aa2 mdm_command: string 'AT+FNR=1,1,1,0'
02/25 22:43:31 aa2 got:[0d][0a]OK[0d]
02/25 22:43:31 aa2 mdm_command: string 'OK' -> OK
02/25 22:43:31 aa2 mdm_send: 'AT+FLI="+31-23-5313386"'
02/25 22:43:31 aa2 got:[0a]AT+FLI="+31-23-5313386"[0d]
02/25 22:43:31 aa2 mdm_command: string 'AT+FLI="+31-23-5313386"'
02/25 22:43:31 aa2 got:[0d][0a]OK[0d]
02/25 22:43:31 aa2 mdm_command: string 'OK' -> OK
02/25 22:43:31 aa2 mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0'
02/25 22:43:31 aa2 got:[0a]AT+FCC=1,5,0,2,0,0,0,0[0d]
02/25 22:43:31 aa2 mdm_command: string 'AT+FCC=1,5,0,2,0,0,0,0'
02/25 22:43:31 aa2 got:[0d][0a]OK[0d]
02/25 22:43:31 aa2 mdm_command: string 'OK' -> OK
02/25 22:43:31 aa2 waiting for line to clear (VTIME), read:
02/25 22:43:32 aa2 removing lock file
02/25 22:43:32 aa2 waiting...
02/25 22:46:18 aa2 select returned 1
02/25 22:46:19 aa2 checking lockfiles, locking the line
02/25 22:46:19 aa2 makelock(cuaa2) called
02/25 22:46:19 aa2 do_makelock: lock='/var/spool/lock/LCK..cuaa2'
02/25 22:46:19 aa2 lock made
02/25 22:46:19 aa2 waiting for ``RING''
02/25 22:46:19 aa2 got: RING ** found **
02/25 22:46:20 aa2 CND: check no: 'none'
02/25 22:46:20 aa2 send: ATA[0d]
02/25 22:46:20 aa2 waiting for ``CONNECT''
02/25 22:46:20 aa2 got: [0d]
02/25 22:46:20 aa2 CND: OKRING[0a]TO:235313386[0d]
02/25 22:46:20 aa2 CND: TO:235313386[0a]ATA[0d]
02/25 22:46:20 aa2 CND: ATA[0d][0a]+FCO[0d]
02/25 22:46:33 aa2 CND: +FCO
02/25 22:46:33 aa2 found action string: ``+FCO_''
02/25 22:46:33 aa2 start fax receiver...
02/25 22:46:33 aa2 fax receiver: entry
02/25 22:46:33 aa2 fax_wait_for(OK)
02/25 22:46:33 aa2 got:[0a][0a][0d][0a]+FHS:73[0d]
02/25 22:46:47 aa2 fax_wait_for: string '+FHS:73'
02/25 22:46:47 aa2 connection hangup: '+FHS:73'
02/25 22:46:47 aa2 (T.30 T2 timeout, expected page not received)
02/25 22:46:47 aa2 got:[0a][0d][0a]OK[0d]
02/25 22:46:47 aa2 fax_wait_for: string 'OK'** found **
02/25 22:46:48 aa2 utmp + wtmp entry made
02/25 22:46:48 aa2 tio_set_flow_control( HARD XON_IN )
02/25 22:46:48 aa2 mdm_send: 'AT+FLO=2'
02/25 22:46:48 aa2 got:[0a][0d][0a]NO CARRIER[0d]
02/25 22:46:48 aa2 mdm_command: string 'NO CARRIER'
02/25 22:46:48 aa2 got:[0a]AT+FLO=2[0d]
02/25 22:46:48 aa2 mdm_command: string 'AT+FLO=2'
02/25 22:46:48 aa2 got:[0d][0a]OK[0d]
02/25 22:46:48 aa2 mdm_command: string 'OK' -> OK
02/25 22:46:48 aa2 fax_get_pages: no pages to receive
02/25 22:46:48 aa2 fax receiver: hangup & end
02/25 22:46:48 aa2 fax_notify_mail: sending mail to: faxadmin
02/25 22:46:49 aa2 notify: '/usr/local/lib/mgetty+sendfax/new_fax 73 '' 0 
>/dev/console 2>&1 </dev/null'
02/25 22:46:49 ##### fax dev=cuaa2, pid=4566, caller='none', name='', id='', 
+FHNG=073, pages=0, time=00:00:28

The system was heavily loaded during this. Might that be of influence? (I've 
never had *that* problem before, though.)

Best regards,
Ben
.