ActiveRecordProfiler
====================

The `active-record-profiler` gem adds a log formatter to improve the standard SQL logging and a log subscriber to provide profiler-like tracking of SQL statements generated by application code. The log formatter makes the SQL statements in your logs look like this (imagine it's all in one log line):

    Person Load (0.3ms)  SELECT  `people`.* FROM `people`  WHERE `people`.`id` = ? LIMIT 1  [["id", 1]] 
      CALLED BY 'app/controllers/day_controller.rb:282:in `find_person''

If you're using log colorizing, then it's even fancier:

![Enhanced Log](./screenshots/enhanced-log.png?raw=true)

Each SQL log entry generated by ActiveRecord will have appended the filename, line number, and function name of the nearest calling application code. The information is determined by walking up the call stack until a filename within the `/app/` directory is found. If no such filename can be found, the SQL will be logged with a location of 'Non-application code'.

Additionally, the profiler will keep track of the total time spent by all SQL calls coming from each calling location, as well as the number of time that location accessed the database. Certain SQL calls not under the direct control of the application are not counted in these statistics, such as `SHOW FIELDS`, `SET NAMES`, `BEGIN`, and `COMMIT` statements which tend to skew the timing statistics and provide less useful information about slow SQL queries.

Periodically, the profiler will dump its statistics out to a file and restart all of its counters/timers. The output file is named for the time, process id, and thread id from which it was written, so that multiple threads/processes can safely write their output simultaneously.

Installation
============
Add it to your Gemfile, like so:

```ruby
gem 'active-record-profiler'
```

Then do `bundle install`, and then add a new initializer, `config/initializers/active_record_profiler.rb`:

```ruby
ActiveRecord::Base.logger =
    ActiveRecordProfiler::Logger.new(ActiveRecord::Base.logger)
ActiveRecordProfiler::LogSubscriber.attach_to :active_record unless Rails.env.test?
```

The first line adds call-site information to ActiveRecord logging, and the second line enables profiling (except in the test environment, where it would mess up your profiling data).

Configuration
=============

## stats_flush_period ##
Control the (approximate) frequency of statistics flushes (default: `1.hour`)

```ruby
ActiveRecordProfiler.stats_flush_period = 1.hour
```

Note that only flushed data is available for use in the reports (described below). If you are running a multithreaded or multiprocess server (which covers most common rails server types), your data will be incomplete until all those threads/processes/servers have flushed their data. This limitation exists primarily to avoid the overhead of coordinating/locking during the process of serving your application's web requests.

## profile_dir ##
Directory where profile data is recorded. (default: `Rails.root,join('log', 'profiler_data'`)

```ruby
ActiveRecordProfiler.profile_dir = Rails.root.join('log', 'profiler_data')
```

## sql_ignore_pattern ##
Any SQL statements matching this pattern will not be tracked by the profiler output, though it will still appear in the enhanced SQL logging. (default: `/^(SHOW (:?FULL )?FIELDS |SET SQL_AUTO_IS_NULL|SET NAMES |EXPLAIN |BEGIN|COMMIT|PRAGMA )/`)

```ruby
ActiveRecordProfiler.sql_ignore_pattern = /^SET /x
```

## app_path_pattern ##
 Any calling location that matches this pattern will be tracked individually. Any locations that do __not__ match will be grouped under a single `Non-application code` label. The default only includes the `app`, `lib`, and `vendor` directories, but that's usually suitable and avoids noise. (default: `Regexp.new(Regexp.quote("#{Rails.root.expand_path}/") + "(:?app|lib|vendor)/")`)

```ruby
ActiveRecordProfiler.app_path_pattern = Regexp.new(Regexp.quote("#{Rails.root.expand_path}/"))
```

## trim_root_path ##
This prefix will be removed from the calling site filepath for brevity. (default: `"#{Rails.root.expand_path}/"`)

```ruby
ActiveRecordProfiler.trim_root_path = "#{Rails.root.parent.expand_path}/app"
```

## profile_self ##
This setting controls whether the profiler records information about how much time was spent in the profiling code itself. If you want to know what kind of overhead the profiler is adding, set this to true. (default: `false`)

```ruby
ActiveRecordProfiler.profile_self = true
```

## link_location ##
Whether or not to make the locations in the profiler reports into source code links (only works with editors that can be launched via URL scheme) (default: `false`):

```ruby
ActiveRecordProfiler.link_location = true
```

## Source Code Editor Links ##
ActiveRecordProfiler currently only knows how to build links for a couple of different editors, but you can configure your own by adding a partial to your application, in `shared/active_record_profiler/_editor.html.erb`, which contains javascript code to set up a new formatter:

```html
<script type="text/javascript">
  // Remove default formatters, if you want:
  // ActiveRecordProfiler.clearLinkFormatters();
  //
  // Add a new editor with a name and a function that takes the file and line 
  // number, and returns a URL that links to that source code location:
  ActiveRecordProfiler.registerLinkFormatter('Sublime Text', 
      function(file, line, selectedLinkFormatter) {
        return "subl://open/?url=file://" + file + "&line=" + line;
      }
  );
</script>
```

The `ActiveRecordProfiler.registerLinkFormatter` method takes a `name` parameter (this shows up in the Editor menu) and a function which will be passed the `file` and `line` of a calling site. It will also be sent the `name` of the currently selected formatter, but this is usually ignored. The function should return a URL that links to the editor or source code view.

Command Line Reports
====================
To see a top-100 list of what SQL statements your application is spending its time in, run the following rake task:

```bash
rake profiler:aggregate max_lines=100 show_sql=true
```

This will return a list of the SQL which is taking the most time in your application in this format:

```
<file path>:<line number>:in <method name>: <total duration>, <call count>, <max single call duration>
```

This will aggregate all of the profiler data you have accumulated; in order to limit the timeframe of the data, use the `prefix` option to specify a partial date/time:

```bash
rake profiler:aggregate max_lines=100 show_sql=true prefix=2010-06-20-10  # data from June 20 during the 10am hour (roughly)
```

Each thread running the profiler flushes its stats periodically, and there is a rake task to combine multiple profiler data files together in order to keep the number of data files down to a manageable number. A good way to manage the data files on a server is to set up a cron task to run the following command once per hour or once per day:

```bash
rake profiler:aggregate compact=<'hour' or 'date'> RAILS_ENV=qa
```

Compacting by hour will result in a single file for each hour any process dumped its stats. Compacting by day will result in a single file for each day. When using the `prefix` option to generate a profiler report, you cannot specify an hour if you have compacted your data by date instead of hour (the prefix matching operates on the file names, which will not have hours if they have been compacted by date).

You can clear out all profiler data using the following command:

```bash
rake profiler:clear_data
```
  
If you want programmatic access to the profiler data, check out the source code for the rake tasks in `lib/active-record-profiler/tasks.rake`.


Web Reports
===========

The `active-record-profiler` gem also includes support for producing reports in your browser, which look something like this:

![Web Report UI](./screenshots/web-reports.png?raw=true)
 
In order to make it available, you'll want to mount the engine within your application's `routes.rb`. Since you don't want the public to have access to your profiler reports, you'll want to limit access to it. You could only mount the profiler's web interface in the development environment:

```ruby
mount ActiveRecordProfiler::Engine => "/profiler"  if Rails.env.development?
```

Or, if you are using [Devise](https://github.com/plataformatec/devise) and have an admin flag on a `User` model, for example:

```ruby
authenticated :user, -> user { user.admin? } do
  mount ActiveRecordProfiler::Engine => "/profiler"
end
```

When you visit the path where you've mounted the web interface, you will by default see a report for the current day. If you just installed `active-record-profiler`, there probably won't be anything there yet, in which case you should go play with your app for a while and come back later. :) Also note that if the web server you are using has multiple processes or threads, you won't see data from those other processes/threads until they dump their data.

Miscellaneous
=============

Copyright (c) 2010 Gist, Inc.
Copyright (c) 2015 Benjamin Turner