tls::socket causes http::status to be eof
Taylor Venable
I'm using tls 1.6 with http 2.7.2 in Tcl 8.5.6 on OpenBSD-current
(i686). Calls to ::http::geturl will frequently fail with
::http::status being set to "eof" - indicating, I believe, that the
connection was closed before the response could be read. Some state
fields (like code) are the empty string, whereas others (like error)
are unset. My code currently simply retries geturl until it works,
and this is effective but oftentimes slightly more time-consuming as
it may take 8 or more retries to finally get the data.
Here's the code that I'm using:
==== [ CODE ] ========================================================
set LASTMSG {}
set LASTCOUNT 0
proc TlsDebug {args} {
global LASTMSG
global LASTCOUNT
if {$args ne $LASTMSG} {
if {$LASTCOUNT > 1} {
puts stderr "!!!!!!!! LAST MESSAGE REPEATED $LASTCOUNT
TIMES"
}
set LASTCOUNT 1
set LASTMSG $args
puts stderr "&&&&&&&& $args"
} else {
incr LASTCOUNT
}
}
::http::register https 443 [list ::tls::socket -ssl2 false -request false -require false -command TlsDebug]
proc post { username password url params {chunk 4096} {redirect false}} {
puts stderr "%%%%%%%% FETCHING $url"
set authorization [::base64::encode "$username:$password"]
set formatted_params [eval [concat "::http::formatQuery" $params]]
set token [::http::geturl $url \
-query $formatted_params \
-headers [list "Authorization" "Basic $authorization"] \
-blocksize $chunk]
upvar #0 $token state
# If the connection is closed too early,
# retry again until it works.
set attempts 1
while {$state(status) eq "eof"} {
::http::cleanup $token
set token [::http::geturl $url \
-query $formatted_params \
-headers [list "Authorization" "Basic $authorization"] \
-blocksize $chunk]
upvar #0 $token state
incr attempts
}
puts stderr "@@@@@@@@ MADE $attempts ATTEMPTS"
set max 0
foreach {name value} $state(meta) {
if {[string length $name] > $max} {
set max [string length $name]
}
if {[regexp -nocase ^location$ $name]} {
# Handle URL redirects
return [post [string trim $value] $params $chunk]
}
}
incr max
set response [dict create]
dict set response code $state(http)
dict set response body $state(body)
::http::cleanup $token
return $response
}
==== [ END CODE ] ====================================================
The extra information emitted by the tls code looks fairly normal to
me:
&&&&&&&& info sock5 handshake start {before/connect initialization}
&&&&&&&& info sock5 connect loop {before/connect initialization}
&&&&&&&& info sock5 connect loop {SSLv3 write client hello A}
&&&&&&&& info sock5 connect exit {SSLv3 read server hello A}
!!!!!!!! LAST MESSAGE REPEATED 1682 TIMES
&&&&&&&& info sock5 connect loop {SSLv3 read server hello A}
&&&&&&&& verify sock5 0 {sha1_hash ACCDF8F064C4A7419EA56CCE9FD6098752BBFB8D subject {CN=*.com,O=TrustBearer Labs,L=Fort Wayne,ST=Indiana,C=US} issuer {CN=*.com,O=TrustBearer Labs,L=Fort Wayne,ST=Indiana,C=US} notBefore {Mar 17 17:49:57 2008 GMT} notAfter {Dec 15 17:49:57 2017 GMT} serial FDAA3C51D4C50471} 0 {self signed certificate}
&&&&&&&& info sock5 connect loop {SSLv3 read server certificate A}
&&&&&&&& info sock5 connect loop {SSLv3 read server key exchange A}
&&&&&&&& info sock5 connect loop {SSLv3 read server done A}
&&&&&&&& info sock5 connect loop {SSLv3 write client key exchange A}
&&&&&&&& info sock5 connect loop {SSLv3 write change cipher spec A}
&&&&&&&& info sock5 connect loop {SSLv3 write finished A}
&&&&&&&& info sock5 connect loop {SSLv3 flush data}
&&&&&&&& info sock5 connect exit {SSLv3 read finished A}
!!!!!!!! LAST MESSAGE REPEATED 1657 TIMES
&&&&&&&& info sock5 connect loop {SSLv3 read finished A}
&&&&&&&& info sock5 handshake done {SSL negotiation finished successfully}
&&&&&&&& info sock5 connect exit {SSL negotiation finished successfully}
&&&&&&&& info sock5 alert read {close notify}
&&&&&&&& info sock5 alert write {close notify}
But then this same information repeats as many times as it takes to
finally get the information back out of the connection.
Does anybody have an idea as to what might be going wrong here? I see
no indication that there's anything wrong with the connection, but
http reports that it's been closed.
Thanks,
--
Taylor Christopher Venable
http://real.metasyntax.net:2357/
Alexandre Ferrieux
>
> I'm using tls 1.6 with http 2.7.2 in Tcl 8.5.6 on OpenBSD-current
> (i686). Calls to ::http::geturl will frequently fail with
> ::http::status being set to "eof" - indicating, I believe, that the
> connection was closed before the response could be read. Some state
> fields (like code) are the empty string, whereas others (like error)
> are unset. My code currently simply retries geturl until it works,
> and this is effective but oftentimes slightly more time-consuming as
> it may take 8 or more retries to finally get the data.
>
>
> Does anybody have an idea as to what might be going wrong here? I see
> no indication that there's anything wrong with the connection, but
> http reports that it's been closed.
This is strongly reminiscent of Bug 1945538
https://sourceforge.net/tracker/index.php?func=detail&aid=1945538&group_id=10894&atid=110894
(especially the "short read" part).
Bottom line: TLS has bugs when it comes to doing event-driven IO, like
async HTTP does.
I've contacted the current maintainer of TLS, Dan Razzell, and expect
him to help on this as soon as his constraints permit. Stay tuned.
(one thing you can do is add a comment to the above SF bug report,
maybe just saying "me too" :-)
-Alex