Breadcrumbs/Mongo integration: Handle 'any_of' cases (#522)

* Breadcrumbs/Mongo integration: Handle 'any_of' cases

* Breadcrumbs/Mongo Integration: Improve filter sanitization process and add unit tests

* Breadcrumbs/Mongo integration: Ensure tests are notated correctly

* Breadcrumbs/Mongo filters: Add 1.9.3 & 2.0.0 compatability

* Breadcrumbs/Mongo integration: Appease rubocop

* Breadcrumbs/Mongo integration: Minor test and efficieny improvements

* Breadcrumbs/Mongo integration: Test improvements

* Breadcrumbs/Mongo integrations: Test spelling

features/fixtures/rails4/app/app/controllers/mongo_controller.rb

@@ -8,6 +8,7 @@ def success_crash
 
   def get_crash
     MongoModel.where(string_field: true).as_json
+    MongoModel.any_of({string_field: true}, {numeric_field: 123}).as_json
     "Statement".prepnd("Failing")
   end
 

features/fixtures/rails4/app/app/models/mongo_model.rb

@@ -2,4 +2,5 @@ class MongoModel
   include Mongoid::Document
 
   field :string_field, type: String
+  field :numeric_field, type: Integer
 end

features/fixtures/rails5/app/app/controllers/mongo_controller.rb

@@ -7,6 +7,7 @@ def success_crash
 
   def get_crash
     MongoModel.where(string_field: true).as_json
+    MongoModel.any_of({string_field: true}, {numeric_field: 123}).as_json
     "Statement".prepnd("Failing")
   end
 

features/fixtures/rails5/app/app/models/mongo_model.rb

@@ -2,4 +2,5 @@ class MongoModel
   include Mongoid::Document
 
   field :string_field, type: String
+  field :numeric_field, type: Integer
 end

features/rails_features/mongo_breadcrumbs.feature

@@ -52,6 +52,15 @@ Scenario Outline: Breadcrumb with filter parameters
   And the event "breadcrumbs.1.metaData.duration" is not null
   And the event "breadcrumbs.1.metaData.collection" equals "mongo_models"
   And the event "breadcrumbs.1.metaData.filter" equals "{"string_field":"?"}"
+  And the event "breadcrumbs.2.timestamp" is a timestamp
+  And the event "breadcrumbs.2.metaData.event_name" equals "mongo.succeeded"
+  And the event "breadcrumbs.2.metaData.command_name" equals "find"
+  And the event "breadcrumbs.2.metaData.database_name" equals "rails<rails_version>_development"
+  And the event "breadcrumbs.2.metaData.operation_id" is not null
+  And the event "breadcrumbs.2.metaData.request_id" is not null
+  And the event "breadcrumbs.2.metaData.duration" is not null
+  And the event "breadcrumbs.2.metaData.collection" equals "mongo_models"
+  And the event "breadcrumbs.2.metaData.filter" equals "{"$or":[{"string_field":"?"},{"numeric_field":"?"}]}"
 
   Examples:
     | ruby_version | rails_version |

lib/bugsnag/integrations/mongo.rb

@@ -10,6 +10,7 @@ class MongoBreadcrumbSubscriber
     MONGO_MESSAGE_PREFIX = "Mongo query "
     MONGO_EVENT_PREFIX = "mongo."
     MONGO_COMMAND_KEY = :bugsnag_mongo_commands
+    MAX_FILTER_DEPTH = 5
 
     ##
     # Listens to the 'started' event, storing the command for later usage
@@ -56,7 +57,7 @@ def leave_mongo_breadcrumb(event_name, event)
         collection_key = event.command_name == "getMore" ? "collection" : event.command_name
         meta_data[:collection] = command[collection_key]
         unless command["filter"].nil?
-          filter = command["filter"].map { |key, _v| [key, '?'] }.to_h
+          filter = sanitize_filter_hash(command["filter"])
           meta_data[:filter] = JSON.dump(filter)
         end
       end
@@ -65,6 +66,39 @@ def leave_mongo_breadcrumb(event_name, event)
       Bugsnag.leave_breadcrumb(message, meta_data, Bugsnag::Breadcrumbs::PROCESS_BREADCRUMB_TYPE, :auto)
     end
 
+    ##
+    # Removes values from filter hashes, replacing them with '?'
+    #
+    # @param filter_hash [Hash] the filter hash for the mongo transaction
+    # @param depth [Integer] the current filter depth
+    #
+    # @return [Hash] the filtered hash
+    def sanitize_filter_hash(filter_hash, depth = 0)
+      filter_hash.each_with_object({}) do |(key, value), output|
+        output[key] = sanitize_filter_value(value, depth)
+      end
+    end
+
+    ##
+    # Transforms a value element into a useful, redacted, version
+    #
+    # @param value [Object] the filter value
+    # @param depth [Integer] the current filter depth
+    #
+    # @return [Array, Hash, String] the sanitized value
+    def sanitize_filter_value(value, depth)
+      depth += 1
+      if depth >= MAX_FILTER_DEPTH
+        '[MAX_FILTER_DEPTH_REACHED]'
+      elsif value.is_a?(Array)
+        value.map { |array_value| sanitize_filter_value(array_value, depth) }
+      elsif value.is_a?(Hash)
+        sanitize_filter_hash(value, depth)
+      else
+        '?'
+      end
+    end
+
     ##
     # Stores the mongo command in the request data by the request_id
     #

spec/integrations/mongo_spec.rb

@@ -0,0 +1,262 @@
+# encoding: utf-8
+require 'spec_helper'
+
+describe 'Bugsnag::MongoBreadcrumbSubscriber', :order => :defined do
+  before do
+    unless defined?(::Mongo)
+      @mocked_mongo = true
+      module ::Mongo
+        module Monitoring
+          COMMAND = 'Command'
+          module Global
+          end
+        end
+      end
+      module Kernel
+        alias_method :old_require, :require
+        def require(path)
+          old_require(path) unless path == 'mongo'
+        end
+      end
+    end
+  end
+
+  it "should subscribe to the mongo monitoring service" do
+    expect(::Mongo::Monitoring::Global).to receive(:subscribe) do |command, subscriber|
+      expect(command).to eq(::Mongo::Monitoring::COMMAND)
+      expect(subscriber).to be_an_instance_of(::Bugsnag::MongoBreadcrumbSubscriber)
+    end
+    load './lib/bugsnag/integrations/mongo.rb'
+  end
+
+  context "with the module loaded" do
+    before do
+      allow(::Mongo::Monitoring::Global).to receive(:subscribe)
+      require './lib/bugsnag/integrations/mongo'
+    end
+
+    let(:subscriber) { Bugsnag::MongoBreadcrumbSubscriber.new }
+
+    describe "#started" do
+      it "calls #leave_command with the event" do
+        event = double
+        expect(subscriber).to receive(:leave_command).with(event)
+        subscriber.started(event)
+      end
+    end
+
+    describe "#succeeded" do
+      it "calls #leave_mongo_breadcrumb with the event_name and event" do
+        event = double
+        expect(subscriber).to receive(:leave_mongo_breadcrumb).with("succeeded", event)
+        subscriber.succeeded(event)
+      end
+    end
+
+    describe "#failed" do
+      it "calls #leave_mongo_breadcrumb with the event_name and event" do
+        event = double
+        expect(subscriber).to receive(:leave_mongo_breadcrumb).with("failed", event)
+        subscriber.failed(event)
+      end
+    end
+
+    describe "#leave_mongo_breadcrumb" do
+      let(:event) { double(
+        :command_name => "command",
+        :database_name => "database",
+        :operation_id => "1234567890",
+        :request_id => "123456",
+        :duration => "123.456"
+      ) }
+      let(:event_name) { "event_name" }
+      it "leaves a breadcrumb with relevant meta_data, message, type, and automatic notation" do
+        expect(Bugsnag).to receive(:leave_breadcrumb).with(
+          "Mongo query #{event_name}",
+          {
+            :event_name => "mongo.#{event_name}",
+            :command_name => "command",
+            :database_name => "database",
+            :operation_id => "1234567890",
+            :request_id => "123456",
+            :duration => "123.456"
+          },
+          "process",
+          :auto
+        )
+        subscriber.send(:leave_mongo_breadcrumb, event_name, event)
+      end
+
+      it "adds message data if present" do
+        allow(event).to receive(:message).and_return("This is a message")
+        expect(Bugsnag).to receive(:leave_breadcrumb).with(
+          "Mongo query #{event_name}",
+          {
+            :event_name => "mongo.#{event_name}",
+            :command_name => "command",
+            :database_name => "database",
+            :operation_id => "1234567890",
+            :request_id => "123456",
+            :duration => "123.456",
+            :message => "This is a message"
+          },
+          "process",
+          :auto
+        )
+        subscriber.send(:leave_mongo_breadcrumb, event_name, event)
+      end
+
+      context "command data is present" do
+        let(:command) {
+          {
+            "command" => "collection_name_command",
+            "collection" => "collection_name_getMore",
+            "filter" => nil
+          }
+        }
+
+        it "adds the collection name" do
+          expect(subscriber).to receive(:pop_command).with("123456").and_return(command)
+          expect(Bugsnag).to receive(:leave_breadcrumb).with(
+            "Mongo query #{event_name}",
+            {
+              :event_name => "mongo.#{event_name}",
+              :command_name => "command",
+              :database_name => "database",
+              :operation_id => "1234567890",
+              :request_id => "123456",
+              :duration => "123.456",
+              :collection => "collection_name_command"
+            },
+            "process",
+            :auto
+          )
+          subscriber.send(:leave_mongo_breadcrumb, event_name, event)
+        end
+
+        it "adds the correct collection name for 'getMore' commands" do
+          allow(event).to receive(:command_name).and_return("getMore")
+          expect(subscriber).to receive(:pop_command).with("123456").and_return(command)
+          expect(Bugsnag).to receive(:leave_breadcrumb).with(
+            "Mongo query #{event_name}",
+            {
+              :event_name => "mongo.#{event_name}",
+              :command_name => "getMore",
+              :database_name => "database",
+              :operation_id => "1234567890",
+              :request_id => "123456",
+              :duration => "123.456",
+              :collection => "collection_name_getMore"
+            },
+            "process",
+            :auto
+          )
+          subscriber.send(:leave_mongo_breadcrumb, event_name, event)
+        end
+
+        it "adds a JSON string of filter data" do
+          command["filter"] = {"a" => 1, "b" => 2, "$or" => [{"c" => 3}, {"d" => 4}]}
+          expect(subscriber).to receive(:pop_command).with("123456").and_return(command)
+          expect(Bugsnag).to receive(:leave_breadcrumb).with(
+            "Mongo query #{event_name}",
+            {
+              :event_name => "mongo.#{event_name}",
+              :command_name => "command",
+              :database_name => "database",
+              :operation_id => "1234567890",
+              :request_id => "123456",
+              :duration => "123.456",
+              :collection => "collection_name_command",
+              :filter => '{"a":"?","b":"?","$or":[{"c":"?"},{"d":"?"}]}'
+            },
+            "process",
+            :auto
+          )
+          subscriber.send(:leave_mongo_breadcrumb, event_name, event)
+        end
+      end
+    end
+
+    describe "#sanitize_filter_hash" do
+      it "calls into #sanitize_filter_value with the value from each {k,v} pair" do
+        expect(subscriber.send(:sanitize_filter_hash, {:a => 1, :b => 2})).to eq({:a => '?', :b => '?'})
+      end
+    end
+
+    describe "#sanitize_filter_value" do
+      it "returns '?' for strings, numbers, booleans, and nil" do
+        expect(subscriber.send(:sanitize_filter_value, 523, 0)).to eq('?')
+        expect(subscriber.send(:sanitize_filter_value, "string", 0)).to eq('?')
+        expect(subscriber.send(:sanitize_filter_value, true, 0)).to eq('?')
+        expect(subscriber.send(:sanitize_filter_value, nil, 0)).to eq('?')
+      end
+
+      it "is recursive and iterative for array values" do
+        expect(subscriber.send(:sanitize_filter_value, [1, [2, [3]]], 0)).to eq(['?', ['?', ['?']]])
+      end
+
+      it "calls #sanitize_filter_hash for hash values" do
+        expect(subscriber).to receive(:sanitize_filter_hash).with({:a => 1}, 1)
+        subscriber.send(:sanitize_filter_value, {:a => 1}, 0)
+      end
+
+      it "returns [MAX_FILTER_DEPTH_REACHED] if the filter depth is exceeded" do
+        expect(subscriber.send(:sanitize_filter_value, 1, 4)).to eq('[MAX_FILTER_DEPTH_REACHED]')
+      end
+    end
+
+    describe "#leave_command" do
+      it "extracts and stores the command by request_id" do
+        request_id = "123456"
+        command = "this is a command string"
+        event = double(:command => command, :request_id => request_id)
+
+        subscriber.send(:leave_command, event)
+        command_hash = Bugsnag.configuration.request_data[Bugsnag::MongoBreadcrumbSubscriber::MONGO_COMMAND_KEY]
+        expect(command_hash[request_id]).to eq(command)
+      end
+    end
+
+    describe "#pop_command" do
+      let(:request_id) { "123456" }
+      let(:command) { "this is a command string" }
+      before do
+        event = double(:command => command, :request_id => request_id)
+        subscriber.send(:leave_command, event)
+      end
+
+      it "returns the command given a request_id" do
+        expect(subscriber.send(:pop_command, request_id)).to eq(command)
+      end
+
+      it "removes the command from the request_data" do
+        subscriber.send(:pop_command, request_id)
+        command_hash = Bugsnag.configuration.request_data[Bugsnag::MongoBreadcrumbSubscriber::MONGO_COMMAND_KEY]
+        expect(command_hash).not_to have_key(request_id)
+      end
+
+      it "returns nil if the request_id is not found" do
+        expect(subscriber.send(:pop_command, "09876")).to be_nil
+      end
+    end
+
+    describe "#event_commands" do
+      it "returns a hash" do
+        expect(subscriber.send(:event_commands)).to be_a(Hash)
+      end
+
+      it "is stored in request data" do
+        subscriber.send(:event_commands)[:key] = "value"
+        command_hash = Bugsnag.configuration.request_data[Bugsnag::MongoBreadcrumbSubscriber::MONGO_COMMAND_KEY]
+        expect(command_hash[:key]).to eq("value")
+      end
+    end
+  end
+
+  after do
+    Object.send(:remove_const, :Mongo) if @mocked_mongo
+    module Kernel
+      alias_method :require, :old_require
+    end
+  end
+end