random 'df' output for an ufs partition on raid5

tobe

tobe

Hello,

I have setup a subversion server and i have some troubles with the output from 'df' for one of the partition.

Code: 
Filesystem    1K-blocks    Used     Avail Capacity  Mounted on
/dev/ad4s1a     8122126  141986   7330370     2%    /
devfs                 1       1         0   100%    /dev
/dev/ad4s1e     4058062      12   3733406     0%    /tmp
/dev/ad4s1f   118827874 1893694 107427952     2%    /usr
/dev/ad4s1d    16244334  102456  14842332     1%    /var
/dev/mfid0s1d 507788836   -1958 467167688    -0%    /data/subversion
/dev/mfid0s1e 910209118 4928892 832463498     1%    /data/backup

Filesystem    1K-blocks    Used     Avail Capacity  Mounted on
/dev/ad4s1a     8122126  141986   7330370     2%    /
devfs                 1       1         0   100%    /dev
/dev/ad4s1e     4058062      12   3733406     0%    /tmp
/dev/ad4s1f   118827874 1893694 107427952     2%    /usr
/dev/ad4s1d    16244334  102456  14842332     1%    /var
/dev/mfid0s1d 507788836   -4550 467170280    -0%    /data/subversion
/dev/mfid0s1e 910209118 4928892 832463498     1%    /data/backup

Filesystem    1K-blocks    Used     Avail Capacity  Mounted on
/dev/ad4s1a     8122126  141986   7330370     2%    /
devfs                 1       1         0   100%    /dev
/dev/ad4s1e     4058062      12   3733406     0%    /tmp
/dev/ad4s1f   118827874 1893694 107427952     2%    /usr
/dev/ad4s1d    16244334  102456  14842332     1%    /var
/dev/mfid0s1d 507788836  -15894 467181624    -0%    /data/subversion
/dev/mfid0s1e 910209118 4928892 832463498     1%    /data/backup

Filesystem    1K-blocks    Used     Avail Capacity  Mounted on
/dev/ad4s1a     8122126  141986   7330370     2%    /
devfs                 1       1         0   100%    /dev
/dev/ad4s1e     4058062      12   3733406     0%    /tmp
/dev/ad4s1f   118827874 1893694 107427952     2%    /usr
/dev/ad4s1d    16244334  102456  14842332     1%    /var
/dev/mfid0s1d 507788836  -16966 467182696    -0%    /data/subversion
/dev/mfid0s1e 910209118 4928892 832463498     1%    /data/backup

The 'Used' size for the partition '/dev/mfid0s1d' is negative and change each time (i'm not writing to the partition).

The server is a Dell PowerEdge 2900, and the partition is created on a raid 5 hardware array.

Code: 
mfi0: <Dell PERC 5/i> mem 0xd80f0000-0xd80fffff,0xfc4e0000-0xfc4fffff irq 142 at device 14.0 on pci2
mfi0: Megaraid SAS driver Ver 3.00
mfi0: 5607 (298379343s/0x0020/info) - Shutdown command received from host
mfi0: 5608 (boot + 0s/0x0020/info) - Firmware initialization started (PCI ID 0015/1028/1f03/1028)
mfi0: 5609 (boot + 0s/0x0020/info) - Firmware version 1.00.02-0157
mfi0: 5610 (boot + 26s/0x0008/info) - Battery Present
mfi0: 5611 (boot + 43s/0x0004/info) - Enclosure (SES) discovered on PD 08(e1/s255)
...
mfi0: 5623 (298379461s/0x0020/info) - Time established as 06/15/09 11:11:01; (44 seconds since power on)
mfid0: <MFI Logical Disk> on mfi0
mfid0: 1429760MB (2928148480 sectors) RAID volume '' is optimal
mfi0: 5624 (298379518s/0x0008/info) - Battery temperature is normal
mfi0: 5625 (298379518s/0x0008/info) - Battery started charging
mfi0: 5626 (298379518s/0x0008/info) - Current capacity of the battery is above threshold

There's a bug report about it http://www.freebsd.org/cgi/query-pr.cgi?pr=92432&cat= and I suspect that the problem is related to UFS snapshots, since this is the only partition where snapshots where created and destroyed.

At the end of 'dmesg', sometime, the following lines appears:
Code: 
WARNING: Expected rawoffset 0, found 63
WARNING: Expected rawoffset 0, found 63
WARNING: Expected rawoffset 0, found 63

uname -a:
Code: 
FreeBSD server.xxxxx.net 7.1-RELEASE-p6 FreeBSD 7.1-RELEASE-p6 #0: Tue Jun  9 16:26:47 UTC 2009     root@i386-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  i386
 
Yes i did a fsck and it fixed the problem. Now i'm creating and deleting snapshots to see if i can find a reproduction rule.

Edit:

After creating and deleting snapshots, the problem is back.

Steps:
- create snapshot 1
- create snapshot 2
- create snapshot 3
- create snapshot 4
- destroy snapshot 1
- destroy snapshots 2
- destroy snapshot 3
- destroy snapshot 4

Each time a snapshot is created, it is mdconfig'ured (as readonly) and mounted in a directory in /dev/ads4s1a (the root filesystem) as readonly.

Each time a snapshot is destroyed, it is first umounted, then un-mdconfig'ured and then the snapshot is unlinked.

I got a few other messages in dmesg about commands timeouts:

Code: 
mfi0: COMMAND 0xc53066d0 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc53064a0 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5306900 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5305230 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc53062c0 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5306810 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5307120 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5307670 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5306220 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5305d20 TIMEOUT AFTER 43 SECONDS
mfi0: COMMAND 0xc5305aa0 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc5306db0 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc53056e0 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc5306680 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc5305640 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc5305320 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc5307260 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc5306400 TIMEOUT AFTER 31 SECONDS
mfi0: COMMAND 0xc5307490 TIMEOUT AFTER 31 SECONDS
WARNING: Expected rawoffset 0, found 63
WARNING: Expected rawoffset 0, found 63
WARNING: Expected rawoffset 0, found 63

After a few minutes of random 'Used' in the 'df' output, the problem disappeared by itself :/
 
You must log in or register to reply here.
Back
Top