Bug #17240
closedinode_permission error with kclient when running client IO with recovery operations.
0%
Description
Steps to reproduce:-
1) With client io running make few osds down and out of the cluster
2) Bring up the osds to in and up state.
3) When recovery IO is going on along with client IO, increase number of pgs in the pools.
Result: Client stops IO and throws warning messages as below:-
[22139.455743] libceph: osd20 up
[22355.006994] INFO: task java:65943 blocked for more than 120 seconds.
[22355.007004] Not tainted 4.8.0-040800rc1-generic #201608072231
[22355.007007] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[22355.007012] java D ffff9e7dfec57fc0 0 65943 65847 0x00000000
[22355.007018] ffff9e7df7eac500 ffff9e7df4400300 ffff9e7dde908538 ffff9e7dee64c000
[22355.007022] ffff9e7dee64bcb0 ffff9e78a8bb4a80 ffff9e78a8bb4a98 ffffffff00000000
[22355.007025] ffff9e78a8bb4a80 ffffffff99a15131 ffff9e7df4400300 ffffffff99a17cf7
[22355.007029] Call Trace:
[22355.007038] [<ffffffff99a15131>] ? schedule+0x31/0x80
[22355.007042] [<ffffffff99a17cf7>] ? rwsem_down_write_failed+0x217/0x390
[22355.007047] [<ffffffff99619d79>] ? __inode_permission+0x69/0xc0
[22355.007052] [<ffffffff9974c923>] ? call_rwsem_down_write_failed+0x13/0x20
[22355.007054] [<ffffffff99a17389>] ? down_write+0x29/0x40
[22355.007058] [<ffffffff9961df4e>] ? path_openat+0x36e/0x1510
[22355.007063] [<ffffffff994a98ef>] ? wake_up_q+0x3f/0x70
[22355.007067] [<ffffffff99500eba>] ? futex_wake_op+0x40a/0x5a0
[22355.007071] [<ffffffff996203b1>] ? do_filp_open+0x91/0x100
[22355.007075] [<ffffffff9960df5e>] ? do_sys_open+0x12e/0x210
[22355.007079] [<ffffffff99a19576>] ? entry_SYSCALL_64_fastpath+0x1e/0xa8
[22355.007082] INFO: task java:65945 blocked for more than 120 seconds.
[22355.007086] Not tainted 4.8.0-040800rc1-generic #201608072231
[22355.007089] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[22355.007093] java D ffff9e7dfea17fc0 0 65945 65847 0x00000000
[22355.007097] ffffffff9a00d500 ffff9e7df6dc2100 ffff9e7dde908538 ffff9e7df3970000
[22355.007100] ffff9e7df396fcb0 ffff9e78a8bb4a80 ffff9e78a8bb4a98 ffffffff00000000
[22355.007104] ffff9e78a8bb4a80 ffffffff99a15131 ffff9e7df6dc2100 ffffffff99a17cf7
[22355.007107] Call Trace:
[22355.007110] [<ffffffff99a15131>] ? schedule+0x31/0x80
[22355.007113] [<ffffffff99a17cf7>] ? rwsem_down_write_failed+0x217/0x390
[22355.007117] [<ffffffff99619d79>] ? __inode_permission+0x69/0xc0
[22355.007120] [<ffffffff9974c923>] ? call_rwsem_down_write_failed+0x13/0x20
[22355.007123] [<ffffffff99a17389>] ? down_write+0x29/0x40
[22355.007126] [<ffffffff9961df4e>] ? path_openat+0x36e/0x1510
[22355.007129] [<ffffffff994a98ef>] ? wake_up_q+0x3f/0x70
[22355.007132] [<ffffffff99500eba>] ? futex_wake_op+0x40a/0x5a0
[22355.007136] [<ffffffff996203b1>] ? do_filp_open+0x91/0x100
[22355.007139] [<ffffffff9960df5e>] ? do_sys_open+0x12e/0x210
[22355.007143] [<ffffffff99a19576>] ? entry_SYSCALL_64_fastpath+0x1e/0xa8
Updated by Rohith Radhakrishnan over 7 years ago
Cluster state at the time:-
ceph -s
cluster ee17af9f-24f1-425e-abd3-d2289102dec1
health HEALTH_ERR
31 pgs are stuck inactive for more than 300 seconds
3 pgs backfill_wait
246 pgs backfilling
99 pgs degraded
52 pgs peering
13 pgs recovery_wait
31 pgs stuck inactive
262 pgs stuck unclean
43 pgs undersized
recovery 52373/3706639 objects degraded (1.413%)
recovery 552557/3706639 objects misplaced (14.907%)
mds0: Behind on trimming (600/250)
monmap e1: 1 mons at {rack6-client-1=10.242.43.93:6789/0}
election epoch 4, quorum 0 rack6-client-1
fsmap e68: 1/1/1 up {0=rack6-client-2=up:active}, 1 up:standby
osdmap e1619: 32 osds: 32 up, 32 in; 257 remapped pgs
flags sortbitwise
pgmap v15401: 2624 pgs, 3 pools, 5823 GB data, 1624 kobjects
13284 GB used, 210 TB / 223 TB avail
52373/3706639 objects degraded (1.413%)
552557/3706639 objects misplaced (14.907%)
2280 active+clean
164 active+remapped+backfilling
52 peering
43 active+undersized+degraded+remapped+backfilling
39 active+degraded+remapped+backfilling
18 activating
10 active+recovery_wait+degraded+remapped
6 active+clean+replay
5 activating+replay
3 active+recovery_wait+degraded
3 active+degraded+remapped+wait_backfill
1 activating+degraded+remapped
Updated by John Spray over 7 years ago
- Category set to Correctness/Safety
- Priority changed from Urgent to High
- Component(FS) kceph added
Updated by Greg Farnum over 7 years ago
- Status changed from New to Closed
When the RADOS cluster has blocked IO, the kernel client is going to have blocked IO. That's just life. :(