Ceph

Trying to remove snapshots causes SLOW_OPS on the active mon and seems to hang indefinitly. The logs show messages
like

Jan  3 09:56:20 ceph-mon-m ceph-mon[1838]: 2019-01-03 09:56:20.075 7f44d1e68700 -1 mon.ceph-mon-m@2(peon) e1
get_health_metrics reporting 3 slow ops, oldest is remove_snaps({39=[6,d,11,14,16,17,18,19]} v0)

I couldn't find any suspicious log entries on the machine that could point to the underlying cause.

root@ceph-mon-m:~# date
Do 3. Jan 09:52:13 CET 2019
root@ceph-mon-m:~# ceph health detail
HEALTH_WARN 3 slow ops, oldest one blocked for 1198614 sec, mon.ceph-mon-m has slow ops
SLOW_OPS 3 slow ops, oldest one blocked for 1198614 sec, mon.ceph-mon-m has slow ops
root@ceph-mon-m:~# ceph daemon mon.ceph-mon-m ops
{
"ops": [
{
"description": "remove_snaps({39=[6,d,11,14,16,17,18,19]} v0)",
"initiated_at": "2018-12-20 12:57:40.852620",
"age": 1198479.743774,
"duration": 1198479.743806,
"type_data": {
"events": [
{
"time": "2018-12-20 12:57:40.852620",
"event": "initiated" 
},
{
"time": "2018-12-20 12:57:40.852620",
"event": "header_read" 
},
{
"time": "2018-12-20 12:57:40.852623",
"event": "throttled" 
},
{
"time": "2018-12-20 12:57:40.852633",
"event": "all_read" 
},
{
"time": "2018-12-20 12:57:40.852717",
"event": "dispatched" 
},
{
"time": "2018-12-20 12:57:40.852723",
"event": "mon:_ms_dispatch" 
},
{
"time": "2018-12-20 12:57:40.852724",
"event": "mon:dispatch_op" 
},
{
"time": "2018-12-20 12:57:40.852725",
"event": "psvc:dispatch" 
},
{
"time": "2018-12-20 12:57:40.852744",
"event": "osdmap:preprocess_query" 
},
{
"time": "2018-12-20 12:57:40.852746",
"event": "osdmap:preprocess_remove_snaps" 
},
{
"time": "2018-12-20 12:57:40.852753",
"event": "forward_request_leader" 
},
{
"time": "2018-12-20 12:57:40.852816",
"event": "forwarded" 
}
],
"info": {
"seq": 42017297,
"src_is_mon": false,
"source": "mds.0 10.120.3.182:6800/1262182774",
"forwarded_to_leader": true
}
}
},
{
"description": "remove_snaps({39=[4,b,12,1a,1b,1c]} v0)",
"initiated_at": "2018-12-20 12:58:40.854322",
"age": 1198419.742072,
"duration": 1198419.742246,
"type_data": {
"events": [
{
"time": "2018-12-20 12:58:40.854322",
"event": "initiated" 
},
{
"time": "2018-12-20 12:58:40.854322",
"event": "header_read" 
},
{
"time": "2018-12-20 12:58:40.854326",
"event": "throttled" 
},
{
"time": "2018-12-20 12:58:40.854338",
"event": "all_read" 
},
{
"time": "2018-12-20 12:58:40.854456",
"event": "dispatched" 
},
{
"time": "2018-12-20 12:58:40.854462",
"event": "mon:_ms_dispatch" 
},
{
"time": "2018-12-20 12:58:40.854463",
"event": "mon:dispatch_op" 
},
{
"time": "2018-12-20 12:58:40.854464",
"event": "psvc:dispatch" 
},
{
"time": "2018-12-20 12:58:40.854483",
"event": "osdmap:preprocess_query" 
},
{
"time": "2018-12-20 12:58:40.854485",
"event": "osdmap:preprocess_remove_snaps" 
},
{
"time": "2018-12-20 12:58:40.854493",
"event": "forward_request_leader" 
},
{
"time": "2018-12-20 12:58:40.854558",
"event": "forwarded" 
}
],
"info": {
"seq": 42018403,
"src_is_mon": false,
"source": "mds.0 10.120.3.182:6800/1262182774",
"forwarded_to_leader": true
}
}
},
{
"description": "remove_snaps({39=[5,c,10,13,1d,1e,1f,20]} v0)",
"initiated_at": "2018-12-20 12:58:45.865380",
"age": 1198414.731014,
"duration": 1198414.731305,
"type_data": {
"events": [
{
"time": "2018-12-20 12:58:45.865380",
"event": "initiated" 
},
{
"time": "2018-12-20 12:58:45.865380",
"event": "header_read" 
},
{
"time": "2018-12-20 12:58:45.865384",
"event": "throttled" 
},
{
"time": "2018-12-20 12:58:45.865395",
"event": "all_read" 
},
{
"time": "2018-12-20 12:58:45.865511",
"event": "dispatched" 
},
{
"time": "2018-12-20 12:58:45.865518",
"event": "mon:_ms_dispatch" 
},
{
"time": "2018-12-20 12:58:45.865520",
"event": "mon:dispatch_op" 
},
{
"time": "2018-12-20 12:58:45.865520",
"event": "psvc:dispatch" 
},
{
"time": "2018-12-20 12:58:45.865543",
"event": "osdmap:preprocess_query" 
},
{
"time": "2018-12-20 12:58:45.865545",
"event": "osdmap:preprocess_remove_snaps" 
},
{
"time": "2018-12-20 12:58:45.865558",
"event": "forward_request_leader" 
},
{
"time": "2018-12-20 12:58:45.865634",
"event": "forwarded" 
}
],
"info": {
"seq": 42018643,
"src_is_mon": false,
"source": "mds.0 10.120.3.182:6800/1262182774",
"forwarded_to_leader": true
}
}
},
{
"description": "log(1 entries from seq 3165745 at 2019-01-03 09:52:20.050649)",
"initiated_at": "2019-01-03 09:52:20.050685",
"age": 0.545710,
"duration": 0.546115,
"type_data": {
"events": [
{
"time": "2019-01-03 09:52:20.050685",
"event": "initiated" 
},
{
"time": "2019-01-03 09:52:20.050685",
"event": "header_read" 
},
{
"time": "0.000000",
"event": "throttled" 
},
{
"time": "0.000000",
"event": "all_read" 
},
{
"time": "2019-01-03 09:52:20.050901",
"event": "dispatched" 
},
{
"time": "2019-01-03 09:52:20.050905",
"event": "mon:_ms_dispatch" 
},
{
"time": "2019-01-03 09:52:20.050905",
"event": "mon:dispatch_op" 
},
{
"time": "2019-01-03 09:52:20.050906",
"event": "psvc:dispatch" 
},
{
"time": "2019-01-03 09:52:20.050923",
"event": "logm:preprocess_query" 
},
{
"time": "2019-01-03 09:52:20.050925",
"event": "logm:preprocess_log" 
},
{
"time": "2019-01-03 09:52:20.050928",
"event": "forward_request_leader" 
},
{
"time": "2019-01-03 09:52:20.050995",
"event": "forwarded" 
}
],
"info": {
"seq": 62102811,
"src_is_mon": true,
"source": "mon.2 10.120.3.182:6789/0",
"forwarded_to_leader": true
}
}
}
],
"num_ops": 4
}