Skip to content

Commit fff36f5

Browse files
trevrosentrevrosen
committed
Merge branch 'landing/4189' into upstream-master
Land rapid7#4189 * Detect leaked threads during spec runs * Manage threads before/after spec runs
2 parents 7daedac + e3869ee commit fff36f5

File tree

12 files changed

+1050
-360
lines changed

12 files changed

+1050
-360
lines changed

‎Rakefile

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,4 +11,5 @@ Metasploit::Framework::Require.optionally_active_record_railtie
1111

1212
Metasploit::Framework::Application.load_tasks
1313
Metasploit::Framework::Spec::Constants.define_task
14+
Metasploit::Framework::Spec::Threads::Suite.define_task
1415
Metasploit::Framework::Spec::UntestedPayloads.define_task

‎lib/metasploit/framework/spec.rb

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,4 +2,5 @@ module Metasploit::Framework::Spec
22
extend ActiveSupport::Autoload
33

44
autoload :Constants
5+
autoload :Threads
56
end

‎lib/metasploit/framework/spec/threads.rb

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
module Metasploit::Framework::Spec::Threads
2+
extend ActiveSupport::Autoload
3+
4+
autoload :Suite
5+
end

‎lib/metasploit/framework/spec/threads/logger.rb

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,41 @@
1+
#
2+
# Standard Library
3+
#
4+
5+
require 'securerandom'
6+
7+
#
8+
# Project
9+
#
10+
11+
require 'metasploit/framework/spec/threads/suite'
12+
13+
original_thread_new = Thread.method(:new)
14+
15+
# Patches `Thread.new` so that if logs `caller` so thread leaks can be traced
16+
Thread.define_singleton_method(:new) { |*args, &block|
17+
uuid = SecureRandom.uuid
18+
# tag caller with uuid so that only leaked threads caller needs to be printed
19+
lines = ["BEGIN Thread.new caller (#{uuid})"]
20+
21+
caller.each do |frame|
22+
lines << " #{frame}"
23+
end
24+
25+
lines << 'END Thread.new caller'
26+
27+
Metasploit::Framework::Spec::Threads::Suite::LOG_PATHNAME.parent.mkpath
28+
29+
Metasploit::Framework::Spec::Threads::Suite::LOG_PATHNAME.open('a') { |f|
30+
# single puts so threads can't write in between each other.
31+
f.puts lines.join("\n")
32+
}
33+
34+
options = {original_args: args, uuid: uuid}
35+
36+
original_thread_new.call(options) {
37+
# record uuid for thread-leak detection can used uuid to correlate log with this thread.
38+
Thread.current[Metasploit::Framework::Spec::Threads::Suite::UUID_THREAD_LOCAL_VARIABLE] = options.fetch(:uuid)
39+
block.call(*options.fetch(:original_args))
40+
}
41+
}

‎lib/metasploit/framework/spec/threads/suite.rb

Lines changed: 214 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,214 @@
1+
require 'pathname'
2+
3+
# @note needs to use explicit nesting. so this file can be loaded directly without loading 'metasploit/framework' which
4+
# allows for faster loading of rake tasks.
5+
module Metasploit
6+
module Framework
7+
module Spec
8+
module Threads
9+
module Suite
10+
#
11+
# CONSTANTS
12+
#
13+
14+
# Number of allowed threads when threads are counted in `after(:suite)` or `before(:suite)`
15+
EXPECTED_THREAD_COUNT_AROUND_SUITE = 1
16+
# `caller` for all Thread.new calls
17+
LOG_PATHNAME = Pathname.new('log/metasploit/framework/spec/threads/suite.log')
18+
# Regular expression for extracting the UUID out of {LOG_PATHNAME} for each Thread.new caller block
19+
UUID_REGEXP = /BEGIN Thread.new caller \((?<uuid>.*)\)/
20+
# Name of thread local variable that Thread UUID is stored
21+
UUID_THREAD_LOCAL_VARIABLE = "metasploit/framework/spec/threads/logger/uuid"
22+
23+
#
24+
# Module Methods
25+
#
26+
27+
# Configures `before(:suite)` and `after(:suite)` callback to detect thread leaks.
28+
#
29+
# @return [void]
30+
def self.configure!
31+
unless @configured
32+
RSpec.configure do |config|
33+
config.before(:suite) do
34+
thread_count = Metasploit::Framework::Spec::Threads::Suite.non_debugger_thread_list.count
35+
36+
# check with if first so that error message can be constructed lazily
37+
if thread_count > EXPECTED_THREAD_COUNT_AROUND_SUITE
38+
# LOG_PATHNAME may not exist if suite run without `rake spec`
39+
if LOG_PATHNAME.exist?
40+
log = LOG_PATHNAME.read()
41+
else
42+
log "Run `rake spec` to log where Thread.new is called."
43+
end
44+
45+
raise RuntimeError,
46+
"#{thread_count} #{'thread'.pluralize(thread_count)} exist(s) when " \
47+
"only #{EXPECTED_THREAD_COUNT_AROUND_SUITE} " \
48+
"#{'thread'.pluralize(EXPECTED_THREAD_COUNT_AROUND_SUITE)} expected before suite runs:\n" \
49+
"#{log}"
50+
end
51+
52+
LOG_PATHNAME.parent.mkpath
53+
54+
LOG_PATHNAME.open('a') do |f|
55+
# separator so after(:suite) can differentiate between threads created before(:suite) and during the
56+
# suites
57+
f.puts 'before(:suite)'
58+
end
59+
end
60+
61+
config.after(:suite) do
62+
LOG_PATHNAME.parent.mkpath
63+
64+
LOG_PATHNAME.open('a') do |f|
65+
# separator so that a flip flop can be used when reading the file below. Also useful if it turns
66+
# out any threads are being created after this callback, which could be the case if another
67+
# after(:suite) accidentally created threads by creating an Msf::Simple::Framework instance.
68+
f.puts 'after(:suite)'
69+
end
70+
71+
thread_list = Metasploit::Framework::Spec::Threads::Suite.non_debugger_thread_list
72+
thread_count = thread_list.count
73+
74+
if thread_count > EXPECTED_THREAD_COUNT_AROUND_SUITE
75+
error_lines = []
76+
77+
if LOG_PATHNAME.exist?
78+
caller_by_thread_uuid = Metasploit::Framework::Spec::Threads::Suite.caller_by_thread_uuid
79+
80+
thread_list.each do |thread|
81+
thread_uuid = thread[Metasploit::Framework::Spec::Threads::Suite::UUID_THREAD_LOCAL_VARIABLE]
82+
83+
# unmanaged thread, such as the main VM thread
84+
unless thread_uuid
85+
next
86+
end
87+
88+
caller = caller_by_thread_uuid[thread_uuid]
89+
90+
error_lines << "Thread #{thread_uuid}'s status is #{thread.status.inspect} " \
91+
"and was started here:\n"
92+
93+
error_lines.concat(caller)
94+
end
95+
else
96+
error_lines << "Run `rake spec` to log where Thread.new is called."
97+
end
98+
99+
raise RuntimeError,
100+
"#{thread_count} #{'thread'.pluralize(thread_count)} exist(s) when only " \
101+
"#{EXPECTED_THREAD_COUNT_AROUND_SUITE} " \
102+
"#{'thread'.pluralize(EXPECTED_THREAD_COUNT_AROUND_SUITE)} expected after suite runs:\n" \
103+
"#{error_lines.join}"
104+
end
105+
end
106+
end
107+
108+
@configured = true
109+
end
110+
111+
@configured
112+
end
113+
114+
def self.define_task
115+
Rake::Task.define_task('metasploit:framework:spec:threads:suite') do
116+
if Metasploit::Framework::Spec::Threads::Suite::LOG_PATHNAME.exist?
117+
Metasploit::Framework::Spec::Threads::Suite::LOG_PATHNAME.delete
118+
end
119+
120+
parent_pathname = Pathname.new(__FILE__).parent
121+
threads_logger_pathname = parent_pathname.join('logger')
122+
load_pathname = parent_pathname.parent.parent.parent.parent.expand_path
123+
124+
# Must append to RUBYOPT or Rubymine debugger will not work
125+
ENV['RUBYOPT'] = "#{ENV['RUBYOPT']} -I#{load_pathname} -r#{threads_logger_pathname}"
126+
end
127+
128+
Rake::Task.define_task(spec: 'metasploit:framework:spec:threads:suite')
129+
end
130+
131+
# @note Ensure {LOG_PATHNAME} exists before calling.
132+
#
133+
# Yields each line of {LOG_PATHNAME} that happened during the suite run.
134+
#
135+
# @yield [line]
136+
# @yieldparam line [String] a line in the {LOG_PATHNAME} between `before(:suite)` and `after(:suite)`
137+
# @yieldreturn [void]
138+
def self.each_suite_line
139+
in_suite = false
140+
141+
LOG_PATHNAME.each_line do |line|
142+
if in_suite
143+
if line.start_with?('after(:suite)')
144+
break
145+
else
146+
yield line
147+
end
148+
else
149+
if line.start_with?('before(:suite)')
150+
in_suite = true
151+
end
152+
end
153+
end
154+
end
155+
156+
# @note Ensure {LOG_PATHNAME} exists before calling.
157+
#
158+
# Yield each line for each Thread UUID gathered during the suite run.
159+
#
160+
# @yield [uuid, line]
161+
# @yieldparam uuid [String] the UUID of thread thread
162+
# @yieldparam line [String] a line in the `caller` for the given `uuid`
163+
# @yieldreturn [void]
164+
def self.each_thread_line
165+
in_thread_caller = false
166+
uuid = nil
167+
168+
each_suite_line do |line|
169+
if in_thread_caller
170+
if line.start_with?('END Thread.new caller')
171+
in_thread_caller = false
172+
next
173+
else
174+
yield uuid, line
175+
end
176+
else
177+
match = line.match(UUID_REGEXP)
178+
179+
if match
180+
in_thread_caller = true
181+
uuid = match[:uuid]
182+
end
183+
end
184+
end
185+
end
186+
187+
# The `caller` for each Thread UUID.
188+
#
189+
# @return [Hash{String => Array<String>}]
190+
def self.caller_by_thread_uuid
191+
lines_by_thread_uuid = Hash.new { |hash, uuid|
192+
hash[uuid] = []
193+
}
194+
195+
each_thread_line do |uuid, line|
196+
lines_by_thread_uuid[uuid] << line
197+
end
198+
199+
lines_by_thread_uuid
200+
end
201+
202+
# @return
203+
def self.non_debugger_thread_list
204+
Thread.list.reject { |thread|
205+
# don't do `is_a? Debugger::DebugThread` because it requires Debugger::DebugThread to be loaded, which it
206+
# won't when not debugging.
207+
thread.class.name == 'Debugger::DebugThread'
208+
}
209+
end
210+
end
211+
end
212+
end
213+
end
214+
end

0 commit comments

Comments
 (0)