Mgetty gets NO CARRIER on reciept of fax connection

"John M Kodis" (kodis@ccmail.stx.com)
Sun, 19 Oct 1997 15:05:25 est



I'm having trouble getting mgetty to receive faxes. As the log 
fragment below shows, the RING is detected, but the ATA command is 
answered with an ATA / +FMD / NO CARRIER sequence. Reasonably enough, 
mgetty aborts the transaction when the NO CARRIER action string is 
found. Sendfax works fine, now that I've gotten some flow control 
problems ironed out.

10/18 14:41:56 yS2 waiting for ``RING''
10/18 14:41:56 yS2 got: [0d][0a]RING ** found ** 
10/18 14:41:56 yS2 send: ATA[0d]
10/18 14:41:56 yS2 waiting for ``CONNECT''
10/18 14:41:56 yS2 got: [0d][0a]ATA[0d][0d][0a]+FDM[0d][0a][0d][0a]NO CARRIER 
10/18 14:42:11 yS2 found action string: ``NO CARRIER''
10/18 14:42:11 ##### failed A_FAIL dev=ttyS2, pid=18947, caller=none, conn='', 
name=''

This raises a number of questions:

 1) Is this a common problem, and if so, how should I correct it? 
 Nothing in the mgetty+sendfax documentation seemed applicable.
 
 2) Is there a list of the FAX modem strings that would explain, 
 e.g., what +FDM means? This would be helpful in trying to resolve 
 the problem on my own.
 
 3) Are there any other sources of debugging information that I 
 could access or supply to help get a better handle on what is 
 going wrong here?

The complete trace of the session follows. All looks normal to my 
untrained eye right up until the end, when the NO CARRIER sequence 
shown above occurs.

Thanks in advance for any assistance that you can offer, and for 
providing such a complete fax package.

-- John Kodis.

--
10/18 11:55:24 yS2 mgetty: experimental test release 1.1.9-Aug17 
10/18 11:55:24 yS2 mgetty.c compiled at Oct 18 1997, 11:43:45 
10/18 11:55:24 yS2 reading configuration data for port 'ttyS2'
10/18 11:55:24 yS2 reading /usr/local/etc/mgetty+sendfax/mgetty.config... 
10/18 11:55:24 yS2 conf lib: read: 'debug 4'
10/18 11:55:24 yS2 conf lib: read: 'fax-id 410-255-4739' 
10/18 11:55:24 yS2 conf lib: read: 'speed 38400'
10/18 11:55:24 yS2 key: 'speed', type=0, flags=3, data=38400 
10/18 11:55:24 yS2 key: 'switchbd', type=0, flags=1, data=0 
10/18 11:55:24 yS2 key: 'direct', type=3, flags=1, data=FALSE 
10/18 11:55:24 yS2 key: 'blocking', type=3, flags=1, data=FALSE 
10/18 11:55:24 yS2 key: 'port-owner', type=1, flags=1, data=uucp
10/18 11:55:24 yS2 key: 'port-group', type=1, flags=0, data=(empty) 
10/18 11:55:24 yS2 key: 'port-mode', type=0, flags=1, data=432 
10/18 11:55:24 yS2 key: 'toggle-dtr', type=3, flags=1, data=TRUE
10/18 11:55:24 yS2 key: 'toggle-dtr-waittime', type=0, flags=1, data=500 
10/18 11:55:24 yS2 key: 'data-only', type=3, flags=1, data=FALSE
10/18 11:55:24 yS2 key: 'fax-only', type=3, flags=1, data=FALSE 
10/18 11:55:24 yS2 key: 'modem-type', type=1, flags=1, data=auto
10/18 11:55:24 yS2 key: 'init-chat', type=2, flags=1, data= \dATQ0V1H0 OK 
ATS0=0Q0&D3&C1 OK 
10/18 11:55:24 yS2 key: 'force-init-chat', type=2, flags=1, data= 
\d\d\d\d+++\d\d\d
\dATQ0V1H0 OK 
10/18 11:55:24 yS2 key: 'modem-check-time', type=0, flags=1, data=3600 
10/18 11:55:24 yS2 key: 'rings', type=0, flags=1, data=1
10/18 11:55:24 yS2 key: 'get-cnd-chat', type=2, flags=0, data=(empty)
10/18 11:55:24 yS2 key: 'answer-chat', type=2, flags=1, data= ATA CONNECT \c 
  
10/18 11:55:24 yS2 key: 'answer-chat-timeout', type=0, flags=1, data=80 
10/18 11:55:24 yS2 key: 'autobauding', type=3, flags=1, data=FALSE 
10/18 11:55:24 yS2 key: 'ringback', type=3, flags=1, data=FALSE
10/18 11:55:24 yS2 key: 'ringback-time', type=0, flags=1, data=30 
10/18 11:55:24 yS2 key: 'ignore-carrier', type=3, flags=1, data=FALSE 
10/18 11:55:24 yS2 key: 'issue-file', type=1, flags=1, data=/etc/issue 
10/18 11:55:24 yS2 key: 'prompt-waittime', type=0, flags=1, data=500 
10/18 11:55:24 yS2 key: 'login-prompt', type=1, flags=1, data=@!login: 
10/18 11:55:24 yS2 key: 'login-time', type=0, flags=1, data=240
10/18 11:55:24 yS2 key: 'fido-send-emsi', type=3, flags=1, data=TRUE 
10/18 11:55:24 yS2 key: 'fax-id', type=1, flags=3, data=410-255-4739 
10/18 11:55:24 yS2 key: 'fax-server-file', type=1, flags=0, data=(empty) 
10/18 11:55:24 yS2 key: 'diskspace', type=0, flags=1, data=1024
10/18 11:55:24 yS2 key: 'notify', type=1, flags=1, data=faxadmin 
10/18 11:55:24 yS2 key: 'fax-owner', type=1, flags=1, data=uucp 
10/18 11:55:24 yS2 key: 'fax-group', type=1, flags=0, data=(empty) 
10/18 11:55:24 yS2 key: 'fax-mode', type=0, flags=1, data=432 
10/18 11:55:24 yS2 key: 'debug', type=0, flags=2, data=5
10/18 11:55:24 yS2 key: 'statistics-chat', type=2, flags=0, data=(empty) 
10/18 11:55:24 yS2 key: 'statistics-file', type=1, flags=0, data=(empty) 
10/18 11:55:24 yS2 key: 'gettydefs', type=1, flags=1, data=n
10/18 11:55:24 yS2 key: 'term', type=1, flags=0, data=(empty) 
10/18 11:55:24 yS2 check for lockfiles
10/18 11:55:24 yS2 checklock: stat failed, no file 
10/18 11:55:24 yS2 locking the line
10/18 11:55:24 yS2 makelock(ttyS2) called
10/18 11:55:24 yS2 do_makelock: lock='/var/lock/LCK..ttyS2' 
10/18 11:55:24 yS2 lock made
10/18 11:55:25 yS2 tio_get_rs232_lines: status: RTS CTS DSR DTR 
10/18 11:55:25 yS2 lowering DTR to reset Modem
10/18 11:55:25 yS2 tss: set speed to 38400 (017) 
10/18 11:55:25 yS2 tio_set_flow_control( HARD )
10/18 11:55:25 yS2 waiting for line to clear (VTIME), read: 
10/18 11:55:25 yS2 send: \dATQ0V1H0[0d]
10/18 11:55:26 yS2 waiting for ``OK''
10/18 11:55:26 yS2 got: ATQ0V1H0[0d][0d][0a]OK ** found ** 
10/18 11:55:26 yS2 send: ATS0=0Q0&D3&C1[0d]
10/18 11:55:26 yS2 waiting for ``OK''
10/18 11:55:26 yS2 got: [0d][0a]ATS0=0Q0&D3&C1[0d][0d][0a]OK ** found ** 
10/18 11:55:26 yS2 mdm_send: 'ATI'
10/18 11:55:26 yS2 mdm_gis: string 1: '3362' 
10/18 11:55:26 yS2 mdm_identify: string '3362' 
10/18 11:55:26 yS2 unknown numerical modem id 3362 
10/18 11:55:27 yS2 mdm_send: 'AT+FCLASS=2.0'
10/18 11:55:27 yS2 mdm_command: string 'AT+FCLASS=2.0' 
10/18 11:55:27 yS2 mdm_command: string 'OK' -> OK 
10/18 11:55:27 yS2 mdm_send: 'AT+FAA=1;+FCR=1'
10/18 11:55:27 yS2 mdm_command: string 'AT+FAA=1;+FCR=1' 
10/18 11:55:27 yS2 mdm_command: string 'OK' -> OK
10/18 11:55:27 yS2 mdm_send: 'AT+FBO=1'
10/18 11:55:27 yS2 mdm_command: string 'AT+FBO=1' 
10/18 11:55:27 yS2 mdm_command: string 'OK' -> OK 
10/18 11:55:27 yS2 mdm_send: 'AT+FNR=1,1,1,0'
10/18 11:55:27 yS2 mdm_command: string 'AT+FNR=1,1,1,0' 
10/18 11:55:27 yS2 mdm_command: string 'OK' -> OK
10/18 11:55:27 yS2 mdm_send: 'AT+FLI="410-255-4739"'
10/18 11:55:27 yS2 mdm_command: string 'AT+FLI="410-255-4739"' 
10/18 11:55:27 yS2 mdm_command: string 'OK' -> OK
10/18 11:55:28 yS2 mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0'
10/18 11:55:28 yS2 mdm_command: string 'AT+FCC=1,5,0,2,0,0,0,0' 
10/18 11:55:28 yS2 mdm_command: string 'OK' -> OK
10/18 11:55:28 yS2 waiting for line to clear (VTIME), read: 
10/18 11:55:28 yS2 removing lock file
10/18 11:55:28 yS2 waiting...
10/18 12:55:28 yS2 checking if modem is still alive 
10/18 12:55:28 yS2 makelock(ttyS2) called
10/18 12:55:28 yS2 do_makelock: lock='/var/lock/LCK..ttyS2' 
10/18 12:55:28 yS2 lock made
10/18 12:55:28 yS2 mdm_send: 'AT'
10/18 12:55:28 yS2 mdm_command: string 'AT'
10/18 12:55:28 yS2 mdm_command: string 'OK' -> OK
10/18 12:55:28 yS2 waiting for line to clear (VTIME), read: 
10/18 12:55:28 yS2 removing lock file
10/18 12:55:28 yS2 waiting...
10/18 13:55:28 yS2 checking if modem is still alive 
10/18 13:55:28 yS2 makelock(ttyS2) called
10/18 13:55:28 yS2 do_makelock: lock='/var/lock/LCK..ttyS2' 
10/18 13:55:28 yS2 lock made
10/18 13:55:29 yS2 mdm_send: 'AT'
10/18 13:55:29 yS2 mdm_command: string 'AT'
10/18 13:55:29 yS2 mdm_command: string 'OK' -> OK
10/18 13:55:29 yS2 waiting for line to clear (VTIME), read: 
10/18 13:55:29 yS2 removing lock file
10/18 13:55:29 yS2 waiting...
10/18 14:41:56 yS2 checking lockfiles, locking the line 
10/18 14:41:56 yS2 makelock(ttyS2) called
10/18 14:41:56 yS2 do_makelock: lock='/var/lock/LCK..ttyS2' 
10/18 14:41:56 yS2 lock made
10/18 14:41:56 yS2 waiting for ``RING''
10/18 14:41:56 yS2 got: [0d][0a]RING ** found ** 
10/18 14:41:56 yS2 send: ATA[0d]
10/18 14:41:56 yS2 waiting for ``CONNECT''
10/18 14:41:56 yS2 got: [0d][0a]ATA[0d][0d][0a]+FDM[0d][0a][0d][0a]NO CARRIER 
10/18 14:42:11 yS2 found action string: ``NO CARRIER''
10/18 14:42:11 ##### failed A_FAIL dev=ttyS2, pid=18947, caller=none, conn='', 
name=''
  
10/18 14:42:11 yS2 removing lock file

.