Tcl Source Code

I think this failure comes from the merge of
the rmax-ipv6-branch to trunk.  

==== socket-14.2 [socket -async] fileevent connection refused FAILED
==== Contents of test case:

        set client [socket -async localhost [randport]]
        fileevent $client writable {set x [fconfigure $client -error]}
        set after [after 1000 {set x timeout}]
        vwait x
        if {$x eq "timeout"} {
            append x ": [fconfigure $client -error]"
        }
        set x

---- Result was:
timeout: connection refused
---- Result should have been (exact matching):
connection refused
==== socket-14.2 FAILED

allow_comments - 1

Checkin b56716f2ac6b6dc0e769 2011-06-28 11:32:15
creates many http.test and http11.test failures on the
Solaris platform.

Hmm - that last change reverses the order of the result in socket-14.1, but as this order might even be OS dependent and the test only wants to see that both events happen regardless of the order, I'll just lsort the list.

Yes, I also figured that more comments are needed and had already written the following two when your post arrived:
above getsockopt():
                 * Read the error state from the socket to see if the async
                 * connection has succeeded or failed. As this clears the
                 * error condition, we cache the status in the socket state
                 * struct for later retrieval by [fconfigure -error].
... and above Tcl_NotifyChannel():
             * If an asynchronous connection has finally failed, we need to
             * repost the writable event here, because at least some OSes
             * clear the writable state from the socket when the error is
             * read, and so a subsequent select() on behalf of a script level
             * [fileevent] will not fire.
I think I'll append the second half of your second comment.

I have no proof that the latest assertion holds, but I am pretty confident it does, as I see no reason why socket should stop being writable after a connection has been established and before any data has been written to it. But of course it shouldn't hurt to call Tcl_NotifyChannel() regardless of the status, as it'll just save the core another round through select() in the successful case.

Good -- that fixes it !
Please add a comment, because the whole sequence of causality is utterly cryptic to the unaccustomed eye.
For example:

(near the getsockopt cacheing)

/* here we cache the SO_ERROR because it is read destructively */

(near the "if (status != 0)")

/* when getsockopt(SO_ERROR) has returned (and cleared) a nonzero error, it also clears the writable state of the socket in the kernel, preventing a subsequent select() from seeing it again. So we post the fileevent at the Tcl level, so that the notifier will dequeue it before calling select(). Note the condition is necessary and sufficient: when getsockopt(SO_ERROR) reports a zero, no side-effect occurs. */

Reinhard, by the way, do you have proof of that latest assertion holds ? Or dies it just Works On Your Machines ?

Ah - I think I got it. My code was already reposting the event, because OpenBSD also removes the writable state from the socket when reading and clearing the error, but the check for whether this reposting is needed at the bottom of CreateClientSocket() was flawed. It only checked for status being smaller than zero, but getsockopt returns the error value as a positive integer.
So, changing the "if (status < 0) {" to "if (status != 0) {" in the last block of CreateClientSocket() should do the trick.
After that change, strace shows that no second select is happening anymore.

BTW, is it really needed to watch the socket for exceptions here? I did it, because the internal event handler for server socket callbacks do so, but in my tests I've never seen a socket to fire an exception. Given that it is not even possible to set up an exception handler from script level, my guess would be that it is not needed.

OK. In fact, as Konstantin Khomoutov mentioned on the chat, the error-resetting is documented, and hence not so kernel-dependent:

       SO_ERROR
              Get and clear the pending socket error.  Only valid as a getsockopt(2).  Expects an integer.

What *is* kernel dependent, instead, is the secondary side-effect of clearing the writable status.

So, it seems the way out is to arrange for the cached writable-fileevents to be posted directly, without going again through the notifier's select(). Other fileevents (readable) must still be hooked normally, since at that spot we have no proof that the socket is/was readable.

I added the status caching, because on the newer Linux kernel where I developed the code, only the first call to getsockopt(SOL_SOCKET, SO_ERROR) returned the error code and subsequent calls returned success, so the internal event handler would have consumed the error and the user fileevent would have had no chance to find out whether the connection was successful or not.

After a bit of explanations on the chat, I agree that this may be useful for the IPv6 transition, as more and more servers will get DNS records for both their v4 and v6 address.

Now I have found the critical OS behavior that makes the bug appear or disappear: though a first select(writable)  does end up calling TcpAsyncCallback (when the outcome of the asynchronous connection is known), at this spot the code calls getsockopt(SOL_SOCKET, SO_ERROR). On some OSes, like Fedora 12, it turns out that this has a side-effect: the OS no longer things the socket is writable when the outcome is "connection error". This can be seen very clearly through strace: the second select() doesn't wake up on the writable bit when the getsockopt is present, and does when it is not.

By removing the resort to the cached getsockopt (->status field), everything works.
Reinhard, can you explain why you added it ?

File Added - 416162: trace

[00:19]ferrieuxc'mon, this is prio-9, a very recent change, and dgp said he would like to push 8.6b2 out ...
[00:26]ferrieuxanybody aware of the discussion regarding the ability for [connect -async] to try multiple addresses (from DNS) in sequence ?
[00:26]   * ferrieux can't find a TIP
[00:27]ferrieuxto me, sounds like the kind of black magic that doesn't fit in the core. The app will want to have a word to say on the order of the sequence, for example.
[00:31]ferrieuxokay, wrong timezone, but for the record: I am for a revert of 8eefe5a06f

OK, quick dive :)
As it turns out, one single select-callback can be hooked on a given fd at any given time (with Tcl_CreateFileHandler). As a result, the new TcpAsyncCallback and the generic TclChannelEventScriptInvoker (which supports user fileevents) are mutually exclusive. In other words, in no way can internal file handlers not based on TclChannelEventScriptInvoker coexist with user fileevents. As a consequence, there are two options:

 (1) use a scripted callback (a true fileevent) to the same effect (with possible introspection by the curious)

 (2) revert this change, which has not been backed by a TIP anyway

Oh, my conclusion from strace was hasty: the fileevent doesn't fire. Here, source-diving is much more productive.

The core of the bug is that with the new code, an internal writable fileevent is set up (TcpAsyncCallback), and when this one is called, it does Tcl_DeleteFileHandler(), which wipes out any user-provided fileevents.

Clearly this is new and related to the new callback, made necessary for multiple-address iterations.

I'll dive a bit more to grok how one is supposed to remove fileevents one by one. Just specifying the fd sounds too coarse.

FWIW, I do reproduce in 8.6, threaded and unthreaded, on my Fedora 12, but not in 8.5, threaded or unthreaded.
Also, a bit of strace shows that in the failing case, the fileevent does fire, but doesn't unlock th e vwait.

Reinhard, can you provide an strace -f -tt -T of the failing 8.5 and 8.6 on your machine ?

CentOS release 5.6 (Final)

$ uname -a
Linux localhost.localdomain 2.6.18-238.12.1.el5 #1 SMP Tue May 31 13:23:01 EDT 2011 i686 i686 i386 GNU/Linux

On what OS does socket-14.2 fail? The http-4.14 failure is almost certainly unrelated to the ipv6 merge, because it also fails for me on 8.5.

Also failing:

==== http-4.14 http::Event FAILED
==== Contents of test case:

    set token [http::geturl $badurl/?timeout=10 -timeout 10000 -command \#]
    if {$token eq ""} {
        error "bogus return from http::geturl"
    }
    http::wait $token
    http::status $token
    # error code varies among platforms.

---- Test completed normally; Return code was: 0
---- Return code should have been one of: 1
==== http-4.14 FAILED