CURLE_RECV_ERROR schannel: SEC_E_DECRYPT_FAILURE

[egorpugin]

I did this

libcurl
GET https://raw.githubusercontent.com/SoftwareNetwork/database/master//db.version

I expected the following

Everything worked ok for a long time.

curl/libcurl version

7.85.0

operating system

win11, native tls (schannel)

Output

*   Trying 185.199.110.133:443...
* Connected to raw.githubusercontent.com (185.199.110.133) port 443 (#0)
* schannel: disabled automatic use of client certificate
* ALPN: offers h2
* ALPN: offers http/1.1
* ALPN: server accepted h2
* Using HTTP2, server supports multiplexing
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* h2h3 [:method: GET]
* h2h3 [:path: /SoftwareNetwork/database/master//db.version]
* h2h3 [:scheme: https]
* h2h3 [:authority: raw.githubusercontent.com]
* h2h3 [accept: */*]
* Using Stream ID: 1 (easy handle 0x2913cc49bd0)
> GET /SoftwareNetwork/database/master//db.version HTTP/2
Host: raw.githubusercontent.com
accept: */*

* schannel: failed to decrypt data, need more data
* schannel: failed to read data from server: SEC_E_DECRYPT_FAILURE (0x80090330) - The specified data could not be decrypted.
* Failed receiving HTTP2 data
* Connection #0 to host raw.githubusercontent.com left intact

Same for http1.1.
curl_easy_setopt(curl, CURLOPT_HTTP_VERSION, CURL_HTTP_VERSION_1_1);

*   Trying 185.199.110.133:443...
* Connected to raw.githubusercontent.com (185.199.110.133) port 443 (#0)
* schannel: disabled automatic use of client certificate
* ALPN: offers http/1.1
* ALPN: server accepted http/1.1
> GET /SoftwareNetwork/database/master//db.version HTTP/1.1
Host: raw.githubusercontent.com
Accept: */*

* schannel: failed to read data from server: SEC_E_DECRYPT_FAILURE (0x80090330) - The specified data could not be decrypted.
* Closing connection 0
* schannel: shutting down SSL/TLS connection with raw.githubusercontent.com port 443

[bagder]

/cc @gvollant @DHowett @wyattoday any clues?

[jay]

Is this reproducible with the curl tool (curl.exe)? How did you build libcurl? Please give us minimal self contained example code that can be used to reproduce. FWIW this was not reproducible for me using the curl tool in Windows 7, 8 or 10 (21H2).

[egorpugin]

This is custom libcurl build. I re-check my flags. Maybe there was some new HAVE_... checks etc.

[egorpugin]

Here is a repro.

1. Download https://curl.se/windows/dl-7.85.0_1/curl-7.85.0_1-win64-mingw.zip and unpack.
2. set CURL_SSL_BACKEND=schannel
3. curl.exe https://raw.githubusercontent.com/SoftwareNetwork/database/master//db.version -v

>curl.exe https://raw.githubusercontent.com/SoftwareNetwork/database/master//db.version -v
*   Trying 185.199.111.133:443...
* Connected to raw.githubusercontent.com (185.199.111.133) port 443 (#0)
* schannel: disabled automatic use of client certificate
* ALPN: offers h2
* ALPN: offers http/1.1
* ALPN: server accepted h2
* Using HTTP2, server supports multiplexing
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* h2h3 [:method: GET]
* h2h3 [:path: /SoftwareNetwork/database/master//db.version]
* h2h3 [:scheme: https]
* h2h3 [:authority: raw.githubusercontent.com]
* h2h3 [user-agent: curl/7.85.0]
* h2h3 [accept: */*]
* Using Stream ID: 1 (easy handle 0x2581a4da910)
> GET /SoftwareNetwork/database/master//db.version HTTP/2
> Host: raw.githubusercontent.com
> user-agent: curl/7.85.0
> accept: */*
>
* schannel: failed to decrypt data, need more data
* schannel: failed to read data from server: SEC_E_DECRYPT_FAILURE (0x80090330) - The specified data could not be decrypted.
* Failed receiving HTTP2 data
* Connection #0 to host raw.githubusercontent.com left intact
curl: (56) Failed receiving HTTP2 data

[jay]

That's reproducible for me in Windows 11 and it happens regardless of HTTP version setting or TLS setting. curl 7.55.1 (packaged version that comes with Windows) seems to work though so the issue can probably be bisected. I don't have a development environment set up in Windows 11 yet, I'm still in the process of configuring a VM for it.

[jay]

It looks like a TLS 1.3 issue, when I set --tls-max 1.2 I can't reproduce.

/cc @wyattoday

[wyattoday]

I agree that this is an issue with how the internals changes in SChannel when using TLS 1.3.

The actual code I wrote runs on Windows 10, 1809 (a.k.a. Windows 10 build 17763) and newer regardless of whether TLS 1.3 is used or not. The only difference is the presence of the SP_PROT_TLS1_3_CLIENT flag. So, when --tls-max 1.2 is present, the only difference in code the being executed (the code in curl itself) is the absence of the SP_PROT_TLS1_3_CLIENT flag.

So, this internal SChannel code path difference depending on whether it takes the TLS 1.2 route or the TLS 1.3 route.

I assume this is the exact same issue reported here: #9451 . Namely a bug in the ALPN code because SChannel altered the way it handled some internal code.

My guess is that if they (@egorpugin) disabled HTTP2 while still using TLS 1.3 it would work (similar to the other issue).

I don't currently have time to dig into either one of these issues, but I might have some time end of next week if no one picks it up in the meantime.

[JDepooter]

I have been doing a bit of investigation into this problem. I am easily able to reproduce the problem on my Windows 11 machine. This is still reproducible after #9756 is merged, so it is not the same problem as reported in #9451. The problem persists regardless of HTTP version used, and whether or not ALPN is used.

Here is the command line I used in my testing:

curld.exe --verbose --no-alpn --http1.1 https://raw.githubusercontent.com/SoftwareNetwork/database/master/db.version

My full output from this command is here, I will go through this in a bit more detail below.

• STATE: INIT => CONNECT handle 0x1e511f07a30; line 1880 (connection #-5000)
• Added connection 0. The cache now contains 1 members
• STATE: CONNECT => RESOLVING handle 0x1e511f07a30; line 1926 (connection #0)
• Trying 185.199.111.133:443...
• STATE: RESOLVING => CONNECTING handle 0x1e511f07a30; line 2010 (connection #0)
• Connected to raw.githubusercontent.com (185.199.111.133) port 443 (#0)
• STATE: CONNECTING => PROTOCONNECT handle 0x1e511f07a30; line 2075 (connection #0)
• schannel: SSL/TLS connection with raw.githubusercontent.com port 443 (step 1/3)
• Didn't find Session ID in cache for host HTTPS://raw.githubusercontent.com:443
• schannel: checking server certificate revocation
• schannel: disabled automatic use of client certificate
• schannel: sending initial handshake data: sending 289 bytes.
• schannel: sent initial handshake data: sent 289 bytes
• schannel: SSL/TLS connection with raw.githubusercontent.com port 443 (step 2/3)
• schannel: failed to receive handshake, need more data
• STATE: PROTOCONNECT => PROTOCONNECTING handle 0x1e511f07a30; line 2093 (connection #0)
• schannel: SSL/TLS connection with raw.githubusercontent.com port 443 (step 2/3)
• schannel: encrypted data got 4096
• schannel: encrypted data buffer: offset 4096 length 4096
• schannel: sending next handshake data: sending 80 bytes.
• schannel: encrypted data length: 19
• schannel: SSL/TLS handshake complete
• schannel: SSL/TLS connection with raw.githubusercontent.com port 443 (step 3/3)
• Didn't find Session ID in cache for host HTTPS://raw.githubusercontent.com:443
• Added Session ID to cache for HTTPS://raw.githubusercontent.com:443 [server]
• schannel: stored credential handle in session cache
• STATE: PROTOCONNECTING => DO handle 0x1e511f07a30; line 2112 (connection #0)

GET /SoftwareNetwork/database/master/db.version HTTP/1.1
Host: raw.githubusercontent.com
User-Agent: curl/7.86.0-DEV
Accept: /

• STATE: DO => DID handle 0x1e511f07a30; line 2192 (connection #0)
• STATE: DID => PERFORMING handle 0x1e511f07a30; line 2311 (connection #0)
• schannel: client wants to read 102400 bytes
• schannel: encdata_buffer resized 103424
• schannel: encrypted data buffer: offset 19 length 103424
• schannel: encrypted data got 903
• schannel: encrypted data buffer: offset 922 length 103424
• schannel: failed to read data from server: SEC_E_DECRYPT_FAILURE (0x80090330) - The specified data could not be decrypted.
• schannel: schannel_recv cleanup
• multi_done: status: 56 prem: 1 done: 0
• The cache now contains 0 members
• Closing connection 0
• schannel: shutting down SSL/TLS connection with raw.githubusercontent.com port 443
• schannel: clear security context handle
• Expire cleared (transfer 0x1e511f07a30)
  curl: (56) Failure when receiving data from the peer

I have tracked this down to a problem in "step 2" of the TLS connection. It appears that the initial traffic from the server to libcurl (ServerHello and its associated data) are not fully processed.

In step 1, libcurl calls InitializeSecurityContext to generate the ClientHello and its associated data. This is then sent to the server, as indicated by this line in the log:

• schannel: sent initial handshake data: sent 289 bytes

We then move to step 2, where we read data from the server and pass it to another call to InitializeSecurityContext. Here are the relevant lines:

• schannel: encrypted data got 4096
• schannel: encrypted data buffer: offset 4096 length 4096

This is where things get weird. The call to InitializeSecurityContext returns SEC_E_OK, indicating that this stage of the handshake is complete. It populates a SECBUFFER_TOKEN buffer with the outgoing "Client Finished" message for the server. However, it also populates a buffer of type SECBUFFER_EXTRA indicating that not all of the 4096 bytes have been consumed. In the above log, there are 19 bytes which have not been consumed:

• schannel: encrypted data length: 19

Since the return code was SEC_E_OK, libcurl moves to step 3 of the TLS handshake, and sends the "Client Finished" message:

• schannel: sending next handshake data: sending 80 bytes.

After this libcurl calls the schannel_send function with the HTTP request, and then the schannel_recv function to read the response:

• schannel: client wants to read 102400 bytes
• schannel: encdata_buffer resized 103424
• schannel: encrypted data buffer: offset 19 length 103424
• schannel: encrypted data got 903
• schannel: encrypted data buffer: offset 922 length 103424

Notice that the 19 bytes from the initial ServerHello message are still there. When libcurl attempts to get the decrypted data via the DecryptMessage function, this extra data causes the decryption to fail:

• schannel: failed to read data from server: SEC_E_DECRYPT_FAILURE (0x80090330) - The specified data could not be decrypted.

If I change the CURL_SCHANNEL_BUFFER_INIT_SIZE to a larger value (8192), the connection succeeds. In this case, the entire ServerHello message is processed at once. Here is a snippet from a successful request:

• schannel: SSL/TLS connection with raw.githubusercontent.com port 443 (step 2/3)
• schannel: encrypted data got 4292
• schannel: encrypted data buffer: offset 4292 length 8192
• schannel: sending next handshake data: sending 80 bytes.
• schannel: encrypted data length: 215
• schannel: SSL/TLS handshake complete

So it appears that the second call to InitializeSecurityContext is returning SEC_E_OK when there is still unread handshake data in the socket. At this point it feels as though we are working around a bug in the Windows SChannel library. I think there are a few options to consider here, some of which I have already tried and ruled out.

1. We can just increase the initial buffer size. Obviously this is less than ideal, especially for servers which have long certificate chains which may require a large ServerHello message.
2. We can decrease the initial buffer size, trying to force the correct "incomplete message" behaviour from SChannel. This did not work, the InitializeSecurityContext function still eventually returned SEC_E_OK with an SECBUFFER_EXTRA buffer indicating unconsumed bytes.
3. We can add some code to make sure the socket is empty once we get a SEC_E_OK return value from InitializeSecurityContext. I tried this by adding another call to Curl_read_plain after the call to InitializeSecurityContext. This also did not work, I guess those remaining bytes are actually important.
4. We can modify the loop in "step 2", so that it continues to read data when any handshake data is not consumed, even if the InitializeSecurityContext function returns SEC_E_OK. The logic is a bit tricky, because we would need to correctly handle sending the Client Finished handshake message while still processing the ServerHello hello message. I have a working proof of concept of this, and am working on a pull request now.

[jay]

Thanks for the excellent analysis.

This is where things get weird. The call to InitializeSecurityContext returns SEC_E_OK, indicating that this stage of the handshake is complete.

I'd agree... InitializeSecurityContext (Schannel) return value SEC_E_OK says:

"The security context was successfully initialized. There is no need for another InitializeSecurityContext (Schannel) call. If the function returns an output token, that is, if the SECBUFFER_TOKEN in pOutput is of nonzero length, that token must be sent to the server."

So it appears that the second call to InitializeSecurityContext is returning SEC_E_OK when there is still unread handshake data in the socket.

We already have logic that was added a decade ago in 72a5813 for a large handshake problem with Windows CE. Currently that logic looks like this:

curl/lib/vtls/schannel.c

Lines 1538 to 1567 in 93d0928

	/* check if there was additional remaining encrypted data */
	if(inbuf[1].BufferType == SECBUFFER_EXTRA && inbuf[1].cbBuffer > 0) {
	DEBUGF(infof(data, "schannel: encrypted data length: %lu",
	inbuf[1].cbBuffer));
	/*
	There are two cases where we could be getting extra data here:
	1) If we're renegotiating a connection and the handshake is already
	complete (from the server perspective), it can encrypted app data
	(not handshake data) in an extra buffer at this point.
	2) (sspi_status == SEC_I_CONTINUE_NEEDED) We are negotiating a
	connection and this extra data is part of the handshake.
	We should process the data immediately; waiting for the socket to
	be ready may fail since the server is done sending handshake data.
	*/
	/* check if the remaining data is less than the total amount
	and therefore begins after the already processed data */
	if(backend->encdata_offset > inbuf[1].cbBuffer) {
	memmove(backend->encdata_buffer,
	(backend->encdata_buffer + backend->encdata_offset) -
	inbuf[1].cbBuffer, inbuf[1].cbBuffer);
	backend->encdata_offset = inbuf[1].cbBuffer;
	if(sspi_status == SEC_I_CONTINUE_NEEDED) {
	doread = FALSE;
	continue;
	}
	}
	}
	else {
	backend->encdata_offset = 0;
	}

Perhaps that logic is too restrictive? We would need to read more data to complete the handshake, so doread would need to be set true, correct? But the comments there worry me. How can we be expected to tell if the extra data is handshake data or app data at that point?

[egorpugin]

I've found this page regarding SECBUFFER_EXTRA.
https://learn.microsoft.com/en-us/windows/win32/secauthn/extra-buffers-returned-by-schannel

It says:

When the input buffers contains too much information, Schannel does not treat this as an error. The function processes as much of the input as it can, and returns the status code for that processing activity. In addition, Schannel indicates the presence of unprocessed information in the input buffers by returning an output buffer of type SECBUFFER_EXTRA. Testing the output buffers for this type of buffer is the only way to detect this situation. The cbBuffer field of the extra buffer structure indicates how many bytes of input were not processed.

[JDepooter]

My potential fix for this problem is available here:
https://github.com/JDepooter/curl/tree/9431_schannel_recv_error

Note that that branch includes the commit in #9807, so it is really just the final two commits which are of interest to this issue.

I have some reservations about the fix however. As @jay mentioned in his previous comment, we cannot really know whether the "extra" data reported by the InitializeSecurityContext function is further handshake data or application data. We really need to use the return value to indicate this, but it is not reliable at this point. Notably, the TLS 1.3 specification allows for the server to start sending application data with the ServerHello message:
https://datatracker.ietf.org/doc/html/rfc8446#section-2

This is unlikely with https, because the server would not know which data to serve without first receiving a request. I imagine this could be possible in other protocols (ftps maybe?).

[jay]

@andrey-popov are we doing this wrong or is it a bug in schannel?