FHNG=-5 with Sportster While Receiving
Eli Marmor (marmor@elmar.co.il)
Tue, 28 Apr 1998 16:32:40 +0200
This is a multi-part message in MIME format.
--------------69D4245B4950
Content-Type: text/plain; charset=iso-8859-1
Content-Transfer-Encoding: 7bit
Hello,
I believe it is a FAQ, but I couldn't find any answer (though I
found *MANY* others with the same problem, e.g.
http://x10.dejanews.com/getdoc.xp?AN=244872128&CONTEXT=893748424.1844248576&hitnum=56
).
I use a USR Sportster's compatible modem (Data/FAX 1433QH).
The problem exists with my current configuation (RedHat5, built-in
mgetty) AND with my previous configuration (Slackware, my own
compiled version based on an old beta - 1.1.I-don't-remember-minor-
version).
The problem: In about a third (!) of the received faxes, I get the
following error: "+FHNG=-05". The reported error in the e-mail is:
> The fax receive was *not* fully successful
> The Modem returned +FHNG: -5
> (Unexpected hangup / read() error / write() error (int.))
I tried to add the line: "ignore-carrier true" to the file
"/etc/mgetty+sendfax/mgetty.config", but it didn't help (I think it
stopped the hang-ups, but the received messages are still garbaged).
After using "-x 9" (the highest debug-level), I got the attached
file (sorry, it is long).
What's wrong? Is there any solution?
Thanks in advance,
--
Eli Marmor
marmor@elmar.co.il
--------------69D4245B4950
Content-Type: text/plain; charset=iso-8859-1; name="mgetty"
Content-Transfer-Encoding: quoted-printable
Content-Disposition: inline; filename="mgetty"
04/27 08:42:06 yS1 waiting...
04/27 09:02:15 yS1 select returned 1
04/27 09:02:15 yS1 checking lockfiles, locking the line
04/27 09:02:15 yS1 makelock(ttyS1) called
04/27 09:02:15 yS1 do_makelock: lock=3D'/var/lock/LCK..ttyS1'
04/27 09:02:15 yS1 lock made
04/27 09:02:15 yS1 waiting for ``RING''
04/27 09:02:15 yS1 got: [0d]
04/27 09:02:15 yS1 CND: OK[0a]RING ** found **
04/27 09:02:15 yS1 waiting for ``RING''
04/27 09:02:15 yS1 got: [0d]
04/27 09:02:15 yS1 CND: RING[0a][0d][0a]RING ** found **
04/27 09:02:19 yS1 send: ATA[0d]
04/27 09:02:19 yS1 waiting for ``CONNECT''
04/27 09:02:19 yS1 got: [0d]
04/27 09:02:19 yS1 CND: RING[0a]ATA[0d]
04/27 09:02:19 yS1 CND: ATA[0d][0a]+FCO[0d]
04/27 09:02:26 yS1 CND: +FCO
04/27 09:02:26 yS1 found action string: ``+FCO_''
04/27 09:02:26 yS1 start fax receiver...
04/27 09:02:26 yS1 fax receiver: entry
04/27 09:02:26 yS1 fax_wait_for(OK)
04/27 09:02:26 yS1 got:[0a][0a][0d][0a]+FTI:" 569+4033"[0d]=
04/27 09:02:28 yS1 fax_wait_for: string '+FTI:" 569+4033"'
04/27 09:02:28 yS1 fax_id: '+FTI:" 569+4033"'
04/27 09:02:28 yS1 got:[0a][0d][0a]+FCS:0,3,0,2,0,0,0,0[0d]
04/27 09:02:28 yS1 fax_wait_for: string '+FCS:0,3,0,2,0,0,0,0'
04/27 09:02:28 yS1 transmission par.: '+FCS:0,3,0,2,0,0,0,0'
04/27 09:02:28 yS1 got:[0a][0d][0a]OK[0d]
04/27 09:02:28 yS1 fax_wait_for: string 'OK'** found **
04/27 09:02:28 yS1 looking for utmp entry... (my PID: 24125)
04/27 09:02:28 yS1 utmp + wtmp entry made
04/27 09:02:28 yS1 tio_set_flow_control( HARD XON_IN )
04/27 09:02:28 yS1 mdm_send: 'AT+FLO=3D2'
04/27 09:02:28 yS1 got:[0a]AT+FLO=3D2[0d]
04/27 09:02:28 yS1 mdm_command: string 'AT+FLO=3D2'
04/27 09:02:28 yS1 got:[0d][0a]OK[0d]
04/27 09:02:28 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:28 yS1 fax_send: 'AT+FDR'
04/27 09:02:28 yS1 fax_wait_for(CONNECT)
04/27 09:02:28 yS1 got:[0a]AT+FDR[0d]
04/27 09:02:28 yS1 fax_wait_for: string 'AT+FDR'
04/27 09:02:28 yS1 got:[0d][0a]CONNECT[0d]
04/27 09:02:31 yS1 fax_wait_for: string 'CONNECT'** found **
04/27 09:02:31 yS1 sending DC2
04/27 09:02:31 yS1 fax_get_page_data: wait for EOL, got: [0a][ee][ee][e=
b][ee][ef][a4][ee][ee][ee][eb][ee][ef][a4][be][ee][fa]N[ee][ee][ee][eb][e=
e][ef][a4][ee][ee][ee][eb][ee][ef][a4][ee][ee][ee][ee][be][ee][fa]K[ee][e=
f][a4][ee][ee][ee][ee][eb][ee][ef][a4][ee][ee][be][ee][fa]N[ee][ee][ee][e=
b][ee][ef][a1][ee][ef][a4][ee][ee][ee][ee][be][ee][fa]N[ee][ee][ee][be][e=
e][fa]N[ee][ee][eb][ee][ef][a4][ee][bd][be][fa][9c]N[ee][ee][ee][eb][ee][=
ef][a4][ee][be][ee][fa]N[ee][ee][ee][eb][ee][ef][a4][ee][be][ee][fa]N[ee]=
[ee][ee][ee][eb][ee][ef][a4][ee][ee][be][ee][fa]N[ee][ee][be][ee][fa]N[ee=
][eb][ee][ef][a4][ee][ee][ee][ee][ef][fe][ee][a8][9e][ee][fa]N[ee][ee][ee=
][ee][be][ee][fa]N[be][ee][fa]N[ee][ee][ee][ee][ee][be][ee][fa]N[ee][ee][=
ee][eb][ee][ef][a4][eb][ee][ef][a4][ee][ee][be][ee][fa]N[ee][ee][ee][ee][=
be][ee][fa]N[ee][ee][ee][eb][ee][ef][a4][be][ee][fa]N[ee][ee][ee][be][ee]=
[fa]N[ee][ee][eb][ee][ef][a4][ee][ee][ee][ee][be][ee][fa]K[ee][ef][a4][ee=
][ee][ee][ee][ee][be][ee][fa]N[eb][ee][ef][a4][ee][ee][ee][ee][eb][ee][ef=
][a4][eb][ee][ef][a4][ee][ee][ee][ee][eb][ee][ef][a4][ee][ee][eb][ee][ef]=
[a4][ee][ee][eb][ee][ef][a4][ee][be][ee][fa]N[ee][ee][ee][eb][ee][ef][a4]=
[ee][ee][eb][ee][ef][a4][ee][ee][eb][ee][ef][a4][ee][ee][be][ee][fa]N[ee]=
[ee][ee][be][ee][fa]N[ee][ee][ee][ee][be][ee][fa]N[ee][eb][ee][ef][a4][ee=
][eb][ee][ef][a4][ee][ee][ee][eb][ee][ef][a4][ee][ee][ee][ee][be][ee][fa]=
N[eb][ee][ef][a4][ee][ee][ee][be][ee][fa]N[ee][ee][eb][ee][ef][a4][ee][ee=
][ee][ee][eb][ee][ef][a4][eb][ee][ef][a4][ee][bd][bb][f9][d2][1c][a1][93]=
p[14][cf]5[b9]B[99][bd][c7](l[aa]oRh[02][0b]:PU}}}}}}}}}}}}}}}}}}}}}}}}}}=
}}}}}}}}}}}}L:3=3D[18]^.[b6][93]48[1b] [cf]yr[01][b1]&[9b]c[99][b2]2l|[8a=
][be][89][dd]B&[de][89][bd][12]n[0a]=3D+# [8f]ot[91][c6][d2][15][fd]cBrV =
c7[06]8hqSs[e3][8b]#v[ea][1a][11][17]'wc[d7]wvs'2;[92][e9][96][fe][8a][87=
]/[bf][c2][a0]K=3D[15]Em/[d2][84]v3]'[b2]'[e2][c5][a2]E[aa][84]u[15][05][=
8b]"`[89]X[93]ts[87][8b]57>8[b2]7n[a1][a1][11]rwv=3Dwwg1Cvs[so[e8][a8]r[f=
b][fc]*[04][a2][d1]P4[e1][fd]$[e1]c5[d2]{[06]~[16][12]([e8][a8]By[03]X[a6=
]@[08][95][8a]P[07][e7]g W 4[86]D6[bf]V![fa][96][f9][b3][ab]M[f0]D[86][e1=
][[14][06]S[e3][95][f9][95][16][c6][a9][e0][fc][b7][b8][81][16])[fa][b2],=
[0a]-[18]?[18]G[a4][16]+[9d][12][b1];[f8]d[9c]\[fb]?[d2]S[9b][a7]7[dd]3/[=
c7][b2]?rM[18][[f1][0e]2[cc][e9][96][e7][c3][d1]j[e6][af]*[a7][fd][fd][d0=
][c2][90][15][e2]3[a7][89][98][c8]bS[08]b([bc]Z+;.[99]:[a9]<[bf][17]V[83]=
[f3]L[dc]9[09]&!^[86],[a0][d6]Et[[f0]0[0d][1e]w[ab][cb]'[e9][dc][97][89][=
07][9b][10]
04/27 09:02:32 yS1 fax_get_page_data: receiving /var/spool/fax/incoming/=
fn5441f6bS1-_-569+4033_.01...
04/27 09:02:33 yS1 fax_get_page_data: page end, bytes received: 1469
04/27 09:02:33 yS1 fax_wait_for(OK)
04/27 09:02:33 yS1 got:[0d][0a]+FPS:1,6,0,0,0[0d]
04/27 09:02:33 yS1 fax_wait_for: string '+FPS:1,6,0,0,0'
04/27 09:02:33 yS1 page status: +FPS:1,6,0,0,0
04/27 09:02:33 yS1 6 lines received, 0 lines bad, 0 bytes lost
04/27 09:02:33 yS1 got:[0a][0d][0a]+FHS:A1[0d]
04/27 09:02:43 yS1 fax_wait_for: string '+FHS:A1'
04/27 09:02:43 yS1 connection hangup: '+FHS:A1'
04/27 09:02:43 yS1 (Unexpected hangup / read() error / write() error (i=
nt.))
04/27 09:02:43 yS1 got:[0a][0d][0a]OK[0d]
04/27 09:02:44 yS1 fax_wait_for: string 'OK'** found **
04/27 09:02:44 yS1 fax receiver: hangup & end
04/27 09:02:44 yS1 fax_notify_mail: sending mail to: faxadmin
04/27 09:02:44 yS1 notify: '/usr/local/bin/new_fax -5 '_ 569=
+4033_' 1 /var/spool/fax/incoming/fn5441f6bS1-_-569+4033_.01 >/dev/conso=
le 2>&1 </dev/null'
04/27 09:02:44 ##### fax dev=3DttyS1, pid=3D24125, caller=3Dnone, name=3D=
'', id=3D'_ 569+4033_', +FHNG=3D-05, pages=3D1, time=3D00:00:2=
5_
04/27 09:02:45 yS1 mdm_send: 'ATH0'
04/27 09:02:45 yS1 got:[0a]ATH0[0d]
04/27 09:02:45 yS1 mdm_command: string 'ATH0'
04/27 09:02:45 yS1 got:[0d][0a]OK[0d]
04/27 09:02:45 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:45 yS1 removing lock file
--
04/27 09:02:45 yS1 mgetty: experimental test release 1.1.9-Aug17
04/27 09:02:45 yS1 mgetty.c compiled at Oct 30 1997, 01:58:27
04/27 09:02:45 yS1 reading configuration data for port 'ttyS1'
04/27 09:02:45 yS1 reading /etc/mgetty+sendfax/mgetty.config...
04/27 09:02:45 yS1 conf lib: read: 'debug 4'
04/27 09:02:45 yS1 conf lib: read: 'fax-id 972-9-7661314 El-Mar'
04/27 09:02:45 yS1 conf lib: read: 'ignore-carrier true'
04/27 09:02:45 yS1 conf lib: read: 'speed 38400'
04/27 09:02:45 yS1 key: 'speed', type=3D0, flags=3D2, data=3D115200
04/27 09:02:45 yS1 key: 'switchbd', type=3D0, flags=3D1, data=3D0
04/27 09:02:45 yS1 key: 'direct', type=3D3, flags=3D1, data=3DFALSE
04/27 09:02:45 yS1 key: 'blocking', type=3D3, flags=3D1, data=3DFALSE
04/27 09:02:45 yS1 key: 'port-owner', type=3D1, flags=3D1, data=3Duucp
04/27 09:02:45 yS1 key: 'port-group', type=3D1, flags=3D1, data=3Duucp
04/27 09:02:45 yS1 key: 'port-mode', type=3D0, flags=3D1, data=3D432
04/27 09:02:45 yS1 key: 'toggle-dtr', type=3D3, flags=3D1, data=3DTRUE
04/27 09:02:45 yS1 key: 'toggle-dtr-waittime', type=3D0, flags=3D1, dat=
a=3D500
04/27 09:02:45 yS1 key: 'data-only', type=3D3, flags=3D1, data=3DFALSE
04/27 09:02:45 yS1 key: 'fax-only', type=3D3, flags=3D1, data=3DFALSE
04/27 09:02:45 yS1 key: 'modem-type', type=3D1, flags=3D1, data=3Dauto
04/27 09:02:45 yS1 key: 'init-chat', type=3D2, flags=3D1, data=3D \dATQ=
0V1H0 OK ATS0=3D0Q0&D3&C1 OK =
04/27 09:02:45 yS1 key: 'force-init-chat', type=3D2, flags=3D1, data=3D=
\d=10=03\d\d\d+++\d\d\d
\dATQ0V1H0 OK =
04/27 09:02:45 yS1 key: 'modem-check-time', type=3D0, flags=3D1, data=3D=
3600
04/27 09:02:45 yS1 key: 'rings', type=3D0, flags=3D2, data=3D2
04/27 09:02:45 yS1 key: 'get-cnd-chat', type=3D2, flags=3D0, data=3D(em=
pty)
04/27 09:02:45 yS1 key: 'answer-chat', type=3D2, flags=3D1, data=3D ATA=
CONNECT \c =
=
04/27 09:02:45 yS1 key: 'answer-chat-timeout', type=3D0, flags=3D1, dat=
a=3D80
04/27 09:02:45 yS1 key: 'autobauding', type=3D3, flags=3D1, data=3DFALS=
E
04/27 09:02:45 yS1 key: 'ringback', type=3D3, flags=3D1, data=3DFALSE
04/27 09:02:45 yS1 key: 'ringback-time', type=3D0, flags=3D1, data=3D30=
04/27 09:02:45 yS1 key: 'ignore-carrier', type=3D3, flags=3D3, data=3DT=
RUE
04/27 09:02:45 yS1 key: 'issue-file', type=3D1, flags=3D1, data=3D/etc/=
issue
04/27 09:02:45 yS1 key: 'prompt-waittime', type=3D0, flags=3D1, data=3D=
500
04/27 09:02:45 yS1 key: 'login-prompt', type=3D1, flags=3D1, data=3Dlog=
in: =
04/27 09:02:45 yS1 key: 'login-time', type=3D0, flags=3D1, data=3D240
04/27 09:02:45 yS1 key: 'fido-send-emsi', type=3D3, flags=3D1, data=3DT=
RUE
04/27 09:02:45 yS1 key: 'fax-id', type=3D1, flags=3D3, data=3D972-9-766=
1314 El-Mar
04/27 09:02:45 yS1 key: 'fax-server-file', type=3D1, flags=3D0, data=3D=
(empty)
04/27 09:02:45 yS1 key: 'diskspace', type=3D0, flags=3D1, data=3D1024
04/27 09:02:45 yS1 key: 'notify', type=3D1, flags=3D1, data=3Dfaxadmin
04/27 09:02:45 yS1 key: 'fax-owner', type=3D1, flags=3D1, data=3Duucp
04/27 09:02:45 yS1 key: 'fax-group', type=3D1, flags=3D0, data=3D(empty=
)
04/27 09:02:45 yS1 key: 'fax-mode', type=3D0, flags=3D1, data=3D432
04/27 09:02:45 yS1 key: 'debug', type=3D0, flags=3D2, data=3D9
04/27 09:02:45 yS1 key: 'statistics-chat', type=3D2, flags=3D0, data=3D=
(empty)
04/27 09:02:45 yS1 key: 'statistics-file', type=3D1, flags=3D0, data=3D=
(empty)
04/27 09:02:45 yS1 key: 'gettydefs', type=3D1, flags=3D1, data=3Dn
04/27 09:02:45 yS1 key: 'term', type=3D1, flags=3D0, data=3D(empty)
04/27 09:02:46 yS1 check for lockfiles
04/27 09:02:46 yS1 checklock: stat failed, no file
04/27 09:02:46 yS1 locking the line
04/27 09:02:46 yS1 makelock(ttyS1) called
04/27 09:02:46 yS1 do_makelock: lock=3D'/var/lock/LCK..ttyS1'
04/27 09:02:46 yS1 lock made
04/27 09:02:46 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR
04/27 09:02:46 yS1 lowering DTR to reset Modem
04/27 09:02:47 yS1 tss: set speed to 115200 (10002)
04/27 09:02:47 yS1 tio_set_flow_control( HARD )
04/27 09:02:47 yS1 waiting for line to clear (VTIME), read: =
04/27 09:02:47 yS1 send: \dATQ0V1H0[0d]
04/27 09:02:47 yS1 waiting for ``OK''
04/27 09:02:47 yS1 got: ATQ0V1H0[0d]
04/27 09:02:47 yS1 CND: ATQ0V1H0[0d][0a]OK ** found **
04/27 09:02:47 yS1 send: ATS0=3D0Q0&D3&C1[0d]
04/27 09:02:47 yS1 waiting for ``OK''
04/27 09:02:47 yS1 got: [0d]
04/27 09:02:47 yS1 CND: OK[0a]ATS0=3D0Q0&D3&C1[0d]
04/27 09:02:47 yS1 CND: ATS0=3D0Q0&D3&C1[0d][0a]OK ** found **
04/27 09:02:48 yS1 mdm_send: 'ATI'
04/27 09:02:48 yS1 got:[0d][0a]ATI[0d]
04/27 09:02:48 yS1 got:[0d][0a]3362[0d]
04/27 09:02:48 yS1 mdm_gis: string 1: '3362'
04/27 09:02:48 yS1 got:[0a][0d][0a]OK[0d]
04/27 09:02:48 yS1 mdm_identify: string '3362'
04/27 09:02:48 yS1 unknown numerical modem id 3362
04/27 09:02:48 yS1 mdm_send: 'AT+FCLASS=3D2.0'
04/27 09:02:48 yS1 got:[0a]AT+FCLASS=3D2.0[0d]
04/27 09:02:48 yS1 mdm_command: string 'AT+FCLASS=3D2.0'
04/27 09:02:48 yS1 got:[0d][0a]OK[0d]
04/27 09:02:48 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:48 yS1 mdm_send: 'AT+FAA=3D1;+FCR=3D1'
04/27 09:02:48 yS1 got:[0a]AT+FAA=3D1;+FCR=3D1[0d]
04/27 09:02:48 yS1 mdm_command: string 'AT+FAA=3D1;+FCR=3D1'
04/27 09:02:48 yS1 got:[0d][0a]OK[0d]
04/27 09:02:48 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:48 yS1 mdm_send: 'AT+FBO=3D1'
04/27 09:02:48 yS1 got:[0a]AT+FBO=3D1[0d]
04/27 09:02:48 yS1 mdm_command: string 'AT+FBO=3D1'
04/27 09:02:48 yS1 got:[0d][0a]OK[0d]
04/27 09:02:48 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:48 yS1 mdm_send: 'AT+FNR=3D1,1,1,0'
04/27 09:02:48 yS1 got:[0a]AT+FNR=3D1,1,1,0[0d]
04/27 09:02:48 yS1 mdm_command: string 'AT+FNR=3D1,1,1,0'
04/27 09:02:48 yS1 got:[0d][0a]OK[0d]
04/27 09:02:48 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:49 yS1 mdm_send: 'AT+FLI=3D"972-9-7661314 El-Mar"'
04/27 09:02:49 yS1 got:[0a]AT+FLI=3D"972-9-7661314 El-Mar"[0d]
04/27 09:02:49 yS1 mdm_command: string 'AT+FLI=3D"972-9-7661314 El-Mar"=
'
04/27 09:02:49 yS1 got:[0d][0a]OK[0d]
04/27 09:02:49 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:49 yS1 mdm_send: 'AT+FCC=3D1,5,0,2,0,0,0,0'
04/27 09:02:49 yS1 got:[0a]AT+FCC=3D1,5,0,2,0,0,0,0[0d]
04/27 09:02:49 yS1 mdm_command: string 'AT+FCC=3D1,5,0,2,0,0,0,0'
04/27 09:02:49 yS1 got:[0d][0a]OK[0d]
04/27 09:02:49 yS1 mdm_command: string 'OK' -> OK
04/27 09:02:49 yS1 waiting for line to clear (VTIME), read: =
04/27 09:02:49 yS1 removing lock file
04/27 09:02:49 yS1 waiting...
--------------69D4245B4950--