mgetty interfering with diald

Gert Doering (gert@greenie.muc.de)
Fri, 17 Jul 1998 20:23:25 +0200


Hi,

Herbert Betz wrote:
> > Seems sendfax is misconfigured.  Look at the sendfax log file.
> > Maybe mgetty is misconfigured?  Look at the mgetty log file to find out
> > what's happening.
> 
> Well, I looked again and again at the log files and mgetty.info-Files and
> mgetty+sendfax - config files.
> I don't quite like to do this, but I see not much choice than
> to send my logs. Maybe somebody could pick out quickly the offending
> line, that I cannot see in /var/log/mgetty.modem ?

Let's look at the files, and see what can be found.

> There are 3 questions:
> 1) Why would DIALD not dial, when mgetty is active ?

Doesn't it dial *at all*, or does it *fail*? That's a very important
difference.

> (see /var/log/mgetty.modem as attachement)
> 2) Why is the mgetty ringback mode not working ?
> (see /var/log/mgetty.modem below)

That can be seen in the logs.

> 3) in sendfax.config I read:
> # Modem on ttyS1 doesn't work reliably in class 2.0, use class 2 instead
> port ttyS1
> modem-type cls2

That's an EXAMPLE how to use "port-specific stuff".  Since I have NO idea
what kind of modem YOU have, this EXAMPLE is likely to be WRONG on your
system.

> ... but what, if I have a class 2.0 fax modem ? I cannot get
> my USR Courier 14400 or my USR Sportster 33.6 Faxmodem to fax
> with sendfax ...

You won't get them to work reliably anyway.  See my comments about very
early USR Courier modems (before the V.34 modems) and recent USR Sportsters
in the mgetty manual on http://alpha.greenie.net/mgetty/.

[..]
> If mgetty and diald are run independently from one another, they produce
> each a 11 bit ASCII lock file named /var/lock/LCK..modem
> containing a PID. The same applies to sendfax.

I agree, in that case, it really should work (and looking at the logs,
things look good).

> in /etc/inittab:
> mo:23:respawn:/usr/sbin/mgetty -x6 /dev/modem
> 
> ps -ax will produce accordingly to the inittab entry:
> 2982  ?  S      0:00 /usr/sbin/mgetty -x6 /dev/modem

ok.

> debug 5
> fax-id 49 871 63678
> ringback YES
> ringback-time 60

Noted.  Maybe there's a bug in the timing somewhere.

[..]
> 07/17 09:55:35 dem  mgetty: experimental test release 1.1.8-Jul27

... but I'm not going to hunt RING bugs in anything prior to 1.1.16, as
the RING handler has been completely rewritten, and we can explect
completely new and amazing bugs.

> 07/17 09:55:39 dem   waiting for line to clear (VTIME), read: 
> 07/17 09:55:39 dem   removing lock file
> 07/17 09:55:39 dem  waiting...

Modem initialization fine, nothing too unusual.

> /var/log/mgetty.modem
> after 2 consecutive dial-in attempts to test 'RINGBACK':
> ********************************************************
> 07/17 08:48:43 dem    select returned 1
> 07/17 08:48:43 dem   checking lockfiles, locking the line
> 07/17 08:48:43 dem   makelock(modem) called
> 07/17 08:48:43 dem   do_makelock: lock='/var/lock/LCK..modem'
> 07/17 08:48:43 dem   lock made
> 07/17 08:48:43 dem  waiting for ``RING''
> 07/17 08:48:43 dem   got: [0d]
> 07/17 08:48:43 dem    CND: OK[0a]RING ** found **
> 07/17 08:48:43 dem  waiting for ``RING''
> 07/17 08:48:43 dem   got: [0d]
> 07/17 08:48:43 dem    CND: RING[0a][0d][0a]RING ** found **
> ...
> (repeated about 8 times)
> ...
> 07/17 08:49:25 dem  waiting for ``RING''
> 07/17 08:49:25 dem   got: [0d]
> 07/17 08:49:25 dem    CND: RING[0a][0d][0a]RING ** found **
> 07/17 08:49:28 dem  waiting for ``RING''
> 07/17 08:49:28 dem   got: [0d]
> 07/17 08:49:28 dem    CND: RING[0a]
> 07/17 08:49:45 dem  timeout in chat script, waiting for `RING'
> 07/17 08:49:45 dem  ringback: phone stopped after 13 RINGs, waiting for re-ring

Well, that was the first call...

> 07/17 08:49:45 dem  waiting for ``RING''
> 07/17 08:49:45 dem   got:

now it's waiting 60 seconds for the second call ("ringback-time 60")...

> 07/17 08:50:45 dem  timeout in chat script, waiting for `RING'
> 07/17 08:50:45 ##### missed ringback!

... which doesn't come.

So, where's the problem? Are you confusing "ringback" with "callback"?
That's a different issue.  Ringback means, *you* call it *twice*, with
some time in between (10-20 seconds), but not more than 60 seconds between
both calls.

[..]

> Content-Description: /var/log/mgetty.modem after pushing DIALD

Now let's see whether that is more interesting...

> 07/17 14:08:31 dem    select returned 1
> 07/17 14:08:31 dem   checking lockfiles, locking the line
> 07/17 14:08:31 dem   makelock(modem) called
> 07/17 14:08:31 dem   do_makelock: lock='/var/lock/LCK..modem'
> 07/17 14:08:31 dem  lock not made: lock file exists (pid=3376)
> 07/17 14:08:31 dem   lock file exists (dialout)!
> 07/17 14:08:31 dem   lockfile found, pid=3376
> 07/17 14:08:31 dem    looking for utmp entry... (my PID: 3564)
> 07/17 14:08:31 dem   utmp + wtmp entry made
> 07/17 14:08:31 dem   lockfile found, pid=3376
> 07/17 14:08:41 dem   lockfile found, pid=3376
> 07/17 14:08:51 dem   lockfile found, pid=3376
> 07/17 14:09:01 dem   lockfile found, pid=3376
> 07/17 14:09:11 dem   lockfile found, pid=3376
> 07/17 14:09:21 dem   checklock: stat failed, no file
> 07/17 14:09:26 dem   checklock: stat failed, no file

Hmmm. I have the nagging suspicion that diald locks the line just fine
*while dialing*, but removes the lock afterwards, and thus mgetty will
collide with dip/pppd.  This would explain why the lock exists only for 50
seconds, which is far too short for a normal "internet call".

One would need to see the diald log file *with time stamps* at *exactly*
this time to compare what's happening.

gert
-- 
USENET is *not* the non-clickable part of WWW!
                                                           //www.muc.de/~gert/
Gert Doering - Munich, Germany                             gert@greenie.muc.de
fax: +49-89-35655025                        gert.doering@physik.tu-muenchen.de