Received-SPF: softfail (google.com: domain of transitioning linux-kernel-owner@vger.kernel.org does not designate 23.128.96.19 as permitted sender) client-ip=23.128.96.19;
Subject: Re: kselftest: net: tls: hangs
To:     Naresh Kamboju <naresh.kamboju@linaro.org>,
        Jakub Kicinski <kuba@kernel.org>
Cc:     Shuah Khan <shuah@kernel.org>,
        "David S. Miller" <davem@davemloft.net>,
        Paolo Abeni <pabeni@redhat.com>,
        Shuah Khan <skhan@linuxfoundation.org>,
        Linux-Next Mailing List <linux-next@vger.kernel.org>,
        "open list:KERNEL SELFTEST FRAMEWORK" 
        <linux-kselftest@vger.kernel.org>,
        open list <linux-kernel@vger.kernel.org>,
        lkft-triage@lists.linaro.org, Netdev <netdev@vger.kernel.org>
References: <CA+G9fYsntwPrwk39VfsAjRwoSNnb3nX8kCEUa=Gxit7_pfD6bg@mail.gmail.com>
From:   Shuah Khan <skhan@linuxfoundation.org>
Message-ID: <8c81e8ad-6741-b5ed-cf0a-5a302d51d40a@linuxfoundation.org>
Date:   Fri, 25 Mar 2022 16:13:33 -0600
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101
 Thunderbird/78.8.1
MIME-Version: 1.0
In-Reply-To: <CA+G9fYsntwPrwk39VfsAjRwoSNnb3nX8kCEUa=Gxit7_pfD6bg@mail.gmail.com>
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Language: en-US
Content-Transfer-Encoding: 7bit
Precedence: bulk

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