Re: Persistent problem with handshake unit tests

[Guenter Roeck <linux@roeck-us.net>]

On 2/6/24 08:47, Chuck Lever wrote:
> On Fri, Feb 02, 2024 at 09:21:22AM -0800, Guenter Roeck wrote:
>> Hi,
>>
>> when running handshake kunit tests in qemu, I always get the following
>> failure.
>>
>>      KTAP version 1
>>      # Subtest: Handshake API tests
>>      1..11
>>          KTAP version 1
>>          # Subtest: req_alloc API fuzzing
>>          ok 1 handshake_req_alloc NULL proto
>>          ok 2 handshake_req_alloc CLASS_NONE
>>          ok 3 handshake_req_alloc CLASS_MAX
>>          ok 4 handshake_req_alloc no callbacks
>>          ok 5 handshake_req_alloc no done callback
>>          ok 6 handshake_req_alloc excessive privsize
>>          ok 7 handshake_req_alloc all good
>>      # req_alloc API fuzzing: pass:7 fail:0 skip:0 total:7
>>      ok 1 req_alloc API fuzzing
>>      ok 2 req_submit NULL req arg
>>      ok 3 req_submit NULL sock arg
>>      ok 4 req_submit NULL sock->file
>>      ok 5 req_lookup works
>>      ok 6 req_submit max pending
>>      ok 7 req_submit multiple
>>      ok 8 req_cancel before accept
>>      ok 9 req_cancel after accept
>>      ok 10 req_cancel after done
>>      # req_destroy works: EXPECTATION FAILED at net/handshake/handshake-test.c:478
>>      Expected handshake_req_destroy_test == req, but
>>          handshake_req_destroy_test == 00000000
>>          req == c5080280
>>      not ok 11 req_destroy works
>> # Handshake API tests: pass:10 fail:1 skip:0 total:11
>> # Totals: pass:16 fail:1 skip:0 total:17
>> not ok 31 Handshake API tests
>> ############## destroy 0xc5080280
>> ...
>>
>> The line starting with "#######" is from added debug information.
>>
>> diff --git a/net/handshake/handshake-test.c b/net/handshake/handshake-test.c
>> index 16ed7bfd29e4..a2417c56fe15 100644
>> --- a/net/handshake/handshake-test.c
>> +++ b/net/handshake/handshake-test.c
>> @@ -434,6 +434,7 @@ static struct handshake_req *handshake_req_destroy_test;
>>
>>   static void test_destroy_func(struct handshake_req *req)
>>   {
>> +       pr_info("############## destroy 0x%px\n", req);
>>          handshake_req_destroy_test = req;
>>   }
>>
>> It appears that the destroy function works, but is delayed. Unfortunately,
>> I don't know enough about the network subsystem and/or the handshake
>> protocol to suggest a fix. I'd be happy to submit a fix if you let me know
>> how that should look like.
>>
>> Thanks,
>> Guenter
> 
> I am able to reproduce the test failure at boot:
> 
> [  125.404130]     KTAP version 1
> [  125.404690]     # Subtest: Handshake API tests
> [  125.405540]     1..11
> [  125.405966]         KTAP version 1
> [  125.406623]         # Subtest: req_alloc API fuzzing
> [  125.406971]         ok 1 handshake_req_alloc NULL proto
> [  125.408275]         ok 2 handshake_req_alloc CLASS_NONE
> [  125.409599]         ok 3 handshake_req_alloc CLASS_MAX
> [  125.410879]         ok 4 handshake_req_alloc no callbacks
> [  125.412200]         ok 5 handshake_req_alloc no done callback
> [  125.413525]         ok 6 handshake_req_alloc excessive privsize
> [  125.414896]         ok 7 handshake_req_alloc all good
> [  125.416036]     # req_alloc API fuzzing: pass:7 fail:0 skip:0 total:7
> [  125.416891]     ok 1 req_alloc API fuzzing
> [  125.418439]     ok 2 req_submit NULL req arg
> [  125.419399]     ok 3 req_submit NULL sock arg
> [  125.420925]     ok 4 req_submit NULL sock->file
> [  125.422305]     ok 5 req_lookup works
> [  125.423667]     ok 6 req_submit max pending
> [  125.425061]     ok 7 req_submit multiple
> [  125.426151]     ok 8 req_cancel before accept
> [  125.427225]     ok 9 req_cancel after accept
> [  125.428318]     ok 10 req_cancel after done
> [  125.429424]     # req_destroy works: EXPECTATION FAILED at net/handshake/handshake-test.c:477
> [  125.429424]     Expected handshake_req_destroy_test == req, but
> [  125.429424]         handshake_req_destroy_test == 0000000000000000
> [  125.429424]         req == ffff88802c5e6900
> [  125.430479]     not ok 11 req_destroy works
> [  125.435215] # Handshake API tests: pass:10 fail:1 skip:0 total:11
> [  125.435858] # Totals: pass:16 fail:1 skip:0 total:17
> [  125.437224] not ok 69 Handshake API tests
> 
> I'll have a look.
> 

Since the destroy function runs asynchronously, the best I could come up with
was to use completion handling. The following patch fixes the problem for me.

Guenter

---
diff --git a/net/handshake/handshake-test.c b/net/handshake/handshake-test.c
index 16ed7bfd29e4..dc119c1e211b 100644
--- a/net/handshake/handshake-test.c
+++ b/net/handshake/handshake-test.c
@@ -432,9 +432,12 @@ static void handshake_req_cancel_test3(struct kunit *test)

  static struct handshake_req *handshake_req_destroy_test;

+static DECLARE_COMPLETION(handshake_request_destroyed);
+
  static void test_destroy_func(struct handshake_req *req)
  {
         handshake_req_destroy_test = req;
+       complete(&handshake_request_destroyed);
  }

  static struct handshake_proto handshake_req_alloc_proto_destroy = {
@@ -473,6 +476,8 @@ static void handshake_req_destroy_test1(struct kunit *test)
         /* Act */
         fput(filp);

+       wait_for_completion_timeout(&handshake_request_destroyed, msecs_to_jiffies(100));
+
         /* Assert */
         KUNIT_EXPECT_PTR_EQ(test, handshake_req_destroy_test, req);
  }