vgetty/mgetty - different fax reception ?
Dmitry Pogosyan (pogosyan@cita.utoronto.ca)
Sat, 8 May 1999 12:37:56 -0400
Thanks, I'll try restricting max speed. However, there are
explicit examples when my modem happily received 14.4 kbs
transissions. After this dismal 2400 bps speed connection
(and 2400 was all I was getting with vgetty before), modem
intializes and receives next fax perfectly (and then one after
next) - I have log below. I can't see any differences in the log
preceeding good and bad receptions :(. Hate to think if this can be
flaky firmware ...
Remarks:
a) This time the qood connection came from different fax machine,
however this machine also failed to create anything above 2400 bps when I
run vgetty earlier this week
b) In the fast call 'normal' resolution is what was requested.
After that I also received as fast transmission with high resolution
Dmitri
> hi,
>
> On Sat, May 08, 1999 at 09:39:59AM -0400, Dmitry Pogosyan wrote:
> > Between intialization and reception there have been two "modem alive"
>
> > 05/07 15:53:09 yS3 mdm_send: 'AT+FDCC=1,5,0,2,0,0,0,0'
> > 05/07 15:53:09 yS3 got:[0a]AT+FDCC=1,5,0,2,0,0,0,0[0d]
>
> Looks pretty much the way it should be: "gimme 14400".
>
> You could try "fax-max-speed 9600" in mgetty.config - maybe your modem
> doesn't like 14400, and subsequently messes up completely. Unlikely, but
> trying it wouldn't harm...
>
> [..]
> > 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
>
> This is very slow indeed (so it's not just the modem reporting slow
> speeds, it is also using them). 3 minutes for 60 kbyte is slllowww.
>
> gert
> --
--
05/07 18:55:56 yS3 mgetty: experimental test release 1.1.19-Nov24
05/07 18:55:56 yS3 mgetty.c compiled at Jan 21 1999, 09:50:33
05/07 18:55:56 yS3 user id: 0, parent pid: 1
05/07 18:55:56 yS3 reading configuration data for port 'ttyS3'
05/07 18:55:56 yS3 reading /etc/mgetty+sendfax/mgetty.config...
05/07 18:55:56 yS3 conf lib: read: 'debug 4'
05/07 18:55:56 yS3 conf lib: read: 'fax-id 1 416 466 4028'
05/07 18:55:56 yS3 conf lib: read: 'speed 115200'
05/07 18:55:56 yS3 conf lib: read: 'rings 5'
05/07 18:55:56 yS3 conf lib: read: 'port ttyS3'
05/07 18:55:56 yS3 section: port ttyS3, **found**
05/07 18:55:56 yS3 key: 'speed', type=0, flags=3, data=115200
05/07 18:55:56 yS3 key: 'switchbd', type=0, flags=1, data=0
05/07 18:55:56 yS3 key: 'direct', type=3, flags=1, data=FALSE
05/07 18:55:56 yS3 key: 'blocking', type=3, flags=1, data=FALSE
05/07 18:55:56 yS3 key: 'port-owner', type=1, flags=1, data=uucp
05/07 18:55:56 yS3 key: 'port-group', type=1, flags=1, data=uucp
05/07 18:55:56 yS3 key: 'port-mode', type=0, flags=1, data=432
05/07 18:55:56 yS3 key: 'toggle-dtr', type=3, flags=1, data=TRUE
05/07 18:55:56 yS3 key: 'toggle-dtr-waittime', type=0, flags=1, data=500
05/07 18:55:56 yS3 key: 'data-only', type=3, flags=1, data=FALSE
05/07 18:55:56 yS3 key: 'fax-only', type=3, flags=1, data=FALSE
05/07 18:55:56 yS3 key: 'modem-type', type=1, flags=1, data=auto
05/07 18:55:56 yS3 key: 'modem-quirks', type=0, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'init-chat', type=2, flags=1, data= \dATQ0V1H0 OK ATS0=0Q0&D3&C1 OK
05/07 18:55:56 yS3 key: 'force-init-chat', type=2, flags=1, data= \d\d\d\d+++\d\d\d
\dATQ0V1H0 OK
05/07 18:55:56 yS3 key: 'post-init-chat', type=2, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'modem-check-time', type=0, flags=1, data=3600
05/07 18:55:56 yS3 key: 'rings', type=0, flags=3, data=5
05/07 18:55:56 yS3 key: 'msn-list', type=2, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'get-cnd-chat', type=2, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'cnd-program', type=1, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'answer-chat', type=2, flags=1, data= ATA CONNECT \c
05/07 18:55:56 yS3 key: 'answer-chat-timeout', type=0, flags=1, data=80
05/07 18:55:56 yS3 key: 'autobauding', type=3, flags=1, data=FALSE
05/07 18:55:56 yS3 key: 'ringback', type=3, flags=1, data=FALSE
05/07 18:55:56 yS3 key: 'ringback-time', type=0, flags=1, data=30
05/07 18:55:56 yS3 key: 'ignore-carrier', type=3, flags=1, data=FALSE
05/07 18:55:56 yS3 key: 'issue-file', type=1, flags=1, data=/etc/issue
05/07 18:55:56 yS3 key: 'prompt-waittime', type=0, flags=1, data=500
05/07 18:55:56 yS3 key: 'login-prompt', type=1, flags=1, data=@ login:
05/07 18:55:56 yS3 key: 'login-time', type=0, flags=1, data=240
05/07 18:55:56 yS3 key: 'fido-send-emsi', type=3, flags=1, data=TRUE
05/07 18:55:56 yS3 key: 'fax-id', type=1, flags=3, data=1 416 466 4028
05/07 18:55:56 yS3 key: 'fax-min-speed', type=0, flags=1, data=0
05/07 18:55:56 yS3 key: 'fax-max-speed', type=0, flags=1, data=14400
05/07 18:55:56 yS3 key: 'fax-server-file', type=1, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'diskspace', type=0, flags=1, data=5120
05/07 18:55:56 yS3 key: 'notify', type=1, flags=1, data=root
05/07 18:55:56 yS3 key: 'fax-owner', type=1, flags=1, data=uucp
05/07 18:55:56 yS3 key: 'fax-group', type=1, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'fax-mode', type=0, flags=1, data=432
05/07 18:55:56 yS3 key: 'debug', type=0, flags=2, data=9
05/07 18:55:56 yS3 key: 'statistics-chat', type=2, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'statistics-file', type=1, flags=0, data=(empty)
05/07 18:55:56 yS3 key: 'gettydefs', type=1, flags=1, data=n
05/07 18:55:56 yS3 key: 'term', type=1, flags=0, data=(empty)
05/07 18:55:56 yS3 check for lockfiles
05/07 18:55:56 yS3 checklock: stat failed, no file
05/07 18:55:56 yS3 locking the line
05/07 18:55:56 yS3 makelock(ttyS3) called
05/07 18:55:56 yS3 do_makelock: lock='/var/lock/LCK..ttyS3'
05/07 18:55:56 yS3 lock made
05/07 18:55:57 yS3 tio_get_rs232_lines: status: RTS CTS DSR DTR
05/07 18:55:57 yS3 lowering DTR to reset Modem
05/07 18:55:57 yS3 tss: set speed to 115200 (10002)
05/07 18:55:57 yS3 tio_set_flow_control( HARD )
05/07 18:55:57 yS3 waiting for line to clear (VTIME), read:
05/07 18:55:58 yS3 send: \dATQ0V1H0[0d]
05/07 18:55:58 yS3 waiting for ``OK''
05/07 18:55:58 yS3 got: ATQ0V1H0[0d]
05/07 18:55:58 yS3 CND: ATQ0V1H0[0d][0a]OK ** found **
05/07 18:55:58 yS3 send: ATS0=0Q0&D3&C1[0d]
05/07 18:55:58 yS3 waiting for ``OK''
05/07 18:55:58 yS3 got: [0d]
05/07 18:55:58 yS3 CND: OK[0a]ATS0=0Q0&D3&C1[0d]
05/07 18:55:58 yS3 CND: ATS0=0Q0&D3&C1[0d][0a]OK ** found **
05/07 18:55:58 yS3 mdm_send: 'ATI'
05/07 18:55:58 yS3 got:[0d][0a]ATI[0d]
05/07 18:55:58 yS3 got:[0d][0a]56000[0d]
05/07 18:55:58 yS3 mdm_gis: string 1: '56000'
05/07 18:55:58 yS3 got:[0a][0d][0a]OK[0d]
05/07 18:55:58 yS3 mdm_identify: string '56000'
05/07 18:55:58 yS3 Generic Rockwell modem (56000)
05/07 18:55:58 yS3 mdm_send: 'ATI3'
05/07 18:55:58 yS3 got:[0a]ATI3[0d]
05/07 18:55:58 yS3 got:[0d][0a]V2.081-K56_2M_DLP-C Z201[0d]
05/07 18:55:58 yS3 mdm_gis: string 1: 'V2.081-K56_2M_DLP-C Z201'
05/07 18:55:58 yS3 got:[0a][0d][0a]OK[0d]
05/07 18:55:58 yS3 mdm_send: 'ATI4'
05/07 18:55:58 yS3 got:[0a]ATI4[0d]
05/07 18:55:58 yS3 got:[0d][0a]a007880284C6002F[0d]
05/07 18:55:58 yS3 mdm_gis: string 1: 'a007880284C6002F'
05/07 18:55:58 yS3 got:[0a][0d][0a]bC60000000[0d]
05/07 18:55:58 yS3 mdm_gis: string 2: 'bC60000000'
05/07 18:55:58 yS3 got:[0a][0d][0a]r1005111151012004[0d]
05/07 18:55:58 yS3 mdm_gis: string 3: 'r1005111151012004'
05/07 18:55:58 yS3 got:[0a][0d][0a]r3000111170000000[0d]
05/07 18:55:58 yS3 mdm_gis: string 4: 'r3000111170000000'
05/07 18:55:58 yS3 got:[0a][0d][0a]OK[0d]
05/07 18:55:58 yS3 additional info: 'a007880284C6002F'
05/07 18:55:58 yS3 modem quirks: 0004
05/07 18:55:58 yS3 mdm_send: 'AT+FCLASS=2'
05/07 18:55:58 yS3 got:[0a]AT+FCLASS=2[0d]
05/07 18:55:59 yS3 mdm_command: string 'AT+FCLASS=2'
05/07 18:55:59 yS3 got:[0d][0a]OK[0d]
05/07 18:55:59 yS3 mdm_command: string 'OK' -> OK
05/07 18:55:59 yS3 mdm_send: 'AT+FCLASS=0'
05/07 18:55:59 yS3 got:[0a]AT+FCLASS=0[0d]
05/07 18:55:59 yS3 mdm_command: string 'AT+FCLASS=0'
05/07 18:55:59 yS3 got:[0d][0a]OK[0d]
05/07 18:55:59 yS3 mdm_command: string 'OK' -> OK
05/07 18:55:59 yS3 mdm_send: 'AT+FAA=1;+FCR=1'
05/07 18:55:59 yS3 got:[0a]AT+FAA=1;+FCR=1[0d]
05/07 18:55:59 yS3 mdm_command: string 'AT+FAA=1;+FCR=1'
05/07 18:55:59 yS3 got:[0d][0a]OK[0d]
05/07 18:55:59 yS3 mdm_command: string 'OK' -> OK
05/07 18:55:59 yS3 mdm_send: 'AT+FBOR=0'
05/07 18:55:59 yS3 got:[0a]AT+FBOR=0[0d]
05/07 18:55:59 yS3 mdm_command: string 'AT+FBOR=0'
05/07 18:55:59 yS3 got:[0d][0a]OK[0d]
05/07 18:55:59 yS3 mdm_command: string 'OK' -> OK
05/07 18:55:59 yS3 mdm_send: 'AT+FLID="1 416 466 4028"'
05/07 18:55:59 yS3 got:[0a]AT+FLID="1 416 466 4028"[0d]
05/07 18:55:59 yS3 mdm_command: string 'AT+FLID="1 416 466 4028"'
05/07 18:55:59 yS3 got:[0d][0a]OK[0d]
05/07 18:55:59 yS3 mdm_command: string 'OK' -> OK
05/07 18:55:59 yS3 mdm_send: 'AT+FDCC=1,5,0,2,0,0,0,0'
05/07 18:55:59 yS3 got:[0a]AT+FDCC=1,5,0,2,0,0,0,0[0d]
05/07 18:55:59 yS3 mdm_command: string 'AT+FDCC=1,5,0,2,0,0,0,0'
05/07 18:55:59 yS3 got:[0d][0a]OK[0d]
05/07 18:55:59 yS3 mdm_command: string 'OK' -> OK
05/07 18:55:59 yS3 waiting for line to clear (VTIME), read:
05/07 18:55:59 yS3 removing lock file
05/07 18:55:59 yS3 waiting...
05/07 19:55:59 yS3 select returned 0
05/07 19:55:59 yS3 checking if modem is still alive
05/07 19:55:59 yS3 makelock(ttyS3) called
05/07 19:55:59 yS3 do_makelock: lock='/var/lock/LCK..ttyS3'
05/07 19:55:59 yS3 lock made
05/07 19:55:59 yS3 mdm_send: 'AT'
05/07 19:55:59 yS3 got:[0a]AT[0d]
05/07 19:55:59 yS3 mdm_command: string 'AT'
05/07 19:55:59 yS3 got:[0d][0a]OK[0d]
05/07 19:55:59 yS3 mdm_command: string 'OK' -> OK
05/07 19:55:59 yS3 waiting for line to clear (VTIME), read:
05/07 19:56:00 yS3 removing lock file
05/07 19:56:00 yS3 waiting...
05/07 20:01:36 yS3 select returned 1
05/07 20:01:36 yS3 checking lockfiles, locking the line
05/07 20:01:36 yS3 makelock(ttyS3) called
05/07 20:01:36 yS3 do_makelock: lock='/var/lock/LCK..ttyS3'
05/07 20:01:36 yS3 lock made
05/07 20:01:36 yS3 wfr: waiting for ``RING''
05/07 20:01:36 yS3 got: [0a][0d][0a]RING[0d]
05/07 20:01:36 yS3 CND: RING
05/07 20:01:36 yS3 wfr: rc=0, drn=0
05/07 20:01:36 yS3 wfr: waiting for ``RING''
05/07 20:01:36 yS3 got: [0a][0d][0a]RING[0d]
05/07 20:01:42 yS3 CND: RING
05/07 20:01:42 yS3 wfr: rc=0, drn=0
05/07 20:01:42 yS3 wfr: waiting for ``RING''
05/07 20:01:42 yS3 got: [0a]
05/07 20:01:52 yS3 mdm_read_byte: read returned -1: Interrupted system call
05/07 20:01:52 yS3 wfr: timeout waiting for RING
05/07 20:01:52 yS3 wfr: rc=-1, drn=0
05/07 20:01:52 ##### phone stopped ringing (rings=2)
05/07 20:01:52 yS3 waiting for line to clear (VTIME), read:
05/07 20:01:52 yS3 removing lock file
05/07 20:01:52 yS3 waiting...
05/07 21:01:24 yS3 select returned 1
05/07 21:01:24 yS3 checking lockfiles, locking the line
05/07 21:01:24 yS3 makelock(ttyS3) called
05/07 21:01:24 yS3 do_makelock: lock='/var/lock/LCK..ttyS3'
05/07 21:01:24 yS3 lock made
05/07 21:01:24 yS3 wfr: waiting for ``RING''
05/07 21:01:24 yS3 got: [0d][0a]RING[0d]
05/07 21:01:24 yS3 CND: RING
05/07 21:01:24 yS3 wfr: rc=0, drn=0
05/07 21:01:24 yS3 wfr: waiting for ``RING''
05/07 21:01:24 yS3 got: [0a][0d][0a]RING[0d]
05/07 21:01:30 yS3 CND: RING
05/07 21:01:30 yS3 wfr: rc=0, drn=0
05/07 21:01:30 yS3 wfr: waiting for ``RING''
05/07 21:01:30 yS3 got: [0a][0d][0a]RING[0d]
05/07 21:01:36 yS3 CND: RING
05/07 21:01:36 yS3 wfr: rc=0, drn=0
05/07 21:01:36 yS3 wfr: waiting for ``RING''
05/07 21:01:36 yS3 got: [0a][0d][0a]RING[0d]
05/07 21:01:42 yS3 CND: RING
05/07 21:01:42 yS3 wfr: rc=0, drn=0
05/07 21:01:42 yS3 wfr: waiting for ``RING''
05/07 21:01:42 yS3 got: [0a][0d][0a]RING[0d]
05/07 21:01:48 yS3 CND: RING
05/07 21:01:48 yS3 wfr: rc=0, drn=0
05/07 21:01:48 yS3 CND: check no: 'none'
05/07 21:01:48 yS3 send: ATA[0d]
05/07 21:01:48 yS3 waiting for ``CONNECT''
05/07 21:01:48 yS3 got: ATA[0d]
05/07 21:01:48 yS3 CND: OKATA[0d][0a]FAX
05/07 21:01:50 yS3 found action string: ``FAX''
05/07 21:01:50 yS3 start fax receiver...
05/07 21:01:50 yS3 fax receiver: entry
05/07 21:01:50 yS3 fax_wait_for(OK)
05/07 21:01:50 yS3 got:[0a][0d][0a][0d][0a]+FCON[0d]
05/07 21:01:56 yS3 fax_wait_for: string '+FCON'
05/07 21:01:56 yS3 got:[0a][0d][0a]+FDCS: 0,5,0,2,0,0,0,3[0d]
05/07 21:01:57 yS3 fax_wait_for: string '+FDCS: 0,5,0,2,0,0,0,3'
05/07 21:01:57 yS3 transmission par.: '+FDCS: 0,5,0,2,0,0,0,3'
05/07 21:01:57 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:01:57 yS3 fax_wait_for: string 'OK'** found **
05/07 21:01:57 yS3 looking for utmp entry... (my PID: 4270)
05/07 21:01:57 yS3 utmp + wtmp entry made
05/07 21:01:57 yS3 tio_set_flow_control( HARD XON_IN )
05/07 21:01:57 yS3 fax_send: 'AT+FDR'
05/07 21:01:57 yS3 fax_wait_for(CONNECT)
05/07 21:01:57 yS3 got:[0a]AT+FDR[0d]
05/07 21:01:57 yS3 fax_wait_for: string 'AT+FDR'
05/07 21:01:57 yS3 got:[0d][0a]+FCFR[0d]
05/07 21:02:00 yS3 fax_wait_for: string '+FCFR'
05/07 21:02:00 yS3 got:[0a][0d][0a]+FDCS: 0,5,0,2,0,0,0,3[0d]
05/07 21:02:02 yS3 fax_wait_for: string '+FDCS: 0,5,0,2,0,0,0,3'
05/07 21:02:02 yS3 transmission par.: '+FDCS: 0,5,0,2,0,0,0,3'
05/07 21:02:02 yS3 got:[0a][0d][0a]CONNECT[0d]
05/07 21:02:02 yS3 fax_wait_for: string 'CONNECT'** found **
05/07 21:02:02 yS3 sending DC2
05/07 21:02:02 yS3 fax_get_page_data: wait for EOL, got: [0a][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][ff][fc][00]
05/07 21:02:02 yS3 fax_get_page_data: receiving /var/spool/fax/incoming/fn7338cfcS3.01...
05/07 21:02:13 yS3 fax_get_page_data: page end, bytes received: 19877
05/07 21:02:13 yS3 fax_wait_for(OK)
05/07 21:02:13 yS3 got:[0d][0a]+FPTS: 1,2219,0,0[0d]
05/07 21:02:13 yS3 fax_wait_for: string '+FPTS: 1,2219,0,0'
05/07 21:02:13 yS3 page status: +FPTS: 1,2219,0,0
05/07 21:02:13 yS3 2219 lines received, 0 lines bad, 0 bytes lost
05/07 21:02:13 yS3 got:[0a][0d][0a]+FET: 2[0d]
05/07 21:02:15 yS3 fax_wait_for: string '+FET: 2'
05/07 21:02:15 yS3 got:[0a][0d][0a]OK[0d]
05/07 21:02:15 yS3 fax_wait_for: string 'OK'** found **
05/07 21:02:15 yS3 fax_send: 'AT+FDR'
05/07 21:02:15 yS3 fax_wait_for(CONNECT)
05/07 21:02:15 yS3 got:[0a]AT+FDR[0d]
05/07 21:02:15 yS3 fax_wait_for: string 'AT+FDR'
05/07 21:02:15 yS3 got:[0d][0a]+FHNG: 0[0d]
05/07 21:02:18 yS3 fax_wait_for: string '+FHNG: 0'
05/07 21:02:18 yS3 connection hangup: '+FHNG: 0'
05/07 21:02:18 yS3 (Normal and proper end of connection)** found **
05/07 21:02:18 yS3 fax receiver: hangup & end
---------------------------------------------------------------------------
Dmitri Pogosian 102 Aldwych Ave.
tel/fax: 1-416-466-4028 Toronto, ON M4J 1X6
e-mail: pogosyan@cita.utoronto.ca Canada
---------------------------------------------------------------------------