Bug 1594674 - Blocked lock request(s) on a file are reported as slow requests
Summary: Blocked lock request(s) on a file are reported as slow requests
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Ceph Storage
Classification: Red Hat
Component: CephFS
Version: 3.0
Hardware: All
OS: All
low
low
Target Milestone: z5
: 3.0
Assignee: Patrick Donnelly
QA Contact: Tejas
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-06-25 07:35 UTC by Venky Shankar
Modified: 2018-08-09 18:27 UTC (History)
5 users (show)

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:
Clone Of:
Environment:
Last Closed: 2018-08-09 18:27:13 UTC
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Ceph Project Bug Tracker 23989 None None None 2018-06-25 07:35:09 UTC
Red Hat Product Errata RHBA-2018:2375 None None None 2018-08-09 18:27:32 UTC

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


Note You need to log in before you can comment on or make changes to this bug.