From f2b53a3a4b1ddacac4fc18ccbe2b016194a50777 Mon Sep 17 00:00:00 2001 From: zedshaw Date: Sun, 26 Mar 2006 20:01:50 +0000 Subject: mongrel_rails now uses the RailsConfigurator. All rails.rb are now in Mongrel::Rails (like Camping). Configurator has many improvements. Signals on mongrel_rails now work better. git-svn-id: svn+ssh://rubyforge.org/var/svn/mongrel/trunk@122 19e92222-5c0b-0410-8929-a290d50e31e9 --- lib/mongrel/debug.rb | 233 ++++++++++++++++++++++++++++++++++++++------------- 1 file changed, 174 insertions(+), 59 deletions(-) (limited to 'lib/mongrel/debug.rb') diff --git a/lib/mongrel/debug.rb b/lib/mongrel/debug.rb index 8b2dd5c..6178872 100644 --- a/lib/mongrel/debug.rb +++ b/lib/mongrel/debug.rb @@ -1,6 +1,6 @@ require 'logger' require 'set' - +require 'socket' $mongrel_debugging=true @@ -8,14 +8,14 @@ module MongrelDbg SETTINGS = { :tracing => {}} LOGGING = { } - def MongrelDbg::configure(log_dir = "mongrel_debug") + def MongrelDbg::configure(log_dir = "log/mongrel_debug") Dir.mkdir(log_dir) if not File.exist?(log_dir) @log_dir = log_dir end def MongrelDbg::trace(target, message) - if SETTINGS[:tracing][target] + if SETTINGS[:tracing][target] and LOGGING[target] LOGGING[target].log(Logger::DEBUG, message) end end @@ -34,32 +34,28 @@ module MongrelDbg LOGGING[target].close LOGGING[target] = nil end + + def MongrelDbg::tracing?(target) + SETTINGS[:tracing][target] + end end module ObjectTracker @active_objects = nil - @live_object_tracking = false + @live_object_tracking = true def ObjectTracker.configure @active_objects = Set.new + ObjectSpace.each_object do |obj| @active_objects << obj.object_id end - srand @active_objects.object_id - @sample_thread = Thread.new do - loop do - sleep(rand(3) + (rand(100)/100.0)) - ObjectTracker.sample - end - end - @sample_thread.priority = 20 end + def ObjectTracker.start - @stopit = true @live_object_tracking = true - @stopit = false end def ObjectTracker.stop @@ -67,78 +63,197 @@ module ObjectTracker end def ObjectTracker.sample - ospace = Set.new - ObjectSpace.each_object do |obj| - ospace << obj.object_id + Class.stopit do + ospace = Set.new + counts = {} + + # Strings can't be tracked easily and are so numerous that they drown out all else + # so we just ignore them in the counts. + ObjectSpace.each_object do |obj| + if not obj.kind_of? String + ospace << obj.object_id + counts[obj.class] ||= 0 + counts[obj.class] += 1 + end + end + + dead_objects = @active_objects - ospace + new_objects = ospace - @active_objects + live_objects = ospace & @active_objects + + MongrelDbg::trace(:objects, "COUNTS: #{dead_objects.length},#{new_objects.length},#{live_objects.length}") + + if MongrelDbg::tracing? :objects + top_20 = counts.sort{|a,b| b[1] <=> a[1]}[0..20] + MongrelDbg::trace(:objects,"TOP 20: #{top_20.inspect}") + end + + @active_objects = live_objects + new_objects + + [@active_objects, top_20] end - - dead_objects = @active_objects - ospace - new_objects = ospace - @active_objects - live_objects = ospace & @active_objects - - STDERR.puts "#{dead_objects.length},#{new_objects.length},#{live_objects.length}" + end + +end + +$open_files = {} - @active_objects = live_objects + new_objects +class IO + alias_method :orig_open, :open + alias_method :orig_close, :close + + def open(*arg, &blk) + $open_files[self] = args.inspect + orig_open(*arg,&blk) end + def close(*arg,&blk) + $open_files.delete self + orig_close(*arg,&blk) + end end + +module Kernel + alias_method :orig_open, :open + + def open(*arg, &blk) + $open_files[self] = arg[0] + orig_open(*arg,&blk) + end + + def log_open_files + Class.stopit do + open_counts = {} + $open_files.each do |f,args| + open_counts[args] ||= 0 + open_counts[args] += 1 + end + MongrelDbg::trace(:files, open_counts.to_yaml) + end + end +end + + + class Class alias_method :orig_new, :new @@count = 0 - @@stoppit = false + @@stopit = false @@class_caller_count = Hash.new{|hash,key| hash[key] = Hash.new(0)} def new(*arg,&blk) - unless @@stoppit - @@stoppit = true + unless @@stopit + @@stopit = true @@count += 1 - @@class_caller_count[self][caller[0]] += 1 - @@stoppit = false + @@class_caller_count[self][caller.join("\n\t")] += 1 + @@stopit = false end orig_new(*arg,&blk) end - def Class.report_object_creations - @@stoppit = true - puts "Number of objects created = #{@@count}" - - total = Hash.new(0) - - @@class_caller_count.each_key do |klass| - caller_count = @@class_caller_count[klass] - caller_count.each_value do |count| - total[klass] += count - end - end - - klass_list = total.keys.sort{|klass_a, klass_b| - a = total[klass_a] - b = total[klass_b] - if a != b - -1* (a <=> b) - else - klass_a.to_s <=> klass_b.to_s + def Class.report_object_creations(out=$stderr, more_than=20) + Class.stopit do + out.puts "Number of objects created = #{@@count}" + + total = Hash.new(0) + + @@class_caller_count.each_key do |klass| + caller_count = @@class_caller_count[klass] + caller_count.each_value do |count| + total[klass] += count + end end - } - klass_list.each do |klass| - puts "#{total[klass]}\t#{klass} objects created." - caller_count = @@class_caller_count[ klass] - caller_count.keys.sort_by{|call| -1*caller_count[call]}.each do |call| - puts "\t#{call}\tCreated #{caller_count[call]} #{klass} objects." + + klass_list = total.keys.sort{|klass_a, klass_b| + a = total[klass_a] + b = total[klass_b] + if a != b + -1* (a <=> b) + else + klass_a.to_s <=> klass_b.to_s + end + } + + below_count = 0 + + klass_list.each do |klass| + below_calls = 0 + if total[klass] > more_than + out.puts "#{total[klass]}\t#{klass} objects created." + caller_count = @@class_caller_count[ klass] + caller_count.keys.sort_by{|call| -1*caller_count[call]}.each do |call| + if caller_count[call] > more_than + out.puts "\t** #{caller_count[call]} #{klass} objects AT:" + out.puts "\t#{call}\n\n" + else + below_calls += 1 + end + end + out.puts "\t#{below_calls} more objects had calls less that #{more_than} limit.\n\n" if below_calls > 0 + else + below_count += 1 + end end - puts + + out.puts "\t** #{below_count} More objects were created but the count was below the #{more_than} limit." if below_count > 0 end end def Class.reset_object_creations + Class.stopit do + @@count = 0 + @@class_caller_count = Hash.new{|hash,key| hash[key] = Hash.new(0)} + end + end + + def Class.stopit @@stopit = true - @@count = 0 - @@class_caller_count = Hash.new{|hash,key| hash[key] = Hash.new(0)} - @@stoppit = false + yield + @@stopit = false + end + +end + + +module RequestLog + class Files < GemPlugin::Plugin "/handlers" + include Mongrel::HttpHandlerPlugin + + def process(request, response) + MongrelDbg::trace(:files, "#{Time.now} FILES OPEN BEFORE REQUEST #{request.params['PATH_INFO']}") + log_open_files + end + + end + + class Objects < GemPlugin::Plugin "/handlers" + include Mongrel::HttpHandlerPlugin + + def process(request, response) + MongrelDbg::trace(:objects, "#{Time.now} OBJECT STATS BEFORE REQUEST #{request.params['PATH_INFO']}") + ObjectTracker.sample + end + + end + + + class Params < GemPlugin::Plugin "/handlers" + include Mongrel::HttpHandlerPlugin + + def process(request, response) + MongrelDbg::trace(:rails, "#{Time.now} REQUEST #{request.params['PATH_INFO']}") + MongrelDbg::trace(:rails, request.params.to_yaml) + end + end end +END { +open("log/mongrel_debug/object_tracking.log", "w") {|f| Class.report_object_creations(f) } +MongrelDbg::trace(:files, "FILES OPEN AT EXIT") +log_open_files +} -- cgit v1.2.3-24-ge0c7