From 9e1e519fec014067c42d2a3f52d1218c3b3309e2 Mon Sep 17 00:00:00 2001 From: Willem van Bergen Date: Thu, 24 Sep 2009 08:59:05 +0200 Subject: [PATCH] Completely refactored the Rails log format parser to offer more flexibility. Moreover, improved the specs for this parser significantly. --- bin/request-log-analyzer | 3 +- lib/request_log_analyzer/controller.rb | 6 +- lib/request_log_analyzer/file_format/rails.rb | 209 ++++++++++++------ .../file_format/rails_development.rb | 51 +---- spec/fixtures/rails_22.log | 2 +- spec/unit/file_format/rails_format_spec.rb | 181 +++++++++------ 6 files changed, 267 insertions(+), 185 deletions(-) diff --git a/bin/request-log-analyzer b/bin/request-log-analyzer index dbad9ac7..a70ca300 100755 --- a/bin/request-log-analyzer +++ b/bin/request-log-analyzer @@ -15,8 +15,6 @@ begin command_line.command(:console) do |cons| cons.option(:database, :alias => :d, :required => true) - cons.option(:format, :alias => :f, :default => 'rails') - cons.option(:apache_format) end command_line.command(:strip) do |strip| @@ -29,6 +27,7 @@ begin command_line.option(:format, :alias => :f, :default => 'rails') command_line.option(:apache_format) + command_line.option(:rails_format) command_line.option(:file, :alias => :e) command_line.option(:mail, :alias => :m) diff --git a/lib/request_log_analyzer/controller.rb b/lib/request_log_analyzer/controller.rb index e85e6bdc..77f1a33c 100644 --- a/lib/request_log_analyzer/controller.rb +++ b/lib/request_log_analyzer/controller.rb @@ -46,7 +46,9 @@ def self.build_from_arguments(arguments) options[:report_width] = arguments[:report_width] # Apache format workaround - if arguments[:apache_format] + if arguments[:rails_format] + options[:format] = {:rails => arguments[:rails_format]} + elsif arguments[:apache_format] options[:format] = {:apache => arguments[:apache_format]} end @@ -255,7 +257,7 @@ def aggregate_request(request) # 6. Finalize Source def run! - @aggregators.each{|agg| p agg} + # @aggregators.each{|agg| p agg} @aggregators.each { |agg| agg.prepare } install_signal_handlers diff --git a/lib/request_log_analyzer/file_format/rails.rb b/lib/request_log_analyzer/file_format/rails.rb index c216fc4e..b024e3f0 100644 --- a/lib/request_log_analyzer/file_format/rails.rb +++ b/lib/request_log_analyzer/file_format/rails.rb @@ -1,36 +1,80 @@ module RequestLogAnalyzer::FileFormat + # Default FileFormat class for Rails logs. + # + # Instances will be created dynamically based on the lines you want it to parse. You can + # specify what lines should be included in the parser by providing a list to the create + # method as first argument. class Rails < Base - # Processing EmployeeController#index (for 123.123.123.123 at 2008-07-13 06:00:00) [GET] - line_definition :processing do |line| - line.header = true # this line is the first log line for a request - line.teaser = /Processing / - line.regexp = /Processing ((?:\w+::)?\w+)#(\w+)(?: to (\w+))? \(for (\d+\.\d+\.\d+\.\d+) at (\d\d\d\d-\d\d-\d\d \d\d:\d\d:\d\d)\) \[([A-Z]+)\]/ - line.captures << { :name => :controller, :type => :string } \ - << { :name => :action, :type => :string } \ - << { :name => :format, :type => :string, :default => 'html' } \ - << { :name => :ip, :type => :string } \ - << { :name => :timestamp, :type => :timestamp } \ - << { :name => :method, :type => :string } - end + # Creates a Rails FileFormat instance. + # + # The lines that will be parsed can be defined by the argument to this function, + # which should be an array of line names, or a list of line names as comma separated + # string. The resulting report depends on the lines that will be parsed. You can + # also provide s string that describes a common set of lines, like "production", + # "development" or "production". + def self.create(lines = 'production') + line_definitions = line_definer.line_definitions + + lines = lines.to_s.split(',') if lines.kind_of?(String) + lines = [lines.to_s] if lines.kind_of?(Symbol) + + lines.each do |line| + line = line.to_sym + if LINE_COLLECTIONS.has_key?(line) + LINE_COLLECTIONS[line].each { |l| line_definitions[l] = LINE_DEFINITIONS[l] } + elsif LINE_DEFINITIONS.has_key?(line) + line_definitions[line] = LINE_DEFINITIONS[line] + else + raise "Unrecognized Rails log line name: #{line.inspect}!" + end + end - # Filter chain halted as [#{}, :layout=>nil, :cache_path=>#}>] rendered_or_redirected. - line_definition :cache_hit do |line| - line.regexp = /Filter chain halted as \[\# REQUEST_CATEGORIZER, :title => 'Top 20 hits', :amount => 20 + analyze.frequency :method, :title => 'HTTP methods' + analyze.frequency :status, :title => 'HTTP statuses returned' + + if line_definitions.has_key?(:cache_hit) + analyze.frequency(:category => lambda { |request| request =~ :cache_hit ? 'Cache hit' : 'No hit' }, + :title => 'Rails action cache hits') + end + + analyze.duration :duration, :category => REQUEST_CATEGORIZER, :title => "Request duration", :line_type => :completed + analyze.duration :view, :category => REQUEST_CATEGORIZER, :title => "View rendering time", :line_type => :completed + analyze.duration :db, :category => REQUEST_CATEGORIZER, :title => "Database time", :line_type => :completed + + analyze.frequency :category => REQUEST_CATEGORIZER, :title => 'Process blockers (> 1 sec duration)', + :if => lambda { |request| request[:duration] && request[:duration] > 1.0 }, :amount => 20 + + if line_definitions.has_key?(:failure) + analyze.frequency :error, :title => 'Failed requests', :line_type => :failure, :amount => 20 + end - # RuntimeError (Cannot destroy employee): /app/models/employee.rb:198:in `before_destroy' - line_definition :failed do |line| - line.footer = true - line.regexp = /((?:[A-Z]\w+\:\:)*[A-Z]\w+) \((.*)\)(?: on line #(\d+) of .+)?\:(.*)/ - line.captures << { :name => :error, :type => :string } \ - << { :name => :message, :type => :string } \ - << { :name => :line, :type => :integer } \ - << { :name => :file, :type => :string } \ - << { :name => :stack_trace, :type => :string } - end + if line_definitions.has_key?(:rendered) + analyze.duration :render_duration, :category => :render_file, :multiple_per_request => true, + :amount => 20, :title => 'Partial rendering duration' + end + if line_definitions.has_key?(:query_executed) + analyze.duration :query_duration, :category => :query_sql, :multiple_per_request => true, + :amount => 20, :title => 'Query duration' + end + + return analyze.trackers + report_definer.trackers + end # Rails < 2.1 completed line example # Completed in 0.21665 (4 reqs/sec) | Rendering: 0.00926 (4%) | DB: 0.00000 (0%) | 200 OK [http://demo.nu/employees] @@ -40,51 +84,79 @@ class Rails < Base # Completed in 614ms (View: 120, DB: 31) | 200 OK [http://floorplanner.local/demo] RAILS_22_COMPLETED = /Completed in (\d+)ms \((?:View: (\d+), )?DB: (\d+)\) \| (\d\d\d).+\[(http.+)\]/ - # The completed line uses a kind of hack to ensure that both old style logs and new style logs - # are both parsed by the same regular expression. The format in Rails 2.2 was slightly changed, - # but the line contains exactly the same information. - line_definition :completed do |line| - - line.footer = true - line.teaser = /Completed in / - line.regexp = Regexp.new("(?:#{RAILS_21_COMPLETED}|#{RAILS_22_COMPLETED})") - - line.captures << { :name => :duration, :type => :duration, :unit => :sec } \ - << { :name => :view, :type => :duration, :unit => :sec } \ - << { :name => :db, :type => :duration, :unit => :sec } \ - << { :name => :status, :type => :integer } \ - << { :name => :url, :type => :string } # Old variant - - line.captures << { :name => :duration, :type => :duration, :unit => :msec } \ - << { :name => :view, :type => :duration, :unit => :msec } \ - << { :name => :db, :type => :duration, :unit => :msec } \ - << { :name => :status, :type => :integer } \ - << { :name => :url, :type => :string } # 2.2 variant - end - + # A hash of definitions for all common lines in Rails logs. + LINE_DEFINITIONS = { + :processing => RequestLogAnalyzer::LineDefinition.new(:processing, :header => true, + :teaser => /Processing /, + :regexp => /Processing ((?:\w+::)?\w+)#(\w+)(?: to (\w+))? \(for (\d+\.\d+\.\d+\.\d+) at (\d\d\d\d-\d\d-\d\d \d\d:\d\d:\d\d)\) \[([A-Z]+)\]/, + :captures => [{ :name => :controller, :type => :string }, + { :name => :action, :type => :string }, + { :name => :format, :type => :string, :default => 'html' }, + { :name => :ip, :type => :string }, + { :name => :timestamp, :type => :timestamp }, + { :name => :method, :type => :string }]), + + :completed => RequestLogAnalyzer::LineDefinition.new(:completed, :footer => true, + :teaser => /Completed in /, + :regexp => Regexp.union(RAILS_21_COMPLETED, RAILS_22_COMPLETED), + :captures => [{ :name => :duration, :type => :duration, :unit => :sec }, # First old variant capture + { :name => :view, :type => :duration, :unit => :sec }, + { :name => :db, :type => :duration, :unit => :sec }, + { :name => :status, :type => :integer }, + { :name => :url, :type => :string }, # Last old variant capture + { :name => :duration, :type => :duration, :unit => :msec }, # First new variant capture + { :name => :view, :type => :duration, :unit => :msec }, + { :name => :db, :type => :duration, :unit => :msec }, + { :name => :status, :type => :integer }, + { :name => :url, :type => :string }]), # Last new variant capture + + :failure => RequestLogAnalyzer::LineDefinition.new(:failure, :footer => true, + :regexp => /((?:[A-Z]\w+\:\:)*[A-Z]\w+) \((.*)\)(?: on line #(\d+) of (.+))?\:/, + :captures => [{ :name => :error, :type => :string }, + { :name => :message, :type => :string }, + { :name => :line, :type => :integer }, + { :name => :file, :type => :string }]), + + :cache_hit => RequestLogAnalyzer::LineDefinition.new(:cache_hit, + :regexp => /Filter chain halted as \[\# RequestLogAnalyzer::LineDefinition.new(:parameters, + :teaser => / Parameters:/, + :regexp => / Parameters:\s+(\{.*\})/, + :captures => [{ :name => :params, :type => :eval }]), + + :rendered => RequestLogAnalyzer::LineDefinition.new(:rendered, + :teaser => /Rendered /, + :regexp => /Rendered (\w+(?:\/\w+)+) \((\d+\.\d+)ms\)/, + :captures => [{ :name => :render_file, :type => :string }, + { :name => :render_duration, :type => :duration, :unit => :msec }]), + + :query_executed => RequestLogAnalyzer::LineDefinition.new(:query_executed, + :regexp => /\s+(?:\e\[4;36;1m)?((?:\w+::)*\w+) Load \((\d+\.\d+)ms\)(?:\e\[0m)?\s+(?:\e\[0;1m)?([^\e]+) ?(?:\e\[0m)?/, + :captures => [{ :name => :query_class, :type => :string }, + { :name => :query_duration, :type => :duration, :unit => :msec }, + { :name => :query_sql, :type => :sql }]), + + :query_cached => RequestLogAnalyzer::LineDefinition.new(:query_cached, + :regexp => /\s+(?:\e\[4;35;1m)?CACHE \((\d+\.\d+)ms\)(?:\e\[0m)?\s+(?:\e\[0m)?([^\e]+) ?(?:\e\[0m)?/, + :captures => [{ :name => :cached_duration, :type => :duration, :unit => :msec }, + { :name => :cached_sql, :type => :sql }]) + } + + # Definitions of common combinations of lines that can be parsed + LINE_COLLECTIONS = { + :minimal => [:processing, :completed], + :production => [:processing, :completed, :failure, :cache_hit], + :development => [:processing, :completed, :failure, :rendered, :query_executed, :query_cached], + :all => LINE_DEFINITIONS.keys + } + + + # Simple function to categorize Rails requests using controller/actions/format and method. REQUEST_CATEGORIZER = Proc.new do |request| "#{request[:controller]}##{request[:action]}.#{request[:format]} [#{request[:method]}]" end - report do |analyze| - analyze.timespan - analyze.hourly_spread - - analyze.frequency :category => REQUEST_CATEGORIZER, :title => 'Top 20 hits', :amount => 20 - analyze.frequency :method, :title => 'HTTP methods' - analyze.frequency :status, :title => 'HTTP statuses returned' - analyze.frequency :category => lambda { |request| request =~ :cache_hit ? 'Cache hit' : 'No hit' }, :title => 'Rails action cache hits' - - analyze.duration :duration, :category => REQUEST_CATEGORIZER, :title => "Request duration", :line_type => :completed - analyze.duration :view, :category => REQUEST_CATEGORIZER, :title => "View rendering time", :line_type => :completed - analyze.duration :db, :category => REQUEST_CATEGORIZER, :title => "Database time", :line_type => :completed - - analyze.frequency :category => REQUEST_CATEGORIZER, :title => 'Process blockers (> 1 sec duration)', - :if => lambda { |request| request[:duration] && request[:duration] > 1.0 }, :amount => 20 - - analyze.frequency :error, :title => 'Failed requests', :line_type => :failed, :amount => 20 - end - # Define a custom Request class for the Rails file format to speed up timestamp handling # and to ensure that a format is always set. class Request < RequestLogAnalyzer::Request @@ -93,6 +165,11 @@ class Request < RequestLogAnalyzer::Request def convert_timestamp(value, definition) value.gsub(/[^0-9]/, '')[0...14].to_i end + + # Sanitizes SQL queries so that they can be grouped + def convert_sql(sql, definition) + sql.gsub(/\b\d+\b/, ':int').gsub(/`([^`]+)`/, '\1').gsub(/'[^']*'/, ':string').rstrip + end end end diff --git a/lib/request_log_analyzer/file_format/rails_development.rb b/lib/request_log_analyzer/file_format/rails_development.rb index 7222801b..ea4f0eb2 100644 --- a/lib/request_log_analyzer/file_format/rails_development.rb +++ b/lib/request_log_analyzer/file_format/rails_development.rb @@ -4,54 +4,9 @@ module RequestLogAnalyzer::FileFormat # all lines of the normal Rails file format, but parses SQL queries and partial rendering lines # as well. class RailsDevelopment < Rails - - # Parameters: {"action"=>"demo", "controller"=>"page"} - line_definition :parameters do |line| - line.teaser = /Parameters/ - line.regexp = /\s+Parameters:\s+(\{.*\})/ - line.captures << { :name => :params, :type => :eval } - end - - # Rendered layouts/_footer (2.9ms) - line_definition :rendered do |line| - line.regexp = /Rendered (\w+(?:\/\w+)+) \((\d+\.\d+)ms\)/ - line.captures << { :name => :render_file, :type => :string } \ - << { :name => :render_duration, :type => :duration, :unit => :msec } - end - - # User Load (0.4ms) SELECT * FROM `users` WHERE (`users`.`id` = 18205844)  - line_definition :query_executed do |line| - line.regexp = /\s+(?:\e\[4;36;1m)?((?:\w+::)*\w+) Load \((\d+\.\d+)ms\)(?:\e\[0m)?\s+(?:\e\[0;1m)?([^\e]+) ?(?:\e\[0m)?/ - line.captures << { :name => :query_class, :type => :string } \ - << { :name => :query_duration, :type => :duration, :unit => :msec } \ - << { :name => :query_sql, :type => :sql } - end - - # CACHE (0.0ms) SELECT * FROM `users` WHERE (`users`.`id` = 0)  - line_definition :query_cached do |line| - line.regexp = /\s+(?:\e\[4;35;1m)?CACHE \((\d+\.\d+)ms\)(?:\e\[0m)?\s+(?:\e\[0m)?([^\e]+) ?(?:\e\[0m)?/ - line.captures << { :name => :cached_duration, :type => :duration, :unit => :msec } \ - << { :name => :cached_sql, :type => :sql } - end - - # Define the reporting for the additional parsed lines - report(:append) do |analyze| - - analyze.duration :render_duration, :category => :render_file, :multiple_per_request => true, - :amount => 20, :title => 'Partial rendering duration' - - analyze.duration :query_duration, :category => :query_sql, :multiple_per_request => true, - :amount => 20, :title => 'Query duration' - - end - - # Add a converter method for the SQL fields the the Rails request class - class Request < Rails::Request - - # Sanitizes SQL queries so that they can be grouped - def convert_sql(sql, definition) - sql.gsub(/\b\d+\b/, ':int').gsub(/`([^`]+)`/, '\1').gsub(/'[^']*'/, ':string').rstrip - end + def self.create + puts 'DEPRECATED: use --rails-format development instead!' + super('development') end end end diff --git a/spec/fixtures/rails_22.log b/spec/fixtures/rails_22.log index 103f8ba5..0a2452db 100644 --- a/spec/fixtures/rails_22.log +++ b/spec/fixtures/rails_22.log @@ -9,4 +9,4 @@ Rendered shared/_analytics (0.2ms) Rendered layouts/_actions (0.6ms) Rendered layouts/_menu (2.2ms) Rendered layouts/_tabbar (0.5ms) -Completed in 614ms (View: 120, DB: 31) | 200 OK [http://www.example.coml/demo] \ No newline at end of file +Completed in 614ms (View: 120, DB: 31) | 200 OK [http://www.example.com/demo] \ No newline at end of file diff --git a/spec/unit/file_format/rails_format_spec.rb b/spec/unit/file_format/rails_format_spec.rb index fc68fc9c..425c69c6 100644 --- a/spec/unit/file_format/rails_format_spec.rb +++ b/spec/unit/file_format/rails_format_spec.rb @@ -2,6 +2,121 @@ describe RequestLogAnalyzer::FileFormat::Rails do + describe '.create' do + + context 'without providing a lines argument' do + before(:each) { @rails = RequestLogAnalyzer::FileFormat.load(:rails) } + + it "should create a valid file format" do + @rails.should be_valid + end + + it "should parse the production lines" do + production_rails = RequestLogAnalyzer::FileFormat.load(:rails, 'production') + @rails.line_definitions.should == production_rails.line_definitions + end + end + + context 'using a comma separated list of lines as argument' do + before(:each) { @rails = RequestLogAnalyzer::FileFormat.load(:rails, 'minimal,failure') } + + it "should return a valid language" do + @rails.should be_valid + end + + it "should at least parse :processing and :completed lines" do + @rails.line_definitions.should include(:processing, :completed, :failure) + end + end + + RequestLogAnalyzer::FileFormat::Rails::LINE_COLLECTIONS.keys.each do |constant| + context "using the '#{constant}' line collection constant" do + + before(:each) { @rails = RequestLogAnalyzer::FileFormat.load(:rails, constant) } + + it "should return a valid language" do + @rails.should be_valid + end + + it "should at least parse :processing and :completed lines" do + @rails.line_definitions.should include(:processing, :completed) + end + end + end + end + + describe '#parse_line' do + before(:each) do + @rails = RequestLogAnalyzer::FileFormat.load(:rails, :all) + end + + sample_lines = [ + [:processing, nil, + 'Processing PeopleController#index (for 1.1.1.1 at 2008-08-14 21:16:30) [GET]', + { :controller => 'PeopleController', :action => 'index', :timestamp => 20080814211630, :method => 'GET'}], + [:completed, 'Rails 2.1 style', + 'Completed in 0.21665 (4 reqs/sec) | Rendering: 0.00926 (4%) | DB: 0.00000 (0%) | 200 OK [http://demo.nu/employees]', + {:duration => 0.21665, :db => 0.0, :view => 0.00926, :status => 200, :url => 'http://demo.nu/employees'}], + [:completed, 'Rails 2.2 style', + 'Completed in 614ms (View: 120, DB: 31) | 200 OK [http://floorplanner.local/demo]', + {:duration => 0.614, :db => 0.031, :view => 0.120, :status => 200, :url => 'http://floorplanner.local/demo'}], + [:failure, nil, + "NoMethodError (undefined method `update_domain_account' for nil:NilClass):", + {:error => 'NoMethodError', :message => "undefined method `update_domain_account' for nil:NilClass"} ], + [:cache_hit, nil, + 'Filter chain halted as [#{}, :layout=>nil, :cache_path=>#}>] rendered_or_redirected.'], + [:parameters, nil, + ' Parameters: {"action"=>"cached", "controller"=>"cached"}', + {:params => {:action => 'cached', :controller => 'cached'}}], + [:rendered, nil, + 'Rendered layouts/_footer (2.9ms)', + {:render_file => 'layouts/_footer', :render_duration => 0.0029} ], + [:query_executed, 'with coloring', + ' User Load (0.4ms) SELECT * FROM `users` WHERE (`users`.`id` = 18205844) ', + {:query_class => 'User', :query_duration => 0.0004, :query_sql => 'SELECT * FROM users WHERE (users.id = :int)' }], + [:query_executed, 'without coloring', + ' User Load (0.4ms) SELECT * FROM `users` WHERE (`users`.`id` = 18205844) ', + {:query_class => 'User', :query_duration => 0.0004, :query_sql => 'SELECT * FROM users WHERE (users.id = :int)' }], + [:query_cached, 'with coloring', + ' CACHE (0.0ms) SELECT * FROM `users` WHERE (`users`.`id` = 0) ', + {:cached_duration => 0.0, :cached_sql => 'SELECT * FROM users WHERE (users.id = :int)' }], + [:query_cached, 'without coloring', + ' CACHE (0.0ms) SELECT * FROM `users` WHERE (`users`.`id` = 0) ', + {:cached_duration => 0.0, :cached_sql => 'SELECT * FROM users WHERE (users.id = :int)' }], + ] + + sample_lines.each do |(line_type, comment, sample, values)| + values ||= {} + definition = RequestLogAnalyzer::FileFormat::Rails::LINE_DEFINITIONS[line_type] + + context "with a #{line_type.inspect} line #{comment}" do + before(:each) { @parse_result = @rails.parse_line(sample) } + + it "should recognize the line" do + @parse_result.should be_kind_of(Hash) + end + + it "should recognize the line type correctly" do + @parse_result[:line_definition].should == definition + end + + it "should capture #{definition.captures.length} values" do + @parse_result[:captures].should have(definition.captures.length).items + end + + values.each do |key, value| + it "should capture the #{key.inspect} value correctly as #{value.inspect}" do + @rails.request(@parse_result)[key].should == value + end + end + end + end + + it "should return nil with an unsupported line" do + @rails.parse_line('nonsense').should be_nil + end + end + before(:each) do @log_parser = RequestLogAnalyzer::Source::LogParser.new( RequestLogAnalyzer::FileFormat.load(:rails), :parse_strategy => 'cautious') @@ -30,30 +145,13 @@ @log_parser.parse_file(log_fixture(:rails_22)) do |request| request.should =~ :processing request.should =~ :completed - - request[:controller].should == 'PageController' - request[:action].should == 'demo' - request[:url].should == 'http://www.example.coml/demo' - request[:status].should == 200 - request[:duration].should == 0.614 - request[:db].should == 0.031 - request[:view].should == 0.120 end end it "should parse a syslog file with prefix correctly" do @log_parser.should_not_receive(:warn) @log_parser.parse_file(log_fixture(:syslog_1x)) do |request| - request.should be_completed - - request[:controller].should == 'EmployeeController' - request[:action].should == 'index' - request[:url].should == 'http://example.com/employee.xml' - request[:status].should == 200 - request[:duration].should == 0.21665 - request[:db].should == 0.0 - request[:view].should == 0.00926 end end @@ -76,52 +174,3 @@ @log_parser.parse_file(log_fixture(:rails_unordered)) end end - -describe RequestLogAnalyzer::FileFormat::RailsDevelopment do - - before(:each) do - @file_format = RequestLogAnalyzer::FileFormat.load(:rails_development) - @request = @file_format.request - end - - it "should have a valid language definitions" do - @file_format.should be_valid - end - - it "should have a different line definer than Rails" do - rails = RequestLogAnalyzer::FileFormat.load(:rails) - rails.class.line_definer.should_not == @file_format.class.line_definer - end - - it "should parse a rendered line" do - info = @file_format.line_definitions[:rendered].match_for("Rendered layouts/_footer (2.9ms)", @request) - info[:render_file].should == 'layouts/_footer' - info[:render_duration].should == 0.0029 - end - - it "should parse a query executed line with colors" do - info = @file_format.line_definitions[:query_executed].match_for(" User Load (0.4ms) SELECT * FROM `users` WHERE (`users`.`id` = 18205844) ", @request) - info[:query_class].should == 'User' - info[:query_duration].should == 0.0004 - info[:query_sql].should == 'SELECT * FROM users WHERE (users.id = :int)' - end - - it "should parse a query executed line without colors" do - info = @file_format.line_definitions[:query_executed].match_for(" User Load (0.4ms) SELECT * FROM `users` WHERE (`users`.`id` = 18205844) ", @request) - info[:query_class].should == 'User' - info[:query_duration].should == 0.0004 - info[:query_sql].should == 'SELECT * FROM users WHERE (users.id = :int)' - end - - it "should parse a cached query line with colors" do - info = @file_format.line_definitions[:query_cached].match_for(' CACHE (0.0ms) SELECT * FROM `users` WHERE (`users`.`id` = 0) ', @request) - info[:cached_duration].should == 0.0 - info[:cached_sql].should == 'SELECT * FROM users WHERE (users.id = :int)' - end - - it "should parse a cached query line without colors" do - info = @file_format.line_definitions[:query_cached].match_for(' CACHE (0.0ms) SELECT * FROM `users` WHERE (`users`.`id` = 0) ', @request) - info[:cached_duration].should == 0.0 - info[:cached_sql].should == 'SELECT * FROM users WHERE (users.id = :int)' - end -end \ No newline at end of file