Follow up myself, some notes, what helped: - Finding OSDs with excessive bad authorizer logs, killing them, restarting them In many cases this cleared the unknown PGs and restored to more normal I/O. However some OSDs continued with a high amount of messages for some more hours even after restarting. It looks like the message indicated osd<->osd communication errors, so it was not always clear, which side of the osds was failing, so in the end we restarted both osds that were listed in the log message. - It might be related to a specific monitor At some point the monitor on server9 crashed and shortly after I/O from clients began to behave normal again. This is however time wise also near the restart of all osds with high number of bad authorizer messages (which we did before the monitor crashed). At the moment the recovery is running normal (~150-300 MB/s) and client I/O is around 500-700MB/s. However during the problematic time, client I/O was around 0 Byte/s to some kilobyte/s. At the same time recovery speed was high (1-1.5 GB/s), even though osd-max-backfills and osd-recovery-max-active are set to 1 by default. So the cluster was able to recover at high speed, but it was not able to deliver client I/O at any acceptable speed. Are there any other tunables that we should set to avoid this problem? We also set osd recovery op priority = 2 on all nodes by default. - Pool (in-)dependence? One of the strangest things is that the I/O of the SSD pool was also affected, even though only OSDs in the HDD pool were added. Previously I reported OSDs that peer with OSDs of a different class on this mailing list, even though the crush rules limit replication to the same class. - Log sizes With standard osd logging (no settings) the cluster produced around 50 GB logs within 8h of time, with ~10 osds/node, which had the side effect of quickly filling up the log partition. Main log messages was the bad authorizer message + no secret key found. - Octopus to the rescue? Privately I got the hint that some of the problems might be solved in Octopus and I was wondering if anyone can confirm or decline that? Best regards, Nico Nico Schottelius <nico.schottelius@ungleich.ch> writes:

Update, posting information from other posts before:

[08:09:40] server3.place6:~# ceph config-key dump | grep config/ "config/global/auth_client_required": "cephx", "config/global/auth_cluster_required": "cephx", "config/global/auth_service_required": "cephx", "config/global/cluster_network": "2a0a:e5c0:2:1::/64", "config/global/ms_bind_ipv4": "false", "config/global/ms_bind_ipv6": "true", "config/global/osd_class_update_on_start": "false", "config/global/osd_pool_default_size": "3", "config/global/public_network": "2a0a:e5c0:2:1::/64", "config/mgr/mgr/balancer/active": "1", "config/mgr/mgr/balancer/max_misplaced": ".01", "config/mgr/mgr/balancer/mode": "upmap", "config/mgr/mgr/prometheus/rbd_stats_pools": "hdd,ssd,xruk-ssd-pool", "config/osd/osd_max_backfills": "1", "config/osd/osd_recovery_max_active": "1", "config/osd/osd_recovery_op_priority": "1", [08:09:56] server3.place6:~#

To some degree finding osds with huge logs sizes that usually contain

2021-04-13 08:31:25.388 7fa4896a4700 0 --1- [2a0a:e5c0:2:1:21b:21ff:febb:68d8]:0/19492 >> v1:[2a0a:e5c0:2:1:21b:21ff:fe85:a3a2]:6881/29606 conn(0x55a04deadf80 0x55a0273ad000 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=1).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 08:31:25.388 7fa48a6b7700 0 --1- [2a0a:e5c0:2:1:21b:21ff:febb:68d8]:0/19492 >> v1:[2a0a:e5c0:2:1:21b:21ff:fe85:a3a2]:6879/29606 conn(0x55a04eb16d80 0x55a02742c000 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=1).handle_connect_reply_2 connect got BADAUTHORIZER

(with varying osds IPs) and restarting them seems to improve the situation for a bit, but even newly restarted osds go back into the BADAUTHORIZER state.

Nico Schottelius <nico.schottelius@ungleich.ch> writes:

...

Good morning,

I've look somewhat intensively through the list and it seems we are rather hard hit by this. Originally yesterday started on a mixed 14.2.9 and 14.2.16 cluster (osds, mons were all 14.2.16).

We started phasing in 7 new osds, 6 of them throttled by reweighting to 0.1. Symptoms are many unknown PGs, very long stuck in peering (hours), slow activating and the infamous BADAUTHORIZER message. Client I/O is almost 0, not only of the pool with new OSDs, but also of other pools.

We tried restarting all OSDs one by one, which seemed to clear the unknown PGs, however after around 1h they came back to unknown state.

Tuning the --osd-max-backfills=.. and --osd-recovery-max-active=... to 1 does not improve the situation, so we are currently running at =7 for both of them.

An excerpt from one of the osds which heavily logs this issue is below.

Any pointer on how this problem was solved on nautilus before is much appreciated, as the issue started late last night.

Best regards,

Nico

2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: (Original Log Time 2021/04/13-07:38:37.275255) EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "compaction_finished", "compaction_time_micros": 5288403, "compaction_time_cpu_micros": 2940370, "output_level": 2, "num_output_files": 6, "total_output_size": 370673432, "num_input_records": 983055, "num_output_records": 641964, "num_subcompactions": 1, "output_compression": "NoCompression", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [0, 5, 35, 0, 0, 0, 0]} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 421257} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 401289} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 401288} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 401278} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 401277} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 401258} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 401257} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 5, "event": "table_file_deletion", "file_number": 401256} 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: [db/compaction_job.cc:1645] [default] [JOB 6] Compacting 1@1 + 5@2 files to L2, score 1.17 2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: [db/compaction_job.cc:1649] [default] Compaction start summary: Base version 5 Base level 1, inputs: [421255(65MB)], [401318(65MB) 401319(65MB) 401320(65MB) 401321(65MB) 401322(65MB)]

2021-04-13 07:38:37.275 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292317275255, "job": 6, "event": "compaction_started", "compaction_reason": "LevelMaxLevelSize", "files_L1": [421255], "files_L2": [401318, 401319, 401320, 401321, 401322], "score": 1.17224, "input_data_size": 413630461} 2021-04-13 07:38:37.307 7f15a0704700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6862/8751 conn(0x55d520fbcd80 0x55d520ffa000 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:37.315 7f15a372c700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febc:5060]:6835/13651 conn(0x55d521b1bf80 0x55d521b19800 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:37.707 7f15a0704700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6862/8751 conn(0x55d520fbcd80 0x55d520ffa000 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:37.715 7f15a372c700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febc:5060]:6835/13651 conn(0x55d521b1bf80 0x55d521b19800 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:38.119 7f159a469700 4 rocksdb: [db/compaction_job.cc:1332] [default] [JOB 6] Generated table #421271: 130853 keys, 68923910 bytes 2021-04-13 07:38:38.119 7f159a469700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1618292318119320, "cf_name": "default", "job": 6, "event": "table_file_creation", "file_number": 421271, "file_size": 68923910, "table_properties": {"data_size": 67111841, "index_size": 1483972, "filter_size": 327237, "raw_key_size": 10909111, "raw_average_key_size": 83, "raw_value_size": 62457370, "raw_average_value_size": 477, "num_data_blocks": 16807, "num_entries": 130853, "filter_policy_name": "rocksdb.BuiltinBloomFilter"}} 2021-04-13 07:38:38.331 7f15a0704700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febb:68f0]:6884/29245 conn(0x55d521b1a000 0x55d521b16800 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:38.331 7f15a0704700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febb:68f0]:6819/17174 conn(0x55d521b1c400 0x55d521b38000 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:38.507 7f15a0704700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6862/8751 conn(0x55d520fbcd80 0x55d520ffa000 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:38.515 7f15a372c700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febc:5060]:6835/13651 conn(0x55d521b1bf80 0x55d521b19800 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:38.731 7f15a0704700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febb:68f0]:6884/29245 conn(0x55d521b1a000 0x55d521b16800 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER 2021-04-13 07:38:38.731 7f15a0704700 0 --1- [v2:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6816/5534,v1:[2a0a:e5c0:2:1:21b:21ff:febc:7cb6]:6817/5534] >> v1:[2a0a:e5c0:2:1:21b:21ff:febb:68f0]:6819/17174 conn(0x55d521b1c400 0x55d521b38000 :-1 s=CONNECTING_SEND_CONNECT_MSG pgs=0 cs=0 l=0).handle_connect_reply_2 connect got BADAUTHORIZER

-- Sustainable and modern Infrastructures by ungleich.ch