Re: kselftest: net: tls: hangs

[Shuah Khan <skhan@linuxfoundation.org>]

On 3/25/22 1:40 AM, Naresh Kamboju wrote:
> While running kselftest net tls test case on Linux next and mainline kernels
> the test case fails at following sub test cases and hangs every time.
> Please investigate this hang issue.
> 
> kconfigs are generated from kselftest-merge config.
> 
> metadata:
>    git_ref: master
>    git_repo: https://gitlab.com/Linaro/lkft/mirrors/next/linux-next
>    git_sha: b61581ae229d8eb9f21f8753be3f4011f7692384
>    git_describe: next-20220323
>    kernel_version: 5.17.0
>    kernel-config: https://builds.tuxbuild.com/26mKij4yB5Q6WUpOyHHEoHLstVJ/config
> 
> Test log link,
> --------------
> # selftests: net: tls
> # TAP version 13
> # 1..502
> # # Starting 502 tests from 14 test cases.
> # #  RUN           global.non_established ...
> # #            OK  global.non_established
> # ok 1 global.non_established
> # #  RUN           global.keysizes ...
> # #            OK  global.keysizes
> <trim>
> 
> # #  RUN           tls.12_aes_gcm.splice_cmsg_to_pipe ...
> # # tls.c:688:splice_cmsg_to_pipe:Expected splice(self->cfd, NULL,
> p[1], NULL, send_len, 0) (10) == -1 (-1)
> # # tls.c:689:splice_cmsg_to_pipe:Expected errno (2) == EINVAL (22)
> # # splice_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.12_aes_gcm.splice_cmsg_to_pipe
> # not ok 21 tls.12_aes_gcm.splice_cmsg_to_pipe
> # #  RUN           tls.12_aes_gcm.splice_dec_cmsg_to_pipe ...
> # # tls.c:708:splice_dec_cmsg_to_pipe:Expected recv(self->cfd, buf,
> send_len, 0) (10) == -1 (-1)
> # # tls.c:709:splice_dec_cmsg_to_pipe:Expected errno (2) == EIO (5)
> # # splice_dec_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.12_aes_gcm.splice_dec_cmsg_to_pipe
> # not ok 22 tls.12_aes_gcm.splice_dec_cmsg_to_pipe
> # #  RUN           tls.12_aes_gcm.recv_and_splice ...
> # #            OK  tls.12_aes_gcm.recv_and_splice
> 
> <trim>
> 
> # #  RUN           tls.13_aes_gcm.splice_cmsg_to_pipe ...
> # # tls.c:688:splice_cmsg_to_pipe:Expected splice(self->cfd, NULL,
> p[1], NULL, send_len, 0) (10) == -1 (-1)
> # # tls.c:689:splice_cmsg_to_pipe:Expected errno (2) == EINVAL (22)
> # # splice_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.13_aes_gcm.splice_cmsg_to_pipe
> # not ok 70 tls.13_aes_gcm.splice_cmsg_to_pipe
> # #  RUN           tls.13_aes_gcm.splice_dec_cmsg_to_pipe ...
> # # tls.c:708:splice_dec_cmsg_to_pipe:Expected recv(self->cfd, buf,
> send_len, 0) (10) == -1 (-1)
> # # tls.c:709:splice_dec_cmsg_to_pipe:Expected errno (2) == EIO (5)
> # # splice_dec_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.13_aes_gcm.splice_dec_cmsg_to_pipe
> # not ok 71 tls.13_aes_gcm.splice_dec_cmsg_to_pipe
> 
> 
> <trim>
> 
> # #  RUN           tls.12_chacha.splice_cmsg_to_pipe ...
> # # tls.c:688:splice_cmsg_to_pipe:Expected splice(self->cfd, NULL,
> p[1], NULL, send_len, 0) (10) == -1 (-1)
> # # tls.c:689:splice_cmsg_to_pipe:Expected errno (2) == EINVAL (22)
> # # splice_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.12_chacha.splice_cmsg_to_pipe
> # not ok 119 tls.12_chacha.splice_cmsg_to_pipe
> # #  RUN           tls.12_chacha.splice_dec_cmsg_to_pipe ...
> # # tls.c:708:splice_dec_cmsg_to_pipe:Expected recv(self->cfd, buf,
> send_len, 0) (10) == -1 (-1)
> # # tls.c:709:splice_dec_cmsg_to_pipe:Expected errno (2) == EIO (5)
> # # splice_dec_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.12_chacha.splice_dec_cmsg_to_pipe
> # not ok 120 tls.12_chacha.splice_dec_cmsg_to_pipe
> 
> <trim>
> 
> # #  RUN           tls.13_chacha.splice_cmsg_to_pipe ...
> # # tls.c:688:splice_cmsg_to_pipe:Expected splice(self->cfd, NULL,
> p[1], NULL, send_len, 0) (10) == -1 (-1)
> # # tls.c:689:splice_cmsg_to_pipe:Expected errno (2) == EINVAL (22)
> # # splice_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.13_chacha.splice_cmsg_to_pipe
> # not ok 168 tls.13_chacha.splice_cmsg_to_pipe
> # #  RUN           tls.13_chacha.splice_dec_cmsg_to_pipe ...
> # # tls.c:708:splice_dec_cmsg_to_pipe:Expected recv(self->cfd, buf,
> send_len, 0) (10) == -1 (-1)
> # # tls.c:709:splice_dec_cmsg_to_pipe:Expected errno (2) == EIO (5)
> # # splice_dec_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.13_chacha.splice_dec_cmsg_to_pipe
> # not ok 169 tls.13_chacha.splice_dec_cmsg_to_pipe
> 
> <trim>
> 
> # #  RUN           tls.13_sm4_gcm.splice_cmsg_to_pipe ...
> # # tls.c:688:splice_cmsg_to_pipe:Expected splice(self->cfd, NULL,
> p[1], NULL, send_len, 0) (10) == -1 (-1)
> # # tls.c:689:splice_cmsg_to_pipe:Expected errno (2) == EINVAL (22)
> # # splice_cmsg_to_pipe: Test terminated by timeout
> # #          FAIL  tls.13_sm4_gcm.splice_cmsg_to_pipe
> # not ok 217 tls.13_sm4_gcm.splice_cmsg_to_pipe
> # #  RUN           tls.13_sm4_gcm.splice_dec_cmsg_to_pipe ...
> # # tls.c:708:splice_dec_cmsg_to_pipe:Expected recv(self->cfd, buf,
> send_len, 0) (10) == -1 (-1)
> # # tls.c:709:splice_dec_cmsg_to_pipe:Expected errno (2) == EIO (5)
> [  661.901558] kworker/dying (49) used greatest stack depth: 10576 bytes left

This seems to be the problem perhaps.

Jakub, any thoughts. The last change to tls.c was a while back.

> 
> Test case HANG here.
> 
> Full test log links [1] including boot log and test run log.
> 
> Reported-by: Linux Kernel Functional Testing <lkft@linaro.org>
> 
> --
> Linaro LKFT
> https://lkft.linaro.org
> 
> https://lkft.validation.linaro.org/scheduler/job/4770773#L2700
> 

thanks,
-- Shuah
thanks,
-- Shuah