[LU-14976] Changing tbf policy induces high CPU load

• Type: Bug
• Resolution: Fixed
• Priority: Major
• Fix Version/s: Lustre 2.16.0
• Environment: Centos 7 VMs on Lustre 2.14
• Severity: 3
• Assignee: Etienne Aujames
• Reporter: Etienne Aujames

Description

Reproducer:

1. Activate "tbf gid" policy:
   lctl set_param mds.MDS.mdt.nrs_policies="tbf gid"
2. Register a rule for a group (with a small rate value):
   lctl set_param mds.MDS.mdt.nrs_tbf_rule="start eaujames gid={1000} rate=10"
3. Start doing md oprations with the limited gid on the mdt (multithreaded file creations/deletions)
4. When a message is queued inside the policy, changes the policy to tbf:
   lctl set_param mds.MDS.mdt.nrs_policies="tbf"
5. Stop md operations. Lustre consumes 100% on CPU partition where the message is queued:
   For our production filesystem, on MDT0001 all cpt were impacted (>100 rpc in queue, load ~300) and on MDT0000 one cpt was impacted (1 rpc in queue, load ~90).

mds.MDS.mdt.nrs_policies=
regular_requests:
  - name: fifo
    state: started
    fallback: yes
    queued: 0
    active: 0  
  
  - name: crrn
    state: stopped
    fallback: no
    queued: 0
    active: 0
  
  - name: tbf
    state: started
    fallback: no
    queued: 1
    active: 0
  
  - name: delay
    state: stopped
    fallback: no
    queued: 0
    active: 0

When we try to change the policy to fifo, the proccess is block to "stopping" state:

mds.MDS.mdt.nrs_policies=
regular_requests:
  - name: fifo
    state: started
    fallback: yes 
    queued: 0    
    active: 0   

  - name: crrn
    state: stopped
    fallback: no
    queued: 0    
    active: 0  

  - name: tbf 
    state: stopping
    fallback: no
    queued: 1    
    active: 0   
  
  - name: delay
    state: stopped
    fallback: no
    queued: 0
    active: 0

Analyse:

It seems that when we change tbf policy ("tbf gid" -> "tbf"), old rpc queued inside "tbf gid" became inaccessible to ptlrpc threads.

ptlrpc_wait_event wake up when an rpc is availabled to enqueue. But in that case ptlrpc thread is unable to enqueue the request, so it wake up all the time (causing the cpu load).

00000100:00000001:1.0:1630509978.890060:0:4749:0:(service.c:2029:ptlrpc_server_request_get()) Process leaving (rc=0 : 0 : 0)
00000100:00000001:0.0:1630509978.890060:0:5580:0:(service.c:2008:ptlrpc_server_request_get()) Process entered
00000100:00000001:2.0:1630509978.890061:0:5653:0:(service.c:2029:ptlrpc_server_request_get()) Process leaving (rc=0 : 0 : 0)
00000100:00000001:2.0:1630509978.890061:0:5653:0:(service.c:2248:ptlrpc_server_handle_request()) Process leaving (rc=0 : 0 : 0)
00000100:00000001:1.0:1630509978.890061:0:4749:0:(service.c:2248:ptlrpc_server_handle_request()) Process leaving (rc=0 : 0 : 0)
00000100:00000001:0.0:1630509978.890061:0:5580:0:(service.c:2029:ptlrpc_server_request_get()) Process leaving (rc=0 : 0 : 0)
00000100:00000001:0.0:1630509978.890061:0:5580:0:(service.c:2248:ptlrpc_server_handle_request()) Process leaving (rc=0 : 0 : 0)
00000100:00000001:1.0:1630509978.890062:0:4749:0:(service.c:2244:ptlrpc_server_handle_request()) Process entered
00000100:00000001:1.0:1630509978.890062:0:4749:0:(service.c:2008:ptlrpc_server_request_get()) Process entered
00000100:00000001:2.0:1630509978.890063:0:5653:0:(service.c:2244:ptlrpc_server_handle_request()) Process entered
00000100:00000001:2.0:1630509978.890063:0:5653:0:(service.c:2008:ptlrpc_server_request_get()) Process entered
00000100:00000001:1.0:1630509978.890063:0:4749:0:(service.c:2029:ptlrpc_server_request_get()) Process leaving (rc=0 : 0 : 0)
00000100:00000001:0.0:1630509978.890063:0:5580:0:(service.c:2244:ptlrpc_server_handle_request()) Process entered
00000100:00000001:2.0:1630509978.890064:0:5653:0:(service.c:2029:ptlrpc_server_request_get()) Process leaving (rc=0 : 0 : 0)

On my VM for one mdt thread ptlrpc_server_handle_request() is called with 300kHz frequency (doing nothing).

Issue Links

• is related to: LU-14364 Switching QoS from tbf uid to fifo caused soft lockup
• is related to: LU-16846 Fix concole messages in nrs.c
• is related to: LU-9885 Huge amount of costs in ptlrpc_wait_event() at file creation

Comments

[Gerrit Updater]

"Etienne AUJAMES <[e-mail]>" uploaded a new patch: https://review.whamcloud.com/c/fs/lustre-release/+/51119
Subject: LU-14976 nrs: change nrs policies at run time
Project: fs/lustre-release
Branch: b2_12
Current Patch Set: 1
Commit: bdb237e26e903d2eb9d7fb1697965c7234a431f5

[Gerrit Updater]

"Etienne AUJAMES <[e-mail]>" uploaded a new patch: https://review.whamcloud.com/c/fs/lustre-release/+/51118
Subject: LU-14976 nrs: change nrs policies at run time
Project: fs/lustre-release
Branch: b2_15
Current Patch Set: 1
Commit: 8292d1a744b996a43acb8d1f34210d8f9b6c7581

[Peter Jones]

Landed for 2.16

[Gerrit Updater]

"Oleg Drokin <[e-mail]>" merged in patch https://review.whamcloud.com/c/fs/lustre-release/+/48523/
Subject: LU-14976 nrs: change nrs policies at run time
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: c098c09564a125dd44ffe0c135cd1cb6359229e7

[Gerrit Updater]

"Etienne AUJAMES <[e-mail]>" uploaded a new patch: https://review.whamcloud.com/48523
Subject: LU-14976 nrs: change nrs policies at run time
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 37530fe5fc53a80519e4334a3a295e690f03afbc

[Gerrit Updater]

"Oleg Drokin <[e-mail]>" merged in patch https://review.whamcloud.com/44817/
Subject: LU-14976 ptlrpc: align function names with param names
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 7fe49f1e7cf0586da0f389188325014a8a13b849

[Etienne Aujames]

This issue occurred on a filesystem in production.

Here the context:
A user was filling the changelog list 18k open/s  (changelog usage jump from 30% to 70% in one night). So the admin wanted to limit this user to avoid MDT crash.
The activated NRS policy was "tbf gid", the admin changed the tbf policy to "tbf" to limit the user by uid.