Skip to content

Commit ae40629

Browse files
committed
Merge pull request rails#25344 from matthewd/debug-locks
ActionDispatch::DebugLocks
1 parent c6beb6d commit ae40629

File tree

4 files changed

+172
-5
lines changed

4 files changed

+172
-5
lines changed

actionpack/lib/action_dispatch.rb

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -50,6 +50,7 @@ class IllegalStateError < StandardError
5050
autoload :Callbacks
5151
autoload :Cookies
5252
autoload :DebugExceptions
53+
autoload :DebugLocks
5354
autoload :ExceptionWrapper
5455
autoload :Executor
5556
autoload :Flash
Lines changed: 122 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,122 @@
1+
module ActionDispatch
2+
# This middleware can be used to diagnose deadlocks in the autoload interlock.
3+
#
4+
# To use it, insert it near the top of the middleware stack, using
5+
# <tt>config/application.rb</tt>:
6+
#
7+
# config.middleware.insert_before Rack::Sendfile, ActionDispatch::DebugLocks
8+
#
9+
# After restarting the application and re-triggering the deadlock condition,
10+
# <tt>/rails/locks</tt> will show a summary of all threads currently known to
11+
# the interlock, which lock level they are holding or awaiting, and their
12+
# current backtrace.
13+
#
14+
# Generally a deadlock will be caused by the interlock conflicting with some
15+
# other external lock or blocking I/O call. These cannot be automatically
16+
# identified, but should be visible in the displayed backtraces.
17+
#
18+
# NOTE: The formatting and content of this middleware's output is intended for
19+
# human consumption, and should be expected to change between releases.
20+
#
21+
# This middleware exposes operational details of the server, with no access
22+
# control. It should only be enabled when in use, and removed thereafter.
23+
class DebugLocks
24+
def initialize(app, path = '/rails/locks')
25+
@app = app
26+
@path = path
27+
end
28+
29+
def call(env)
30+
req = ActionDispatch::Request.new env
31+
32+
if req.get?
33+
path = req.path_info.chomp('/'.freeze)
34+
if path == @path
35+
return render_details(req)
36+
end
37+
end
38+
39+
@app.call(env)
40+
end
41+
42+
private
43+
def render_details(req)
44+
threads = ActiveSupport::Dependencies.interlock.raw_state do |threads|
45+
# The Interlock itself comes to a complete halt as long as this block
46+
# is executing. That gives us a more consistent picture of everything,
47+
# but creates a pretty strong Observer Effect.
48+
#
49+
# Most directly, that means we need to do as little as possible in
50+
# this block. More widely, it means this middleware should remain a
51+
# strictly diagnostic tool (to be used when something has gone wrong),
52+
# and not for any sort of general monitoring.
53+
54+
threads.each.with_index do |(thread, info), idx|
55+
info[:index] = idx
56+
info[:backtrace] = thread.backtrace
57+
end
58+
59+
threads
60+
end
61+
62+
str = threads.map do |thread, info|
63+
if info[:exclusive]
64+
lock_state = 'Exclusive'
65+
elsif info[:sharing] > 0
66+
lock_state = 'Sharing'
67+
lock_state << " x#{info[:sharing]}" if info[:sharing] > 1
68+
else
69+
lock_state = 'No lock'
70+
end
71+
72+
if info[:waiting]
73+
lock_state << ' (yielded share)'
74+
end
75+
76+
msg = "Thread #{info[:index]} [0x#{thread.__id__.to_s(16)} #{thread.status || 'dead'}] #{lock_state}\n"
77+
78+
if info[:sleeper]
79+
msg << " Waiting in #{info[:sleeper]}"
80+
msg << " to #{info[:purpose].to_s.inspect}" unless info[:purpose].nil?
81+
msg << "\n"
82+
83+
if info[:compatible]
84+
compat = info[:compatible].map { |c| c == false ? "share" : c.to_s.inspect }
85+
msg << " may be pre-empted for: #{compat.join(', ')}\n"
86+
end
87+
88+
blockers = threads.values.select { |binfo| blocked_by?(info, binfo, threads.values) }
89+
msg << " blocked by: #{blockers.map {|i| i[:index] }.join(', ')}\n" if blockers.any?
90+
end
91+
92+
blockees = threads.values.select { |binfo| blocked_by?(binfo, info, threads.values) }
93+
msg << " blocking: #{blockees.map {|i| i[:index] }.join(', ')}\n" if blockees.any?
94+
95+
msg << "\n#{info[:backtrace].join("\n")}\n" if info[:backtrace]
96+
end.join("\n\n---\n\n\n")
97+
98+
[200, { "Content-Type" => "text/plain", "Content-Length" => str.size }, [str]]
99+
end
100+
101+
def blocked_by?(victim, blocker, all_threads)
102+
return false if victim.equal?(blocker)
103+
104+
case victim[:sleeper]
105+
when :start_sharing
106+
blocker[:exclusive] ||
107+
(!victim[:waiting] && blocker[:compatible] && !blocker[:compatible].include?(false))
108+
when :start_exclusive
109+
blocker[:sharing] > 0 ||
110+
blocker[:exclusive] ||
111+
(blocker[:compatible] && !blocker[:compatible].include?(victim[:purpose]))
112+
when :yield_shares
113+
blocker[:exclusive]
114+
when :stop_exclusive
115+
blocker[:exclusive] ||
116+
victim[:compatible] &&
117+
victim[:compatible].include?(blocker[:purpose]) &&
118+
all_threads.all? { |other| !other[:compatible] || blocker.equal?(other) || other[:compatible].include?(blocker[:purpose]) }
119+
end
120+
end
121+
end
122+
end

activesupport/lib/active_support/concurrency/share_lock.rb

Lines changed: 45 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -14,13 +14,46 @@ class ShareLock
1414
# to upgrade share locks to exclusive.
1515

1616

17+
def raw_state # :nodoc:
18+
synchronize do
19+
threads = @sleeping.keys | @sharing.keys | @waiting.keys
20+
threads |= [@exclusive_thread] if @exclusive_thread
21+
22+
data = {}
23+
24+
threads.each do |thread|
25+
purpose, compatible = @waiting[thread]
26+
27+
data[thread] = {
28+
thread: thread,
29+
sharing: @sharing[thread],
30+
exclusive: @exclusive_thread == thread,
31+
purpose: purpose,
32+
compatible: compatible,
33+
waiting: !!@waiting[thread],
34+
sleeper: @sleeping[thread],
35+
}
36+
end
37+
38+
# NB: Yields while holding our *internal* synchronize lock,
39+
# which is supposed to be used only for a few instructions at
40+
# a time. This allows the caller to inspect additional state
41+
# without things changing out from underneath, but would have
42+
# disastrous effects upon normal operation. Fortunately, this
43+
# method is only intended to be called when things have
44+
# already gone wrong.
45+
yield data
46+
end
47+
end
48+
1749
def initialize
1850
super()
1951

2052
@cv = new_cond
2153

2254
@sharing = Hash.new(0)
2355
@waiting = {}
56+
@sleeping = {}
2457
@exclusive_thread = nil
2558
@exclusive_depth = 0
2659
end
@@ -46,7 +79,7 @@ def start_exclusive(purpose: nil, compatible: [], no_wait: false)
4679
return false if no_wait
4780

4881
yield_shares(purpose: purpose, compatible: compatible, block_share: true) do
49-
@cv.wait_while { busy_for_exclusive?(purpose) }
82+
wait_for(:start_exclusive) { busy_for_exclusive?(purpose) }
5083
end
5184
end
5285
@exclusive_thread = Thread.current
@@ -69,7 +102,7 @@ def stop_exclusive(compatible: [])
69102

70103
if eligible_waiters?(compatible)
71104
yield_shares(compatible: compatible, block_share: true) do
72-
@cv.wait_while { @exclusive_thread || eligible_waiters?(compatible) }
105+
wait_for(:stop_exclusive) { @exclusive_thread || eligible_waiters?(compatible) }
73106
end
74107
end
75108
@cv.broadcast
@@ -84,11 +117,11 @@ def start_sharing
84117
elsif @waiting[Thread.current]
85118
# We're nested inside a +yield_shares+ call: we'll resume as
86119
# soon as there isn't an exclusive lock in our way
87-
@cv.wait_while { @exclusive_thread }
120+
wait_for(:start_sharing) { @exclusive_thread }
88121
else
89122
# This is an initial / outermost share call: any outstanding
90123
# requests for an exclusive lock get to go first
91-
@cv.wait_while { busy_for_sharing?(false) }
124+
wait_for(:start_sharing) { busy_for_sharing?(false) }
92125
end
93126
@sharing[Thread.current] += 1
94127
end
@@ -153,7 +186,7 @@ def yield_shares(purpose: nil, compatible: [], block_share: false)
153186
yield
154187
ensure
155188
synchronize do
156-
@cv.wait_while { @exclusive_thread && @exclusive_thread != Thread.current }
189+
wait_for(:yield_shares) { @exclusive_thread && @exclusive_thread != Thread.current }
157190

158191
if previous_wait
159192
@waiting[Thread.current] = previous_wait
@@ -181,6 +214,13 @@ def busy_for_sharing?(purpose)
181214
def eligible_waiters?(compatible)
182215
@waiting.any? { |t, (p, _)| compatible.include?(p) && @waiting.all? { |t2, (_, c2)| t == t2 || c2.include?(p) } }
183216
end
217+
218+
def wait_for(method)
219+
@sleeping[Thread.current] = method
220+
@cv.wait_while { yield }
221+
ensure
222+
@sleeping.delete Thread.current
223+
end
184224
end
185225
end
186226
end

activesupport/lib/active_support/dependencies/interlock.rb

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,10 @@ def permit_concurrent_loads
4646
yield
4747
end
4848
end
49+
50+
def raw_state(&block) # :nodoc:
51+
@lock.raw_state(&block)
52+
end
4953
end
5054
end
5155
end

0 commit comments

Comments
 (0)