bringing in http1 changes #146

tlienart · 2022-08-16T11:33:50Z

0.9.2 + #145 , thanks @quinnj and @fredrikekre who did most of the work. I also added some logic to close #139

I won't merge this before we've had some time to play with it and make sure that we're out of #143 .

It seems to work fine from my checks though the tests lead to an error upon (apparently) calling close(ws) in the test block Server/ws_tracker testing (actually the test block passes but the error is shown)

Any idea how to clean that up?

julia> Unhandled Task ERROR: EOFError: read end of file
Stacktrace:
  [1] (::Base.var"#wait_locked#648")(s::TCPSocket, buf::IOBuffer, nb::Int64)
    @ Base ./stream.jl:892
  [2] unsafe_read(s::TCPSocket, p::Ptr{UInt8}, nb::UInt64)
    @ Base ./stream.jl:900
  [3] unsafe_read(c::HTTP.ConnectionPool.Connection, p::Ptr{UInt8}, n::UInt64)
    @ HTTP.ConnectionPool ~/.julia/packages/HTTP/4Xalq/src/ConnectionPool.jl:173
  [4] unsafe_read
    @ ./io.jl:724 [inlined]
  [5] unsafe_read(s::HTTP.ConnectionPool.Connection, p::Base.RefValue{UInt16}, n::Int64)
    @ Base ./io.jl:723
  [6] read!
    @ ./io.jl:725 [inlined]
  [7] read
    @ ./io.jl:729 [inlined]
  [8] readframe(io::HTTP.ConnectionPool.Connection, ::Type{HTTP.WebSockets.Frame}, buffer::Vector{UInt8}, first_fragment_opcode::HTTP.WebSockets.OpCode)
    @ HTTP.WebSockets ~/.julia/packages/HTTP/4Xalq/src/WebSockets.jl:128
  [9] readframe
    @ ~/.julia/packages/HTTP/4Xalq/src/WebSockets.jl:127 [inlined]
 [10] receive(ws::HTTP.WebSockets.WebSocket)
    @ HTTP.WebSockets ~/.julia/packages/HTTP/4Xalq/src/WebSockets.jl:658
 [11] iterate(ws::HTTP.WebSockets.WebSocket, st::Nothing)
    @ HTTP.WebSockets ~/.julia/packages/HTTP/4Xalq/src/WebSockets.jl:697
 [12] iterate
    @ ~/.julia/packages/HTTP/4Xalq/src/WebSockets.jl:695 [inlined]
 [13] macro expansion
    @ ~/.julia/dev/LiveServer/src/server.jl:361 [inlined]
 [14] (::LiveServer.var"#13#14"{HTTP.WebSockets.WebSocket})()
    @ LiveServer ./task.jl:429

fredrikekre · 2022-08-16T11:36:48Z

Project.toml

@@ -1,7 +1,7 @@
 name = "LiveServer"
 uuid = "16fef848-5104-11e9-1b77-fb7a48bbb589"
 authors = ["Jonas Asprion <jonas.asprion@gmx.ch", "Thibaut Lienart <tlienart@me.com>"]
-version = "0.9.2"
+version = "0.10.0"


I think this could be 0.9, there is nothing breaking here, right?

well now 0.9.2 is HTTP 0.8, 0.9 but this one is just HTTP 1; also we bumped up the minimum req on Julia 1.6, that's why I thought it'd make sense to make it a 0.10

Okay, I think it only matters if you plan on doing more patch releases supporting HTTP 0.8 and 0.9. Perhaps make this 1.0 instead then? Then you have more flexibility for future changes like this since you have three numbers to play around with.

I think 1.0.0 once we're happy this is solid would make sense yes 👍

quinnj · 2022-08-16T12:30:38Z

For the error when close(ws), we could change my cherry-pick commit to just:

    @async begin
        for msg in ws
            # pass
        end
    end

without the errormonitor. In this case, we don't really care if that little reading async tasks throws, because we're justing using it to consume control frames and if that errors then that means we're done w/ the websocket. That kind of thing just always makes me nervous because we're sending the async task off into the void, where it dies silently.

tlienart · 2022-08-16T12:49:48Z

Nice thanks, ~~I get another error now~~:

Edit error came from a line that should have been removed in the tests

@mortenpi @fredrikekre @rikhuijzer if you guys could test the code a bit with your usual work streams so that we can gain confidence in it, that would be much appreciated. I'll do that for a week on my side with Franklin and related repos then we can merge this. Thanks!

(Note: @mortenpi, I'm investigating the issue you neatly pointed out in #135 and think I have a fix, will probably do that in a separate PR though as I want to have time to test stuff in details)

rikhuijzer · 2022-08-16T13:14:18Z

For me, it doesn't crash anymore. On the other hand, when sending a few dozen changes to the server, it seems to now do one page reload per changed file whereas before it was more relaxed and dropped some reloads. Is it possible that this behavior has changed with the fix? More specifically, what happens here is that changing many files will cause the webpage to be refreshed once every second for the next 20 seconds even when no files are changed.

EDIT: And the following error shows in the console. But only 5 times so it is probably unrelated to the many refreshes.

┌ Error: update_and_close_viewers! error
│   exception =
│    ArgumentError: send() requires `!(ws.writeclosed)`
│    Stacktrace:
│      [1] macro expansion
│        @ ~/.julia/packages/HTTP/4Xalq/src/Conditions.jl:25 [inlined]
│      [2] send(ws::HTTP.WebSockets.WebSocket, x::String)
│        @ HTTP.WebSockets ~/.julia/packages/HTTP/4Xalq/src/WebSockets.jl:492
│      [3] (::LiveServer.var"#6#7")(wsi::HTTP.WebSockets.WebSocket)
│        @ LiveServer ~/git/LiveServer.jl/src/server.jl:41
│      [4] foreach
│        @ ./abstractarray.jl:2774 [inlined]
│      [5] update_and_close_viewers!(wss::Vector{HTTP.WebSockets.WebSocket})
│        @ LiveServer ~/git/LiveServer.jl/src/server.jl:39
│      [6] foreach(f::typeof(LiveServer.update_and_close_viewers!), itr::Base.ValueIterator{Dict{String, Vector{HTTP.WebSockets.WebSocket}}})
│        @ Base ./abstractarray.jl:2774
│      [7] file_changed_callback(f_path::String)
│        @ LiveServer ~/git/LiveServer.jl/src/server.jl:73
│      [8] custom_callback(file::String, project::String)
│        @ Books ~/git/Books.jl/src/serve.jl:32
│      [9] (::Books.var"#cb#37"{String})(file::String)
│        @ Books ~/git/Books.jl/src/serve.jl:37
│     [10] file_watcher_task!(fw::LiveServer.SimpleWatcher)
│        @ LiveServer ~/git/LiveServer.jl/src/file_watching.jl:97
│     [11] (::LiveServer.var"#2#3"{LiveServer.SimpleWatcher})()
│        @ LiveServer ./task.jl:484
└ @ LiveServer ~/git/LiveServer.jl/src/server.jl:45

tlienart · 2022-08-16T15:55:17Z

@rikhuijzer thanks! would you might trying again the refresh thing? it might have been a sleep that was unnecessarily long, it used to be shorter;

Also for what you report with the error; you saw it with verbose=true right? otherwise you shouldn't have seen it

mortenpi · 2022-08-16T21:40:38Z

I switched to using this branch now, and so far so good! But if anything does pop up, I'll make sure to post here.

tlienart · 2022-08-17T07:53:10Z

On the other hand, when sending a few dozen changes to the server, it seems to now do one page reload per changed file whereas before it was more relaxed and dropped some reloads.

I'm seeing something like this too, will try to figure out how to avoid this; also the refresh don't seem to work well with Safari for some reason.

rikhuijzer · 2022-08-17T08:06:18Z

also the refresh don't seem to work well with Safari for some reason.

Yes. I'm also doing more tests here and I'm running into this too on Firefox. When I change a file then the page refreshes but without updating the content. This happens on every file change in some situations. Let me know if you need a MWE. It will probably take me 30-120 minutes to make one.

EDIT: On the bright side, I've had zero crashes so that's good.

tlienart · 2022-08-17T08:43:27Z

Looks like we'll need @quinnj's help again here, adding a @show wsi in update_and_close_viewers! gives out sometimes a very large output with elements like

wsi = HTTP.WebSockets.WebSocket(UUID("cd7bed91-ed75-43fc-b48d-e1b85e897759"), 🔁 0s 127.0.0.1:8000:8000 RawFD(23), HTTP.Messages.Request: """ GET /posts/literate HTTP/1.1 Host: localhost:8000 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:91.0) Gecko/20100101 Firefox/91.0 Accept: / Accept-Language: en-US,en;q=0.5 Accept-Encoding: gzip, deflate Sec-WebSocket-Version: 13 Origin: http://localhost:8000 Sec-WebSocket-Extensions: permessage-deflate Sec-WebSocket-Key: i5GpPM1jV4Aj2+yuu2pFWQ== DNT: 1 Connection: keep-alive, Upgrade Sec-Fetch-Dest: websocket Sec-Fetch-Mode: websocket Sec-Fetch-Site: same-origin Pragma: no-cache Cache-Control: no-cache Upgrade: websocket """, HTTP.Messages.Response: """ HTTP/1.1 101 Switching Protocols Upgrade: websocket Connection: Upgrade Sec-WebSocket-Accept: dNNlknH/u1CUDRv3a0TA4Cj5vdI= """, 9223372036854775807, 1024, false, UInt8[], UInt8[], false, false) wsi = HTTP.WebSockets.WebSocket(UUID("20dd1c66-f2f8-4eb2-b0c6-24e270cc091b"), 💀 0s 127.0.0.1:8000:8000 RawFD(4294967295), HTTP.Messages.Request: """ GET /posts/literate HTTP/1.1 Host: localhost:8000 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:91.0) Gecko/20100101 Firefox/91.0 Accept: / Accept-Language: en-US,en;q=0.5 Accept-Encoding: gzip, deflate Sec-WebSocket-Version: 13 Origin: http://localhost:8000 Sec-WebSocket-Extensions: permessage-deflate Sec-WebSocket-Key: 8uaJyozlUidkoz7haA/WGw== DNT: 1 Connection: keep-alive, Upgrade Sec-Fetch-Dest: websocket Sec-Fetch-Mode: websocket Sec-Fetch-Site: same-origin Pragma: no-cache Cache-Control: no-cache Upgrade: websocket """, HTTP.Messages.Response: """ HTTP/1.1 101 Switching Protocols Upgrade: websocket Connection: Upgrade Sec-WebSocket-Accept: tXZ3HJnfc0/b3yH2eFa0FGYwnEU=

""", 9223372036854775807, 1024, false, UInt8[0x03, 0xe9], UInt8[], true, true)

if there's only one tab open, there should only be one update and one close message right? It might be that the sleep time really needs to be 1.0s in ea81c46 ... but I'm going blind here

(these things don't happen with the non-http1 version so it's a recent change that causes this afaik)

quinnj · 2022-08-17T20:47:32Z

Sorry for my ignorance, but can someone help me understand the expected behavior? i.e. when I change a file, the browser should refresh and show the updated content; but what if I change multiple files at the same time; that should only trigger one refresh, but show the updated content of all the files?

quinnj · 2022-08-18T03:26:28Z

@tlienart, can you try changing the definition of update_and_close_viewers! to:

function update_and_close_viewers!(wss::Vector{HTTP.WebSockets.WebSocket})
    # collect and empty! wss as soon as possible in case other
    # file changes also happen quickly and we have races called here
    websockets = collect(wss)
    empty!(wss)
    foreach(websockets) do wsi
        try
            send(wsi, "update")
            close(wsi)
        catch e
            if VERBOSE[]
                @error "update_and_close_viewers! error" exception=(e, catch_backtrace())
            end
        end
    end
    return nothing
end

I think the problem here is that the new WebSockets code follows the spec more closely with regards to close(wsi) where it will wait until the remote responds appropriately for a "clean close". Now, we can't wait forever, so currently the WebSockets code will wait 5 seconds and then bail with a "dirty close". I think what's happening here is one file triggers update_and_close_viewers! and all the update messages are sent and the websockets initiate closing, but other files also change simultaneously and also trigger update_and_close_viewers!, but the websocket queue (wsi) hasn't been emptied yet, so we attempt to send/close again on websockets that are probably already closed (hence the TWO websockets we see in @tlienart's example where the 2nd one shows the connection is already dead).

The solution here is to eagerly empty the websocket array and then initiate the update/closing sequences so we don't run into double closes.

tlienart · 2022-08-18T10:36:41Z

@ others watching this thread, kindly test the latest commit (7e33358) as, for me, it works as 0.9.2 did.

Rest is probably mostly relevant for @quinnj.

Thanks for taking the time to look into this again @quinnj, I don't understand HTTP's code enough to try to point you in the right direction so this is not super easy. Multi close seems like it could have been a problem indeed (it was not just two, it was many refreshes over a number of seconds).

One thing is that in LS we don't want to wait for clean events, we just want things to be quick and robust. And it seems that the close from WebSockets is too slow.

In the last commit, I go directly via close(ws.io) and also removed a few changes which seemed to cause problems. This was not very principled but the code as it is now seems to work as reliably as 0.9.2.

For reference since you were asking above what the expected behaviour is (let's say with a single browser/tab to keep things simple)

server starts
(A) tab opens or is refreshed eg pointing to index.html
ws is initiated (and should remain alive until we close it)
event on index.html --> send a single update message to ws (B)
close and discard ws
the update message sent in (B) causes a location.reload() on the browser side, this initiates a new ws2, back to (A)
...
CTRL+C
all web sockets still alive should be closed and discarded
close server

This is the basic order of operation. Notes:

if index.html is updated, only tabs pointing to index.html should be refreshed, and they should only be refreshed once
for non-html file updates (e.g. foo.css), all tabs are updated once as they might all depend on the asset

Closing time

Edit next commit 3afd7df seems to fix this with the use of forceclose

It can take a couple of seconds to close all remaining ws and the server. This means that between the time a user presses CTRL+C and the actual end, there is a noticeable lag. This should be reduced as much as possible as, otherwise, the user might be tempted to hit CTRL+C again which may then cause other problems (e.g. crash the proper termination of Franklin).

Maybe this (and the previous) could be addressed if there was an acceptable way in HTTP to say try to do X quickly and don't wait to see if it was successful. Ultimately on the LS side, we're not going to handle any unsuccessful closures so we don't want to have to wait until we get something that tells us it's (un)successful.

This seems to be fixed if we use forceclose

rikhuijzer · 2022-08-18T10:57:53Z

@ others watching this thread, kindly test the latest commit (7e33358) as, for me, it works as 0.9.2 did.

Works great here. Zero error or warnings in the terminal, zero disconnects, and functionality is as before. Thanks both!

tlienart · 2022-08-18T11:25:46Z

Thanks a lot for testing @rikhuijzer !

Latest commit seems to fix the slow server closing bit (using HTTP.Servers.forceclose) so overall we should be good.

I'll leave this open a few days more for people to test and then merge.

bringing in http1 changes

b98dc2b

fredrikekre reviewed Aug 16, 2022

View reviewed changes

tlienart mentioned this pull request Aug 16, 2022

Jq/http1 again #145

Closed

1.0 + comment on errormonitor

4af75c7

removing an obsolete test line

2d39b86

decrease ping time

ea81c46

tlienart mentioned this pull request Aug 18, 2022

Silent crash in servedocs #143

Closed

tlienart added 2 commits August 18, 2022 12:12

trying a bunch of other changes

c88d47b

increase time before writable check in tests

7e33358

force close the server to speed up termination

3afd7df

tlienart merged commit ded962e into master Aug 23, 2022

tlienart deleted the http1b branch July 10, 2023 08:45

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

bringing in http1 changes #146

bringing in http1 changes #146

tlienart commented Aug 16, 2022 •

edited

Loading

fredrikekre Aug 16, 2022

tlienart Aug 16, 2022

fredrikekre Aug 16, 2022

tlienart Aug 16, 2022

quinnj commented Aug 16, 2022

tlienart commented Aug 16, 2022 •

edited

Loading

rikhuijzer commented Aug 16, 2022 •

edited

Loading

tlienart commented Aug 16, 2022 •

edited

Loading

mortenpi commented Aug 16, 2022

tlienart commented Aug 17, 2022

rikhuijzer commented Aug 17, 2022 •

edited

Loading

tlienart commented Aug 17, 2022 •

edited

Loading

quinnj commented Aug 17, 2022

quinnj commented Aug 18, 2022

tlienart commented Aug 18, 2022 •

edited

Loading

rikhuijzer commented Aug 18, 2022

tlienart commented Aug 18, 2022 •

edited

Loading

bringing in http1 changes #146

bringing in http1 changes #146

Conversation

tlienart commented Aug 16, 2022 • edited Loading

fredrikekre Aug 16, 2022

Choose a reason for hiding this comment

tlienart Aug 16, 2022

Choose a reason for hiding this comment

fredrikekre Aug 16, 2022

Choose a reason for hiding this comment

tlienart Aug 16, 2022

Choose a reason for hiding this comment

quinnj commented Aug 16, 2022

tlienart commented Aug 16, 2022 • edited Loading

rikhuijzer commented Aug 16, 2022 • edited Loading

tlienart commented Aug 16, 2022 • edited Loading

mortenpi commented Aug 16, 2022

tlienart commented Aug 17, 2022

rikhuijzer commented Aug 17, 2022 • edited Loading

tlienart commented Aug 17, 2022 • edited Loading

quinnj commented Aug 17, 2022

quinnj commented Aug 18, 2022

tlienart commented Aug 18, 2022 • edited Loading

Closing time

rikhuijzer commented Aug 18, 2022

tlienart commented Aug 18, 2022 • edited Loading

tlienart commented Aug 16, 2022 •

edited

Loading

tlienart commented Aug 16, 2022 •

edited

Loading

rikhuijzer commented Aug 16, 2022 •

edited

Loading

tlienart commented Aug 16, 2022 •

edited

Loading

rikhuijzer commented Aug 17, 2022 •

edited

Loading

tlienart commented Aug 17, 2022 •

edited

Loading

tlienart commented Aug 18, 2022 •

edited

Loading

tlienart commented Aug 18, 2022 •

edited

Loading