Project

General

Profile

Actions

Bug #48895

closed

ceph: krbd client con get stuck in CON_SOCK_STATE_CONNECTING state

Added by fan chen over 3 years ago. Updated over 2 years ago.

Status:
Duplicate
Priority:
Normal
Assignee:
Category:
libceph
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
2 - major
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

hi,

I've been working on krbd client and found an issue that would appear now and then, 
we also have been investigating this issue for a very long time and have no any idea,
wish for someone's help, the kernel client version is 4.18 and the ceph version is L(12.2.12).
At first, I can briefly describe this issue's situation, in our k8s environment, 
krbd devices are used as POD's volumes, when PODs restart, the krbd device must
be remapped to a new PODs, Once in a while we found that the krbd device unmap reported
"Device busy". and this busy status could remain for one or two days, and was not able to
recover automatically, this situation can not be accepted.
After checking the krbd device status, there were many BLOCKED processes there,
we also saw many inflight IOes on that krbd devices by getting /sys/kernel/debug/ceph/.../osdc.

REQUESTS 18 homeless 0
11276122 osd6 7.2264aa9b 7.9b [6,35,29]/17 [6,35,29]/17 e5824 rbd_data.2f8496b8b4567.0000000000000000 0x400024 1 set-alloc-hint,write
11276123 osd6 7.114cb213 7.13 [6,11,29]/17 [6,11,29]/17 e5824 rbd_data.2f8496b8b4567.0000000000000001 0x400024 1 set-alloc-hint,write
11276127 osd6 7.8459213 7.13 [6,11,29]/17 [6,11,29]/17 e5824 rbd_data.2f8496b8b4567.000000000000a822 0x400024 1 set-alloc-hint,write
11276234 osd6 7.ea3de642 7.42 [6,23,29]/17 [6,23,29]/17 e5824 rbd_header.2f8496b8b4567 0x400024 1 watch-watch
11277114 osd6 7.fe0fb09b 7.9b [6,35,29]/17 [6,35,29]/17 e5824 rbd_data.13536b8b4567.00000000000004a0 0x400024 1 set-alloc-hint,write
[...]

and survey the syslog for OSD6 we also could find some pervious information like:

Aug 20 20:42:10 node-2 kernel: libceph: osd6 up
Aug 20 20:44:36 node-2 kernel: libceph: osd6 down
Aug 20 20:45:12 node-2 kernel: libceph: osd6 up
Aug 20 20:48:01 node-2 kernel: libceph: osd6 down
Aug 20 20:48:05 node-2 kernel: libceph: osd6 up
Aug 20 20:49:55 node-2 kernel: libceph: osd6 192.168.30.6:6804 socket closed (con state OPEN)
Aug 20 20:55:23 node-2 kernel: libceph: osd6 192.168.30.6:6804 socket closed (con state CONNECTING)
Aug 20 21:01:26 node-2 kernel: libceph: osd6 192.168.30.6:6804 socket closed (con state OPEN)
Aug 20 21:01:44 node-2 kernel: libceph: osd6 down
Aug 20 21:17:51 node-2 kernel: libceph: osd6 up
Aug 20 21:20:03 node-2 kernel: libceph: osd6 192.168.30.6:6804 socket closed (con state CONNECTING)
Aug 20 21:22:16 node-2 kernel: libceph: osd6 192.168.30.6:6804 socket closed (con state CONNECTING)

In addition, we can work around this issue by restart OSD.6.

Luckily, we also had dumped a kcore, we found that the krbd client connection got stuck in CON_SOCK_STATE_CONNECTING state:

crash> tree -t rbtree -o ceph_osd.o_node -N 0xffff8683cbe88818 -s ceph_osd.o_osd,o_con

fff87830f7d9800
o_osd = 6
o_con = {
private = 0xffff87830f7d9800,
ops = 0xffff000009e717a8 <osd_con_ops>,
msgr = 0xffff8483c2e34080,
sock_state = {
counter = 3
},
sock = 0xffff8383a8eec340,
peer_addr = {
type = 0,
nonce = 15937,
in_addr = {
ss_family = 2,
__data = "\032\224\300\250\036\006\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
}
},
peer_addr_for_me = {
type = 0,
nonce = 0,
in_addr = {
ss_family = 0,
__data = "\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
}
},
flags = 2,
state = 3,

8< 8< 8< 8< 8< 8< 8< 8< 8< 8< 8< 8< 8< 8< 8<

crash> tree -t rbtree -o ceph_osd.o_node -N 0xffff8683cbe88818 -s ceph_osd.o_osd,o_con.in_banner
ffff8683cbe88800
o_osd = 8
o_con.in_banner = "ceph v027\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
ffff87830f7d9800
o_osd = 6
o_con.in_banner = "\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
ffff8783d47be000
o_osd = 4
o_con.in_banner = "ceph v027\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
ffff8783d943d800
o_osd = 7
o_con.in_banner = "ceph v027\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
ffff87830471f000
o_osd = 13
o_con.in_banner = "ceph v027\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
ffff8783d9289800
o_osd = 11
o_con.in_banner = "ceph v027\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
ffff878314a6b000
o_osd = 12
o_con.in_banner = "ceph v027\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
ffff878314a62800
o_osd = 14
o_con.in_banner = "ceph v027\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",

we could confirm that the con->state was getting stuck in CON_STATE_CONNECTING state,
In the flowchart refs form CEPH source code:

send_server_banner                             send_client_banner
        |                                              |
v v
wait_client_banner wait_server_banner | | | v
v handle_server_banner_and_identify
wait_connect_message <---------\ | | | | v | wait_connect_message_auth | send_connect_message <----------\ | | | | |
v v | | |
handle_connect_message_2 | v | | | | wait_connect_reply |
v v | | | |
replace -> send_connect_message_reply | V | | | wait_connect_reply_auth | | | | |
v v v |
open ---\ handle_connect_reply_2 --------/

then we can suspect that the ceph krbd client hadn't got any "banner" messages from
OSD server, the ceph client connection to OSD.6 was not able to get connected all the time.
But from the TCP sock connection state we could ensure that the sock connection was OK.

Maybe this issue related to the network subsystem, but I am not familiar with the
network subsystem, I hope someone can give some advices for this issue, thanks in advance.

Related issues 1 (1 open0 closed)

Is duplicate of Linux kernel client - Bug #7139: dead tcp connections during connection negotiation may lead to hangsIn ProgressIlya Dryomov

Actions
Actions

Also available in: Atom PDF