Target 28k8 dead after fax received

Hans (hans@comerwell.xs4all.nl)
Mon, 9 Nov 1998 12:45:06 +0100


I'm testing my own poor 28k8 faxmodem again. It receives faxes from the
faxmodem in my other pc, but after receiving a fax it seems dead for about 8
minutes. (Must have been a hard job ;-)

I once killed mgetty and tried some AT commands in minicom, but the modem
does not respond at all.

BTW: It's cheap testing, because I dial only a '3' so the call goes through
the Dutch PTT's Quattrovox in my room. I don't have to pay the
(monopolistic) telecom provider KPN.

Here's the log (removed phone numbers):

11/09 11:05:47 yS2    select returned 1
11/09 11:05:47 yS2   checking lockfiles, locking the line
11/09 11:05:47 yS2   makelock(ttyS2) called
11/09 11:05:47 yS2   do_makelock: lock='/var/lock/LCK..ttyS2'
11/09 11:05:47 yS2   lock made
11/09 11:05:47 yS2  wfr: waiting for ``RING''
11/09 11:05:47 yS2   got: [0a][0d][0a]RING[0d]
11/09 11:05:47 yS2    CND: RING
11/09 11:05:47 yS2   wfr: rc=0, drn=0
11/09 11:05:47 yS2  send: ATA[0d]
11/09 11:05:47 yS2  waiting for ``CONNECT''
11/09 11:05:47 yS2   got: ATA[0d]
11/09 11:05:47 yS2    CND: OKATA[0d][0a]FAX
11/09 11:05:49 yS2  found action string: ``FAX''
11/09 11:05:49 yS2  start fax receiver...
11/09 11:05:49 yS2   fax receiver: entry
11/09 11:05:49 yS2   tss: set speed to 19200 (016)
11/09 11:05:49 yS2  fax_wait_for(OK)
11/09 11:05:49 yS2    got:[0a][0d][0a][1c][fc]+FTSI: 
                           "    +31(0)xx-remotephone"[0d]
11/09 11:05:56 yS2   fax_wait_for: string '+FTSI: 
                           "    +31(0)xx-remotephone"'
11/09 11:05:56 yS2  fax_id: '+FTSI: "    +31(0)xx-remotephone"'
11/09 11:05:56 yS2    got:[0a]+FDCS: 1,5,0,2,0,0,0,0[0d]
11/09 11:05:56 yS2   fax_wait_for: string '+FDCS: 1,5,0,2,0,0,0,0'
11/09 11:05:56 yS2  transmission par.: '+FDCS: 1,5,0,2,0,0,0,0'
11/09 11:05:56 yS2    got:[0a][0d][0a]OK[0d]
11/09 11:06:00 yS2   fax_wait_for: string 'OK'** found **
11/09 11:06:00 yS2    looking for utmp entry... (my PID: 381)
11/09 11:06:00 yS2   utmp + wtmp entry made
11/09 11:06:00 yS2   tio_set_flow_control( HARD XON_IN )
11/09 11:06:00 yS2  fax_send: 'AT+FDR'
11/09 11:06:00 yS2  fax_wait_for(CONNECT)
11/09 11:06:00 yS2    got:[0a]AT+FDR[0d]
11/09 11:06:00 yS2   fax_wait_for: string 'AT+FDR'
11/09 11:06:00 yS2    got:[0d][0a]+FCFR[0d]
11/09 11:06:01 yS2   fax_wait_for: string '+FCFR'
11/09 11:06:01 yS2    got:[0a]+FDCS: 1,5,0,2,0,0,0,0[0d]
11/09 11:06:01 yS2   fax_wait_for: string '+FDCS: 1,5,0,2,0,0,0,0'
11/09 11:06:01 yS2  transmission par.: '+FDCS: 1,5,0,2,0,0,0,0'
11/09 11:06:01 yS2    got:[0a][0d][0a]CONNECT[0d]
11/09 11:06:01 yS2   fax_wait_for: string 'CONNECT'** found **
11/09 11:06:01 yS2   sending DC2
11/09 11:06:01 yS2   fax_get_page_data: wait for EOL, got: 
                                                  [0a][ff][14][d9][a8][00]
11/09 11:06:01 yS2  fax_get_page_data: receiving 
             /var/spool/fax/incoming/ff646be7bS2-_-+31-0-xx-remotephone_.01...
11/09 11:06:14 yS2  fax_get_page_data: page end, bytes received: 22331
11/09 11:06:14 yS2  fax_wait_for(OK)
11/09 11:06:14 yS2    got:[0d][0a]+FPTS: 1[0d]
11/09 11:06:14 yS2   fax_wait_for: string '+FPTS: 1'
11/09 11:06:14 yS2  page status: +FPTS: 1
11/09 11:06:14 yS2    got:[0a][0d][0a]+FET: 2[0d]
11/09 11:06:15 yS2   fax_wait_for: string '+FET: 2'
11/09 11:06:15 yS2    got:[0a][0d][0a]OK[0d]
11/09 11:06:15 yS2   fax_wait_for: string 'OK'** found **
11/09 11:06:16 yS2  fax_send: 'AT+FDR'
11/09 11:06:16 yS2  fax_wait_for(CONNECT)
11/09 11:06:16 yS2    got:[0a]AT+FDR[0d]
11/09 11:06:16 yS2   fax_wait_for: string 'AT+FDR'
11/09 11:06:16 yS2    got:[0d][0a]+FHNG: 0[0d]
11/09 11:06:19 yS2   fax_wait_for: string '+FHNG: 0'
11/09 11:06:19 yS2  connection hangup: '+FHNG: 0'
11/09 11:06:19 yS2   (Normal and proper end of connection)** found **
11/09 11:06:19 yS2   fax receiver: hangup & end
11/09 11:06:19 yS2   fax_notify_mail: sending mail to: faxadmin
11/09 11:06:19 ##### fax dev=ttyS2, pid=381, caller='none', name='', 
         id='_    +31(0)xx-remotephone_', +FHNG=000, pages=1, time=00:00:32

(so far good, it seems)

11/09 11:06:20 yS2  mdm_send: 'ATH0'
11/09 11:06:20 yS2    got:[0a][0d][0a]OK[0d]
11/09 11:06:20 yS2   mdm_command: string 'OK' -> OK
11/09 11:06:20 yS2   removing lock file
--
11/09 11:06:20 yS2  mgetty: experimental test release 1.1.18-Sep11
11/09 11:06:20 yS2  check for lockfiles
11/09 11:06:20 yS2   checklock: stat failed, no file
11/09 11:06:20 yS2  locking the line
11/09 11:06:20 yS2   makelock(ttyS2) called
11/09 11:06:20 yS2   do_makelock: lock='/var/lock/LCK..ttyS2'
11/09 11:06:20 yS2   lock made
11/09 11:06:21 yS2   tio_get_rs232_lines: status: RTS CTS DSR
11/09 11:06:21 yS2  lowering DTR to reset Modem
11/09 11:06:22 yS2   tss: set speed to 115200 (10002)
11/09 11:06:22 yS2   tio_set_flow_control( HARD )
11/09 11:06:22 yS2   waiting for line to clear (VTIME), read: 
11/09 11:06:22 yS2  send: ATZ[0d]
11/09 11:06:22 yS2  waiting for ``OK''
11/09 11:06:22 yS2   got: ATZ[0d]
11/09 11:06:22 yS2    CND: ATZ
11/09 11:06:42 yS2  timeout in chat script, waiting for `OK'
11/09 11:06:42 yS2  init chat timed out, trying force-init-chat
11/09 11:06:42 yS2  send: \d[10][03]\d\d\d+++\d\d\d[0d]\dATQ0V1H0[0d]
11/09 11:06:46 yS2  waiting for ``OK''
11/09 11:06:46 yS2   got: [10][03]+++[0d]
11/09 11:06:46 yS2    CND: __+++ATQ0V1H0[0d]
11/09 11:06:46 yS2    CND: ATQ0V1H0
11/09 11:07:06 yS2  timeout in chat script, waiting for `OK'
11/09 11:07:06 yS2  init chat failed, exiting...: Interrupted system call
11/09 11:07:06 ##### failed in mg_init_data, dev=ttyS2, pid=389

11/09 11:07:06 yS2   removing lock file
--

....... 12x restart! ..........

--
11/09 11:14:39 yS2  mgetty: experimental test release 1.1.18-Sep11
11/09 11:14:39 yS2  check for lockfiles
11/09 11:14:39 yS2   checklock: stat failed, no file
11/09 11:14:39 yS2  locking the line
11/09 11:14:39 yS2   makelock(ttyS2) called
11/09 11:14:39 yS2   do_makelock: lock='/var/lock/LCK..ttyS2'
11/09 11:14:39 yS2   lock made
11/09 11:14:40 yS2   tio_get_rs232_lines: status: RTS CTS DSR DTR
11/09 11:14:40 yS2  lowering DTR to reset Modem
11/09 11:14:40 yS2   tss: set speed to 115200 (10002)
11/09 11:14:40 yS2   tio_set_flow_control( HARD )
11/09 11:14:40 yS2   waiting for line to clear (VTIME), read: 
11/09 11:14:41 yS2  send: ATZ[0d]
11/09 11:14:41 yS2  waiting for ``OK''
11/09 11:14:41 yS2   got: ATZ[0d]
11/09 11:14:41 yS2    CND: ATZ[e0][e0][00][00][e0][00][e0][e0][00][e0]
                     [00][00][e0][e0][00][00][e0][e0][e0][00][e0][00]
                     [00][e0][e0][e0][e0][00][00][e0][00]
11/09 11:15:01 yS2  timeout in chat script, waiting for `OK'
11/09 11:15:01 yS2  init chat timed out, trying force-init-chat
11/09 11:15:01 yS2  send: \d[10][03]\d\d\d+++\d\d\d[0d]\dATQ0V1H0[0d]
11/09 11:15:05 yS2  waiting for ``OK''
11/09 11:15:05 yS2   got: [10][03]+++[0d]
11/09 11:15:05 yS2    CND: __ATQ0V1H0[0d]
11/09 11:15:05 yS2    CND: ATQ0V1H0[0d][0a]OK ** found **
11/09 11:15:05 yS2   force-init succeeded, retrying init-chat
11/09 11:15:05 yS2   waiting for line to clear (VTIME), read: [0d][0a]
11/09 11:15:06 yS2  send: ATZ[0d]
11/09 11:15:06 yS2  waiting for ``OK''
11/09 11:15:06 yS2   got: ATZ[0d]
11/09 11:15:06 yS2    CND: OKATZ[0d][0a]OK ** found **
11/09 11:15:06 yS2  mdm_send: 'ATI'
11/09 11:15:06 yS2    got:[0d][0a]ATI[0d]
11/09 11:15:06 yS2    got:[0d][0a]288[0d]
11/09 11:15:07 yS2   mdm_gis: string 1: '288'
11/09 11:15:07 yS2    got:[0a][0d][0a]OK[0d]
11/09 11:15:07 yS2   mdm_identify: string '288'
11/09 11:15:07 yS2  Trust Communicator 28 K8 detected
11/09 11:15:07 yS2  modem quirks: 0001
11/09 11:15:07 yS2  mdm_send: 'AT+FCLASS=2'
11/09 11:15:07 yS2    got:[0a]AT+FCLASS=2[0d]
11/09 11:15:07 yS2   mdm_command: string 'AT+FCLASS=2'
11/09 11:15:07 yS2    got:[0d][0a]OK[0d]
11/09 11:15:07 yS2   mdm_command: string 'OK' -> OK
11/09 11:15:07 yS2  mdm_send: 'AT+FAA=1;+FCR=1'
11/09 11:15:07 yS2    got:[0a]AT+FAA=1;+FCR=1[0d]
11/09 11:15:07 yS2   mdm_command: string 'AT+FAA=1;+FCR=1'
11/09 11:15:07 yS2    got:[0d][0a]OK[0d]
11/09 11:15:07 yS2   mdm_command: string 'OK' -> OK
11/09 11:15:07 yS2  mdm_send: 'AT+FBOR=0'
11/09 11:15:07 yS2    got:[0a]AT+FBOR=0[0d]
11/09 11:15:07 yS2   mdm_command: string 'AT+FBOR=0'
11/09 11:15:07 yS2    got:[0d][0a]OK[0d]
11/09 11:15:07 yS2   mdm_command: string 'OK' -> OK
11/09 11:15:07 yS2  mdm_send: 'AT+FLID="+31-(0)xx-myphone"'
11/09 11:15:07 yS2    got:[0a]AT+FLID="+31-(0)xx-myphone"[0d]
11/09 11:15:07 yS2   mdm_command: string 'AT+FLID="+31-(0)xx-myphone"'
11/09 11:15:07 yS2    got:[0d][0a]OK[0d]
11/09 11:15:07 yS2   mdm_command: string 'OK' -> OK
11/09 11:15:07 yS2  mdm_send: 'AT+FDCC=1,5,0,2,0,0,0,0'
11/09 11:15:07 yS2    got:[0a]AT+FDCC=1,5,0,2,0,0,0,0[0d]
11/09 11:15:07 yS2   mdm_command: string 'AT+FDCC=1,5,0,2,0,0,0,0'
11/09 11:15:07 yS2    got:[0d][0a]OK[0d]
11/09 11:15:07 yS2   mdm_command: string 'OK' -> OK
11/09 11:15:07 yS2   waiting for line to clear (VTIME), read: 
11/09 11:15:07 yS2   removing lock file
11/09 11:15:07 yS2  waiting...



====================== mid output:
testing for modem on /dev/ttyS2 with 38400 bps...
>>> ATI
ATI
288

OK
>>> ATI0
ATI0
288

OK
>>> ATI1
ATI1
253

OK
>>> ATI2
ATI2
OK

OK
>>> ATI3
ATI3
WS-2814IM4
VERSION 1.00.4
02-05-01

OK
>>> ATI4
ATI4
OK
>>> ATI5
ATI5
COUNTRY DEFAULT : 022
COUNTRY SETTING : 022

OK
>>> ATI6
ATI6
OK
>>> ATI7
ATI7
OK
>>> ATI8
ATI8
OK
>>> ATI9
ATI9
OK
>>> ATI10
ATI10
OK
>>> ATI11
ATI11
OK
>>> ATI12
ATI12
OK
>>> ATI13
ATI13
OK
>>> ATI14
ATI14
OK
>>> ATI15
ATI15
OK
>>> AT+FCLASS=?
AT+FCLASS=?
0,1,2

OK
>>> AT+FMFR?
AT+FMFR?
CIS

OK
>>> AT+FMDL?
AT+FMDL?
WS-2814IM4
VERSION 1.00.4
02-05-01

OK
>>> AT+FREV?
AT+FREV?VERSION 1.00.4
02-05-01

OK
>>> AT+FMI?
AT+FMI?
ERROR
>>> AT+FMM?
AT+FMM?
ERROR
>>> AT+FMR?
AT+FMR?
ERROR
========================

Hans