SSL POST fails

[Nahor]

Hi,

I have a little program in VB that uses WinInet to post (POST request)
data on a server through HTTPS.

The first request works fine.
Any following requests that quickly follow (less than ~17s after the
previous request) works fine.
If a request is made more than ~17s after the previous one, it fails.

When I say "fail", the CGI on the server is correctly called but there
is no data in the request (in perl, $ENV{CONTENT_LENGTH} == 0).

A simple C# program that uses WebClient.UploadData() works fine which
indicates that problem is on the client side.

Sniffing the network, I see that WinInet tries to keep the SSL socket
opened and reuses it for the following requests.
However, after ~17s, the server closes the socket on its end but Winet
doesn't seem aware of it. When the next request comes, Wininet tries to
use that socket and fails. It then reopens a new one but somehow, the
POST data doesn't arrives in the CGI.

Is there a way to force WinInet to close its socket when a request is
done? Or is there another solution?

Nahor

[EMonaco]

Nahor,

Interesting. I am currently working with the Wininet/ISAPI developers
group on a problem that on the face of it sounds identical. We are doing
complete claims in a single HTTPS Post/Response using WinInet. What I find
is if I send 3 simultaneously from different threads, let them all complete,
and then do a new claim, it fails. Microsoft suspects the SSL socket is
being reused, and I suspect it may be getting closed by the service which
then causes it to fail so it has to open a new one, and do SSL handshake but
when it comes time to resend the headers/content.... it ONLY sends the
headers... never the content. What this means for this app is that the
server ends up waiting for data that never arrives. I don't know if its
WinINet or the server, but when this happens it takes 1 hour before the
synchronous HttpSendRequest() returns with ERROR_INTERNET_TIMEOUT.

If you have installed Q832894 (an IE Patch first put out on 2/2) this is
probably the same thing I am seeing. I've been working with the
6.0.2800.1106 and 6.0.2800.1400 debug logging versions of WinInet. The
socket reuse appears in 1106 as well, but it recovers and resends not only
the headers, but the content as well and works without a problem. My guess
is you have the 1/24/2004 version 6.0.2800.1400 of wininet.dll from Q832894.
My hope is it is something they can patch- because even though I can
reproduce the problem using WinInet myself- the same thing occurs in a 3rd
Party component our customer's use that is no longer supported by the 3rd
Party creator.

I will try to remember to post updates on how this case is going with MS
Dev support on this thread. Also I am forwarding the details of your post to
the tech working on my case. May be more info for him or at least lets him
know I'm not the only one on the planet with this problem.

Regards,
Erin.

Post by Nahor
Hi,
I have a little program in VB that uses WinInet to post (POST request)
data on a server through HTTPS.
The first request works fine.
Any following requests that quickly follow (less than ~17s after the
previous request) works fine.
If a request is made more than ~17s after the previous one, it fails.
When I say "fail", the CGI on the server is correctly called but there
is no data in the request (in perl, $ENV{CONTENT_LENGTH} == 0).
A simple C# program that uses WebClient.UploadData() works fine which
indicates that problem is on the client side.
Sniffing the network, I see that WinInet tries to keep the SSL socket
opened and reuses it for the following requests.
However, after ~17s, the server closes the socket on its end but Winet
doesn't seem aware of it. When the next request comes, Wininet tries to
use that socket and fails. It then reopens a new one but somehow, the
POST data doesn't arrives in the CGI.
Is there a way to force WinInet to close its socket when a request is
done? Or is there another solution?
Nahor

[Nahor]

My guess is you have the 1/24/2004 version 6.0.2800.1400 of wininet.dll from Q832894.

Indeed, I have that version of WinInet. I already suspected some issues
with the recent IE critical updates. I wanted to try our program on
other OS but I haven't had the opportunity yet.
I also upgraded the server to a more recent version of
openssl/apache/mod_ssl recently and for a while I was afraid the problem
was coming from there. But since the C# application was working fine I
had my doubt.

As for the data not being sent, from the look of the sniffed data, it
would seems that the data is sent to the server. I suspect encryption
issues like encrypting the data with the session key from the previous
connection. Or some other kind of bad reinitialization of WinInet's
state. I'm going to see if I can get more detailled logs from mod_ssl.


Did Microsoft tell you how important this issue is to them? I need to
know if I can just hack a quick workaround for now or if a more
permanent solution needs to be investigated.


Nahor

[Stephen Sulzer]

A quick workaround might be to tell WinInet to not reuse the SSL socket
connection for subsequent requests. Reusing the socket connection can
provide a nice performance increase (especially for SSL), but if your
application is only sending requests occasionally (say a couple per minute),
then it should not matter.

To tell WinInet to close the connection after the request completes, set a
"Connection: Close" header on the request.

Stephen

Post by Nahor

My guess is you have the 1/24/2004 version 6.0.2800.1400 of wininet.dll from Q832894.

Indeed, I have that version of WinInet. I already suspected some issues
with the recent IE critical updates. I wanted to try our program on
other OS but I haven't had the opportunity yet.
I also upgraded the server to a more recent version of
openssl/apache/mod_ssl recently and for a while I was afraid the problem
was coming from there. But since the C# application was working fine I
had my doubt.
As for the data not being sent, from the look of the sniffed data, it
would seems that the data is sent to the server. I suspect encryption
issues like encrypting the data with the session key from the previous
connection. Or some other kind of bad reinitialization of WinInet's
state. I'm going to see if I can get more detailled logs from mod_ssl.
Did Microsoft tell you how important this issue is to them? I need to
know if I can just hack a quick workaround for now or if a more
permanent solution needs to be investigated.
Nahor

[Nahor]

Post by Stephen Sulzer
To tell WinInet to close the connection after the request completes, set a
"Connection: Close" header on the request.

Yes! Exactly what I was looking for. And it works. Thanks a bunch!!

Nahor

[EMonaco]

I wish this was a solution for me, unfortunately, I need something else as I
can not change the 3rd party component we are using as it is no longer
supported.



Erin.

Post by Nahor

Post by Stephen Sulzer
To tell WinInet to close the connection after the request completes, set a
"Connection: Close" header on the request.

Yes! Exactly what I was looking for. And it works. Thanks a bunch!!
Nahor

[Nahor]

From what I've seen "directly" from the WinINet debug log is that
HEADER/CONTENT is attempted once on the old socket, and after it opens the
new and does the SSL handshake on that, it is then only sending request
headers, no content....

Yes, you're right. I tried again but sending 10KB of dummy data. This I
can't mistake with headers data. Result: only 3 SSL data packets were
sent on the failed request (147 bytes, 342 and 21). Obviously less than
10KB.
Sorry for the false info and I appreciate the effort you spent
correcting it. :)


Nahor

[Nahor]

I've been working with the 6.0.2800.1106 and 6.0.2800.1400 debug
logging versions of WinInet. The socket reuse appears in 1106

I haven't looked in details, I just did a quick verification and I can
confirm that 1106 does work but not 1400 (Q832894). I've looked at a
Win2K Japanese machine and a Win98 French. My own machine XP Pro English
doesn't work with 1400 but used to until the second half of January
(which matches well with the 1/24 you talked about).

Thanks for the info and I'm looking forward to hear about you again :)

Nahor

[EMonaco]

Nahor,

Just got a response from MS Dev support:
Have not tried fix or anything yet.

<><><>
Hello

After researching this issue further, it appears you may be running into
yet another bug:

831167 Wininet retries POST requests with a blank header
http://support.microsoft.com/?id=831167


KB article above has a fix. Just like previous patch, you need to
install a new fix and make sure that registry is configured as explained
in KB.

Please try this fix and let me know if this resolves the issue.

<><><>

What makes me MAD is that I think I actually ran across this early on this
month, and just forgot about it (because we had 3 separate issues all with
HTTPS!

Erin.

Post by Nahor
Hi,
I have a little program in VB that uses WinInet to post (POST request)
data on a server through HTTPS.
The first request works fine.
Any following requests that quickly follow (less than ~17s after the
previous request) works fine.
If a request is made more than ~17s after the previous one, it fails.
When I say "fail", the CGI on the server is correctly called but there
is no data in the request (in perl, $ENV{CONTENT_LENGTH} == 0).
A simple C# program that uses WebClient.UploadData() works fine which
indicates that problem is on the client side.
Sniffing the network, I see that WinInet tries to keep the SSL socket
opened and reuses it for the following requests.
However, after ~17s, the server closes the socket on its end but Winet
doesn't seem aware of it. When the next request comes, Wininet tries to
use that socket and fails. It then reopens a new one but somehow, the
POST data doesn't arrives in the CGI.
Is there a way to force WinInet to close its socket when a request is
done? Or is there another solution?
Nahor

[Nahor]

Post by EMonaco
831167 Wininet retries POST requests with a blank header
http://support.microsoft.com/?id=831167

I tried it on the Win2K Japanese and Win98 French and it works on both.
Thanks Erin,

Nahor

[EMonaco]

All,

I've tried the patch (which is a 6.0.2800.1405 wininet.dll) it worked on
both my own wininet repro code as well as the 3rd party component (in a
quick test). I'll spend the weekend hammering on it to make sure we are set-
have also asked MS if there is a 1405 debug version (cuz I didn't see it at
the FTP site I posted in the "Log File for Wininet" thread a few posts down.

I also have to validate that the workarounds we've done for the other 2
issues still work with this latest version of WinINet.


Erin.

Post by EMonaco
Nahor,
Have not tried fix or anything yet.
<><><>
Hello
After researching this issue further, it appears you may be running into
831167 Wininet retries POST requests with a blank header
http://support.microsoft.com/?id=831167
KB article above has a fix. Just like previous patch, you need to
install a new fix and make sure that registry is configured as explained
in KB.
Please try this fix and let me know if this resolves the issue.
<><><>
What makes me MAD is that I think I actually ran across this early on this
month, and just forgot about it (because we had 3 separate issues all with
HTTPS!
Erin.

Post by Nahor
Hi,
I have a little program in VB that uses WinInet to post (POST request)
data on a server through HTTPS.
The first request works fine.
Any following requests that quickly follow (less than ~17s after the
previous request) works fine.
If a request is made more than ~17s after the previous one, it fails.
When I say "fail", the CGI on the server is correctly called but there
is no data in the request (in perl, $ENV{CONTENT_LENGTH} == 0).
A simple C# program that uses WebClient.UploadData() works fine which
indicates that problem is on the client side.
Sniffing the network, I see that WinInet tries to keep the SSL socket
opened and reuses it for the following requests.
However, after ~17s, the server closes the socket on its end but Winet
doesn't seem aware of it. When the next request comes, Wininet tries to
use that socket and fails. It then reopens a new one but somehow, the
POST data doesn't arrives in the CGI.
Is there a way to force WinInet to close its socket when a request is
done? Or is there another solution?
Nahor

[Stephen Sulzer]

Geez. I don't understand why the fix for MS04-004 broke POST-over-SSL
scenarios in which the persistent connection from the socket pool had
expired. For WinInet, MS04-004 was just suppose to disallow
"username:password" in HTTP URLs and also discard certain stored passwords.
Good grief!

Post by EMonaco
Nahor,
Have not tried fix or anything yet.
<><><>
Hello
After researching this issue further, it appears you may be running into
831167 Wininet retries POST requests with a blank header
http://support.microsoft.com/?id=831167
KB article above has a fix. Just like previous patch, you need to
install a new fix and make sure that registry is configured as explained
in KB.
Please try this fix and let me know if this resolves the issue.
<><><>
What makes me MAD is that I think I actually ran across this early on this
month, and just forgot about it (because we had 3 separate issues all with
HTTPS!
Erin.

[EMonaco]

Stephen,

You know, I've asked myself that same question. I don't get it either.
Here is another example of "Huh? What're they doin with the .1400 vs the
.1106?

[.1106 Synchronous HttpOpenRequest()]
13:21:39.604 00000b70:<app> 001 HttpOpenRequestA(0xcc0020, "POST",
"/xxxxx/xxxxxx/xxxxxxxxxxxx/xxxx/xxxxxxx.xxxx", "", "", 0x0, 0x848c0300,
0x00000000)
13:21:39.703 00000b70:<app> 002 InternetCreateUrlA(0xd6dfd0, 0x0,
0x16df88, 0xd6e010)
13:21:39.703 00000b70:<app> 002 URL =
"https://xxx.xxxxx.xxx:nnnn/xxxxx/xxxxxx/xxxxxxxxxxxx/xxxx/xxxxxxx.xxxx"
13:21:39.703 00000b70:<app> 002 InternetCreateUrlA() returning TRUE
13:21:39.703 00000b70:<app> 002
InternetCanonicalizeUrlA("https://xxx.xxxxx.xxx:nnnn/xxxxx/xxxxxx/xxxxxxxxxx
xx/xxxx/xxxxxxx.xxxx", 0x16b9f0, 0xd6e010 [75], 0x4000000)
13:21:39.703 00000b70:<app> 002 InternetCanonicalizeUrlA() returning TRUE
13:21:39.703 00000b70:<app> 001 HttpOpenRequestA() returning handle 0xcc0024

[.1400 Synchronous HttpOpenRequest()]
16:35:34.452 00000f78:<app> 001 HttpOpenRequestA(0xcc0008, "POST",
"/xxxxx/xxxxxx/xxxxxxxxxxxx/xxxx/xxxxxxx.xxxx", "", "", 0x0, 0x848c0300,
0x00000000)
16:35:34.452 00000f78:<app> 002 InternetCreateUrlA(0xc7eb5c, 0x2000,
0x1cb4c0, 0xc7eb9c)
16:35:34.452 00000f78:<app> 002 URL =
"https://xxx.xxxxx.xxx:nnnn/xxxxx/xxxxxx/xxxxxxxxxxxx/xxxx/xxxxxxx.xxxx"
16:35:34.453 00000f78:<app> 002 InternetCreateUrlA() returning TRUE
16:35:34.453 00000f78:<app> 002
InternetCanonicalizeUrlA("https://xxx.xxxxx.xxx:nnnn/xxxxx/xxxxxx/xxxxxxxxxx
xx/xxxx/xxxxxxx.xxxx", 0x166910, 0xc7eb9c [70], 0x4000000)
16:35:34.453 00000f78:<app> 002 InternetCanonicalizeUrlA() returning 122
[ERROR_INSUFFICIENT_BUFFER]
16:35:34.453 00000f78:<app> 002 InternetCanonicalizeUrlA() returning FALSE
16:35:34.453 00000f78:<app> 002
InternetCanonicalizeUrlA("https://xxx.xxxxx.xxx:nnnn/xxxxx/xxxxxx/xxxxxxxxxx
xx/xxxx/xxxxxxx.xxxx", 0x166910, 0xc7eb9c [71], 0x4000000)
16:35:34.453 00000f78:<app> 002 InternetCanonicalizeUrlA() returning TRUE
16:35:34.453 00000f78:<app> 001 HttpOpenRequestA() returning handle 0xcc000c

The URL is 71 bytes (this includes the null). The 1106 version seems to
allocate a buffer lstrlen(URL)+5; The 1400 version allocates the buffer at
just lstrlen(URL), the problem with this is that InternetCanonicalizeUrl()
will ALWAYS fail on the first attempt now with [ERROR_INSUFFIECIENT_BUFFER].
Forcing it to increase the buffer size and than reissue the
InternetCanconicalizeUrl() call. (I'd think they would start with
lstrlen(URL)+1 (for null) and if no substitutions are necessary you're good
to go.) This caused a problem in some of my apps because I am doing
asynchronous calls- I would just check the GetLastError() for
ERROR_IO_PENDING. The problem is the 0x7A [ERROR_INSUFFICIENT_BUFFER] would
end up being returned on GetLastError() for the HttpOpenRequest() if the
call completed synchronously (which it apparently always does).
Unfortunately, even though GetLastError() is not returning ERROR_SUCCESS,
the call does return a valid handle.

Now some of you may point out that I should be checking the value returned
from HttpOpenRequest() before calling GetLastError() and I can not argue
with that. But I remind you that my point is I don't see the point for the
change they made. The way they have it now, even if NO substitutions are
required the call WILL fail requiring additional processing and another call
to InternetCanonicalizeUrl().

Erin.

Post by Stephen Sulzer
Geez. I don't understand why the fix for MS04-004 broke POST-over-SSL
scenarios in which the persistent connection from the socket pool had
expired. For WinInet, MS04-004 was just suppose to disallow
"username:password" in HTTP URLs and also discard certain stored passwords.
Good grief!

Post by EMonaco
Nahor,
Have not tried fix or anything yet.
<><><>
Hello
After researching this issue further, it appears you may be running into
831167 Wininet retries POST requests with a blank header
http://support.microsoft.com/?id=831167
KB article above has a fix. Just like previous patch, you need to
install a new fix and make sure that registry is configured as explained
in KB.
Please try this fix and let me know if this resolves the issue.
<><><>
What makes me MAD is that I think I actually ran across this early on this
month, and just forgot about it (because we had 3 separate issues all with
HTTPS!
Erin.