diff options
Diffstat (limited to 'activesupport')
| -rw-r--r-- | activesupport/CHANGELOG | 7 | ||||
| -rw-r--r-- | activesupport/lib/active_support.rb | 1 | ||||
| -rw-r--r-- | activesupport/lib/active_support/buffered_logger.rb | 44 | ||||
| -rw-r--r-- | activesupport/lib/active_support/core_ext/array/conversions.rb | 6 | ||||
| -rw-r--r-- | activesupport/lib/active_support/core_ext/string/inflections.rb | 17 | ||||
| -rw-r--r-- | activesupport/lib/active_support/tagged_logging.rb | 63 | ||||
| -rw-r--r-- | activesupport/test/buffered_logger_test.rb | 53 | ||||
| -rw-r--r-- | activesupport/test/core_ext/string_ext_test.rb | 12 | ||||
| -rw-r--r-- | activesupport/test/tagged_logging_test.rb | 67 |
9 files changed, 252 insertions, 18 deletions
diff --git a/activesupport/CHANGELOG b/activesupport/CHANGELOG index 63f406cd9f..d3a838cff0 100644 --- a/activesupport/CHANGELOG +++ b/activesupport/CHANGELOG @@ -1,5 +1,12 @@ *Rails 3.2.0 (unreleased)* +* Added ActiveSupport:TaggedLogging that can wrap any standard Logger class to provide tagging capabilities [DHH] + + Logger = ActiveSupport::TaggedLogging.new(Logger.new(STDOUT)) + Logger.tagged("BCX") { Logger.info "Stuff" } # Logs "[BCX] Stuff" + Logger.tagged("BCX", "Jason") { Logger.info "Stuff" } # Logs "[BCX] [Jason] Stuff" + Logger.tagged("BCX") { Logger.tagged("Jason") { Logger.info "Stuff" } } # Logs "[BCX] [Jason] Stuff" + * Added safe_constantize that constantizes a string but returns nil instead of an exception if the constant (or part of it) does not exist [Ryan Oblak] * ActiveSupport::OrderedHash is now marked as extractable when using Array#extract_options! [Prem Sichanugrist] diff --git a/activesupport/lib/active_support.rb b/activesupport/lib/active_support.rb index cc9ea5cffa..ff78e718f2 100644 --- a/activesupport/lib/active_support.rb +++ b/activesupport/lib/active_support.rb @@ -71,6 +71,7 @@ module ActiveSupport autoload :OrderedOptions autoload :Rescuable autoload :StringInquirer + autoload :TaggedLogging autoload :XmlMini end diff --git a/activesupport/lib/active_support/buffered_logger.rb b/activesupport/lib/active_support/buffered_logger.rb index 26412cd7f4..136e245859 100644 --- a/activesupport/lib/active_support/buffered_logger.rb +++ b/activesupport/lib/active_support/buffered_logger.rb @@ -25,22 +25,28 @@ module ActiveSupport # Silences the logger for the duration of the block. def silence(temporary_level = ERROR) if silencer + old_logger_level = @tmp_levels[Thread.current] begin - old_logger_level, self.level = level, temporary_level + @tmp_levels[Thread.current] = temporary_level yield self ensure - self.level = old_logger_level + if old_logger_level + @tmp_levels[Thread.current] = old_logger_level + else + @tmp_levels.delete(Thread.current) + end end else yield self end end - attr_accessor :level + attr_writer :level attr_reader :auto_flushing def initialize(log, level = DEBUG) @level = level + @tmp_levels = {} @buffer = Hash.new { |h,k| h[k] = [] } @auto_flushing = 1 @guard = Mutex.new @@ -62,8 +68,12 @@ module ActiveSupport end end + def level + @tmp_levels[Thread.current] || @level + end + def add(severity, message = nil, progname = nil, &block) - return if @level > severity + return if level > severity message = (message || (block && block.call) || progname).to_s # If a newline is necessary then create a new message ending with a newline. # Ensures that the original message is not mutated. @@ -84,7 +94,7 @@ module ActiveSupport end # end def #{severity.downcase}? # def debug? - #{severity} >= @level # DEBUG >= @level + #{severity} >= level # DEBUG >= @level end # end EOT end @@ -105,13 +115,15 @@ module ActiveSupport def flush @guard.synchronize do - buffer.each do |content| - @log.write(content) - end + write_buffer(buffer) # Important to do this even if buffer was empty or else @buffer will # accumulate empty arrays for each request where nothing was logged. clear_buffer + + # Clear buffers associated with dead threads or else spawned threads + # that don't call flush will result in a memory leak. + flush_dead_buffers end end @@ -133,5 +145,21 @@ module ActiveSupport def clear_buffer @buffer.delete(Thread.current) end + + # Find buffers created by threads that are no longer alive and flush them to the log + # in order to prevent memory leaks from spawned threads. + def flush_dead_buffers #:nodoc: + @buffer.keys.reject{|thread| thread.alive?}.each do |thread| + buffer = @buffer[thread] + write_buffer(buffer) + @buffer.delete(thread) + end + end + + def write_buffer(buffer) + buffer.each do |content| + @log.write(content) + end + end end end diff --git a/activesupport/lib/active_support/core_ext/array/conversions.rb b/activesupport/lib/active_support/core_ext/array/conversions.rb index 3b22e8b4f9..f3d06ecb2f 100644 --- a/activesupport/lib/active_support/core_ext/array/conversions.rb +++ b/activesupport/lib/active_support/core_ext/array/conversions.rb @@ -39,10 +39,10 @@ class Array # # Blog.all.to_formatted_s # => "First PostSecond PostThird Post" # - # Adding in the <tt>:db</tt> argument as the format yields a prettier - # output: + # Adding in the <tt>:db</tt> argument as the format yields a comma separated + # id list: # - # Blog.all.to_formatted_s(:db) # => "First Post,Second Post,Third Post" + # Blog.all.to_formatted_s(:db) # => "1,2,3" def to_formatted_s(format = :default) case format when :db diff --git a/activesupport/lib/active_support/core_ext/string/inflections.rb b/activesupport/lib/active_support/core_ext/string/inflections.rb index c7ceeb9de4..fd91b3cacb 100644 --- a/activesupport/lib/active_support/core_ext/string/inflections.rb +++ b/activesupport/lib/active_support/core_ext/string/inflections.rb @@ -9,14 +9,25 @@ require 'active_support/inflector/transliterate' class String # Returns the plural form of the word in the string. # + # If the optional parameter +count+ is specified, + # the singular form will be returned if <tt>count == 1</tt>. + # For any other value of +count+ the plural will be returned. + # + # ==== Examples # "post".pluralize # => "posts" # "octopus".pluralize # => "octopi" # "sheep".pluralize # => "sheep" # "words".pluralize # => "words" # "the blue mailman".pluralize # => "the blue mailmen" # "CamelOctopus".pluralize # => "CamelOctopi" - def pluralize - ActiveSupport::Inflector.pluralize(self) + # "apple".pluralize(1) # => "apple" + # "apple".pluralize(2) # => "apples" + def pluralize(count = nil) + if count == 1 + self + else + ActiveSupport::Inflector.pluralize(self) + end end # The reverse of +pluralize+, returns the singular form of a word in a string. @@ -42,7 +53,7 @@ class String def constantize ActiveSupport::Inflector.constantize(self) end - + # +safe_constantize+ tries to find a declared constant with the name specified # in the string. It returns nil when the name is not in CamelCase # or is not initialized. See ActiveSupport::Inflector.safe_constantize diff --git a/activesupport/lib/active_support/tagged_logging.rb b/activesupport/lib/active_support/tagged_logging.rb new file mode 100644 index 0000000000..a59fc26d5d --- /dev/null +++ b/activesupport/lib/active_support/tagged_logging.rb @@ -0,0 +1,63 @@ +require 'active_support/core_ext/object/blank' +require 'logger' + +module ActiveSupport + # Wraps any standard Logger class to provide tagging capabilities. Examples: + # + # Logger = ActiveSupport::TaggedLogging.new(Logger.new(STDOUT)) + # Logger.tagged("BCX") { Logger.info "Stuff" } # Logs "[BCX] Stuff" + # Logger.tagged("BCX", "Jason") { Logger.info "Stuff" } # Logs "[BCX] [Jason] Stuff" + # Logger.tagged("BCX") { Logger.tagged("Jason") { Logger.info "Stuff" } } # Logs "[BCX] [Jason] Stuff" + # + # This is used by the default Rails.logger as configured by Railties to make it easy to stamp log lines + # with subdomains, request ids, and anything else to aid debugging of multi-user production applications. + class TaggedLogging + def initialize(logger) + @logger = logger + @tags = Hash.new { |h,k| h[k] = [] } + end + + def tagged(*new_tags) + tags = current_tags + new_tags = Array.wrap(new_tags).flatten.reject(&:blank?) + tags.concat new_tags + yield + ensure + new_tags.size.times { tags.pop } + end + + def add(severity, message = nil, progname = nil, &block) + @logger.add(severity, "#{tags_text}#{message}", progname, &block) + end + + %w( fatal error warn info debug unkown ).each do |severity| + eval <<-EOM, nil, __FILE__, __LINE__ + 1 + def #{severity}(progname = nil, &block) + add(Logger::#{severity.upcase}, progname, &block) + end + EOM + end + + def flush(*args) + @tags.delete(Thread.current) + @logger.flush(*args) if @logger.respond_to?(:flush) + end + + def method_missing(method, *args) + @logger.send(method, *args) + end + + protected + + def tags_text + tags = current_tags + if tags.any? + tags.collect { |tag| "[#{tag}]" }.join(" ") + " " + end + end + + def current_tags + @tags[Thread.current] + end + end +end diff --git a/activesupport/test/buffered_logger_test.rb b/activesupport/test/buffered_logger_test.rb index 21049d685b..386006677b 100644 --- a/activesupport/test/buffered_logger_test.rb +++ b/activesupport/test/buffered_logger_test.rb @@ -198,4 +198,57 @@ class BufferedLoggerTest < Test::Unit::TestCase end assert byte_string.include?(BYTE_STRING) end + + def test_silence_only_current_thread + @logger.auto_flushing = true + run_thread_a = false + + a = Thread.new do + while !run_thread_a do + sleep(0.001) + end + @logger.info("x") + run_thread_a = false + end + + @logger.silence do + run_thread_a = true + @logger.info("a") + while run_thread_a do + sleep(0.001) + end + end + + a.join + + assert @output.string.include?("x") + assert !@output.string.include?("a") + end + + def test_flush_dead_buffers + @logger.auto_flushing = false + + a = Thread.new do + @logger.info("a") + end + + keep_running = true + Thread.new do + @logger.info("b") + while keep_running + sleep(0.001) + end + end + + @logger.info("x") + a.join + @logger.flush + + + assert @output.string.include?("x") + assert @output.string.include?("a") + assert !@output.string.include?("b") + + keep_running = false + end end diff --git a/activesupport/test/core_ext/string_ext_test.rb b/activesupport/test/core_ext/string_ext_test.rb index 5c1dddaf96..4d876954cf 100644 --- a/activesupport/test/core_ext/string_ext_test.rb +++ b/activesupport/test/core_ext/string_ext_test.rb @@ -20,7 +20,7 @@ end class StringInflectionsTest < Test::Unit::TestCase include InflectorTestCases include ConstantizeTestCases - + def test_erb_escape string = [192, 60].pack('CC') expected = 192.chr + "<" @@ -64,6 +64,10 @@ class StringInflectionsTest < Test::Unit::TestCase end assert_equal("plurals", "plurals".pluralize) + + assert_equal("blargles", "blargle".pluralize(0)) + assert_equal("blargle", "blargle".pluralize(1)) + assert_equal("blargles", "blargle".pluralize(2)) end def test_singularize @@ -301,13 +305,13 @@ class StringInflectionsTest < Test::Unit::TestCase "\354\225\204\353\246\254\353\236\221 \354\225\204\353\246\254 \354\225\204\353\235\274\353\246\254\354\230\244".force_encoding('UTF-8').truncate(10) end end - + def test_constantize run_constantize_tests_on do |string| string.constantize end end - + def test_safe_constantize run_safe_constantize_tests_on do |string| string.safe_constantize @@ -381,7 +385,7 @@ class OutputSafetyTest < ActiveSupport::TestCase test "A fixnum is safe by default" do assert 5.html_safe? end - + test "a float is safe by default" do assert 5.7.html_safe? end diff --git a/activesupport/test/tagged_logging_test.rb b/activesupport/test/tagged_logging_test.rb new file mode 100644 index 0000000000..17c4214dfc --- /dev/null +++ b/activesupport/test/tagged_logging_test.rb @@ -0,0 +1,67 @@ +require 'abstract_unit' +require 'active_support/core_ext/logger' +require 'active_support/tagged_logging' + +class TaggedLoggingTest < ActiveSupport::TestCase + class MyLogger < ::Logger + def flush(*) + info "[FLUSHED]" + end + end + + setup do + @output = StringIO.new + @logger = ActiveSupport::TaggedLogging.new(MyLogger.new(@output)) + end + + test "tagged once" do + @logger.tagged("BCX") { @logger.info "Funky time" } + assert_equal "[BCX] Funky time\n", @output.string + end + + test "tagged twice" do + @logger.tagged("BCX") { @logger.tagged("Jason") { @logger.info "Funky time" } } + assert_equal "[BCX] [Jason] Funky time\n", @output.string + end + + test "tagged thrice at once" do + @logger.tagged("BCX", "Jason", "New") { @logger.info "Funky time" } + assert_equal "[BCX] [Jason] [New] Funky time\n", @output.string + end + + test "tagged once with blank and nil" do + @logger.tagged(nil, "", "New") { @logger.info "Funky time" } + assert_equal "[New] Funky time\n", @output.string + end + + test "keeps each tag in their own thread" do + @logger.tagged("BCX") do + Thread.new do + @logger.tagged("OMG") { @logger.info "Cool story bro" } + end.join + @logger.info "Funky time" + end + assert_equal "[OMG] Cool story bro\n[BCX] Funky time\n", @output.string + end + + test "cleans up the taggings on flush" do + @logger.tagged("BCX") do + Thread.new do + @logger.tagged("OMG") do + @logger.flush + @logger.info "Cool story bro" + end + end.join + end + assert_equal "[FLUSHED]\nCool story bro\n", @output.string + end + + test "mixed levels of tagging" do + @logger.tagged("BCX") do + @logger.tagged("Jason") { @logger.info "Funky time" } + @logger.info "Junky time!" + end + + assert_equal "[BCX] [Jason] Funky time\n[BCX] Junky time!\n", @output.string + end +end |