pktcdvd ->open_mutex lockdep splat

Hi all,

I noticed the splat below on one of my test VMs when running latest upstream with lockdep enabled. I'm not really sure why this occurs because I'm not actually using this device for anything I'm aware of. I suppose it's possible this has a busted userspace or kvm config, as this is just one of a handful of scratch VMs I have around for development purposes. I'm happy to try and dig further into it or just expunge it if this is of little interest.

FWIW, the splat itself reproduces back before ->open_mutex was created from bd_mutex by commit a8698707a183 ("block: move bd_mutex to struct gendisk"). I went as far back as v5.10 and still observed it.

Brian

--- 8< ---

[   11.667694] block (null): writer mapped to sr0

[   11.677407] ============================================
[   11.680650] WARNING: possible recursive locking detected
[   11.683581] 6.8.0+ #346 Tainted: G            E     
[   11.686246] --------------------------------------------
[   11.689075] systemd-udevd/1438 is trying to acquire lock:
[   11.690607] ffff8bb78f553cc8 (&disk->open_mutex){+.+.}-{3:3}, at: bdev_open+0x60/0x3e0
[   11.692504] 
               but task is already holding lock:
[   11.693921] ffff8bb786b39cc8 (&disk->open_mutex){+.+.}-{3:3}, at: bdev_open+0x239/0x3e0
[   11.695806] 
               other info that might help us debug this:
[   11.697362]  Possible unsafe locking scenario:

[   11.698779]        CPU0
[   11.699397]        ----
[   11.699994]   lock(&disk->open_mutex);
[   11.700923]   lock(&disk->open_mutex);
[   11.701849] 
                *** DEADLOCK ***

[   11.703273]  May be due to missing lock nesting notation

[   11.704878] 3 locks held by systemd-udevd/1438:
[   11.705967]  #0: ffff8bb786b39cc8 (&disk->open_mutex){+.+.}-{3:3}, at: bdev_open+0x239/0x3e0
[   11.707966]  #1: ffffffffc085c768 (pktcdvd_mutex){+.+.}-{3:3}, at: pkt_open+0x2b/0x630 [pktcdvd]
[   11.710080]  #2: ffffffffc085d868 (&ctl_mutex#2){+.+.}-{3:3}, at: pkt_open+0x39/0x630 [pktcdvd]
[   11.712164] 
               stack backtrace:
[   11.713200] CPU: 3 PID: 1438 Comm: systemd-udevd Tainted: G            E      6.8.0+ #346
[   11.715122] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014
[   11.717123] Call Trace:
[   11.717741]  <TASK>
[   11.718271]  dump_stack_lvl+0x79/0xb0
[   11.719194]  __lock_acquire+0x1228/0x2170
[   11.720172]  lock_acquire+0xbb/0x2c0
[   11.721030]  ? bdev_open+0x60/0x3e0
[   11.721869]  __mutex_lock+0x77/0xd40
[   11.722724]  ? bdev_open+0x60/0x3e0
[   11.723558]  ? find_held_lock+0x2b/0x80
[   11.724470]  ? bdev_open+0x56/0x3e0
[   11.725324]  ? bdev_open+0x60/0x3e0
[   11.726173]  ? bdev_open+0x60/0x3e0
[   11.727031]  bdev_open+0x60/0x3e0
[   11.727844]  bdev_file_open_by_dev+0xbf/0x120
[   11.728909]  pkt_open+0x10e/0x630 [pktcdvd]
[   11.729944]  ? bdev_open+0x22f/0x3e0
[   11.730815]  ? lock_release+0xb8/0x270
[   11.731729]  ? bdev_open+0x239/0x3e0
[   11.732605]  blkdev_get_whole+0x25/0x90
[   11.733544]  bdev_open+0x29f/0x3e0
[   11.734380]  ? iput.part.0+0x34/0x260
[   11.735277]  ? __pfx_blkdev_open+0x10/0x10
[   11.736282]  blkdev_open+0x8b/0xc0
[   11.737090]  do_dentry_open+0x172/0x580
[   11.738002]  path_openat+0x3a9/0xa30
[   11.738864]  do_filp_open+0xa1/0x130
[   11.739731]  ? _raw_spin_unlock+0x23/0x40
[   11.740700]  do_sys_openat2+0x82/0xb0
[   11.741596]  __x64_sys_openat+0x49/0x80
[   11.742529]  do_syscall_64+0x7c/0x190
[   11.743406]  entry_SYSCALL_64_after_hwframe+0x6c/0x74
[   11.744599] RIP: 0033:0x7f30e4afd70b
[   11.745450] Code: 25 00 00 41 00 3d 00 00 41 00 74 4b 64 8b 04 25 18 00 00 00 85 c0 75 67 44 89 e2 48 89 ee bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 91 00 00 00 48 8b 54 24 28 64 48 2b 14 25
[   11.749817] RSP: 002b:00007ffdafd13250 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
[   11.751633] RAX: ffffffffffffffda RBX: 0000000000006000 RCX: 00007f30e4afd70b
[   11.753306] RDX: 0000000000080900 RSI: 00007ffdafd132d0 RDI: 00000000ffffff9c
[   11.754966] RBP: 00007ffdafd132d0 R08: 0000000000000000 R09: 00007ffdafd13160
[   11.756624] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000080900
[   11.758311] R13: 0000000000080900 R14: 0000000000000006 R15: 00007ffdafd13470
[   11.760041]  </TASK>

Ok, I guess the reason I was only seeing this in one particular VM is that for whatever reason, something happens to invoke pktsetup during boot on that guest. If I boot up a separate VM/distro and run 'pktsetup 0 /dev/sr0,' I see the same splat..

Brian

pktcdvd is completely unmaintained and in horrible shape unfortunately, and no one is interested in caring for it.

I can only recommend to not build it into any kernel you can care about.

Heh, Ok thanks. I was poking around the code a bit just to try and figure if there was some easy/incremental improvement to be made here, but if so, I'm not familiar enough with the code to see it. I was particularly wondering why the multi-open occurs across the setup and pktcdvd device open and if that can be avoided. It looks like the main difference is the nonblock flag. From digging down into cdrom_open(), that is what controls whether or not the drive is opened for data or control purposes (i.e., so dictates whether media is read or not), and so that seems to explain why a blocking open would be deferred to pktcdvd device open.

Anyways, it does seem like the warning itself is benign because the pktcdvd and backing device will be separate disks.

Brian