Allow logging the behaviour of middleware

CHANGELOG

@@ -1,5 +1,7 @@
 28-04-2021
 
+  - FEATURE: Permit tracing middleware behaviour via `MessageBus#on_middleware_attributes`.
+
 - Version 3.3.5
 
   - PERF: Optimised CORS preflight handling

README.md

@@ -611,6 +611,20 @@ MessageBus.extra_response_headers_lookup do |env|
 end
 ```
 
+### Performance monitoring
+
+MessageBus has hooks into its middleware for your application to perform monitoring of its performance.
+
+Firstly, the result of several decisions and the values used to arrive at them, such as whether to use long-polling or chunked encoding, can be provided to a logging routine of your definition:
+
+```ruby
+MessageBus.on_middleware_attributes do |attributes|
+  Rails.logger.debug(attributes)
+end
+```
+
+See `MessageBus.on_middleware_attributes` for the values that are provided.
+
 ## How it works
 
 MessageBus provides durable messaging following the publish-subscribe (pubsub) pattern to subscribers who track their own subscriptions. Durability is by virtue of the persistence of messages in backlogs stored in the selected backend implementation (Redis, Postgres, etc) which can be queried up until a configurable expiry. Subscribers must keep track of the ID of the last message they processed, and request only more-recent messages in subsequent connections.

lib/message_bus.rb

@@ -599,6 +599,18 @@ def client_message_filters
     @config[:client_message_filters]
   end
 
+  # @yield [env] a routine to handle middleware decisions for tracing purposes
+  # @yieldparam [Hash<Symbol => Object>] attributes attributes detailing how message_bus handled the request
+  # @return [void]
+  #
+  # The provided attributes are: `:messagebus_seq`, `:messagebus_query_string`, `:messagebus_client_count`,
+  # `:messagebus_long_polling`, `:messagebus_http_version`, `:messagebus_dont_chunk`, `:messagebus_allow_chunked`,
+  # `:messagebus_backlog_size`, `:messagebus_subscription_count`.
+  def on_middleware_attributes(&blk)
+    configure(on_middleware_attributes: blk) if blk
+    @config[:on_middleware_attributes]
+  end
+
   private
 
   ENCODE_SITE_TOKEN = "$|$"

lib/message_bus/rack/middleware.rb

@@ -139,6 +139,20 @@ def handle_request(env)
 
     backlog = client.backlog
 
+    if @bus.on_middleware_attributes
+      @bus.on_middleware_attributes.call(
+        messagebus_seq: client.seq,
+        messagebus_query_string: env['QUERY_STRING'],
+        messagebus_client_count: @connection_manager.client_count,
+        messagebus_long_polling: long_polling,
+        messagebus_http_version: env['HTTP_VERSION'],
+        messagebus_dont_chunk: env['HTTP_DONT_CHUNK'],
+        messagebus_allow_chunked: allow_chunked,
+        messagebus_backlog_size: backlog.size,
+        messagebus_subscription_count: client.subscriptions.count
+      )
+    end
+
     if backlog.length > 0 && !allow_chunked
       client.close
       @bus.logger.debug "Delivering backlog #{backlog} to client #{client_id} for user #{user_id}"

spec/lib/message_bus/rack/middleware_spec.rb

@@ -478,5 +478,34 @@ def call(env)
         parsed.first['data'].must_equal 'testfoo'
       end
     end
+
+    describe "on_middleware_attributes handling" do
+      it "passes attributes of the request handling to the configured proc" do
+        @bus.chunked_encoding_enabled = true
+        @async_middleware.allow_chunked
+
+        attributes = nil
+        @bus.on_middleware_attributes do |attrs|
+          attributes = attrs
+        end
+
+        post("/message-bus/1234?dlp=t",
+             JSON.generate('/foo' => 1, __seq: 3),
+             "CONTENT_TYPE" => "application/json",
+             "HTTP_DONT_CHUNK" => "foo")
+
+        attributes.must_equal({
+          messagebus_seq: 3,
+          messagebus_query_string: "dlp=t",
+          messagebus_client_count: 0,
+          messagebus_long_polling: false,
+          messagebus_http_version: nil,
+          messagebus_dont_chunk: "foo",
+          messagebus_allow_chunked: false,
+          messagebus_backlog_size: 1,
+          messagebus_subscription_count: 1,
+        })
+      end
+    end
   end
 end