#206 TLS socket fileevent write handler not called on negotiation failure

[Ashok P. Nadkarni]

In wish:

proc pargs {args} {puts [join $args ,]}
set so [twapi::tls_socket -async expired.badssl.com 443; fileevent $so writable [list pargs $so]

The above TLS negotiation fails - expire cert. However the handler pargs is never invoked.

[Harald Oehlmann]

Preface

Thank you for bringing this annoying issue up into a small example.

This is probably due to the weakness of the stacked channel architecture in error cases.
I suppose, the same issues apply to TCLTLS.
It is probalbly a stacked channel issue and not a TWAPI issue.

Nevertheless, Ashok is in a good position to look after this.
If I can be of any help, please advice.
I may retry to trigger Andreas to look into this regarding stacked channels.
Expert time is a rare resource and we are all voluntears.

May I ask you to check, if you get the same results as I do.
I am working on TCL8.6.12 32bit on Windows 64.
I enter the examples into the console.

Example code

There is a bracket missing in the example. So, I re-spelled it like:

proc pargs {args} {puts "<[join $args ,]>"}
set so [twapi::tls_socket -async expired.badssl.com 443]
fileevent $so writable [list pargs $so]

I can confirm, that the fileevent never fires, even after waiting for the socket timeout.

This is my typicall use-case of a socket. In consequence, all my programs will not work.
This is an issue for me and many others.

TWAPI 4.7.1

I have tried this with TWAPI 4.7.1, which has enhancements in this field.
Here is the result:

% set so [twapi::tls_socket -async expired.badssl.com 443]
rc2
% fconfigure $so -error
key "Socket" not known in dictionary

In TWAPI, the "-error" situation may probably be enhanced. At least, the error origins from TWAPI code. Here is the stack trace:

% set so [twapi::tls_socket -async expired.badssl.com 443]
rc10
% catch {fconfigure $so -error} err derr
1
(el1005_scanlink_integration) 33 % set derr
-errorstack {INNER dictGet CALL {_chansocket rc10} CALL {cget rc10 -error}} -errorcode {TCL LOOKUP DICT Socket} -errorinfo {key "Socket" not known in dictionary
    while executing
"dict get $_channels($chan) Socket"
    (procedure "_chansocket" line 7)
    invoked from within
"_chansocket $chan"
    (procedure "cget" line 16)
    invoked from within
"::twapi::tls cget rc10 -error"
    (chan handler subcommand "cget")
    invoked from within
"fconfigure $so -error"} -errorline 1 -code 1 -level 0

And I have thought, there is a guard against this error in TWAPI 4.7.1.

Get the error by a blocking read command

The only way I found to find the correct error message is a blocking read command:

% set so [twapi::tls_socket -async expired.badssl.com 443]
% catch {read $so} err derr
1
% pdict derr
dict derr
-errorstack -> 'INNER {invokeStk1 InitializeSecurityContext {937008 94172512} {937008 94172672} expired.badssl.com 32768 0 0 {{2 <huge block of mixed binary data> e_loop rc2} CALL {_blocking_negotiate_loop rc2} CALL {_blocking_negotiate_loop rc2} CALL {_client_blocking_negotiate rc2} CALL {_negotiate2 rc2} CALL {_negotiate rc2} CALL {_negotiate rc2} CALL {_negotiate rc2} CALL {read rc2 4096}'
-errorcode  -> 'TWAPI_WIN32 -2146893016 {Das empfangene Zertifikat ist abgelaufen.}'
-errorinfo  -> 'Das empfangene Zertifikat ist abgelaufen.
    while executing
"InitializeSecurityContext  $Credentials  $Handle  $Target  $Inattr  0  $Datarep  $inbuflist  0"
    (procedure "sspi_step" line 35)
    invoked from within
"sspi_step $SspiContext $indata"
    (procedure "rethrow" line 2)
    invoked from within
"rethrow"
    invoked from within
"trap {
            lassign [sspi_step $SspiContext $indata] status outdata leftover
        } onerror {} {
            debuglog "sspi_step returned er..."
    (procedure "_blocking_negotiate_loop" line 23)
    invoked from within
"_blocking_negotiate_loop $chan"
    (procedure "_client_blocking_negotiate" line 8)
    invoked from within
"_client_blocking_negotiate $chan"
    (procedure "_negotiate2" line 53)
    invoked from within
"_negotiate2 $chan"
    (procedure "rethrow" line 2)
    invoked from within
"rethrow"
    invoked from within
"trap {
        _negotiate2 $chan
    } onerror {} {
        variable _channels
        if {[info exists _channels($chan)]} {
            if {[dict get..."
    (procedure "_negotiate" line 3)
    invoked from within
"_negotiate $chan"
    (procedure "read" line 12)
    invoked from within
"::twapi::tls read rc2 4096"
    (chan handler subcommand "read")
    invoked from within
"read $so"'
-errorline  -> '1'
-code       -> '1'
-level      -> '0'

The stack trace is highly reduced due to big binary blocks included.
IMHO it is easy to reproduce, so try it on your own ;-).

The timing is 300 ms:

% timerate {set so [twapi::tls_socket -async expired.badssl.com 443]; catch {read $so}} 1
313332.0 µs/# 1 # 3.192 #/sec 313.332 net-ms

Non blocking IO

The only way to avoid deadlocks is non-blocking I/O. Here is an example with non-blocking read:

% set so [twapi::tls_socket -async expired.badssl.com 443];fconfigure $so -blocking 0;for {set c 0} {$c < 10000} {incr c} {puts -nonewline "$c,[read $so] ";update;after 100}
0, 1, 2, 3, Das empfangene Zertifikat ist abgelaufen.

The correct error message is returned.

Remark, that the "update" is required. Otherwise, we will run in a socket timeout after 52 seconds. I suppose, this also applies on currect connects.

Current work-arounds

Current work-arounds may be a periodic check for:

• a non-blocking read (as above)
• error in "fconfigure $so -error"

Here is the test code for the 2nd work around:

% set so [twapi::tls_socket -async expired.badssl.com 443];for {set c 0} {$c < 700} {incr c} {puts -nonewline "$c,[fconfigure $so -error] ";update;after 100}
0, 1, 2, key "Socket" not known in dictionary

Thank you all,
Harald

[Anonymous]

Harald,

Let us tackle the problem with fileevent not firing first.

Did you type the commands into the wish shell or in a script? Please try running as a script, not typing into a shell. If you type into a shell, type the line

set so [twapi::tls_socket -async expired.badssl.com 443]; fileevent $so writable [list pargs $so]

as a single line (the two commands separated by colon), not as two separate lines.

Do you see the event firing then?

[Anonymous]

BTW, my previous post does not imply there is no bug. It is more to narrow down the solution

[Harald Oehlmann]

Dear Ashok,
sorry, I was not notified about your post. I forgot to subscribe.

Here is the proposed test:

% proc pargs {args} {puts "<[join $args ,]>"}
% set so [twapi::tls_socket -async expired.badssl.com 443]; fileevent $so writable [list pargs $so]
<rc0>

Yes, in this case, it works. So, the issue is, that the update should not be run jet.
Sorry, that was stupid and logic.

The important role of "update" got only clear to me after some experimentations.

Thanks also for the solution provided by private E-Mail. I will make tests today.

Thank you so much,
Harald

[Harald Oehlmann]

Preface

Thank you for the enhanced version of tls.tcl.
Please allow me to repeat the tests here for this use-case.

iocp was active and it was renamed to socket.
Sorry, I forgot this detail.

package require iocp_inet 
rename ::socket ::socket_ori
rename ::iocp::inet::socket ::socket

In addition, twapi socket is registered to the http package.
autoproxy ran, but probably did not do anything.

fileevent

Test, if the standard scripted fileevent still fires. The event queue did not run between socket and fileevent:

% proc pargs {args} {puts "<[join $args ,]>"}
% set so [twapi::tls_socket -async expired.badssl.com 443];fileevent $so writable [list pargs $so]
<rc0>

Test ok.

fileevent after update

In contrast to the former version, the fileevent now fires, even if the update ran.
Here is the code:

% proc pargs {args} {puts "<[join $args ,]>"}
% set so [twapi::tls_socket -async expired.badssl.com 443]
rc0
% fileevent $so writable [list pargs $so]
<rc0>

Remark that some time elapsed between the execution of the lines.
This did not work before and works now. The event fires -> fixed.

fconfigure -error

fconfigre -error reported a script error before, and not the real socket error.
So, lets try it again:

set so [twapi::tls_socket -async expired.badssl.com 443]
rc2
% catch {fconfigure $so -error} err derr
1
-errorstack -> 'INNER {returnImm {Socket not connected. Das empfangene Zertifikat ist abgelaufen.} {}} CALL {_chansocket rc3} CALL {cget rc3 -error}'
-errorcode  -> 'NONE'
-errorinfo  -> 'Socket not connected. Das empfangene Zertifikat ist abgelaufen.
    while executing
"error $error"
    (procedure "_chansocket" line 12)
    invoked from within
"_chansocket $chan"
    (procedure "cget" line 16)
    invoked from within
"::twapi::tls cget rc3 -error"
    (chan handler subcommand "cget")
    invoked from within
"fconfigure $so -error"'
-errorline  -> '1'
-code       -> '1'
-level      -> '0'

The error message is ok, but the command should not raise the error state.
We will see below, that this is critical for the http case.

Still an issue.

use case of http

Within the http package, the fileevent writable procedure tests fconfigure -error for the empty string.

% proc writeevent {so args} {
    # this is the original from http.tcl proc http::Connect
    if {
            [eof $so] ||
            [set err [fconfigure $so -error]] ne ""
    } {
       puts "Read error: $err"
   }
}
% set so [twapi::tls_socket -async expired.badssl.com 443];fconfigure $so -blocking 0;fileevent $so writable [list writeevent $so]
BGError {Socket not connected. Das empfangene Zertifikat ist abgelaufen.}
> Socket not connected. Das empfangene Zertifikat ist abgelaufen.
>     while executing
> "error $error"
>     (procedure "_chansocket" line 12)
>     invoked from within
> "_chansocket $chan"
>     (procedure "cget" line 16)
>     invoked from within
> "::twapi::tls cget rc4 -error"
>     (chan handler subcommand "cget")
>     invoked from within
> "fconfigure $so -error"
>     (procedure "writeevent" line 5)
>     invoked from within
> "writeevent rc4"
> --Traceback--
> INNER:returnImm {Socket not connected. Das empfangene Zertifikat ist abgelaufen.} {}
> CALL:_chansocket rc4
> CALL:cget rc4 -error
> CALL:writeevent rc4
> CALL:writeevent rc4
> CALL:::twapi::tls::_post_write_event_callback rc4
> 

To my analysis, the http package will fail in this case.
fconfigure -error should return the error without raising an error.

So, lets try with the http package with registered twapi socket TLS:

% set h [http::geturl https://expired.badssl.com]
^A1 URL https://expired.badssl.com - token ::http::1
{Using rc5 for expired.badssl.com:443 - token ::http::1} {} 
BGError {Socket not connected. Das empfangene Zertifikat ist abgelaufen.}
> Socket not connected. Das empfangene Zertifikat ist abgelaufen.
>     while executing
> "error $error"
>     (procedure "_chansocket" line 12)
>     invoked from within
> "_chansocket $chan"
>     (procedure "cget" line 16)
>     invoked from within
> "::twapi::tls cget rc5 -error"
>     (chan handler subcommand "cget")
>     invoked from within
> "fconfigure $state(sock) -error"
>     (procedure "http::Connect" line 8)
>     invoked from within
> "http::Connect ::http::1 https {} /"
> --Traceback--
> INNER:returnImm {Socket not connected. Das empfangene Zertifikat ist abgelaufen.} {}
> CALL:_chansocket rc5
> CALL:cget rc5 -error
> CALL:http::Connect ::http::1 https {} /
> CALL:http::Connect ::http::1 https {} /
> CALL:::twapi::tls::_post_write_event_callback rc5
> 

As supposed, the http package call runs into an error due to that fact.

use case of receiving first from server

I use long standing connection to a device (barcode scanner in my case), where the device may send at any time after the connect.
* a wirtable event is used after socket creation to cancel the connect timeout (not shown in example).
* a readable event is used to detect received data.

In the error case, this is tricky, as the write and read event should be called by the error case.

% proc writeevent {so args} {
    puts "write event fired"
    # here, the timeout is cancled
   fileevent $so writable ""
    fileevent $so readable [list readevent $so]
}
% proc readevent {so args} {
   if {[catch {set data [read $so]} err]} {
       puts "Read error: $err"
       close $so
   }
   # handle data and eof here...
}
% set so [twapi::tls_socket -async expired.badssl.com 443];fconfigure $so -blocking 0;fileevent $so writable [list writeevent $so]
write event fired
Read error: Das empfangene Zertifikat ist abgelaufen.

This is a great result and did probably not work with the old version, as the readable event would not have been executed after the update.

Result

Great improvement in fileevent and in the error text.
The "fconfigure -error" should not raise an error state

Thank you for all,
Harald

[Harald Oehlmann]

Thanks, Ashok, for sending the corrected version for the fconfigure -error issue.
I repeat all tests and only mention the so far failed tests.

fconfigure -error

fconfigre -error reported a script error before, and not the real socket error.
So, lets try it again:

% set so [twapi::tls_socket -async expired.badssl.com 443]
rc0
% catch {fconfigure $so -error} err derr
0
% set err
Das empfangene Zertifikat ist abgelaufen.

-> correct, error returned without error level.

use case of http

Within the http package, the fileevent writable procedure tests fconfigure -error for the empty string.

% proc writeevent {so args} {
    # this is the original from http.tcl proc http::Connect
    if {
            [eof $so] ||
            [set err [fconfigure $so -error]] ne ""
    } {
       puts "Read error: $err"
   }
}
% set so [twapi::tls_socket -async expired.badssl.com 443];fconfigure $so -blocking 0;fileevent $so writable [list writeevent $so]
Read error: Das empfangene Zertifikat ist abgelaufen.

Ok, now returns error without calling bg error.

So, lets try with the http package with registered twapi socket TLS:

% set h [http::geturl https://expired.badssl.com]
^A1 URL https://expired.badssl.com - token ::http::1
{Using rc4 for expired.badssl.com:443 - token ::http::1} {}
{WARNING - if testing, pay special attention to this case (GJ) which is seldom executed - token ::http::1}
{Closing socket rc4 (no connection info)}
connect failed Das empfangene Zertifikat ist abgelaufen.
% catch {http::geturl https://expired.badssl.com} err derr
1
 % set err
connect failed Das empfangene Zertifikat ist abgelaufen.

So, the command throws now an error what is ok.

Result

All issues fixed, thank you for the great work !

You rock,
Harald

[Anonymous]

Harald,

I’ve uploaded the new tclkits. Thanks for your testing

/Ashok

From: bugs@twapi.p.re.sourceforge.net bugs@twapi.p.re.sourceforge.net On Behalf Of Harald Oehlmann
Sent: Wednesday, June 22, 2022 11:10 PM
To: apnadkarni@users.sourceforge.net
Subject: [twapi:bugs] #206 TLS socket fileevent write handler not called on negotiation failure

Thanks, Ashok, for sending the corrected version for the fconfigure -error issue.
I repeat all tests and only mention the so far failed tests.

fconfigure -error

fconfigre -error reported a script error before, and not the real socket error.
So, lets try it again:

% set so [twapi::tls_socket -async expired.badssl.com 443]
rc0
% catch {fconfigure $so -error} err derr
0
% set err
Das empfangene Zertifikat ist abgelaufen.

-> correct, error returned without error level.

use case of http

Within the http package, the fileevent writable procedure tests fconfigure -error for the empty string.

% proc writeevent {so args} {
# this is the original from http.tcl proc http::Connect
if {
[eof $so] ||
[set err [fconfigure $so -error]] ne ""
} {
puts "Read error: $err"
}
}
% set so [twapi::tls_socket -async expired.badssl.com 443];fconfigure $so -blocking 0;fileevent $so writable [list writeevent $so]
Read error: Das empfangene Zertifikat ist abgelaufen.

Ok, now returns error without calling bg error.

So, lets try with the http package with registered twapi socket TLS:

% set h [http::geturl https://expired.badssl.com]
^A1 URL https://expired.badssl.com - token ::http::1
{Using rc4 for expired.badssl.com:443 - token ::http::1} {}
{WARNING - if testing, pay special attention to this case (GJ) which is seldom executed - token ::http::1}
{Closing socket rc4 (no connection info)}
connect failed Das empfangene Zertifikat ist abgelaufen.
% catch {http::geturl https://expired.badssl.com} err derr
1
% set err
connect failed Das empfangene Zertifikat ist abgelaufen.

So, the command throws now an error what is ok.

Result

All issues fixed, thank you for the great work !

You rock,
Harald

---

[bugs:#206] https://sourceforge.net/p/twapi/bugs/206/ TLS socket fileevent write handler not called on negotiation failure

Status: open
Target Release: Unscheduled
Created: Sun Nov 14, 2021 08:31 AM UTC by Ashok P. Nadkarni
Last Updated: Tue Jun 21, 2022 07:07 PM UTC
Owner: nobody

In wish:

proc pargs {args} {puts [join $args ,]}
set so [twapi::tls_socket -async expired.badssl.com 443; fileevent $so writable [list pargs $so]

The above TLS negotiation fails - expire cert. However the handler pargs is never invoked.

---

Sent from sourceforge.net because apnadkarni@users.sourceforge.net apnadkarni@users.sourceforge.net is subscribed to https://sourceforge.net/p/twapi/bugs/

To unsubscribe from further messages, a project admin can change settings at https://sourceforge.net/p/twapi/admin/bugs/options. Or, if this is a mailing list, you can unsubscribe from the mailing list.

[Harald Oehlmann]

Thank you, TWAPI release 4.7.2 fixes this. Thanks for making a real release for this issue.

Bug may be closed.
THanks for all,
Harald

Just as a side not for people, who may repeat this:
if a custom verify command is used, the error decission is on the command.

So, with the following configuration, the issue is not detected:

http::register https 443 {::twapi::tls_socket -verifier TWAPIVerifier}
proc TWAPIVerifier {args} {
    return 1
}
% set h [http::geturl https://expired.badssl.com]
::http::4
% http::status $h
ok
% http::code $h
HTTP/1.1 200 OK
% http::data $h
<!DOCTYPE html>
<html>
<head>
  <meta charset="utf-8">
  <meta name="viewport" content="width=device-width, initial-scale=1">
  <link rel="shortcut icon" href="/icons/favicon-red.ico"/>
  <link rel="apple-touch-icon" href="/icons/icon-red.png"/>
  <title>expired.badssl.com</title>
  <link rel="stylesheet" href="/style.css">
  <style>body { background: red; }</style>
</head>
<body>
<div id="content">
  <h1 style="font-size: 12vw;">
    expired.<br>badssl.com
  </h1>
</div>

</body>
</html>