Hello ceph-users:
First ,sorry my english ...
I find a bug
(16.2.10 and 18.2.1), but i do not know why
test steps:
1、config all hosts contain chronyd service
3、add hosts
ssh-copy-id -f -i /etc/ceph/
ceph.pub root@node2
ssh-copy-id -f -i /etc/ceph/
ceph.pub root@node-1
4、add osds:
ceph orch daemon add osd node1:/dev/sda
ceph orch daemon add osd node1:/dev/sdb
ceph orch daemon add osd node1:/dev/sdc
ceph orch daemon add osd node1:/dev/sdd
ceph orch daemon add osd node2:/dev/sda
ceph orch daemon add osd node2:/dev/sdb
ceph orch daemon add osd node2:/dev/sdc
ceph orch daemon add osd node2:/dev/sdd
5、ceph osd pool create test_pool
512 512 --size=3
6、disconnect node1 (which is monitor leader) cluster and public network
ifdown enp35s0f0
ifdown enp35s0f1
7、stay overnight(more than three hours)
8、connect node1 cluster and public network
ifup enp35s0f0
ifup enp35s0f1
then, the osds of node1 call get_auth_session_key from mon.node1 which is not new leader,get the wrong secret_id=4.
the others report error "could not find secret_id=4" more than 40 minutes
the ceph.log content of node1:
2023-12-20T09:48:
30.199224+0800 mon.node1 (mon.
0) 1891 : cluster [WRN] Health check failed: Failed to place 1 daemon(s) (CEPHADM_DAEMON_PLACE_FAIL)
2023-12-20T09:49:
37.816260+0800 mon.node1 (mon.
0) 1901 : cluster [INF] Health check cleared: CEPHADM_DAEMON_PLACE_FAIL (was: Failed to place 1 daemon(s))
2023-12-20T09:49:
44.222046+0800 mon.node1 (mon.
0) 1902 : cluster [WRN] Health check failed: Failed to place 1 daemon(s) (CEPHADM_DAEMON_PLACE_FAIL)
2023-12-20T09:50:
00.000090+0800 mon.node1 (mon.
0) 1905 : cluster [WRN] overall HEALTH_WARN Failed to place 1 daemon(s); 3 failed cephadm daemon(s); 1 pool(s) do not have an application enabled
2023-12-20T09:50:
51.916464+0800 mon.node1 (mon.
0) 1912 : cluster [INF] Health check cleared: CEPHADM_DAEMON_PLACE_FAIL (was: Failed to place 1 daemon(s))
2023-12-20T09:51:
07.127982+0800 mon.node1 (mon.
0) 1916 : cluster [WRN] Health check failed: Failed to place 1 daemon(s) (CEPHADM_DAEMON_PLACE_FAIL)
2023-12-21T01:13:
55.241891+0800 osd.0 (osd.0) 3 : cluster [WRN] Monitor daemon marked osd.0 down, but it is still running
2023-12-21T01:14:
05.853054+0800 mon.node-1 (mon.2) 36 : cluster [INF] mon.node-1 calling monitor election
2023-12-21T01:14:
06.013934+0800 mon.node1 (mon.
0) 1971 : cluster [INF] mon.node1 is new leader, mons node1,node2,node-1 in quorum (ranks 0,1,2)
2023-12-21T01:14:
06.041158+0800 mon.node1 (mon.
0) 1976 : cluster [INF] Health check cleared: MON_DOWN (was: 1/3 mons down, quorum node2,node-1)
the ceph.log content of node2:
2023-12-21T01:10:
01.065051+0800 mon.node2 (mon.
1) 11522 : cluster [WRN] Health check failed: Failed to place 1 daemon(s) (CEPHADM_DAEMON_PLACE_FAIL)
2023-12-21T01:11:
11.092640+0800 mon.node2 (mon.
1) 11531 : cluster [INF] Health check cleared: CEPHADM_DAEMON_PLACE_FAIL (was: Failed to place 1 daemon(s))
2023-12-21T01:11:
19.197355+0800 mon.node2 (mon.
1) 11532 : cluster [WRN] Health check failed: Failed to place 1 daemon(s) (CEPHADM_DAEMON_PLACE_FAIL)
2023-12-21T01:12:
34.469403+0800 mon.node2 (mon.
1) 11547 : cluster [INF] Health check cleared: CEPHADM_DAEMON_PLACE_FAIL (was: Failed to place 1 daemon(s))
2023-12-21T01:12:
42.476793+0800 mon.node2 (mon.
1) 11549 : cluster [WRN] Health check failed: Failed to place 1 daemon(s) (CEPHADM_DAEMON_PLACE_FAIL)
2023-12-21T01:13:
55.233774+0800 osd.5 (osd.5) 3 : cluster [WRN] Monitor daemon marked osd.5 down, but it is still running
2023-12-21T01:13:
55.236038+0800 osd.4 (osd.4) 3 : cluster [WRN] Monitor daemon marked osd.4 down, but it is still running
2023-12-21T01:14:00.
109136+0800 mon.node2 (mon.
1) 11589 : cluster [WRN] Health check update: Degraded data redundancy: 1/8 objects degraded
(12.500%), 1 pg degraded, 188 pgs undersized (PG_DEGRADED)
2023-12-21T01:14:00.
311410+0800 osd.3 (osd.3) 3 : cluster [WRN] Monitor daemon marked osd.3 down, but it is still running
2023-12-21T01:13:
55.241891+0800 osd.0 (osd.0) 3 : cluster [WRN] Monitor daemon marked osd.0 down, but it is still running
2023-12-21T01:14:
05.853054+0800 mon.node-1 (mon.2) 36 : cluster [INF] mon.node-1 calling monitor election
2023-12-21T01:14:
06.013934+0800 mon.node1 (mon.
0) 1971 : cluster [INF] mon.node1 is new leader, mons node1,node2,node-1 in quorum (ranks 0,1,2)
2023-12-21T01:14:
06.041158+0800 mon.node1 (mon.
0) 1976 : cluster [INF] Health check cleared: MON_DOWN (was: 1/3 mons down, quorum node2,node-1)
the osd log of node1:
2023-12-21T01:13:
44.680+0800 7fcd2bed
8640 10 cephx: verify_service_ticket_reply service auth secret_id 2 session_key AQDIIINlUlSmKBAAvL5rKyyIb6vt89rxUGlsxg== validity=
259200.000000
2023-12-21T01:13:
44.680+0800 7fcd2bed
8640 10 cephx: verify_service_ticket_reply service mon secret_id 4 session_key AQDIIINlWvamKBAAxOaZsuCMdgutax1n2ZRbZQ== validity=
3600.000000
2023-12-21T01:13:
44.680+0800 7fcd2bed
8640 10 cephx: verify_service_ticket_reply service osd secret_id 4 session_key AQDIIINlXAinKBAAOwTlViH3CJRgSvj5Kn9qtA== validity=
3600.000000
2023-12-21T01:13:
44.680+0800 7fcd2bed
8640 10 cephx: verify_service_ticket_reply service mgr secret_id 4 session_key AQDIIINlUiGnKBAAr6WBaSawzVyDoqEs8cENdg== validity=
3600.000000
the osd log of node2:
2023-12-21T01:13:
52.170+0800 7fa
581293640 20 AuthRegistry(0x7ffc86c1e7b0) get_handler peer_type 4 method 2 cluster_methods [2] service_methods [2] client_methods [2]
the mon log of node1:
2023-12-21T01:13:
44.424+0800 7fa7976e
9640 10 cephx server mgr.node1.apderh: start_session server_challenge 524ce5eea3e4dd75
2023-12-21T01:13:
44.424+0800 7fa7976e
9640 10 cephx server mgr.node1.apderh: handle_request get_auth_session_key for mgr.node1.apderh
2023-12-21T01:13:
44.424+0800 7fa7976e
9640 20 cephx server mgr.node1.apderh: checking old_ticket: secret_id=2 len=112, old_ticket_may_be_omitted=0
2023-12-21T01:13:
44.424+0800 7fa7976e
9640 10 cephx server mgr.node1.apderh: allowing reclaim of global_id
14184 (valid ticket presented, will encrypt new ticket)
2023-12-21T01:13:
44.424+0800 7fa7976e
9640 10 cephx: build_service_ticket_reply encoding 1 tickets with secret AQBmKIJlvHeYJRAAf5h+auT4c9Ilo/nlUqRJlg==
2023-12-21T01:13:
44.424+0800 7fa7976e
9640 10 cephx: build_service_ticket_reply encoding 4 tickets with secret AQDIIINldY1mGRAApH04rNRZtuyAUrQn5PNG7A==
2023-12-21T01:13:
44.433+0800 7fa7936e
1640 0 mon.node1@0(probing) e3 handle_command mon_command({"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node1.apderh/mirror_snapshot_schedule"} v 0) v1
2023-12-21T01:13:
44.433+0800 7fa7936e
1640 0 log_channel(audit) log [INF] : from='mgr.14184
10.40.10.200:0/2514043697' entity='mgr.node1.apderh' cmd=[{"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node1.apderh/mirror_snapshot_schedule"}]: dispatch
2023-12-21T01:13:
44.434+0800 7fa7936e
1640 0 mon.node1@0(probing) e3 handle_command mon_command({"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node1.apderh/trash_purge_schedule"} v 0) v1
2023-12-21T01:13:
44.434+0800 7fa7936e
1640 0 log_channel(audit) log [INF] : from='mgr.14184
10.40.10.200:0/2514043697' entity='mgr.node1.apderh' cmd=[{"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node1.apderh/trash_purge_schedule"}]: dispatch
the mon log of node2:
2023-12-21T01:13:
10.292+0800 7f88c0ed
0640 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1703092390293629, "job": 1145, "event": "table_file_deletion", "file_number": 2272}
2023-12-21T01:13:
10.295+0800 7f88c0ed
0640 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1703092390296385, "job": 1145, "event": "table_file_deletion", "file_number": 2270}
2023-12-21T01:13:
10.303+0800 7f88c0ed
0640 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1703092390304703, "job": 1145, "event": "table_file_deletion", "file_number": 2269}
2023-12-21T01:13:
32.438+0800 7f88baec
4640 0 mon.node2@1(leader) e3 handle_command mon_command({"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node2.rnirud/trash_purge_schedule"} v 0) v1
2023-12-21T01:13:
32.438+0800 7f88baec
4640 0 log_channel(audit) log [INF] : from='mgr.14252
10.40.10.201:0/357060750' entity='mgr.node2.rnirud' cmd=[{"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node2.rnirud/trash_purge_schedule"}]: dispatch
2023-12-21T01:13:
32.440+0800 7f88baec
4640 0 mon.node2@1(leader) e3 handle_command mon_command({"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node2.rnirud/mirror_snapshot_schedule"} v 0) v1
2023-12-21T01:13:
32.440+0800 7f88baec
4640 0 log_channel(audit) log [INF] : from='mgr.14252
10.40.10.201:0/357060750' entity='mgr.node2.rnirud' cmd=[{"prefix":"config rm","who":"mgr","name":"mgr/rbd_support/node2.rnirud/mirror_snapshot_schedule"}]: dispatch
2023-12-21T01:13:
51.142+0800 7f88baec
4640 0 mon.node2@1(leader) e3 handle_command mon_command({"prefix": "config dump", "format": "json"} v 0) v1
2023-12-21T01:13:
51.144+0800 7f88baec
4640 0 mon.node2@1(leader) e3 handle_command mon_command({"prefix": "config generate-minimal-conf"} v 0) v1
2023-12-21T01:13:
51.145+0800 7f88baec
4640 0 mon.node2@1(leader) e3 handle_command mon_command({"prefix": "auth get", "entity": "client.admin"} v 0) v1
2023-12-21T01:13:
52.247+0800 7f88baec
4640 0 mon.node2@1(leader) e3 handle_command mon_command([{prefix=config-key set, key=mgr/cephadm/host.node1}] v 0) v1
2023-12-21T01:13:
55.187+0800 7f88beecc
640 10 cephx server osd.0: start_session server_challenge dba982c2bced072d
2023-12-21T01:13:
55.187+0800 7f88bf6cd
640 10 cephx server osd.3: start_session server_challenge e9db92f3f5af188c
2023-12-21T01:13:
55.187+0800 7f88bf6cd
640 10 cephx server osd.5: start_session server_challenge 1be9f89b4bd9cdbc
2023-12-21T01:13:
55.188+0800 7f88beecc
640 10 cephx server osd.0: handle_request get_auth_session_key for osd.0