27 Apr
2020
27 Apr
'20
3:43 p.m.
Hi;
I've build two iscsi gateway for our (small) ceph cluster.The cluster is a nautilus
installation, 4
nodes with 9x4TB each, and it's working fine. We mainly use it via s3 object storage
interface,
but I've deployed also some rbd block devices and a cephfs filesystem.
Now I'm trying to connect it to my xenserver installation. Xenserver doesn't speak
rados, so
I've build the iscsi gateways. Right now they are self-hosted on the xenserver, with
plan to
move them into physical boxes if/when needed.
The gateways are build on centos8, tcmu-runner just cloned from git (I think it's
1.5.2). I've
been able to connect them to our six nodes xenserver cluster, and now I'm trying to
use it.
When I attempt a migration of a VM disk, on the new iscsi volume, I've got these
messages
on the logfile that I find very worrying:
Apr 27 17:32:21 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:22 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:22 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:25 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:25 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:26 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:26 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:27 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:27 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:28 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:28 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:29 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:29 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:30 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:30 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:31 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:31 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:32 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:32 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:33 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:33 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:34 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:34 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:36 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
After a while the migration fails, and I keep seend the error on the logs:
Apr 27 17:36:01 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:06 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:08 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:09 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:16 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:21 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:21 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:26 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:28 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:29 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:36 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Any hints? Is this a bug?
--
*Simone Lazzaris*
*Qcom S.p.A. a socio unico*
simone.lazzaris(a)qcom.it[1] | www.qcom.it[2]
* LinkedIn[3]* | *Facebook[4]*
[5]
27 Apr
27 Apr
4:46 p.m.
On 4/27/20 10:43 AM, Simone Lazzaris wrote:
Hi;
I've build two iscsi gateway for our (small) ceph cluster.The cluster is a nautilus
installation, 4
nodes with 9x4TB each, and it's working fine. We mainly use it via s3 object storage
interface,
but I've deployed also some rbd block devices and a cephfs filesystem.
Now I'm trying to connect it to my xenserver installation. Xenserver doesn't
speak rados, so
I've build the iscsi gateways. Right now they are self-hosted on the xenserver, with
plan to
move them into physical boxes if/when needed.
The gateways are build on centos8, tcmu-runner just cloned from git (I think it's
1.5.2). I've
been able to connect them to our six nodes xenserver cluster, and now I'm trying to
use it.
Are you using the ceph-iscsi tools with tcmu-runner or did you setup
tcmu-runner directly with targetcli?
When I attempt a migration of a VM disk, on the new
iscsi volume, I've got these messages
on the logfile that I find very worrying:
Apr 27 17:32:21 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:22 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:22 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
You would see these:
1. when paths are discovered initially. The initiator is sending IO to
all paths at the same time, so the lock is bouncing between all the paths.
You should only see this for 10-60 seconds depending on how many paths
you have, number of nodes, etc. When the multipath layer kicks in and
adds the paths to the dm-multipath device then they should stop.
2. during failover/failback when the multipath layer switches paths and
one path takes the lock from the previously used one.
Or, if you exported a disk to multiple initiator nodes, and some
initiator nodes can't reach the active optimized path, so some
initiators are using the optimized path and some are using the
non-optimized path.
3. If you have misconfigured the system. If you used active/active or
had initiator nodes discover different paths for the same disk or not
log into all the paths.
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]:
alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:23 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:25 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:25 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:26 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:26 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:27 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:27 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:28 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:28 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:29 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:29 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:30 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:30 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:31 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:31 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:32 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:32 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:33 iscsi2 tcmu-runner[2344]: tcmu_notify_lock_lost:222
rbd/rbdindex0.scsidisk0:
Async lock drop. Old state 1
Apr 27 17:32:33 iscsi2 tcmu-runner[2344]: alua_implicit_transition:574 rbd/
rbdindex0.scsidisk0: Starting lock acquisition operation.
Apr 27 17:32:34 iscsi2 tcmu-runner[2344]: tcmu_rbd_lock:762 rbd/rbdindex0.scsidisk0:
Acquired exclusive lock.
Apr 27 17:32:34 iscsi2 tcmu-runner[2344]: tcmu_acquire_dev_lock:441 rbd/
rbdindex0.scsidisk0: Lock acquisition successful
Apr 27 17:32:36 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
After a while the migration fails, and I keep seend the error on the logs:
Apr 27 17:36:01 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
What are you using for path_checker in /etc/multipath.conf on the
initiator side?
This is a bug but can be ignored. I am working on a fix. Basically, we
the multipath layer is checking our state. We report we do not have the
lock correctly to the initiator, but we also get this log message over
and over when the multipath layer sends its path checker command.
Apr 27 17:36:06 iscsi2 tcmu-runner[2344]:
tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:08 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:09 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:16 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:21 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:21 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:26 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:28 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:29 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Apr 27 17:36:36 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516 rbd/rbdindex0.scsidisk0:
Could not check lock ownership. Error: Cannot send after transport endpoint shutdown.
Any hints? Is this a bug?
--
*Simone Lazzaris*
*Qcom S.p.A. a socio unico*
simone.lazzaris(a)qcom.it[1] | www.qcom.it[2]
* LinkedIn[3]* | *Facebook[4]*
[5]
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
28 Apr
28 Apr
7:21 a.m.
In data lunedì 27 aprile 2020 18:46:09 CEST, Mike Christie ha scritto:
[snip]
path_checker is set to "tur".
Are you using the ceph-iscsi tools with tcmu-runner or
did you setup
tcmu-runner directly with targetcli?
I followed this guide: https://docs.ceph.com/docs/master//rbd/iscsi-target-cli/[1]
and
configured the target with gwcli, so I think I'm using ceph-iscsi tools.
[snip]
You would see these:
1. when paths are discovered initially. The initiator is sending IO to
all paths at the same time, so the lock is bouncing between all the paths.
Ok, but the nodes are already configured and all path discovered. So that's not the
case.
You should only see this for 10-60 seconds depending
on how many paths
you have, number of nodes, etc. When the multipath layer kicks in and
adds the paths to the dm-multipath device then they should stop.
I have NO such logs when the system is running unless I start USING the luns
2. during failover/failback when the multipath layer
switches paths and
one path takes the lock from the previously used one.
No failover/failback is occuring.
Or, if you exported a disk to multiple initiator
nodes, and some
initiator nodes can't reach the active optimized path, so some
initiators are using the optimized path and some are using the
non-optimized path.
I do have exported the disk to multiple initiator nodes. How can I tell if they are using
all the
active path?
3. If you have misconfigured the system. If you used
active/active or
had initiator nodes discover different paths for the same disk or not
log into all the paths.
That may be the case, as I don't have much experience with multipath. Anyway,
following the
ceph guide, I've setup the device in /etc/multipath.conf like this:
device {
vendor "LIO-ORG"
product ".*"
path_grouping_policy "failover"
path_selector "queue-length 0"
path_checker "tur"
hardware_handler "1 alua"
prio "alua"
prio_args "exclusive_pref_bit"
failback 60
no_path_retry "queue"
fast_io_fail_tmo 25
}
and multipath -ll show this on all the six nodes:
36001405d7480e5f84b94ab19ebeebd6c dm-1 LIO-ORG ,TCMU device
size=1.0T features='1 queue_if_no_path' hwhandler='1 alua' wp=rw
|-+- policy='queue-length 0' prio=50 status=active
| `- 16:0:0:0 sdb 8:16 active ready running
`-+- policy='queue-length 0' prio=10 status=enabled
`- 15:0:0:0 sdc 8:32 active ready running
Al all nodes, one path (sdb 8:16) is always "active" with prio 50 and the other
(sdc 8:32) is
always "enabled" with prio 10. I haven't figured out how can I check which
iscsi-gateway is
mapped to the "active" path...
[snip]
Apr 27
17:36:01 iscsi2 tcmu-runner[2344]: tcmu_rbd_has_lock:516
rbd/rbdindex0.scsidisk0: Could not check lock ownership. Error: Cannot
send after transport endpoint shutdown.
What are you using for path_checker in
/etc/multipath.conf on the
initiator side? This is a bug but can be ignored. I am working on a
fix. Basically, we
the multipath layer is checking our state. We report we do not have the
lock correctly to the initiator, but we also get this log message over
and over when the multipath layer sends its path checker command.
And that's ok...
Thanks for all the help you can provide!
*Simone Lazzaris*
*Qcom S.p.A. a socio unico*
simone.lazzaris(a)qcom.it[2] | www.qcom.it[3]
* LinkedIn[4]* | *Facebook[5]*
[6]
--------
[1] https://docs.ceph.com/docs/master//rbd/iscsi-target-cli/
[2] mailto:simone.lazzaris@qcom.it
[3] https://www.qcom.it
[4] https://www.linkedin.com/company/qcom-spa
[5] http://www.facebook.com/qcomspa
[6] https://www.qcom.it/pdf/other/bannerfirmamail.gif
4:41 p.m.
On 4/28/20 2:21 AM, Simone Lazzaris wrote:
For linux's multipath-tools prio=50 is the active optimized (AO) path.
prio=10 is the active non-optimized (ANO) path. The prio=50 one should
be the one with status=active.
To map that to an iscsi gateway then you can do the following.
If sdb is the AO one, then run
iscsiadm -m session -P 3
Here you can see the sdXYZ name to iscsi session mapping. The iscsi
session/connection's target IP address from that command should match to
the gateway that is listed as the "owner" of the LUN in the "gwcli
ls"
output.
In data lunedì 27 aprile 2020 18:46:09 CEST, Mike
Christie ha scritto:
[snip]
I followed this guide:
https://docs.ceph.com/docs/master//rbd/iscsi-target-cli/ and configured
the target with gwcli, so I think I'm using ceph-iscsi tools.
[snip]
Could you send me:
1. The /var/log/messages for the initiator when you do IO and see those
lock messages.
2. The output of
From one of the gateways:
# gwcli ls
From the initiator node you send the /var/log/messages for:
# iscsiadm -m session -P 3
# multipath -ll
3. version info:
# uname -a
If you using rpm do:
# rpm -q ceph-iscsi
# rpm -q tcmu-runner
# rpm -q python-rtslib
Are you using the ceph-iscsi tools with
tcmu-runner or did you setup
tcmu-runner directly with targetcli?
You would see these:
1. when paths are discovered initially. The
initiator is sending IO to
all paths at the same time, so the lock is
bouncing between all the paths.
Ok, but the nodes are already configured and all path discovered. So
that's not the case.
You should only see this for 10-60 seconds
depending on how many paths
you have, number of nodes, etc. When the
multipath layer kicks in and
adds the paths to the dm-multipath device then
they should stop.
I have NO such logs when the system is running unless I start USING the
luns
2. during failover/failback when the multipath
layer switches paths and
one path takes the lock from the previously used
one.
No failover/failback is occuring.
Or, if you exported a disk to multiple initiator
nodes, and some
initiator nodes can't reach the active
optimized path, so some
initiators are using the optimized path and some
are using the
non-optimized path.
I do have exported the disk to multiple initiator nodes. How can I tell
if they are using all the active path?
29 Apr
29 Apr
7:11 a.m.
In data martedì 28 aprile 2020 18:41:27 CEST, Mike Christie ha scritto:
Could you send me:
1. The /var/log/messages for the initiator when you do IO and see those
lock messages.
On the initiator (XenServer 7.1 which is based on CentOS AFAIK) the /var/log/messages is
empty.
I (sporadicly) see:
Apr 29 09:00:36 xs-n1 systemd[1]: Starting Multipath Count Service...
Apr 29 09:00:36 xs-n1 systemd[1]: Started Multipath Count Service.
Apr 29 09:00:36 xs-n1 systemd[1]: Started Session 146 of user root.
Apr 29 09:00:36 xs-n1 systemd[1]: Starting Session 146 of user root.
Apr 29 09:00:40 xs-n1 multipathd: dm-3: remove map (uevent)
Apr 29 09:00:40 xs-n1 multipathd: dm-3: devmap not registered, can't remove
Apr 29 09:00:40 xs-n1 multipathd: dm-3: remove map (uevent)
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="PBD.get_all_records"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen] mpathalert=>xapi
[label="host.get_all_records"];
2. The output of
From one of the gateways:
# gwcli ls
Attached (gwcli.txt)
From the initiator node you send the /var/log/messages
for:
# iscsiadm -m session -P 3
attacched (iscsi-session.txt)
# multipath -ll
36001405d7480e5f84b94ab19ebeebd6c dm-0 LIO-ORG ,TCMU device
size=3.0T features='1 queue_if_no_path' hwhandler='1 alua' wp=rw
|-+- policy='queue-length 0' prio=50 status=active
| `- 2:0:0:0 sdc 8:32 active ready running
`-+- policy='queue-length 0' prio=10 status=enabled
`- 3:0:0:0 sdb 8:16 active ready running
3. version info:
# uname -a
On the Initiator:
Linux xs-n1 4.4.0+2 #1 SMP Thu Jun 15 16:38:02 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
On the Target:
Linux iscsi1 4.18.0-147.8.1.el8_1.x86_64 #1 SMP Thu Apr 9 13:49:54 UTC 2020 x86_64 x86_64
x86_64 GNU/Linux
If you using rpm do:
# rpm -q ceph-iscsi
# rpm -q tcmu-runner
# rpm -q python-rtslib
No, I've installed them from source on the target
To map that to an iscsi gateway then you can do the
following.
If sdb is the AO one, then run
iscsiadm -m session -P 3
Here you can see the sdXYZ name to iscsi session mapping. The iscsi
session/connection's target IP address from that command should match to
the gateway that is listed as the "owner" of the LUN in the "gwcli
ls"
output.
I see... thanks for the hint.
I've done a test: I've unmapped all the drive, then mapped the first gateway
(iscsi1) on all the
nodes, waited, then mapped the second gateway, to be sure that all the nodes would see the
first node as the active/master one.
Now things seems a little better in "normal" vm use: I only see the "Cannot
send after
transport endpoint shutdown." on the secondary target node.
I do see some hopping between the nodes when importing a disk drive, but at this point
I'm
starting to suspect some strange activity from the Xen infrastructure in that
circumstance.
--
*Simone Lazzaris*
*Qcom S.p.A. a socio unico*
3:47 p.m.
On 4/29/20 2:11 AM, Simone Lazzaris wrote:
* LinkedIn <https://www.linkedin.com/company/qcom-spa>* | *Facebook*
<http://www.facebook.com/qcomspa
In data martedì 28 aprile 2020 18:41:27 CEST, Mike
Christie ha scritto:
Attached (gwcli.txt)
36001405d7480e5f84b94ab19ebeebd6c dm-0 LIO-ORG ,TCMU device
size=3.0T features='1 queue_if_no_path' hwhandler='1 alua' wp=rw
|-+- policy='queue-length 0' prio=50 status=active
| `- 2:0:0:0 sdc 8:32 active ready running
`-+- policy='queue-length 0' prio=10 status=enabled
`- 3:0:0:0 sdb 8:16 active ready running
No, I've installed them from source on the target
What version of tcmu-runner did you use? Was it one of the 1.4 or 1.5
releases or from the github master branch?
There was a bug in the older 1.4 release where due to a linux kernel
initiator side change the behavior for an error code we used went from
retrying for up to 5 minutes to 5 times. The 5 retries were then used in
less than a second, so we could see the issue you are seeing.
Could you send me:
1. The /var/log/messages for the initiator when
you do IO and see those
lock messages.
On the initiator (XenServer 7.1 which is based on CentOS AFAIK) the
/var/log/messages is empty.
I (sporadicly) see:
Apr 29 09:00:36 xs-n1 systemd[1]: Starting Multipath Count Service...
Apr 29 09:00:36 xs-n1 systemd[1]: Started Multipath Count Service.
Apr 29 09:00:36 xs-n1 systemd[1]: Started Session 146 of user root.
Apr 29 09:00:36 xs-n1 systemd[1]: Starting Session 146 of user root.
Apr 29 09:00:40 xs-n1 multipathd: dm-3: remove map (uevent)
Apr 29 09:00:40 xs-n1 multipathd: dm-3: devmap not registered, can't remove
Apr 29 09:00:40 xs-n1 multipathd: dm-3: remove map (uevent)
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="PBD.get_all_records"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_uuid"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_name_label"];
Apr 29 09:00:40 xs-n1 mpathalert: [debug|xs-n1|2 ||mscgen]
mpathalert=>xapi [label="host.get_all_records"];
2. The output of
From one of the gateways:
# gwcli ls
From the initiator node you send the
/var/log/messages for:
# iscsiadm -m session -P 3
attacched (iscsi-session.txt)
# multipath -ll
3. version info:
# uname -a
On the Initiator:
Linux xs-n1 4.4.0+2 #1 SMP Thu Jun 15 16:38:02 UTC 2017 x86_64 x86_64
x86_64 GNU/Linux
On the Target:
Linux iscsi1 4.18.0-147.8.1.el8_1.x86_64 #1 SMP Thu Apr 9 13:49:54 UTC
2020 x86_64 x86_64 x86_64 GNU/Linux
If you using rpm do:
# rpm -q ceph-iscsi
# rpm -q tcmu-runner
# rpm -q python-rtslib
To map that to an iscsi gateway then you can do
the following.
If sdb is the AO one, then run
iscsiadm -m session -P 3
Here you can see the sdXYZ name to iscsi session
mapping. The iscsi
session/connection's target IP address from
that command should match to
the gateway that is listed as the
"owner" of the LUN in the "gwcli ls"
output.
I see... thanks for the hint.
I've done a test: I've unmapped all the drive, then mapped the first
gateway (iscsi1) on all the nodes, waited, then mapped the second
gateway, to be sure that all the nodes would see the first node as the
active/master
Now things seems a little better in "normal" vm use: I only see the
"Cannot send after transport endpoint shutdown." on the secondary target
node.
I do see some hopping between the nodes when importing a disk drive, but
at this point I'm starting to suspect some strange activity from the Xen
infrastructure in that circumstance.
--
*Simone Lazzaris*
*Qcom S.p.A. a socio unico*
simone.lazzaris(a)qcom.it <mailto:simone.lazzaris@qcom.it> | www.qcom.it
<https://www.qcom.it
4:10 p.m.
What version of tcmu-runner did you use? Was it one of the 1.4 or 1.5
releases or from the github master branch?
There was a bug in the older 1.4 release where due to a linux kernel
initiator side change the behavior for an error code we used went from
retrying for up to 5 minutes to 5 times. The 5 retries were then used in
less than a second, so we could see the issue you are seeing.
I've done a
git clone https://github.com/open-iscsi/tcmu-runner
In version.h i see:
#define TCMUR_VERSION "1.5.2"
So I think I'm using the latest source available.
*Simone Lazzaris*
*Qcom S.p.A. a socio unico*
simone.lazzaris(a)qcom.it[1] | www.qcom.it[2]
* LinkedIn[3]* | *Facebook*[4]
[5]
--------
[1] mailto:simone.lazzaris@qcom.it
[2] https://www.qcom.it
[3] https://www.linkedin.com/company/qcom-spa
[4] http://www.facebook.com/qcomspa
[5] https://www.qcom.it/pdf/other/bannerfirmamail.gif
28 Apr
28 Apr
7:55 a.m.
You can check the lock lists on each rbd and you can try removing the lock but only when
the vm is shutdown and rbd is not used
rbd lock list pool/volume-id
rbd lock rm pool/volume-id "lock_id" client_id
This was a bug in luminous upgrade i believe and i found it back in the days from this
article but seems the link doesn't work now
https://der-jd.de/blog/2018/12/27/openstack-ceph-luminous-upgrade.html
1460
days inactive
1462
days old
7 comments
3 participants
participants (3)
-
Mike Christie -
Simone Lazzaris -
tdados＠hotmail.com