Hi,
when running the dev_addr_lists unit test with lock debugging enabled,
I always get the following lockdep warning.
[ 7.031327] ====================================
[ 7.031393] WARNING: kunit_try_catch/1886 still has locks held!
[ 7.031478] 6.8.0-rc6-00053-g0fec7343edb5-dirty #1 Tainted: G W N
[ 7.031728] ------------------------------------
[ 7.031816] 1 lock held by kunit_try_catch/1886:
[ 7.031896] #0: ffffffff8ed35008 (rtnl_mutex){+.+.}-{3:3}, at: dev_addr_test_init+0x6a/0x100
Instrumentation shows that dev_addr_test_exit() is called, but only
after the warning fires.
Is this a problem with kunit tests or a problem with this specific test ?
Thanks,
Guenter
On Thu, 29 Feb 2024 at 03:45, Guenter Roeck <[email protected]> wrote:
>
> Hi,
>
> when running the dev_addr_lists unit test with lock debugging enabled,
> I always get the following lockdep warning.
>
> [ 7.031327] ====================================
> [ 7.031393] WARNING: kunit_try_catch/1886 still has locks held!
> [ 7.031478] 6.8.0-rc6-00053-g0fec7343edb5-dirty #1 Tainted: G W N
> [ 7.031728] ------------------------------------
> [ 7.031816] 1 lock held by kunit_try_catch/1886:
> [ 7.031896] #0: ffffffff8ed35008 (rtnl_mutex){+.+.}-{3:3}, at: dev_addr_test_init+0x6a/0x100
>
> Instrumentation shows that dev_addr_test_exit() is called, but only
> after the warning fires.
>
> Is this a problem with kunit tests or a problem with this specific test ?
A bit of both, I think. KUnit test cleanup is not guaranteed to run in
the same thread as the test, so that definitely is triggering lockdep
warnings.
On the other hand, we really should make this particular case work in
KUnit. Ideally test cleanup will happen on the test thread first, and
only fall back to another test if the test thread otherwise aborted.
So, this is probably something we won't be able to fix if the test
fails, but it definitely shouldn't be happening here where it passes.
I'll look into fixing that.
-- David
On 2/29/24 00:10, David Gow wrote:
> On Thu, 29 Feb 2024 at 03:45, Guenter Roeck <[email protected]> wrote:
>>
>> Hi,
>>
>> when running the dev_addr_lists unit test with lock debugging enabled,
>> I always get the following lockdep warning.
>>
>> [ 7.031327] ====================================
>> [ 7.031393] WARNING: kunit_try_catch/1886 still has locks held!
>> [ 7.031478] 6.8.0-rc6-00053-g0fec7343edb5-dirty #1 Tainted: G W N
>> [ 7.031728] ------------------------------------
>> [ 7.031816] 1 lock held by kunit_try_catch/1886:
>> [ 7.031896] #0: ffffffff8ed35008 (rtnl_mutex){+.+.}-{3:3}, at: dev_addr_test_init+0x6a/0x100
>>
>> Instrumentation shows that dev_addr_test_exit() is called, but only
>> after the warning fires.
>>
>> Is this a problem with kunit tests or a problem with this specific test ?
>
> A bit of both, I think. KUnit test cleanup is not guaranteed to run in
> the same thread as the test, so that definitely is triggering lockdep
> warnings.
>
> On the other hand, we really should make this particular case work in
> KUnit. Ideally test cleanup will happen on the test thread first, and
> only fall back to another test if the test thread otherwise aborted.
>
> So, this is probably something we won't be able to fix if the test
> fails, but it definitely shouldn't be happening here where it passes.
> I'll look into fixing that.
>
Here is a different warning, from the same test:
[ 10.622270] =====================================
[ 10.622346] WARNING: bad unlock balance detected!
[ 10.622481] 6.8.0-rc6 #1 Tainted: G N
[ 10.622624] -------------------------------------
[ 10.622698] kunit_try_catch/1354 is trying to release lock (rtnl_mutex) at:
[ 10.623123] [<ffffd7c5cbdb75cc>] __rtnl_unlock+0x3c/0x84
[ 10.623538] but there are no more locks to release!
That seems to be kind of the opposite problem. I noticed this only
once in my tests, so it is much rarer than the other warning.
Guenter
On 2/29/24 00:10, David Gow wrote:
> On Thu, 29 Feb 2024 at 03:45, Guenter Roeck <[email protected]> wrote:
>>
>> Hi,
>>
>> when running the dev_addr_lists unit test with lock debugging enabled,
>> I always get the following lockdep warning.
>>
>> [ 7.031327] ====================================
>> [ 7.031393] WARNING: kunit_try_catch/1886 still has locks held!
>> [ 7.031478] 6.8.0-rc6-00053-g0fec7343edb5-dirty #1 Tainted: G W N
>> [ 7.031728] ------------------------------------
>> [ 7.031816] 1 lock held by kunit_try_catch/1886:
>> [ 7.031896] #0: ffffffff8ed35008 (rtnl_mutex){+.+.}-{3:3}, at: dev_addr_test_init+0x6a/0x100
>>
>> Instrumentation shows that dev_addr_test_exit() is called, but only
>> after the warning fires.
>>
>> Is this a problem with kunit tests or a problem with this specific test ?
>
> A bit of both, I think. KUnit test cleanup is not guaranteed to run in
> the same thread as the test, so that definitely is triggering lockdep
> warnings.
>
> On the other hand, we really should make this particular case work in
> KUnit. Ideally test cleanup will happen on the test thread first, and
> only fall back to another test if the test thread otherwise aborted.
>
> So, this is probably something we won't be able to fix if the test
> fails, but it definitely shouldn't be happening here where it passes.
> I'll look into fixing that.
>
Other tests seem to have similar problems with locking:
[ 25.762445] # Subtest: drm_vc4_test_pv_muxing
[ 25.845857] [drm] Initialized vc4 0.0.0 20140616 for drm_vc4_test_pv_muxing.drm-kunit-mock-device on minor 0
[ 25.859603]
[ 25.859867] ====================================
[ 25.860085] WARNING: kunit_try_catch/1729 still has locks held!
[ 25.860354] 6.8.0-rc6-00066-g1c8c39f56e47-dirty #1 Tainted: G W N
[ 25.860675] ------------------------------------
[ 25.860918] 2 locks held by kunit_try_catch/1729:
[ 25.865468] #0: ffff17e04945d850 (crtc_ww_class_acquire){+.+.}-{0:0}, at: drm_kunit_helper_acquire_ctx_alloc+0x44/0xd4
[ 25.866383] #1: ffff17e047042518 (crtc_ww_class_mutex){+.+.}-{3:3}, at: modeset_lock.part.0+0x134/0x1d0
Guenter