add prosopite n+1 query detection

Detection is disabled by default, but can be enabled by setting the
N_PLUS_ONE_DETECTION environment variable to 'true'. For more information,
see doc/detect_n_plus_one_queries.md

closes EVAL-2973
flag=none

Test Plan:
1. Start rails
2. Create a coures with multiple assignments and go to
   /courses/:id/assignments
3. Notice there are no N+1 query warnings shown in log/development.log
   and that log/prosopite.log does not exist.
4. Run the `spec/models/grading_period_spec.rb` spec file and notice that
   no N+1 query warnings are shown in log/test.log
5. Set `N_PLUS_ONE_DETECTION: 'true'` in docker-compose.override.yml
   under web: :environment.
6. Stop/start rails
7. Go to /courses/:id/assignments
8. Notice there are N+1 query warnings shown in log/development.log
   and that log/prosopite.log exists and also has warnings in it.
9. Run the `spec/models/grading_period_spec.rb` spec file and notice that
   N+1 query warnings are shown in log/test.log (but not in
   log/prosopite.log)

Change-Id: I33f43e65df10e2161f1a0687eee3e0b7826bfe3d
Reviewed-on: https://gerrit.instructure.com/c/canvas-lms/+/313592
Tested-by: Service Cloud Jenkins <svc.cloudjenkins@instructure.com>
Reviewed-by: Cody Cutrer <cody@instructure.com>
Build-Review: Jacob Burroughs <jburroughs@instructure.com>
QA-Review: Kai Bjorkman <kbjorkman@instructure.com>
Product-Review: Cameron Ray <cameron.ray@instructure.com>

Gemfile.d/app.rb

@@ -112,6 +112,7 @@ gem "pdf-reader", "2.5.0"
 gem "pg_query", "2.2.0"
 gem "prawn-rails", "1.3.0"
   gem "matrix", "0.4.2" # Used to be a default gem but is no more, but prawn depends on it implicitly
+gem "prosopite", "~> 1.3"
 gem "rack", "2.2.3"
 gem "rack-brotli", "1.0.0"
 gem "rack-test", "1.1.0"

Gemfile.rails70.lock.partial

@@ -856,6 +856,7 @@ GEM
     prawn-table (0.2.2)
       prawn (>= 1.3.0, < 3.0.0)
     promise.rb (0.7.4)
+    prosopite (1.3.0)
     pry (0.14.2)
       coderay (~> 1.1)
       method_source (~> 1.0)
@@ -1331,6 +1332,7 @@ DEPENDENCIES
   pg (= 1.4.5)
   pg_query (= 2.2.0)
   prawn-rails (= 1.3.0)
+  prosopite (~> 1.3)
   pry-byebug (= 3.10.1)
   puma (= 5.2.2)
   qti_exporter!

app/controllers/application_controller.rb

@@ -47,6 +47,17 @@ class ApplicationController < ActionController::Base
   #   (which is common for 401, 404, 500 responses)
   # Around action yields return (in REVERSE order) after all after actions
 
+  if !Rails.env.production? && Canvas::Plugin.value_to_boolean(ENV["N_PLUS_ONE_DETECTION"])
+    around_action :n_plus_one_detection
+
+    def n_plus_one_detection
+      Prosopite.scan
+      yield
+    ensure
+      Prosopite.finish
+    end
+  end
+
   prepend_before_action :load_user, :load_account
   # make sure authlogic is before load_user
   skip_before_action :activate_authlogic

config/docker-compose.override.yml.example

@@ -50,6 +50,7 @@ services:
       # AR_QUERY_TRACE: 'true'
       # AR_QUERY_TRACE_TYPE: 'all' # 'all', 'write', or 'read'
       # AR_QUERY_TRACE_LINES: 10
+      # N_PLUS_ONE_DETECTION: 'true'
 
   postgres:
     volumes:

config/initializers/prosopite.rb

@@ -0,0 +1,33 @@
+# frozen_string_literal: true
+
+#
+# Copyright (C) 2023 - present Instructure, Inc.
+#
+# This file is part of Canvas.
+#
+# Canvas is free software: you can redistribute it and/or modify it under
+# the terms of the GNU Affero General Public License as published by the Free
+# Software Foundation, version 3 of the License.
+#
+# Canvas is distributed in the hope that it will be useful, but WITHOUT ANY
+# WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR
+# A PARTICULAR PURPOSE. See the GNU Affero General Public License for more
+# details.
+#
+# You should have received a copy of the GNU Affero General Public License along
+# with this program. If not, see <http://www.gnu.org/licenses/>.
+
+module ProsopiteInitializer
+  def self.configure!
+    Rails.application.config.after_initialize do
+      # Only report N+1 cases where query count is >= 3
+      Prosopite.min_n_queries = 3
+      # Send warnings to the Rails log
+      Prosopite.rails_logger = true
+      # Send warnings to log/prosopite.log for development
+      Prosopite.prosopite_logger = true if Rails.env.development?
+    end
+  end
+end
+
+ProsopiteInitializer.configure!

doc/detect_n_plus_one_queries.md

@@ -0,0 +1,69 @@
+# Detect N+1 Queries
+
+Canvas uses the [prosopite](https://github.com/charkost/prosopite) gem to detect N+1 query problems and prints information about them to `log/development.log` in development, and to `log/test.log` in test. It also prints this information to its own dedicated log file, `log/prosopite.log` when in development. Here's an example report:
+
+```ruby
+N+1 queries detected:
+  SELECT "context_external_tools".* FROM "public"."context_external_tools" WHERE "context_external_tools"."id" = 1 LIMIT 1
+  SELECT "context_external_tools".* FROM "public"."context_external_tools" WHERE "context_external_tools"."id" = 1 LIMIT 1
+  SELECT "context_external_tools".* FROM "public"."context_external_tools" WHERE "context_external_tools"."id" = 1 LIMIT 1
+  SELECT "context_external_tools".* FROM "public"."context_external_tools" WHERE "context_external_tools"."id" = 1 LIMIT 1
+Call stack:
+  config/initializers/postgresql_adapter.rb:315:in `exec_query'
+  app/models/content_tag.rb:283:in `content'
+  app/models/assignment.rb:3504:in `quiz_lti?'
+  app/models/assignment.rb:394:in `can_duplicate?'
+  lib/api/v1/assignment.rb:193:in `assignment_json'
+  lib/api/v1/assignment_group.rb:82:in `block in assignment_group_json'
+  lib/api/v1/assignment_group.rb:75:in `map'
+  lib/api/v1/assignment_group.rb:75:in `assignment_group_json'
+  ...<more stack trace>
+```
+
+In production, the gem can only be used via the `Prosopite.scan` method (the use case being testing some code for N+1s in a Rails Console).
+
+## Prosopite.scan
+
+You can pass a block to `Prosopite.scan` to have it check for N+1 queries:
+
+```ruby
+Prosopite.scan do
+  Course.where(id: 1..5).each { |course| course.assignments.first }
+end
+
+N+1 queries detected:
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 4 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 1 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 2 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 3 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+Call stack:
+  config/initializers/postgresql_adapter.rb:315:in `exec_query'
+  (irb):5:in `block (2 levels) in <main>'
+  (irb):5:in `block in <main>'
+  (irb):4:in `<main>'
+
+```
+
+If you don't want to pass a block, you can use `Prosopite.scan` along with `Prosopite.finish`:
+
+```ruby
+Prosopite.scan
+Course.where(id: 1..5).each { |course| course.assignments.first }
+foo = "bar"
+Prosopite.finish
+N+1 queries detected:
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 4 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 1 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 2 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+  SELECT "assignments".* FROM "public"."assignments" WHERE "assignments"."context_id" = 3 AND "assignments"."context_type" = 'Course' ORDER BY assignments.created_at LIMIT 1
+Call stack:
+  config/initializers/postgresql_adapter.rb:315:in `exec_query'
+  (irb):5:in `block in <main>'
+  (irb):5:in `<main>'
+```
+
+## Enabling Detection
+
+Automatic N+1 detection for requests is off by default. Setting the N_PLUS_ONE_DETECTION environment variable to 'true' causes all controller actions to be wrapped in a `Prosopite.scan` while in `development` or `test`. It also causes all rspec tests to be wrapped in a `Prosopite.scan`.
+
+You can manually invoke `Prosopite.scan` in any environment, even when the N_PLUS_ONE_DETECTION environment variable is not set to 'true'.

spec/spec_helper.rb

@@ -557,6 +557,16 @@ RSpec.configure do |config|
     Canvas::Redis.redis_used = false
   end
 
+  if Canvas::Plugin.value_to_boolean(ENV["N_PLUS_ONE_DETECTION"])
+    config.before do
+      Prosopite.scan
+    end
+
+    config.after do
+      Prosopite.finish
+    end
+  end
+
   # ****************************************************************
   # There used to be a lot of factory methods here!
   # In an effort to move us toward a nicer test factory solution,