Hi,
I'm encountering a strange situation.
I'm writing to an ext3 filesystem mounted like this:
/dev/scsi/host2/bus0/target0/lun0/part3 on /tmp/volumes/md0 type ext3 (rw,noatime,data=ordered)
with the physical device being a FC-connected RAID (IBM DF4000)
no software raid personality is used
I'm using 2.4.18-19.7
My test program writes files in a loop, with the essential system calls being:
[pid 13335] mkdir("/tmp/volumes/md0/1/13335/00028", 0777) = 0
[pid 13335] fsync(4) = 0
[pid 13335] time(NULL) = 1044515538
[pid 13335] gettimeofday({1044515538, 96401}, {4294967176, 0}) = 0
[pid 13335] getpid() = 13335
[pid 13335] sendto(3, "[Feb 6 9:12:18.096401 13335]: mkdir /tmp/volumes/md0/1/13335/00028\n", 69, 0, {sin_family=AF_INET, sin_port=htons(12345), sin_addr=inet_addr("127.0.0.1")}}, 16) = 69
[pid 13335] open("/tmp/volumes/md0/1/13335/00028", O_RDONLY|O_SYNC) = 5
[pid 13335] open("/tmp/volumes/md0/1/13335/00028/file", O_RDWR|O_CREAT|O_SYNC, 027777774120) = 6
[pid 13335] fsync(5) = 0
[pid 13335] time(NULL) = 1044515538
[pid 13335] gettimeofday({1044515538, 112558}, {4294967176, 0}) = 0
[pid 13335] getpid() = 13335
[pid 13335] sendto(3, "[Feb 6 9:12:18.112558 13335]: open /tmp/volumes/md0/1/13335/00028/file\n", 73, 0, {sin_family=AF_INET, sin_port=htons(12345), sin_addr=inet_addr("127.0.0.1")}}, 16) = 73
[pid 13335] getpid() = 13335
[pid 13335] write(6, "\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5\6\7\10\t\n\v\f\r\16\17\20\21\22\23\24\25\26\27\30\31\0\1\2\3\4\5"..., 8192) = 8192
[pid 13335] fsync(6) = 0
[pid 13335] time(NULL) = 1044515538
[pid 13335] gettimeofday({1044515538, 160822}, {4294967176, 0}) = 0
[pid 13335] getpid() = 13335
[pid 13335] sendto(3, "[Feb 6 9:12:18.160822 13335]: write /tmp/volumes/md0/1/13335/00028/file\n", 74, 0, {sin_family=AF_INET, sin_port=htons(12345), sin_addr=inet_addr("127.0.0.1")}}, 16) = 74
[pid 13335] close(6) = 0
[pid 13335] close(5) = 0
[pid 13335] time(NULL) = 1044515538
[pid 13335] gettimeofday({1044515538, 161148}, {4294967176, 0}) = 0
[pid 13335] getpid() = 13335
[pid 13335] sendto(3, "[Feb 6 9:12:18.161148 13335]: finished /tmp/volumes/md0/1/13335/00028/file\n", 77, 0, {sin_family=AF_INET, sin_port=htons(12345), sin_addr=inet_addr("127.0.0.1")}}, 16) = 77
[
In the middle of this loop of writing I turn down the power to my RAID
in the first minute the last writes/actions seem to be pending. After that the write actions return successfully (which is very strange) and all following actions return with errors.
When I turn on the power again, the fs seems to restore, and the file is available with the correct data.
But when I do e2fsck to the device I get:
[root@node2-integ /]# e2fsck -y -f /dev/scsi/host2/bus0/target0/lun0/part3
e2fsck 1.27 (8-Mar-2002)
Pass 1: Checking inodes, blocks, and sizes
Pass 2: Checking directory structure
Entry '8075' in /1 (1687558) has an incorrect filetype (was 2, should be 1).
Fix? yes
Entry '00036' in /1/8022 (1736710) has deleted/unused inode 1179660. Clear? yes
Entry '00037' in /1/8024 (1802246) has deleted/unused inode 1146892. Clear? yes
Entry '00036' in /1/8027 (1998854) has deleted/unused inode 2654219. Clear? yes
Entry '00036' in /1/8035 (2097158) has deleted/unused inode 2588683. Clear? yes
Entry '00036' in /1/8033 (2228230) has deleted/unused inode 1212428. Clear? yes
Entry '00037' in /1/8038 (2326534) has deleted/unused inode 1114124. Clear? yes
Entry '00009' in /2/8179 (2981900) is a link to directory /1/8069 (1785868).
Clear? yes
Entry '00013' in /2/8176 (2998284) is a link to directory /1/8045/00036 (1261580).
Clear? yes
Entry '00013' in /2/8178 (3047436) is a link to directory /1/8039/00036 (1196044).
Clear? yes
Entry '00009' in /2/8184 (3227660) is a link to directory /1/8071 (1949708).
Clear? yes
Entry '00012' in /2/8182 (3293196) is a link to directory /1/8029/00037 (1277964).
Clear? yes
Entry '00012' in /2/8193 (3375116) is a link to directory /1/8021/00037 (1228812).
Clear? yes
Entry '00008' in /2/8188 (3522572) is a link to directory /1/8065 (1523724).
Clear? yes
Entry '00009' in /2/8186 (3588108) is a link to directory /1/8070 (1884172).
Clear? yes
Entry '00012' in /2/8198 (3637260) is a link to directory /1/8025/00038 (1294348).
Clear? yes
Entry '00008' in /2/8195 (3735564) is a link to directory /1/8066 (1556492).
Clear? yes
Entry '00009' in /2/8204 (3964940) is a link to directory /1/8068 (1753100).
Clear? yes
Entry '00008' in /2/8205 (3981319) is a link to directory /1/8067 (1589260).
Clear? yes
Entry '00012' in /2/8205 (3981319) is a link to directory /1/8034/00036 (1245196).
Clear? yes
Pass 3: Checking directory connectivity
'..' in /1/8039/00036 (1196044) is /2/8178 (3047436), should be /1/8039 (2359302).
Fix? yes
'..' in /1/8021/00037 (1228812) is /2/8193 (3375116), should be /1/8021 (1703942).
Fix? yes
'..' in /1/8034/00036 (1245196) is /2/8205 (3981319), should be /1/8034 (2179078).
Fix? yes
'..' in /1/8045/00036 (1261580) is /2/8176 (2998284), should be /1/8045 (2703366).
Fix? yes
'..' in /1/8029/00037 (1277964) is /2/8182 (3293196), should be /1/8029 (1900550).
Fix? yes
'..' in /1/8025/00038 (1294348) is /2/8198 (3637260), should be /1/8025 (1867782).
Fix? yes
'..' in /1/8065 (1523724) is /2/8188 (3522572), should be /1 (1687558).
Fix? yes
'..' in /1/8066 (1556492) is /2/8195 (3735564), should be /1 (1687558).
Fix? yes
'..' in /1/8067 (1589260) is /2/8205 (3981319), should be /1 (1687558).
Fix? yes
'..' in /1/8068 (1753100) is /2/8204 (3964940), should be /1 (1687558).
Fix? yes
'..' in /1/8069 (1785868) is /2/8179 (2981900), should be /1 (1687558).
Fix? yes
Unconnected directory inode 1835020 (/1/8069/???)
Connect to /lost+found? yes
'..' in /1/8070 (1884172) is /2/8186 (3588108), should be /1 (1687558).
Fix? yes
'..' in /1/8071 (1949708) is /2/8184 (3227660), should be /1 (1687558).
Fix? yes
Unconnected directory inode 2064396 (/1/8071/???)
Connect to /lost+found? yes
Pass 4: Checking reference counts
Inode 1671181 ref count is 1, should be 2. Fix? yes
Inode 1687558 ref count is 73, should be 65. Fix? yes
Inode 1703942 ref count is 41, should be 40. Fix? yes
Inode 1736710 ref count is 39, should be 38. Fix? yes
Inode 1785868 ref count is 1, should be 2. Fix? yes
Inode 1802246 ref count is 40, should be 39. Fix? yes
Inode 1835020 ref count is 3, should be 2. Fix? yes
Inode 1867782 ref count is 42, should be 41. Fix? yes
Inode 1900550 ref count is 41, should be 40. Fix? yes
Inode 1949708 ref count is 1, should be 2. Fix? yes
Inode 1998854 ref count is 39, should be 38. Fix? yes
Inode 2064396 ref count is 3, should be 2. Fix? yes
Inode 2097158 ref count is 39, should be 38. Fix? yes
Inode 2179078 ref count is 40, should be 39. Fix? yes
Inode 2228230 ref count is 39, should be 38. Fix? yes
Inode 2326534 ref count is 40, should be 39. Fix? yes
Inode 2359302 ref count is 40, should be 39. Fix? yes
Inode 2703366 ref count is 40, should be 39. Fix? yes
Pass 5: Checking group summary information
Block bitmap differences: -2228755 -2294289 -2359827 -2392595 -2425363 -2458131 -2490899 -2523667 -2556435 -2589203 -(3441172--3441173) -(5177874--5177876) -(5308946--5308948) -11862554 -12157466 -12223002 -12255770 -12288538
Fix? yes
Free blocks count wrong for group #68 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #70 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #72 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #73 (32232, counted=32235).
Fix? yes
<snipped groups >
Free blocks count wrong for group #74 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #75 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #76 (32229, counted=32232).
Fix? yes
Free blocks count wrong for group #77 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #78 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #79 (32232, counted=32235).
Fix? yes
Free blocks count wrong for group #81 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #82 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #83 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #84 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #85 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #86 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #87 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #88 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #89 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #90 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #91 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #92 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #93 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #94 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #95 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #96 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #97 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #101 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #102 (32233, counted=32235).
Fix? yes
Free blocks count wrong for group #105 (32231, counted=32234).
Fix? yes
Free blocks count wrong for group #107 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #109 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #113 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #115 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #118 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #119 (32233, counted=32234).
Fix? yes
Free blocks count wrong for group #158 (32233, counted=32236).
Fix? yes
Free blocks count wrong for group #162 (32233, counted=32236).
Fix? yes
Free blocks count wrong for group #256 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #257 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #258 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #259 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #260 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #261 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #262 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #263 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #264 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #265 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #266 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #267 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #268 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #269 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #270 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #271 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #273 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #274 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #275 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #276 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #277 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #278 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #279 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #280 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #281 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #282 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #283 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #284 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #285 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #286 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #287 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #288 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #289 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #290 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #291 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #292 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #293 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #294 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #295 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #296 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #297 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #298 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #299 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #300 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #301 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #302 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #303 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #304 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #305 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #306 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #307 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #308 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #309 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #310 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #311 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #312 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #313 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #314 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #315 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #316 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #317 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #318 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #319 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #320 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #321 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #322 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #323 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #324 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #325 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #326 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #327 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #328 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #329 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #330 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #331 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #332 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #333 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #334 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #335 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #336 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #337 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #338 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #339 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #340 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #341 (32234, counted=32231).
Fix? yes
Free blocks count wrong for group #342 (32234, counted=32231).
Fix? yes
<snipped again>
and then the file is missing.
This seems to be incorrect behaviour. How should my application know that there was an error writing the file and provide the correct recovery ?
I've yet to test this on other filesystems or journal modes.
Does anyone have any explanation for this behaviour, or suggestion for workarounds ?
I can provide the test program if anyone is interested in reproducing.
Regards,
Yuval
--
Yuval Yeret
Exanet
yuval@exanet.com
http://www.exanet.com
Tel. 972-9-9717782
Fax. 972-9-9717778
<<Yuval Yeret (E-mail).vcf>>
BEGIN:VCARD
VERSION:2.1
N:Yeret;Yuval
FN:Yuval Yeret (E-mail)
ORG:Exanet
TITLE:Clustering and Platform Team Leader
TEL;WORK;VOICE:972-9-9717782
TEL;CELL;VOICE:972-54-802458
TEL;WORK;FAX:972-9-9717778
ADR;WORK;ENCODING=QUOTED-PRINTABLE:;;9 hamanofim st=0D=0Ap.o. 4064;Herzelia;;46140;Israel
LABEL;WORK;ENCODING=QUOTED-PRINTABLE:9 hamanofim st=0D=0Ap.o. 4064=0D=0AHerzelia 46140=0D=0AIsrael
EMAIL;PREF;INTERNET:mailto:yuval@exanet.com
REV:20020903T070728Z
END:VCARD
