Instrument fail2ban and allow2ban bans

README.md

@@ -29,6 +29,7 @@ See the [Backing & Hacking blog post](https://www.kickstarter.com/backing-and-ha
     - [`blocklist(name, &block)`](#blocklistname-block)
     - [Fail2Ban](#fail2ban)
     - [Allow2Ban](#allow2ban)
+    - [Knowing when a ban is applied](#knowing-when-a-ban-is-applied)
   - [Throttling](#throttling)
     - [`throttle(name, options, &block)`](#throttlename-options-block)
   - [Tracks](#tracks)
@@ -237,6 +238,42 @@ Rack::Attack.blocklist('allow2ban login scrapers') do |req|
 end
 ```
 
+#### Knowing when a ban is applied
+
+The `blocklist` event fires for *every* request a blocklist rejects, which means
+a client banned for an hour produces an event on each of its blocked requests,
+and none at all on the request that actually tripped the ban. To be notified the
+moment a ban is applied, subscribe to `ban.rack_attack`:
+
+```ruby
+ActiveSupport::Notifications.subscribe('ban.rack_attack') do |name, start, finish, request_id, payload|
+  # payload => {
+  #   name: 'fail2ban',        # or 'allow2ban'
+  #   discriminator: '1.2.3.4',
+  #   count: 3,
+  #   maxretry: 3,
+  #   findtime: 600,
+  #   bantime: 300,
+  #   request: nil
+  # }
+  Rails.logger.warn("Banned #{payload[:discriminator]} for #{payload[:bantime]}s")
+end
+```
+
+The event fires exactly once per ban, and the discriminator identifies who was
+banned. This is especially useful with `Allow2Ban`, where the request that
+crosses `maxretry` is still allowed through, so the ban is otherwise invisible
+until the *next* request arrives.
+
+`payload[:request]` is `nil` unless you pass the request to the filter, which is
+optional:
+
+```ruby
+Rack::Attack::Allow2Ban.filter(req.ip, maxretry: 20, findtime: 1.minute, bantime: 1.hour, request: req) do
+  req.path == '/login' and req.post?
+end
+```
+
 ### Throttling
 
 Throttle state is stored in a [configurable cache](#cache-store-configuration) (which defaults to `Rails.cache` if present).

lib/rack/attack.rb

@@ -46,6 +46,14 @@ def instrument(request)
         end
       end
 
+      # Instruments the moment a Fail2Ban/Allow2Ban ban is written, as opposed
+      # to `instrument` above, which fires on every request a check matches.
+      # Deliberately does not write to `request.env`, so the `blocklist` (or
+      # `track`) event for this same request is emitted exactly as before.
+      def instrument_ban(payload)
+        notifier.instrument("ban.rack_attack", payload) if notifier
+      end
+
       def cache
         @cache ||= Cache.new
       end

lib/rack/attack/allow2ban.rb

@@ -12,11 +12,9 @@ def key_prefix
 
         # everything is the same here except we only return true
         # (blocking the request) if they have tripped the limit.
-        def fail!(discriminator, bantime, findtime, maxretry)
-          count = cache.count("#{key_prefix}:count:#{discriminator}", findtime)
-          if count >= maxretry
-            ban!(discriminator, bantime)
-          end
+        def fail!(discriminator, bantime, findtime, maxretry, request = nil)
+          super
+
           # we may not block them this time, but they're banned for next time
           false
         end

lib/rack/attack/fail2ban.rb

@@ -13,7 +13,9 @@ def filter(discriminator, options)
             # Return true for blocklist
             true
           elsif yield
-            fail!(discriminator, bantime, findtime, maxretry)
+            # `request` is optional and only enriches the `ban.rack_attack`
+            # payload; the event is emitted with or without it.
+            fail!(discriminator, bantime, findtime, maxretry, options[:request])
           end
         end
 
@@ -34,10 +36,20 @@ def key_prefix
           'fail2ban'
         end
 
-        def fail!(discriminator, bantime, findtime, maxretry)
+        def fail!(discriminator, bantime, findtime, maxretry, request = nil)
           count = cache.count("#{key_prefix}:count:#{discriminator}", findtime)
           if count >= maxretry
             ban!(discriminator, bantime)
+
+            Rack::Attack.instrument_ban(
+              name: key_prefix,
+              discriminator: discriminator,
+              count: count,
+              maxretry: maxretry,
+              findtime: findtime,
+              bantime: bantime,
+              request: request
+            )
           end
 
           true

spec/acceptance/allow2ban_spec.rb

@@ -4,6 +4,8 @@
 require "timecop"
 
 describe "allow2ban" do
+  let(:notifications) { [] }
+
   before do
     Rack::Attack.cache.store = ActiveSupport::Cache::MemoryStore.new
 
@@ -70,4 +72,34 @@
       assert_equal 200, last_response.status
     end
   end
+
+  it "notifies when the ban is applied, on the request that is still allowed through" do
+    ActiveSupport::Notifications.subscribe("ban.rack_attack") do |_name, _start, _finish, _id, payload|
+      notifications.push(payload)
+    end
+
+    get "/scarce-resource"
+
+    assert_equal 200, last_response.status
+    assert notifications.empty?, "should not notify before maxretry is reached"
+
+    # Allow2Ban lets this request through, but the ban is written for the next
+    # one -- this is the only point at which a ban can be observed.
+    get "/scarce-resource"
+
+    assert_equal 200, last_response.status
+    assert_equal 1, notifications.size
+
+    notification = notifications.pop
+    assert_equal 'allow2ban', notification[:name]
+    assert_equal '127.0.0.1', notification[:discriminator]
+    assert_equal 2, notification[:count]
+    assert_equal 2, notification[:maxretry]
+
+    # Now banned: blocked, but the ban is not re-applied so nothing fires.
+    get "/"
+
+    assert_equal 403, last_response.status
+    assert notifications.empty?
+  end
 end

spec/acceptance/fail2ban_spec.rb

@@ -117,4 +117,64 @@
     assert_equal 'fail2ban pentesters', notification[:request].env["rack.attack.matched"]
     assert_equal :blocklist, notification[:request].env["rack.attack.match_type"]
   end
+
+  it "notifies once when the ban is applied, not on subsequent banned requests" do
+    ActiveSupport::Notifications.subscribe("ban.rack_attack") do |_name, _start, _finish, _id, payload|
+      notifications.push(payload)
+    end
+
+    get "/private-place"
+
+    assert_equal 403, last_response.status
+    assert notifications.empty?, "should not notify before maxretry is reached"
+
+    # This request reaches maxretry and writes the ban.
+    get "/private-place"
+
+    assert_equal 403, last_response.status
+    assert_equal 1, notifications.size
+
+    notification = notifications.pop
+    assert_equal 'fail2ban', notification[:name]
+    assert_equal '127.0.0.1', notification[:discriminator]
+    assert_equal 2, notification[:count]
+    assert_equal 2, notification[:maxretry]
+    assert_equal 30, notification[:findtime]
+    assert_equal 60, notification[:bantime]
+
+    # Already banned: blocked, but the ban is not re-applied so nothing fires.
+    get "/"
+
+    assert_equal 403, last_response.status
+    assert notifications.empty?
+  end
+
+  it "omits the request from the ban payload when the filter is not given one" do
+    ActiveSupport::Notifications.subscribe("ban.rack_attack") do |_name, _start, _finish, _id, payload|
+      notifications.push(payload)
+    end
+
+    2.times { get "/private-place" }
+
+    assert_equal 1, notifications.size
+    assert_nil notifications.pop[:request]
+  end
+
+  it "includes the request in the ban payload when one is passed to the filter" do
+    Rack::Attack.blocklist("fail2ban with request") do |request|
+      Rack::Attack::Fail2Ban.filter("with-request:#{request.ip}",
+                                    maxretry: 1, findtime: 30, bantime: 60, request: request) do
+        request.path.include?("tarpit")
+      end
+    end
+
+    ActiveSupport::Notifications.subscribe("ban.rack_attack") do |_name, _start, _finish, _id, payload|
+      notifications.push(payload)
+    end
+
+    get "/tarpit"
+
+    assert_equal 1, notifications.size
+    assert_equal "/tarpit", notifications.pop[:request].path
+  end
 end