The first package will lost if server send package first.

WebSockets v1.5.2 HTTP v0.8.16.

steps to produce the issue:

start a server who will send a greeting immediately after the establishment of a web socket connection

using WebSockets
serverWS = WebSockets.ServerWS((req) -> WebSockets.Response(200), (ws_server) -> (writeguarded(ws_server, "Hello"); readguarded(ws_server)))
ta = @async WebSockets.with_logger(WebSocketLogger()) do
                       WebSockets.serve(serverWS, port = 8000)
                   end

then connect to the server and read the response. In most cases it will hang

WebSockets.open("ws://127.0.0.1:8000") do ws_client
                        data, success = readguarded(ws_client) # will hang with really high possibility!
                        if success
                            println(stderr, ws_client, " received:", String(data))
                        end
                    end;

I think it is the due to the same or similar cause of the issue #114 fixed 2 years ago.

That was a good job on #114!

I can't reproduce. Haven't checked which version of HTTP is used by Websockets now so that might be it.

However, won't the sequence of events here hard to predict? Perhaps different the first time and the second time you run it due to warming up? I ran the last line many times.

I put some logging into your code. Could you provoke the error again and post the output?

using WebSockets
serverWS = WebSockets.ServerWS(
    (req) -> begin
        @wslog "Got a http response, replying with 200"
        WebSockets.Response(200)
    end, 
    (ws_server) -> begin
        @wslog ws_server
        writeguarded(ws_server, "Hello")
        @wslog "We said hello, and will wait for one message before start closing."
        @wslog readguarded(ws_server)
        @wslog ws_server
        @wslog "A little unusually, we now start a closing protocol from the server side."
    end)

ta = @async WebSockets.with_logger(WebSocketLogger()) do
                       WebSockets.serve(serverWS, port = 8000)
                       @wslog "The server has exited now."
                   end

WebSockets.with_logger(WebSocketLogger()) do
    WebSockets.open("ws://127.0.0.1:8000") do ws_client
        @wslog readguarded(ws_client) # will hang with really high possibility!
    end
    @wslog "The client has exited now"
end

It is the the logging statement @wslog ws_server before ```writeguarded(ws_server, "Hello") hiding the bug.

just swap these two line, it will hang.

please have a look at the attached pdf. I changed @wslog to @info to make the code run in my setting.

WebSockets Client Test ( Server First) - Jupyter Notebook.pdf

versioninfo()

using Pkg
Pkg.activate(".")
Pkg.add("WebSockets")
Pkg.add("HTTP")
Pkg.add("MbedTLS")
Pkg.status()

using WebSockets
using Logging

serverWS = WebSockets.ServerWS(
    (req) -> begin
        @info "Got a http response, replying with 200"
        WebSockets.Response(200)
    end, 
    (ws_server) -> begin
        writeguarded(ws_server, "Hello")
        @info ws_server
        @info "We said hello, and will wait for one message before start closing."
        @info "server received:" readguarded(ws_server)
        @info ws_server
        @info "A little unusually, we now start a closing protocol from the server side."
    end)

ta = @async WebSockets.with_logger(WebSocketLogger()) do
                       WebSockets.serve(serverWS, port = 54321)
                       @info "The server has exited now."
                   end

WebSockets.with_logger(WebSocketLogger()) do
    WebSockets.open("ws://127.0.0.1:54321") do ws_client
        @info "client connected." ws_client
        data, success = readguarded(ws_client) # will hang with really high possibility!
        @info "client received: " data
        @info "read success: " success 
    end
    @info "The client has exited now"
end

the output looks like:

┌ Info: client connected.
└   ws_client = WebSocket{TCPSocket}(client, CONNECTED): paused
[ Info: WebSocket(server, CONNECTED)
[ Info: We said hello, and will wait for one message before start closing.

In cases you may need an automatic test, I write one:


using InteractiveUtils
versioninfo()

using Pkg
Pkg.activate(".")
Pkg.add("WebSockets")
Pkg.add("HTTP")
Pkg.add("MbedTLS")
Pkg.add("OpenTrick")
Pkg.status()

using Test
using WebSockets
using OpenTrick

function ws_handler(ws_server)  
    writeguarded(ws_server, "Hello")
    @info ws_server
    @info "We said hello, and will wait for one message before start closing."
    @info "server received:" readguarded(ws_server)
    @info ws_server
    @info "A little unusually, we now start a closing protocol from the server side."
end

function ws_handler_sleep_first(ws_server) 
    @info "sleep before sending first package..." 
    sleep(1)
    @info "Done."
    ws_handler(ws_server)
end

function do_test(;port=12345, sleep_first::Bool=false, ip="127.0.0.1")
    handler = sleep_first ? ws_handler_sleep_first : ws_handler
    server = WebSockets.ServerWS((req)->nothing, handler)
    server_task = @async WebSockets.serve(server, ip, port)
    client_io = opentrick(WebSockets.open, "ws://$(ip):$(port)/some/path")
    ret = Dict{String, Any}("data"=>nothing, "success"=>false)
    t = @async begin
            @info "reading greeting..."
            @warn "Will hang if WebSockets didn't fix bug #158 https://github.com/JuliaWeb/WebSockets.jl/issues/158"
            data, success = readguarded(client_io)
            data_str = String(data)
            @info "client received:" data_str success
            ret["data"] = data_str
            ret["success"] = success
            @info ret
            write(client_io, "bye")
            close(client_io)
        end
    @info t.state
    @test timedwait(()-> t.state != :runnable, 5.) === :ok
    @info ret
    @test ret["data"] == "Hello"
    @test ret["success"] == true
    put!(server.in, "Quit!")
    @test_throws TaskFailedException wait(server_task)
end

@testset "server first" begin
    @testset "sleep before sending Hello" begin
        do_test(sleep_first=true)
    end
    @testset "sending Hello first" begin
        do_test(sleep_first=false)
    end
end

for now the output looks like:

[root@7b850612e23f:~/Downloads/websockets_test 2020-07-24 04:39:28] 
^_^ ls
Manifest.toml  Project.toml  WebSocketsClientAutoTest.jl
[root@7b850612e23f:~/Downloads/websockets_test 2020-07-24 04:39:28] 
^_^ julia WebSocketsClientAutoTest.jl 
Julia Version 1.5.0-beta1.0
Commit 6443f6c95a (2020-05-28 17:42 UTC)
Platform Info:
  OS: Linux (x86_64-pc-linux-gnu)
  CPU: Intel(R) Core(TM) i7-4770HQ CPU @ 2.20GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-9.0.1 (ORCJIT, haswell)
Environment:
  JULIA_GPG = 3673DF529D9049477F76B37566E3C7DC03D6E495
  JULIA_VERSION = 1.5.0-beta1
  JULIA_PATH = /usr/local/julia
  JULIA_PKG_SERVER = https://pkg.julialang.org
 Activating environment at `~/Downloads/websockets_test/Project.toml`
   Updating registry at `~/.julia/registries/General`
...
Status `~/Downloads/websockets_test/Project.toml`
  [cd3eb016] HTTP v0.8.16
  [739be429] MbedTLS v1.0.2
  [102dff8d] OpenTrick v0.2.1
  [104b5d7c] WebSockets v1.5.2
[ Info: sleep before sending first package...
[ Info: runnable
[ Info: reading greeting...
┌ Warning: Will hang if WebSockets didn't fix bug #158 https://github.com/JuliaWeb/WebSockets.jl/issues/158
└ @ Main ~/Downloads/websockets_test/WebSocketsClientAutoTest.jl:42
[ Info: Done.
[ Info: WebSocket(server, CONNECTED)
┌ Info: client received:
│   data_str = "Hello"
└   success = true
[ Info: We said hello, and will wait for one message before start closing.
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
┌ Info: server received:
└   readguarded(ws_server) = (UInt8[0x62, 0x79, 0x65], true)
[ Info: WebSocket(server, CONNECTED)
[ Info: A little unusually, we now start a closing protocol from the server side.
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
[ Info: WebSocket(server, CONNECTED)
[ Info: runnable
[ Info: We said hello, and will wait for one message before start closing.
[ Info: reading greeting...
┌ Warning: Will hang if WebSockets didn't fix bug #158 https://github.com/JuliaWeb/WebSockets.jl/issues/158
└ @ Main ~/Downloads/websockets_test/WebSocketsClientAutoTest.jl:42
sending Hello first: Test Failed at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:53
  Expression: timedwait((()->begin
                t.state != :runnable
            end), 5.0) === :ok
   Evaluated: timed_out === ok
Stacktrace:
 [1] do_test(; port::Int64, sleep_first::Bool, ip::String) at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:53
 [2] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [3] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.5/Test/src/Test.jl:1114
 [4] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [5] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.5/Test/src/Test.jl:1114
 [6] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:62
[ Info: Dict{String,Any}("success" => false,"data" => nothing)
sending Hello first: Test Failed at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:55
  Expression: ret["data"] == "Hello"
   Evaluated: nothing == "Hello"
Stacktrace:
 [1] do_test(; port::Int64, sleep_first::Bool, ip::String) at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:55
 [2] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [3] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.5/Test/src/Test.jl:1114
 [4] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [5] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.5/Test/src/Test.jl:1114
 [6] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:62
sending Hello first: Test Failed at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:56
  Expression: ret["success"] == true
   Evaluated: false == true
Stacktrace:
 [1] do_test(; port::Int64, sleep_first::Bool, ip::String) at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:56
 [2] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [3] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.5/Test/src/Test.jl:1114
 [4] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [5] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.5/Test/src/Test.jl:1114
 [6] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:62
Test Summary:                | Pass  Fail  Total
server first                 |    5     3      8
  sleep before sending Hello |    4            4
  sending Hello first        |    1     3      4
ERROR: LoadError: Some tests did not pass: 5 passed, 3 failed, 0 errored, 0 broken.
in expression starting at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:61

Thank you for the extensive report, zhanglix. Your next-to-last example, run locally with me looks like:

┌ Info: client connected.
└   ws_client = WebSocket{TCPSocket}(client, CONNECTED): ✓
[ Info: WebSocket(server, CONNECTED)
[ Info: We said hello, and will wait for one message before start closing.
┌ Info: client received:
│   data =
│    5-element Array{UInt8,1}:
│     0x48
│     0x65
│     0x6c
│     0x6c
└     0x6f
┌ Info: read success:
└   success = true
┌ Info: server received:
└   readguarded(ws_server) = (UInt8[], false)
[ Info: The client has exited now
[ Info: WebSocket(server, CLOSED)
[ Info: A little unusually, we now start a closing protocol from the server side.

Also for the last test you provide (a similar quick close from the server side is included in test/runtests.jl), no error is triggered on my machine. Looking at the logs, I get HTTP v0.8.17 where your output says v0.8.16. HTTP v0.8.17 was released the day after your post, but the changes are irrelevant.

Log from your last test:

(@v1.4) pkg> activate .
 Activating new environment at `C:\Users\F\.julia\environments\WebSockets\Project.toml`

(@WebSockets) pkg> status
Status `C:\Users\F\.julia\environments\WebSockets\Project.toml`
  (empty environment)

julia> using InteractiveUtils

julia> versioninfo()
Julia Version 1.4.0
Commit b8e9a9ecc6 (2020-03-21 16:36 UTC)
Platform Info:
  OS: Windows (x86_64-w64-mingw32)
  CPU: Intel(R) Core(TM) i7-7700HQ CPU @ 2.80GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-8.0.1 (ORCJIT, skylake)
Environment:
  JULIA_ERROR_COLOR = yellow

julia>

julia> using Pkg

julia> Pkg.activate(".")
 Activating new environment at `C:\Users\F\.julia\environments\WebSockets\Project.toml`

julia> Pkg.add("WebSockets")
  Resolving package versions...
   Updating `C:\Users\F\.julia\environments\WebSockets\Project.toml`
  [104b5d7c] + WebSockets v1.5.2
   Updating `C:\Users\F\.julia\environments\WebSockets\Manifest.toml`
  [cd3eb016] + HTTP v0.8.17
  [83e8ac13] + IniFile v0.5.0
  [739be429] + MbedTLS v1.0.2
  [c8ffd9c3] + MbedTLS_jll v2.16.6+1
  [104b5d7c] + WebSockets v1.5.2
  [2a0f44e3] + Base64
  [ade2ca70] + Dates
  [8ba89e20] + Distributed
  [b77e0a4c] + InteractiveUtils
  [76f85450] + LibGit2
  [8f399da3] + Libdl
  [56ddb016] + Logging
  [d6f4376e] + Markdown
  [44cfe95a] + Pkg
  [de0858da] + Printf
  [3fa0cd96] + REPL
  [9a3f8284] + Random
  [ea8e919c] + SHA
  [9e88b42a] + Serialization
  [6462fe0b] + Sockets
  [8dfed614] + Test
  [cf7118a7] + UUIDs
  [4ec0a83e] + Unicode

julia> Pkg.add("HTTP")
  Resolving package versions...
   Updating `C:\Users\F\.julia\environments\WebSockets\Project.toml`
  [cd3eb016] + HTTP v0.8.17
   Updating `C:\Users\F\.julia\environments\WebSockets\Manifest.toml`
 [no changes]

julia> Pkg.add("MbedTLS")
  Resolving package versions...
   Updating `C:\Users\F\.julia\environments\WebSockets\Project.toml`
  [739be429] + MbedTLS v1.0.2
   Updating `C:\Users\F\.julia\environments\WebSockets\Manifest.toml`
 [no changes]

julia> Pkg.add("OpenTrick")
  Resolving package versions...
  Installed OpenTrick ─ v0.2.1
   Updating `C:\Users\F\.julia\environments\WebSockets\Project.toml`
  [102dff8d] + OpenTrick v0.2.1
   Updating `C:\Users\F\.julia\environments\WebSockets\Manifest.toml`
  [102dff8d] + OpenTrick v0.2.1

julia> Pkg.status()
Status `C:\Users\F\.julia\environments\WebSockets\Project.toml`
  [cd3eb016] HTTP v0.8.17
  [739be429] MbedTLS v1.0.2
  [102dff8d] OpenTrick v0.2.1
  [104b5d7c] WebSockets v1.5.2

julia>

julia>

julia> using Test

julia> using WebSockets

julia> using OpenTrick
[ Info: Precompiling OpenTrick [102dff8d-99cb-5cc2-9bf9-d9fe3a2e5e7a]
...
...
...
[ Info: sleep before sending first package...
[ Info: runnable
[ Info: reading greeting...
┌ Warning: Will hang if WebSockets didn't fix bug #158 https://github.com/JuliaWeb/WebSockets.jl/issues/158
└ @ Main REPL[18]:9
[ Info: Done.
[ Info: WebSocket(server, CONNECTED)
┌ Info: client received:
│   data_str = "Hello"
└   success = true
[ Info: We said hello, and will wait for one message before start closing.
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
┌ Info: server received:
└   readguarded(ws_server) = (UInt8[0x62, 0x79, 0x65], true)
[ Info: WebSocket(server, CONNECTED)
[ Info: A little unusually, we now start a closing protocol from the server side.
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
[ Info: WebSocket(server, CONNECTED)
[ Info: runnable
[ Info: We said hello, and will wait for one message before start closing.
[ Info: reading greeting...
┌ Warning: Will hang if WebSockets didn't fix bug #158 https://github.com/JuliaWeb/WebSockets.jl/issues/158
└ @ Main REPL[18]:9
┌ Info: client received:
│   data_str = "Hello"
└   success = true
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
┌ Info: server received:
└   readguarded(ws_server) = (UInt8[0x62, 0x79, 0x65], true)
[ Info: WebSocket(server, CONNECTED)
[ Info: A little unusually, we now start a closing protocol from the server side.
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
Test Summary: | Pass  Total
server first  |    8      8
Test.DefaultTestSet("server first", Any[Test.DefaultTestSet("sleep before sending Hello", Any[], 4, false), Test.DefaultTestSet("sending Hello first", Any[], 4, false)], 0, false)

I have not yet been able to reproduce, and the reasons are down to: 1) Windows OK / Ubuntu not OK? 2) Julia up to 1.4.0 OK, 1.5.0-beta1 not OK? 3) Running via REPL ok, notebook not OK?

I started re-running the automatic tests on PR #157 just now. You can study the logs from it in a few minutes.

Side note: Some rather insignificant printing tests will be triggered which are not relevant to this. WebSockets is on low-maintenance at the time, because I am not working on web-related projects, and HTTP/WebSockets keeps steadily improving.

I have not yet been able to reproduce, and the reasons are down to: 1) Windows OK / Ubuntu not OK? 2) Julia up to 1.4.0 OK, 1.5.0-beta1 not OK? 3) Running via REPL ok, notebook not OK?

Sorry, I was a little busy last week. Maybe I need to have a look at the code.

Side note: Some rather insignificant printing tests will be triggered which are not relevant to this. WebSockets is on low-maintenance at the time, because I am not working on web-related projects, and HTTP/WebSockets keeps steadily improving.

Did you mean HTTP/WebSockets is the preferred over WebSockets?

It is easier to maintain code quality, threshold of use and user bug finding when packages are small.

This package condenses error messages and never shows them to the client side. It shows server status without using glyphs for server status that don't show up on windows, and has an interface for subprotocols. Those features ought to make their way into HTTP over time, although some may not, either because other use cases require debugging from a client machine, or because a better overall solution already exist.

It is easier to maintain code quality, threshold of use and user bug finding when packages are small.

This package condenses error messages and never shows them to the client side. It shows server status without using glyphs for server status that don't show up on windows, and has an interface for subprotocols. Those features ought to make their way into HTTP over time, although some may not, either because other use cases require debugging from a client machine, or because a better overall solution already exist.

Sorry, No offense. I was just asking if you mean HTTP/WebSockets is better maintained.

For now I think WebSockets is better maintained. I opened a similar issue in HTTP/WebSockets 11 days ago, and got no comments so far.

I tried with Julia 1.4.2 and no luck. PS (all my tests ran in docker container hosted in a macbook)

Julia Version 1.4.2
Commit 44fa15b150* (2020-05-23 18:35 UTC)
Platform Info:
  OS: Linux (x86_64-pc-linux-gnu)
  CPU: Intel(R) Core(TM) i7-4770HQ CPU @ 2.20GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-8.0.1 (ORCJIT, haswell)
Environment:
  JULIA_GPG = 3673DF529D9049477F76B37566E3C7DC03D6E495
  JULIA_VERSION = 1.4.2
  JULIA_PATH = /usr/local/julia
  JULIA_PKG_SERVER = https://pkg.julialang.org
 Activating environment at `~/Downloads/websockets_test/Project.toml`
   Updating registry at `~/.julia/registries/General`
  Resolving package versions...
   Updating `~/Downloads/websockets_test/Project.toml`
 [no changes]
   Updating `~/Downloads/websockets_test/Manifest.toml`
 [no changes]
  Resolving package versions...
   Updating `~/Downloads/websockets_test/Project.toml`
 [no changes]
   Updating `~/Downloads/websockets_test/Manifest.toml`
 [no changes]
  Resolving package versions...
   Updating `~/Downloads/websockets_test/Project.toml`
 [no changes]
   Updating `~/Downloads/websockets_test/Manifest.toml`
 [no changes]
  Resolving package versions...
   Updating `~/Downloads/websockets_test/Project.toml`
 [no changes]
   Updating `~/Downloads/websockets_test/Manifest.toml`
 [no changes]
Status `~/Downloads/websockets_test/Project.toml`
  [cd3eb016] HTTP v0.8.16
  [739be429] MbedTLS v1.0.2
  [102dff8d] OpenTrick v0.2.1
  [104b5d7c] WebSockets v1.5.2
[ Info: sleep before sending first package...
[ Info: runnable
[ Info: reading greeting...
┌ Warning: Will hang if WebSockets didn't fix bug #158 https://github.com/JuliaWeb/WebSockets.jl/issues/158
└ @ Main ~/Downloads/websockets_test/WebSocketsClientAutoTest.jl:42
[ Info: Done.
[ Info: WebSocket(server, CONNECTED)
┌ Info: client received:
│   data_str = "Hello"
└   success = true
[ Info: We said hello, and will wait for one message before start closing.
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
┌ Info: server received:
└   readguarded(ws_server) = (UInt8[0x62, 0x79, 0x65], true)
[ Info: WebSocket(server, CONNECTED)
[ Info: A little unusually, we now start a closing protocol from the server side.
[ Info: Dict{String,Any}("success" => true,"data" => "Hello")
[ Info: WebSocket(server, CONNECTED)
[ Info: runnable
[ Info: We said hello, and will wait for one message before start closing.
[ Info: reading greeting...
┌ Warning: Will hang if WebSockets didn't fix bug #158 https://github.com/JuliaWeb/WebSockets.jl/issues/158
└ @ Main ~/Downloads/websockets_test/WebSocketsClientAutoTest.jl:42
sending Hello first: Test Failed at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:53
  Expression: timedwait((()->begin
                t.state != :runnable
            end), 5.0) === :ok
   Evaluated: timed_out === ok
Stacktrace:
 [1] do_test(; port::Int64, sleep_first::Bool, ip::String) at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:53
 [2] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [3] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.4/Test/src/Test.jl:1113
 [4] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [5] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.4/Test/src/Test.jl:1113
 [6] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:62
[ Info: Dict{String,Any}("success" => false,"data" => nothing)
sending Hello first: Test Failed at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:55
  Expression: ret["data"] == "Hello"
   Evaluated: nothing == "Hello"
Stacktrace:
 [1] do_test(; port::Int64, sleep_first::Bool, ip::String) at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:55
 [2] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [3] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.4/Test/src/Test.jl:1113
 [4] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [5] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.4/Test/src/Test.jl:1113
 [6] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:62
sending Hello first: Test Failed at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:56
  Expression: ret["success"] == true
   Evaluated: false == true
Stacktrace:
 [1] do_test(; port::Int64, sleep_first::Bool, ip::String) at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:56
 [2] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [3] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.4/Test/src/Test.jl:1113
 [4] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:66
 [5] top-level scope at /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.4/Test/src/Test.jl:1113
 [6] top-level scope at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:62
Test Summary:                | Pass  Fail  Total
server first                 |    5     3      8
  sleep before sending Hello |    4            4
  sending Hello first        |    1     3      4
ERROR: LoadError: Some tests did not pass: 5 passed, 3 failed, 0 errored, 0 broken.
in expression starting at /root/Downloads/websockets_test/WebSocketsClientAutoTest.jl:61

I suspect the line io = getrawstream(stream) in function _openstream(f::Function, stream, key::String) will cause buffered data in stream.t lost.

"Called by open with a stream connected to a server, after handshake is initiated"
function _openstream(f::Function, stream, key::String)
    startread(stream)
    response = stream.message
    if response.status != 101
        return
    end
    check_upgrade(stream)
    if header(response, "Sec-WebSocket-Accept") != generate_websocket_key(key)
        throw(WebSocketError(0, "Invalid Sec-WebSocket-Accept\n" *
                                "$response"))
    end
    # unwrap the stream
    io = getrawstream(stream) # buffered data lost?
    ws = WebSocket(io, false)
    try
        f(ws)
    finally
        close(ws)
    end
end

I tested a similar logic with HTTP.WebSockets, and it shows clear that there are "10-byte excess" in HTTP.ConnectionPool.Transaction.

┌ Debug: notifing caller...
│   io = OpenTrick.IOWrapper{HTTP.WebSockets.WebSocket{HTTP.DebugRequest.IODebug{HTTP.ConnectionPool.Transaction{Sockets.TCPSocket}}}}(HTTP.WebSockets.WebSocket{HTTP.DebugRequest.IODebug{HTTP.ConnectionPool.Transaction{Sockets.TCPSocket}}}(T0  ⏸    0↑🔒    0↓🔒   2s 127.0.0.1:54321:41260 ≣16 10-byte excess RawFD(0x00000015), 0x01, false, UInt8[], UInt8[], false, false), Base.GenericCondition{Base.AlwaysLockedST}(Base.InvasiveLinkedList{Task}(Task (runnable) @0x00007f6de9a3c010, Task (runnable) @0x00007f6de9a3c010), Base.AlwaysLockedST(1)))

I think I can see how a misbehaving client will send erratic data instead of waiting for a response to the upgrade. That's why the server can disregard data that may have been put on the stream out-of-protocol (which is to wait).

Will have a more detailed look later...

It's not about misbehaving client. It is the client misses the first package when subscribing data from a server. The client sent nothing.

I also experienced this issue. It's some sort of timing issue, the first message sent by the server can be lost if it's sent before the client finishes setting up the WebSocket. The issue is easy to miss if you have some overhead before you send data on the server side (as indicated by https://github.com/JuliaWeb/WebSockets.jl/issues/158#issuecomment-663342710), since any delay between establishing connection and sending a message from the server gives the client time to finish setting up. Probably also dependent on system performance.

For example, in my case, a first connection (without precompilation having an impact in server code) is slow enough on the server side that the client side manages to set up the WebSocket and receive the message. Subsequent connections (with precompilation) were much faster server side and hit on this issue.

It seems like the underlying TCPSocket buffers the first message too quickly, before the WebSocket is fully established client-side.

A patch in WebSockets._openstream fixed this for me.

function WebSockets._openstream(f::Function, stream, key::String)
    HTTP.startread(stream)
    response = stream.message
    if response.status != 101
        return
    end
    WebSockets.check_upgrade(stream)
    if HTTP.header(response, "Sec-WebSocket-Accept") != WebSockets.generate_websocket_key(key)
        throw(WebSockets.WebSocketError(0, "Invalid Sec-WebSocket-Accept\n" *
                                "$response"))
    end
    # unwrap the stream
    io = HTTP.ConnectionPool.getrawstream(stream)
    prebuffered = bytesavailable(stream) # patch <- find how many bytes the underlying stream already processed
    ws = WebSockets.WebSocket(io, false)
    ws.socket.buffer.ptr -= prebuffered # patch <- move the stream buffer pointer back by the amount that was prebuffered
    try
        f(ws)
    finally
        close(ws)
    end
end

When making version 1.6.0, we experienced various hangups we couldn't properly explain, depending on Julia version. These are possibly related, possibly not. We require Julia version 1.8.2 for the current WebSockets.jl version.

JuliaWeb / WebSockets.jl

The first package will lost if server send package first. #158