Format.kprintf usage



I am struggling to understand some code that uses the function Format.kfprintf, I understand how Format.fprintf works:

utop # Format.fprintf Format.std_formatter "@[%s: [%d]@]@." "test" 1;;
test: [1]
- : unit = ()

but I can not find how to use Format.kfprintf, I think that like Printf.ksprintf, it is used when you want to create function that can handle different formats ( but I am stuck.

Can someone provide me a simple example?


Format.kprinft -> Format.kfprintf


kprintf is deprecated, you should use ksprintf instead. These functions takes a callback which is called with the format string fully expanded. For instance:

# Format.ksprintf (fun str -> print_endline ("X: " ^ str)) "hello %d" 10;;
X: hello 10
- : unit = ()


@samoht, sorry I writted the wrong function, I struggle with Format.kfprintf.


kfprintf is like fprintf but you can continue to print stuff using the callback. For instance:

# Format.kfprintf (fun ppf -> Format.fprintf ppf "after") Format.std_formatter "@[%s: [%d]@]@." "test" 1;;
test: [1]
after- : unit = ()

It’s usually used to reset the formatter instead of printing more things on it.


kfprintf is useful for implementing custom “printf”-like functions,
e.g. this simple logging system (inspired from Daniel Bünzli’s work):

# let log_enabled = ref true;;
val log_enabled : bool ref = {contents = true}

(* now the log function itself. It uses a continuation passing trick
   to do the least amount of work possible when logging is disabled *)

# let log k =
    if !log_enabled then (
        (fun fmt ->
          Format.printf "(@[<2>debug@ :time %.2f@ " (Sys.time());
          Format.kfprintf (fun out -> Format.fprintf out "@])@.")
            Format.std_formatter fmt)
val log :
  ((('a, Format.formatter, unit, unit) format4 -> 'a) ->
   unit) ->
  unit = <fun>

(* now we can use the log function *)
# log (fun k->k "hello %d" 42);;
(debug :time 1.40 hello 42)
- : unit = ()

(* disabled, nothing happen *)
# log_enabled := false;;
- : unit = ()
# log (fun k->k "hello %d" 42);;
- : unit = ()

Sadly the types are a bit complicated to follow, but notice how kfprintf
is used to call custom code (the final “@])@.” to close parenthesis,
print a new line, and flush) after the user’s message.


@c-cube, it was the code from Logs that I was reading and it seems that it uses a peculiar form of format in this part (

let format_reporter
    ?(pp_header = pp_exec_header)
    ?(app = Format.std_formatter)
    ?(dst = Format.err_formatter) ()
  let report src level ~over k msgf =
    let k _ = over (); k () in
    msgf @@ fun ?header ?tags fmt ->
    let ppf = if level = App then app else dst in
    Format.kfprintf k ppf ("%a@[" ^^ fmt ^^ "@]@.") pp_header (level, header)
  { report }

Now I understand Format.kprintf but what blocks me is this part: ("%a@[" ^^ fmt ^^ "@]@."). In Logs the default ouput is app_name: [level] message but with the code above, the part pp_header (level, header) that prints the header is at the last position of the argument and fmt is in fact something like (fun m -> m "mylog").


To give credit where it is due, the closure trick was actually suggested by @yallop and profiled by @drup to validate its performance before it got into logs.

EDIT: here’s the initial discussion


Ah, interesting. I remember seeing this trick on something mirage related first, and then you released Logs…


The fmt is the one you specify in fun m -> m fmt so it’s well ordered: the "%a@[" is used by pp_header (level, header) and following arguments (if any and specified in the fun m -> m fmt function) will follow.


@dbuenzli, just to be sure, in the initial discussion the acronym CPS is for continuation passing style ?


Don’t see that being mentioned anywhere, but I’d say it’s likely.



Ah this discussion. Yes CPS stands for continuation passing style.


I read the original thread but still don’t understand how the fastest CPS implementation compares with heavyweight approach when we remove logging in compile-time?


Indeed that measurement doesn’t seem to have been made.

The reason might be that you rarely want to this in practice: you can be sure you will end-up regretting removing logging at some point when you get into trouble.

The actual incurred overhead (basically closure creation) on non-logging would still be interesting to know though.


Actually, I did measure that, which I mention in . If you use flambda and that the “debug” flag is statically known, when using the CPS technnique flambda can completely remove the printing statement. So it’s equivalent to the heavy-weight version which uses a syntax extension, for example.

Also, I added a benchmark testing the CPS technique to the flambda bench suite, so you can check that it is still valid. I don’t remember the URL, but I’m sure one of the flambda people (cc @chambart @mshinwell) will jump in and give it to us. :slight_smile:


Ah ok so that format_pp_cont: 14.16 0 is the actual non-logging CPS overhead in what you benchmarked (i.e. a few cycles an no allocs).