arthur诊断故事第一集--vol的故事

[weixin_38051062]

arthur诊断故事第一集--vol的故事
希望大家能与我共同探讨，那样大家都可以少走一些弯路，多一些效率。
版权所有：arthur
转载注明：转载自 永远的UNIX-solaris版 http://www.chinaunix.net

问题现象：

$ cd /vol
$ ls -l
NFS server for volume management (/vol) not responding still trying
^CNFS getattr failed for server for volume management (/vol): error 23 (RPC: Uni
tdata error)
$cd /
$ls -al 居然死机 ft


实验过程：

由于是带服务的机器，只能选择在我的机器上做实验了，哎，可怜我的肉鸡啊。

做了自己都忘记的几十步操作后终于发现vold不正常了，窃喜。

# /usr/sbin/vold //你可能问我为什么不用volmgt起，问题是一样的。

Mon Dec 15 16:23:30 2003 fatal: mounting of "/vol" failed

debug模式启动，发现以下文件内容
#/usr/sbin/vold -t -v -L 99 -l /var/adm/vold.debug_log

#more /var/adm/vold.debug_log
Mon Dec 15 11:45:30 2003 debug[5]: main: debug level 99 (verbose = 1)
Mon Dec 15 11:45:30 2003 debug[1]: reading config file: /etc/vold.conf
Mon Dec 15 11:45:30 2003 debug[1]: dso_load(): opening /usr/lib/vold/db_mem.so.1

Mon Dec 15 11:45:30 2003 info: dso_load: loaded /usr/lib/vold/db_mem.so.1
Mon Dec 15 11:45:30 2003 debug[1]: dso_load(): opening /usr/lib/vold/label_cdrom
.so.1
Mon Dec 15 11:45:30 2003 info: label_cdrom: init
Mon Dec 15 11:45:30 2003 info: dso_load: loaded /usr/lib/vold/label_cdrom.so.1
Mon Dec 15 11:45:30 2003 debug[1]: dso_load(): opening /usr/lib/vold/label_dos.s
o.1
Mon Dec 15 11:45:30 2003 info: dso_load: loaded /usr/lib/vold/label_dos.so.1
Mon Dec 15 11:45:30 2003 debug[1]: dso_load(): opening /usr/lib/vold/label_sun.s
o.1
Mon Dec 15 11:45:30 2003 info: label_sun: init
Mon Dec 15 11:45:30 2003 info: dso_load: loaded /usr/lib/vold/label_sun.so.1
Mon Dec 15 11:45:30 2003 debug[1]: dso_load(): opening /usr/lib/vold/dev_cdrom.s
o.1
Mon Dec 15 11:45:30 2003 info: dso_load: loaded /usr/lib/vold/dev_cdrom.so.1
Mon Dec 15 11:45:30 2003 debug[10]: dev_use: cdrom drive at /dev/rdsk/c*s2, cdro
m%d@, u/g=nobody/nobody, temp_flag=FALSE, force_flag=FALSE
Mon Dec 15 11:45:30 2003 debug[10]: path = /dev/rdsk/c0t6d0s2 and rawpath = /dev
/rdsk/c0t6d0s2
Mon Dec 15 11:45:30 2003 debug[10]: path = /dev/rdsk/c1t0d0s2 and rawpath = /dev
/rdsk/c1t0d0s2
Mon Dec 15 11:45:30 2003 debug[5]: cdrom(probing): /dev/rdsk/c1t0d0s2 is not a C
D-ROM drive
Mon Dec 15 11:45:30 2003 debug[5]: cdrom(probing2):dkc.dki_ctype = d; DKC_CDROM
= 1
Mon Dec 15 11:45:30 2003 debug[3]: /dev/rdsk/c1t0d0s2 wrong kind of device
Mon Dec 15 11:45:30 2003 debug[10]: path = /dev/rdsk/c1t1d0s2 and rawpath = /dev
/rdsk/c1t1d0s2
Mon Dec 15 11:45:30 2003 debug[5]: cdrom(probing): /dev/rdsk/c1t1d0s2 is not a C
D-ROM drive
Mon Dec 15 11:45:30 2003 debug[5]: cdrom(probing2):dkc.dki_ctype = d; DKC_CDROM
= 1
Mon Dec 15 11:45:30 2003 debug[3]: /dev/rdsk/c1t1d0s2 wrong kind of device
Mon Dec 15 11:45:30 2003 info: cdrom_use: /dev/rdsk/c0t6d0s2
Mon Dec 15 11:45:30 2003 debug[5]: Firmware does not need fdisk fix ***
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added rdsk (0x534c0) to /vol (0x
524b0)
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added dsk (0x536a0) to /vol (0x5
24b0)
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added rmt (0x53880) to /vol (0x5
24b0)
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added dev (0x53a60) to /vol (0x5
24b0)
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[15]: startupdate: dev
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: dev, db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate: dev
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added rdsk (0x53b80) to dev (0x5
3a60)
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[15]: startupdate: dev
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: dev, db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate: dev
Mon Dec 15 11:45:30 2003 debug[15]: startupdate: rdsk
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: rdsk, db 'mem'
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added c0t6d0 (0x53ca0) to rdsk (
0x53b80)
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO=%sp%d; path_trunc=/dev/rdsk/c
0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0p0; rawpth=/dev/rdsk
/c0t6d0p0
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO=%sp%d; path_trunc=/dev/rdsk/c
0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0p1; rawpth=/dev/rdsk
/c0t6d0p1
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO=%sp%d; path_trunc=/dev/rdsk/c
0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0p2; rawpth=/dev/rdsk
/c0t6d0p2
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO=%sp%d; path_trunc=/dev/rdsk/c
0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0p3; rawpth=/dev/rdsk
/c0t6d0p3
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO=%sp%d; path_trunc=/dev/rdsk/c
0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0p4; rawpth=/dev/rdsk
/c0t6d0p4
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s0; rawpth=/dev/rdsk
/c0t6d0s0
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s1; rawpth=/dev/rdsk
/c0t6d0s1
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s2; rawpth=/dev/rdsk
/c0t6d0s2
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s3; rawpth=/dev/rdsk
/c0t6d0s3
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s4; rawpth=/dev/rdsk
/c0t6d0s4
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s5; rawpth=/dev/rdsk
/c0t6d0s5
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s6; rawpth=/dev/rdsk
/c0t6d0s6
Mon Dec 15 11:45:30 2003 debug[9]: CDROM_NAMEPROTO_S=%ss%d; path_trunc=/dev/rdsk
/c0t6d0
Mon Dec 15 11:45:30 2003 debug[9]: namebuf1=/dev/rdsk/c0t6d0s7; rawpth=/dev/rdsk
/c0t6d0s7
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[15]: startupdate: dev
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: dev, db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate: dev
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added dsk (0x53dc0) to dev (0x53
a60)
Mon Dec 15 11:45:30 2003 debug[15]: startupdate:
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: , db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate:
Mon Dec 15 11:45:30 2003 debug[15]: startupdate: dev
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: dev, db 'mem'
Mon Dec 15 11:45:30 2003 debug[15]: endupdate: dev
Mon Dec 15 11:45:30 2003 debug[15]: startupdate: dsk
Mon Dec 15 11:45:30 2003 debug[15]: setupdated: dsk, db 'mem'
Mon Dec 15 11:45:30 2003 debug[10]: node_mkobj: added c0t6d0 (0x53ee0) to dsk (0
x53dc0)
Mon Dec 15 11:45:30 2003 debug[5]: cdp->;cd_blk_p0_path = /dev/dsk/c0t6d0p0
Mon Dec 15 11:45:30 2003 debug[15]: dev_makedp: just added mapping for /dev/rdsk
/c0t6d0s2 (32,50)
Mon Dec 15 11:45:30 2003 debug[4]: dev_usepath: new path /dev/rdsk/c0t6d0
Mon Dec 15 11:45:30 2003 debug[1]: dso_load(): opening /usr/lib/vold/dev_floppy.
so.1
Mon Dec 15 11:45:30 2003 info: dso_load: loaded /usr/lib/vold/dev_floppy.so.1
Mon Dec 15 11:45:30 2003 debug[10]: dev_use: floppy drive at /dev/rdiskette[0-9]
, floppy%d@, u/g=nobody/nobody, temp_flag=FALSE, force_flag=FALSE
Mon Dec 15 11:45:30 2003 warning: either couldn't find a driver for floppy "/dev
/rdiskette[0-9]", or it's already managed
Mon Dec 15 11:45:30 2003 debug[1]: dso_load(): opening /usr/lib/vold/dev_rmdisk.
so.1
Mon Dec 15 11:45:30 2003 info: dso_load: loaded /usr/lib/vold/dev_rmdisk.so.1
Mon Dec 15 11:45:30 2003 debug[10]: dev_use: rmdisk drive at /dev/rdsk/c*s2, rmd
isk%d@, u/g=nobody/nobody, temp_flag=FALSE, force_flag=FALSE
Mon Dec 15 11:45:30 2003 debug[5]: rmdisk(probing): "/dev/rdsk/c0t6d0s2" already
in use
Mon Dec 15 11:45:30 2003 debug[3]: /dev/rdsk/c0t6d0s2 wrong kind of device
Mon Dec 15 11:45:30 2003 debug[9]: Rawpath = /dev/rdsk/c1t0d0s2
Mon Dec 15 11:45:30 2003 debug[9]: checking on /dev/rdsk/c1t0d0s2, is it removab
le?
Mon Dec 15 11:45:30 2003 debug[5]: rmdisk(probing): device "/dev/rdsk/c1t0d0s2"
not removable
Mon Dec 15 11:45:30 2003 debug[3]: /dev/rdsk/c1t0d0s2 wrong kind of device
Mon Dec 15 11:45:30 2003 debug[9]: Rawpath = /dev/rdsk/c1t1d0s2
Mon Dec 15 11:45:30 2003 debug[9]: checking on /dev/rdsk/c1t1d0s2, is it removab
le?
Mon Dec 15 11:45:30 2003 debug[5]: rmdisk(probing): device "/dev/rdsk/c1t1d0s2"
not removable
Mon Dec 15 11:45:30 2003 debug[3]: /dev/rdsk/c1t1d0s2 wrong kind of device
Mon Dec 15 11:45:30 2003 warning: either couldn't find a driver for rmdisk "/dev
/rdsk/c*s2", or it's already managed
Mon Dec 15 11:45:30 2003 debug[10]: vold_util.c(2104): 'fs' is considered unsafe
Mon Dec 15 11:45:30 2003 debug[10]: vold_util.c(2104): 'fs' is considered unsafe
Mon Dec 15 11:45:30 2003 debug[10]: vold_util.c(2104): 'fs' is considered unsafe
Mon Dec 15 11:45:30 2003 debug[10]: vold_util.c(2104): 'fs' is considered unsafe
Mon Dec 15 11:45:30 2003 info: vold: running
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0p
0" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom: /dev/rdsk/c0t6d0p0; No such file or di
rectory
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
0" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
1" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
2" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
3" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
4" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
5" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
6" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[1]: cdrom_thread_wait: opening "/dev/rdsk/c0t6d0s
7" RDONLY ...
Mon Dec 15 11:45:30 2003 debug[3]: cdrom_thread_wait: ioctl(DKIOCSTATE) on "/dev
/rdsk/c0t6d0s2"
Mon Dec 15 11:45:30 2003 debug[12]: vold_run: about to poll()
Mon Dec 15 11:45:30 2003 debug[12]: vold_run: poll() returned 1 (errno 1)
GETATTR call(fh=[0x0, 0x1, 0x1])
GETATTR return (stat=NFS_OK, type = 2, mode = 555, nlink = 6, uid = 0, gid = 0,
size = 512, blocksize = 512, rdev = 0, blocks = 0, fsid = 0, fileid = 2, atime=M
on Dec 15 11:45:30 2003, mtime=Mon Dec 15 11:45:30 2003, ctime=Mon Dec 15 11:45:
30 2003)
Mon Dec 15 11:45:30 2003 debug[12]: vold_run: about to poll()
Mon Dec 15 11:45:30 2003 debug[3]: cdrom_thread_wait: ioctl(DKIOCSTATE) on "/dev
/rdsk/c0t6d0s2"
Mon Dec 15 11:45:30 2003 warning: vold restarted
Mon Dec 15 11:45:30 2003 debug[12]: vold_run: poll() returned -1 (errno 4)
Mon Dec 15 11:45:30 2003 debug[10]: vold_run: poll interrupted



Mon Dec 15 11:45:30 2003 fatal: mounting of "/vol" failed


重新CP正确的vold.conf回来，发现系统错误依旧
重新启动系统，使用正确的文件配置，居然可以启动
#/usr/sbin/vold

一切正常了

# cd vol
# ls
dev   dsk   rdsk  rmt
# ps -ef | grep vold
    root   259     1  0 16:27:40 ?        0:00 /usr/sbin/vold
    root   416   413  0 16:28:43 pts/2    0:00 grep vold
#

所以怀疑重新启动系统可以解决问题！

果然，重新启动以后一切正常，那和NT有什么区别了呢！

我想可能它和/TMP有关系，于是删除了/TMP下所有的东西！

重新/usr/sbin/vold，问题依旧,靠，郁闷呀我！

那是什么问题呢

试试把/vol -f umount 下来
# umount /vol
nfs umount: u10:vold(pid471) server not responding: RPC: Program not registered
重新启动/usr/sbin/vold，停在这里不动了，哈哈，我想我找到问题了。

解决方法：
我想我们的解决方法就是，umount -f /vol,重新启动/usr/sbin/vold


就这么一个小东西又弄了几个小时，K，难道我真的老了吗？