Bug 2190288

Raimund Noticed this. was at the top of my screen and I missed it.
Makes sense why we cannot open the core file.
We will check with the customer


Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/tcmu-runner...Reading symbols from /usr/lib/debug/usr/bin/tcmu-runner-1.5.4-7.el8.x86_64.debug...done.
done.
BFD: warning: /home/loberman/core.tcmu-runner.0.7b56bb3deb88430fa96e13c4fc7ad1ed.1152774.1682583301000000 is truncated: expected core file size >= 4912242688, found: 2147483648

We are still waiting on a valid core from the customer.
The first one was truncated.
Regards
Laurence

I am not sure if I got the backtrace right yet using my test node to debug.
But to me looks like the cluster pointer is NULL

gdb) up
#1  0x00007f7d3bcece7e in rados_service_update_status () from /lib64/librados.so.2
(gdb) up
#2  0x00007f7d3cb3546e in tcmu_rbd_service_status_update (dev=0x41a7600, has_lock=false)
    at /usr/src/debug/tcmu-runner-1.5.4-7.el8.x86_64/rbd.c:137
137		ret = rados_service_update_status(state->cluster, status_buf);

(gdb) p state->cluster
$1 = (rados_t) 0x0


static int tcmu_rbd_service_status_update(struct tcmu_device *dev,
                                          bool has_lock)
{
        struct tcmu_rbd_state *state = tcmur_dev_get_private(dev);
        struct tcmur_device *rdev = tcmu_dev_get_private(dev);
        char *status_buf = NULL;
        int ret;

        ret = asprintf(&status_buf,
                       "%s%c%s%c%s%c%"PRIu64"%c%s%c%"PRIu64"%c%s%c%"PRIu64"%c",
                       "lock_owner", '\0', has_lock ? "true" : "false", '\0',
                       "lock_lost_cnt", '\0', rdev->lock_lost_cnt, '\0',
                       "conn_lost_cnt", '\0', rdev->conn_lost_cnt, '\0',
                       "cmd_timed_out_cnt", '\0', rdev->cmd_timed_out_cnt, '\0');
        if (ret < 0) {
                tcmu_dev_err(dev, "Could not allocate status buf. Service will not be updated.\n");
                return ret;
        }

        ret = rados_service_update_status(state->cluster, status_buf);
        if (ret < 0) {
                tcmu_dev_err(dev, "Could not update service status. (Err %d)\n",
                             ret);
        }

        free(status_buf);
        return ret;
}

tcmur_device: skip reporting events if the device is closed 

After the rbd device being blocklisted it will lost the connection and at the same time will timedout all the IOs. While the tcmu-runner will report a 'lock_lost_cnt' event to ceph cluster. And if during this the device is reopened it will cause the use-after-free bug.

Notes
When reopening the device it will hold the 'rdev->rdev_lock' lock and then clear the 'TCMUR_DEV_FLAG_IS_OPEN' flag. And we can check this flag and just skip reporting events if the device is closed.

So null means device closed ?

need to understand why we were blocklisted though, That should only happen if we have access to the same LUN from two gateways at the same time.

@Raimund, lets get the logs also available so we can check the blocklisting

Chatted with Raimund

Hello @

Hello @rsachere and @loberman ,

FYI, I'd be cautious to use the Block List as anything of value. There was a site down and a Block List entry was thought to be part of the cause and it turned out to be nothing to do about nothing. Raimund, ping HKlein if you want to know more.

Best regards,
Manny

(In reply to loberman from comment #14)
> tcmur_device: skip reporting events if the device is closed 
> 
> After the rbd device being blocklisted it will lost the connection and at
> the same time will timedout all the IOs. While the tcmu-runner will report a
> 'lock_lost_cnt' event to ceph cluster. And if during this the device is
> reopened it will cause the use-after-free bug.
> 
> Notes
> When reopening the device it will hold the 'rdev->rdev_lock' lock and then
> clear the 'TCMUR_DEV_FLAG_IS_OPEN' flag. And we can check this flag and just
> skip reporting events if the device is closed.
> 
> So null means device closed ?
> 

No, it's the entity of network connection with Rados will be freed after the device is closed.

> need to understand why we were blocklisted though, That should only happen
> if we have access to the same LUN from two gateways at the same time.
> 
> @Raimund, lets get the logs also available so we can check the blocklisting

Yeah, for tcmu-runner there will always be only one active LUN, so when another gateway is trying to access the ceph Rados that gateway will try to acquire the rbd exclusive lock from Rados and then Rados will blocklist current the lock owner. Please make sure the multiple path config is correct in initiator side, currently the ceph-iscsi couldn't do real AA, cu should make sure the path choice policy is ALUA.

Thanks.

@xiubo Li, Request you to provide the complete test steps to verify the BZ.

Hi Xiubo Li,

Following are the test steps performed for verifyigng the BZ - No issue was seen during the test.
1, Setup a ceph-iscsi cluster, which should include 2 gateways, and please enable the debug logs in tcmu-runner services in these two gateways
2, In the initiator side just use fio or other test tools write raw IOs to these two '/dev/sd{x}' scsi devices directly at the same time.
3, Run the test in Step2 for minutes or longer time to see whether could you see the crash
4, If you hit any crash again please provide the debug logs.

NOTE - 1) IOs against same image of different gateways path i.e /dev/sda and /dev/sdb were performed for few hours - Issue is not seen
- 2) Ran FIO against random luns for 5-6 hours and no issue were seen
FYI, Debug log was enabled and there was no seg fault/crash or any error noticed in the tcmu logs.

ceph version and tcmu snippet

[root@ceph-amk-upgrade-53-ga-s8g9v2-node1-installer cephuser]# rpm -qa | grep tcmu*
[root@ceph-amk-upgrade-53-ga-s8g9v2-node1-installer cephuser]# ceph version
ceph version 16.2.10-171.el8cp (00a157ecd158911ece116ae43095de793ed9f389) pacific (stable)

[root@ceph-amk-upgrade-53-ga-s8g9v2-node5 /]# rpm -qa | grep tcmu*
tcmu-runner-1.5.4-8.el8cp.x86_64
libtcmu-1.5.4-8.el8cp.x86_64

FIO workload used -  
fio --name=test-1 --numjobs=1 --rw=write/randwrite --bs=4/8/32k --iodepth=8 --fsync=32 --time_based --group_reporting --ioengine=libaio --filename=/dev/sda

(In reply to Preethi from comment #46)
> Hi Xiubo Li,
> 
> Following are the test steps performed for verifyigng the BZ - No issue was
> seen during the test.
> 1, Setup a ceph-iscsi cluster, which should include 2 gateways, and please
> enable the debug logs in tcmu-runner services in these two gateways
> 2, In the initiator side just use fio or other test tools write raw IOs to
> these two '/dev/sd{x}' scsi devices directly at the same time.
> 3, Run the test in Step2 for minutes or longer time to see whether could you
> see the crash
> 4, If you hit any crash again please provide the debug logs.
> 
> NOTE - 1) IOs against same image of different gateways path i.e /dev/sda and
> /dev/sdb were performed for few hours - Issue is not seen
> - 2) Ran FIO against random luns for 5-6 hours and no issue were seen
> FYI, Debug log was enabled and there was no seg fault/crash or any error
> noticed in the tcmu logs.
> 
> ceph version and tcmu snippet
> 
> [root@ceph-amk-upgrade-53-ga-s8g9v2-node1-installer cephuser]# rpm -qa |
> grep tcmu*
> [root@ceph-amk-upgrade-53-ga-s8g9v2-node1-installer cephuser]# ceph version
> ceph version 16.2.10-171.el8cp (00a157ecd158911ece116ae43095de793ed9f389)
> pacific (stable)
> 
> [root@ceph-amk-upgrade-53-ga-s8g9v2-node5 /]# rpm -qa | grep tcmu*
> tcmu-runner-1.5.4-8.el8cp.x86_64
> libtcmu-1.5.4-8.el8cp.x86_64
> 
> FIO workload used -  
> fio --name=test-1 --numjobs=1 --rw=write/randwrite --bs=4/8/32k --iodepth=8
> --fsync=32 --time_based --group_reporting --ioengine=libaio
> --filename=/dev/sda

Nice work Preeithi. 

Thanks very much for your tests.
- Xiubo

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Red Hat Ceph Storage 5.3 Bug Fix update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2023:3259