Project

General

Profile

Actions

Bug #44197

closed

read_until returns Operation not permitted in a mixed arch client MON session

Added by Tony Davies about 4 years ago. Updated about 3 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

debug 2020-02-19 02:19:14.678 7f95fa7d00 20 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_read_frame_epilogue_main message integrity check success:  expected_crc=3814917087 calculated_crc=3814917087
debug 2020-02-19 02:19:14.678 7f95fa7d00 10 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_read_frame_dispatch tag=1
debug 2020-02-19 02:19:14.678 7f95fa7d00 30 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_frame_payload
00000000  08 01 01 01 1c 00 00 00  02 00 00 00 00 00 00 00  |................|
00000010  10 00 00 00 02 00 0c e4  0a 69 1c c7 00 00 00 00  |.........i......|
00000020  00 00 00 00                                       |....|
00000024

debug 2020-02-19 02:19:14.678 7f95fa7d00 20 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_hello payload.length()=36
debug 2020-02-19 02:19:14.678 7f95fa7d00  5 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_hello received hello: peer_type=8 peer_addr_for_me=v2:10.105.28.199:3300/0
debug 2020-02-19 02:19:14.678 7f95fa7d00  5 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_hello getsockname says I am 10.244.1.192:3300 when talking to v2:10.244.7.134:56850/0
debug 2020-02-19 02:19:14.678 7f95fa7d00 10 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=1 rx=0 tx=0).handle_hello accept of host_type 8, policy.lossy=1 policy.server=1 policy.standby=0 policy.resetcheck=0
debug 2020-02-19 02:19:14.678 7f95fa7d00 20 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=1 rx=0 tx=0).post_server_banner_exchange
debug 2020-02-19 02:19:14.678 7f95fa7d00 20 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=AUTH_ACCEPTING pgs=0 cs=0 l=1 rx=0 tx=0).read_frame
debug 2020-02-19 02:19:14.678 7f95fa7d00 20 -- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 msgr2=0x55d60d75c0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read start len=32
debug 2020-02-19 02:19:14.678 7f95fa7d00 25 -- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 msgr2=0x55d60d75c0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until len is 32 state_offset is 0
debug 2020-02-19 02:19:14.678 7f95fa7d00  1 -- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 msgr2=0x55d60d75c0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_bulk peer close file descriptor 15
debug 2020-02-19 02:19:14.678 7f95fa7d00 25 -- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 msgr2=0x55d60d75c0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until read_bulk recv_end is 0 left is 32 got -1
debug 2020-02-19 02:19:14.678 7f95fa7d00  1 -- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 msgr2=0x55d60d75c0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until read failed
debug 2020-02-19 02:19:14.678 7f95fa7d00 20 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=AUTH_ACCEPTING pgs=0 cs=0 l=1 rx=0 tx=0).handle_read_frame_preamble_main r=-1
debug 2020-02-19 02:19:14.678 7f95fa7d00  1 --2- [v2:10.105.28.199:3300/0,v1:10.105.28.199:6789/0] >>  conn(0x55d1273860 0x55d60d75c0 unknown :-1 s=AUTH_ACCEPTING pgs=0 cs=0 l=1 rx=0 tx=0).handle_read_frame_preamble_main read frame length and tag failed r=-1 ((1) Operation not permitted)

Fails when using armv7/armhf, successful on aarch64 (same host/node)

OS: Alpine Linux v3.11
Packages built per https://github.com/PhoenixMage/aports/tree/master/community/ceph
Ceph: 14.2.6

Ceph mon ip: 10.105.28.199
Rados client ip: 10.244.3.182

Command executed: rados --debug_ms 30 --debug_auth 20 --no-mon-config lspools -m 10.105.28.199 > ~/rados_debug-mon-c.log 2>&1


Files

server_2268322028.log (55.1 KB) server_2268322028.log Tony Davies, 02/19/2020 03:14 AM
client_2268322028.log (307 KB) client_2268322028.log Tony Davies, 02/19/2020 03:14 AM

Related issues 1 (0 open1 closed)

Related to RADOS - Bug #39039: mon connection reset, command not resentDuplicateSage Weil

Actions
Actions #1

Updated by Brad Hubbard about 4 years ago

  • Description updated (diff)
Actions #2

Updated by Brad Hubbard about 4 years ago

  • Subject changed from ceph and rados failing to authenticate to read_until returns Operation not permitted in a mixed arch client MON session
Actions #3

Updated by Brad Hubbard about 4 years ago

  • Assignee set to Brad Hubbard
Actions #4

Updated by Brad Hubbard about 4 years ago

  • Related to Bug #39039: mon connection reset, command not resent added
Actions #5

Updated by Tony Davies almost 4 years ago

This also continues to happen on octopus, I just tested on 15.2.0.

I have attached the build instructions I used to compile on armv7 to #39039. I can also provide the alpine package or a docker image I use for rook.

I tested this on a lab cluster after disabling cephx per https://docs.ceph.com/docs/octopus/rados/configuration/auth-config-ref/#disabling-cephx

My armv7 instance was successfully able to get a response from the test cluser using

ceph -s

Re-enabling cephx on the same lab cluster caused the hang to reappear, so I guess it narrows the issue to cephx.

Actions #6

Updated by Tony Davies almost 4 years ago

Sorry to avoid confusion I will explain my setup.

I am running rook (1.3.1) ceph (15.2.0) on kubernetes using multiple architectures.

Architectures are:
  • aarch64 (Rock Pi 4, RPi3b)
  • x86_64 (vmware vm)
  • armv7l (Olimex Lime2) - these have a sata port so I plan for them to be my osds

All are running near identical versions of Alpine Linux (3.11.5), kernels vary slightly but systems are in sync

Being kubernetes things are a bit fluid but at time of testing:
  • mon-a and mon-c are on aarch64, mon-b is x86_64
  • mgr is on aarch64
  • Working osd is on x86_64
  • Rook operator is on aarch64
I have started instances of the rook toolbox on each architecture and run
ceph -s
on each with the following results:
  • aarch64 returns status
  • x86_64 returns status
  • armv7 hangs

I setup a seperate non kubernetes instance of mon on a seperate x86_64 vm running Alpine 3.11.5 and disabled cephx as per https://docs.ceph.com/docs/octopus/rados/configuration/auth-config-ref/#disabling-cephx and modified /etc/ceph/ceph.conf on the armv7 toolbox instance to use the vm mon and armv7 executing

ceph -s
returned the status.

If I then enable cephx on this standalone vm armv7 will start to hang when

ceph -s
is executed

All the ceph packages for alpine and the docker images used were created by me so I am happy to troubleshoot from that side.

Actions #7

Updated by Greg Farnum almost 4 years ago

So it sounds like cephx doesn't work when the client's 32-bit and the server's 64-bit?

We do try and maintain things like that but at this point it wouldn't surprise me.

Just to confirm, the monitors are in quorum together and the armv7 node without cephx can connect to every monitor? Can it do simple IO to the OSD?

Actions #8

Updated by Tony Davies almost 4 years ago

The 3 monitors are in a quorum together when it has been failing.

I have not disabled cephx in that environment, I ran up a test env and disabled cephx on that to test so IO to the OSD has not been tested.

It is possible to disable cephx only for a single node? If so I would be happy to try.

Actions #9

Updated by Brad Hubbard almost 4 years ago

Okay, I got a chance to really dive into this.

I set up just a monitor on x86_64 and created a container instance of the container you provided on an aarch64 machine and was able to reproduce a hang. I then set up a centos7 container and installed the packages from https://download.ceph.com/rpm-octopus/el7/noarch/. This container operates normally. I then compared debug output for the two.

Working: https://download.ceph.com/rpm-octopus/el7

2020-06-16T01:00:27.005-0400 7f4704a10700 20 --2- [v2:10.19.176.26:3300/0,v1:10.19.176.26:6789/0] >>  conn(0x5608c251a000 0x5608c251c000 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_read_frame_preamble_main r=0
2020-06-16T01:00:27.005-0400 7f4704a10700 30 --2- [v2:10.19.176.26:3300/0,v1:10.19.176.26:6789/0] >>  conn(0x5608c251a000 0x5608c251c000 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_read_frame_preamble_main preamble
00000000  01 01 24 00 00 00 08 00  00 00 00 00 00 00 00 00  |..$.............|
00000010  00 00 00 00 00 00 00 00  00 00 00 00 3f bd 6b 06  |............?.k.|
00000020

2020-06-16T01:00:27.005-0400 7f4704a10700 10 --2- [v2:10.19.176.26:3300/0,v1:10.19.176.26:6789/0] >>  conn(0x5608c251a000 0x5608c251c000 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_read_frame_preamble_main got new segment: len=36 align=8

Not working: Provided container image

2020-06-16T00:19:16.745-0400 7fa98cc21700 30 --2- [v2:10.19.176.26:3300/0,v1:10.19.176.26:6789/0] >>  conn(0x558d6c86c000 0x558d6c872000 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_read_frame_preamble_main preamble
00000000  01 01 24 00 00 00 04 00  00 00 00 00 00 00 00 00  |..$.............|
00000010  00 00 00 00 00 00 00 00  00 00 00 00 5c e9 a7 98  |............\...|
00000020

2020-06-16T00:19:16.745-0400 7fa98cc21700 10 --2- [v2:10.19.176.26:3300/0,v1:10.19.176.26:6789/0] >>  conn(0x558d6c86c000 0x558d6c872000 unknown :-1 s=HELLO_ACCEPTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_read_frame_preamble_main got new segment: len=36 align=4

Notice the differences in the value for 'align'.

Alignment appears to be a 'ceph_le16' which ultimately depends on the value of 'CEPH_BIG_ENDIAN' so maybe this is set in the failure case (since these machines are all little endian)?

src/include/byteorder.h:

// mswab == maybe swab (if not LE)
#ifdef CEPH_BIG_ENDIAN
template<typename T>
inline T mswab(T val) {
  return swab(val);
}
#else
template<typename T>
inline T mswab(T val) {
  return val;
}
#endif

template<typename T>
struct ceph_le {                                                                                                                                                                                                                             
private:
  T v;
public:
  ceph_le<T>& operator=(T nv) {
    v = mswab(nv);
    return *this;
  }
  operator T() const { return mswab(v); }
  friend inline bool operator==(ceph_le a, ceph_le b) {
    return a.v == b.v;
  }
} __attribute__ ((packed));

using ceph_le64 = ceph_le<__u64>;
using ceph_le32 = ceph_le<__u32>;
using ceph_le16 = ceph_le<__u16>;

Tony, can you check the cmake logs for the build you did for that container image to see how CEPH_BIG_ENDIAN and CEPH_LITTLE_ENDIAN are being used?

Actions #10

Updated by Tony Davies almost 4 years ago

Brad Hubbard wrote:

Okay, I got a chance to really dive into this.

I set up just a monitor on x86_64 and created a container instance of the container you provided on an aarch64 machine and was able to reproduce a hang. I then set up a centos7 container and installed the packages from https://download.ceph.com/rpm-octopus/el7/noarch/. This container operates normally. I then compared debug output for the two.

[...]

Tony, can you check the cmake logs for the build you did for that container image to see how CEPH_BIG_ENDIAN and CEPH_LITTLE_ENDIAN are being used?

Hey Brad, I dont have the build logs for that particular image any more as it was built on cloud.drone.io. I just kicked off another build for 15.2.3 and get the following:

-- Check if the system is big endian
-- Searching 16 bit integer
-- Check size of unsigned short
-- Check size of unsigned short - done
-- Searching 16 bit integer - Using unsigned short
-- Check if the system is big endian - little endian

I get the same on my x86_64 and aarch64 builds. Hit me up on IRC and we can chat about any more specific tests you want to run.

Actions #11

Updated by Brad Hubbard over 3 years ago

So what I said previously was wrong because all of these are little endian systems but the client that fails is 32 bit which probably makes the alignment value of '4' correct. Looking into this further.

Actions #12

Updated by Vladimir Bashkirtsev about 3 years ago

Issue was likely use of 32 bit words on 32 bit systems to store 64 bit config option values. Config pushed by 64 bit mon to 32 bit osd was corrupted on arrival as 64 bit values were just trimmed. This was fixed in https://github.com/ceph/ceph/pull/38837 and I can run mixed 32/64 bit cluster with this patch.

Actions #13

Updated by Brad Hubbard about 3 years ago

  • Status changed from New to Resolved
  • Pull request ID set to 38837

Thanks for the update, and the patch!

Actions

Also available in: Atom PDF