Re: zero-filed page on VOP_PUTPAGES

[Emmanuel Dreyfus <manu%netbsd.org@localhost>]

On Wed, Aug 17, 2011 at 07:09:34AM +0200, Emmanuel Dreyfus wrote:
> I will investigate further.

Here are the findings. I run with yamt's patch, and without 
PUFFS_KFLAG_WTCACHE. zeroed chunks will randomly appear, and it seems
this is not restricted to offset zero after all.

Attached are two traces: 0chunk-ok.txt where no corruption occur, 
and 0chunk-bad.txt where I get 3682 zeroed bytes at offet 36864.

It is surprising to see how the taces are different: the one that
is fine does not use async (FAF) writes, while the one that gets
corruuption does. grep optype gives the short sumaries below

Case where everthing is okay:
    reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_CLOSE, cookie: 0xbb90f340,
    reqid: 1078, opclass 2, optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
    reqid: 1079, opclass 2, optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
    reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_SETATTR, cookie: 0xbb90f340,
    reqid: 1080, opclass 2, optype: PUFFS_VN_INACTIVE, cookie: 0xbb90f340,
 
Corrupted case:
    reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
    reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
    reqid: 1322, opclass 2, optype: PUFFS_VN_SETATTR, cookie: 0xbb90f340,
    reqid: 1323, opclass 2, optype: PUFFS_VN_FSYNC, cookie: 0xbb90f340,
    reqid: 1324, opclass 1, optype: PUFFS_VFS_SYNC, cookie: 0x0,
    reqid: 1325, opclass 2, optype: PUFFS_VN_GETATTR, cookie: 0xbb90f340,
    reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_CLOSE, cookie: 0xbb90f340,
    reqid: 1342, opclass 2, optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
    reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_SETATTR, cookie: 0xbb90f340,
    reqid: 1343, opclass 2, optype: PUFFS_VN_INACTIVE, cookie: 0xbb90f340,

-- 
Emmanuel Dreyfus
manu%netbsd.org@localhost

        reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
                aux: 0xbb92102c, auxlen: 32912, pid: 0, lwpid: 27
                offset: 0, resid 32768, ioflag 0x0
                since previous call: 0.007031
        reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
                aux: 0xbb93302c, auxlen: 7922, pid: 0, lwpid: 27
                offset: 32768, resid 7778, ioflag 0x0
                since previous call: 0.000637
        reqid: 1322, opclass 2, optype: PUFFS_VN_SETATTR, cookie: 0xbb90f340,
                aux: 0xbb92002c, auxlen: 240, pid: 0, lwpid: 27
                size: 40546/0x9e62
                since previous call: 0.000024
        RV reqid: 1321, result: 0 
        RV reqid: 1322, result: 0 
        reqid: 1323, opclass 2, optype: PUFFS_VN_FSYNC, cookie: 0xbb90f340,
                aux: 0xbb91e02c, auxlen: 148, pid: 0, lwpid: 27
                since previous call: 0.026446
        RV reqid: 1323, result: 0 
        reqid: 1324, opclass 1, optype: PUFFS_VFS_SYNC, cookie: 0x0,
                aux: 0xbb91f02c, auxlen: 132, pid: 0, lwpid: 27
                since previous call: 0.015758
        RV reqid: 1324, result: 0 
        reqid: 1325, opclass 2, optype: PUFFS_VN_GETATTR, cookie: 0xbb90f340,
                aux: 0xbb91e02c, auxlen: 240, pid: 10480, lwpid: 1
                since previous call: 0.010160
        RV reqid: 1325, result: 0 

        (many PUFFS_VN_GETATTR)

        reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_CLOSE, cookie: 0xbb90f340,
                aux: 0xbb91f02c, auxlen: 132, pid: 6141, lwpid: 1
                since previous call: 0.006899
        reqid: 1342, opclass 2, optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
                aux: 0xbb91f02c, auxlen: 7943, pid: 6141, lwpid: 1
                offset: 36864, resid 7799, ioflag 0x0
                since previous call: 0.000024
        RV reqid: 1342, result: 0 
                resid after op: 0
        reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_SETATTR, cookie: 0xbb90f340,
                aux: 0xbb91e02c, auxlen: 240, pid: 6141, lwpid: 1
                size: 44663/0xae77
                since previous call: 0.000629
        reqid: 1343, opclass 2, optype: PUFFS_VN_INACTIVE, cookie: 0xbb90f340,
                aux: 0xbb92002c, auxlen: 44, pid: 6141, lwpid: 1
                since previous call: 0.000089
        RV reqid: 1343, result: 0 

        reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_CLOSE, cookie: 0xbb90f340,
                aux: 0xbb91f02c, auxlen: 132, pid: 11196, lwpid: 1
                since previous call: 0.011250
        reqid: 1078, opclass 2, optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
                aux: 0xbb91f02c, auxlen: 32912, pid: 11196, lwpid: 1
                offset: 0, resid 32768, ioflag 0x0
                since previous call: 0.000031
        RV reqid: 1078, result: 0 
                resid after op: 0
        reqid: 1079, opclass 2, optype: PUFFS_VN_WRITE, cookie: 0xbb90f340,
                aux: 0xbb91f02c, auxlen: 12039, pid: 11196, lwpid: 1
                offset: 32768, resid 11895, ioflag 0x0
                since previous call: 0.000996
        RV reqid: 1079, result: 0 
                resid after op: 0
        reqid: 0, opclass 2 (FAF), optype: PUFFS_VN_SETATTR, cookie: 0xbb90f340,
                aux: 0xbb91e02c, auxlen: 240, pid: 11196, lwpid: 1
                size: 44663/0xae77
                since previous call: 0.000777
        reqid: 1080, opclass 2, optype: PUFFS_VN_INACTIVE, cookie: 0xbb90f340,
                aux: 0xbb92002c, auxlen: 44, pid: 11196, lwpid: 1
                since previous call: 0.000096
        RV reqid: 1080, result: 0