[LU-2619] Bogus value of dqb_curinodes returned by osc_quotactl

• Type: Bug
• Resolution: Won't Fix
• Priority: Minor
• Affects Version/s: Lustre 2.4.0
• Labels: llnl
• Severity: 3
• Assignee: Niu Yawei (Inactive)
• Reporter: Prakash Surya (Inactive)

Description

When running lfs quota -u <USER> <FS> on Sequoia, a couple users do not have any files in their directory but quota reports a bogus large value:

# lfs quota -u pjmccart /p/ls1
Disk quotas for user pjmccart (uid 8624):
     Filesystem  kbytes   quota   limit   grace   files   quota   limit   grace
         /p/ls1     913       0       0       - 18446744073709547865       0       0       -

# du -sh /p/ls1/pjmccart/
913K    /p/ls1/pjmccart/

# ls -alR /p/ls1/pjmccart/
/p/ls1/pjmccart/:
total 1214
913 drwx------    2 pjmccart pjmccart 934400 Nov 15 10:28 ./
302 drwxr-xr-x 2193 root     root     308736 Jan 11 08:05 ../ 

Using systemtap to print the obd_quotactl structure when the osc_quotactl function returns, I see odd values coming from two of the OSCs:

osc_quotactl: "ls1-OST0037-osc-c0000003c865a400": {.qc_cmd=8388867, .qc_type=0, .qc_id=8624, .qc_stat=0, .qc_dqinfo={.dqi_bgrace=0, .dqi_igrace=0, .dqi_flags=0, .dqi_valid=0}, .qc_dqblk={.dqb_bhardlimit=0, .dqb_bsoftlimit=0, .dqb_curspace=0, .dqb_ihardlimit=0, .dqb_isoftlimit=0, .dqb_curinodes=0, .dqb_btime=0, .dqb_itime=0, .dqb_valid=15, .dqb_padding=0}}
osc_quotactl: "ls1-OST0038-osc-c0000003c865a400": {.qc_cmd=8388867, .qc_type=0, .qc_id=8624, .qc_stat=0, .qc_dqinfo={.dqi_bgrace=0, .dqi_igrace=0, .dqi_flags=0, .dqi_valid=0}, .qc_dqblk={.dqb_bhardlimit=0, .dqb_bsoftlimit=0, .dqb_curspace=0, .dqb_ihardlimit=0, .dqb_isoftlimit=0, .dqb_curinodes=18446744073709551615, .dqb_btime=0, .dqb_itime=0, .dqb_valid=15, .dqb_padding=0}}
osc_quotactl: "ls1-OST0039-osc-c0000003c865a400": {.qc_cmd=8388867, .qc_type=0, .qc_id=8624, .qc_stat=0, .qc_dqinfo={.dqi_bgrace=0, .dqi_igrace=0, .dqi_flags=0, .dqi_valid=0}, .qc_dqblk={.dqb_bhardlimit=0, .dqb_bsoftlimit=0, .dqb_curspace=0, .dqb_ihardlimit=0, .dqb_isoftlimit=0, .dqb_curinodes=0, .dqb_btime=0, .dqb_itime=0, .dqb_valid=15, .dqb_padding=0}}

osc_quotactl: "ls1-OST0073-osc-c0000003c865a400": {.qc_cmd=8388867, .qc_type=0, .qc_id=8624, .qc_stat=0, .qc_dqinfo={.dqi_bgrace=0, .dqi_igrace=0, .dqi_flags=0, .dqi_valid=0}, .qc_dqblk={.dqb_bhardlimit=0, .dqb_bsoftlimit=0, .dqb_curspace=0, .dqb_ihardlimit=0, .dqb_isoftlimit=0, .dqb_curinodes=3, .dqb_btime=0, .dqb_itime=0, .dqb_valid=15, .dqb_padding=0}}
osc_quotactl: "ls1-OST0074-osc-c0000003c865a400": {.qc_cmd=8388867, .qc_type=0, .qc_id=8624, .qc_stat=0, .qc_dqinfo={.dqi_bgrace=0, .dqi_igrace=0, .dqi_flags=0, .dqi_valid=0}, .qc_dqblk={.dqb_bhardlimit=0, .dqb_bsoftlimit=0, .dqb_curspace=0, .dqb_ihardlimit=0, .dqb_isoftlimit=0, .dqb_curinodes=18446744073709551615, .dqb_btime=0, .dqb_itime=0, .dqb_valid=15, .dqb_padding=0}}
osc_quotactl: "ls1-OST0075-osc-c0000003c865a400": {.qc_cmd=8388867, .qc_type=0, .qc_id=8624, .qc_stat=0, .qc_dqinfo={.dqi_bgrace=0, .dqi_igrace=0, .dqi_flags=0, .dqi_valid=0}, .qc_dqblk={.dqb_bhardlimit=0, .dqb_bsoftlimit=0, .dqb_curspace=0, .dqb_ihardlimit=0, .dqb_isoftlimit=0, .dqb_curinodes=3, .dqb_btime=0, .dqb_itime=0, .dqb_valid=15, .dqb_padding=0}}

Specifically, the values of dqb_curinodes:

ls1-OST0074-osc-c0000003c865a400:dqb_curinodes=18446744073709551615
ls1-OST0038-osc-c0000003c865a400:dqb_curinodes=18446744073709551615

Issue Links

• is related to: LU-2435 inode accounting in osd-zfs is racy

Comments

[Niu Yawei (Inactive)]

Thank you, I didn't see any difference in client code.

Looks the debug patch (http://review.whamcloud.com/#/c/8191/) has been applied in the code, is it possible to capture server logs with D_QUOTA enabled? So we can see if the bogus value is returned from osd_acct_index_lookup().

[Christopher Morrone (Inactive)]

In other words, tag 2.4.2-13chaos.

[D. Marc Stearman (Inactive)]

Yes it is still happening on all of our file systems, so the current tag will work for you.

[Prakash Surya (Inactive)]

As always, our source and releases are on github: https://github.com/chaos/lustre

As far as which releases were installed on the servers and clients in question, I'll have to ask the admins. Marc Stearman, can you double check this issue is still occurring on Sequoia and report back the version currently installed there?

[Niu Yawei (Inactive)]

The bogus 'dqb_curinodes' comes from OST, I'm wondering how it can contribute to the 'files' of 'lfs quota' output, because we only collect inode usage on MDTs:

                        /* collect space usage from OSTs */
                        oqctl_tmp->qc_dqblk.dqb_curspace = 0;
                        rc = obd_quotactl(sbi->ll_dt_exp, oqctl_tmp);
                        if (!rc || rc == -EREMOTEIO) {
                                oqctl->qc_dqblk.dqb_curspace =
                                        oqctl_tmp->qc_dqblk.dqb_curspace;
                                oqctl->qc_dqblk.dqb_valid |= QIF_SPACE;
                        }

                        /* collect space & inode usage from MDTs */
                        oqctl_tmp->qc_dqblk.dqb_curspace = 0;
                        oqctl_tmp->qc_dqblk.dqb_curinodes = 0;
                        rc = obd_quotactl(sbi->ll_md_exp, oqctl_tmp);
                        if (!rc || rc == -EREMOTEIO) {
                                oqctl->qc_dqblk.dqb_curspace +=
                                        oqctl_tmp->qc_dqblk.dqb_curspace;
                                oqctl->qc_dqblk.dqb_curinodes =
                                        oqctl_tmp->qc_dqblk.dqb_curinodes;
                                oqctl->qc_dqblk.dqb_valid |= QIF_INODES;
                        } else {
                                oqctl->qc_dqblk.dqb_valid &= ~QIF_SPACE;
                        }

I did some local testing that making OST to return fake 'curinodes' to client, however, client ignored the fake value as expected.

While investigating why server returns bogus value, I think I'd verify the client code you running wasn't changed by some unexpected patch. Could you show me where to check the client code? (llnl tree? which tag?) Thank you.

[Niu Yawei (Inactive)]

I'm assuming the bad "dqb_curinodes" values uncovered by the client systemtap script is coming from the server, is that not the case?

That's quite possible. I'm just not sure the purpose of using a 'fail_loc' on server to return bad value to client.

[Prakash Surya (Inactive)]

Well, I'm still unsure where the bad value is coming from, but my guess is it's coming from the server. I could be wrong, though.

I'm assuming the bad "dqb_curinodes" values uncovered by the client systemtap script is coming from the server, is that not the case?

[Niu Yawei (Inactive)]

what do you mean using a 'fail_loc' on server to return a bogus value to client? I don't think server is expected to return a bad value.

[Prakash Surya (Inactive)]

Yes, we see the same behavior on 2.1 and 2.4 clients. The server is 2.4 only, though. I don't know if the same would happen on a 2.1 server. We have a reproducer, but I think it is dependent on the server returning a "bad" value. Perhaps we can try to reproduce this in a VM setup, using a "fail_loc" on the server to return a bogus value to the client? I haven't tried that, but it might work.

[Niu Yawei (Inactive)]

This problem happened on both 2.1.4 client 2.4 client, right? Is it possible to make a reproducer?

[Prakash Surya (Inactive)]

Sigh.. Systemtap is failing me..

# porter34 /root > stap -v TOSS-27.stp 
Pass 1: parsed user script and 91 library script(s) using 101264virt/26156res/2964shr/24060data kb, in 110usr/0sys/111real ms.
semantic error: failed to retrieve location attribute for 'osd' (dieoffset: 0x8434c): identifier '$osd' at TOSS-27.stp:3:9
        source:                 @cast($osd, "osd_device")->od_svname$,
                                      ^

Pass 2: analyzed script: 1 probe(s), 7 function(s), 0 embed(s), 0 global(s) using 249680virt/34380res/6848shr/27132data kb, in 20usr/20sys/40real ms.
Pass 2: analysis failed.  Try again with another '--vp 01' option.
# porter34 /root > cat TOSS-27.stp 
probe module("osd-zfs").function("osd_acct_index_lookup").return {
        printf("%s: %s: id: %s, ispace: %u, bspace: %u\n", probefunc(),
                @cast($osd, "osd_device")->od_svname$,
                $buf, @cast($rec, "lquota_acct_rec")->ispace,
                @cast($rec, "lquota_acct_rec")->bspace);
}