[LU-15299] sanity-quota test_71a: FAIL: user write failure, but expect success

• Type: Bug
• Resolution: Unresolved
• Priority: Minor
• Affects Version/s: Lustre 2.15.0
• Severity: 3
• Assignee: WC Triage
• Reporter: Elena Gryaznova

Description

== sanity-quota test 71a: Check PFL with quota pools ===== 11:13:43 (1637838823)
Waiting for MDT destroys to complete
Creating test directory
fail_val=0
fail_loc=0
fail_val=0
fail_loc=0
User quota (block hardlimit:100 MB)
Creating new pool
fre801: Pool lustre.qpool1 created
Adding targets to pool
fre801: OST lustre-OST0000_UUID added to pool lustre.qpool1
fre801: OST lustre-OST0001_UUID added to pool lustre.qpool1
Creating new pool
fre801: Pool lustre.qpool2 created
Adding targets to pool
fre801: OST lustre-OST0001_UUID added to pool lustre.qpool2
used 0
Write...
running as uid/gid/euid/egid 60000/60000/60000/60000, groups:
 [dd] [if=/dev/zero] [bs=1M] [of=/mnt/lustre/d71a.sanity-quota/f71a.sanity-quota-0] [count=10]
dd: error writing '/mnt/lustre/d71a.sanity-quota/f71a.sanity-quota-0': Disk quota exceeded
10+0 records in
9+0 records out
9437184 bytes (9.4 MB, 9.0 MiB) copied, 0.415265 s, 22.7 MB/s
Disk quotas for usr quota_usr (uid 60000):
     Filesystem  kbytes   quota   limit   grace   files   quota   limit   grace
    /mnt/lustre    9216       0  102400       -       1       0       0       -
lustre-MDT0000_UUID
                      0       -       0       -       1       -       0       -
lustre-MDT0001_UUID
                      0       -       0       -       0       -       0       -
lustre-OST0000_UUID
                   9216       -   10240       -       -       -       -       -
lustre-OST0001_UUID
                      0       -       0       -       -       -       -       -
Total allocated inode limit: 0, total allocated block limit: 10240
Files for user (quota_usr):
  File: /mnt/lustre/d71a.sanity-quota/f71a.sanity-quota-0
  Size: 9437184   	Blocks: 18432      IO Block: 4194304 regular file
Device: 2c54f966h/743766374d	Inode: 144115540850445625  Links: 1
Access: (0644/-rw-r--r--)  Uid: (60000/quota_usr)   Gid: (60000/quota_usr)
Access: 2021-11-25 11:14:10.000000000 +0000
Modify: 2021-11-25 11:14:11.000000000 +0000
Change: 2021-11-25 11:14:11.000000000 +0000
 Birth: -
 sanity-quota test_71a: @@@@@@ FAIL: user write failure, but expect success 

Issue Links

• is related to: LU-18293 sanity-quota test_1a, 1b, 1c: FAIL: user write success, but expect EDQUOT

Comments

[Yang Sheng]

Hit again, on ost:

00040000:04000000:2.0:1744789608.395648:0:292236:0:(qsd_handler.c:746:qsd_op_begin0()) $$$ op_begin space:1032  qsd:lustre-OST0000 qtype:usr id:1001 enforced:1 granted: 10240 pending:0 waiting:0 req:0 usage: 9216 qunit:1024 qtune:512 edquot:1 default:no revoke:0
00040000:00000001:2.0:1744789608.395652:0:292236:0:(qsd_handler.c:638:qsd_acquire()) Process entered
00040000:04000000:2.0:1744789608.395654:0:292236:0:(qsd_handler.c:641:qsd_acquire()) $$$ acquiring:1032 count=0  qsd:lustre-OST0000 qtype:usr id:1001 enforced:1 granted: 10240 pending:0 waiting:1032 req:0 usage: 9216 qunit:1024 qtune:512 edquot:1 default:no revoke:0
00040000:00000001:2.0:1744789608.395657:0:292236:0:(qsd_entry.c:213:qsd_refresh_usage()) Process entered
00040000:00000001:2.0:1744789608.395658:0:292236:0:(lquota_disk.c:556:lquota_disk_read()) Process entered
00000001:00000001:2.0:1744789608.395660:0:292236:0:(osd_quota.c:132:osd_acct_index_lookup()) Process entered
00000001:00000001:2.0:1744789608.395663:0:292236:0:(osd_quota.c:147:osd_acct_index_lookup()) Process leaving (rc=1 : 1 : 1)
00040000:00000001:2.0:1744789608.395665:0:292236:0:(lquota_disk.c:566:lquota_disk_read()) Process leaving (rc=0 : 0 : 0)
00040000:04000000:2.0:1744789608.395667:0:292236:0:(qsd_entry.c:236:qsd_refresh_usage()) $$$ disk usage: 9216  qsd:lustre-OST0000 qtype:usr id:1001 enforced:1 granted: 10240 pending:0 waiting:1032 req:0 usage: 9216 qunit:1024 qtune:512 edquot:1 default:no revoke:0
00040000:00000001:2.0:1744789608.395670:0:292236:0:(qsd_entry.c:237:qsd_refresh_usage()) Process leaving (rc=0 : 0 : 0)
00040000:00000001:2.0:1744789608.395671:0:292236:0:(qsd_handler.c:445:qsd_acquire_local()) Process entered
00040000:00000001:2.0:1744789608.395672:0:292236:0:(qsd_handler.c:474:qsd_acquire_local()) Process leaving (rc=18446744073709551494 : -122 : ffffffffffffff86)
00040000:00000001:2.0:1744789608.395673:0:292236:0:(qsd_handler.c:683:qsd_acquire()) Process leaving (rc=1 : 1 : 1)
00040000:04000000:2.0:1744789608.395675:0:292236:0:(qsd_handler.c:773:qsd_op_begin0()) $$$ acquire quota failed:-122  qsd:lustre-OST0000 qtype:usr id:1001 enforced:1 granted: 10240 pending:0 waiting:1032 req:0 usage: 9216 qunit:1024 qtune:512 edquot:1 default:no revoke:0
00040000:00000001:2.0:1744789608.395678:0:292236:0:(qsd_handler.c:828:qsd_op_begin0()) Process leaving (rc=18446744073709551494 : -122 : ffffffffffffff86)
00040000:00000001:2.0:1744789608.395679:0:292236:0:(qsd_handler.c:930:qsd_op_begin()) Process leaving (rc=18446744073709551494 : -122 : ffffffffffffff86)
00000001:00000001:2.0:1744789608.395681:0:292236:0:(osd_quota.c:615:osd_declare_qid()) Process leaving (rc=18446744073709551494 : -122 : ffffffffffffff86)

script:

test_1_check_write() {
        local testfile="$1"
        local qtype="$2"
        local limit=$3
        local short_qtype=${qtype:0:1}

        log "Write..."
        $RUNAS $DD of=$testfile count=$((limit/2)) oflag=direct ||
                quota_error $short_qtype $TSTUSR \
                        "$qtype write failure, but expect success"
        log "Write out of block quota ..."
        # this time maybe cache write, ignore it's failure
        $RUNAS $DD of=$testfile count=$((limit/2)) seek=$((limit/2)) \
                                                oflag=direct || true
        # flush cache, ensure noquota flag is set on client

[James A Simmons]

This is very common with the latest master