Subject: tar tages ages on raid1/raidframe?
To: None <current-users@netbsd.org>
From: Hanno 'Rince' Wagner <wagner@fitug.de>
List: current-users
Date: 10/22/2001 01:08:26
Hi,

I am running a current netbsd, with a large RAID-1-Filesystem on two
identical IDE-Drives (one master, one slave):

Filesystem  1K-blocks     Used     Avail Capacity  Mounted on
/dev/raid1a  94701605 81427892   8538632    90%    /data2

/dev/raid1a on /data2 type ffs (NFS exported, local)

angua# raidctl -s raid1
Components:
           /dev/wd0a: optimal
           /dev/wd1a: optimal
No spares.
Component label for /dev/wd0a:
   Row: 0, Column: 0, Num Rows: 1, Num Columns: 2
   Version: 2, Serial Number: 22222, Mod Counter: 245
   Clean: No, Status: 0
   sectPerSU: 128, SUsPerPU: 1, SUsPerRU: 1
   Queue size: 100, blocksize: 512, numBlocks: 195711104
   RAID Level: 1
   Autoconfig: Yes
   Root partition: No
   Last configured as: raid1
Component label for /dev/wd1a:
   Row: 0, Column: 1, Num Rows: 1, Num Columns: 2
   Version: 2, Serial Number: 22222, Mod Counter: 245
   Clean: No, Status: 0
   sectPerSU: 128, SUsPerPU: 1, SUsPerRU: 1
   Queue size: 100, blocksize: 512, numBlocks: 195711104
   RAID Level: 1
   Autoconfig: Yes
   Root partition: No
   Last configured as: raid1
Parity status: clean
Reconstruction is 100% complete.
Parity Re-write is 100% complete.
Copyback is 100% complete.
	       

wd0 at pciide1 channel 0 drive 0: <Maxtor 4W100H6>
wd0: drive supports 16-sector PIO transfers, LBA addressing
wd0: 95562 MB, 16383 cyl, 16 head, 63 sec, 512 bytes/sect x 195711264 sectors
wd0: 32-bit data port
wd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 5 (Ultra/100)
wd0(pciide1:0:0): using PIO mode 4, Ultra-DMA mode 5 (Ultra/100) (using DMA data transfers)
Component on: wd0a: 195711264

wd1 at pciide1 channel 0 drive 1: <Maxtor 4W100H6>
wd1: drive supports 16-sector PIO transfers, LBA addressing
wd1: 95562 MB, 16383 cyl, 16 head, 63 sec, 512 bytes/sect x 195711264 sectors
wd1: 32-bit data port
wd1: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 5 (Ultra/100)
wd1(pciide1:0:1): using PIO mode 4, Ultra-DMA mode 5 (Ultra/100) (using DMA data transfers)
Component on: wd1a: 195711264



This RAID-1 works fine, until I try to untar some stuff (or cp on
it). Suddenly, it takes ages to extract files from a tar-archive to
this filesystem.

I made a ktrace on a tar xfz <file.tar.gz> and it shows the following:

(the ktrace-command was: "ktrace tar xfz file.tgz")
then I made a "kdump -R > /tmp/tartrace.out" and got some million
lines already. (-R for getting deltas between syscalls)

To get it more readable, I used:

"tail -10000 /tmp/tartrace.out | grep tar" and got the following
examples:

[..]
  4708 tar      0.000000 GIO   fd 4 wrote 8 bytes
  4708 tar      0.000207 RET   write 4096/0x1000
  4708 tar      0.000023 CALL  read(0x3,0x80a5000,0x2800)
  4708 tar      0.000059 GIO   fd 3 read 4088 bytes
[..]

this sounds, fine, but:

[..]
 4708 tar      0.000000 GIO   fd 3 read 8 bytes
 4708 tar      0.000256 RET   read 4096/0x1000
 4708 tar      0.000127 CALL  mkdir(0x80a4100,0x1e8)
 4708 tar      0.000043 NAMI  "path/to/new/extracted/files/with/patches/in"
 4708 tar      2.004427 RET   mkdir 0
 4708 tar      0.000127 CALL  mkdir(0x80a4100,0x1e8)
 4708 tar      0.000031 NAMI  "path/to/new/extracted/files/with/more/patches/in"
 4708 tar      9.566940 RET   mkdir 0
 4708 tar      0.000141 CALL  unlink(0x80a4100)
 4708 tar      0.000031 NAMI  "path/to/new/extracted/files/with/more/patches/and/more"
 4708 tar      0.000103 RET   unlink -1 errno 2 No such file or directory
 4708 tar      0.000026 CALL  open(0x80a4100,0x60d,0x1e8)
 4708 tar      0.000029 NAMI  "path/to/new/extracted/file/with/new/patches/and/more"
 4708 tar      0.021196 RET   open 4
 4708 tar      0.000068 CALL  write(0x4,0x80a5a00,0x600)
 4708 tar      35.469303 GIO   fd 4 wrote 1536 bytes
			       
[..]

  4708 tar      0.000000 GIO   fd 3 read 8 bytes
         "        # tree "
  4708 tar      0.000241 RET   read 4096/0x1000
  4708 tar      0.000086 CALL  write(0x4,0x80a5000,0x3b)
  4708 tar      34.178226 GIO   fd 4 wrote 59 bytes
[..]


And so on.

So, I can see that an mkdir takes once two seconds, once 9.5. And I
see that it takes 35 seconds(!) to write some small bytes and I
don't know why.

Is there any hint why this takes so long? The disks itself shouldn't
be the bottleneck, except of having one large filesystem, is there
something wrong?


Ciao, Hanno
-- 
|  Hanno Wagner  | Member of the HTML Writers Guild  | Rince@IRC      |
| Eine gewerbliche Nutzung meiner Email-Adressen ist nicht gestattet! |
| 74 a3 53 cc 0b 19 - we did it!          |    Generation @           |

#"Das liegt daran, da{ wir - die hinterhYltigen Spoiler-Illuminaten von Kiel -
# die Abfertigung der Dusselpostings aufgeteilt haben, und Du wurdest eben
# Anja zugeteilt." -- Achim Held in d.u.n.g