Post over SSL

Hi,

I'm trying to complete POST requests over a HTTPS connection. I see in the
trace loggin that a successfull connection is made, and that the system
tries to read from the socket. But after that, the request freezes and no
data gets passed on. A GET request on the very same site functions
admirably.

The socket used to connect is in non-blocking mode (it was also non-blocking
during the GET request).

After 5 minutes, a timeout occurs in my application and libwww is shutdown.
Below is the trace logging gathered with HTSetTraceMessageMask( "sop" ) on a
small POST-test that I wrote. This pair of files work correctly when used
over HTTP. First a successfull fetch with a GET:

------------
Request..... Created 1400dc000
ChunkStream. Chunk 1400282a0 created with max size 0
HTAccess.... Accessing document https://xx.xx.xx.xx:10198/post.html
Net Before.. calling 3000480e700 (request 1400dc000, context 0)
Net Object.. 1400ca320 created with hash 0
Net Object.. starting request 1400dc000 (retry=1) with net object 1400ca320
HTTP........ Looking for `https://xx.xx.xx.xx:10198/post.html'
HTHost parse Looking up `xx.xx.xx.xx' on port 10198
Event....... Created event 1400c4f80 with context 1400ca3c0, priority 20,
and timeout 120000
Event....... Created event 1400c4f50 with context 1400ca3c0, priority 20,
and timeout 120000
Event....... Created event 1400c4fb0 with context 1400ca3c0, priority 20,
and timeout 120000
Host info... added `xx.xx.xx.xx' with host 1400ca3c0 to list 1400c9580
Host connect Grabbing lock on Host 1400ca3c0 with 1400ca320
Host info... Added Net 1400ca320 (request 1400dc000) to pipe on Host
1400ca3c0, 1 requests made, 1 requests in pipe, 0 pending
HTHost...... No ActivateRequest callback handler registered
HTHost 1400ca3c0 going to state TCP_CHANNEL.
HTHost 1400ca3c0 going to state TCP_DNS.
ParseInet... as port 10198 on xx.xx.xx.xx with 1 homes
HTHost 1400ca3c0 going to state TCP_NEED_SOCKET.
Socket...... Created 6
Net Manager. Increasing active sockets to 1, 0 persistent sockets
Socket...... Turned off Nagle's algorithm
Socket...... Non-blocking socket
Channel..... Hash value is 6
Channel..... Added 1400c4fe0 to list 140028360
HTSSLWriter. Created 1400c5040
Socket...... TCP send buffer size is 32768 for socket 6
HTHost 1400ca3c0 going to state TCP_NEED_CONNECT.
HTDoConnect. WOULD BLOCK `xx.xx.xx.xx'
Host Event.. WRITE passed to `https://xx.xx.xx.xx:10198/post.html'
HTHost 1400ca3c0 going to state TCP_CONNECTED.
HTHost 1400ca3c0 connected.
Host connect Unlocking Host 1400ca3c0
StreamStack. Constructing stream stack for text/x-http to */*
Tee......... Created stream 1400c5070 with resolver 3000a005a10
HTTP........ Dumping response to `w3chttp.out'
Tee......... Created stream 1400c50d0 with resolver 3000a005a10
HTTP........ Dumping request to `w3chttp.out'
HTTP........ Generating HTTP/1.x Request Headers
HTTPGen..... Extra local
HTTP........ Generating General Headers
Buffer...... Flushing 1400ca280
HTSSL New... Created new SSL Object 1400dc660
HTSSL....... Setting up 1400dc660 on socket 6
HTSSL....... New reference count = 1
SSL_connect: before/connect initialization
SSL_connect: SSLv3 write client hello A
SSL_connect: SSLv3 read server hello A
SSL_connect: SSLv3 read server certificate A
SSL_connect: SSLv3 read server key exchange A
SSL_connect: SSLv3 read server done A
SSL_connect: SSLv3 write client key exchange A
SSL_connect: SSLv3 write change cipher spec A
SSL_connect: SSLv3 write finished A
SSL_connect: SSLv3 flush data
SSL_connect: SSLv3 read finished A
HTSSLWriter. SSL returned 0
HTSSLWriter. 407 bytes written to 6
HTSSL New... Found SSL 1400dc660 with sd =  6
HTSSL....... New reference count = 2
HTSSLReader. SSL returned 0
HTSSLReader. 2328 bytes read from socket 6
Response.... Created 1400c5c40
Host info... New mode is 1 for host 1400ca3c0
Net Manager. 1 active sockets, increasing persistent sockets to 1
Host info... added host 1400ca3c0 as persistent
Net Object.. Persistent connection set ON succeeded
StreamStack. Constructing stream stack for message/rfc822 to */*
Error....... Add   2    Severity: 8     Parameter: `OK' Where:
`HTTPNextState'
Host........ passing 17 bytes as consumed to 1400e0800
Host........ 2311 bytes remaining 
MIME header. Date: Tue, 13 Jun 2000 18:17:30 GMT
MIME header. Server: Apache/1.3.12 (Unix) mod_perl/1.21 mod_ssl/2.6.2
OpenSSL/0.9.5a
MIME header. Cache-Control: no-cache
MIME header. Last-Modified: Tue, 13 Jun 2000 10:50:50 GMT
MIME header. ETag: "dc0e-7d6-3946120a"
MIME header. Accept-Ranges: bytes
MIME header. Content-Length: 2006
MIME header. Connection: close
MIMEParser.. Close received...
MIME header. Content-Type: text/html
Building.... C-T stack from www/unknown to */*
StreamStack. Constructing stream stack for www/unknown to */*
Building.... Content-Decoding stack
Building.... Transfer-Decoding stack
Host........ passing 305 bytes as consumed to 1400e0800
Host........ 2006 bytes remaining 
GUESSING.... Result of content analysis: Text=97% Newlines=2% Ctrl=0%
High=0%
Guessed..... Content-Type `text/plain'
StreamStack. Constructing stream stack for text/plain to */*
StreamStack. Source output
Host........ passing 2006 bytes as consumed to 1400e0800
Host........ 0 bytes remaining 
HTSSLReader. Target returns 200
HTTP Clean.. Called with status 200, net 1400ca320
Net Object.. Delete 1400ca320 and call AFTER filters
Host info... Remove 1400ca320 from pipe
Host Object. got close notifiation on socket 6
Channel..... Semaphore set to 0 for channel 1400c4fe0
Channel..... Delete 1400c4fe0 with semaphore 0, status 200
Channel..... Delete input stream 1400e0800 from channel 1400c4fe0
HTSSLReader. Free 1400e0800
HTSSL Free.. ref_count = 1
MIME........ FREEING....
Channel..... Delete input stream 1400e0800 from channel 1400c4fe0
HTSSLReader. FREEING....
HTSSLWriter. FREEING....
HTSSL Free.. ref_count = 0
HTSSL.Free.. FINAL RELEASE
Net Manager. Decreasing active sockets to 0, 1 persistent sockets
Channel..... Deleted 1400c4fe0, socket 6
Net Manager. 0 active sockets, decreasing persistent sockets to 0
Host info... removed host 1400ca3c0 as persistent
Net Object.. Check for pending Net objects
Net Object.. Freeing object 1400ca320
Net After... calling 120015c90 (request 1400dc000, response 1400c5c40,
status 200, context 0)
Request..... Delete 1400dc000
Request..... Deleting dangling output stream
Chunkstream. FREEING...
Request..... Deleting dangling debug stream
Chunkstream. FREEING...
Response.... Delete 1400c5c40
------------

Then the unsuccessfull POST request

------------
Request..... Created 1400dc000
ChunkStream. Chunk 1400c9480 created with max size 0
HTAccess.... Accessing document https://xx.xx.xx.xx:10198/perl/post.pl
Net Before.. calling 3000480e700 (request 1400dc000, context 0)
Net Object.. 1400ca320 created with hash 0
Net Object.. starting request 1400dc000 (retry=1) with net object 1400ca320
HTTP........ Looking for `https://xx.xx.xx.xx:10198/perl/post.pl'
HTHost parse Looking up `xx.xx.xx.xx' on port 10198
Event....... Created event 1400c4ec0 with context 1400ca3c0, priority 20,
and timeout 120000
Event....... Created event 1400c5130 with context 1400ca3c0, priority 20,
and timeout 120000
Event....... Created event 1400c5160 with context 1400ca3c0, priority 20,
and timeout 120000
Host info... added `xx.xx.xx.xx' with host 1400ca3c0 to list 140028340
Host connect Grabbing lock on Host 1400ca3c0 with 1400ca320
Host info... Added Net 1400ca320 (request 1400dc000) to pipe on Host
1400ca3c0, 1 requests made, 1 requests in pipe, 0 pending
HTHost...... No ActivateRequest callback handler registered
HTHost 1400ca3c0 going to state TCP_CHANNEL.
HTHost 1400ca3c0 going to state TCP_DNS.
ParseInet... as port 10198 on xx.xx.xx.xx with 1 homes
HTHost 1400ca3c0 going to state TCP_NEED_SOCKET.
Socket...... Created 6
Net Manager. Increasing active sockets to 1, 0 persistent sockets
Socket...... Turned off Nagle's algorithm
Socket...... Non-blocking socket
Channel..... Hash value is 6
Channel..... Added 1400c51c0 to list 1400dc440
HTSSLWriter. Created 1400c5190
Socket...... TCP send buffer size is 32768 for socket 6
HTHost 1400ca3c0 going to state TCP_NEED_CONNECT.
HTDoConnect. WOULD BLOCK `xx.xx.xx.xx'
Host Event.. WRITE passed to `https://xx.xx.xx.xx:10198/perl/post.pl'
HTHost 1400ca3c0 going to state TCP_CONNECTED.
HTHost 1400ca3c0 connected.
Host connect Unlocking Host 1400ca3c0
StreamStack. Constructing stream stack for text/x-http to */*
Tee......... Created stream 1400c5220 with resolver 3000a005a10
HTTP........ Dumping response to `w3chttp.out'
Tee......... Created stream 1400c5340 with resolver 3000a005a10
HTTP........ Dumping request to `w3chttp.out'
HTTP........ Generating HTTP/1.x Request Headers
HTTPGen..... Extra local
HTTP........ Generating General Headers
MIME........ Generating Entity Headers
Buffer...... Flushing 1400caa00
HTSSL New... Created new SSL Object 1400dc880
HTSSL....... Setting up 1400dc880 on socket 6
HTSSL....... New reference count = 1
SSL_connect: before/connect initialization
SSL_connect: SSLv3 write client hello A
SSL_connect: SSLv3 read server hello A
SSL_connect: SSLv3 read server certificate A
SSL_connect: SSLv3 read server key exchange A
SSL_connect: SSLv3 read server done A
SSL_connect: SSLv3 write client key exchange A
SSL_connect: SSLv3 write change cipher spec A
SSL_connect: SSLv3 write finished A
SSL_connect: SSLv3 flush data
SSL_connect: SSLv3 read finished A
HTSSLWriter. SSL returned 0
HTSSLWriter. 497 bytes written to 6
Uploading... Holding 1400c9580 for 21 ms using time 1400c53d0
HTSSL New... Found SSL 1400dc880 with sd =  6
HTSSL....... New reference count = 2
------------

Here the request hangs. After 5 minutes, my application closes down and
frees all libwww resources, and the following messages appear:

------------
SSL3 alert read:warning:close notify
HTSSLReader. SSL returned 6
HTSSLReader. FIN received on socket 6
HTSSL....... Closing SSL Object 1400dc880
HTSSL Free.. ref_count = 1
HTTP Clean.. Called with status -1, net 1400ca320
Net Object.. Delete 1400ca320 and call AFTER filters
Host info... Remove 1400ca320 from pipe
Host Object. closing socket 6
Channel..... Semaphore set to 0 for channel 1400c51c0
Channel..... Delete 1400c51c0 with semaphore 0, status -1
Channel..... Delete input stream 1400e0800 from channel 1400c51c0
HTSSLReader. Free 1400e0800
Channel..... Delete input stream 1400e0800 from channel 1400c51c0
HTSSLReader. FREEING....
HTSSLWriter. FREEING....
HTSSL Free.. ref_count = 0
HTSSL.Free.. FINAL RELEASE
Net Manager. Decreasing active sockets to 0, 0 persistent sockets
Channel..... Deleted 1400c51c0, socket 6
Host info... removed host 1400ca3c0 as persistent
Net Object.. Check for pending Net objects
Net Object.. Freeing object 1400ca320
Response.... Created 1400c5280
Net After... calling 120015c90 (request 1400dc000, response 1400c5280,
status -1, context 0)
Request..... Delete 1400dc000
Request..... Deleting dangling output stream
Chunkstream. FREEING...
Request..... Deleting dangling debug stream
Chunkstream. FREEING...
Response.... Delete 1400c5280
WWWLibTerm.. Cleaning up LIBRARY OF COMMON CODE
Net Object.. Kill ALL Net objects!!!
Event....... Deleted event 0
Event....... Deleted event 0
Event....... Deleted event 0
------------

Can anybody tell me whether or not this is supposed to work? If you need
more information, please tell me. I seriously don't see what is going wrong.
I have searched the mailing-lists, to no avail.

--
The woods are lovely, dark and deep,
But I have lines to code before I sleep, lines
to code before I sleep.

Received on Tuesday, 13 June 2000 15:03:25 UTC