Skip to content

Commit 229e427

Browse files
Merge pull request #2126 from CliMA/gb/fix_docs
Fix typo in debugging docs
2 parents a0a223e + ad5d557 commit 229e427

File tree

2 files changed

+131
-13
lines changed

2 files changed

+131
-13
lines changed

docs/src/debugging.md

Lines changed: 88 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -14,36 +14,111 @@ this data after any operation that ClimaCore performs.
1414

1515
## Example
1616

17-
```@example
17+
### Print `NaNs` when they are found
18+
19+
In this example, we add a callback that simply prints `NaNs found` every
20+
instance when they are detected in a `ClimaCore` operation.
21+
22+
To do this, we need two ingredients:
23+
24+
First, we need to enable the callback system:
25+
```@example clima_debug
1826
import ClimaCore
19-
using ClimaCore: DataLayouts
2027
ClimaCore.DebugOnly.call_post_op_callback() = true
28+
```
29+
30+
The line `ClimaCore.DebugOnly.call_post_op_callback() = true` means that at the
31+
end of every `ClimaCore` operation, the function
32+
`ClimaCore.DebugOnly.post_op_callback` is called. By default, this function does
33+
nothing. So, the second ingredient is to define a method:
34+
```@example clima_debug
2135
function ClimaCore.DebugOnly.post_op_callback(result, args...; kwargs...)
22-
if any(isnan, parent(data))
23-
println("NaNs found!")
24-
end
36+
if any(isnan, parent(result))
37+
println("NaNs found!")
38+
end
2539
end
26-
27-
FT = Float64;
28-
data = DataLayouts.VIJFH{FT}(Array{FT}, zeros; Nv=5, Nij=2, Nh=2)
29-
@. data = NaN
3040
```
41+
If needed, `post_op_callback` can be specialized or behave differently in
42+
different cases, but here, it only checks if `NaN`s are in the given that.
3143

3244
Note that, due to dispatch, `post_op_callback` will likely need a very general
3345
method signature, and using `post_op_callback
3446
(result::DataLayouts.VIJFH, args...; kwargs...)` above fails (on the CPU),
3547
because `post_op_callback` ends up getting called multiple times with different
3648
datalayouts.
3749

50+
Now, let us put everything together and demonstrate a complete example:
51+
52+
```@example clima_debug
53+
import ClimaCore
54+
ClimaCore.DebugOnly.call_post_op_callback() = true
55+
function ClimaCore.DebugOnly.post_op_callback(result, args...; kwargs...)
56+
if any(isnan, parent(result))
57+
println("NaNs found!")
58+
end
59+
end
60+
61+
FT = Float64
62+
data = ClimaCore.DataLayouts.VIJFH{FT}(Array{FT}, zeros; Nv=5, Nij=2, Nh=2)
63+
@. data = NaN
64+
ClimaCore.DebugOnly.call_post_op_callback() = false # hide
65+
```
66+
This example should print `NaN` on your standard output.
67+
68+
### Infiltrating
69+
70+
[Infiltrator.jl](https://github.com/JuliaDebug/Infiltrator.jl) is a simple
71+
debugging tool for Julia packages.
72+
73+
Here is an example, where we can use Infiltrator.jl to find where NaNs is coming
74+
from interactively.
75+
76+
```julia
77+
import ClimaCore
78+
import Infiltrator # must be in your default environment
79+
ClimaCore.DebugOnly.call_post_op_callback() = true
80+
function ClimaCore.DebugOnly.post_op_callback(result, args...; kwargs...)
81+
if any(isnan, parent(result))
82+
println("NaNs found!")
83+
# Let's define the stack trace so that we know where this came from
84+
st = stacktrace()
85+
86+
# Let's use Infiltrator.jl to exfiltrate to drop into the REPL.
87+
# Now, `Infiltrator.safehouse` will be a NamedTuple
88+
# containing `result`, `args` and `kwargs`.
89+
Infiltrator.@exfiltrate
90+
end
91+
end
92+
93+
FT = Float64
94+
data = ClimaCore.DataLayouts.VIJFH{FT}(Array{FT}, zeros; Nv=5, Nij=2, Nh=2)
95+
@. data = NaN
96+
# Let's see what happened
97+
(;result, args, kwargs, st) = Infiltrator.safehouse;
98+
99+
# You can print the stack trace, to see where the NaNs were found:
100+
ClimaCore.DebugOnly.print_depth_limited_stack_trace(st;maxtypedepth=1)
101+
102+
# Once there, you can see that the call lead you to `copyto!`,
103+
# Inspecting `args` shows that the `Broadcasted` object used to populate the
104+
# result was:
105+
julia> args[2]
106+
Base.Broadcast.Broadcasted{Base.Broadcast.DefaultArrayStyle{0}}(identity, (NaN,))
107+
108+
# And there's your problem, NaNs is on the right-hand-side of that assignment.
109+
```
110+
111+
### Caveats
112+
38113
!!! warn
39114

40-
While this debugging tool may be helpful, it's not bullet proof. NaNs can
115+
While `post_op_callback` may be helpful, it's not bullet proof. NaNs can
41116
infiltrate user data any time internals are used. For example `parent
42117
(data) .= NaN` will not be caught by ClimaCore.DebugOnly, and errors can be
43118
observed later than expected.
44119

45120
!!! note
46121

47-
This method is called in many places, so this is a performance-critical code
48-
path and expensive operations performed in `post_op_callback` may
49-
significantly slow down your code.
122+
`post_op_callback` is called in many places, so this is a
123+
performance-critical code path and expensive operations performed in
124+
`post_op_callback` may significantly slow down your code.

src/DebugOnly/DebugOnly.jl

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,4 +46,47 @@ function example_debug_post_op_callback(result, args...; kwargs...)
4646
end
4747
end
4848

49+
"""
50+
depth_limited_stack_trace([io::IO, ]st::Base.StackTraces.StackTrace; maxtypedepth=3)
51+
52+
Given a stacktrace `st`, return a vector of strings containing the trace with
53+
depth-limited printing.
54+
"""
55+
depth_limited_stack_trace(st::Base.StackTraces.StackTrace; maxtypedepth = 3) =
56+
depth_limited_stack_trace(stdout, st; maxtypedepth)
57+
58+
function depth_limited_stack_trace(
59+
io::IO,
60+
st::Base.StackTraces.StackTrace;
61+
maxtypedepth = 3,
62+
)
63+
return map(s -> type_depth_limit(io, string(s); maxtypedepth), st)
64+
end
65+
66+
function type_depth_limit(io::IO, s::String; maxtypedepth::Union{Nothing, Int})
67+
sz = get(io, :displaysize, displaysize(io))::Tuple{Int, Int}
68+
return Base.type_depth_limit(s, max(sz[2], 120); maxdepth = maxtypedepth)
69+
end
70+
71+
"""
72+
depth_limited_stack_trace([io::IO, ]st::Base.StackTraces.StackTrace; maxtypedepth=3)
73+
74+
Given a stacktrace `st`, return a vector of strings containing the trace with
75+
depth-limited printing.
76+
"""
77+
print_depth_limited_stack_trace(
78+
st::Base.StackTraces.StackTrace;
79+
maxtypedepth = 3,
80+
) = print_depth_limited_stack_trace(stdout, st; maxtypedepth)
81+
82+
function print_depth_limited_stack_trace(
83+
io::IO,
84+
st::Base.StackTraces.StackTrace;
85+
maxtypedepth = 3,
86+
)
87+
for t in depth_limited_stack_trace(st; maxtypedepth)
88+
println(io, t)
89+
end
90+
end
91+
4992
end

0 commit comments

Comments
 (0)