dbuenzli / logs

Logging infrastructure for OCaml
http://erratique.ch/software/logs
ISC License
87 stars 19 forks source link

Logs enforces Format #53

Open craff opened 1 week ago

craff commented 1 week ago

Logs seems to enforce the use of Format, while the polymorphic "format" types could allow to use Printf or a user defined function, for instance when you want to avoid mixing messages with concurrent system. The are two problems with Format:

Could give a functorial interface that would allow both Printf and Format ?

dbuenzli commented 1 week ago

I think there are enough hooks in the library to make it thread-safe (see e.g. Logs_threaded).

Regarding being slower than printf I suspect you won't see the difference in most use cases. If that is the case then I guess you can simply redefine a bunch of function that sprintf and then log a single string.

So so far I think that:

Could give a functorial interface that would allow both Printf and Format ?

Is likely not worth the complexity.

craff commented 1 week ago

My main problem is that I have my own Log facility with an interface

Log.(f log_type_and level (fun k -> k "Format string" format args")

And I use Format only because it is imposed by Logs which is itself imposed by caqti. I do no want to add any contention for logging (Each domain log to a different file, this is much simpler). Still, I got a thread safety problem (uncaught internal format exception issue on ocaml) when logging to stdout for simple tests.

I now duplicate the stdout formatter in that case and I think I am safe, but I would prefer not to think and use Printf. The problem is that logging is sometime outside the exception handlers to report unhandled exception.

I will probably do my own Db logging and not use at all the log feature proposed by caqti.

For performance, with a medium log level on a website with simple_httpd, logging becomes non neglectable. And I do see a difference of 5% to 10% between Format and Printf. Format in 25-30% slower than Printf with a only a few %s and %d. As exposed by the following code:

let test : (('a, 'b, unit) format -> 'a) -> int -> unit =
  fun f nb ->
    for i = 0 to nb do
      f "coucou: %d %s %f\n%!" i (string_of_int i) (float i)
    done

let t0 = Unix.gettimeofday ()
let _ = test Printf.printf 1_000_000
let t1 = Unix.gettimeofday ()
let _ = test Format.printf 1_000_000
let t2 = Unix.gettimeofday ()

let _ = Printf.eprintf "Printf: %f Format: %f\n%!"  (t1 -. t0) (t2 -. t1)
dbuenzli commented 1 week ago

I find it odd that caqti imposes Logs. But then in this case providing a functor would not help either.

That being said I wouldn't mind adding something to Logs that allows per domain log files.

Otherwise I tried your program on my machine an in terms of absolute numbers I get:

brzo > /dev/null Printf: 0.980098 Format: 1.207523

So that's a 243ms difference on 1 million requests.

Let's say that's 250ms. This means the concrete loss per request for using Format instead of Printf is 250ns per request, I suspect this represents nothing w.r.t. to the latency of your network and/or database access.