vgetty/mgetty - different fax reception ?
Dmitry Pogosyan (pogosyan@cita.utoronto.ca)
Fri, 7 May 1999 21:59:05 -0400
Hi all !
Few days (ZOOM - slow fax reception) ago I asked about advice on why my
fax reception with ZOOM 2919 faxmodem and vgetty-1.1.19 is always slow.
I tried sending fax from two fax machine (say A and B), and reception was
always in +FDCS=0,0,0,0,0,0,0,5 mode. Irrespectively of me
trying to send fax in fine resolution or not.
I used default initialization string for vgetty, so only option in
voice.conf I could imagine relevant was enabling fax:data autodetection.
Today I launched just mgetty binary in place of vgetty. Did not touch
any configuration files. Results were quite different. Reception
from one of my remote trial faxes (A) now was consistently
very nice +FDCS=1,5,0,2,0,0,0,3. The second fax machine (B, in my office)
was actually replaced this week. Brand new Ricoh fax again produced
only 2400 bps reception at my mode, however high/normal resolution
was handled properly. The reception mode was 1,0,0,2,0,0,0,1.
I'd appreciate if experts can explain me how vgetty and mgetty
reception could be different, and what should I do to achieve
consistent not too low speed of fax reception.
I have included my recent log with mgetty below (2 calls + initialization
stage - at the end) Sorry for it's length.
Best regards, Dmitri
05/07 18:51:37 yS3 wfr: waiting for ``RING''
05/07 18:51:37 yS3 got: [0d][0a]RING[0d]
05/07 18:51:37 yS3 CND: RING
05/07 18:51:37 yS3 wfr: rc=0, drn=0
05/07 18:52:01 yS3 CND: check no: 'none'
05/07 18:52:01 yS3 send: ATA[0d]
05/07 18:52:01 yS3 waiting for ``CONNECT''
05/07 18:52:01 yS3 got: ATA[0d]
05/07 18:52:01 yS3 CND: OKATA[0d][0a]FAX
05/07 18:52:03 yS3 found action string: ``FAX''
05/07 18:52:03 yS3 start fax receiver...
05/07 18:52:03 yS3 fax receiver: entry
05/07 18:52:03 yS3 fax_wait_for(OK)
05/07 18:52:03 yS3 got:[0a][0d][0a][0d][0a]+FCON[0d]
05/07 18:52:09 yS3 fax_wait_for: string '+FCON'
05/07 18:52:09 yS3 got:[0a][0d][0a]+FTSI: " 14169783921"[0d]
05/07 18:52:11 yS3 fax_wait_for: string '+FTSI: " 14169783921"'
05/07 18:52:11 yS3 fax_id: '+FTSI: " 14169783921"'
05/07 18:52:11 yS3 got:[0a][0d][0a]+FDCS: 1,0,0,2,0,0,0,1[0d]
05/07 18:52:11 yS3 fax_wait_for: string '+FDCS: 1,0,0,2,0,0,0,1'
05/07 18:52:11 yS3 transmission par.: '+FDCS: 1,0,0,2,0,0,0,1'
05/07 18:52:11 yS3 got:[0a][0d][0a]OK[0d]
05/07 18:52:11 yS3 fax_wait_for: string 'OK'** found **
05/07 18:52:11 yS3 looking for utmp entry... (my PID: 4203)
05/07 18:52:11 yS3 utmp + wtmp entry made
05/07 18:52:11 yS3 tio_set_flow_control( HARD XON_IN )
05/07 18:52:11 yS3 fax_send: 'AT+FDR'
05/07 18:52:11 yS3 fax_wait_for(CONNECT)
05/07 18:52:11 yS3 got:[0a]AT+FDR[0d]
05/07 18:52:11 yS3 fax_wait_for: string 'AT+FDR'
05/07 18:52:11 yS3 got:[0d][0a]+FCFR[0d]
05/07 18:52:14 yS3 fax_wait_for: string '+FCFR'
05/07 18:52:14 yS3 got:[0a][0d][0a]+FDCS: 1,0,0,2,0,0,0,1[0d]
05/07 18:52:17 yS3 fax_wait_for: string '+FDCS: 1,0,0,2,0,0,0,1'
05/07 18:52:17 yS3 transmission par.: '+FDCS: 1,0,0,2,0,0,0,1'
05/07 18:52:17 yS3 got:[0a][0d][0a]CONNECT[0d]
05/07 18:52:17 yS3 fax_wait_for: string 'CONNECT'** found **
05/07 18:52:17 yS3 sending DC2
05/07 18:52:17 yS3 fax_get_page_data: wait for EOL, got: [0a]T[ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][c0][05]6j[00]
05/07 18:52:17 yS3 fax_get_page_data: receiving /var/spool/fax/incoming/ff7336e91S3-14169783921.01...
05/07 18:55:50 yS3 fax_get_page_data: page end, bytes received: 64167
05/07 18:55:50 yS3 fax_wait_for(OK)
05/07 18:55:50 yS3 got:[0d][0a]+FPTS: 1,2219,0,0[0d]
05/07 18:55:50 yS3 fax_wait_for: string '+FPTS: 1,2219,0,0'
05/07 18:55:50 yS3 page status: +FPTS: 1,2219,0,0
05/07 18:55:50 yS3 2219 lines received, 0 lines bad, 0 bytes lost
05/07 18:55:50 yS3 got:[0a][0d][0a]+FET: 2[0d]
05/07 18:55:52 yS3 fax_wait_for: string '+FET: 2'
05/07 18:55:52 yS3 got:[0a][0d][0a]OK[0d]
05/07 18:55:52 yS3 fax_wait_for: string 'OK'** found **
05/07 18:55:52 yS3 fax_send: 'AT+FDR'
05/07 18:55:52 yS3 fax_wait_for(CONNECT)
05/07 18:55:52 yS3 got:[0a]AT+FDR[0d]
05/07 18:55:52 yS3 fax_wait_for: string 'AT+FDR'
05/07 18:55:52 yS3 got:[0d][0a]+FHNG: 0[0d]
05/07 18:55:55 yS3 fax_wait_for: string '+FHNG: 0'
05/07 18:55:55 yS3 connection hangup: '+FHNG: 0'
05/07 18:55:55 yS3 (Normal and proper end of connection)** found **
05/07 18:55:55 yS3 fax receiver: hangup & end
05/07 18:55:56 yS3 mdm_send: 'ATH0'
05/07 18:55:56 yS3 got:[0a][0d][0a]OK[0d]
05/07 18:55:56 yS3 mdm_command: string 'OK' -> OK
05/07 18:55:56 yS3 removing lock file
--
05/07 21:05:26 yS3 select returned 1
05/07 21:05:26 yS3 checking lockfiles, locking the line
05/07 21:05:26 yS3 makelock(ttyS3) called
05/07 21:05:26 yS3 do_makelock: lock='/var/lock/LCK..ttyS3'
05/07 21:05:26 yS3 lock made
05/07 21:05:26 yS3 wfr: waiting for ``RING''
05/07 21:05:26 yS3 got: [0d][0a]RING[0d]
05/07 21:05:26 yS3 CND: RING
05/07 21:05:26 yS3 wfr: rc=0, drn=0
05/07 21:05:26 yS3 wfr: waiting for ``RING''
05/07 21:05:50 yS3 CND: check no: 'none'
05/07 21:05:50 yS3 send: ATA[0d]
05/07 21:05:50 yS3 waiting for ``CONNECT''
05/07 21:05:50 yS3 got: ATA[0d]
05/07 21:05:50 yS3 CND: OKATA[0d][0a]FAX
05/07 21:05:54 yS3 found action string: ``FAX''
05/07 21:05:54 yS3 start fax receiver...
05/07 21:05:54 yS3 fax receiver: entry
05/07 21:05:54 yS3 fax_wait_for(OK)
05/07 21:05:54 yS3 got:[0a][0d][0a][0d][0a]+FCON[0d]
05/07 21:05:59 yS3 fax_wait_for: string '+FCON'
05/07 21:05:59 yS3 got:[0a][0d][0a]+FDCS: 1,5,0,2,0,0,0,3[0d]
05/07 21:06:01 yS3 fax_wait_for: string '+FDCS: 1,5,0,2,0,0,0,3'
05/07 21:06:01 yS3 transmission par.: '+FDCS: 1,5,0,2,0,0,0,3'
05/07 21:06:01 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:06:01 yS3 fax_wait_for: string 'OK'** found **
05/07 21:06:01 yS3 looking for utmp entry... (my PID: 4332)
05/07 21:06:01 yS3 utmp + wtmp entry made
05/07 21:06:01 yS3 tio_set_flow_control( HARD XON_IN )
05/07 21:06:01 yS3 fax_send: 'AT+FDR'
05/07 21:06:01 yS3 fax_wait_for(CONNECT)
05/07 21:06:01 yS3 got:[0a]AT+FDR[0d]
05/07 21:06:01 yS3 fax_wait_for: string 'AT+FDR'
05/07 21:06:01 yS3 got:[0d][0a]+FCFR[0d]
05/07 21:06:04 yS3 fax_wait_for: string '+FCFR'
05/07 21:06:04 yS3 got:[0a][0d][0a]+FDCS: 1,5,0,2,0,0,0,3[0d]
05/07 21:06:06 yS3 fax_wait_for: string '+FDCS: 1,5,0,2,0,0,0,3'
05/07 21:06:06 yS3 transmission par.: '+FDCS: 1,5,0,2,0,0,0,3'
05/07 21:06:06 yS3 got:[0a][0d][0a]CONNECT[0d]
05/07 21:06:06 yS3 fax_wait_for: string 'CONNECT'** found **
05/07 21:06:06 yS3 sending DC2
05/07 21:06:06 yS3 fax_get_page_data: wait for EOL, got: [0a][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][c0][00]
05/07 21:06:06 yS3 fax_get_page_data: receiving /var/spool/fax/incoming/ff7338deeS3.01...
05/07 21:06:28 yS3 fax_get_page_data: page end, bytes received: 39234
05/07 21:06:28 yS3 fax_wait_for(OK)
05/07 21:06:28 yS3 got:[0d][0a]+FPTS: 1,2219,0,0[0d]
05/07 21:06:28 yS3 fax_wait_for: string '+FPTS: 1,2219,0,0'
05/07 21:06:28 yS3 page status: +FPTS: 1,2219,0,0
05/07 21:06:28 yS3 2219 lines received, 0 lines bad, 0 bytes lost
05/07 21:06:28 yS3 got:[0a][0d][0a]+FET: 2[0d]
05/07 21:06:29 yS3 fax_wait_for: string '+FET: 2'
05/07 21:06:29 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:06:29 yS3 fax_wait_for: string 'OK'** found **
05/07 21:06:29 yS3 fax_send: 'AT+FDR'
05/07 21:06:29 yS3 fax_wait_for(CONNECT)
05/07 21:06:29 yS3 got:[0a]AT+FDR[0d]
05/07 21:06:29 yS3 fax_wait_for: string 'AT+FDR'
05/07 21:06:29 yS3 got:[0d][0a]+FHNG: 0[0d]
05/07 21:06:32 yS3 fax_wait_for: string '+FHNG: 0'
05/07 21:06:32 yS3 connection hangup: '+FHNG: 0'
05/07 21:06:32 yS3 (Normal and proper end of connection)** found **
05/07 21:06:32 yS3 fax receiver: hangup & end
05/07 21:06:33 yS3 mdm_send: 'ATH0'
05/07 21:06:33 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:06:33 yS3 mdm_command: string 'OK' -> OK
05/07 21:06:33 yS3 removing lock file
--
05/07 21:06:33 yS3 mgetty: experimental test release 1.1.19-Nov24
05/07 21:06:33 yS3 mgetty.c compiled at Jan 21 1999, 09:50:33
05/07 21:06:33 yS3 user id: 0, parent pid: 1
05/07 21:06:33 yS3 reading configuration data for port 'ttyS3'
05/07 21:06:33 yS3 reading /etc/mgetty+sendfax/mgetty.config...
05/07 21:06:33 yS3 conf lib: read: 'debug 4'
05/07 21:06:33 yS3 conf lib: read: 'fax-id 1 416 466 4028'
05/07 21:06:33 yS3 conf lib: read: 'speed 115200'
05/07 21:06:33 yS3 conf lib: read: 'rings 5'
05/07 21:06:33 yS3 conf lib: read: 'port ttyS3'
05/07 21:06:33 yS3 section: port ttyS3, **found**
05/07 21:06:33 yS3 key: 'speed', type=0, flags=3, data=115200
05/07 21:06:33 yS3 key: 'switchbd', type=0, flags=1, data=0
05/07 21:06:33 yS3 key: 'direct', type=3, flags=1, data=FALSE
05/07 21:06:33 yS3 key: 'blocking', type=3, flags=1, data=FALSE
05/07 21:06:33 yS3 key: 'port-owner', type=1, flags=1, data=uucp
05/07 21:06:33 yS3 key: 'port-group', type=1, flags=1, data=uucp
05/07 21:06:33 yS3 key: 'port-mode', type=0, flags=1, data=432
05/07 21:06:33 yS3 key: 'toggle-dtr', type=3, flags=1, data=TRUE
05/07 21:06:33 yS3 key: 'toggle-dtr-waittime', type=0, flags=1, data=500
05/07 21:06:33 yS3 key: 'data-only', type=3, flags=1, data=FALSE
05/07 21:06:33 yS3 key: 'fax-only', type=3, flags=1, data=FALSE
05/07 21:06:33 yS3 key: 'modem-type', type=1, flags=1, data=auto
05/07 21:06:33 yS3 key: 'modem-quirks', type=0, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'init-chat', type=2, flags=1, data= \dATQ0V1H0 OK ATS0=0Q0&D3&C1 OK
05/07 21:06:33 yS3 key: 'force-init-chat', type=2, flags=1, data= \d\d\d\d+++\d\d\d
\dATQ0V1H0 OK
05/07 21:06:33 yS3 key: 'post-init-chat', type=2, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'modem-check-time', type=0, flags=1, data=3600
05/07 21:06:33 yS3 key: 'rings', type=0, flags=3, data=5
05/07 21:06:33 yS3 key: 'msn-list', type=2, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'get-cnd-chat', type=2, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'cnd-program', type=1, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'answer-chat', type=2, flags=1, data= ATA CONNECT \c
05/07 21:06:33 yS3 key: 'answer-chat-timeout', type=0, flags=1, data=80
05/07 21:06:33 yS3 key: 'autobauding', type=3, flags=1, data=FALSE
05/07 21:06:33 yS3 key: 'ringback', type=3, flags=1, data=FALSE
05/07 21:06:33 yS3 key: 'ringback-time', type=0, flags=1, data=30
05/07 21:06:33 yS3 key: 'ignore-carrier', type=3, flags=1, data=FALSE
05/07 21:06:33 yS3 key: 'issue-file', type=1, flags=1, data=/etc/issue
05/07 21:06:33 yS3 key: 'prompt-waittime', type=0, flags=1, data=500
05/07 21:06:33 yS3 key: 'login-prompt', type=1, flags=1, data=@ login:
05/07 21:06:33 yS3 key: 'login-time', type=0, flags=1, data=240
05/07 21:06:33 yS3 key: 'fido-send-emsi', type=3, flags=1, data=TRUE
05/07 21:06:33 yS3 key: 'fax-id', type=1, flags=3, data=1 416 466 4028
05/07 21:06:33 yS3 key: 'fax-min-speed', type=0, flags=1, data=0
05/07 21:06:33 yS3 key: 'fax-max-speed', type=0, flags=1, data=14400
05/07 21:06:33 yS3 key: 'fax-server-file', type=1, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'diskspace', type=0, flags=1, data=5120
05/07 21:06:33 yS3 key: 'notify', type=1, flags=1, data=root
05/07 21:06:33 yS3 key: 'fax-owner', type=1, flags=1, data=uucp
05/07 21:06:33 yS3 key: 'fax-group', type=1, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'fax-mode', type=0, flags=1, data=432
05/07 21:06:33 yS3 key: 'debug', type=0, flags=2, data=9
05/07 21:06:33 yS3 key: 'statistics-chat', type=2, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'statistics-file', type=1, flags=0, data=(empty)
05/07 21:06:33 yS3 key: 'gettydefs', type=1, flags=1, data=n
05/07 21:06:33 yS3 key: 'term', type=1, flags=0, data=(empty)
05/07 21:06:33 yS3 check for lockfiles
05/07 21:06:33 yS3 checklock: stat failed, no file
05/07 21:06:33 yS3 locking the line
05/07 21:06:33 yS3 makelock(ttyS3) called
05/07 21:06:33 yS3 do_makelock: lock='/var/lock/LCK..ttyS3'
05/07 21:06:33 yS3 lock made
05/07 21:06:34 yS3 tio_get_rs232_lines: status: RTS CTS DSR DTR
05/07 21:06:34 yS3 lowering DTR to reset Modem
05/07 21:06:34 yS3 tss: set speed to 115200 (10002)
05/07 21:06:34 yS3 tio_set_flow_control( HARD )
05/07 21:06:34 yS3 waiting for line to clear (VTIME), read:
05/07 21:06:35 yS3 send: \dATQ0V1H0[0d]
05/07 21:06:35 yS3 waiting for ``OK''
05/07 21:06:35 yS3 got: ATQ0V1H0[0d]
05/07 21:06:35 yS3 CND: ATQ0V1H0[0d][0a]OK ** found **
05/07 21:06:35 yS3 send: ATS0=0Q0&D3&C1[0d]
05/07 21:06:35 yS3 waiting for ``OK''
05/07 21:06:35 yS3 got: [0d]
05/07 21:06:35 yS3 CND: OK[0a]ATS0=0Q0&D3&C1[0d]
05/07 21:06:35 yS3 CND: ATS0=0Q0&D3&C1[0d][0a]OK ** found **
05/07 21:06:35 yS3 mdm_send: 'ATI'
05/07 21:06:35 yS3 got:[0d][0a]ATI[0d]
05/07 21:06:35 yS3 got:[0d][0a]56000[0d]
05/07 21:06:35 yS3 mdm_gis: string 1: '56000'
05/07 21:06:35 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:06:35 yS3 mdm_identify: string '56000'
05/07 21:06:35 yS3 Generic Rockwell modem (56000)
05/07 21:06:35 yS3 mdm_send: 'ATI3'
05/07 21:06:35 yS3 got:[0a]ATI3[0d]
05/07 21:06:35 yS3 got:[0d][0a]V2.081-K56_2M_DLP-C Z201[0d]
05/07 21:06:35 yS3 mdm_gis: string 1: 'V2.081-K56_2M_DLP-C Z201'
05/07 21:06:35 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:06:35 yS3 mdm_send: 'ATI4'
05/07 21:06:35 yS3 got:[0a]ATI4[0d]
05/07 21:06:35 yS3 got:[0d][0a]a007880284C6002F[0d]
05/07 21:06:35 yS3 mdm_gis: string 1: 'a007880284C6002F'
05/07 21:06:35 yS3 got:[0a][0d][0a]bC60000000[0d]
05/07 21:06:35 yS3 mdm_gis: string 2: 'bC60000000'
05/07 21:06:35 yS3 got:[0a][0d][0a]r1005111151012004[0d]
05/07 21:06:35 yS3 mdm_gis: string 3: 'r1005111151012004'
05/07 21:06:35 yS3 got:[0a][0d][0a]r3000111170000000[0d]
05/07 21:06:35 yS3 mdm_gis: string 4: 'r3000111170000000'
05/07 21:06:35 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:06:35 yS3 additional info: 'a007880284C6002F'
05/07 21:06:35 yS3 modem quirks: 0004
05/07 21:06:35 yS3 mdm_send: 'AT+FCLASS=2'
05/07 21:06:35 yS3 got:[0a]AT+FCLASS=2[0d]
05/07 21:06:35 yS3 mdm_command: string 'AT+FCLASS=2'
05/07 21:06:35 yS3 got:[0d][0a]OK[0d]
05/07 21:06:35 yS3 mdm_command: string 'OK' -> OK
05/07 21:06:36 yS3 mdm_send: 'AT+FCLASS=0'
05/07 21:06:36 yS3 got:[0a]AT+FCLASS=0[0d]
05/07 21:06:36 yS3 mdm_command: string 'AT+FCLASS=0'
05/07 21:06:36 yS3 got:[0d][0a]OK[0d]
05/07 21:06:36 yS3 mdm_command: string 'OK' -> OK
05/07 21:06:36 yS3 mdm_send: 'AT+FAA=1;+FCR=1'
05/07 21:06:36 yS3 got:[0a]AT+FAA=1;+FCR=1[0d]
05/07 21:06:36 yS3 mdm_command: string 'AT+FAA=1;+FCR=1'
05/07 21:06:36 yS3 got:[0d][0a]OK[0d]
05/07 21:06:36 yS3 mdm_command: string 'OK' -> OK
05/07 21:06:36 yS3 mdm_send: 'AT+FBOR=0'
05/07 21:06:36 yS3 got:[0a]AT+FBOR=0[0d]
05/07 21:06:36 yS3 mdm_command: string 'AT+FBOR=0'
05/07 21:06:36 yS3 got:[0d][0a]OK[0d]
05/07 21:06:36 yS3 mdm_command: string 'OK' -> OK
05/07 21:06:36 yS3 mdm_send: 'AT+FLID="1 416 466 4028"'
05/07 21:06:36 yS3 got:[0a]AT+FLID="1 416 466 4028"[0d]
05/07 21:06:36 yS3 mdm_command: string 'AT+FLID="1 416 466 4028"'
05/07 21:06:36 yS3 got:[0d][0a]OK[0d]
05/07 21:06:36 yS3 mdm_command: string 'OK' -> OK
05/07 21:06:36 yS3 mdm_send: 'AT+FDCC=1,5,0,2,0,0,0,0'
05/07 21:06:36 yS3 got:[0a]AT+FDCC=1,5,0,2,0,0,0,0[0d]
05/07 21:06:36 yS3 mdm_command: string 'AT+FDCC=1,5,0,2,0,0,0,0'
05/07 21:06:36 yS3 got:[0d][0a]OK[0d]
05/07 21:06:36 yS3 mdm_command: string 'OK' -> OK
05/07 21:06:36 yS3 waiting for line to clear (VTIME), read:
05/07 21:06:36 yS3 removing lock file
05/07 21:06:36 yS3 waiting...
---------------------------------------------------------------------------
Dmitri Pogosian 102 Aldwych Ave.
tel/fax: 1-416-466-4028 Toronto, ON M4J 1X6
e-mail: pogosyan@cita.utoronto.ca Canada
---------------------------------------------------------------------------