- ceph-users - lists.ceph.io

rbd snap create now working and just hangs forever
by Boris Behrens 22 Apr '21

22 Apr '21

Hi, I have a customer VM that is running fine, but I can not make snapshots anymore. rbd snap create rbd/IMAGE@test-bb-1 just hangs forever. When I checked the status with rbd status rbd/IMAGE it shows one watcher, the cpu node where the VM is running. What can I do to investigate further, without restarting the VM. This is the only affected VM and it stopped working three days ago.

2 5

Re: monclient(hunting): handle_auth_bad_method server allowed_methods [2] but i only support [2]
by Ilya Dryomov 22 Apr '21

22 Apr '21

On Thu, Apr 22, 2021 at 6:01 PM Cem Zafer <cemzafer(a)gmail.com> wrote: > > Thanks Ilya, pointing me out to the right direction. > So if I change the auth_allow_insecure_global_id_reclaim to true means older userspace clients allowed to the cluster? Yes, but upgrading all clients and setting it to false is recommended. Thanks, Ilya

1 0

Re: monclient(hunting): handle_auth_bad_method server allowed_methods [2] but i only support [2]
by Ilya Dryomov 22 Apr '21

22 Apr '21

On Thu, Apr 22, 2021 at 5:04 PM Cem Zafer <cemzafer(a)gmail.com> wrote: > > Hi Ilya, > Yes you are correct, I have set auth_allow_insecure_global_id_reclaim to false. > Host ceph-common package version is 16.2.0 and the cluster ceph -v output is as follows. > > root@ceph100:~# ceph -v > ceph version 16.2.1 (afb9061ab4117f798c858c741efa6390e48ccf10) pacific (stable) > Regards. Right, so because you set auth_allow_insecure_global_id_reclaim to false, older userspace clients, in this case 16.2.0, are not allowed to connect because they won't reclaim their global_id in a secure fashion. See https://docs.ceph.com/en/latest/security/CVE-2021-20288/ for details. Thanks, Ilya > > On Thu, Apr 22, 2021 at 4:49 PM Ilya Dryomov <idryomov(a)gmail.com> wrote: >> >> On Thu, Apr 22, 2021 at 3:24 PM Cem Zafer <cemzafer(a)gmail.com> wrote: >> > >> > Hi, >> > I have recently add a new host to ceph and copied /etc/ceph directory to >> > the new host. When I execute the simple ceph command as "ceph -s", get the >> > following error. >> > >> > 021-04-22T14:50:46.226+0300 7ff541141700 -1 monclient(hunting): >> > handle_auth_bad_method server allowed_methods [2] but i only support [2] >> > 2021-04-22T14:50:46.226+0300 7ff540940700 -1 monclient(hunting): >> > handle_auth_bad_method server allowed_methods [2] but i only support [2] >> > 2021-04-22T14:50:46.226+0300 7ff533fff700 -1 monclient(hunting): >> > handle_auth_bad_method server allowed_methods [2] but i only support [2] >> > [errno 13] RADOS permission denied (error connecting to the cluster) >> > >> > When I looked at the syslog on the ceph cluster node, I saw that message >> > too. >> > >> > Apr 22 14:51:40 ceph100 bash[27979]: debug 2021-04-22T11:51:40.684+0000 >> > 7fe4d28cb700 0 cephx server client.admin: attempt to reclaim global_id >> > 264198 without presenting ticket >> > Apr 22 14:51:40 ceph100 bash[27979]: debug 2021-04-22T11:51:40.684+0000 >> > 7fe4d28cb700 0 cephx server client.admin: could not verify old ticket >> > >> > Anyone can help me out or assist to the right direction or link? >> >> Hi Cem, >> >> I take it that you upgraded to one of 14.2.20, 15.2.11 or 16.2.1 >> releases and then set auth_allow_insecure_global_id_reclaim to false? >> >> What version of ceph-common package is installed on that host? What is >> the output of "ceph -v"? >> >> Thanks, >> >> Ilya

1 0

monclient(hunting): handle_auth_bad_method server allowed_methods [2] but i only support [2]
by Cem Zafer 22 Apr '21

22 Apr '21

Hi, I have recently add a new host to ceph and copied /etc/ceph directory to the new host. When I execute the simple ceph command as "ceph -s", get the following error. 021-04-22T14:50:46.226+0300 7ff541141700 -1 monclient(hunting): handle_auth_bad_method server allowed_methods [2] but i only support [2] 2021-04-22T14:50:46.226+0300 7ff540940700 -1 monclient(hunting): handle_auth_bad_method server allowed_methods [2] but i only support [2] 2021-04-22T14:50:46.226+0300 7ff533fff700 -1 monclient(hunting): handle_auth_bad_method server allowed_methods [2] but i only support [2] [errno 13] RADOS permission denied (error connecting to the cluster) When I looked at the syslog on the ceph cluster node, I saw that message too. Apr 22 14:51:40 ceph100 bash[27979]: debug 2021-04-22T11:51:40.684+0000 7fe4d28cb700 0 cephx server client.admin: attempt to reclaim global_id 264198 without presenting ticket Apr 22 14:51:40 ceph100 bash[27979]: debug 2021-04-22T11:51:40.684+0000 7fe4d28cb700 0 cephx server client.admin: could not verify old ticket Anyone can help me out or assist to the right direction or link? Regards.

2 1

Download-Mirror eu.ceph.com misses Debian Release file
by Robert Sander 22 Apr '21

22 Apr '21

Hi, to whomever it may concern: The mirror server eu.ceph.com does to carry the Release files for 15.2.11 in https://eu.ceph.com/debian-15.2.11/dists/*/ and 16.2.1 in https://eu.ceph.com/debian-16.2.1/dists/*/ Regards -- Robert Sander Heinlein Consulting GmbH Schwedter Str. 8/9b, 10119 Berlin http://www.heinlein-support.de Tel: 030 / 405051-43 Fax: 030 / 405051-19 Zwangsangaben lt. §35a GmbHG: HRB 93818 B / Amtsgericht Berlin-Charlottenburg, Geschäftsführer: Peer Heinlein -- Sitz: Berlin

1 0

After upgrade to 15.2.11 no access to cluster any more
by Robert Sander 22 Apr '21

22 Apr '21

Hi, I upgraded a test cluster to 15.2.11 and after the upgrade has been finished the cluster status was in HEALTH_WARN because of: AUTH_INSECURE_GLOBAL_ID_RECLAIM_ALLOWED: mons are allowing insecure global_id reclaim According to the documentation at https://docs.ceph.com/en/octopus/rados/operations/health-checks/#auth-insec… I ran ceph config set mon auth_allow_insecure_global_id_reclaim false because no client was reporting using insecure global_ids. Now "ceph -s" cannot connect to the cluster any more: # ceph -s [errno 13] RADOS permission denied (error connecting to the cluster) What should I do? Regards -- Robert Sander Heinlein Consulting GmbH Schwedter Str. 8/9b, 10119 Berlin http://www.heinlein-support.de Tel: 030 / 405051-43 Fax: 030 / 405051-19 Zwangsangaben lt. §35a GmbHG: HRB 93818 B / Amtsgericht Berlin-Charlottenburg, Geschäftsführer: Peer Heinlein -- Sitz: Berlin

2 2

_delete_some new onodes has appeared since PG removal started
by Dan van der Ster 21 Apr '21

21 Apr '21

Hi Igor, After updating to 14.2.19 and then moving some PGs around we have a few warnings related to the new efficient PG removal code, e.g. [1]. Is that something to worry about? Best Regards, Dan [1] /var/log/ceph/ceph-osd.792.log:2021-04-14 20:34:34.353 7fb2439d4700 0 osd.792 pg_epoch: 40906 pg[10.14b2s0( v 40734'290069 (33782'287000,40734'290069] lb MIN (bitwise) local-lis/les=33990/33991 n=36272 ec=4951/4937 lis/c 33990/33716 les/c/f 33991/33747/0 40813/40813/37166) [933,626,260,804,503,491]p933(0) r=-1 lpr=40813 DELETING pi=[33716,40813)/4 crt=40734'290069 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[0#10:4d280000::::head#] /var/log/ceph/ceph-osd.851.log:2021-04-14 18:40:13.312 7fd87bded700 0 osd.851 pg_epoch: 40671 pg[10.133fs5( v 40662'288967 (33782'285900,40662'288967] lb MIN (bitwise) local-lis/les=33786/33787 n=13 ec=4947/4937 lis/c 40498/33714 les/c/f 40499/33747/0 40670/40670/33432) [859,199,913,329,439,79]p859(0) r=-1 lpr=40670 DELETING pi=[33714,40670)/4 crt=40662'288967 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[5#10:fcc80000::::head#] /var/log/ceph/ceph-osd.851.log:2021-04-14 20:58:14.393 7fd87adeb700 0 osd.851 pg_epoch: 40906 pg[10.2e8s3( v 40610'288991 (33782'285900,40610'288991] lb MIN (bitwise) local-lis/les=33786/33787 n=161220 ec=4937/4937 lis/c 39826/33716 les/c/f 39827/33747/0 40617/40617/39225) [717,933,727,792,607,129]p717(0) r=-1 lpr=40617 DELETING pi=[33716,40617)/3 crt=40610'288991 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[3#10:17400000::::head#] /var/log/ceph/ceph-osd.883.log:2021-04-14 18:55:16.822 7f78c485d700 0 osd.883 pg_epoch: 40857 pg[7.d4( v 40804'9911289 (35835'9908201,40804'9911289] lb MIN (bitwise) local-lis/les=40782/40783 n=195 ec=2063/1989 lis/c 40782/40782 les/c/f 40783/40844/0 40781/40845/40845) [877,870,894] r=-1 lpr=40845 DELETING pi=[40782,40845)/1 crt=40804'9911289 lcod 40804'9911288 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[#7:2b000000::::head#]

4 13

EC Backfill Observations
by Josh Baergen 21 Apr '21

21 Apr '21

Hey all, I wanted to confirm my understanding of some of the mechanics of backfill in EC pools. I've yet to find a document that outlines this in detail; if there is one, please send it my way. :) Some of what I write below is likely in the "well, duh" category, but I tended towards completeness. First off, I understand that backfill reservations work the same way between replicated pools and EC pools. A local reservation is taken on the primary OSD, then a remote reservation on the backfill target(s), before the backfill is allowed to begin. Until this point, the backfill is in the backfill_wait state. When the backfill begins, though, is when the differences begin. Let's say we have an EC 3:2 PG that's backfilling from OSD 2 to OSD 5 (formatted here like pgs_brief): 1.1 active+remapped+backfilling [0,1,5,3,4] 0 [0,1,2,3,4] 0 The question in my mind was: Where is the data for this backfill coming from? In replicated pools, all reads come from the primary. However, in this case, the primary does not have the data in question; the primary has to either read the EC chunk from OSD 2, or it has to reconstruct it by reading from 3 of the OSDs in the acting set. Based on observation, I _think_ this is what happens: 1. As long as the PG is not degraded, the backfill read is simply forwarded by the primary to OSD 2. 2. Once the PG becomes degraded, the backfill read needs to use the reconstructing path, and begins reading from 3 of the OSDs in the acting set. Questions: 1. Can anyone confirm or correct my description of how EC backfill operates? In particular, in case 2 above, does it matter whether OSD 2 is the cause of degradation, for example? Does the read still get forwarded to a single OSD when it's parity chunks that are being moved via backfill? 2. I'm curious as to why a 3rd reservation, for the source OSD, wasn't introduced as a part of EC in Ceph. We've occasionally seen an OSD become overloaded because several backfills were reading from it simultaneously, and there's no way to control this via the normal osd_max_backfills mechanism. Is anyone aware of discussions to this effect? Thanks! Josh

2 4

MDS_TRIM 1 MDSs behind on trimming and
by Flemming Frandsen 21 Apr '21

21 Apr '21

I've just spent a couple of hours waiting for an MDS server to replay a journal that it was behind on and it seems to be getting worse. The system is not terribly busy, but there are 14 ops in flight that are very old and do not seem to go away on their own. Is there anything I can do to unwedge the mds server? root@dalmore:~# ceph health detail HEALTH_WARN 1 MDSs report slow metadata IOs; 1 MDSs report slow requests; 1 MDSs behind on trimming MDS_SLOW_METADATA_IO 1 MDSs report slow metadata IOs mds.dalmore(mds.0): 1 slow metadata IOs are blocked > 30 secs, oldest blocked for 4107 secs MDS_SLOW_REQUEST 1 MDSs report slow requests mds.dalmore(mds.0): 14 slow requests are blocked > 30 secs MDS_TRIM 1 MDSs behind on trimming mds.dalmore(mds.0): Behind on trimming (3443/128) max_segments: 128, num_segments: 3443 root@dalmore:~# ceph daemon mds.dalmore dump_ops_in_flight { "ops": [ { "description": "client_request(client.9801215:348401522 readdir #0x2001fba1c83 2021-04-21 15:46:30.820531 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:46:30.822084", "age": 4020.3439449050002, "duration": 4020.343998116, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348401522", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348401522 }, "events": [ { "time": "2021-04-21 15:46:30.822084", "event": "initiated" }, { "time": "2021-04-21 15:46:30.822084", "event": "header_read" }, { "time": "2021-04-21 15:46:30.822090", "event": "throttled" }, { "time": "2021-04-21 15:46:30.822108", "event": "all_read" }, { "time": "2021-04-21 15:46:30.966336", "event": "dispatched" }, { "time": "2021-04-21 15:46:30.966419", "event": "acquired locks" }, { "time": "2021-04-21 16:01:40.084378", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084438", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9801215:348454506 setfilelock rule 1, type 4, owner 14336643358275911908, pid 32085, start 0, length 0, wait 0 #0x1001e694623 20 21-04-21 15:55:50.829175 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:55:50.832432", "age": 3460.3335972099999, "duration": 3460.333751787, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348454506", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348454506 }, "events": [ { "time": "2021-04-21 15:55:50.832432", "event": "initiated" }, { "time": "2021-04-21 15:55:50.832432", "event": "header_read" }, { "time": "2021-04-21 15:55:50.832439", "event": "throttled" }, { "time": "2021-04-21 15:55:50.832465", "event": "all_read" }, { "time": "2021-04-21 15:55:50.832608", "event": "dispatched" }, { "time": "2021-04-21 16:01:40.084448", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084451", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9143865:2383945773 getattr pAsLsXsFs #0x10004f6a16b 2021-04-21 16:35:30.075110 caller_uid=0, caller_gid=0{})", "initiated_at": "2021-04-21 16:35:30.077995", "age": 1081.0880337159999, "duration": 1081.0882681850001, "type_data": { "flag_point": "failed to authpin, subtree is being exported", "reqid": "client.9143865:2383945773", "op_type": "client_request", "client_info": { "client": "client.9143865", "tid": 2383945773 }, "events": [ { "time": "2021-04-21 16:35:30.077995", "event": "initiated" }, { "time": "2021-04-21 16:35:30.077995", "event": "header_read" }, { "time": "2021-04-21 16:35:30.077999", "event": "throttled" }, { "time": "2021-04-21 16:35:30.078018", "event": "all_read" }, { "time": "2021-04-21 16:35:30.078091", "event": "dispatched" }, { "time": "2021-04-21 16:35:30.078156", "event": "failed to authpin, subtree is being exported" } ] } }, { "description": "client_request(client.9801215:348417261 lookup #0x10004cd0675/tasks 2021-04-21 15:49:09.248696 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:49:09.252834", "age": 3861.9131950870001, "duration": 3861.9135065690002, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348417261", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348417261 }, "events": [ { "time": "2021-04-21 15:49:09.252834", "event": "initiated" }, { "time": "2021-04-21 15:49:09.252834", "event": "header_read" }, { "time": "2021-04-21 15:49:09.252839", "event": "throttled" }, { "time": "2021-04-21 15:49:09.252856", "event": "all_read" }, { "time": "2021-04-21 15:49:09.252982", "event": "dispatched" }, { "time": "2021-04-21 15:49:09.253070", "event": "failed to authpin, subtree is being exported" }, { "time": "2021-04-21 16:01:40.084439", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084444", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9143865:2383945793 getattr pAsLsXsFs #0x10004f6a16b 2021-04-21 16:40:33.868658 caller_uid=0, caller_gid=0{})", "initiated_at": "2021-04-21 16:40:33.871565", "age": 777.29446343799998, "duration": 777.29486169500001, "type_data": { "flag_point": "failed to authpin, subtree is being exported", "reqid": "client.9143865:2383945793", "op_type": "client_request", "client_info": { "client": "client.9143865", "tid": 2383945793 }, "events": [ { "time": "2021-04-21 16:40:33.871565", "event": "initiated" }, { "time": "2021-04-21 16:40:33.871565", "event": "header_read" }, { "time": "2021-04-21 16:40:33.871572", "event": "throttled" }, { "time": "2021-04-21 16:40:33.871617", "event": "all_read" }, { "time": "2021-04-21 16:40:33.871699", "event": "dispatched" }, { "time": "2021-04-21 16:40:33.871909", "event": "failed to authpin, subtree is being exported" } ] } }, { "description": "client_request(client.9801215:348424659 lookup #0x10004cd0675/slaves 2021-04-21 15:50:01.592755 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:50:01.595195", "age": 3809.5708340870001, "duration": 3809.5713271260001, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348424659", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348424659 }, "events": [ { "time": "2021-04-21 15:50:01.595195", "event": "initiated" }, { "time": "2021-04-21 15:50:01.595195", "event": "header_read" }, { "time": "2021-04-21 15:50:01.595198", "event": "throttled" }, { "time": "2021-04-21 15:50:01.595210", "event": "all_read" }, { "time": "2021-04-21 15:50:01.595307", "event": "dispatched" }, { "time": "2021-04-21 15:50:01.595389", "event": "failed to authpin, subtree is being exported" }, { "time": "2021-04-21 16:01:40.084444", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084448", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9801215:348456034 setfilelock rule 1, type 4, owner 14336643483181153700, pid 32085, start 0, length 0, wait 0 #0x1001e694623 20 21-04-21 15:56:20.849213 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:56:20.851803", "age": 3430.3142257680001, "duration": 3430.3148090620002, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348456034", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348456034 }, "events": [ { "time": "2021-04-21 15:56:20.851803", "event": "initiated" }, { "time": "2021-04-21 15:56:20.851803", "event": "header_read" }, { "time": "2021-04-21 15:56:20.851815", "event": "throttled" }, { "time": "2021-04-21 15:56:20.851853", "event": "all_read" }, { "time": "2021-04-21 15:56:20.851983", "event": "dispatched" }, { "time": "2021-04-21 16:01:40.084452", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084454", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9801215:348456035 lookup #0x10004cd0675/tasks 2021-04-21 15:56:20.849213 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:56:20.851899", "age": 3430.314129722, "duration": 3430.3147965909998, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348456035", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348456035 }, "events": [ { "time": "2021-04-21 15:56:20.851899", "event": "initiated" }, { "time": "2021-04-21 15:56:20.851899", "event": "header_read" }, { "time": "2021-04-21 15:56:20.851900", "event": "throttled" }, { "time": "2021-04-21 15:56:20.851908", "event": "all_read" }, { "time": "2021-04-21 15:56:20.852165", "event": "dispatched" }, { "time": "2021-04-21 15:56:20.852254", "event": "failed to authpin, subtree is being exported" }, { "time": "2021-04-21 16:01:40.084455", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084457", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9801215:348456036 lookup #0x10004cd0675/slaves 2021-04-21 15:56:20.849213 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:56:20.879287", "age": 3430.2867415639998, "duration": 3430.287496596, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348456036", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348456036 }, "events": [ { "time": "2021-04-21 15:56:20.879287", "event": "initiated" }, { "time": "2021-04-21 15:56:20.879287", "event": "header_read" }, { "time": "2021-04-21 15:56:20.879292", "event": "throttled" }, { "time": "2021-04-21 15:56:20.879306", "event": "all_read" }, { "time": "2021-04-21 15:56:20.879408", "event": "dispatched" }, { "time": "2021-04-21 15:56:20.879502", "event": "failed to authpin, subtree is being exported" }, { "time": "2021-04-21 16:01:40.084458", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084460", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9801215:348456042 lookup #0x10004cd0675/jul 2021-04-21 15:58:53.729411 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:58:53.740318", "age": 3277.4257106780001, "duration": 3277.4265688219998, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348456042", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348456042 }, "events": [ { "time": "2021-04-21 15:58:53.740318", "event": "initiated" }, { "time": "2021-04-21 15:58:53.740318", "event": "header_read" }, { "time": "2021-04-21 15:58:53.740324", "event": "throttled" }, { "time": "2021-04-21 15:58:53.740345", "event": "all_read" }, { "time": "2021-04-21 15:58:53.743424", "event": "dispatched" }, { "time": "2021-04-21 15:58:53.750527", "event": "failed to authpin, subtree is being exported" }, { "time": "2021-04-21 16:01:40.084465", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084468", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9143865:2383914038 getattr pAsLsXsFs #0x10004f6a16b 2021-04-21 16:29:35.332632 caller_uid=903, caller_gid=1003{})", "initiated_at": "2021-04-21 16:29:35.333838", "age": 1435.8321910940001, "duration": 1435.833136707, "type_data": { "flag_point": "failed to authpin, subtree is being exported", "reqid": "client.9143865:2383914038", "op_type": "client_request", "client_info": { "client": "client.9143865", "tid": 2383914038 }, "events": [ { "time": "2021-04-21 16:29:35.333838", "event": "initiated" }, { "time": "2021-04-21 16:29:35.333838", "event": "header_read" }, { "time": "2021-04-21 16:29:35.333841", "event": "throttled" }, { "time": "2021-04-21 16:29:35.333854", "event": "all_read" }, { "time": "2021-04-21 16:29:35.335013", "event": "dispatched" }, { "time": "2021-04-21 16:29:35.335091", "event": "failed to authpin, subtree is being exported" } ] } }, { "description": "client_request(client.10439445:7 lookup #0x10004cd0675/jul 2021-04-21 16:26:17.334272 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 16:26:17.352448", "age": 1633.813581226, "duration": 1633.8146036109999, "type_data": { "flag_point": "cleaned up request", "reqid": "client.10439445:7", "op_type": "client_request", "client_info": { "client": "client.10439445", "tid": 7 }, "events": [ { "time": "2021-04-21 16:26:17.352448", "event": "initiated" }, { "time": "2021-04-21 16:26:17.352448", "event": "header_read" }, { "time": "2021-04-21 16:26:17.352450", "event": "throttled" }, { "time": "2021-04-21 16:26:17.352460", "event": "all_read" }, { "time": "2021-04-21 16:26:17.356901", "event": "dispatched" }, { "time": "2021-04-21 16:26:17.357337", "event": "failed to authpin, subtree is being exported" }, { "time": "2021-04-21 16:38:08.054109", "event": "killing request" }, { "time": "2021-04-21 16:38:08.054120", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9801215:348456041 lookup #0x10004cd0675/jul 2021-04-21 15:56:23.089216 caller_uid=1000, caller_gid=1000{})", "initiated_at": "2021-04-21 15:56:23.091531", "age": 3428.0744974170002, "duration": 3428.0756079930002, "type_data": { "flag_point": "cleaned up request", "reqid": "client.9801215:348456041", "op_type": "client_request", "client_info": { "client": "client.9801215", "tid": 348456041 }, "events": [ { "time": "2021-04-21 15:56:23.091531", "event": "initiated" }, { "time": "2021-04-21 15:56:23.091531", "event": "header_read" }, { "time": "2021-04-21 15:56:23.091536", "event": "throttled" }, { "time": "2021-04-21 15:56:23.091555", "event": "all_read" }, { "time": "2021-04-21 15:56:23.091660", "event": "dispatched" }, { "time": "2021-04-21 15:56:23.091763", "event": "failed to authpin, subtree is being exported" }, { "time": "2021-04-21 16:01:40.084461", "event": "killing request" }, { "time": "2021-04-21 16:01:40.084465", "event": "cleaned up request" } ] } }, { "description": "client_request(client.9143865:2383885743 getattr pAsLsXsFs #0x10004f6a16b 2021-04-21 16:26:36.713371 caller_uid=903, caller_gid=1003{})", "initiated_at": "2021-04-21 16:26:36.716418", "age": 1614.4496113350001, "duration": 1614.4508114350001, "type_data": { "flag_point": "failed to authpin, subtree is being exported", "reqid": "client.9143865:2383885743", "op_type": "client_request", "client_info": { "client": "client.9143865", "tid": 2383885743 }, "events": [ { "time": "2021-04-21 16:26:36.716418", "event": "initiated" }, { "time": "2021-04-21 16:26:36.716418", "event": "header_read" }, { "time": "2021-04-21 16:26:36.716421", "event": "throttled" }, { "time": "2021-04-21 16:26:36.716435", "event": "all_read" }, { "time": "2021-04-21 16:26:36.716526", "event": "dispatched" }, { "time": "2021-04-21 16:26:36.716632", "event": "failed to authpin, subtree is being exported" } ] } } ], "num_ops": 14 } -- Flemming Frandsen - YAPH - http://osaa.dk - http://dren.dk/

2 7

osd nearfull is not detected
by Konstantin Shalygin 21 Apr '21

21 Apr '21

Hi, On the adopted cluster Prometheus was triggered for "osd full > 90%" But Ceph itself - not. Actually OSD is drained (see %USE). root@host# ceph osd df name osd.696 ID CLASS WEIGHT REWEIGHT SIZE RAW USE DATA OMAP META AVAIL %USE VAR PGS STATUS 696 nvme 0.91199 1.00000 912 GiB 830 GiB 684 GiB 8 KiB 146 GiB 81 GiB 91.09 1.00 47 up TOTAL 912 GiB 830 GiB 684 GiB 8.1 KiB 146 GiB 81 GiB 91.09 MIN/MAX VAR: 1.00/1.00 STDDEV: 0 root@host# ceph osd df name osd.696 ID CLASS WEIGHT REWEIGHT SIZE RAW USE DATA OMAP META AVAIL %USE VAR PGS STATUS 696 nvme 0.91199 1.00000 912 GiB 830 GiB 684 GiB 8 KiB 146 GiB 81 GiB 91.08 1.00 47 up TOTAL 912 GiB 830 GiB 684 GiB 8.1 KiB 146 GiB 81 GiB 91.08 MIN/MAX VAR: 1.00/1.00 STDDEV: 0 root@host# ceph osd df name osd.696 ID CLASS WEIGHT REWEIGHT SIZE RAW USE DATA OMAP META AVAIL %USE VAR PGS STATUS 696 nvme 0.91199 1.00000 912 GiB 830 GiB 684 GiB 8 KiB 146 GiB 81 GiB 91.07 1.00 47 up TOTAL 912 GiB 830 GiB 684 GiB 8.1 KiB 146 GiB 81 GiB 91.07 MIN/MAX VAR: 1.00/1.00 STDDEV: 0 Pool 18 is another class pool, OSD's of this pool triggered as usual, but for pool 17 - don't. root@host# ceph health detail HEALTH_WARN noout flag(s) set; Some pool(s) have the nodeep-scrub flag(s) set; Low space hindering backfill (add storage if this doesn't resolve itself): 2 pgs backfill_toofull OSDMAP_FLAGS noout flag(s) set POOL_SCRUB_FLAGS Some pool(s) have the nodeep-scrub flag(s) set Pool meta_ru1b has nodeep-scrub flag Pool data_ru1b has nodeep-scrub flag PG_BACKFILL_FULL Low space hindering backfill (add storage if this doesn't resolve itself): 2 pgs backfill_toofull pg 18.1008 is active+remapped+backfill_wait+backfill_toofull, acting [336,462,580] pg 18.27e0 is active+remapped+backfill_wait+backfill_toofull, acting [401,627,210] On my experience , Ceph triggers when OSD drain on backfillfull_ratio, then on nearfull_ratio until usage will drops to 84.99% I don't think is to possible to configure silence for this Current usage: root@host# ceph df detail RAW STORAGE: CLASS SIZE AVAIL USED RAW USED %RAW USED hdd 4.3 PiB 1022 TiB 3.3 PiB 3.3 PiB 76.71 nvme 161 TiB 61 TiB 82 TiB 100 TiB 62.30 TOTAL 4.4 PiB 1.1 PiB 3.4 PiB 3.4 PiB 76.20 POOLS: POOL ID PGS STORED OBJECTS USED %USED MAX AVAIL QUOTA OBJECTS QUOTA BYTES DIRTY USED COMPR UNDER COMPR meta_ru1b 17 2048 3.1 TiB 7.15G 82 TiB 92.77 2.1 TiB N/A N/A 7.15G 0 B 0 B data_ru1b 18 16384 1.1 PiB 3.07G 3.3 PiB 88.29 148 TiB N/A N/A 3.07G 0 B 0 B Current OSD dump header: epoch 270540 fsid ccf2c233-4adf-423c-b734-236220096d4e created 2019-02-14 15:30:56.642918 modified 2021-04-21 20:33:54.481616 flags noout,sortbitwise,recovery_deletes,purged_snapdirs,pglog_hardlimit crush_version 7255 full_ratio 0.95 backfillfull_ratio 0.9 nearfull_ratio 0.85 require_min_compat_client jewel min_compat_client jewel require_osd_release nautilus pool 17 'meta_ru1b' replicated size 3 min_size 2 crush_rule 1 object_hash rjenkins pg_num 2048 pgp_num 2048 autoscale_mode warn last_change 240836 lfor 0/0/51990 flags hashpspool,nodeep-scrub stripe_width 0 application metadata pool 18 'data_ru1b' replicated size 3 min_size 2 crush_rule 0 object_hash rjenkins pg_num 16384 pgp_num 16384 autoscale_mode warn last_change 270529 lfor 0/0/52038 flags hashpspool,nodeep-scrub stripe_width 0 application data max_osd 780 Current versions: { "mon": { "ceph version 14.2.19 (bb796b9b5bab9463106022eef406373182465d11) nautilus (stable)": 3 }, "mgr": { "ceph version 14.2.19 (bb796b9b5bab9463106022eef406373182465d11) nautilus (stable)": 3 }, "osd": { "ceph version 14.2.19 (bb796b9b5bab9463106022eef406373182465d11) nautilus (stable)": 780 }, "mds": {}, "overall": { "ceph version 14.2.19 (bb796b9b5bab9463106022eef406373182465d11) nautilus (stable)": 786 } } Dan, maybe there was something like that in your memory? My guess is that some counter type overflowed Thanks, k

2 2