Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Test failures in 0.25.0 release #53

Closed
felixonmars opened this issue Mar 28, 2023 · 4 comments
Closed

Test failures in 0.25.0 release #53

felixonmars opened this issue Mar 28, 2023 · 4 comments

Comments

@felixonmars
Copy link

I got these new test failures when packaging for Arch. It reproduces reliably across multiple builders.

Some environment: Ruby 3.0.5, async-http 0.59.5, async-io 1.34.0, protocol-rack 0.2.4, protocol-websocket 0.10.0

{"time":"2023-03-28T10:07:37+02:00","severity":"warn","class":"Async::Pool::Controller","oid":4460,"pid":1352,"subject":"#<Async::Pool::Controller(0/∞)>","message":"Closing resource while still in use!","resource":"#<Async::HTTP::Protocol::HTTP1::Client:0x00005587dfb659d8>","usage":1}
{"time":"2023-03-28T10:07:37+02:00","severity":"warn","class":"Async::Pool::Controller","oid":5300,"pid":1352,"subject":"#<Async::Pool::Controller(0/∞)>","message":"Closing resource while still in use!","resource":"#<Async::HTTP::Protocol::HTTP2::Client 1 active streams>","usage":1}
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
31 passed 2 failed 1 errored out of 34 total (57 assertions)
🏁 Finished in 47.5ms; 1201.103 assertions per second.
🐇 No slow tests found! Well done!

🤔 Failed assertions:
describe Async::WebSocket::Client with http/1 it behaves like a websocket client with #send_close it can read incoming messages and then close test/async/websocket/client.rb:112:24
        expect 0 to
                be == 3
                        ✗ assertion failed test/async/websocket/client.rb:39
        expect #<Async::WebSocket::Connection:0x00005587df9057b0 @framer=#<Async::WebSocket::Client::Framer:0x00005587df905b48 @stream=#<Async::IO::Stream:0x00005587df8df538 @io=#<Async::IO::Socket:0x00005587df8dfb00 @io=#<Socket:(closed)>, @reactor=#<Async::Reactor:0x00005587df8c51b0 @parent=nil, @children=#<Async::Children:0x00005587df8c4a08 @head=nil, @tail=nil, @size=0, @transient_count=0>, @annotation=nil, @object_name=nil, @transient=false, @head=nil, @tail=nil, @selector=nil, @timers=#<Timers::Group:0x00005587df8c5098 @events=#<Timers::Events:0x00005587df8c5048 @sequence=#<Timers::PriorityHeap:0x00005587df8c4ff8 @contents=[]>, @queue=[]>, @timers=#<Set: {}>, @paused_timers=#<Set: {}>, @interval=#<Timers::Interval:0x00005587df8c4e68 @total=0.0, @current=171696.099093903>>, @logger=nil, @ready=[], @running=[], @scheduler=#<Async::Scheduler:0x00005587df8c4da0 @reactor=#<Async::Reactor:0x00005587df8c51b0 ...>>, @interrupted=false, @guard=#<Thread::Mutex:0x00005587df8c4d50>, @blocked=0, @unblocked=[]>, @monitor=nil, @readable=nil, @writable=nil, @any=nil, @timeout=nil>, @eof=false, @pending=0, @writing=#<Async::Semaphore:0x00005587df8df498 @count=0, @limit=1, @waiting=[], @parent=nil>, @block_size=65536, @maximum_read_size=8388608, @read_buffer="", @write_buffer="", @drain_buffer="", @input_buffer="">, @frames={0=>Protocol::WebSocket::ContinuationFrame, 1=>Protocol::WebSocket::TextFrame, 2=>Protocol::WebSocket::BinaryFrame, 8=>Protocol::WebSocket::CloseFrame, 9=>Protocol::WebSocket::PingFrame, 10=>Protocol::WebSocket::PongFrame}, @pool=nil, @connection=nil>, @mask=true, @state=:closed, @frames=[], @reserved=3, @reader=#<Protocol::WebSocket::Extension::Compression::Inflate:0x00005587df9055f8 @parent=#<Async::WebSocket::Connection:0x00005587df9057b0 ...>, @inflate=nil, @window_bits=15, @context_takeover=true>, @writer=#<Protocol::WebSocket::Extension::Compression::Deflate:0x00005587df905530 @parent=#<Async::WebSocket::Connection:0x00005587df9057b0 ...>, @deflate=#<Zlib::Deflate:0x00005587df905170>, @level=-1, @memory_level=8, @strategy=0, @window_bits=15, @context_takeover=true>, @protocol=nil> to
                be closed?
describe Async::WebSocket::Client with http/2 it behaves like a websocket client with #send_close it can read incoming messages and then close test/async/websocket/client.rb:117:24
        expect 0 to
                be == 3
                        ✗ assertion failed test/async/websocket/client.rb:39
        expect #<Async::WebSocket::Connection:0x00005587dfcbe050 @framer=#<Async::WebSocket::Client::Framer:0x00005587dfcbe398 @stream=#<Protocol::HTTP::Body::Stream:0x00005587dfcbe7a8 @input=nil, @output=nil, @buffer=nil, @closed=true>, @frames={0=>Protocol::WebSocket::ContinuationFrame, 1=>Protocol::WebSocket::TextFrame, 2=>Protocol::WebSocket::BinaryFrame, 8=>Protocol::WebSocket::CloseFrame, 9=>Protocol::WebSocket::PingFrame, 10=>Protocol::WebSocket::PongFrame}, @pool=nil, @connection=nil>, @mask=true, @state=:closed, @frames=[], @reserved=3, @reader=#<Protocol::WebSocket::Extension::Compression::Inflate:0x00005587dfcbde98 @parent=#<Async::WebSocket::Connection:0x00005587dfcbe050 ...>, @inflate=nil, @window_bits=15, @context_takeover=true>, @writer=#<Protocol::WebSocket::Extension::Compression::Deflate:0x00005587dfcbddd0 @parent=#<Async::WebSocket::Connection:0x00005587dfcbe050 ...>, @deflate=#<Zlib::Deflate:0x00005587dfcbdbc8>, @level=-1, @memory_level=8, @strategy=0, @window_bits=15, @context_takeover=true>, @protocol=nil> to
                be closed?
describe Async::WebSocket::Client with http/1 it behaves like a websocket client with #send_close it can read incoming messages and then close test/async/websocket/client.rb:112:24
        expect 0 to
                be == 3
                        ✗ assertion failed test/async/websocket/client.rb:39
        expect #<Async::WebSocket::Connection:0x00005587df9057b0 @framer=#<Async::WebSocket::Client::Framer:0x00005587df905b48 @stream=#<Async::IO::Stream:0x00005587df8df538 @io=#<Async::IO::Socket:0x00005587df8dfb00 @io=#<Socket:(closed)>, @reactor=#<Async::Reactor:0x00005587df8c51b0 @parent=nil, @children=#<Async::Children:0x00005587df8c4a08 @head=nil, @tail=nil, @size=0, @transient_count=0>, @annotation=nil, @object_name=nil, @transient=false, @head=nil, @tail=nil, @selector=nil, @timers=#<Timers::Group:0x00005587df8c5098 @events=#<Timers::Events:0x00005587df8c5048 @sequence=#<Timers::PriorityHeap:0x00005587df8c4ff8 @contents=[]>, @queue=[]>, @timers=#<Set: {}>, @paused_timers=#<Set: {}>, @interval=#<Timers::Interval:0x00005587df8c4e68 @total=0.0, @current=171696.099093903>>, @logger=nil, @ready=[], @running=[], @scheduler=#<Async::Scheduler:0x00005587df8c4da0 @reactor=#<Async::Reactor:0x00005587df8c51b0 ...>>, @interrupted=false, @guard=#<Thread::Mutex:0x00005587df8c4d50>, @blocked=0, @unblocked=[]>, @monitor=nil, @readable=nil, @writable=nil, @any=nil, @timeout=nil>, @eof=false, @pending=0, @writing=#<Async::Semaphore:0x00005587df8df498 @count=0, @limit=1, @waiting=[], @parent=nil>, @block_size=65536, @maximum_read_size=8388608, @read_buffer="", @write_buffer="", @drain_buffer="", @input_buffer="">, @frames={0=>Protocol::WebSocket::ContinuationFrame, 1=>Protocol::WebSocket::TextFrame, 2=>Protocol::WebSocket::BinaryFrame, 8=>Protocol::WebSocket::CloseFrame, 9=>Protocol::WebSocket::PingFrame, 10=>Protocol::WebSocket::PongFrame}, @pool=nil, @connection=nil>, @mask=true, @state=:closed, @frames=[], @reserved=3, @reader=#<Protocol::WebSocket::Extension::Compression::Inflate:0x00005587df9055f8 @parent=#<Async::WebSocket::Connection:0x00005587df9057b0 ...>, @inflate=nil, @window_bits=15, @context_takeover=true>, @writer=#<Protocol::WebSocket::Extension::Compression::Deflate:0x00005587df905530 @parent=#<Async::WebSocket::Connection:0x00005587df9057b0 ...>, @deflate=#<Zlib::Deflate:0x00005587df905170>, @level=-1, @memory_level=8, @strategy=0, @window_bits=15, @context_takeover=true>, @protocol=nil> to
                be closed?
describe Async::WebSocket::Client with http/2 it behaves like a websocket client with #send_close it can read incoming messages and then close test/async/websocket/client.rb:117:24
        expect 0 to
                be == 3
                        ✗ assertion failed test/async/websocket/client.rb:39
        expect #<Async::WebSocket::Connection:0x00005587dfcbe050 @framer=#<Async::WebSocket::Client::Framer:0x00005587dfcbe398 @stream=#<Protocol::HTTP::Body::Stream:0x00005587dfcbe7a8 @input=nil, @output=nil, @buffer=nil, @closed=true>, @frames={0=>Protocol::WebSocket::ContinuationFrame, 1=>Protocol::WebSocket::TextFrame, 2=>Protocol::WebSocket::BinaryFrame, 8=>Protocol::WebSocket::CloseFrame, 9=>Protocol::WebSocket::PingFrame, 10=>Protocol::WebSocket::PongFrame}, @pool=nil, @connection=nil>, @mask=true, @state=:closed, @frames=[], @reserved=3, @reader=#<Protocol::WebSocket::Extension::Compression::Inflate:0x00005587dfcbde98 @parent=#<Async::WebSocket::Connection:0x00005587dfcbe050 ...>, @inflate=nil, @window_bits=15, @context_takeover=true>, @writer=#<Protocol::WebSocket::Extension::Compression::Deflate:0x00005587dfcbddd0 @parent=#<Async::WebSocket::Connection:0x00005587dfcbe050 ...>, @deflate=#<Zlib::Deflate:0x00005587dfcbdbc8>, @level=-1, @memory_level=8, @strategy=0, @window_bits=15, @context_takeover=true>, @protocol=nil> to
                be closed?

🔥 Errored assertions:
describe Async::WebSocket::Client with http/1 it behaves like a websocket client with #close(1001) it closes with custom error test/async/websocket/client.rb:112:82
        expect #<Proc:0x00005587dfbd72e0 test/async/websocket/client.rb:86> to
                raise exception Protocol::WebSocket::Error and have {attribute code be == 1001}
                        ⚠ Errno::EPIPE: Broken pipe
                                /usr/lib/ruby/3.0.0/socket.rb:456 __write_nonblock
                                /usr/lib/ruby/3.0.0/socket.rb:456 write_nonblock
                                /usr/lib/ruby/gems/3.0.0/gems/async-io-1.34.0/lib/async/io/generic.rb:216 async_send
                                /usr/lib/ruby/gems/3.0.0/gems/async-io-1.34.0/lib/async/io/generic.rb:62 block in wrap_blocking_method
                                /usr/lib/ruby/gems/3.0.0/gems/async-io-1.34.0/lib/async/io/generic.rb:156 write
                                /usr/lib/ruby/gems/3.0.0/gems/async-io-1.34.0/lib/async/io/stream.rb:160 block in flush
                                /usr/lib/ruby/gems/3.0.0/gems/async-1.30.3/lib/async/semaphore.rb:80 acquire
                                /usr/lib/ruby/gems/3.0.0/gems/async-io-1.34.0/lib/async/io/stream.rb:155 flush
                                /usr/lib/ruby/gems/3.0.0/gems/protocol-websocket-0.10.0/lib/protocol/websocket/framer.rb:42 flush
                                /usr/lib/ruby/gems/3.0.0/gems/protocol-websocket-0.10.0/lib/protocol/websocket/connection.rb:55 flush
                                /usr/lib/ruby/gems/3.0.0/gems/protocol-websocket-0.10.0/lib/protocol/websocket/connection.rb:200 send_close
                                /usr/lib/ruby/gems/3.0.0/gems/protocol-websocket-0.10.0/lib/protocol/websocket/connection.rb:83 rescue in read_frame
                                /usr/lib/ruby/gems/3.0.0/gems/protocol-websocket-0.10.0/lib/protocol/websocket/connection.rb:68 read_frame
                                /usr/lib/ruby/gems/3.0.0/gems/protocol-websocket-0.10.0/lib/protocol/websocket/connection.rb:230 read
                                /usr/lib/ruby/3.0.0/delegate.rb:87 method_missing
                                test/async/websocket/client.rb:87 block (5 levels) in <top (required)>
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/raise_exception.rb:22 block in call
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/assertions.rb:295 block in nested
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/output/buffered.rb:64 indented
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/assertions.rb:293 nested
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/raise_exception.rb:20 call
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/expect.rb:40 block in to
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/assertions.rb:295 block in nested
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/output/buffered.rb:64 indented
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/assertions.rb:293 nested
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/expect.rb:39 to
                                test/async/websocket/client.rb:86 block (4 levels) in <top (required)>
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/it.rb:49 block in handle_skip
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/it.rb:48 catch
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/it.rb:48 handle_skip
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/it.rb:42 block (2 levels) in call
                                /usr/lib/ruby/gems/3.0.0/gems/sus-0.20.2/lib/sus/base.rb:28 around
                                /usr/lib/ruby/gems/3.0.0/gems/sus-fixtures-async-0.1.1/lib/sus/fixtures/async/reactor_context.rb:70 block (2 levels) in around
                                /usr/lib/ruby/gems/3.0.0/gems/sus-fixtures-async-0.1.1/lib/sus/fixtures/async/reactor_context.rb:37 block in run_with_timeout
                                /usr/lib/ruby/gems/3.0.0/gems/async-1.30.3/lib/async/task.rb:261 block in make_fiber
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
@PeterRunich
Copy link
Contributor

PeterRunich commented Apr 2, 2023 •
edited
Loading

I think my issue #50 relates to this, we fixed something with ioquatix. This also affected protocol-websocket. Everything works for protocol-websocket 0.11.0.
Try bundle update async-websocket or if you don't use bundler gem update async-websocket.
I think we should bump version in .gemspec. @ioquatix

@PeterRunich PeterRunich mentioned this issue Apr 2, 2023
Merged
2 tasks
@ioquatix
Copy link
Member

ioquatix commented Apr 2, 2023

I have released 0.25.1 with #54 merged. Can you let me know if that fixes the issues?

@ioquatix
Copy link
Member

ioquatix commented Apr 2, 2023

Also, I removed

zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.
zlib(finalizer): the stream was freed prematurely.

which was emitted by the CRuby zlib code, I guess it took effect in 3.1

@felixonmars
Copy link
Author

Confirmed that updating protocol-websocket to 0.11.0 fixes this. Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@ioquatix @felixonmars @PeterRunich