Bug 1594674

Summary: Blocked lock request(s) on a file are reported as slow requests
Product: [Red Hat Storage] Red Hat Ceph Storage Reporter: Venky Shankar <vshankar>
Component: CephFSAssignee: Patrick Donnelly <pdonnell>
Status: CLOSED ERRATA QA Contact: Tejas <tchandra>
Severity: low Docs Contact:
Priority: low    
Version: 3.0CC: ceph-eng-bugs, ceph-qe-bugs, john.spray, rperiyas, tchandra
Target Milestone: z5   
Target Release: 3.0   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: RHEL: ceph-12.2.4-32 Ubuntu: ceph_12.2.4-36redhat1xenial Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-08-09 18:27:13 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Venky Shankar 2018-06-25 07:35:09 UTC
Description of problem:
A blocking lock request (e.g. a conflicting lock request on a file region using flock(2)) will result in MDS reporting/logging the request as "slow request".

Version-Release number of selected component (if applicable):
3.0

How reproducible:
100%

Steps to Reproduce:
Best tested by using flock(1) (as below) or following similar steps w/ a C program.

1. In one ceph kclient mount run: flock -x </path/to/file/in/cepfs/mount> sleep 3600
2. In another ceph kclient mount run: flock -x </path/to/file/in/cepfs/mount> sleep 3600
3. wait for some time (~30 odd seconds)
4. Check the MDS log for slow requests (should resemble something like below):


2018-06-25 03:27:30.305830 7f039ad85700  0 log_channel(cluster) log [WRN] : 1 slow requests, 1 included below; oldest blocked for > 32.606567 secs                                                        
2018-06-25 03:27:30.305895 7f039ad85700  0 log_channel(cluster) log [WRN] : slow request 32.606567 seconds old, received at 2018-06-25 03:26:57.699199: client_request(client.324120:4 setfilelockrule 2, type 2, owner 15445109620320908090, pid 11253, start 0, length 0, wait 1 #0x10000000001 2018-06-25 03:26:57.692840 caller_uid=1000, caller_gid=1000{}) currently acquired locks

Additionally the blocked request can be checked by dumping the in-flight request as:

# ceph daemon mds.<id> dump_ops_in_flight          

Actual results:
Slow request reported by MDS:

Expected results:
The lock request should not be reported as slow request

Comment 12 errata-xmlrpc 2018-08-09 18:27:13 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2018:2375