Re: serial console oddity

On  9 Nov, Don Lewis wrote:
> On  9 Nov, Bruce Evans wrote:
>> On Sat, 8 Nov 2003, Don Lewis wrote:

>>> This is totally consistent until I "kill
>>> -HUP" syslogd, which I believe causes syslogd to close and open
>>> /dev/console, after which the syslog output appears correct on the
>>> console. When the syslogd output is being corrupted, I can cat a file to
>>> /dev/console and the output appears to be correct.
>> 
>> When I debugged this, syslogd didn't seem to keep the console open,
>> so the open()/close() in ttymsg() always caused the problem.  I didn't
>> notice killing syslogd makes a difference.  Perhaps it helps due to a
>> missing close.  Holding the console open may be a workaround or even
>> the correct fix.  It's not clear where this should be done (should all
>> clients of ttymsg() do it?).  Running getty on the console or on the
>> underlying tty device should do it accidentally.
> 
> It looks to me like syslogd keeps the console open in addition to the
> open()/close() in ttymsg().  cfline() calls open() on anything that
> begins with '/' and calls isatty() to figure out whether it should set
> the type to F_CONSOLE, F_TTY, or F_FILE, and init() closes the file
> descriptor for all of these when syslogd is HUPed.
> 
> I wonder if the console descriptor is getting revoked ...

That appears to be the situation:

scratch:~ 101>cat /var/run/syslog.pid 
275
scratch:~ 102>fstat -p 275
USER     CMD          PID   FD MOUNT      INUM MODE         SZ|DV R/W
root     syslogd      275 root /             2 drwxr-xr-x    1024  r
root     syslogd      275   wd /             2 drwxr-xr-x    1024  r
root     syslogd      275 text /        575452 -r-xr-xr-x   32204  r
root     syslogd      275    0 /dev          8 crw-rw-rw-    null rw
root     syslogd      275    1 /dev          8 crw-rw-rw-    null rw
root     syslogd      275    2 /dev          8 crw-rw-rw-    null rw
root     syslogd      275    3* local dgram c6c97000
root     syslogd      275    4* internet6 dgram udp c6c84ee0
root     syslogd      275    5* internet dgram udp c6c85000
root     syslogd      275    6 /dev         17 crw-------    klog  r
root     syslogd      275    8 -         -         bad    -
root     syslogd      275    9 /        447635 -rw-r--r--   45602  w
root     syslogd      275   10 /        450144 -rw-------       0  w
root     syslogd      275   11 /        448526 -rw-------   85593  w
root     syslogd      275   12 /        447600 -rw-r-----    3119  w
root     syslogd      275   13 /        450142 -rw-r--r--   19324  w
root     syslogd      275   14 /        447744 -rw-r--r--     274  w
root     syslogd      275   15 /        447492 -rw-------   19063  w
root     syslogd      275   16 /        448732 -rw-------   15508  w
root     syslogd      275   17 /        450145 -rw-r-----       0  w
root     syslogd      275   18 /        450146 -rw-r-----       0  w

If we could somehow keep the console open, that would probably be a
sufficient fix for the problem of discarded output.  We probably don't
care in the case of messages to users' terminals, since the users
presumably have those devices open.  There's no such guarantee in the
case of the console.


BTW, here's an example where I HUPed syslogd so that it works, but the
rc script output is truncated.  I think the partial message at the
beginning of the 'vnlru' line should be "Stopping cron.".

Nov  9 12:46:54 scratch shutdown: reboot by dl: 
Stopping inetd.
Shutting down daemon processes:killall: Nov  9 12:46:56 scratch upsmon[504]: upsmon parent: exiting (child exited)
warning: kill -TERM 504: No such process
Nov  9 12:46:56 scratch kernel: pid 502 (upsd), uid 66: exited on signal 6
.
Stopping cWaiting (max 60 seconds) for system process `vnlru' to stop...stopped
Waiting (max 60 seconds) for system process `bufdaemon' to stop...stopped
Waiting (max 60 seconds) for system process `syncer' to stop...stopped

syncing disks, buffers remaining... 12 12 
done
Uptime: 13h34m21s
Shutting down ACPI
Rebooting...