[v2] vsock/test: Fix occasional failure in SIOCOUTQ tests

[PATCH net v2] vsock/test: Fix occasional failure in SIOCOUTQ tests

Posted by Konstantin Shkolnyy 7 months, 1 week ago

These tests:
    "SOCK_STREAM ioctl(SIOCOUTQ) 0 unsent bytes"
    "SOCK_SEQPACKET ioctl(SIOCOUTQ) 0 unsent bytes"
output: "Unexpected 'SIOCOUTQ' value, expected 0, got 64 (CLIENT)".

They test that the SIOCOUTQ ioctl reports 0 unsent bytes after the data
have been received by the other side. However, sometimes there is a delay
in updating this "unsent bytes" counter, and the test fails even though
the counter properly goes to 0 several milliseconds later.

The delay occurs in the kernel because the used buffer notification
callback virtio_vsock_tx_done(), called upon receipt of the data by the
other side, doesn't update the counter itself. It delegates that to
a kernel thread (via vsock->tx_work). Sometimes that thread is delayed
more than the test expects.

Change the test to poll SIOCOUTQ until it returns 0 or a timeout occurs.

Signed-off-by: Konstantin Shkolnyy <kshk@linux.ibm.com>
---
Changes in v2:
 - Use timeout_check() to end polling, instead of counting iterations.

 tools/testing/vsock/vsock_test.c | 28 ++++++++++++++++------------
 1 file changed, 16 insertions(+), 12 deletions(-)

diff --git a/tools/testing/vsock/vsock_test.c b/tools/testing/vsock/vsock_test.c
index d0f6d253ac72..613551132a96 100644
--- a/tools/testing/vsock/vsock_test.c
+++ b/tools/testing/vsock/vsock_test.c
@@ -1264,21 +1264,25 @@ static void test_unsent_bytes_client(const struct test_opts *opts, int type)
 	send_buf(fd, buf, sizeof(buf), 0, sizeof(buf));
 	control_expectln("RECEIVED");
 
-	ret = ioctl(fd, SIOCOUTQ, &sock_bytes_unsent);
-	if (ret < 0) {
-		if (errno == EOPNOTSUPP) {
-			fprintf(stderr, "Test skipped, SIOCOUTQ not supported.\n");
-		} else {
+	/* SIOCOUTQ isn't guaranteed to instantly track sent data. Even though
+	 * the "RECEIVED" message means that the other side has received the
+	 * data, there can be a delay in our kernel before updating the "unsent
+	 * bytes" counter. Repeat SIOCOUTQ until it returns 0.
+	 */
+	timeout_begin(TIMEOUT);
+	do {
+		ret = ioctl(fd, SIOCOUTQ, &sock_bytes_unsent);
+		if (ret < 0) {
+			if (errno == EOPNOTSUPP) {
+				fprintf(stderr, "Test skipped, SIOCOUTQ not supported.\n");
+				break;
+			}
 			perror("ioctl");
 			exit(EXIT_FAILURE);
 		}
-	} else if (ret == 0 && sock_bytes_unsent != 0) {
-		fprintf(stderr,
-			"Unexpected 'SIOCOUTQ' value, expected 0, got %i\n",
-			sock_bytes_unsent);
-		exit(EXIT_FAILURE);
-	}
-
+		timeout_check("SIOCOUTQ");
+	} while (sock_bytes_unsent != 0);
+	timeout_end();
 	close(fd);
 }
 
-- 
2.34.1

Re: [PATCH net v2] vsock/test: Fix occasional failure in SIOCOUTQ tests

Posted by Paolo Abeni 7 months ago

On 5/7/25 5:14 PM, Konstantin Shkolnyy wrote:
> These tests:
>     "SOCK_STREAM ioctl(SIOCOUTQ) 0 unsent bytes"
>     "SOCK_SEQPACKET ioctl(SIOCOUTQ) 0 unsent bytes"
> output: "Unexpected 'SIOCOUTQ' value, expected 0, got 64 (CLIENT)".
> 
> They test that the SIOCOUTQ ioctl reports 0 unsent bytes after the data
> have been received by the other side. However, sometimes there is a delay
> in updating this "unsent bytes" counter, and the test fails even though
> the counter properly goes to 0 several milliseconds later.
> 
> The delay occurs in the kernel because the used buffer notification
> callback virtio_vsock_tx_done(), called upon receipt of the data by the
> other side, doesn't update the counter itself. It delegates that to
> a kernel thread (via vsock->tx_work). Sometimes that thread is delayed
> more than the test expects.
> 
> Change the test to poll SIOCOUTQ until it returns 0 or a timeout occurs.
> 
> Signed-off-by: Konstantin Shkolnyy <kshk@linux.ibm.com>

Could you please provide a suitable fixes tag?

No need to repost, just reply here.

Thanks!

Paolo

Re: [PATCH net v2] vsock/test: Fix occasional failure in SIOCOUTQ tests

Posted by Stefano Garzarella 7 months ago

On Tue, May 13, 2025 at 10:46:35AM +0200, Paolo Abeni wrote:
>On 5/7/25 5:14 PM, Konstantin Shkolnyy wrote:
>> These tests:
>>     "SOCK_STREAM ioctl(SIOCOUTQ) 0 unsent bytes"
>>     "SOCK_SEQPACKET ioctl(SIOCOUTQ) 0 unsent bytes"
>> output: "Unexpected 'SIOCOUTQ' value, expected 0, got 64 (CLIENT)".
>>
>> They test that the SIOCOUTQ ioctl reports 0 unsent bytes after the data
>> have been received by the other side. However, sometimes there is a delay
>> in updating this "unsent bytes" counter, and the test fails even though
>> the counter properly goes to 0 several milliseconds later.
>>
>> The delay occurs in the kernel because the used buffer notification
>> callback virtio_vsock_tx_done(), called upon receipt of the data by the
>> other side, doesn't update the counter itself. It delegates that to
>> a kernel thread (via vsock->tx_work). Sometimes that thread is delayed
>> more than the test expects.
>>
>> Change the test to poll SIOCOUTQ until it returns 0 or a timeout occurs.
>>
>> Signed-off-by: Konstantin Shkolnyy <kshk@linux.ibm.com>
>
>Could you please provide a suitable fixes tag?
>
>No need to repost, just reply here.

I always get confused whether to use Fixes tags for tests, but I saw 
this patch target `net`, so it makes sense. BTW IMHO it can go 
eventually through net-next, which is the target tree I usually use for 
new tests but also test fixes.

In any case, the tag should be this one:

Fixes: 18ee44ce97c1 ("test/vsock: add ioctl unsent bytes test")

Thanks,
Stefano

Re: [PATCH net v2] vsock/test: Fix occasional failure in SIOCOUTQ tests

Posted by Stefano Garzarella 7 months, 1 week ago

On Wed, 7 May 2025 at 17:15, Konstantin Shkolnyy <kshk@linux.ibm.com> wrote:
>
> These tests:
>     "SOCK_STREAM ioctl(SIOCOUTQ) 0 unsent bytes"
>     "SOCK_SEQPACKET ioctl(SIOCOUTQ) 0 unsent bytes"
> output: "Unexpected 'SIOCOUTQ' value, expected 0, got 64 (CLIENT)".
>
> They test that the SIOCOUTQ ioctl reports 0 unsent bytes after the data
> have been received by the other side. However, sometimes there is a delay
> in updating this "unsent bytes" counter, and the test fails even though
> the counter properly goes to 0 several milliseconds later.
>
> The delay occurs in the kernel because the used buffer notification
> callback virtio_vsock_tx_done(), called upon receipt of the data by the
> other side, doesn't update the counter itself. It delegates that to
> a kernel thread (via vsock->tx_work). Sometimes that thread is delayed
> more than the test expects.
>
> Change the test to poll SIOCOUTQ until it returns 0 or a timeout occurs.
>
> Signed-off-by: Konstantin Shkolnyy <kshk@linux.ibm.com>
> ---
> Changes in v2:
>  - Use timeout_check() to end polling, instead of counting iterations.

Why removing the sleep?

Thanks,
Stefano

>
>  tools/testing/vsock/vsock_test.c | 28 ++++++++++++++++------------
>  1 file changed, 16 insertions(+), 12 deletions(-)
>
> diff --git a/tools/testing/vsock/vsock_test.c b/tools/testing/vsock/vsock_test.c
> index d0f6d253ac72..613551132a96 100644
> --- a/tools/testing/vsock/vsock_test.c
> +++ b/tools/testing/vsock/vsock_test.c
> @@ -1264,21 +1264,25 @@ static void test_unsent_bytes_client(const struct test_opts *opts, int type)
>         send_buf(fd, buf, sizeof(buf), 0, sizeof(buf));
>         control_expectln("RECEIVED");
>
> -       ret = ioctl(fd, SIOCOUTQ, &sock_bytes_unsent);
> -       if (ret < 0) {
> -               if (errno == EOPNOTSUPP) {
> -                       fprintf(stderr, "Test skipped, SIOCOUTQ not supported.\n");
> -               } else {
> +       /* SIOCOUTQ isn't guaranteed to instantly track sent data. Even though
> +        * the "RECEIVED" message means that the other side has received the
> +        * data, there can be a delay in our kernel before updating the "unsent
> +        * bytes" counter. Repeat SIOCOUTQ until it returns 0.
> +        */
> +       timeout_begin(TIMEOUT);
> +       do {
> +               ret = ioctl(fd, SIOCOUTQ, &sock_bytes_unsent);
> +               if (ret < 0) {
> +                       if (errno == EOPNOTSUPP) {
> +                               fprintf(stderr, "Test skipped, SIOCOUTQ not supported.\n");
> +                               break;
> +                       }
>                         perror("ioctl");
>                         exit(EXIT_FAILURE);
>                 }
> -       } else if (ret == 0 && sock_bytes_unsent != 0) {
> -               fprintf(stderr,
> -                       "Unexpected 'SIOCOUTQ' value, expected 0, got %i\n",
> -                       sock_bytes_unsent);
> -               exit(EXIT_FAILURE);
> -       }
> -
> +               timeout_check("SIOCOUTQ");
> +       } while (sock_bytes_unsent != 0);
> +       timeout_end();
>         close(fd);
>  }
>
> --
> 2.34.1
>

Re: [PATCH net v2] vsock/test: Fix occasional failure in SIOCOUTQ tests

Posted by Konstantin Shkolnyy 7 months, 1 week ago

On 07-May-25 10:41, Stefano Garzarella wrote:
> On Wed, 7 May 2025 at 17:15, Konstantin Shkolnyy <kshk@linux.ibm.com> wrote:
>>
>> These tests:
>>      "SOCK_STREAM ioctl(SIOCOUTQ) 0 unsent bytes"
>>      "SOCK_SEQPACKET ioctl(SIOCOUTQ) 0 unsent bytes"
>> output: "Unexpected 'SIOCOUTQ' value, expected 0, got 64 (CLIENT)".
>>
>> They test that the SIOCOUTQ ioctl reports 0 unsent bytes after the data
>> have been received by the other side. However, sometimes there is a delay
>> in updating this "unsent bytes" counter, and the test fails even though
>> the counter properly goes to 0 several milliseconds later.
>>
>> The delay occurs in the kernel because the used buffer notification
>> callback virtio_vsock_tx_done(), called upon receipt of the data by the
>> other side, doesn't update the counter itself. It delegates that to
>> a kernel thread (via vsock->tx_work). Sometimes that thread is delayed
>> more than the test expects.
>>
>> Change the test to poll SIOCOUTQ until it returns 0 or a timeout occurs.
>>
>> Signed-off-by: Konstantin Shkolnyy <kshk@linux.ibm.com>
>> ---
>> Changes in v2:
>>   - Use timeout_check() to end polling, instead of counting iterations.
> 
> Why removing the sleep?

I just imagined that whoever uses SIOCOUTQ might want to repeat it 
without a delay, so why not do it, it's a test. Is there a reason to 
insert a sleep?

Re: [PATCH net v2] vsock/test: Fix occasional failure in SIOCOUTQ tests

Posted by Stefano Garzarella 7 months, 1 week ago

On Wed, 7 May 2025 at 18:01, Konstantin Shkolnyy <kshk@linux.ibm.com> wrote:
>
> On 07-May-25 10:41, Stefano Garzarella wrote:
> > On Wed, 7 May 2025 at 17:15, Konstantin Shkolnyy <kshk@linux.ibm.com> wrote:
> >>
> >> These tests:
> >>      "SOCK_STREAM ioctl(SIOCOUTQ) 0 unsent bytes"
> >>      "SOCK_SEQPACKET ioctl(SIOCOUTQ) 0 unsent bytes"
> >> output: "Unexpected 'SIOCOUTQ' value, expected 0, got 64 (CLIENT)".
> >>
> >> They test that the SIOCOUTQ ioctl reports 0 unsent bytes after the data
> >> have been received by the other side. However, sometimes there is a delay
> >> in updating this "unsent bytes" counter, and the test fails even though
> >> the counter properly goes to 0 several milliseconds later.
> >>
> >> The delay occurs in the kernel because the used buffer notification
> >> callback virtio_vsock_tx_done(), called upon receipt of the data by the
> >> other side, doesn't update the counter itself. It delegates that to
> >> a kernel thread (via vsock->tx_work). Sometimes that thread is delayed
> >> more than the test expects.
> >>
> >> Change the test to poll SIOCOUTQ until it returns 0 or a timeout occurs.
> >>
> >> Signed-off-by: Konstantin Shkolnyy <kshk@linux.ibm.com>
> >> ---
> >> Changes in v2:
> >>   - Use timeout_check() to end polling, instead of counting iterations.
> >
> > Why removing the sleep?
>
> I just imagined that whoever uses SIOCOUTQ might want to repeat it
> without a delay, so why not do it, it's a test. Is there a reason to
> insert a sleep?
>

Okay, now that I think back on it, it's the same thing I thought of when 
I did this.

I guess in v1 the sleep was just to limit the number of cycles.

LGTM:
Reviewed-by: Stefano Garzarella <sgarzare@redhat.com>