Multiple issues after upgrading to Pacific (16.2.7)

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hello folks.

Last week we upgraded a cluster from Nautilus to Pacific, and since then we have seen some issues with the cluster.

The first issue is that we’ve seen a spam of log messages from OSDs in the format of:

-1 osd.1301 pg_epoch: 7742497 pg[10.c19( v 7742481'1954479 (7292960'1947941,7742481'1954479] local-lis/les=7305119/7305120 n=35726 ec=3435285/322 lis/c=7305119/7305119 les/c/f=7305120/7305120/164163 sis=7305119) [1301,1151,307] r=0 lpr=7305119 crt=7742481'1954479 lcod 7742481'1954478 mlcod 7742481'1954478 active+clean]  scrubber pg(10.c19) handle_scrub_reserve_grant: received unsolicited reservation grant from osd 307 (0x55bae91691e0)
-1 osd.1301 pg_epoch: 7742498 pg[10.c19( v 7742481'1954479 (7292960'1947941,7742481'1954479] local-lis/les=7305119/7305120 n=35726 ec=3435285/322 lis/c=7305119/7305119 les/c/f=7305120/7305120/164163 sis=7305119) [1301,1151,307] r=0 lpr=7305119 crt=7742481'1954479 lcod 7742481'1954478 mlcod 7742481'1954478 active+clean]  scrubber pg(10.c19) handle_scrub_reserve_grant: received unsolicited reservation grant from osd 307 (0x55baf11f89a0)
-1 osd.1301 pg_epoch: 7742528 pg[10.c19( v 7742481'1954479 (7292960'1947941,7742481'1954479] local-lis/les=7305119/7305120 n=35726 ec=3435285/322 lis/c=7305119/7305119 les/c/f=7305120/7305120/164163 sis=7305119) [1301,1151,307] r=0 lpr=7305119 crt=7742481'1954479 lcod 7742481'1954478 mlcod 7742481'1954478 active+clean TIME_FOR_DEEP]  scrubber pg(10.c19) handle_scrub_reserve_grant: received unsolicited reservation grant from osd 307 (0x55baeef65e40)

This seems related to scrubs, and regular scrubs and deep-scrubs are still happening, so I’m unsure of what/if this has an effect on the cluster. The only reference I was able to find to this issue was a previous thread to this list: https://www.mail-archive.com/ceph-users@xxxxxxx/msg13304.html <https://www.mail-archive.com/ceph-users@xxxxxxx/msg13304.html> In this thread it is mentioned that this issue has been fixed on the master branch but that this fix (along with a fix for a more serious issue? ) has not been back ported to the stable Ceph version. Is there a way to mitigate this issue? Is it related to being an upgraded cluster and not a new Pacific cluster? Can I get a link to the specific issue in question?


The second issue also seems related to scrubs, when we set nodeep-scrub/noscrub a bunch of OSDs crash with this exception:

/src/osd/scrub_machine.cc: In function 'void Scrub::ScrubMachine::assert_not_active() const' thread 7fdf61752700 time 2022-02-11T12:24:02.836325+0000
/src/osd/scrub_machine.cc: 55: FAILED ceph_assert(state_cast<const NotActive*>())

ceph version 16.2.7 (dd0603118f56ab514f133c8d2e3adfc983942503) pacific (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x158) [0x56543596ab7e]
2: /usr/bin/ceph-osd(+0x56ad98) [0x56543596ad98]
3: /usr/bin/ceph-osd(+0x9e8fef) [0x565435de8fef]
4: (PgScrubber::replica_scrub_op(boost::intrusive_ptr<OpRequest>)+0x4bf) [0x565435dd954f]
5: (PG::replica_scrub(boost::intrusive_ptr<OpRequest>, ThreadPool::TPHandle&)+0x62) [0x565435b24342]
6: (PrimaryLogPG::do_request(boost::intrusive_ptr<OpRequest>&, ThreadPool::TPHandle&)+0x7bb) [0x565435be9b3b]
7: (OSD::dequeue_op(boost::intrusive_ptr<PG>, boost::intrusive_ptr<OpRequest>, ThreadPool::TPHandle&)+0x309) [0x565435a728e9]
8: (ceph::osd::scheduler::PGOpItem::run(OSD*, OSDShard*, boost::intrusive_ptr<PG>&, ThreadPool::TPHandle&)+0x68) [0x565435cd0838]
9: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0xc28) [0x565435a92d48]
10: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x5c4) [0x5654361045b4]
11: (ShardedThreadPool::WorkThreadSharded::entry()+0x14) [0x565436107254]
12: /lib64/libpthread.so.0(+0x817a) [0x7fdf845e917a]
13: clone()

The only reference I was able to find related to this issue is https://tracker.ceph.com/issues/51338 <https://tracker.ceph.com/issues/51338>, but there isn’t much information there. Is this related to the first issue perhaps?


The third issue is that the data size of our mons has been steadily increasing:

    mon.node834 is 68 GiB >= mon_data_size_warn (15 GiB)
    mon.node846 is 66 GiB >= mon_data_size_warn (15 GiB)
    mon.node857 is 66 GiB >= mon_data_size_warn (15 GiB)

According to https://docs.ceph.com/en/latest/rados/operations/health-checks/#mon-disk-big <https://docs.ceph.com/en/latest/rados/operations/health-checks/#mon-disk-big> this could be because we have PGs that have not reached the active+clean state in a long time, but that is not the case. All of them are currently active+clean(+some scrubbing). It also seems that compactions are happening:

(One mon log)
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834199812452, "job": 118147, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L5": [589046], "files_L6": [588997], "score": -1, "input_data_size": 116707515}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834240603257, "job": 118153, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [589059, 589057, 589055, 589053], "files_L3": [589041, 589042], "score": 1, "input_data_size": 217951350}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834282042365, "job": 118158, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [589071, 589069, 589067, 589065], "files_L3": [589060, 589061, 589062, 589063], "score": 1, "input_data_size": 297654768}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834312134845, "job": 118163, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L0": [589082, 589080, 589078], "files_L3": [589072, 589074, 589075, 589076], "score": -1, "input_data_size": 284384439}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834312469305, "job": 118164, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L3": [589085, 589086, 589087], "files_L4": [589047, 589048, 589049], "score": -1, "input_data_size": 327370401}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834312791541, "job": 118166, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L5": [589088], "files_L6": [589050, 589051], "score": -1, "input_data_size": 139795968}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834372497363, "job": 118172, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [589101, 589099, 589097, 589095], "files_L3": [589083, 589084], "score": 1, "input_data_size": 219362956}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834420286570, "job": 118177, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [589113, 589111, 589109, 589107], "files_L3": [589102, 589103, 589104, 589105], "score": 1, "input_data_size": 302058511}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834437696547, "job": 118181, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L0": [589122, 589120], "files_L3": [589115, 589116, 589117, 589118], "score": -1, "input_data_size": 264729846}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834438002444, "job": 118182, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L3": [589125, 589126], "files_L4": [589089, 589090, 589091], "score": -1, "input_data_size": 316733348}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834438386929, "job": 118184, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L5": [589127], "files_L6": [589093], "score": -1, "input_data_size": 104499335}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834443987312, "job": 118187, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L0": [589134], "files_L3": [589123, 589124], "score": -1, "input_data_size": 145560290}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834444185578, "job": 118188, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L3": [589135], "files_L4": [589114, 589024, 589025, 589026, 589073], "score": -1, "input_data_size": 401991636}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834444596784, "job": 118190, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L5": [589138], "files_L6": [589027, 589028], "score": -1, "input_data_size": 202726259}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834449004148, "job": 118192, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L0": [589148], "files_L3": [589136, 589137], "score": -1, "input_data_size": 88564651}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834449113453, "job": 118193, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L3": [589149], "files_L4": [589139, 589140, 589141, 589142, 589143], "score": -1, "input_data_size": 339848774}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834449496277, "job": 118195, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L5": [589151], "files_L6": [589144, 589145, 589146, 589029, 589030, 589031, 589032], "score": -1, "input_data_size": 406673638}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834494177320, "job": 118200, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [589169, 589167, 589165, 589163], "files_L3": [589150], "score": 1, "input_data_size": 107109402}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834536579684, "job": 118205, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [589179, 589177, 589175, 589173], "files_L3": [589170, 589171], "score": 1, "input_data_size": 182927048}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834554409071, "job": 118208, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L0": [589186, 589184], "files_L3": [589180, 589181, 589182], "score": -1, "input_data_size": 216532891}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834554649315, "job": 118209, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L3": [589188, 589189, 589190], "files_L4": [589128, 589129, 589130], "score": -1, "input_data_size": 318917446}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834554952517, "job": 118211, "event": "compaction_started", "compaction_reason": "ManualCompaction", "files_L5": [589191], "files_L6": [589131, 589132], "score": -1, "input_data_size": 136121815}
4 rocksdb: EVENT_LOG_v1 {"time_micros": 1644834597684175, "job": 118217, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [589204, 589202, 589200, 589198], "files_L3": [589187], "score": 1, "input_data_size": 151217963}


So I’m not really sure why the state is not being pruned…

Lastly, I was wondering if there is any kind of statistic about which version is mostly used in production nowadays. Are most people still on Octopus?

Thank you and best regards,
André Cruz
_______________________________________________
ceph-users mailing list -- ceph-users@xxxxxxx
To unsubscribe send an email to ceph-users-leave@xxxxxxx




[Index of Archives]     [Information on CEPH]     [Linux Filesystem Development]     [Ceph Development]     [Ceph Large]     [Ceph Dev]     [Linux USB Development]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [xfs]


  Powered by Linux