How to Log

The Log documentation is a bit terse, and I can figure out how to best use it.

Here’s what I want to do: I have a small Kemal app, and I’d like to have a log per user. I figure I can create a Log::Backend that stuffs the entries in a database table attaching user_id to make it easy to make a “latest log entries” page per user. And I’d like something for a Kemal handler to grab onto to say “this happened to this user”.

But sources, contexts and data? I can have one logger, and just and the current user_id to the data of each message, but the user is determined at the start of the request, so it would be neater if there was just a user log that handlers could use without having to worry about the user.

Can I just have a user logger and then set the user_id as context at the start of the request? Or is there a better approach?

1 Like

Yes, context attached to a log will be included with all other future logs on that fiber.

Most likely my fault. Is there anything specific you would have liked to see?

Maybe a guide in the docs would be a good addition. Similar to how database guide complements the db api doc.

5 Likes

@bcardiff

There’s a lot of information on how to do things, but not as much to the “why”. Why use sources (the only reason I found was being able to set the level for each differently, and identification), when do context make sense over data (possibly mentioning the relationship with fibers, for those of us that’s still not quite fluent in fibers)? It states

A recommended pattern is to declare a Log constant in the namespace of your shard or module as follows:

But why? I can guess, but when haven’t grogged how things work, a bit more explanation helps.

Which is more guide material, I guess.

Maybe it’s because my use-case isn’t the obvious one that I was left more confused than enlightened (which is usually the case with Crystal documentation).

2 Likes
  • Different log levels
  • Different backends also is a flexibility you will get

Something not immediate is that by using just Log.info and other methods and allowing the constant lookup do its work you can even tweak by monkey patching at class level by declaring a new constant.

But even more important IMO is that you can copy-paste code around on different context and not deal with changing log to Log. Ultimately the top level Log is available.

In some cases you might prefer to pass a Log instance. It’s fine, but I prefer the constant always for the above reasons. But is very opinionated.

  • Different backends also is a flexibility you will get

I suspected that, but the docs doesn’t talk much about the backends.

Something not immediate is that…

Oooh, but of course. These kinds of elegant hacks are exactly something that can be missed when you’re coming from languages where everything has to be explicit and defined. That should be mentioned.

In some cases you might prefer to pass a Log instance.

Yeah, in the case I mentioned above, I’ll want a UserLog contstant as I don’t want to propagate upwards. But I’ll certainly use it for more regular logging at some point.

OK, I’m getting an error:

In /usr/share/crystal/src/log/metadata.cr:206:27

 206 | def initialize(hash : NamedTuple | Hash)
                             ^---------
Error: can't use NamedTuple(T) in unions yet, use a more specific type

On what I basically copied from the docs:

N2y::User::Log.debug &.emit("Fetched accounts", accounts: accounts)

Am I holding it wrong?

What’s the type of accounts?

The following works as expected:

require "log"

Log.setup_from_env

Log.info &.emit("Lorem ipsum", a: 1)
# 2023-07-03T00:51:11.443420Z   INFO - Lorem ipsum -- a: 1

Also @Xen, I don’t know the full context but from what I gather from this topic I would attempt to not pass a logger of the user. I would setup the user info the log context and use a custom backend to store user logs as needed. The benefit is that you could customize which namespaces and severities log this way.

I put a small example at Sample Kemal app with per user logging · GitHub to describe what I mean.

Ah, array of stuffs, that’s the problem. I want to be able to pass along some data that’ll get saved as JSON (for debugging). I should just .to_json before passing it to the log.

I put a small example

Brilliant, this is exactly what I’ve been hacking together. Nice to know I’m not barking up the wrong tree.

Either that or convert the JSON value to a Log::Metadata::Value which are very similar but there is no direct conversion due to separate concerns mostly. But if you are in a specific app it might be fine to assume that all your json values can be converted to log metadata values.

Yeah, the idea is just to save the JSON in the database with the log entry. In most cases it’s going to be the JSON from an external service that didn’t answer like I thought it would, so it makes sense just to have a JSON column in the log table.

Thanks for the help.