SEO

Hello,

I have a system with 3 160 GB IDE disks (Samsung SP160SP) running at 2 PCI
IDE controllers (Promise Ultra133 Tx2). I installed a SuSE 9.0 and created 3
(software) raid 5 arrays with SuSE's setup software yast.

System boots, raid works but the systems is very slow now. CPU is a PIII 500
MHz, RAM is 256 MB big. No GUI is installed. If I do a less it runs so
slow, that I can see single lines moving across the screen when I scroll.

A top shows processes raid5d and raid5syncd have together allways over 95%
CPU time.

I found some articles with similar problems, but I don't know where to
start. One article pointed out that Promise Ultra133 Tx2 does not work
correctly in 2.4 kernels (I use 2.4.21) and does not switch to DMA. But this
is not the problem at my machine. All hdds are running with dma100.
dmesg:
hde: 312581808 sectors (160042 MB) w/2048KiB Cache, CHS=19457/255/63,
UDMA(100)
hdg: 312581808 sectors (160042 MB) w/2048KiB Cache, CHS=19457/255/63,
UDMA(100)
hdi: 312581808 sectors (160042 MB) w/2048KiB Cache, CHS=19457/255/63,
UDMA(100)


Then I found lines like this for the raid devices in dmesg:
md: md2: raid array is not clean -- starting background reconstruction
kmod: failed to exec /sbin/modprobe -s -k md-personality-4, errno = 2
md: personality 4 is not loaded!
md :do_md_run() returned -22
md: md2 stopped.

I read, that one reason for this message could be a missing alias in
modules.conf. But there is a line
alias md-personality-4 raid5

and I have a raid5.o in /lib/modules...

What else can be reasons for this kernel message? And why is nevertheless
the raid array running? I have root at md1, and root can be mounted by
kernel.

I attach dmesg output file.

Hope for hints.


Thomas


zone(0): 4096 pages.
zone(1): 61440 pages.
zone(2): 0 pages.
Building zonelist for node : 0
Kernel command line: root=/dev/md1 vga=0x31a splash=silent acpi=off desktop
bootsplash: silent mode.
Initializing CPU#0
Detected 501.192 MHz processor.
Console: colour dummy device 80x25
Calibrating delay loop... 987.13 BogoMIPS
Memory: 255456k/262144k available (1590k kernel code, 6300k reserved, 605k
data, 160k init, 0k highmem)
Dentry cache hash table entries: 32768 (order: 6, 262144 bytes)
Inode cache hash table entries: 16384 (order: 5, 131072 bytes)
Mount cache hash table entries: 512 (order: 0, 4096 bytes)
Buffer-cache hash table entries: 16384 (order: 4, 65536 bytes)
Page-cache hash table entries: 65536 (order: 6, 262144 bytes)
CPU: L1 I cache: 16K, L1 D cache: 16K
CPU: L2 cache: 512K
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
CPU: After generic, caps: 0383f9ff 00000000 00000000 00000000
CPU: Common caps: 0383f9ff 00000000 00000000 00000000
CPU: Intel Pentium III (Katmai) stepping 03
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Checking 'hlt' instruction... OK.
POSIX conformance testing by UNIFIX
mtrr: v1.40 (20010327) Richard Gooch (rgooch@atnf.csiro.au)
mtrr: detected mtrr type: Intel
ACPI: Subsystem revision 20030619
ACPI: Disabled via command line (acpi=off)
PCI: PCI BIOS revision 2.10 entry at 0xfb150, last bus=1
PCI: Using configuration type 1
PCI: Probing PCI hardware
PCI: Probing PCI hardware (bus 00)
PCI: Using IRQ router VIA [1106/0596] at 00:07.0
Activating ISA DMA hang workarounds.
Linux NET4.0 for Linux 2.4
Based upon Swansea University Computer Society NET3.039
Initializing RT netlink socket
apm: BIOS version 1.2 Flags 0x07 (Driver version 1.16)
PISCH: Plug In Scheduler Interface (Version 6)
Starting kswapd
bigpage subsystem: allocated 0 bigpages (=0MB).
kinoded started
VFS: Disk quotas vdquot_6.5.1
aio_setup: num_physpages = 16384
aio_setup: sizeof(struct page) = 48
vesafb: framebuffer at 0xe6000000, mapped to 0xd0810000, size 8192k
vesafb: mode is 1280x1024x16, linelength=2560, pages=2
vesafb: protected mode interface info at c000:47bb
vesafb: scrolling: redraw
vesafb: directcolor: size=0:5:6:5, shift=0:11:5:0
bootsplash 3.0.9-2003/09/08: looking for picture... no good signature found.
Console: switching to colour frame buffer device 160x64
fb0: VESA VGA frame buffer device
pty: 256 Unix98 ptys configured
Serial driver version 5.05c (2001-07-08) with HUB-6 MANY_PORTS MULTIPORT
SHARE_IRQ SERIAL_PCI enabled
ttyS00 at 0x03f8 (irq = 4) is a 16550A
ttyS01 at 0x02f8 (irq = 3) is a 16550A
Real Time Clock Driver v1.10e
Floppy drive(s): fd0 is 1.44M
FDC 0 is a post-1991 82077
RAMDISK driver initialized: 16 RAM disks of 64000K size 1024 blocksize
loop: loaded (max 16 devices)
Uniform Multi-Platform E-IDE driver Revision: 7.00beta4-2.4
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
VP_IDE: IDE controller at PCI slot 00:07.1
VP_IDE: chipset revision 6
VP_IDE: not 100% native mode: will probe irqs later
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
VP_IDE: VIA vt82c596b (rev 12) IDE UDMA66 controller on pci00:07.1
ide0: BM-DMA at 0xa000-0xa007, BIOS settings: hdaMA, hdbMA
ide1: BM-DMA at 0xa008-0xa00f, BIOS settings: hdcMA, hddMA
PDC20269: IDE controller at PCI slot 00:09.0
PCI: Found IRQ 11 for device 00:09.0
PDC20269: chipset revision 2
PDC20269: not 100% native mode: will probe irqs later
PDC20269: ROM enabled at 0xe7000000
ide2: BM-DMA at 0xb800-0xb807, BIOS settings: hdeio, hdfio
ide3: BM-DMA at 0xb808-0xb80f, BIOS settings: hdgio, hdhio
PDC20269: IDE controller at PCI slot 00:0a.0
PCI: Found IRQ 9 for device 00:0a.0
PDC20269: chipset revision 2
PDC20269: not 100% native mode: will probe irqs later
PDC20269: ROM enabled at 0xe8000000
ide4: BM-DMA at 0xcc00-0xcc07, BIOS settings: hdiio, hdjio
ide5: BM-DMA at 0xcc08-0xcc0f, BIOS settings: hdkio, hdlio
hdb: LTN526S, ATAPI CD/DVD-ROM drive
hde: SAMSUNG SP1604N, ATA DISK drive
blk: queue c03c0228, I/O limit 4095Mb (mask 0xffffffff)
hdg: SAMSUNG SP1604N, ATA DISK drive
blk: queue c03c06bc, I/O limit 4095Mb (mask 0xffffffff)
hdi: SAMSUNG SV1604N, ATA DISK drive
blk: queue c03c0b50, I/O limit 4095Mb (mask 0xffffffff)
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
ide2 at 0xa800-0xa807,0xac02 on irq 11
ide3 at 0xb000-0xb007,0xb402 on irq 11
ide4 at 0xbc00-0xbc07,0xc002 on irq 9
hde: attached ide-disk driver.
hde: host protected area => 1
hde: 312581808 sectors (160042 MB) w/2048KiB Cache, CHS=19457/255/63,
UDMA(100)
hdg: attached ide-disk driver.
hdg: host protected area => 1
hdg: 312581808 sectors (160042 MB) w/2048KiB Cache, CHS=19457/255/63,
UDMA(100)
hdi: attached ide-disk driver.
hdi: host protected area => 1
hdi: 312581808 sectors (160042 MB) w/2048KiB Cache, CHS=19457/255/63,
UDMA(100)
ide-floppy driver 0.99.newide
Partition check:
hde: hde1 hde2 hde3 hde4
hdg: hdg1 hdg2 hdg3 hdg4
hdi: hdi1 hdi2 hdi3 hdi4
ide-floppy driver 0.99.newide
md: md driver 0.90.0 MAX_MD_DEVS=256, MD_SB_DISKS=27
md: Autodetecting RAID arrays.
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
md: autorun ...
md: considering hdi4 ...
md: adding hdi4 ...
md: adding hdg4 ...
md: adding hde4 ...
md: created md2
md: bind<hde4,1>
md: bind<hdg4,2>
md: bind<hdi4,3>
md: running: <hdi4><hdg4><hde4>
md: hdi4's event counter: 0000000e
md: hdg4's event counter: 0000000e
md: hde4's event counter: 0000000e
md: md2: raid array is not clean -- starting background reconstruction
kmod: failed to exec /sbin/modprobe -s -k md-personality-4, errno = 2
md: personality 4 is not loaded!
md :do_md_run() returned -22
md: md2 stopped.
md: unbind<hdi4,2>
md: export_rdev(hdi4)
md: unbind<hdg4,1>
md: export_rdev(hdg4)
md: unbind<hde4,0>
md: export_rdev(hde4)
md: considering hdi3 ...
md: adding hdi3 ...
md: adding hdg3 ...
md: adding hde3 ...
md: created md1
md: bind<hde3,1>
md: bind<hdg3,2>
md: bind<hdi3,3>
md: running: <hdi3><hdg3><hde3>
md: hdi3's event counter: 0000000e
md: hdg3's event counter: 0000000e
md: hde3's event counter: 0000000e
md: md1: raid array is not clean -- starting background reconstruction
kmod: failed to exec /sbin/modprobe -s -k md-personality-4, errno = 2
md: personality 4 is not loaded!
md :do_md_run() returned -22
md: md1 stopped.
md: unbind<hdi3,2>
md: export_rdev(hdi3)
md: unbind<hdg3,1>
md: export_rdev(hdg3)
md: unbind<hde3,0>
md: export_rdev(hde3)
md: considering hdi2 ...
md: adding hdi2 ...
md: adding hdg2 ...
md: adding hde2 ...
md: created md0
md: bind<hde2,1>
md: bind<hdg2,2>
md: bind<hdi2,3>
md: running: <hdi2><hdg2><hde2>
md: hdi2's event counter: 0000000e
md: hdg2's event counter: 0000000e
md: hde2's event counter: 0000000e
kmod: failed to exec /sbin/modprobe -s -k md-personality-4, errno = 2
md: personality 4 is not loaded!
md :do_md_run() returned -22
md: md0 stopped.
md: unbind<hdi2,2>
md: export_rdev(hdi2)
md: unbind<hdg2,1>
md: export_rdev(hdg2)
md: unbind<hde2,0>
md: export_rdev(hde2)
md: ... autorun DONE.
NET4: Linux TCP/IP 1.0 for NET4.0
IP Protocols: ICMP, UDP, TCP, IGMP
IP: routing cache hash table of 2048 buckets, 16Kbytes
TCP: Hash tables configured (established 16384 bind 32768)
Linux IP multicast router 0.06 plus PIM-SM
NET4: Unix domain sockets 1.0/SMP for Linux NET4.0.
cryptoapi: loaded
RAMDISK: Compressed image found at block 0
Freeing initrd memory: 263k freed
VFS: Mounted root (ext2 filesystem).
raid5: measuring checksumming speed
8regs : 912.000 MB/sec
32regs : 408.000 MB/sec
pIII_sse : 1012.000 MB/sec
pII_mmx : 1116.000 MB/sec
p5_mmx : 1172.000 MB/sec
raid5: using function: pIII_sse (1012.000 MB/sec)
md: raid5 personality registered as nr 4
md: Autodetecting RAID arrays.
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
[events: 0000000e]
md: autorun ...
md: considering hde2 ...
md: adding hde2 ...
md: adding hdg2 ...
md: adding hdi2 ...
md: created md0
md: bind<hdi2,1>
md: bind<hdg2,2>
md: bind<hde2,3>
md: running: <hde2><hdg2><hdi2>
md: hde2's event counter: 0000000e
md: hdg2's event counter: 0000000e
md: hdi2's event counter: 0000000e
md0: max total readahead window set to 1024k
md0: 2 data-disks, max readahead per data-disk: 512k
raid5: device hde2 operational as raid disk 0
raid5: device hdg2 operational as raid disk 1
raid5: device hdi2 operational as raid disk 2
raid5: allocated 3293kB for md0
raid5: raid level 5 set md0 active with 3 out of 3 devices, algorithm 2
RAID5 conf printout:
--- rd:3 wd:3 fd:0
disk 0, s:0, o:1, n:0 rd:0 us:1 dev:hde2
disk 1, s:0, o:1, n:1 rd:1 us:1 dev:hdg2
disk 2, s:0, o:1, n:2 rd:2 us:1 dev:hdi2
RAID5 conf printout:
--- rd:3 wd:3 fd:0
disk 0, s:0, o:1, n:0 rd:0 us:1 dev:hde2
disk 1, s:0, o:1, n:1 rd:1 us:1 dev:hdg2
disk 2, s:0, o:1, n:2 rd:2 us:1 dev:hdi2
md: updating md0 RAID superblock on device
md: hde2 [events: 0000000f]
(write) hde2's sb offset: 513984
md: hdg2 [events: 0000000f]
(write) hdg2's sb offset: 513984
md: hdi2 [events: 0000000f]
(write) hdi2's sb offset: 513984
[events: 00000000]
md: invalid raid superblock magic on md0
md: md0 has invalid sb, not importing!
md: no nested md device found
md: considering hde3 ...
md: adding hde3 ...
md: adding hdg3 ...
md: adding hdi3 ...
md: created md1
md: bind<hdi3,1>
md: bind<hdg3,2>
md: bind<hde3,3>
md: running: <hde3><hdg3><hdi3>
md: hde3's event counter: 0000000e
md: hdg3's event counter: 0000000e
md: hdi3's event counter: 0000000e
md: md1: raid array is not clean -- starting background reconstruction
md1: max total readahead window set to 1024k
md1: 2 data-disks, max readahead per data-disk: 512k
raid5: device hde3 operational as raid disk 0
raid5: device hdg3 operational as raid disk 1
raid5: device hdi3 operational as raid disk 2
raid5: allocated 3293kB for md1
raid5: raid level 5 set md1 active with 3 out of 3 devices, algorithm 2
raid5: raid set md1 not clean; reconstructing parity
RAID5 conf printout:
--- rd:3 wd:3 fd:0
disk 0, s:0, o:1, n:0 rd:0 us:1 dev:hde3
disk 1, s:0, o:1, n:1 rd:1 us:1 dev:hdg3
disk 2, s:0, o:1, n:2 rd:2 us:1 dev:hdi3
RAID5 conf printout:
--- rd:3 wd:3 fd:0
disk 0, s:0, o:1, n:0 rd:0 us:1 dev:hde3
disk 1, s:0, o:1, n:1 rd:1 us:1 dev:hdg3
disk 2, s:0, o:1, n:2 rd:2 us:1 dev:hdi3
md: updating md1 RAID superblock on device
md: hde3 [events: 0000000f]
(write) hde3's sb offset: 10490368
md: syncing RAID array md1
md: minimum _guaranteed_ reconstruction speed: 100 KB/sec/disc.
md: using maximum available idle IO bandwith (but not more than 100000
KB/sec) for reconstruction.
md: using 508k window, over a total of 10490368 blocks.
md: hdg3 [events: 0000000f]
spurious 8259A interrupt: IRQ7.
(write) hdg3's sb offset: 10490368
md: hdi3 [events: 0000000f]
(write) hdi3's sb offset: 10490368
[events: 00000000]
md: invalid raid superblock magic on md1
md: md1 has invalid sb, not importing!
md: no nested md device found
md: considering hde4 ...
md: adding hde4 ...
md: adding hdg4 ...
md: adding hdi4 ...
md: created md2
md: bind<hdi4,1>
md: bind<hdg4,2>
md: bind<hde4,3>
md: running: <hde4><hdg4><hdi4>
md: hde4's event counter: 0000000e
md: hdg4's event counter: 0000000e
md: hdi4's event counter: 0000000e
md: md2: raid array is not clean -- starting background reconstruction
md2: max total readahead window set to 1024k
md2: 2 data-disks, max readahead per data-disk: 512k
raid5: device hde4 operational as raid disk 0
raid5: device hdg4 operational as raid disk 1
raid5: device hdi4 operational as raid disk 2
raid5: allocated 3293kB for md2
raid5: raid level 5 set md2 active with 3 out of 3 devices, algorithm 2
raid5: raid set md2 not clean; reconstructing parity
RAID5 conf printout:
--- rd:3 wd:3 fd:0
disk 0, s:0, o:1, n:0 rd:0 us:1 dev:hde4
disk 1, s:0, o:1, n:1 rd:1 us:1 dev:hdg4
disk 2, s:0, o:1, n:2 rd:2 us:1 dev:hdi4
RAID5 conf printout:
--- rd:3 wd:3 fd:0
disk 0, s:0, o:1, n:0 rd:0 us:1 dev:hde4
disk 1, s:0, o:1, n:1 rd:1 us:1 dev:hdg4
disk 2, s:0, o:1, n:2 rd:2 us:1 dev:hdi4
md: updating md2 RAID superblock on device
md: hde4 [events: 0000000f]
(write) hde4's sb offset: 145251584
md: delaying resync of md2 until md1 has finished resync (they share one or
more physical units)
md: hdg4 [events: 0000000f]
(write) hdg4's sb offset: 145251584
md: hdi4 [events: 0000000f]
(write) hdi4's sb offset: 145251584
[events: 00000000]
md: invalid raid superblock magic on md2
md: md2 has invalid sb, not importing!
md: no nested md device found
md: ... autorun DONE.
raid5: switching cache buffer size, 4096 --> 1024
md: swapper(pid 1) used obsolete MD ioctl, upgrade your software to use new
ictls.
raid5: switching cache buffer size, 1024 --> 4096
reiserfs: found format "3.6" with standard journal
reiserfs: enabling write barrier flush mode
reiserfs: using ordered data mode
reiserfs: checking transaction log (device md(9,1)) ...
for (md(9,1))
Using r5 hash to sort names
VFS: Mounted root (reiserfs filesystem) readonly.
Trying to move old root to /initrd ... failed
Unmounting old root
Trying to free ramdisk memory ... okay
Freeing unused kernel memory: 160k freed
md: array md0 already exists!
md: array md1 already exists!
md: array md2 already exists!
md: Autodetecting RAID arrays.
md: autorun ...
md: ... autorun DONE.
reiserfs: enabling write barrier flush mode
LVM version 1.0.5+(mp-v6a)(22/07/2002) module loaded
raid5: switching cache buffer size, 4096 --> 1024
raid5: switching cache buffer size, 4096 --> 1024
reiserfs: enabling write barrier flush mode
raid5: switching cache buffer size, 1024 --> 4096
Adding Swap: 1027832k swap-space (priority 42)
reiserfs: enabling write barrier flush mode
reiserfs: enabling write barrier flush mode
raid5: switching cache buffer size, 1024 --> 4096
reiserfs: found format "3.6" with standard journal
reiserfs: enabling write barrier flush mode
reiserfs: using ordered data mode
reiserfs: checking transaction log (device md(9,2)) ...
for (md(9,2))
Using r5 hash to sort names
raw1394: /dev/raw1394 device initialized
usb.c: registered new driver usbdevfs
usb.c: registered new driver hub
usb-uhci.c: $Revision: 1.275 $ time 13:50:22 Sep 24 2003
usb-uhci.c: High bandwidth mode enabled
usb-uhci.c: USB UHCI at I/O 0xa400, IRQ 5
usb-uhci.c: Detected 2 ports
usb.c: new USB bus registered, assigned bus number 1
hub.c: USB hub found
hub.c: 2 ports detected
usb-uhci.c: v1.275:USB Universal Host Controller Interface driver
uhci.c: USB Universal Host Controller Interface driver v1.1
mice: PS/2 mouse device common for all mice
IPsec Security Association Database (SADB): initialized.
IPsec Security Policy Database (SPD): initialized.
IPsec PF_KEY V2: initialized
i8253 count too high! resetting..
IPv6 v0.8 (usagi-cvs/IPsec6 based StS) for NET4.0
IPv6 over IPv4 tunneling driver
i8253 count too high! resetting..
isapnp: Scanning for PnP cards...
isapnp: No Plug & Play device found

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
NotDashEscaped: You need GnuPG to verify this message

In comp.os.linux.setup Thomas Olschewski <junk@innomic.de> suggested:
> Hello,

> I have a system with 3 160 GB IDE disks (Samsung SP160SP) running at 2 PCI
> IDE controllers (Promise Ultra133 Tx2). I installed a SuSE 9.0 and created 3
> (software) raid 5 arrays with SuSE's setup software yast.

> System boots, raid works but the systems is very slow now. CPU is a PIII 500
> MHz, RAM is 256 MB big. No GUI is installed. If I do a less it runs so
> slow, that I can see single lines moving across the screen when I scroll.

> A top shows processes raid5d and raid5syncd have together allways over 95%
> CPU time.

I'd check first if the RAID has already finished syncing 'cat
/proc/mdstat' or alike. That may take some time with RAID5 on
large disks and a slow system. 'mdadm' has some more options to
check sw-raid status (man mdadm).

Next, I'd check performance '-Tt' with hdparm and the
udma?/pio?/etc settings of the disks (man hdparm) and correct
them if needed up to the maximum possible.

Good luck

--
Michael Heiming (GPG-Key ID: 0xEDD27B94)
mail: echo zvpunry@urvzvat.qr | perl -pe 'y/a-z/n-za-m/'
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (GNU/Linux)

iD8DBQFAn7rdAkPEju3Se5QRAoLNAJ9gXz3P/tLByHyXP7HZzrUPNvBAXgCePJ8q
JdAQNOG48SIah1DaMwCHiow=
=itZe
-----END PGP SIGNATURE-----

> I'd check first if the RAID has already finished syncing 'cat
> /proc/mdstat' or alike. That may take some time with RAID5 on
> large disks and a slow system. 'mdadm' has some more options to
> check sw-raid status (man mdadm).

Thank you. I let the machine syncing now. Speed is about 15 MB/sec, that
seems fast enough to me. How often does this sync process take place?


Thomas