NASの自作 Part22

ひきつづき再起動時のRAID構築失敗について調査しています。まず調査にはログが必要不可欠ということで dmesg に出力する方法を調べました。どうやら /dev/kmsg に書き込むこと dmesg コマンドで表示されるようです。さっそく /etc/init.d/mdadm-raid の先頭に以下のコマンドを追加して再起動してみます。

echo "#### mdadm-raid" > /dev/kmsg

結果は予想に反して、"md/raid:md0: not enough operational devices (8/10 failed)" のRAID構築失敗のエラーの後にログが出力されていました。どうやら失敗しているRAIDを再構築するコマンドは mdadm-raid ではなく、もっと前の起動処理で行われているようです。

とりあえず、 /etc/init.d にあるスクリプト全てにログを出力するコードを追加して再起動してみることにします。全てのスクリプトの先頭に "#### {スクリプト名}" という形式でログを出力します。

root@OMV-NODE804:~# dmesg | egrep '(sd|md|####)'
[    0.000000] Linux version 3.2.0-4-amd64 (debian-kernel@lists.debian.org) (gcc version 4.6.3 (Debian 4.6.3-14) ) #1 SMP Debian 3.2.68-1+deb7u3
[    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.2.0-4-amd64 root=UUID=6445948c-2f87-4c3c-a949-38a617780bc8 ro quiet
[    0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-3.2.0-4-amd64 root=UUID=6445948c-2f87-4c3c-a949-38a617780bc8 ro quiet
[    2.254821] usb usb1: Manufacturer: Linux 3.2.0-4-amd64 ehci_hcd
[    2.255242] usb usb2: Manufacturer: Linux 3.2.0-4-amd64 xhci_hcd
[    2.255419] usb usb3: Manufacturer: Linux 3.2.0-4-amd64 xhci_hcd
[    2.298704] usb usb4: Manufacturer: Linux 3.2.0-4-amd64 ehci_hcd
[    2.558824] sd 1:0:0:0: [sda] 234441648 512-byte logical blocks: (120 GB/111 GiB)
[    2.558836] sd 2:0:0:0: [sdb] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    2.558839] sd 2:0:0:0: [sdb] 4096-byte physical blocks
[    2.558867] sd 3:0:0:0: [sdc] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    2.558872] sd 3:0:0:0: [sdc] 4096-byte physical blocks
[    2.558875] sd 2:0:0:0: [sdb] Write Protect is off
[    2.558878] sd 2:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[    2.558886] sd 1:0:0:0: [sda] Write Protect is off
[    2.558889] sd 1:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    2.558895] sd 2:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.558906] sd 1:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.558909] sd 3:0:0:0: [sdc] Write Protect is off
[    2.558912] sd 3:0:0:0: [sdc] Mode Sense: 00 3a 00 00
[    2.558926] sd 3:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.559371]  sda: sda1 sda2 < sda5 >
[    2.559612] sd 1:0:0:0: [sda] Attached SCSI disk
[    2.560601] sd 1:0:0:0: Attached scsi generic sg0 type 0
[    2.560636] sd 2:0:0:0: Attached scsi generic sg1 type 0
[    2.560664] sd 3:0:0:0: Attached scsi generic sg2 type 0
[    2.607793] Pid: 0, comm: swapper/2 Not tainted 3.2.0-4-amd64 #1 Debian 3.2.68-1+deb7u3
[    3.112442]  sdc: unknown partition table
[    3.112571] sd 3:0:0:0: [sdc] Attached SCSI disk
[    3.127760]  sdb: unknown partition table
[    3.127875] sd 2:0:0:0: [sdb] Attached SCSI disk
[    3.500932] md: md0 stopped.
[    3.501331] md: bind
[    3.501438] md: bind
[    3.994858] md: raid6 personality registered for level 6
[    3.994860] md: raid5 personality registered for level 5
[    3.994861] md: raid4 personality registered for level 4
[    3.995005] md/raid:md0: device sdb operational as raid disk 0
[    3.995007] md/raid:md0: device sdc operational as raid disk 1
[    3.995385] md/raid:md0: allocated 10592kB
[    3.995401] md/raid:md0: not enough operational devices (8/10 failed)
[    3.995507]  disk 0, o:1, dev:sdb
[    3.995508]  disk 1, o:1, dev:sdc
[    3.995763] md/raid:md0: failed to run raid set.
[    3.995856] md: pers->run() failed ...
[    4.069375] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
[    4.201633] #### mountkernfs.sh
[    4.237798] #### udev
[    5.189529] #### hdparm
[    5.190485] #### hdparm
[    5.197348] #### hdparm
[    5.266182] #### mountdevsubfs.sh
[    5.355199] #### bootlogd
[    5.368195] #### hdparm
[    5.368707] #### hostname.sh
[    5.370004] #### hwclock.sh
[    5.393968] #### keyboard-setup
[    5.515923] #### checkroot.sh
[    5.526566] Adding 4789244k swap on /dev/sda5.  Priority:-1 extents:1 across:4789244k SS
[    5.529744] EXT4-fs (sda1): re-mounted. Opts: (null)
[    5.555651] EXT4-fs (sda1): re-mounted. Opts: errors=remount-ro
[    5.564496] #### checkroot-bootclean.sh
[    5.566137] #### mtab.sh
[    5.566461] #### kmod
[    5.566600] #### mdadm-raid
[    5.595234] #### mountkernfs.sh
[    5.622390] #### lvm2
[    5.623261] #### mountkernfs.sh
[    5.662715] #### mountdevsubfs.sh
[    5.694587] #### mountdevsubfs.sh
[    5.741703] #### checkfs.sh
[    5.757084] #### mountall.sh
[    5.813939] #### mountall-bootclean.sh
[    5.820861] #### openmediavault
[    5.821033] #### procps
[    5.821153] #### resolvconf
[    5.821870] #### urandom
[    5.822226] #### udev-mtab
[    5.847143] #### networking
[    5.889887] #### rpcbind
[    5.912610] #### nfs-common
[    5.947556] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[    5.966808] #### mountnfs.sh
[    5.981312] #### mountnfs-bootclean
[    6.005421] #### bootmisc.sh
[    6.018247] #### kbd
[    6.057054] #### console-setup
[    6.173083] #### quota
[    6.175544] #### stop-bootlogd-single
[    6.185236] #### nfs-common
[    6.186178] #### rpcbind
[    6.188689] sd 6:0:0:0: [sdd] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.188692] sd 6:0:0:0: [sdd] 4096-byte physical blocks
[    6.188720] sd 6:0:0:0: [sdd] Write Protect is off
[    6.188722] sd 6:0:0:0: [sdd] Mode Sense: 00 3a 00 00
[    6.188734] sd 6:0:0:0: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.188836] sd 6:0:0:0: Attached scsi generic sg3 type 0
[    6.189081] sd 6:0:1:0: [sde] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.189083] sd 6:0:1:0: [sde] 4096-byte physical blocks
[    6.189087] sd 6:0:1:0: Attached scsi generic sg4 type 0
[    6.189113] sd 6:0:1:0: [sde] Write Protect is off
[    6.189115] sd 6:0:1:0: [sde] Mode Sense: 00 3a 00 00
[    6.189130] sd 6:0:1:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.189245] sd 6:0:2:0: [sdf] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.189248] sd 6:0:2:0: [sdf] 4096-byte physical blocks
[    6.189263] sd 6:0:2:0: Attached scsi generic sg5 type 0
[    6.189279] sd 6:0:2:0: [sdf] Write Protect is off
[    6.189281] sd 6:0:2:0: [sdf] Mode Sense: 00 3a 00 00
[    6.189295] sd 6:0:2:0: [sdf] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.189414] sd 6:0:3:0: [sdg] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.189417] sd 6:0:3:0: [sdg] 4096-byte physical blocks
[    6.189446] sd 6:0:3:0: [sdg] Write Protect is off
[    6.189448] sd 6:0:3:0: [sdg] Mode Sense: 00 3a 00 00
[    6.189461] sd 6:0:3:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.189648] sd 6:0:3:0: Attached scsi generic sg6 type 0
[    6.189795] sd 6:0:4:0: [sdh] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.189798] sd 6:0:4:0: [sdh] 4096-byte physical blocks
[    6.189818] sd 6:0:4:0: Attached scsi generic sg7 type 0
[    6.189976] sd 6:0:5:0: [sdi] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.189978] sd 6:0:5:0: [sdi] 4096-byte physical blocks
[    6.189998] sd 6:0:4:0: [sdh] Write Protect is off
[    6.190001] sd 6:0:4:0: [sdh] Mode Sense: 00 3a 00 00
[    6.190009] sd 6:0:5:0: [sdi] Write Protect is off
[    6.190011] sd 6:0:5:0: [sdi] Mode Sense: 00 3a 00 00
[    6.190015] sd 6:0:4:0: [sdh] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.190030] sd 6:0:5:0: [sdi] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.190861] sd 6:0:5:0: Attached scsi generic sg8 type 0
[    6.191058] sd 6:0:6:0: Attached scsi generic sg9 type 0
[    6.191319] sd 6:0:7:0: Attached scsi generic sg10 type 0
[    6.194022] sd 6:0:6:0: [sdj] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.194025] sd 6:0:6:0: [sdj] 4096-byte physical blocks
[    6.194077] sd 6:0:6:0: [sdj] Write Protect is off
[    6.194080] sd 6:0:6:0: [sdj] Mode Sense: 00 3a 00 00
[    6.194095] sd 6:0:6:0: [sdj] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.197362] sd 6:0:7:0: [sdk] 5860533168 512-byte logical blocks: (3.00 TB/2.72 TiB)
[    6.197365] sd 6:0:7:0: [sdk] 4096-byte physical blocks
[    6.197397] sd 6:0:7:0: [sdk] Write Protect is off
[    6.197400] sd 6:0:7:0: [sdk] Mode Sense: 00 3a 00 00
[    6.197413] sd 6:0:7:0: [sdk] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    6.734423]  sdh: unknown partition table
[    6.734585] sd 6:0:4:0: [sdh] Attached SCSI disk
[    6.737781]  sde: unknown partition table
[    6.737889] sd 6:0:1:0: [sde] Attached SCSI disk
[    6.743101]  sdg: unknown partition table
[    6.743239] sd 6:0:3:0: [sdg] Attached SCSI disk
[    6.745442]  sdi: unknown partition table
[    6.745565] sd 6:0:5:0: [sdi] Attached SCSI disk
[    6.747598]  sdj: unknown partition table
[    6.747733] sd 6:0:6:0: [sdj] Attached SCSI disk
[    6.750024]  sdf: unknown partition table
[    6.750162] sd 6:0:2:0: [sdf] Attached SCSI disk
[    6.752701]  sdd: unknown partition table
[    6.752828] sd 6:0:0:0: [sdd] Attached SCSI disk
[    6.762891] #### hdparm
[    6.765335] #### hdparm
[    6.773771] #### hdparm
[    6.779256] #### hdparm
[    6.782838] #### hdparm
[    6.783995]  sdk: unknown partition table
[    6.784127] sd 6:0:7:0: [sdk] Attached SCSI disk
[    6.786419] #### hdparm
[    6.789049] #### hdparm
[    6.819010] #### hdparm
[    7.286032] #### bootlogd

結果を見ると、どうやら /etc/init.d 以下のスクリプトが実行される前に、何者かがRAIDを再構築しようとしているようです。。。さらなる調査が必要なようです。