Noisy error messages when browser window is closed

[rdeits]

The bug

This was originally opened as https://github.com/rdeits/MeshCat.jl/issues/108 but I don't think there's anything I can do about it in MeshCat.jl directly. The problem is simply that rendering a WebIO scope in a browser window and then closing that window causes a long error stacktrace, even though the "error" is simply the normal closing of the websocket:

julia> Error handling websocket connection:
WebSockets.WebSocketClosedError("ws|server respond to OPCODE_CLOSE 1001:Going Away")
Stacktrace:
 [1] try_yieldto(::typeof(Base.ensure_rescheduled), ::Base.RefValue{Task}) at ./event.jl:196
 [2] wait() at ./event.jl:255
 [3] wait(::Condition) at ./event.jl:46
 [4] wait(::Task) at ./task.jl:188
 [5] create_socket(::Dict{Any,Any}) at /home/rdeits/.julia/packages/WebIO/2mZPb/src/providers/mux.jl:44
 [6] (::getfield(Mux, Symbol("##5#6")){getfield(Mux, Symbol("##28#29")){Array{SubString{String},1}},typeof(WebIO.create_socket)})(::Function, ::Dict{Any,Any}) at /home/rdeits/.julia/packages/Mux/FeATY/src/Mux.jl:17
 [7] #1 at /home/rdeits/.julia/packages/Mux/FeATY/src/Mux.jl:10 [inlined]
 [8] splitquery(::getfield(Mux, Symbol("##1#2")){getfield(Mux, Symbol("##5#6")){getfield(Mux, Symbol("##28#29")){Array{SubString{String},1}},typeof(WebIO.create_socket)},getfield(Mux, Symbol("##1#2")){typeof(Mux.wclose),getfield(Mux, Symbol("##1#2")){getfield(Mux, Symbol("##18#19")){getfield(Mux, Symbol("##22#23")){Symbol,Int64}},getfield(Mux, Symbol("##20#21")){String}}}}, ::Dict{Any,Any}) at /home/rdeits/.julia/packages/Mux/FeATY/src/basics.jl:34
 [9] #1 at /home/rdeits/.julia/packages/Mux/FeATY/src/Mux.jl:10 [inlined]
 [10] wcatch(::getfield(Mux, Symbol("##1#2")){typeof(Mux.splitquery),getfield(Mux, Symbol("##1#2")){getfield(Mux, Symbol("##5#6")){getfield(Mux, Symbol("##28#29")){Array{SubString{String},1}},typeof(WebIO.create_socket)},getfield(Mux, Symbol("##1#2")){typeof(Mux.wclose),getfield(Mux, Symbol("##1#2")){getfield(Mux, Symbol("##18#19")){getfield(Mux, Symbol("##22#23")){Symbol,Int64}},getfield(Mux, Symbol("##20#21")){String}}}}}, ::Dict{Any,Any}) at /home/rdeits/.julia/packages/Mux/FeATY/src/websockets_integration.jl:12
 [11] todict at /home/rdeits/.julia/packages/Mux/FeATY/src/Mux.jl:10 [inlined]
 [12] #3 at /home/rdeits/.julia/packages/Mux/FeATY/src/Mux.jl:14 [inlined] (repeats 2 times)
 [13] (::getfield(Mux, Symbol("##1#2")){getfield(Mux, Symbol("##3#4")){getfield(Mux, Symbol("##3#4")){typeof(Mux.todict),typeof(Mux.wcatch)},typeof(Mux.splitquery)},getfield(Mux, Symbol("##1#2")){getfield(Mux, Symbol("##5#6")){getfield(Mux, Symbol("##28#29")){Array{SubString{String},1}},typeof(WebIO.create_socket)},getfield(Mux, Symbol("##1#2")){typeof(Mux.wclose),getfield(Mux, Symbol("##1#2")){getfield(Mux, Symbol("##18#19")){getfield(Mux, Symbol("##22#23")){Symbol,Int64}},getfield(Mux, Symbol("##20#21")){String}}}}})(::Tuple{HTTP.Messages.Request,WebSockets.WebSocket{Sockets.TCPSocket}}) at /home/rdeits/.julia/packages/Mux/FeATY/src/Mux.jl:10
 [14] (::getfield(Mux, Symbol("##9#10")){Mux.App})(::HTTP.Messages.Request, ::WebSockets.WebSocket{Sockets.TCPSocket}) at /home/rdeits/.julia/packages/Mux/FeATY/src/server.jl:49
 [15] upgrade(::getfield(Mux, Symbol("##9#10")){Mux.App}, ::HTTP.Streams.Stream{HTTP.Messages.Request,HTTP.ConnectionPool.Transaction{Sockets.TCPSocket}}) at /home/rdeits/.julia/packages/WebSockets/pc4iW/src/HTTP.jl:201
 [16] (::getfield(WebSockets, Symbol("#_servercoroutine#11")){WebSockets.ServerWS})(::HTTP.Streams.Stream{HTTP.Messages.Request,HTTP.ConnectionPool.Transaction{Sockets.TCPSocket}}) at /home/rdeits/.julia/packages/WebSockets/pc4iW/src/HTTP.jl:370
 [17] macro expansion at /home/rdeits/.julia/packages/HTTP/hJSsm/src/Servers.jl:360 [inlined]
 [18] (::getfield(HTTP.Servers, Symbol("##13#14")){getfield(WebSockets, Symbol("#_servercoroutine#11")){WebSockets.ServerWS},HTTP.ConnectionPool.Transaction{Sockets.TCPSocket},HTTP.Streams.Stream{HTTP.Messages.Request,HTTP.ConnectionPool.Transaction{Sockets.TCPSocket}}})() at ./task.jl:259

This does not actually break anything, but it makes using WebIO difficult, particularly when there are real errors mixed in with this noise. I've trained myself to ignore it, but it's hard to ask end-users to do the same.

Context

WebIO 0.8.11, Mux 0.7.0, HTTP 0.8.6, WebSockets 1.5.2.

MWE

using WebIO
using Mux

n = node(:div, "hello world")
webio_serve(page("/", req -> n), 8000)

open localhost:8000 in your browser, then close the window and observe the backtrace output filling the Julia window.

[shashi]

@hustf do you know how to gracefully handle this?

[cstjean]

What I wonder is whether the app is GC'ed in spite of this error.

[hustf]

'End users' don't need even a one-liner I think.

WebSockets already hides the lowest level traces. The traces above are from Mux / WebIO. Since they are kind of intertwined, we'd need to revise both simultanously to use something like this approach:

import WebSockets.readguarded
while true
    data, success = readguarded(sock)
    !success && break
    println(String(data))
end

I had some trouble developing master now. Instead, with Revise and a minimum change approach we can drop it all:

julia> using WebIO,Mux
import Mux.wcatch
wcatch(app, req) = app(req)
n = node(:div, "hello world")
webio_serve(page("/", req -> n), 8000)

[hustf]

@cstjean: I think it is. But to be sure, I like to break directly out of read /write loops without checking isopen or eof.

[cstjean]

My tests with

                    finalizer(gui) do _
                        println("\n\n\n\n app was collected")
                    end

suggest that the app is never GC'ed :worried: . Refreshing the page over and over gradually increases memory usage without bounds, and calling GC.gc() does not collect it.

app was collected is printed many times when I close Julia, as the finalizers are run.