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 extend CommonRegularExpressions # 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') definitions_hash = line_definer.line_definitions.clone lines = lines.to_s.split(',') if lines.is_a?(String) lines = [lines.to_s] if lines.is_a?(Symbol) lines.each do |line| line = line.to_sym if LINE_COLLECTIONS.key?(line) LINE_COLLECTIONS[line].each { |l| definitions_hash[l] ||= LINE_DEFINITIONS[l] } elsif LINE_DEFINITIONS.key?(line) definitions_hash[line] ||= LINE_DEFINITIONS[line] else fail "Unrecognized Rails log line name: #{line.inspect}!" end end new(definitions_hash, report_trackers(definitions_hash)) end # Creates trackers based on the specified line definitions. # # The more lines that will be parsed, the more information will appear in the report. def self.report_trackers(lines) analyze = RequestLogAnalyzer::Aggregator::Summarizer::Definer.new analyze.timespan analyze.hourly_spread analyze.frequency category: REQUEST_CATEGORIZER, title: 'Most requested' analyze.frequency :method, title: 'HTTP methods' analyze.frequency :status, title: 'HTTP statuses returned' if lines.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 } if lines.key?(:failure) analyze.frequency :error, title: 'Failed requests', line_type: :failure end if lines.key?(:rendered) analyze.duration :render_duration, category: :render_file, multiple: true, title: 'Partial rendering duration' end if lines.key?(:query_executed) analyze.duration :query_duration, category: :query_sql, multiple: true, title: 'Query duration' end 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] RAILS_21_COMPLETED = /Completed in (\d+\.\d{5}) \(\d+ reqs\/sec\) (?:\| Rendering: (\d+\.\d{5}) \(\d+\%\) )?(?:\| DB: (\d+\.\d{5}) \(\d+\%\) )?\| (\d\d\d).+\[(http.+)\]/ # Rails > 2.1 completed line example # 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{3}).+\[(http.+)\]/ # 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 (#{ip_address}) at (#{timestamp('%Y-%m-%d %H:%M:%S')})\) \[([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, teaser: /((?:[A-Z]\w*[a-z]\w+\:\:)*[A-Z]\w*[a-z]\w+) \((.*)\)(?: on line #(\d+) of (.+))?\:/, regexp: /((?:[A-Z]\w*[a-z]\w+\:\:)*[A-Z]\w*[a-z]\w+) \((.*)\)(?: on line #(\d+) of (.+))?\:\s*$/, 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 \[\#