sendfax: dial 12345 failed (ERROR / NO CARRIER)

Ingo Renner (renner@iml.fhg.de)
29 Jan 2000 22:22:04 GMT


Hi,

wie schon im Subject zitiert, habe ich Probleme sendfax/mgetty dazu zu
bewegen ein Fax abzuschicken.
Da mein Modem an einer TK Anlage hängt, vermute ich das Problem hier.
Das Signal "freie Amtsleitung", welche von der TKanlage erzeugt wird,
erscheint mir etwas tiefer als das Signal der Telekom. Das Modem scheint zu
erkennen, das es nicht das Orginal ist und legt sofort wieder auf, was man
auch schön sehen kann, wenn man sich den Status dr TKAnlage anschaut.
Wenn ich allerdings in minicom ein ATD12345 absetze, wird sauber auf die
Amtsleitung der Telekom durchgestellt, auch TKinterne Verbindungen klappen
wunderbar. 
Fieserweise habe ich es schon zweimal geschafft, mich selbst auf der zweiten
Leitung anzufaxen, nur leider klppt das vielleicht 1 mal in 100
aufeinanderfolgenden sendfax aufrufen. Ich kann es jedenfalls nicht
ernsthaft reproduzieren. Faxempfang funktioniert übrigens wunderbar.


Nun zur mgetty config:
Distri ist ne SuSE 6.2
mgetty-1.1.21 selbst compiliert nach den Vorgaben in policy.h und
doc/modems.db 
Modem sagt auf ATI1 es ist ein U1496E  V 6.15 M

Nun zu den Logs:

plato:~ # faxrunq
processing F000005/JOB...  
sendfax -v 12345 f1.g3
Trying fax device '/dev/ttyS1'... OK.
Dialing 12345...
sendfax: dial 12345 failed (ERROR / NO CARRIER)
command exited with status 10 

Hier das sendfax.log, allerdings habe ich meine Telnr ausgeXt.
was mich stutzig macht, ist die Bemerkung:
    mdm_read_byte: read returned -1: Interrupted system call
Die Hinweise dazu in der mgetty Doku habe ich gefunden, leider hilft mir das
nicht weiter, da es mit minicom klappt und ich den init String aus der
modems.db übernommen habe. An dieser Stelle lege ich mir nun die Karten.
--
01/29 22:51:13  sendfax: experimental test release 1.1.21-Jul24
01/29 22:51:13   sendfax.c compiled at Jan 29 2000, 20:51:05
01/29 22:51:13  sending fax to 12345
01/29 22:51:13  checking f1.g3
01/29 22:51:13   makelock(ttyS1) called
01/29 22:51:13   do_makelock: lock='/var/lock/LCK..ttyS1'
01/29 22:51:13   lock made
01/29 22:51:13   tss: set speed to 38400 (017)
01/29 22:51:13   tio_set_flow_control( HARD )
01/29 22:51:13 yS1   fax_open_device succeeded, ttyS1 -> 4
01/29 22:51:13 yS1   reading specific data for port 'ttyS1'
01/29 22:51:13 yS1   reading /opt/local/mgetty+sendfax/etc/sendfax.config...
01/29 22:51:13 yS1   conf lib: read: 'verbose y'
01/29 22:51:13 yS1   conf lib: read: 'debug 5'
01/29 22:51:13 yS1   conf lib: read: 'fax-devices ttyS1'
01/29 22:51:13 yS1   conf lib: read: 'fax-id 49 xxx xxxxx'
01/29 22:51:13 yS1   conf lib: read: 'max-tries 3'
01/29 22:51:13 yS1   conf lib: read: 'max-tries-continue y'
01/29 22:51:13 yS1   key: 'fax-devices', type=1, flags=4, data=(ignored)
01/29 22:51:13 yS1   key: 'modem-init', type=1, flags=0, data=(empty)
01/29 22:51:13 yS1   key: 'modem-handshake', type=1, flags=1, data=AT&H3
01/29 22:51:13 yS1   key: 'modem-type', type=1, flags=1, data=auto
01/29 22:51:13 yS1   key: 'modem-quirks', type=0, flags=0, data=(empty)
01/29 22:51:13 yS1   key: 'fax-send-flow', type=4, flags=1, data=7
01/29 22:51:13 yS1   key: 'fax-rec-flow', type=4, flags=1, data=7
01/29 22:51:13 yS1   key: 'max-tries', type=0, flags=3, data=3
01/29 22:51:13 yS1   key: 'max-tries-continue', type=3, flags=3, data=TRUE
01/29 22:51:13 yS1   key: 'speed', type=0, flags=1, data=38400
01/29 22:51:13 yS1   key: 'switchbd', type=0, flags=1, data=0
01/29 22:51:13 yS1   key: 'open-delay', type=0, flags=0, data=(empty)
01/29 22:51:13 yS1   key: 'ignore-carrier', type=3, flags=1, data=TRUE
01/29 22:51:13 yS1   key: 'dial-prefix', type=1, flags=1, data=ATD
01/29 22:51:13 yS1   key: 'fax-id', type=1, flags=3, data=49 231 7275185
01/29 22:51:13 yS1   key: 'poll-dir', type=1, flags=1, data=.
01/29 22:51:13 yS1   key: 'normal-res', type=3, flags=1, data=FALSE
01/29 22:51:13 yS1   key: 'fax-min-speed', type=0, flags=1, data=0
01/29 22:51:13 yS1   key: 'fax-max-speed', type=0, flags=1, data=14400
01/29 22:51:13 yS1   key: 'debug', type=0, flags=3, data=5
01/29 22:51:13 yS1   key: 'verbose', type=3, flags=2, data=TRUE
01/29 22:51:13 yS1   key: '', type=3, flags=1, data=FALSE
01/29 22:51:13 yS1   key: 'page-header', type=1, flags=0, data=(empty)
01/29 22:51:13 yS1   key: '', type=3, flags=1, data=FALSE
01/29 22:51:13 yS1   key: '', type=3, flags=1, data=FALSE
01/29 22:51:13 yS1   key: '', type=1, flags=1, data=
01/29 22:51:13 yS1   tss: set speed to 38400 (017)
01/29 22:51:13 yS1  mdm_send: 'ATV1Q0'
01/29 22:51:13 yS1   mdm_command: string 'ATV1Q0'
01/29 22:51:13 yS1   mdm_command: string 'OK' -> OK
01/29 22:51:13 yS1  mdm_send: 'ATI'
01/29 22:51:23 yS1  Warning: got alarm signal!
01/29 22:51:23 yS1  mdm_read_byte: read returned -1: Interrupted system call
01/29 22:51:23 yS1  mdm_get_line: cannot read byte, return: Interrupted
system call
01/29 22:51:23 yS1   mdm_identify: string '<ERROR>'
01/29 22:51:23 yS1  mdm_identify: can't get modem ID
01/29 22:51:23 yS1  mdm_send: 'AT+FCLASS=?'
01/29 22:51:23 yS1   mdm_gis: string 1: '0,2,2.0,6,8'
01/29 22:51:23 yS1  available modem classes: 0,2,2.0,6,8
01/29 22:51:23 yS1  mdm_send: 'AT+FCLASS=2.0'
01/29 22:51:23 yS1   mdm_command: string 'AT+FCLASS=2.0'
01/29 22:51:23 yS1   mdm_command: string 'OK' -> OK
01/29 22:51:24 yS1  mdm_send: 'AT+FLI="49 231 7275185"'
01/29 22:51:24 yS1   mdm_command: string 'AT+FLI="49 231 7275185"'
01/29 22:51:24 yS1   mdm_command: string 'OK' -> OK
01/29 22:51:24 yS1  mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0'
01/29 22:51:24 yS1   mdm_command: string 'AT+FCC=1,5,0,2,0,0,0,0'
01/29 22:51:24 yS1   mdm_command: string 'OK' -> OK
01/29 22:51:24 yS1  mdm_send: 'AT+FBO=0'
01/29 22:51:24 yS1   mdm_command: string 'AT+FBO=0'
01/29 22:51:34 yS1  Warning: got alarm signal!
01/29 22:51:34 yS1  mdm_read_byte: read returned -1: Interrupted system call
01/29 22:51:34 yS1  mdm_get_line: cannot read byte, return: Interrupted
system call -> ERROR
01/29 22:51:34 yS1  mdm_send: 'AT+FNR=1,1,1,0'
01/29 22:51:34 yS1  mdm_read_byte: read returned 0: Success
01/29 22:51:34 yS1  mdm_get_line: cannot read byte, return: Success -> ERROR
01/29 22:51:34 yS1  mdm_send: 'AT+FLO=2'
01/29 22:51:34 yS1   mdm_command: string 'AT+FLO=2'
01/29 22:51:34 yS1   mdm_command: string 'OK' -> OK
01/29 22:51:34 yS1  mdm_send: 'AT&H3'
01/29 22:51:34 yS1   mdm_command: string 'AT&H3'
01/29 22:51:34 yS1   mdm_command: string 'OK' -> OK
01/29 22:51:34 yS1  fax_send: 'ATD12345'
01/29 22:51:34 yS1  fax_wait_for(OK)
01/29 22:51:34 yS1   fax_wait_for: string 'ATD12345'
01/29 22:51:35 yS1   fax_wait_for: string 'NO CARRIER'
01/29 22:51:35 yS1  ABORTING: line='NO CARRIER'
01/29 22:51:35 ##### failed dialing, phone="12345", +FHS:-4, dev=ttyS1,
time=1s, acct=""

01/29 22:51:35 yS1  fax_send: 'AT+FCLASS=0'
01/29 22:51:35 yS1   removing lock file



Das mgetty.log

--
01/29 22:47:10 dem  mgetty: experimental test release 1.1.21-Jul24
01/29 22:47:10 dem  check for lockfiles
01/29 22:47:10 dem  locking the line
01/29 22:47:10 dem  lowering DTR to reset Modem
01/29 22:47:20 dem  send: \dATQ0V1H0[0d][0a]
01/29 22:47:21 dem  waiting for `OK'' ** found **
01/29 22:47:22 dem  send: ATS0=0Q0&D3&H3&N0&K4[0d][0a]
01/29 22:47:22 dem  waiting for `OK'' ** found **
01/29 22:47:22 dem  mdm_send: 'ATI'
01/29 22:47:22 dem  ZyXEL 1496 detected
01/29 22:47:22 dem  mdm_send: 'ATI1'
01/29 22:47:22 dem  additional info: 'U1496E  V 6.15 M  '
01/29 22:47:22 dem  mdm_send: 'AT+FCLASS=2.0' -> OK
01/29 22:47:22 dem  mdm_send: 'AT+FAA=0;+FCR=1' -> OK
01/29 22:47:22 dem  mdm_send: 'AT+FBO=1' -> OK
01/29 22:47:22 dem  mdm_send: 'AT+FNR=1,1,1,0' -> OK
01/29 22:47:23 dem  mdm_send: 'AT+FLI="49 xxx xxxxx"' -> OK
01/29 22:47:23 dem  mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0' -> OK
01/29 22:47:23 dem  waiting...
01/29 22:51:13 dem  wfr: waiting for `RING''
01/29 22:51:23 dem  mdm_read_byte: read returned -1: Interrupted system call
01/29 22:51:23 dem  wfr: timeout waiting for RING
01/29 22:51:23 dem  huh? Junk on the line?


        Ciao,
                Ingo