[dm-devel] [QUESTION]: multipath device with wrong path lead to metadata err

Fri Feb 5 11:49:17 UTC 2021

Hi Martin,

I have removed multipathd_query in my test script. And a flock is added
before/after reonfigure() and  iscsi login/out.

Sequence of events:

(1)iscsi log out
/dev/sdi(36001405b7679bd96b094bccbf971bc90) is removed.

multipath -r:
sdi->fd is closed.
ref of sdi becomes 0.

(2)iscsi log in
/dev/sdi(3600140531f063b3e19349bc82028e0cc) is added.

(3)multipath -r:
/dev/sdi is discovered but added to 36001405b7679bd96b094bccbf971bc90.

This is very confusing. The reason I can think of is that get_uid() in
pathinfo() gets the wrong wwid.

What do you think of this phenomenon?

Regards,
Lixiaokeng

The kernel log:
84087 Feb  5 16:13:12 client1 kernel: [618082.728130] sd 1:0:0:2: [sdi] Synchronizing SCSI cache

multipath -r (first)
84103 Feb  5 16:13:12 client1 kernel: [618082.992107] lxk kernel params 0 1 alua 1 1 service-time 0 1 1 8:96 1
84104 Feb  5 16:13:12 client1 kernel: [618082.992109] name dm-6; majir:minor 253:6; dm-6

84153 Feb  5 16:13:12 client1 kernel: [618083.244950] sd 2:0:0:1: [sdi] Attached SCSI disk

multipath -r (second)
84200 Feb  5 16:13:12 client1 kernel: [618084.453983] lxk kernel params 0 1 alua 1 1 service-time 0 1 1 8:128 1
84201 Feb  5 16:13:12 client1 kernel: [618084.453985] name dm-6; majir:minor 253:6; dm-6

The userspace log:
multipath -r (first)
 84334 Feb  5 16:13:12 client1 multipathd[3816730]: lock .mul_iscsi.lock
 84335 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405ca5165367d67447ea68108e1d: remove multipath map
 84336 Feb  5 16:13:12 client1 multipathd[3816730]: sdh: orphan path, map flushed
 84337 Feb  5 16:13:12 client1 multipathd[3816730]: BUG: orphaning path sdh that holds hwe of 36001405ca5165367d67447ea68108e1d
 84338 Feb  5 16:13:12 client1 multipathd[3816730]: close sdh pp->fd
 84339 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140531f063b3e19349bc82028e0cc: remove multipath map
 84340 Feb  5 16:13:12 client1 multipathd[3816730]: sdj: orphan path, map flushed
 84341 Feb  5 16:13:12 client1 multipathd[3816730]: BUG: orphaning path sdj that holds hwe of 3600140531f063b3e19349bc82028e0cc
 84342 Feb  5 16:13:12 client1 multipathd[3816730]: close sdj pp->fd
 84343 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140584e11eb1818c4afab12c17800: remove multipath map
 84344 Feb  5 16:13:12 client1 multipathd[3816730]: sde: orphan path, map flushed
 84345 Feb  5 16:13:12 client1 multipathd[3816730]: BUG: orphaning path sde that holds hwe of 3600140584e11eb1818c4afab12c17800
 84346 Feb  5 16:13:12 client1 multipathd[3816730]: close sde pp->fd
 84347 Feb  5 16:13:12 client1 systemd[3714763]: opt-test-3600140584e11eb1818c4afab12c17800.mount: Succeeded.
 84348 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: remove multipath map
 84349 Feb  5 16:13:12 client1 systemd[1]: opt-test-3600140584e11eb1818c4afab12c17800.mount: Succeeded.
 84350 Feb  5 16:13:12 client1 multipathd[3816730]: sdi: orphan path, map flushed
 84351 Feb  5 16:13:12 client1 multipathd[3816730]: BUG: orphaning path sdi that holds hwe of 36001405b7679bd96b094bccbf971bc90
 84352 Feb  5 16:13:12 client1 multipathd[3816730]: close sdi pp->fd
 84353 Feb  5 16:13:12 client1 multipathd[3816730]: 8:144: cannot find block device
 84354 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140531f063b3e19349bc82028e0cc: remove multipath map
 84355 Feb  5 16:13:12 client1 multipathd[3816730]: 8:112: cannot find block device
 84356 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405ca5165367d67447ea68108e1d: remove multipath map
 84357 Feb  5 16:13:12 client1 multipathd[3816730]: 8:64: cannot find block device
 84358 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140584e11eb1818c4afab12c17800: remove multipath map
 84359 Feb  5 16:13:12 client1 multipathd[3816730]: 8:128: cannot find block device
 84360 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: remove multipath map
 84361 Feb  5 16:13:12 client1 multipathd[3816730]: sda: orphan path, blacklisted
 84362 Feb  5 16:13:12 client1 multipathd[3816730]: sdb: orphan path, blacklisted
 84363 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140584e11eb1818c4afab12c17800: set ACT_CREATE (map does not exist)
 84364 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140584e11eb1818c4afab12c17800: load table [0 20971520 multipath 0 1 alua 1 1 service-time 0 1 1 8:32 1]
 84365 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: set ACT_CREATE (map does not exist)
 84366 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: load table [0 20971520 multipath 0 1 alua 1 1 service-time 0 1 1 8:96 1]
 84367 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405ca5165367d67447ea68108e1d: set ACT_CREATE (map does not exist)
 84368 Feb  5 16:13:12 client1 iscsid[294822]: Connection61647:0 to [target: iqn.2003-01.org.linux-iscsi.openeuler.aarch64:sn.155b59349631, portal: 100.1.2.1,3260] through [iface: default] is shutdown.
 84369 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405ca5165367d67447ea68108e1d: load table [0 20971520 multipath 0 1 alua 1 1 service-time 0 1 1 8:48 1]
 84370 Feb  5 16:13:12 client1 multipathd[3816730]: lock .mul_iscsi.lock
 84371 Feb  5 16:13:12 client1 multipath[73791]: lock .mul_iscsi.lock

multipath -r (second)
 84439 Feb  5 16:13:12 client1 multipathd[3816730]: reconfigure (operator)
 84440 Feb  5 16:13:12 client1 multipath[73858]: loading /lib64/multipath/libchecktur.so checker
 84441 Feb  5 16:13:12 client1 multipathd[3816730]: lock .mul_iscsi.lock
 84442 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140584e11eb1818c4afab12c17800: remove multipath map
 84443 Feb  5 16:13:12 client1 multipathd[3816730]: sdc: orphan path, map flushed
 84444 Feb  5 16:13:12 client1 multipathd[3816730]: BUG: orphaning path sdc that holds hwe of 3600140584e11eb1818c4afab12c17800
 84445 Feb  5 16:13:12 client1 multipathd[3816730]: close sdc pp->fd
 84446 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: remove multipath map
 84447 Feb  5 16:13:12 client1 multipathd[3816730]: sdg: orphan path, map flushed
 84448 Feb  5 16:13:12 client1 multipathd[3816730]: BUG: orphaning path sdg that holds hwe of 36001405b7679bd96b094bccbf971bc90
 84449 Feb  5 16:13:12 client1 multipathd[3816730]: close sdg pp->fd
 84450 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405ca5165367d67447ea68108e1d: remove multipath map
 84451 Feb  5 16:13:12 client1 multipathd[3816730]: sdd: orphan path, map flushed
 84452 Feb  5 16:13:12 client1 multipathd[3816730]: BUG: orphaning path sdd that holds hwe of 36001405ca5165367d67447ea68108e1d
 84453 Feb  5 16:13:12 client1 multipathd[3816730]: close sdd pp->fd
 84454 Feb  5 16:13:12 client1 multipathd[3816730]: 8:144: cannot find block device
 84455 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140531f063b3e19349bc82028e0cc: remove multipath map
 84456 Feb  5 16:13:12 client1 multipathd[3816730]: 8:48: cannot find block device
 84457 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405ca5165367d67447ea68108e1d: remove multipath map
 84458 Feb  5 16:13:12 client1 multipathd[3816730]: 8:32: cannot find block device
 84459 Feb  5 16:13:12 client1 multipathd[3816730]: 3600140584e11eb1818c4afab12c17800: remove multipath map
 84460 Feb  5 16:13:12 client1 multipathd[3816730]: 8:96: cannot find block device
 84461 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: remove multipath map
 84462 Feb  5 16:13:12 client1 multipathd[3816730]: sda: orphan path, blacklisted
 84463 Feb  5 16:13:12 client1 multipathd[3816730]: sdb: orphan path, blacklisted
 84464 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: set ACT_CREATE (map does not exist)
 84465 Feb  5 16:13:12 client1 multipathd[3816730]: 36001405b7679bd96b094bccbf971bc90: load table [0 20971520 multipath 0 1 alua 1 1 service-time 0 1 1 8:128 1]
 84466 Feb  5 16:13:12 client1 multipathd[3816730]: lock .mul_iscsi.lock