Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP
Browse files

Fix Application#trace which would interleave CR in a multi-threaded c…

…ontext.

Running rake with tracing on and executing multitasks would show
a trace with multiple traces on a single line and other lines having
multiple CRs. This is because #trace used IO#puts behind the scenes.

IO#puts first calls #write with the string, followed by another #write
with the CR. Because of the gap in-between calls, another thread
could sneak in a CR or another string.

The fix is to make sure calls to trace create a single string with
a CR appended before calling IO#print. This will output a single
string with a trailing CR in thread-safe way.

Example output showing the error:

** Execute 98** Execute 68** Execute 69

** Execute 74

** Execute 78** Execute 81
** Execute 84** Execute 100

** Execute 89
  • Loading branch information...
commit 4f87251c48102a7e589ba45c493afa371afa21c3 1 parent 34098ab
@michaeljbishop michaeljbishop authored
Showing with 51 additions and 1 deletion.
  1. +13 −1 lib/rake/application.rb
  2. +38 −0 test/test_rake_application.rb
View
14 lib/rake/application.rb
@@ -316,7 +316,19 @@ def display_prerequisites
def trace(*str)
options.trace_output ||= $stderr
- options.trace_output.puts(*str)
+
+ # use the same semantics as puts, but use print and append a CR to the end to
+ # make sure the entire string is output as a single unit.
+ sep = ($\||"\n")
+ if str.empty?
+ options.trace_output.print sep
+ else
+ msgs = str.flatten.collect do |m|
+ next m + sep if m.is_a?(String) && !m.end_with?("\n")
+ m
+ end
+ options.trace_output.print(*msgs)
+ end
end
def sort_options(options)
View
38 test/test_rake_application.rb
@@ -340,6 +340,44 @@ def test_handle_options_trace_does_not_eat_following_task_names
assert @app.options.trace
end
+ def test_trace_output_does_not_combine_messages_on_a_single_line
+ assert !@app.options.trace
+ @app.options.trace = true
+ output = StringIO.new
+
+ # simulate the slow IO of writing to a file stream. This will
+ # exacerbate the problem
+ class << output
+ alias :old_write :write
+ def write (*args)
+ sleep(rand * 0.0001)
+ self.old_write(*args)
+ end
+ end
+
+ @app.options.trace_output = output
+ assert_equal output, @app.options.trace_output
+
+ (1..100).to_a.each do |i|
+ task i.to_s do
+ end
+ multitask :doit => i.to_s
+ end
+
+ # invoke all tasks simultaneously, if it behaves exactly
+ # like #puts, the trace will write a message and then before
+ # it writes the \n, another thread will
+ # write a trace message and output.string will look like:
+ #
+ # ** Execute 56** Execute 72 << We regex for number followed by **
+ #
+ # ** Execute 74
+
+ Rake::Task[:doit].invoke
+
+ refute( /[\d]+\*\*/ =~ output.string, "trace does not write single, atomic lines!")
+ end
+
def test_good_run
ran = false
Please sign in to comment.
Something went wrong with that request. Please try again.