[ruby-core:98172] [Ruby master Bug#16782] `lock': deadlock; recursive locking (ThreadError) in 2.7.1
From:
ko1@...
Date:
2020-05-07 07:29:53 UTC
List:
ruby-core #98172
Issue #16782 has been updated by ko1 (Koichi Sasada).
> deadlock; recursive locking
seems not difficult error, the same thread tries to lock a mutex twice without unlocking.
can you check it?
----------------------------------------
Bug #16782: `lock': deadlock; recursive locking (ThreadError) in 2.7.1
https://bugs.ruby-lang.org/issues/16782#change-85410
* Author: ioquatix (Samuel Williams)
* Status: Open
* Priority: Normal
* Assignee: ko1 (Koichi Sasada)
* Backport: 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN
----------------------------------------
Using the latest `async-http` repo:
```
% bundle exec rspec spec/async/http/performance_spec.rb
Traceback (most recent call last):
11: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/task.rb:258:in `block in make_fiber'
10: from /home/samuel/.gem/ruby/2.7.1/gems/async-io-1.28.0/lib/async/io/socket.rb:73:in `block in accept'
9: from /home/samuel/.gem/ruby/2.7.1/gems/async-io-1.28.0/lib/async/io/server.rb:32:in `block in accept_each'
8: from /home/samuel/Documents/socketry/async-http/lib/async/http/server.rb:67:in `accept'
7: from /home/samuel/Documents/socketry/async-http/lib/async/http/protocol/http1/connection.rb:80:in `close'
6: from /home/samuel/.gem/ruby/2.7.1/gems/protocol-http1-0.12.0/lib/protocol/http1/connection.rb:135:in `close'
5: from /home/samuel/.gem/ruby/2.7.1/gems/async-io-1.28.0/lib/async/io/stream.rb:224:in `close'
4: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/wrapper.rb:164:in `close'
3: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/wrapper.rb:215:in `cancel_monitor'
2: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/wrapper.rb:215:in `close'
1: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/wrapper.rb:215:in `deregister'
/home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/wrapper.rb:215:in `lock': SIGTERM (SignalException)
9: from /home/samuel/.gem/ruby/2.7.1/gems/async-container-0.14.1/lib/async/container/forked.rb:64:in `block in spawn'
8: from /home/samuel/.gem/ruby/2.7.1/gems/async-container-0.14.1/lib/async/container/group.rb:42:in `fork'
7: from /home/samuel/.gem/ruby/2.7.1/gems/async-container-0.14.1/lib/async/container/group.rb:42:in `fork'
6: from /home/samuel/.gem/ruby/2.7.1/gems/async-container-0.14.1/lib/async/container/forked.rb:67:in `block (2 levels) in spawn'
5: from /home/samuel/.gem/ruby/2.7.1/gems/async-container-0.14.1/lib/async/container/controller.rb:47:in `block in async'
4: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/reactor.rb:58:in `run'
3: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/reactor.rb:58:in `ensure in run'
2: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/reactor.rb:250:in `close'
1: from /home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/reactor.rb:250:in `close'
/home/samuel/.gem/ruby/2.7.1/gems/async-1.24.2/lib/async/reactor.rb:250:in `lock': deadlock; recursive locking (ThreadError)
runs benchmark
Finished in 4.5 seconds (files took 0.2483 seconds to load)
2 examples, 0 failures
% ruby --version
ruby 2.7.1p83 (2020-03-31 revision a0c7c23c9c) [x86_64-linux]
```
About 1 in 10-100 runs will trigger this result. I also tried current head and could reproduce:
```
Running 2s test @ http://127.0.0.1:9294/
8 threads and 8 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 10.35ms 14.03ms 46.73ms 78.86%
Req/Sec 0.99k 454.60 2.30k 63.80%
16122 requests in 2.10s, 787.51KB read
Requests/sec: 7675.89
Transfer/sec: 374.94KB
4.66s error: Async::Task [oid=0x1360] [pid=69337] [2020-04-13 15:40:21 +1200]
| ThreadError: deadlock; recursive locking
| → /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/wrapper.rb:215 in `lock'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/wrapper.rb:215 in `deregister'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/wrapper.rb:215 in `close'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/wrapper.rb:215 in `cancel_monitor'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/wrapper.rb:164 in `close'
| /home/samuel/.gem/ruby/2.8.0/gems/async-io-1.28.0/lib/async/io/shared_endpoint.rb:78 in `ensure in block (2 levels) in bind'
| /home/samuel/.gem/ruby/2.8.0/gems/async-io-1.28.0/lib/async/io/shared_endpoint.rb:78 in `block (2 levels) in bind'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/task.rb:258 in `block in make_fiber'
| Caused by Async::Stop: Async::Stop
| → /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/task.rb:66 in `yield'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/wrapper.rb:233 in `wait_for'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/wrapper.rb:124 in `wait_readable'
| /home/samuel/.gem/ruby/2.8.0/gems/async-io-1.28.0/lib/async/io/generic.rb:220 in `async_send'
| /home/samuel/.gem/ruby/2.8.0/gems/async-io-1.28.0/lib/async/io/socket.rb:62 in `accept'
| /home/samuel/.gem/ruby/2.8.0/gems/async-io-1.28.0/lib/async/io/server.rb:36 in `accept_each'
| /home/samuel/.gem/ruby/2.8.0/gems/async-io-1.28.0/lib/async/io/shared_endpoint.rb:104 in `block in accept'
| /home/samuel/.gem/ruby/2.8.0/gems/async-io-1.28.0/lib/async/io/shared_endpoint.rb:76 in `block (2 levels) in bind'
| /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/task.rb:258 in `block in make_fiber'
Traceback (most recent call last):
9: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/forked.rb:64:in `block in spawn'
8: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/group.rb:42:in `fork'
7: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/group.rb:42:in `fork'
6: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/forked.rb:67:in `block (2 levels) in spawn'
5: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/controller.rb:47:in `block in async'
4: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:56:in `run'
3: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:234:in `run'
2: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:204:in `run_once'
1: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:204:in `select'
/home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:204:in `lock': SIGTERM (SignalException)
9: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/forked.rb:64:in `block in spawn'
8: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/group.rb:42:in `fork'
7: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/group.rb:42:in `fork'
6: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/forked.rb:67:in `block (2 levels) in spawn'
5: from /home/samuel/.gem/ruby/2.8.0/gems/async-container-0.14.1/lib/async/container/controller.rb:47:in `block in async'
4: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:58:in `run'
3: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:58:in `ensure in run'
2: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:250:in `close'
1: from /home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:250:in `close'
/home/samuel/.gem/ruby/2.8.0/gems/async-1.24.2/lib/async/reactor.rb:250:in `lock': deadlock; recursive locking (ThreadError)
runs benchmark
Finished in 4.56 seconds (files took 0.31919 seconds to load)
2 examples, 0 failures
```
It's relatively straight forward to reproduce.
--
https://bugs.ruby-lang.org/
Unsubscribe: <mailto:ruby-core-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>