lucasmazza · August 31, 2017 02:25 · May 29, 2013 · Feb 23, 2013 · Feb 23, 2013 · Feb 23, 2013
diff --git a/tagged_logging_with_session.rb b/tagged_logging_with_session.rb
@@ -26,7 +26,7 @@ def compute_devise_tags(env)
         key = serializer.key_for(scope)
 
         if session_data = serializer.session[key]
-          ["current #{scope}", session_data[1]].join(": ")
+          ["current #{scope}", session_data[1]].flatten.join(": ")
         end
       end.compact
     end

diff --git a/tagged_logging_with_query.rb b/tagged_logging_with_query.rb
@@ -13,7 +13,11 @@ def call(env)
     end
 
     private
-
+
+    # `warden.user` returns an instance of your objects, so
+    # hits the database (but this shouldn't be a issue with AR query cache).
+    # It might be useful if you need to log any information about
+    # your users that isn't stored in the session
     def compute_devise_tags(env)
       warden = env['warden']
       Devise.mappings.keys.map do |scope|

diff --git a/tagged_logging_with_session.rb b/tagged_logging_with_session.rb
@@ -13,7 +13,12 @@ def call(env)
     end
 
     private
-
+    # This implementation uses a `internal` object from Warden API
+    # that just read the session data and return an Array with
+    # the record class, id and authenticable salt. This data
+    # is produced by the `serialize_into_session` method,
+    # See https://github.com/plataformatec/devise/blob/master/lib/devise/models/authenticatable.rb#L187-L189
+    # for more information.
     def compute_devise_tags(env)
       serializer = Warden::SessionSerializer.new(env)
 

diff --git a/README.md b/README.md
@@ -1,6 +1,31 @@
 # Devise / Warden Tagged logging
 
+I wrote a middleware (actually two, but they do the same with different implementations) that logs information about signed in scopes in a Rails + Devise application. The solution works with multiple logins (like having a person logged both as an `Admin` and a `User`). I tested against Rails 4 and Devise `HEAD`, but it should work fine in any Rails 3 application.
+
+This solution doesn't use the `log_tags` configuration option since it isn't very helpful when you need to retrieve information stored in cookies/session. That information isn't 'ready' when the `Rails::Rack::Logger` is executed, since it happens way down in the middleware chain.
+
+Add one of the following implementations to your application load path and use the following configuration to add the middleware to your application stack:
+
 ```ruby
-# Add this to your application config.
+# application.rb
 config.app_middleware.insert_after("Warden::Manager", "Devise::TaggedLogging")
-```
+```
+
+You logs will end up looking like this:
+
+```
+Started GET "/projects/1/users/1/02-2013" for 127.0.0.1 at 2013-02-23 13:42:56 -0300
+  User Load (1.2ms)  SELECT "users".* FROM "users" WHERE "users"."id" = 1 ORDER BY "users"."id" ASC LIMIT 1
+[current user: 1] Processing by ReportsController#show as HTML
+[current user: 1]   Parameters: {"project_id"=>"1", "user_id"=>"1", "month"=>"02-2013"}
+[current user: 1]   Project Load (1.1ms)  SELECT "projects".* FROM "projects" WHERE "projects"."id" = $1 LIMIT 1  [["id", "1"]]
+[current user: 1]   User Load (0.7ms)  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1  [["id", "1"]]
+[current user: 1]   Rendered reports/show.html.erb within layouts/application (189.8ms)
+[current user: 1]   User Load (1.1ms)  SELECT "users".* FROM "users" ORDER BY "users"."name" ASC
+[current user: 1]   Project Load (0.5ms)  SELECT "projects".* FROM "projects" ORDER BY "projects"."name" ASC
+[current user: 1]   Rendered layouts/shared/_header.html.erb (15.4ms)
+[current user: 1] Completed 200 OK in 1811ms (Views: 306.9ms | ActiveRecord: 5.9ms)
+```
+
+Beware that the first line doesn't have any related information since it's logged by `Rails::Rack::Logger`, where you don't have the session data yet.
+
diff --git a/tagged_logging_with_query.rb b/tagged_logging_with_query.rb
@@ -17,7 +17,7 @@ def call(env)
     def compute_devise_tags(env)
       warden = env['warden']
       Devise.mappings.keys.map do |scope|
-        if record = warden.user(:scope => scope)
+        if record = warden.user(scope: scope)
           ["current #{scope}", record.to_key].join(": ")
         end
       end.compact

diff --git a/README.md b/README.md
@@ -0,0 +1,6 @@
+# Devise / Warden Tagged logging
+
+```ruby
+# Add this to your application config.
+config.app_middleware.insert_after("Warden::Manager", "Devise::TaggedLogging")
+```
diff --git a/tagged_logging_with_query.rb b/tagged_logging_with_query.rb
@@ -0,0 +1,30 @@
+module Devise
+  class TaggedLogging
+    def initialize(app)
+      @app = app
+    end
+
+    def call(env)
+      if logger.respond_to?(:tagged)
+        logger.tagged(compute_devise_tags(env)) { @app.call(env) }
+      else
+        @app.call(env)
+      end
+    end
+
+    private
+
+    def compute_devise_tags(env)
+      warden = env['warden']
+      Devise.mappings.keys.map do |scope|
+        if record = warden.user(:scope => scope)
+          ["current #{scope}", record.to_key].join(": ")
+        end
+      end.compact
+    end
+
+    def logger
+      Rails.logger
+    end
+  end
+end
diff --git a/tagged_logging_with_session.rb b/tagged_logging_with_session.rb
@@ -0,0 +1,33 @@
+module Devise
+  class TaggedLogging
+    def initialize(app)
+      @app = app
+    end
+
+    def call(env)
+      if logger.respond_to?(:tagged)
+        logger.tagged(compute_devise_tags(env)) { @app.call(env) }
+      else
+        @app.call(env)
+      end
+    end
+
+    private
+
+    def compute_devise_tags(env)
+      serializer = Warden::SessionSerializer.new(env)
+
+      Devise.mappings.keys.map do |scope|
+        key = serializer.key_for(scope)
+
+        if session_data = serializer.session[key]
+          ["current #{scope}", session_data[1]].join(": ")
+        end
+      end.compact
+    end
+
+    def logger
+      Rails.logger
+    end
+  end
+end