diff --git a/docs/_html/index.html b/docs/_html/index.html index fec48de..7cb827c 100644 --- a/docs/_html/index.html +++ b/docs/_html/index.html @@ -11,7 +11,7 @@
Ppx_minidebug
val is_local_debug_runtime : toplevel_opt_arg -> bool
type context = {
log_value : log_value;
track_or_explicit : [ `Diagn | `Debug | `Track ];
output_type_info : bool;
interrupts : bool;
comptime_log_level : int;
entry_log_level : int;
toplevel_opt_arg : toplevel_opt_arg;
}
val init_context : context Stdlib.ref
val parse_log_level :
+Ppx_minidebug (ppx_minidebug.Ppx_minidebug) Module Ppx_minidebug
val is_local_debug_runtime : toplevel_opt_arg -> bool
type context = {
log_value : log_value;
track_or_explicit : [ `Diagn | `Debug | `Track ];
output_type_info : bool;
interrupts : bool;
comptime_log_level : int;
entry_log_level : int;
toplevel_opt_arg : toplevel_opt_arg;
}
val init_context : context Stdlib.ref
type rule = {
ext_point : string;
track_or_explicit : [ `Diagn | `Debug | `Track ];
toplevel_opt_arg : toplevel_opt_arg;
expander : [ `Debug | `Debug_this | `Str ];
log_value : log_value;
entry_log_level : int option;
}
val entry_rules : (string, rule) Stdlib.Hashtbl.t
val traverse_expression : context Ppxlib.Ast_traverse.map_with_context
val debug_this_expander : context -> Ppxlib.expression -> Ppxlib.expression
val debug_expander :
- context ->
- Ppxlib__.Import.Ast.expression ->
- Ppxlib__.Import.Ast.expression
type rule = {
ext_point : string;
track_or_explicit : [ `Diagn | `Debug | `Track ];
toplevel_opt_arg : toplevel_opt_arg;
expander : [ `Debug | `Str ];
log_value : log_value;
entry_log_level : int option;
}
val entry_rules : (string, rule) Stdlib.Hashtbl.t
val traverse_expression : context Ppxlib.Ast_traverse.map_with_context
val debug_expander : context -> Ppxlib.expression -> Ppxlib.expression
val str_expander :
context ->
loc:Ppxlib.location ->
Ppxlib.structure_item list ->
diff --git a/docs/_html/ppx_minidebug/index.html b/docs/_html/ppx_minidebug/index.html
index 522a3d6..19e043b 100644
--- a/docs/_html/ppx_minidebug/index.html
+++ b/docs/_html/ppx_minidebug/index.html
@@ -48,7 +48,7 @@
let () = Debug_runtime.(html_config := `Html default_html_config)
let () = Debug_runtime.boxify_sexp_from_size := 50
Here we also convert the logged sexp
values (with at least 50 atoms) to trees. Example result:
Highlighting search terms
The PrintBox
runtime also supports highlighting paths to logs that match a highlight_terms
regular expression. For example:
To limit the highlight noise, some log entries can be excluded from propagating the highlight status using the exclude_on_path
setting. To trim excessive logging while still providing some context, you can set prune_upto
to a level greater than 0, which only outputs highlighted boxes below that level.
PrintBox
creating helpers with defaults: debug
and debug_file
The configuration for the above example is more concisely just:
module Debug_runtime = (val Minidebug_runtime.debug_file ~highlight_terms:(Re.str "169") "debug")
Similarly, debug
returns a PrintBox
module, which by default logs to stdout
:
module Debug_runtime = (val Minidebug_runtime.debug ())
Hyperlinks to source locations
The HTML and Markdown outputs support emitting file locations as hyperlinks. For example:
module Debug_runtime = (val Minidebug_runtime.debug_file ~hyperlink:"" "debug")
where ~hyperlink
is the prefix to let you tune the file path and select a browsing option. For illustration, the prefixes for Markdown / HTML outputs I might use at the time of writing:
~hyperlink:"./"
or ~hyperlink:"../"
depending on the relative locations of the log file and the binary~hyperlink:"vscode://file//wsl.localhost/Ubuntu/home/lukstafi/ppx_minidebug/"
- if left-clicking a link from within VS Code Live Preview follows the file in the HTML preview window rather than an editor window, middle-click the link
~hyperlink:"https://github.com/lukstafi/ppx_minidebug/tree/main/"
Recommended: values_first_mode
This setting puts the result of the computation as the header of a computation subtree, rather than the source code location of the computation. I recommend using this setting as it reduces noise and makes the important information easier to find and visible with less unfolding. Another important benefit is that it makes hyperlinks usable, by pushing them from the summary line to under the fold. I decided to not make it the default setting, because it is not available in the Flushing
runtime, and can be confusing.
For example:
module Debug_runtime =
(val Minidebug_runtime.debug ~highlight_terms:(Re.str "3") ~values_first_mode:true ())
-let%debug_this_show rec loop_highlight (x : int) : int =
+let%debug_show rec loop_highlight (x : int) : int =
let z : int = (x - 1) / 2 in
if x <= 0 then 0 else z + loop_highlight (z + (x / 2))
let () = print_endline @@ Int.to_string @@ loop_highlight 7
Truncated results:
BEGIN DEBUG SESSION
@@ -71,7 +71,7 @@
└─┬──────────────────┐
│loop_highlight = 4│
├──────────────────┘
- ├─"test/test_expect_test.ml":1042:41-1044:58
When logging uses sexps and boxification, and the result is decomposed into a subtree, only the header of the result subtree is put in the header line, and the rest of the result subtree is just underneath it with a <returns>
or a <values>
header. Example showcasing the printbox-html
backend:
Example showcasing the printbox-md
(Markdown) backend:
Usage
Tracing only happens in explicitly marked lexical scopes. The entry extension points vary along four axes:
%debug_
vs. %track_
vs. %diagn_
- The prefix
%debug_
means logging fewer things: only let-bound values and functions are logged, and functions only when either: directly in a %debug_
-annotated let binding, or their return type is annotated. %track_
also logs: which if
, match
, function
branch is taken, for
and while
loops, and all functions, including anonymous ones.- The prefix
%diagn_
means only generating logs for explicitly logged values, i.e. introduced by [%log_entry]
, [%log ...]
, [%log_result ...]
and [%log_printbox ...]
statements.
Optional infix _this_
puts only the body of a let
definition in scope for logging.
let%debug_this_show v: t = compute value in outer scope
will trace v
and the type-annotated bindings and functions inside compute value
, but it will not trace outer scope
.
Optional infixes _rt_
and _rtb_
add a first-class module argument to a function, and unpack it as module Debug_runtime
for the scope of the function.
_rt_
uses the module type Minidebug_runtime.Debug_runtime
._rtb_
uses the module type Minidebug_runtime.PrintBox_runtime
.- This functionality is "one use only": it applies only to the function the extension point is attached to.
Representation and printing mechanism: _pp
, _show
, recommended: _sexp
_pp
is currently most restrictive as it requires the type of a value to be an identifier. The identifier is converted to a pp_
printing function, e.g. pp_int
._show
converts values to strings via the %show
extension provided by deriving.show
: e.g. [%show: int list]
._sexp
converts values to sexp expressions first using %sexp_of
, e.g. [%sexp_of: int list]
. The runtime can decide how to print the sexp expressions. The PrintBox
backend allows to convert the sexps to box structures first, with the boxify_sexp_from_size
setting. This means large values can be unfolded gradually for inspection.
Plus, there are non-entry extension points %log
, %log_printbox
and %log_result
for logging values. They are not registered, which as a side effect should somewhat mitigate conflicts with other ppx extensions for logging. There's also an un-registered extension point %log_entry
for opening a log subtree.
See examples in the test directory, and especially the inline tests.
Only type-annotated let-bindings, function arguments, function results can be implicitly logged. However, the bindings and function arguments can be nested patterns with only parts of them type-annotated! The explicit loggers %log
and %log_result
take a value and reconstruct its type from partial type annotations (deconstructing the expression), sometimes assuming unknown types are strings. The %log_printbox
logger takes a PrintBox.t
value. The %log_entry
logger takes a string value for the header of the log subtree.
To properly trace in concurrent settings, ensure that different threads use different log channels. For example, you can bind Debug_runtime
locally: let module Debug_runtime = Minidebug_runtime.debug_file thread_name in ...
ppx_minidebug
can be installed using opam
. ppx_minidebug.runtime
depends on printbox
, ptime
, mtime
, sexplib0
.
Breaking infinite recursion with max_nesting_depth
and looping with max_num_children
; Flushing
-based traces
The PrintBox
backend only produces any output when a top-level log entry gets closed. This makes it harder to debug infinite loops and especially infinite recursion. The setting max_nesting_depth
terminates a computation when the given log nesting is exceeded. For example:
module Debug_runtime = (val Minidebug_runtime.debug ())
+ ├─"test/test_expect_test.ml":1042:41-1044:58
When logging uses sexps and boxification, and the result is decomposed into a subtree, only the header of the result subtree is put in the header line, and the rest of the result subtree is just underneath it with a <returns>
or a <values>
header. Example showcasing the printbox-html
backend:
Example showcasing the printbox-md
(Markdown) backend:
Usage
Tracing only happens in explicitly marked lexical scopes. For extension points applied directly to bindings (let-definitions) only the let
definition in scope for logging, the body of the definition(s) is considered outside the extension point. (But if the extension is over an expression with a nested let-binding, the body of the definition is in the scope of the extension.)
The entry extension points vary along three axes:
%debug_
vs. %track_
vs. %diagn_
- The prefix
%debug_
means logging fewer things: only let-bound values and functions are logged, and functions only when either: directly in a %debug_
-annotated let binding, or their return type is annotated. %track_
also logs: which if
, match
, function
branch is taken, for
and while
loops, and all functions, including anonymous ones.- The prefix
%diagn_
means only generating logs for explicitly logged values, i.e. introduced by [%log_entry]
, [%log ...]
, [%log_result ...]
and [%log_printbox ...]
statements.
Optional infixes _rt_
and _l_
:
_rt_
adds a first-class module argument to a function, and unpacks it as module Debug_runtime
for the scope of the function._l_
calls _get_local_debug_runtime
, and unpacks it for the scope of the function: let module Debug_runtime = (val _get_local_debug_runtime ()) in ...
.- This functionality is "one use only": it applies only to the function the extension point is attached to.
Representation and printing mechanism: _pp
, _show
, recommended: _sexp
_pp
is currently most restrictive as it requires the type of a value to be an identifier. The identifier is converted to a pp_
printing function, e.g. pp_int
._show
converts values to strings via the %show
extension provided by deriving.show
: e.g. [%show: int list]
._sexp
converts values to sexp expressions first using %sexp_of
, e.g. [%sexp_of: int list]
. The runtime can decide how to print the sexp expressions. The PrintBox
backend allows to convert the sexps to box structures first, with the boxify_sexp_from_size
setting. This means large values can be unfolded gradually for inspection.
Plus, there are non-entry extension points %log
, %log_printbox
and %log_result
for logging values. They are not registered, which as a side effect should somewhat mitigate conflicts with other ppx extensions for logging. There's also an un-registered extension point %log_entry
for opening a log subtree.
See examples in the test directory, and especially the inline tests.
Only type-annotated let-bindings, function arguments, function results can be implicitly logged. However, the bindings and function arguments can be nested patterns with only parts of them type-annotated! The explicit loggers %log
and %log_result
take a value and reconstruct its type from partial type annotations (deconstructing the expression), sometimes assuming unknown types are strings. The %log_printbox
logger takes a PrintBox.t
value. The %log_entry
logger takes a string value for the header of the log subtree.
To properly trace in concurrent settings, ensure that different threads use different log channels. For example, you can bind Debug_runtime
locally: let module Debug_runtime = Minidebug_runtime.debug_file thread_name in ...
ppx_minidebug
can be installed using opam
. ppx_minidebug.runtime
depends on printbox
, ptime
, mtime
, sexplib0
.
Breaking infinite recursion with max_nesting_depth
and looping with max_num_children
; Flushing
-based traces
The PrintBox
backend only produces any output when a top-level log entry gets closed. This makes it harder to debug infinite loops and especially infinite recursion. The setting max_nesting_depth
terminates a computation when the given log nesting is exceeded. For example:
module Debug_runtime = (val Minidebug_runtime.debug ())
let%debug_show rec loop_exceeded (x : int) : int =
[%debug_interrupts
@@ -169,7 +169,7 @@
│ └─"test/test_expect_test.ml":421:14: result
│ └─result = 3
└─track_branches = 3
-3
and
let%track_this_show anonymous (x : int) =
+3
and
let%track_show anonymous (x : int) =
Array.fold_left ( + ) 0 @@ Array.init (x + 1) (fun (i : int) -> i)
in
print_endline @@ Int.to_string @@ anonymous 3
gives:
BEGIN DEBUG SESSION
@@ -250,7 +250,7 @@
baz
├─"test/test_expect_test.ml":2979:10-2982:28
└─("for baz, f squared", 64)
- 109 |}]
At runtime, the level can be set via Minidebug_runtime.debug ~log_level
or Minidebug_runtime.debug_file ~log_level
at runtime creation, or via Debug_runtime.log_level := ...
later on, also for the flushing backend. Check out the test suite test_expect_test.ml:"%log runtime log levels while-loop" for examples:
let%track_rtb_sexp result () : int =
+ 109 |}]
At runtime, the level can be set via Minidebug_runtime.debug ~log_level
or Minidebug_runtime.debug_file ~log_level
at runtime creation, or via Debug_runtime.log_level := ...
later on, also for the flushing backend. Check out the test suite test_expect_test.ml:"%log runtime log levels while-loop" for examples:
let%track_rt_sexp result () : int =
let i = ref 0 in
let j = ref 0 in
while !i < 6 do
@@ -267,8 +267,8 @@
print_endline
@@ Int.to_string
(result
- (Minidebug_runtime.debug ~values_first_mode:true ~log_level:2
- ~global_prefix:"Warning" ())
+ Minidebug_runtime.(
+ forget_printbox @@ debug ~values_first_mode:true ~log_level:2 ~global_prefix:"Warning" ())
());
...
At compile time, the level can be set for a scope with %log_level
, or globally with %global_debug_log_level
. (%log_level
is not registered to minimize incompatibility with other logging frameworks.) For example:
[%%global_log_level 2]
@@ -301,7 +301,7 @@
[%log1 "for bar, b-3", (b - 3 : int)];
(b - 3) * y
in
- let%debug2_this_show baz { first : int; second : int } : int =
+ let%debug2_show baz { first : int; second : int } : int =
let { first : int; second : int } = { first = first + 1; second = second + 3 } in
[%log "for baz, f squared", (first * first : int)];
(first * first) + second
@@ -481,7 +481,7 @@
("This is like", 3, "or", 3.14, "above")
└─{orphaned from #1}
("tau =", 6.28)
- └─{orphaned from #1} |}]
~verbose_entry_ids:true
tags all logs with entry ids, it shouldn't be needed in regular use.
Reducing the size of generated logs
Summary of possibilities:
- log levels
no_debug_if
prune_upto
truncate_children
split_files_after
- HTML browsers can handle really large files (less luck with Markdown).
The log levels discussed in the previous section certainly reduce the amount generated, but they either help too little (Nonempty_entries
) or they remove logs too indiscriminately (Prefixed
) for use in a debugging context. Dynamically controlling the runtime log level is one option, but there are some other options.
In the PrintBox backend, you can disable the logging of specified subtrees, when the output is irrelevant, would be a distraction, or the logs take up too much space. The test suite example:
let%debug_this_show rec fixpoint_changes (x: int): int =
+ └─{orphaned from #1} |}]
~verbose_entry_ids:true
tags all logs with entry ids, it shouldn't be needed in regular use.
Reducing the size of generated logs
Summary of possibilities:
- log levels
no_debug_if
prune_upto
truncate_children
split_files_after
- HTML browsers can handle really large files (less luck with Markdown).
The log levels discussed in the previous section certainly reduce the amount generated, but they either help too little (Nonempty_entries
) or they remove logs too indiscriminately (Prefixed
) for use in a debugging context. Dynamically controlling the runtime log level is one option, but there are some other options.
In the PrintBox backend, you can disable the logging of specified subtrees, when the output is irrelevant, would be a distraction, or the logs take up too much space. The test suite example:
let%debug_show rec fixpoint_changes (x: int): int =
let z: int = (x - 1) / 2 in
(* The call [x = 2] is not printed because it is a descendant of
the no-debug call [x = 4]. *)
@@ -504,7 +504,7 @@
└─fixpoint_changes = 9
9
The no_debug_if
mechanism requires modifying the logged sources, and since it's limited to cutting out subtrees of the logs, it can be tricky to select and preserve the context one wants. The highlighting mechanism with the prune_upto
setting avoids these problems. You provide a search term without modifying the debugged sources. You can tune the pruning level to keep the context around the place the search term was found.
Setting the option truncate_children
will only log the given number of children at each node, prioritizing the most recent ones. An example from the test suite:
let module Debug_runtime = (val Minidebug_runtime.debug ~truncate_children:10 ()) in
let () =
- let%track_this_show _bar : unit =
+ let%track_show _bar : unit =
for i = 0 to 30 do
let _baz : int = i * 2 in
()
@@ -571,11 +571,11 @@
g : int = 12
├─"test/test_expect_test.ml":1447:49-1447:72
└─b : int = 6
- 12 |}]
You can also use at the module level: [%%global_debug_type_info true]
, prior to the code of interest.
Explicit logging with %log
(and %log_result
) has different but related restrictions compared to logging of let or argument bindings. We reconstruct the type of the expression from partial type information, where in addition to type annotations we take into account: string, int and float literals, tuple, array, list, and lazy
expresssions. We do not analyze applications, nor constructors other than "nil" []
and "cons" ::
for lists. When a type is unknown, for the whole expression and for a tuple element we assume the type string
. We don't assume string for direct subexpressions of arrays, lists, and lazy
.
Dealing with concurrent execution
For programs with threads or domains running concurrently, you need to ensure that each thread uses its own instance of a debug runtime, writing to its own log file. Currently, ppx_minidebug
doesn't do any checks to prevent abuse: using the same debug runtime instance from multiple threads or opening the same file by multiple debug runtime instances.
We offer three helpers for dealing with multiple debug runtimes. There is an optional runtime instance-level setting global_prefix
, which adds the given information to all log headers coming from the instance.
There are extension points %debug_lb_sexp
, %debug_this_lb_sexp
, %track_lb_sexp
, etc. They call a function _get_local_printbox_debug_runtime ()
, or _get_local_debug_runtime ()
for the _l_
variants, and unpack the argument as module Debug_runtime
(in a function body). The feature helps using a runtime instance dedicated to a thread or domain, since for example _get_local_debug_runtime
can retrieve the runtime using Domain.DLS
. To avoid surprises, this feature only takes effect for directly annotated functions, and unpacks a Debug_runtime
inside the function body (regardless of whether there is a _this_
), so that we get the appropriate runtime for the dynamic local scope.
Example from the test suite:
let i = ref 0 in
+ 12 |}]
You can also use at the module level: [%%global_debug_type_info true]
, prior to the code of interest.
Explicit logging with %log
(and %log_result
) has different but related restrictions compared to logging of let or argument bindings. We reconstruct the type of the expression from partial type information, where in addition to type annotations we take into account: string, int and float literals, tuple, array, list, and lazy
expresssions. We do not analyze applications, nor constructors other than "nil" []
and "cons" ::
for lists. When a type is unknown, for the whole expression and for a tuple element we assume the type string
. We don't assume string for direct subexpressions of arrays, lists, and lazy
.
Dealing with concurrent execution
For programs with threads or domains running concurrently, you need to ensure that each thread uses its own instance of a debug runtime, writing to its own log file. Currently, ppx_minidebug
doesn't do any checks to prevent abuse: using the same debug runtime instance from multiple threads or opening the same file by multiple debug runtime instances.
We offer three helpers for dealing with multiple debug runtimes. There is an optional runtime instance-level setting global_prefix
, which adds the given information to all log headers coming from the instance.
There are extension points %debug_l_sexp
, %track_l_sexp
, etc. They call a function _get_local_debug_runtime ()
and unpack the argument as module Debug_runtime
(in a function body). The feature helps using a runtime instance dedicated to a thread or domain, since for example _get_local_debug_runtime
can retrieve the runtime using Domain.DLS
. To avoid surprises, this feature only takes effect for directly annotated functions, and unpacks a Debug_runtime
inside the function body, so that we get the appropriate runtime for the dynamic local scope.
NOTE: it's important to annotate functions that might be called from threads (spawned domains) using the _l_
variants of extension points, e.g. %debug_l_sexp
(not %debug_sexp
!). For clearest output, should configure _get_local_debug_runtime ()
to return the same runtime as the Debug_runtime
module that is in a file-wide scope, when called from the main thread / main domain.
Example from the test suite:
let i = ref 0 in
let _get_local_debug_runtime () =
Minidebug_runtime.debug_flushing ~global_prefix:("foo-" ^ string_of_int !i) ()
in
-let%track_this_l_show foo () =
+let%track_l_show foo () =
let () = () in
()
in
@@ -604,7 +604,7 @@
BEGIN DEBUG SESSION foo-5
foo-5 foo begin "test/test_expect_test.ml":3783:28:
foo-5 foo end
- |}]
Another similar feature is the extension points %debug_rtb_sexp
, %debug_this_rtb_sexp
, %track_rtb_sexp
, etc. They add a first-class module argument to a function, and unpack the argument as module Debug_runtime
. At present, passing of the runtime instance to functions needs to be done manually. Note that only the function attached to the _rt_
or _rtb_
extension point is modified, regardless of whether there is a _this_
.
Example from the test suite:
let%track_rtb_show foo l : int =
+ |}]
Another similar feature is the extension points %debug_rt_sexp
, %track_rt_sexp
, etc. They add a first-class module argument to a function, and unpack the argument as module Debug_runtime
. At present, passing of the runtime instance to functions needs to be done manually. Note that only the function attached to the _rt_
extension point is modified.
Example from the test suite:
let%track_rt_show foo l : int =
match (l : int list) with [] -> 7 | y :: _ -> y * 2
in
let () =
@@ -613,7 +613,7 @@
(Minidebug_runtime.debug ~global_prefix:"foo-1" ~values_first_mode:true ())
[ 7 ]
in
-let%track_rtb_show baz : int list -> int = function
+let%track_rt_show baz : int list -> int = function
| [] -> 7
| [ y ] -> y * 2
| [ y; z ] -> y + z
@@ -622,13 +622,13 @@
let () =
print_endline @@ Int.to_string
@@ baz
- (Minidebug_runtime.debug ~global_prefix:"baz-1" ~values_first_mode:true ())
+ Minidebug_runtime.(forget_printbox @@ debug ~global_prefix:"baz-1" ~values_first_mode:true ())
[ 4 ]
in
let () =
print_endline @@ Int.to_string
@@ baz
- (Minidebug_runtime.debug ~global_prefix:"baz-2" ~values_first_mode:true ())
+ Minidebug_runtime.(forget_printbox @@ debug ~global_prefix:"baz-2" ~values_first_mode:true ())
[ 4; 5; 6 ]
in
[%expect