Bug 1700538

Summary:

generated openstack keyring not working on rhcs4/osp15 composes (admin keyring does work)

Product:

[Red Hat Storage] Red Hat Ceph Storage

Reporter:

John Fulton <johfulto>

Component:

Ceph-Ansible

Assignee:

Guillaume Abrioux <gabrioux>

Status:

CLOSED NOTABUG

QA Contact:

ceph-qe-bugs <ceph-qe-bugs>

Severity:

medium

Docs Contact:

Priority:

unspecified

Version:

4.0

CC:

aschoen, ceph-eng-bugs, gmeno, nthomas, sankarshan

Target Milestone:

Target Release:

4.0

Hardware:

Unspecified

OS:

Unspecified

Whiteboard:

Fixed In Version:

Doc Type:

If docs needed, set a value

Doc Text:

Story Points:

---

Clone Of:

Environment:

Last Closed:

2019-04-17 16:59:42 UTC

Type:

Bug

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

---

oVirt Team:

---

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

---

Target Upstream Version:

Embargoed:

Bug Depends On:

Bug Blocks:

1594251

Attachments:

Description	Flags
output from 'rbd --debug-ms 10 -c /etc/ceph/ceph.conf --keyring /etc/ceph/ceph.client.openstack.keyring -p vms ls -l'	none
output of 'rbd --debug-ms 10 -c /etc/ceph/ceph.conf --keyring /etc/ceph/ceph.client.admin.keyring'	none
ceph-ansible depoyment log with -vvv	none

Description John Fulton 2019-04-16 20:10:03 UTC

While testing the RHCS4 composes [1] against the OSP15 composes on RHEL8 the Ceph deployment completes but the OpenStack keyring which is generated by default [2] does not work [3] in that a simple command like the following times out with "monclient(hunting): authenticate timed out after 300":

 rbd -c /etc/ceph/ceph.conf --keyring /etc/ceph/ceph.client.openstack.keyring -p vms ls -l

However if I replace [4] the content of the ceph.client.openstack.keyring with the content of the ceph.client.admin.keyring on all nodes then it works!



[1] 
ceph-ansible-4.0.0-0.beta1.95.g6d506dba.el8cp.noarch
docker-registry.engineering.redhat.com/ceph/rhceph-4-rhel8:latest 7678fc9d3643

[2] 
[root@overcloud-controller-0 ceph]# cat ceph.client.openstack.keyring
[client.openstack]
        key = AQDH1LVcAAAAABAAqLWKC0cdZJdLHCphocW9Zg==
        caps mgr = "allow *"
        caps mon = "profile rbd"
        caps osd = "profile rbd pool=volumes, profile rbd pool=backups, profile rbd pool=vms, profile rbd pool=images, profile rbd pool=metrics"
[root@overcloud-controller-0 ceph]# 

[3] http://paste.openstack.org/show/749262

[4] workaround
# ensure ceph.client.admin.keyring is in /etc/ceph/ on all nodes
cp -a ceph.client.openstack.keyring ceph.client.openstack.keyring.bak
cat ceph.client.admin.keyring > ceph.client.openstack.keyring

Comment 2 John Fulton 2019-04-17 15:31:01 UTC

Created attachment 1555943 [details]
output from 'rbd --debug-ms 10 -c /etc/ceph/ceph.conf --keyring /etc/ceph/ceph.client.openstack.keyring -p vms ls -l'

Comment 3 John Fulton 2019-04-17 15:46:26 UTC

Created attachment 1555944 [details]
output of 'rbd --debug-ms 10 -c /etc/ceph/ceph.conf --keyring /etc/ceph/ceph.client.admin.keyring'

It might be useful to compare these two attachments to see why the admin key is working but the openstack key is not.

Comment 4 John Fulton 2019-04-17 16:01:42 UTC

Created attachment 1555949 [details]
ceph-ansible depoyment log with -vvv

Comment 5 Guillaume Abrioux 2019-04-17 16:09:41 UTC

adding `-n client.openstack` makes that command working, eg:

bash-4.4# rbd --debug-ms 1  -c /etc/ceph/ceph.conf --keyring /etc/ceph/ceph.client.openstack.keyring -n client.openstack -p vms ls 
2019-04-17 16:09:02.574 7f832484d040  1  Processor -- start
2019-04-17 16:09:02.575 7f832484d040  1 --  start start
2019-04-17 16:09:02.575 7f832484d040  1 --2-  >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475a8d0 0x5639f475ad10 unknown :-1 s=NONE pgs=0 cs=0 l=0 rx=0 tx=0).connect
2019-04-17 16:09:02.575 7f832484d040  1 --  --> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] -- mon_getmap magic: 0 v1 -- 0x5639f45c0fc0 con 0x5639f475a8d0
2019-04-17 16:09:02.575 7f8312883700  1 --2-  >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475a8d0 0x5639f475ad10 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0)._handle_peer_banner_payload supported=0 required=0
2019-04-17 16:09:02.576 7f8312883700  1 --  --> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x5639f4654f30 con 0x5639f475a8d0
2019-04-17 16:09:02.576 7f8312883700  1 --2-  >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475a8d0 0x5639f475ad10 crc :-1 s=SESSION_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).send_client_ident getsockname reveals I am 172.17.3.73:35344 when talking to v2:172.17.3.73:3300/0
2019-04-17 16:09:02.576 7f8312883700  1 -- 172.17.3.73:0/1458310170 learned_addr learned my addr 172.17.3.73:0/1458310170 (peer_addr_for_me v2:172.17.3.73:0/0)
2019-04-17 16:09:02.576 7f8312883700  1 --2- 172.17.3.73:0/1458310170 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475a8d0 0x5639f475ad10 crc :-1 s=READY pgs=2406 cs=0 l=1 rx=0 tx=0).ready entity=mon.0 client_cookie=9c6ac40a59307686 server_cookie=0 in_seq=0 out_seq=0
2019-04-17 16:09:02.576 7f8311881700  1 -- 172.17.3.73:0/1458310170 <== mon.0 v2:172.17.3.73:3300/0 1 ==== mon_map magic: 0 v1 ==== 244+0+0 (crc 0 0 0) 0x5639f4654f30 con 0x5639f475a8d0
2019-04-17 16:09:02.577 7f8311881700  1 -- 172.17.3.73:0/1458310170 <== mon.0 v2:172.17.3.73:3300/0 2 ==== config(0 keys) v1 ==== 4+0+0 (crc 0 0 0) 0x7f8304002570 con 0x5639f475a8d0
2019-04-17 16:09:02.577 7f8311881700  1 -- 172.17.3.73:0/1458310170 <== mon.0 v2:172.17.3.73:3300/0 3 ==== mon_map magic: 0 v1 ==== 244+0+0 (crc 0 0 0) 0x7f8304002970 con 0x5639f475a8d0
2019-04-17 16:09:02.577 7f832484d040  1 -- 172.17.3.73:0/1458310170 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475a8d0 msgr2=0x5639f475ad10 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
2019-04-17 16:09:02.577 7f832484d040  1 --2- 172.17.3.73:0/1458310170 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475a8d0 0x5639f475ad10 crc :-1 s=READY pgs=2406 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.578 7f832484d040  1 -- 172.17.3.73:0/1458310170 shutdown_connections 
2019-04-17 16:09:02.578 7f832484d040  1 --2- 172.17.3.73:0/1458310170 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475a8d0 0x5639f475ad10 unknown :-1 s=CLOSED pgs=2406 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.578 7f832484d040  1 -- 172.17.3.73:0/1458310170 shutdown_connections 
2019-04-17 16:09:02.578 7f832484d040  1 -- 172.17.3.73:0/1458310170 wait complete.
2019-04-17 16:09:02.578 7f832484d040  1 -- 172.17.3.73:0/1458310170 >> 172.17.3.73:0/1458310170 conn(0x5639f46cb700 msgr2=0x5639f46cbb40 unknown :-1 s=STATE_NONE l=0).mark_down
2019-04-17 16:09:02.578 7f832484d040  1  Processor -- start
2019-04-17 16:09:02.578 7f832484d040  1 --  start start
2019-04-17 16:09:02.579 7f832484d040  1 --2-  >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475efb0 0x5639f475f3f0 unknown :-1 s=NONE pgs=0 cs=0 l=1 rx=0 tx=0).connect
2019-04-17 16:09:02.579 7f832484d040  1 --  --> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] -- mon_getmap magic: 0 v1 -- 0x5639f4581580 con 0x5639f475efb0
2019-04-17 16:09:02.579 7f8312883700  1 --2-  >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475efb0 0x5639f475f3f0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rx=0 tx=0)._handle_peer_banner_payload supported=0 required=0
2019-04-17 16:09:02.580 7f8312883700  1 --  --> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x5639f475f940 con 0x5639f475efb0
2019-04-17 16:09:02.580 7f8312883700  1 --2-  >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475efb0 0x5639f475f3f0 crc :-1 s=SESSION_CONNECTING pgs=0 cs=0 l=1 rx=0 tx=0).send_client_ident getsockname reveals I am 172.17.3.73:35346 when talking to v2:172.17.3.73:3300/0
2019-04-17 16:09:02.580 7f8312883700  1 -- 172.17.3.73:0/611322385 learned_addr learned my addr 172.17.3.73:0/611322385 (peer_addr_for_me v2:172.17.3.73:0/0)
2019-04-17 16:09:02.580 7f8312883700  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475efb0 0x5639f475f3f0 crc :-1 s=READY pgs=2407 cs=0 l=1 rx=0 tx=0).ready entity=mon.0 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
2019-04-17 16:09:02.580 7f8311080700  1 -- 172.17.3.73:0/611322385 <== mon.0 v2:172.17.3.73:3300/0 1 ==== mon_map magic: 0 v1 ==== 244+0+0 (crc 0 0 0) 0x5639f475f940 con 0x5639f475efb0
2019-04-17 16:09:02.580 7f8311080700  1 -- 172.17.3.73:0/611322385 <== mon.0 v2:172.17.3.73:3300/0 2 ==== config(0 keys) v1 ==== 4+0+0 (crc 0 0 0) 0x7f830400e490 con 0x5639f475efb0
2019-04-17 16:09:02.580 7f8311080700  1 -- 172.17.3.73:0/611322385 <== mon.0 v2:172.17.3.73:3300/0 3 ==== mon_map magic: 0 v1 ==== 244+0+0 (crc 0 0 0) 0x7f8304004560 con 0x5639f475efb0
2019-04-17 16:09:02.580 7f832484d040  1 -- 172.17.3.73:0/611322385 --> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] -- mon_subscribe({mgrmap=0+}) v3 -- 0x5639f4761030 con 0x5639f475efb0
2019-04-17 16:09:02.580 7f832484d040  1 -- 172.17.3.73:0/611322385 --> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] -- mon_subscribe({osdmap=0}) v3 -- 0x5639f4761600 con 0x5639f475efb0
2019-04-17 16:09:02.581 7f8311080700  1 -- 172.17.3.73:0/611322385 <== mon.0 v2:172.17.3.73:3300/0 4 ==== mgrmap(e 3) v1 ==== 3378+0+0 (crc 0 0 0) 0x7f83040011d0 con 0x5639f475efb0
2019-04-17 16:09:02.581 7f8311080700  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:6800/89,v1:172.17.3.73:6801/89] conn(0x7f8300003db0 0x7f83000062d0 unknown :-1 s=NONE pgs=0 cs=0 l=1 rx=0 tx=0).connect
2019-04-17 16:09:02.581 7f8311080700  1 -- 172.17.3.73:0/611322385 <== mon.0 v2:172.17.3.73:3300/0 5 ==== osd_map(20..20 src has 1..20) v4 ==== 3090+0+0 (crc 0 0 0) 0x7f83040085b0 con 0x5639f475efb0
2019-04-17 16:09:02.581 7f832484d040  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.103:6800/20073,v1:172.17.3.103:6801/20073] conn(0x5639f4764b30 0x5639f4766f80 unknown :-1 s=NONE pgs=0 cs=0 l=1 rx=0 tx=0).connect
2019-04-17 16:09:02.581 7f832484d040  1 -- 172.17.3.73:0/611322385 --> [v2:172.17.3.103:6800/20073,v1:172.17.3.103:6801/20073] -- osd_op(unknown.0.0:1 3.1c 3:3831950c:::rbd_directory:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected e20) v8 -- 0x5639f45d3050 con 0x5639f4764b30
2019-04-17 16:09:02.581 7f8312082700  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:6800/89,v1:172.17.3.73:6801/89] conn(0x7f8300003db0 0x7f83000062d0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rx=0 tx=0)._handle_peer_banner_payload supported=0 required=0
2019-04-17 16:09:02.582 7f8313084700  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.103:6800/20073,v1:172.17.3.103:6801/20073] conn(0x5639f4764b30 0x5639f4766f80 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rx=0 tx=0)._handle_peer_banner_payload supported=0 required=0
2019-04-17 16:09:02.583 7f8312082700  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:6800/89,v1:172.17.3.73:6801/89] conn(0x7f8300003db0 0x7f83000062d0 crc :-1 s=READY pgs=764 cs=0 l=1 rx=0 tx=0).ready entity=mgr.4122 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
2019-04-17 16:09:02.584 7f8313084700  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.103:6800/20073,v1:172.17.3.103:6801/20073] conn(0x5639f4764b30 0x5639f4766f80 crc :-1 s=READY pgs=258 cs=0 l=1 rx=0 tx=0).ready entity=osd.0 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
2019-04-17 16:09:02.585 7f8313084700  1 -- 172.17.3.73:0/611322385 <== osd.0 v2:172.17.3.103:6800/20073 1 ==== osd_op_reply(1 rbd_directory [read 0~0] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 157+0+0 (crc 0 0 0) 0x7f830c004120 con 0x5639f4764b30
2019-04-17 16:09:02.585 7f832484d040  1 -- 172.17.3.73:0/611322385 >> [v2:172.17.3.103:6800/20073,v1:172.17.3.103:6801/20073] conn(0x5639f4764b30 msgr2=0x5639f4766f80 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
2019-04-17 16:09:02.585 7f832484d040  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.103:6800/20073,v1:172.17.3.103:6801/20073] conn(0x5639f4764b30 0x5639f4766f80 crc :-1 s=READY pgs=258 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.585 7f832484d040  1 -- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:6800/89,v1:172.17.3.73:6801/89] conn(0x7f8300003db0 msgr2=0x7f83000062d0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
2019-04-17 16:09:02.585 7f832484d040  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:6800/89,v1:172.17.3.73:6801/89] conn(0x7f8300003db0 0x7f83000062d0 crc :-1 s=READY pgs=764 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.585 7f832484d040  1 -- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475efb0 msgr2=0x5639f475f3f0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
2019-04-17 16:09:02.585 7f832484d040  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475efb0 0x5639f475f3f0 crc :-1 s=READY pgs=2407 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.586 7f832484d040  1 -- 172.17.3.73:0/611322385 shutdown_connections 
2019-04-17 16:09:02.586 7f832484d040  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.103:6800/20073,v1:172.17.3.103:6801/20073] conn(0x5639f4764b30 0x5639f4766f80 unknown :-1 s=CLOSED pgs=258 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.586 7f832484d040  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:3300/0,v1:172.17.3.73:6789/0] conn(0x5639f475efb0 0x5639f475f3f0 unknown :-1 s=CLOSED pgs=2407 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.586 7f832484d040  1 --2- 172.17.3.73:0/611322385 >> [v2:172.17.3.73:6800/89,v1:172.17.3.73:6801/89] conn(0x7f8300003db0 0x7f83000062d0 unknown :-1 s=CLOSED pgs=764 cs=0 l=1 rx=0 tx=0).stop
2019-04-17 16:09:02.586 7f832484d040  1 -- 172.17.3.73:0/611322385 shutdown_connections 
2019-04-17 16:09:02.586 7f832484d040  1 -- 172.17.3.73:0/611322385 wait complete.
2019-04-17 16:09:02.586 7f832484d040  1 -- 172.17.3.73:0/611322385 >> 172.17.3.73:0/611322385 conn(0x5639f475a870 msgr2=0x5639f46cb700 unknown :-1 s=STATE_NONE l=0).mark_down
bash-4.4#