logcraft icon indicating copy to clipboard operation
logcraft copied to clipboard

how to best extend access log (not application logs) output with dynamic request data

Open linstantnoodles opened this issue 11 months ago • 1 comments

first thank you for creating this logger! one thing I'm trying to do is to extend the access logging json output to include dynamic data only available in the middle of a request cycle such as userid

config.logcraft.global_context does work for static values, but it doesn't have access to the request object

Logcraft.within_log_context is great for application logs, but that context does not get applied to access logs

by contrast in the default rails logging, log_tags allows you to extend the standard rails access logs and it passes along the request object https://guides.rubyonrails.org/configuring.html#config-log-tags

potential solution using Thread.current

one potential workaround i've considered given that LogCraft actually merges thread locals into its context

i.e the dynamic_log_context

    def format(event)
      log_entry = background_of(event).merge evaluated_global_context,
                                             dynamic_log_context,
                                             message_from(event.data)
      @formatter.call log_entry
    end

is to set the value on Thread.current and configure global_context with

    config.logcraft.global_context = lambda {
      return { user_id: Thread.current["user_id"] }
    }

i think that technically works... but it feels a bit gross, esp. b.c it's unclear whether these values actually get cleaned up (https://stackoverflow.com/questions/7896298/safety-of-thread-current-usage-in-rails).

let me know if i'm missing something obvious. if not, it would be cool to have functionality similar to rails log_tags config where the request object is used (it's still a global, but im assuming it gets destroyed at end of request), i'm also happy to look into making pr for it too. lmk

linstantnoodles avatar Jan 16 '25 16:01 linstantnoodles

Hi @linstantnoodles ,

Thanks for the question. This issue honestly never came up before in any of our projects and that's why there's no specific solution for it in Logcraft. In any case, the solution you suggested would work (I think) but I believe there is a simpler way - which might entail some compromises though.

The first thing Logcraft does when a request's processing is started is open a new thread-local log context (using within_log_context) in the request ID logging middleware, to make sure that there is an open context for the application to put additional context data in. This is followed by the request logger, which produces the access log. This means that the access log can be extended with context information using LogContextHelper.add_to_log_context (see https://github.com/zormandi/logcraft?tab=readme-ov-file#adding-context-information-to-log-messages in the README).

The reason Logcraft.within_log_context doesn't work for your case is that within_log_context actually starts a new context and pushes it on top of the previous one. These contexts are stacked so that when one is finished, you can jump back to the previous one. (In retrospect, it might make sense for these new contexts to contain the previous ones as well, but that's not how it works right now.) So basically, if you use within_log_context then the context you're writing to in your application is already popped off the stack by the time it reaches the access logger.

The reason I said this solution might mean some compromises is that if you choose to use add_to_log_context in your application code (e.g. controllers) then that means any additional data you put into the log context will reach the access log. There is no clear way to separate which context goes to the access log and which to the application log.

Anyway, I hope this helps.

zormandi avatar Jan 19 '25 10:01 zormandi