[2066] in SIPB-AFS-requests
outage this morning probably micropolis' fault
daemon@ATHENA.MIT.EDU (Tom Yu)
Sat Jul 29 08:59:01 1995
Date: Sat, 29 Jul 1995 08:58:51 -0400
To: sipb-afsreq@MIT.EDU
Cc: hartmans@MIT.EDU, mycroft@MIT.EDU
From: Tom Yu <tlyu@MIT.EDU>
At about 04:50, rosebud's fileserver stopped responding and wedged
into disk wait. After a bos restart failed, I attempted to reboot the
machine, but first edited rc.conf to not start afs. At this point, I
was unable to get a shell, so I used bos exec to edit the rc.conf and
reboot. The reboot hung, probably since some disks could not be
accessed. I suspect the Micropolis drive is at fault. I did manage
to get a crash dump before rebooting, though I did not get over to W20
from E40 until after 06:00 because of the heavy rain. Fortunately
proven volunteered to drive me over.
I started the afs server processes almost without incident, though the
bosserver and the db servers spontaneously died as soon as I made it
back into the office. I kill -QUIT'ed the fileserver process that was
still running and manually started the bosserver again. It stayed up
this time.
[Some examination of the fileserver source code indicates that a
SIGTERM will force a debugging stats dump of its fd's rather than
telling it to quit. This strikes me as very wrong. Transarc sux.]
In case anyone wants to take another look, I left the crashdump
sitting in /var/adm/crash/vm{core,unix}.0. Please don't delete it
yet; I may still want to look at it again. (and there's plenty of
free space in /var anyway) Yes, I did restore "AFSSRV=true" in
rc.conf.
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
ignore everything below if you don't want gory details of crashdump
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
Anyway I poked around the crash dump and got a few interesting
tidbits:
[gee crash is a really useful tool if you can beat it into submission]
> scsi -targ
SCSI target informaiton:
Controller #0 Targid #0:
sc_alive: 1
device_comp: rzcomplete
sc_flags: Operation complete
sc_cat_flags: 0x0
sc_devtype: DISK device
sc_unit: 0
sc_device: RZxx
sc_szflags: Normal (no szflags set),Disconnect occured during this command
sc_curcmd: DISK: WRITE 10-byte Command
sc_actcmd: DISK: WRITE 10-byte Command
sc_selstat: The device has disconnected
sc_xstate: Write DMA processing
sc_xevent: Process next request from queue
sc_pxstate: Start DMA WRITE
sc_c_status: Good
sc_c_snskey: Successful cmd or EOT, ILI, FILEMARK
sc_status: Good
sc_message: Disconnect
sc_devnam: MICROP 3243-19SC2908a4
sc_revlvl: CN05
This seems to indicate that the Micropolis drive did an asynchronous
process of a write command and never reconnected to the bus.
> proc
SLT S PID PPID PGRP UID PY CPU SIGS Event Flags
%%%%%stuff deleted%%%%%
16 s 750 1 749 0 20 3 100 buf[504] in pagi
17 s 246 1 228 0 20 0 124 buf[2] in pagi ptchg
18 s 247 1 228 0 20 3 4120 buf[346] in pagi ptchg
35 s 753 1 752 0 20 2 100 buf[52] in pagi
40 s 762 1 758 0 21 19 101 buf[504] in pagi ptchg
42 r 766 1 228 0 113 255 0 in ptchg
> ps
SLOT PID UID COMMAND
%%%%%stuff deleted%%%%%
16 750 0 (ls)
17 246 0 (fileserver)
18 247 0 (volserver)
35 753 0 (ls)
40 762 0 (quota)
42 766 0 (reboot)
The "ls" command were what I tried to execute (ls /vicepb, ls /vicepc)
right before the machine mostly hung. The quota process was from a
hanging login. Interestingly enough, the buf structures reveal the
following:
> buf 504 2 346 52 504
BUF MAJ MIN BLOCK COUNT SIZE RESID GNO FWD BACK FLAGS
504 15 3 6912 7168 8192 0 52 -1 read busy wnt out
2 15 3 919504 8192 8192 0 504 -1 read busy out
346 15 4 652880 8192 8192 0 2 339 busy out cache
52 15 4 178528 3072 4096 0 144 -1 read busy out
504 15 3 6912 7168 8192 0 52 -1 read busy wnt out
These are the buf headers for the buffers in use by the hanging
processes. Note that they're all tagged as "busy". Also, I noticed that:
brw------- 1 root 21, 3 Jan 24 1995 /dev/rz0d
brw------- 1 root 21, 4 Jan 24 1995 /dev/rz0e
Note: 21 == 0x15. Yes, the major/minor numbers output by crash are in
hex. No, they don't tell you that. blurgh.
Anyway I think we have a smoking gun. The Micropolis disk is probably
flaking somehow w.r.t. asynchronous writes. If this happens again we
should consider getting it tested/replaced. For now I'm really
tempted to move the data off of it and onto the new Seagate.
FYI, to force a dump on a maxine:
1. Halt the machine. (control-alt-return)
2. Type "go 0x8003008" at the ">>>" prompt. (in case this is hard to
remember, just remember that it's the kernel start address +
8; you can reboot a random maxine in the cluster to find the
start address)
3. Wait for dump to finish.
4. Pray that you remembered to set "SAVECORE=true" :-)
---Tom
