search

ceph / ceph-iscsi

Ceph iSCSI tools
GNU General Public License v3.0
62 stars 59 forks source link

rbd-target-api stuck on uninterruptible sleep #169

Open phvalguima opened 4 years ago

phvalguima commented 4 years ago

Environment: ceph-iscsi, rtslib-fb, configshell-fb and tcmu-runner all checked out from master branches, following: https://docs.ceph.com/docs/master/rbd/iscsi-target-cli-manual-install/ Ubuntu 19.10

I am aware of similar a similar issue, but I don't know if they refer to my case: https://github.com/ceph/ceph-iscsi-cli/issues/102

Testing failover scenario with 2 gateways: one target instance goes down and initiators running multipath should choose the other available. To simulate the failover, I (accidentally) ran: sudo systemctl stop tcmu-runner sudo systemctl stop rbd-target-gw sudo systemctl stop rbd-target-api

By running this sequence, I got rbd-target-api stuck on D state. Checking rbd-* process with ps, I can see:

$ sudo ps aux | grep rbd root 2685 0.0 5.8 1121860 119116 ? Ds Dec28 1:32 /usr/bin/python3 /usr/bin/rbd-target-api ubuntu 19379 0.0 0.0 6428 852 pts/0 S+ 22:01 0:00 grep --color=auto rbd $ sudo ps -flp 2685 F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD 4 D root 2685 1 0 80 0 - 280465 iscsit Dec28 ? 00:01:32 /usr/bin/python3 /usr/bin/rbd-target-api

tcmu-runner is not present on ps.

Digging into process 2685 (rbd-target-api), I can see following stacktrace, memory map and logs: rbd-target-api logs (from shutdown received onwards): https://pastebin.ubuntu.com/p/hMVZDxTVNT/ /proc/2685/stack: https://pastebin.ubuntu.com/p/G4f5B5BWd6/ /proc/2685/maps: https://pastebin.ubuntu.com/p/Pb56KqyJCj/

Stacktrace shows that rbd-target-api is on uninterruptible sleep waiting on ISCSI to finish. However, tcmu-runner is already dead so it will never return.

I understand rbd-target-api needs to run some iscsi-related tasks, for example, removing itself as a target from gateway list. However, it should first ensure tcmu-runner is healthy before running any action that may cause it to hang. Otherwise, if tcmu-runner is not running, it should raise an exception and fail; and giving some feedback to the operator.

Also, I saw gwcli command was hanging and not only on the gateway that failed.

I can imagine this scenario happening in operations where tcmu-runner crashes for some unrelated reason and rbd-target-api eventually hangs waiting for it to reply. The only solution I see is to reboot the node.

mikechristie commented 4 years ago

Thanks for the detailed report.

This is sort of fixed in the current upstream kernel with the patch

commit 2ff717cdc693d532e4560f43858443aea7d88197 Author: Cathy Avery cavery@redhat.com Date: Thu Feb 28 14:28:24 2019 -0500

scsi: target: tcmu: wait for nl reply only if there are listeners or during an add

That patch fixes your specific issue where tcmu-runner is not up when a management operation like removal is run during rbd-target-api shutdown. However, we still need to handle:

  1. addition. We had to special case this in the kernel due to regressions caused during initialization.
  2. tcmu-runner goes down while a operation is in progress.

There are actually a couple other bugs related to how we interact wth the kernel when processing management operations like these. I am looking into modifying ceph-iscsi/rtslib and tcmu-runner so ceph-iscsi via rtslib talks directly to tcmu-runner so we do not have the extra kernel operations that can fail.

It's on the TODO, but it's a lot of work, so for now don't do that : ) And, I'm working on the more general issues.

phvalguima commented 4 years ago

@mikechristie I did not see any issues with tcmu-runner, to be honest. I stopped it before anything. I am not sure if rbd-target-api hang because of tcmu-runner process absence.

Thanks for the feedback. I realize it is a complex change which very likely does not involve ceph-iscsi only!

mikechristie commented 4 years ago

@mikechristie I did not see any issues with tcmu-runner, to be honest. I stopped it before anything. I am not sure if rbd-target-api hang because of tcmu-runner process absence.

The problem is that if you stop tcmu-runner it will just exit. tcmu-runner leaves everything running in the kernel, but older kernels could not detect that tcmu-runner was no longer running.

When you then stop rbd-target-api, it will do a remove call to the kernel. In older kernels, the target_core_user kernel module will send a netlink command to user space and then wait for a response. In older kernels the netlink layer would not correctly return failure if there were no listeners like for the case if runner was not running (some kernels would always return failure so there was not way to detect the issue). So in older kernels we would end up waiting for a response that would never come. With the patch in the previous comment, we can detect if tcmu-runner is not running and will return immediately.

phvalguima commented 4 years ago

I am using kernel 5.3.0 I can confirm that commit is present on my kernel by checking out the code and running: $ git branch --contains 2ff717cdc693

hamidreza-hosseini commented 3 years ago

I have the same issue on ubuntu 20 LTS and I can not restart rbd-target-api because it fails on starting and wont start:

sudo systemctl status rbd-target-api.service 
● rbd-target-api.service - Ceph iscsi target configuration API
     Loaded: loaded (/lib/systemd/system/rbd-target-api.service; enabled; vendor preset: enabled)
     Active: deactivating (stop-sigterm) since Sat 2020-11-28 17:01:40 +0330; 20s ago
   Main PID: 37651 (rbd-target-api)
      Tasks: 55 (limit: 9451)
     Memory: 141.4M
     CGroup: /system.slice/rbd-target-api.service
             ├─15289 /usr/bin/python3 /usr/bin/rbd-target-api
             └─37651 /usr/bin/python3 /usr/bin/rbd-target-api

Nov 28 14:36:53 dev11 systemd[1]: Started Ceph iscsi target configuration API.
Nov 28 14:36:54 dev11 rbd-target-api[37651]: Started the configuration object watcher
Nov 28 14:36:54 dev11 rbd-target-api[37651]: Processing osd blacklist entries for this node
Nov 28 14:36:54 dev11 rbd-target-api[37651]: Checking for config object changes every 1s
Nov 28 14:36:55 dev11 rbd-target-api[37651]: Reading the configuration object to update local LIO configuration
Nov 28 14:36:55 dev11 rbd-target-api[37651]: Processing Gateway configuration
Nov 28 14:36:55 dev11 rbd-target-api[37651]: Setting up iqn.2003-01.com.redhat.iscsi-gw:iscsi-igw
Nov 28 14:36:55 dev11 rbd-target-api[37651]: (Gateway.load_config) successfully loaded existing target definition
Nov 28 17:01:40 dev11 systemd[1]: Stopping Ceph iscsi target configuration API...

journalctl:

Unable to locate Target Portal Group on iqn.2003-01.com.redhat.iscsi-gw:iscsi-igw
 kernel: Unable to locate Target Portal Group on iqn.2003-01.com.redhat.iscsi-gw:iscsi-igw
 kernel: iSCSI Login negotiation failed.
 kernel: Unable to locate Target Portal Group on iqn.2003-01.com.redhat.iscsi-gw:iscsi-igw
 kernel: iSCSI Login negotiation failed.