Hello,
It looks like I have found a bug in Garbage Collection.
If yaffs2 is under heavy pressure on free space, sometimes it corrupts some
files. File corruption is such, that part of file is lost (all bytes are 0
there). When reading such file, it gives
Chunk -1 not found zero instead
messages.
That corruption can be detected only after file cache is flushed (I'm
unmounting and mounting back that nand).
Some details:
NAND Block size: 2048 bytes
File size: 81566 bytes (39 data chunks)
File name: xxx
Lost bytes: [0x2800..0xb000) (chunks [6..22])
Here is trace output, when that file is written:
yaffs_mknod: making oject for xxx, mode 81a4 dev 0
Writing chunk 12538 tags 439 0
Writing chunk 12539 tags 439 1
Writing chunk 12540 tags 439 2
Writing chunk 12541 tags 439 3
Writing chunk 12542 tags 439 4
Writing chunk 12543 tags 439 5
Writing chunk 14784 tags 439 6
GC Selected block 66 with 8 free
yaffs: GC erasedBlocks 4 aggressive 1
Collecting block 66, in use 56, shrink 0,
Writing chunk 14785 tags 887 22
line 2521 delete of chunk 4224
...<GC stuff here>
Writing chunk 14840 tags 1185 16
line 2521 delete of chunk 4287
Writing chunk 14841 tags 439 7
Writing chunk 14842 tags 439 8
Writing chunk 14843 tags 439 9
Writing chunk 14844 tags 439 10
Writing chunk 14845 tags 439 11
Writing chunk 14846 tags 439 12
Writing chunk 14847 tags 439 13
Writing chunk 20160 tags 439 14
GC Selected block 52 with 4 free
yaffs: GC erasedBlocks 4 aggressive 1
Collecting block 52, in use 60, shrink 0,
Writing chunk 20161 tags 1126 30
line 2521 delete of chunk 3328
...<GC stuff here>
Writing chunk 20220 tags 887 2
line 2521 delete of chunk 3391
Writing chunk 20221 tags 439 15
Writing chunk 20222 tags 439 16
Writing chunk 20223 tags 439 17
Writing chunk 37824 tags 439 18
GC Selected block 240 with 4 free
yaffs: GC erasedBlocks 4 aggressive 1
Collecting block 240, in use 60, shrink 0,
Writing chunk 37825 tags 1448 76
line 2521 delete of chunk 15361
...<GC stuff here>
Writing chunk 37884 tags 1729 6
line 2521 delete of chunk 15420
Writing chunk 37885 tags 439 19
Writing chunk 37886 tags 439 20
Writing chunk 37887 tags 439 21
Writing chunk 45056 tags 439 22
GC Selected block 196 with 3 free
yaffs: GC erasedBlocks 4 aggressive 1
Collecting block 196, in use 61, shrink 0,
Writing chunk 45057 tags 932 243
line 2521 delete of chunk 12544
...<GC stuff here>
Writing chunk 45109 tags 932 244
line 2521 delete of chunk 12596
Writing chunk 45110 tags 932 245
line 2521 delete of chunk 12597
Writing chunk 45111 tags 932 0
line 2521 delete of chunk 12601
<here comes the interesting part - GC collects file 'xxx', which is being
written right now>
Writing chunk 45112 tags 439 0
line 2521 delete of chunk 12602
Writing chunk 45113 tags 439 1
line 2521 delete of chunk 12603
Writing chunk 45114 tags 439 2
line 2521 delete of chunk 12604
Writing chunk 45115 tags 439 3
line 2521 delete of chunk 12605
Writing chunk 45116 tags 439 4
line 2521 delete of chunk 12606
Writing chunk 45117 tags 439 5
line 2521 delete of chunk 12607
<here GC ends its collection. Note, that blocks 0..5 of 'xxx' are rewritten by
GC. It looks like here it looses those blocks 6..22 >
Writing chunk 45118 tags 439 23
Writing chunk 45119 tags 439 24
Writing chunk 3264 tags 439 25
GC Selected block 255 with 2 free
yaffs: GC erasedBlocks 4 aggressive 1
Collecting block 255, in use 63, shrink 1,
Writing chunk 3265 tags 985 118
line 2521 delete of chunk 16320
...<GC stuff here>
Writing chunk 3326 tags 985 128
line 2521 delete of chunk 16383
Writing chunk 3327 tags 439 26
Writing chunk 4096 tags 439 27
GC Selected block 273 with 3 free
yaffs: GC erasedBlocks 4 aggressive 1
Collecting block 273, in use 61, shrink 1,
Writing chunk 4097 tags 985 129
line 2521 delete of chunk 17472
...<GC stuff here>
Writing chunk 4157 tags 985 137
line 2521 delete of chunk 17535
Writing chunk 4158 tags 439 28
Writing chunk 4159 tags 439 29
Writing chunk 4160 tags 439 30
GC Selected block 709 with 43 free
yaffs: GC erasedBlocks 4 aggressive 1
Collecting block 709, in use 59, shrink 1,
Writing chunk 4161 tags 1193 135
line 2521 delete of chunk 45377
...<GC stuff here>
Writing chunk 4181 tags 985 0
line 2521 delete of chunk 45439
yaffs: About to finally delete object 735
Writing chunk 4182 tags 735 0
line 3383 delete of chunk 45170
line 4169 delete of chunk 4246
Writing chunk 4183 tags 439 31
Writing chunk 4184 tags 439 32
Writing chunk 4185 tags 439 33
Writing chunk 4186 tags 439 34
Writing chunk 4187 tags 439 35
Writing chunk 4188 tags 439 36
Writing chunk 4189 tags 439 37
Writing chunk 4190 tags 439 38
Writing chunk 4191 tags 439 39
Writing chunk 4192 tags 439 40
Writing chunk 4193 tags 439 0
line 3383 delete of chunk 45176
Writing chunk 4194 tags 439 0
line 3383 delete of chunk 4257
Writing chunk 4195 tags 439 0
line 3383 delete of chunk 4258
Writing chunk 4196 tags 439 0
line 3383 delete of chunk 4259
Is it enough with this information, to find and fix the bug? I have no idea,
how to fix it...
And one more thing - while after a while it gives such messages:
gc did not increase free chunks before 319 after 319
yaffs: GC !!!no reclaim!!! erasedBlocks 4 after try 1 block 23
is it ok? Can it happen under normal condition?
Here is output of /proc/yaffs
YAFFS built:Jul 29 2005 16:16:21
$Id: yaffs_fs.c,v 1.9 2005/07/19 20:41:59 charles Exp $
$Id: yaffs_guts.c,v 1.10 2005/07/26 03:05:28 charles Exp $
Device 0 "NAND Main"
startBlock......... 0
endBlock........... 991
chunkGroupBits..... 0
chunkGroupSize..... 1
nErasedBlocks...... 5
nTnodesCreated..... 5400
nFreeTnodes........ 84
nObjectsCreated.... 1600
nFreeObjects....... 132
nFreeChunks........ 1647
nPageWrites........ 0
nPageReads......... 0
nBlockErasures..... 904
nGCCopies.......... 0
garbageCollections. 904
passiveGCs......... 19
nRetriedWrites..... 0
nRetireBlocks...... 0
eccFixed........... 0
eccUnfixed......... 0
tagsEccFixed....... 0
tagsEccUnfixed..... 0
cacheHits.......... 3
nDeletedFiles...... 749
nUnlinkedFiles..... 2129
nBackgroudDeletions 0
useNANDECC......... 1
isYaffs2........... 1
Regards,
-Artis