_delete_some new onodes has appeared since PG removal started
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#]
Hi Dan, Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch. The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal. New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening.... Thanks, Igor On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
We saw this warning once in testing (https://tracker.ceph.com/issues/49900#note-1), but there, the problem was different, which also led to a crash. That issue has been fixed but if you can provide osd logs with verbose logging, we might be able to investigate further. Neha On Wed, Apr 14, 2021 at 4:14 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch.
The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal.
New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening....
Thanks,
Igor
On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Thanks Igor and Neha for the quick responses. I posted an osd log with debug_osd 10 and debug_bluestore 20: ceph-post-file: 09094430-abdb-4248-812c-47b7babae06c Hope that helps, Dan On Thu, Apr 15, 2021 at 1:27 AM Neha Ojha <nojha@redhat.com> wrote:
We saw this warning once in testing (https://tracker.ceph.com/issues/49900#note-1), but there, the problem was different, which also led to a crash. That issue has been fixed but if you can provide osd logs with verbose logging, we might be able to investigate further.
Neha
On Wed, Apr 14, 2021 at 4:14 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch.
The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal.
New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening....
Thanks,
Igor
On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Do we have a tracker for this? We should ideally be able to remove that final collection_list from the optimized pg removal. It can take a really long time and lead to osd flapping: 2021-04-21 15:23:37.003 7f51c273c700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:41.595 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _collection_list, latency = 67.7234s, lat = 67s cid =10.14aes4_head start GHMAX end GHMAX max 30 2021-04-21 15:23:41.595 7f51a3e81700 0 osd.941 pg_epoch: 43004 pg[10.14aes4( v 42754'296580 (40999'293500,42754'296580] lb MIN (bitwise) local-lis/les=41331/41332 n=159058 ec=4951/4937 lis/c 41331/41331 les/c/f 41332/42758/0 41330/42759/33461) [171,903,106,27,395,773]p171(0) r=-1 lpr=42759 DELETING pi=[41331,42759)/1 crt=42754'296580 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[4#10:75280000::::head#] 2021-04-21 15:23:50.061 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency slow operation observed for submit_transact, latency = 8.46584s 2021-04-21 15:23:50.062 7f51a3e81700 1 heartbeat_map reset_timeout 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:50.115 7f51b6ca1700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _txc_committed_kv, latency = 8.51916s, txc = 0x5573928a7340 2021-04-21 15:23:50.473 7f51b2498700 0 log_channel(cluster) log [WRN] : Monitor daemon marked osd.941 down, but it is still running -- dan On Thu, Apr 15, 2021 at 10:32 AM Dan van der Ster <dan@vanderster.com> wrote:
Thanks Igor and Neha for the quick responses.
I posted an osd log with debug_osd 10 and debug_bluestore 20: ceph-post-file: 09094430-abdb-4248-812c-47b7babae06c
Hope that helps,
Dan
On Thu, Apr 15, 2021 at 1:27 AM Neha Ojha <nojha@redhat.com> wrote:
We saw this warning once in testing (https://tracker.ceph.com/issues/49900#note-1), but there, the problem was different, which also led to a crash. That issue has been fixed but if you can provide osd logs with verbose logging, we might be able to investigate further.
Neha
On Wed, Apr 14, 2021 at 4:14 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch.
The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal.
New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening....
Thanks,
Igor
On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Dan, you about this issue [1] ? I was start to backfill new OSD's on 14.2.19: pool have 2048PG with 7.14G objects... avg number of PG is 3486328 objects [1] https://tracker.ceph.com/issues/47044 <https://tracker.ceph.com/issues/47044> k
On 21 Apr 2021, at 16:37, Dan van der Ster <dan@vanderster.com> wrote:
Do we have a tracker for this?
We should ideally be able to remove that final collection_list from the optimized pg removal. It can take a really long time and lead to osd flapping:
2021-04-21 15:23:37.003 7f51c273c700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:41.595 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _collection_list, latency = 67.7234s, lat = 67s cid =10.14aes4_head start GHMAX end GHMAX max 30 2021-04-21 15:23:41.595 7f51a3e81700 0 osd.941 pg_epoch: 43004 pg[10.14aes4( v 42754'296580 (40999'293500,42754'296580] lb MIN (bitwise) local-lis/les=41331/41332 n=159058 ec=4951/4937 lis/c 41331/41331 les/c/f 41332/42758/0 41330/42759/33461) [171,903,106,27,395,773]p171(0) r=-1 lpr=42759 DELETING pi=[41331,42759)/1 crt=42754'296580 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[4#10:75280000::::head#] 2021-04-21 15:23:50.061 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency slow operation observed for submit_transact, latency = 8.46584s 2021-04-21 15:23:50.062 7f51a3e81700 1 heartbeat_map reset_timeout 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:50.115 7f51b6ca1700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _txc_committed_kv, latency = 8.51916s, txc = 0x5573928a7340 2021-04-21 15:23:50.473 7f51b2498700 0 log_channel(cluster) log [WRN] : Monitor daemon marked osd.941 down, but it is still running
-- dan
On Thu, Apr 15, 2021 at 10:32 AM Dan van der Ster <dan@vanderster.com> wrote:
Thanks Igor and Neha for the quick responses.
I posted an osd log with debug_osd 10 and debug_bluestore 20: ceph-post-file: 09094430-abdb-4248-812c-47b7babae06c
Hope that helps,
Dan
On Thu, Apr 15, 2021 at 1:27 AM Neha Ojha <nojha@redhat.com> wrote:
We saw this warning once in testing (https://tracker.ceph.com/issues/49900#note-1), but there, the problem was different, which also led to a crash. That issue has been fixed but if you can provide osd logs with verbose logging, we might be able to investigate further.
Neha
On Wed, Apr 14, 2021 at 4:14 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch.
The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal.
New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening....
Thanks,
Igor
On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Yes, with the fixes in 14.2.19 PG removal is really much much much better than before. But on some clusters (in particular with rocksdb on the hdd) there is still a rare osd flap at the end of the PG removal -- indicated by the logs I shared earlier. Our workaround to prevent that new flap is to increase osd_heartbeat_grace (e.g. to 45). With 3.5M objects in a PG, I suggest that you try moving one PG with upmap and watch how it goes (especially at the end). -- dan On Wed, Apr 21, 2021 at 4:01 PM Konstantin Shalygin <k0ste@k0ste.ru> wrote:
Dan, you about this issue [1] ?
I was start to backfill new OSD's on 14.2.19: pool have 2048PG with 7.14G objects... avg number of PG is 3486328 objects
[1] https://tracker.ceph.com/issues/47044
k
On 21 Apr 2021, at 16:37, Dan van der Ster <dan@vanderster.com> wrote:
Do we have a tracker for this?
We should ideally be able to remove that final collection_list from the optimized pg removal. It can take a really long time and lead to osd flapping:
2021-04-21 15:23:37.003 7f51c273c700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:41.595 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _collection_list, latency = 67.7234s, lat = 67s cid =10.14aes4_head start GHMAX end GHMAX max 30 2021-04-21 15:23:41.595 7f51a3e81700 0 osd.941 pg_epoch: 43004 pg[10.14aes4( v 42754'296580 (40999'293500,42754'296580] lb MIN (bitwise) local-lis/les=41331/41332 n=159058 ec=4951/4937 lis/c 41331/41331 les/c/f 41332/42758/0 41330/42759/33461) [171,903,106,27,395,773]p171(0) r=-1 lpr=42759 DELETING pi=[41331,42759)/1 crt=42754'296580 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[4#10:75280000::::head#] 2021-04-21 15:23:50.061 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency slow operation observed for submit_transact, latency = 8.46584s 2021-04-21 15:23:50.062 7f51a3e81700 1 heartbeat_map reset_timeout 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:50.115 7f51b6ca1700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _txc_committed_kv, latency = 8.51916s, txc = 0x5573928a7340 2021-04-21 15:23:50.473 7f51b2498700 0 log_channel(cluster) log [WRN] : Monitor daemon marked osd.941 down, but it is still running
-- dan
On Thu, Apr 15, 2021 at 10:32 AM Dan van der Ster <dan@vanderster.com> wrote:
Thanks Igor and Neha for the quick responses.
I posted an osd log with debug_osd 10 and debug_bluestore 20: ceph-post-file: 09094430-abdb-4248-812c-47b7babae06c
Hope that helps,
Dan
On Thu, Apr 15, 2021 at 1:27 AM Neha Ojha <nojha@redhat.com> wrote:
We saw this warning once in testing (https://tracker.ceph.com/issues/49900#note-1), but there, the problem was different, which also led to a crash. That issue has been fixed but if you can provide osd logs with verbose logging, we might be able to investigate further.
Neha
On Wed, Apr 14, 2021 at 4:14 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch.
The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal.
New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening....
Thanks,
Igor
On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Nope, umpap is currently impossible on this clusters 😬 due client lib (guys works on update now). ID CLASS WEIGHT REWEIGHT SIZE RAW USE DATA OMAP META AVAIL %USE VAR PGS STATUS TYPE NAME -166 10.94385 - 11 TiB 382 GiB 317 GiB 64 KiB 66 GiB 11 TiB 3.42 1.00 - host meta115 768 nvme 0.91199 1.00000 932 GiB 36 GiB 30 GiB 8 KiB 6.0 GiB 896 GiB 3.85 1.13 1 up osd.768 769 nvme 0.91199 1.00000 932 GiB 22 GiB 18 GiB 4 KiB 4.0 GiB 909 GiB 2.41 0.71 0 up osd.769 770 nvme 0.91199 1.00000 932 GiB 38 GiB 31 GiB 8 KiB 6.3 GiB 894 GiB 4.04 1.18 2 up osd.770 771 nvme 0.91199 1.00000 932 GiB 22 GiB 18 GiB 0 B 3.9 GiB 910 GiB 2.33 0.68 0 up osd.771 772 nvme 0.91199 1.00000 932 GiB 37 GiB 30 GiB 4 KiB 6.1 GiB 895 GiB 3.93 1.15 2 up osd.772 773 nvme 0.91199 1.00000 932 GiB 34 GiB 28 GiB 4 KiB 6.0 GiB 898 GiB 3.65 1.07 1 up osd.773 774 nvme 0.91199 1.00000 932 GiB 32 GiB 26 GiB 8 KiB 5.4 GiB 900 GiB 3.43 1.00 1 up osd.774 775 nvme 0.91199 1.00000 932 GiB 36 GiB 30 GiB 4 KiB 6.1 GiB 895 GiB 3.91 1.14 2 up osd.775 776 nvme 0.91199 1.00000 932 GiB 36 GiB 30 GiB 4 KiB 6.4 GiB 895 GiB 3.90 1.14 1 up osd.776 777 nvme 0.91199 1.00000 932 GiB 36 GiB 30 GiB 8 KiB 6.1 GiB 895 GiB 3.89 1.14 2 up osd.777 778 nvme 0.91199 1.00000 932 GiB 32 GiB 27 GiB 8 KiB 5.5 GiB 899 GiB 3.48 1.02 1 up osd.778 779 nvme 0.91199 1.00000 932 GiB 21 GiB 17 GiB 4 KiB 3.7 GiB 911 GiB 2.23 0.65 0 up osd.779 TOTAL 11 TiB 382 GiB 317 GiB 65 KiB 66 GiB 11 TiB 3.42 MIN/MAX VAR: 0.65/1.18 STDDEV: 0.66 Second PG landed... don't see any huge spikes on ceph_osd_op_latency metric. k
On 21 Apr 2021, at 17:12, Dan van der Ster <dan@vanderster.com> wrote:
Yes, with the fixes in 14.2.19 PG removal is really much much much better than before.
But on some clusters (in particular with rocksdb on the hdd) there is still a rare osd flap at the end of the PG removal -- indicated by the logs I shared earlier. Our workaround to prevent that new flap is to increase osd_heartbeat_grace (e.g. to 45).
With 3.5M objects in a PG, I suggest that you try moving one PG with upmap and watch how it goes (especially at the end).
Hi Dan, I recall no relevant tracker, feel free to create. Curious if you had bluefs_buffered_io set to true when faced that? Thanks, Igor On 4/21/2021 4:37 PM, Dan van der Ster wrote:
Do we have a tracker for this?
We should ideally be able to remove that final collection_list from the optimized pg removal. It can take a really long time and lead to osd flapping:
2021-04-21 15:23:37.003 7f51c273c700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:41.595 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _collection_list, latency = 67.7234s, lat = 67s cid =10.14aes4_head start GHMAX end GHMAX max 30 2021-04-21 15:23:41.595 7f51a3e81700 0 osd.941 pg_epoch: 43004 pg[10.14aes4( v 42754'296580 (40999'293500,42754'296580] lb MIN (bitwise) local-lis/les=41331/41332 n=159058 ec=4951/4937 lis/c 41331/41331 les/c/f 41332/42758/0 41330/42759/33461) [171,903,106,27,395,773]p171(0) r=-1 lpr=42759 DELETING pi=[41331,42759)/1 crt=42754'296580 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[4#10:75280000::::head#] 2021-04-21 15:23:50.061 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency slow operation observed for submit_transact, latency = 8.46584s 2021-04-21 15:23:50.062 7f51a3e81700 1 heartbeat_map reset_timeout 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:50.115 7f51b6ca1700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _txc_committed_kv, latency = 8.51916s, txc = 0x5573928a7340 2021-04-21 15:23:50.473 7f51b2498700 0 log_channel(cluster) log [WRN] : Monitor daemon marked osd.941 down, but it is still running
-- dan
On Thu, Apr 15, 2021 at 10:32 AM Dan van der Ster <dan@vanderster.com> wrote:
Thanks Igor and Neha for the quick responses.
I posted an osd log with debug_osd 10 and debug_bluestore 20: ceph-post-file: 09094430-abdb-4248-812c-47b7babae06c
Hope that helps,
Dan
On Thu, Apr 15, 2021 at 1:27 AM Neha Ojha <nojha@redhat.com> wrote:
We saw this warning once in testing (https://tracker.ceph.com/issues/49900#note-1), but there, the problem was different, which also led to a crash. That issue has been fixed but if you can provide osd logs with verbose logging, we might be able to investigate further.
Neha
On Wed, Apr 14, 2021 at 4:14 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch.
The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal.
New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening....
Thanks,
Igor
On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Here's a tracker: https://tracker.ceph.com/issues/50466 bluefs_buffered_io is indeed enabled on this cluster, but I suspect it doesn't help for this precise issue because the collection isn't repeated fully listed any more. -- dan On Wed, Apr 21, 2021 at 4:22 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
I recall no relevant tracker, feel free to create.
Curious if you had bluefs_buffered_io set to true when faced that?
Thanks,
Igor
On 4/21/2021 4:37 PM, Dan van der Ster wrote:
Do we have a tracker for this?
We should ideally be able to remove that final collection_list from the optimized pg removal. It can take a really long time and lead to osd flapping:
2021-04-21 15:23:37.003 7f51c273c700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:41.595 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _collection_list, latency = 67.7234s, lat = 67s cid =10.14aes4_head start GHMAX end GHMAX max 30 2021-04-21 15:23:41.595 7f51a3e81700 0 osd.941 pg_epoch: 43004 pg[10.14aes4( v 42754'296580 (40999'293500,42754'296580] lb MIN (bitwise) local-lis/les=41331/41332 n=159058 ec=4951/4937 lis/c 41331/41331 les/c/f 41332/42758/0 41330/42759/33461) [171,903,106,27,395,773]p171(0) r=-1 lpr=42759 DELETING pi=[41331,42759)/1 crt=42754'296580 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[4#10:75280000::::head#] 2021-04-21 15:23:50.061 7f51a3e81700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency slow operation observed for submit_transact, latency = 8.46584s 2021-04-21 15:23:50.062 7f51a3e81700 1 heartbeat_map reset_timeout 'OSD::osd_op_tp thread 0x7f51a3e81700' had timed out after 15 2021-04-21 15:23:50.115 7f51b6ca1700 0 bluestore(/var/lib/ceph/osd/ceph-941) log_latency_fn slow operation observed for _txc_committed_kv, latency = 8.51916s, txc = 0x5573928a7340 2021-04-21 15:23:50.473 7f51b2498700 0 log_channel(cluster) log [WRN] : Monitor daemon marked osd.941 down, but it is still running
-- dan
On Thu, Apr 15, 2021 at 10:32 AM Dan van der Ster <dan@vanderster.com> wrote:
Thanks Igor and Neha for the quick responses.
I posted an osd log with debug_osd 10 and debug_bluestore 20: ceph-post-file: 09094430-abdb-4248-812c-47b7babae06c
Hope that helps,
Dan
On Thu, Apr 15, 2021 at 1:27 AM Neha Ojha <nojha@redhat.com> wrote:
We saw this warning once in testing (https://tracker.ceph.com/issues/49900#note-1), but there, the problem was different, which also led to a crash. That issue has been fixed but if you can provide osd logs with verbose logging, we might be able to investigate further.
Neha
On Wed, Apr 14, 2021 at 4:14 PM Igor Fedotov <ifedotov@suse.de> wrote:
Hi Dan,
Seen that once before and haven't thoroughly investigated yet but I think the new PG removal stuff just revealed this "issue". In fact it had been in the code before the patch.
The warning means that new object(s) (given the object names these are apparently system objects, don't remember what's this exactly) has been written to a PG after it was staged for removal.
New PG removal properly handles that case - that was just a paranoid check for an unexpected situation which has actually triggered. Hence IMO no need to worry at this point but developers might want to validate why this is happening....
Thanks,
Igor
On 4/14/2021 10:26 PM, Dan van der Ster wrote:
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#]
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
This is hdd or hybrids OSD's? How much obj per PG avg? k Sent from my iPhone
On 21 Apr 2021, at 17:44, Dan van der Ster <dan@vanderster.com> wrote:
Here's a tracker: https://tracker.ceph.com/issues/50466
bluefs_buffered_io is indeed enabled on this cluster, but I suspect it doesn't help for this precise issue because the collection isn't repeated fully listed any more.
hdd only. ~160k objects per PG. The flapping is pretty rare -- we've moved hundreds of PGs today and only one flap. (this is with osd_heartbeat_grace =45. with the default 20s we had one flap per ~hour) -- dan On Wed, Apr 21, 2021 at 5:20 PM Konstantin Shalygin <k0ste@k0ste.ru> wrote:
This is hdd or hybrids OSD's? How much obj per PG avg?
k
Sent from my iPhone
On 21 Apr 2021, at 17:44, Dan van der Ster <dan@vanderster.com> wrote:
Here's a tracker: https://tracker.ceph.com/issues/50466
bluefs_buffered_io is indeed enabled on this cluster, but I suspect it doesn't help for this precise issue because the collection isn't repeated fully listed any more.
We are also start detect wrong marks 2021-04-22 00:02:11.245 7faccf703700 0 osd.22 pg_epoch: 271687 pg[17.739( v 270365'95284021 (270347'95280922,270365'95284021] lb MIN (bitwise) local-lis/les=269695/269696 n=3488450 ec=51990/51987 lis/c 271642/271615 les/c/f 271643/271616/0 271644/271653/271653) [702,655,39] r=-1 lpr=271653 DELETING pi=[269695,271653)/3 crt=270365'95284021 lcod 270365'95284020 unknown NOTIFY mbc={}] _delete_some additional unexpected onode list (new onodes has appeared since PG removal started[#17:9ce00000::::head#] 2021-04-22 00:02:16.846 7faccf703700 0 bluestore(/var/lib/ceph/osd/ceph-22) log_latency slow operation observed for submit_transact, latency = 5.59719s 2021-04-22 00:02:16.846 7face5be2700 0 bluestore(/var/lib/ceph/osd/ceph-22) log_latency_fn slow operation observed for _txc_committed_kv, latency = 5.59982s, txc = 0x259aa700 2021-04-22 00:02:16.962 7face13d9700 0 log_channel(cluster) log [WRN] : Monitor daemon marked osd.22 down, but it is still running 2021-04-22 00:02:16.962 7face13d9700 0 log_channel(cluster) log [DBG] : map e271689 wrongly marked me down at e271688 2021-04-21 22:36:07.299 7f6e0b153700 0 bluestore(/var/lib/ceph/osd/ceph-23) log_latency slow operation observed for submit_transact, latency = 58.6702s 2021-04-21 22:36:07.303 7f6e24638700 0 bluestore(/var/lib/ceph/osd/ceph-23) log_latency_fn slow operation observed for _txc_committed_kv, latency = 58.6741s, txc = 0xb99aea00 2021-04-21 22:36:07.483 7f6e1fe2f700 0 log_channel(cluster) log [WRN] : Monitor daemon marked osd.23 down, but it is still running 2021-04-21 22:36:07.483 7f6e1fe2f700 0 log_channel(cluster) log [DBG] : map e270669 wrongly marked me down at e270667 Recently I was created [1], seems some of reproducer I was increased delete_sleep, again [1] https://tracker.ceph.com/issues/50297 k
On 21 Apr 2021, at 18:26, Dan van der Ster <dan@vanderster.com> wrote:
hdd only. ~160k objects per PG.
The flapping is pretty rare -- we've moved hundreds of PGs today and only one flap. (this is with osd_heartbeat_grace =45. with the default 20s we had one flap per ~hour)
participants (4)
-
Dan van der Ster
-
Igor Fedotov
-
Konstantin Shalygin
-
Neha Ojha