After upgrading Openssl from 1.1.1s to 3.1.4, same Python script generate "SSL Error(407) - shutdown while in init" on Openssl 3.1.4 while 1.1.1s has no similar issue..

[Syllinia]

The Python test script is as follows. It works fine with Openssl 1.1.1. But after upgrading Openssl to 3.1.4, there's ssl error "SSL Error(407) - shutdown while in init". In both versions, this SSL error is generated in SSL_shutdown while SSL->statem.in_init is 1. It seems that in Openssl 3.1.4 if SSL->statem.in_init is not set to 0 soon enough and then TCP FIN is received and the application calls SSL_shutdown the "SSL Error(407) - shutdown while in init" will be generated.

The environment executing the Python script is as follows.
~$ pip list | grep -i requests
requests 2.22.0
~$
~$ openssl version
OpenSSL 1.1.1f 31 Mar 2020
~$ uname -a
Linux us01 5.4.0-164-generic 181-Ubuntu SMP Fri Sep 1 13:41:22 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

url = 'https://xxxxxx/autotest/xxx/web_cache.php'

def ssl_test(url, n):
    for i in range(n):
        resp = requests.get(url, verify=False)
        if resp.status_code != 200:
            print(i+1, resp.status_code)
        time.sleep(1)
    
    print('Done!')

ssl_test(url, 5)

Furthermore, I got more clues.
1.Whiling using Openssl 3.1.4, if I open debug commands which output logs on the terminal that will slows down the execution of the processing, "SSL Error(407) - shutdown while in init" can't be generated.
2.If I close the debug commands, "SSL Error(407) - shutdown while in init" is generated.
In the above image, the left part corresponds to case 2 while the right part corresponds to case 1. I calculate the delta time between Finished TLS record from SSL server and TCP FIN sent by SSL client. And we can see that the delta time on the right part is 38 times the one on the left. On the left side, TCP FIN is received 0.001831 seconds after SSL servers sends TLS Finish but SSL->statem.in_init is still 1 which is not as expected.
The reason why I choose Finished TLS record from SSL server is because after this packet I believe SSL->statem.in_init should be set to 0. And the reason why I choose TCP FIN sent by SSL client is because I gdb my application and found while processing TCP FIN from SSL client I can see "SSL Error(407) - shutdown while in init" is recorded.

I analyzed Openssl source code regarding SSL->statem.in_init in both 3.1.4 and 1.1.1s and didn't found obvious difference.

Please help to provide your thoughts. Any productive suggestions are welcome. Thanks.

[t8m]

@mattcaswell any idea?

[mattcaswell]

That looks unexpected. I can't explain that behaviour at the moment. What is quite strange though is the DecodeError alert that the server seems to be sending right near the end of the traces. That is a fatal error that should not happen in normal operation.

[Syllinia]

Thanks for your analysis. However, the right part also contains DecodeError(#29).