@debug the next REPL line before evaling it #2179

musoke · 2023-07-11T22:00:23Z

Add a @debug expression within DocTests.eval_repl to show which line is about to be evaluated.
This was requested in #2013

I have found it useful while attempting to track down a similar issue.

musoke · 2023-07-11T22:05:34Z

Apologies to user @ debug for accidentally tagging you on this.

mortenpi · 2023-07-12T02:43:51Z

Do you have an example of what the output looks from this?

musoke · 2023-07-12T03:13:41Z

I do. Here is output I got while debugging the doc builds of musoke/WolframExpr.jl@30e0a5b.

In this case one can get some hints from looking at the debug log of the previous line of the REPL, but it is not clear if the hang happened during verification of the previous output or creation of the next. It's also not helpful if the error is on the first line.

     Testing Running tests...
┌ Debug: Doctesting in temporary directory: /tmp/jl_4fcV7O
│   modules =
│    1-element Vector{Module}:
│     WolframExpr
└ @ Documenter ~/.julia/packages/Documenter/oxl3Q/src/doctest.jl:73
┌ Debug: Document: remotes
│   remote = nothing
│   remotes = nothing
└ @ Documenter ~/.julia/packages/Documenter/oxl3Q/src/documents.jl:380
[ Info: SetupBuildDirectory: setting up build directory.
[ Info: Doctest: running doctests.
┌ Debug: Running doctests.
└ @ Documenter.DocTests ~/.julia/packages/Documenter/oxl3Q/src/DocTests.jl:47
┌ Debug: Evaluating REPL line
│   input = "using WolframExpr"
│   output = ""
└ @ Documenter.DocTests ~/.julia/packages/Documenter/oxl3Q/src/DocTests.jl:244
┌ Debug: Verifying doctest at ~/.julia/dev/WolframExpr/src/WolframExpr.jl:20-30
│
│ ```jldoctest
│ julia> using WolframExpr
│
│ julia> f = string_to_function("x+y", [:x, :y]);
│
│ julia> f(1, 2)
│ 3
│
│ julia> f(1.2, 2)
│ 3.2
│ ```
│
│ Subexpression:
│
│ using WolframExpr
│
│ Evaluated output:
│
│
│
│ Expected output:
│
│
└ @ Documenter.DocTests ~/.julia/packages/Documenter/oxl3Q/src/DocTests.jl:351
┌ Debug: Evaluating REPL line
│   input = "f = string_to_function(\"x+y\", [:x, :y]);"
│   output = ""
└ @ Documenter.DocTests ~/.julia/packages/Documenter/oxl3Q/src/DocTests.jl:244

mortenpi

Not sure if it become too noisy or not, but if you think more detail would be useful, then the at-debug could also go into the inner for?

mortenpi · 2023-07-12T03:47:39Z

src/DocTests.jl

@@ -241,6 +241,7 @@ end

 function eval_repl(block, sandbox, meta::Dict, doc::Documenter.Document, page)
    for (input, output) in repl_splitter(block.code)
+        @debug "Evaluating REPL line" input output


Suggested change

@debug "Evaluating REPL line" input output

@debug "Evaluating doctest REPL line" input expected_output = output

I updated to include this suggestion and the file & line numbers of the doctest. The output for the same test as above now looks like

Testing Running tests... ┌ Debug: Doctesting in temporary directory: /tmp/jl_58qp0Y │ modules = │ 1-element Vector{Module}: │ WolframExpr └ @ Documenter ~/.julia/dev/Documenter/src/doctest.jl:73 ┌ Debug: Document: remotes │ remote = nothing │ remotes = nothing └ @ Documenter ~/.julia/dev/Documenter/src/documents.jl:380 [ Info: SetupBuildDirectory: setting up build directory. [ Info: Doctest: running doctests. ┌ Debug: Running doctests. └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:47 ┌ Debug: Evaluating doctest REPL line from ~/.julia/dev/WolframExpr/src/WolframExpr.jl:20-30 │ input = "using WolframExpr" │ expected_output = "" └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:246 ┌ Debug: Verifying doctest at ~/.julia/dev/WolframExpr/src/WolframExpr.jl:20-30 │ │ ```jldoctest │ julia> using WolframExpr │ │ julia> f = string_to_function("x+y", [:x, :y]); │ │ julia> f(1, 2) │ 3 │ │ julia> f(1.2, 2) │ 3.2 │ ``` │ │ Subexpression: │ │ using WolframExpr │ │ Evaluated output: │ │ │ │ Expected output: │ │ └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:354 ┌ Debug: Evaluating doctest REPL line from ~/.julia/dev/WolframExpr/src/WolframExpr.jl:20-30 │ input = "f = string_to_function(\"x+y\", [:x, :y]);" │ expected_output = "" └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:246

Add a `@debug` expression within DocTests.eval_repl to show which line is about to be evaluated. This was requested in JuliaDocs#2013

musoke · 2023-07-12T13:18:25Z

src/DocTests.jl

@@ -242,6 +242,8 @@ end
 function eval_repl(block, sandbox, meta::Dict, doc::Documenter.Document, page)
    for (input, output) in repl_splitter(block.code)
        result = Result(block, input, output, meta[:CurrentFile])
+        src_lines = Documenter.find_block_in_file(result.block.code, result.file)


Ideally, this would be more like

src_lines = Documenter.find_block_in_file(input, result.file)

to narrow down the exact line, but find_block_in_file finds the first match in the file, so lines that appear in more than one doctest are wrong. E.g. initial using statements.

As written, there may still be slight confusion if the same line appears twice in one doctest or major confusion if one doctest appears as a subset of another.

result.block should be the same as block, so maybe we can move this outside of the for loop? In other words, it's looking for the line range of the whole jldoctest code block anyway, right?

musoke · 2023-07-12T14:26:02Z

Not sure if it become too noisy or not, but if you think more detail would be useful, then the at-debug could also go into the inner for?

I had this in an earlier version but didn't include it the initial PR. It is no noisier when each REPL line contains only one expression. (This also means that I didn't need it for what I was testing, so wasn't sure how useful it is.)

I have pushed a version that does this. The exs in the inner loop can't be matched to expected output, so I don't output them. They can be seen in the output of debug_report if it gets far enough to matter.

Here's updated output:

     Testing Running tests...
     ┌ Debug: Doctesting in temporary directory: /tmp/jl_Syps7H
     │   modules =
     │    1-element Vector{Module}:
     │     WolframExpr
     └ @ Documenter ~/.julia/dev/Documenter/src/doctest.jl:73
     ┌ Debug: Document: remotes
     │   remote = nothing
     │   remotes = nothing
     └ @ Documenter ~/.julia/dev/Documenter/src/documents.jl:380
     [ Info: SetupBuildDirectory: setting up build directory.
     [ Info: Doctest: running doctests.
     ┌ Debug: Running doctests.
     └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:47
     ┌ Debug: Evaluating doctest REPL line from ~/.julia/dev/WolframExpr/src/WolframExpr.jl:20-30
     │   unparsed_string = "using WolframExpr\n"
     │   parsed_expression = :(using WolframExpr)
     └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:248
     ┌ Debug: Verifying doctest at ~/.julia/dev/WolframExpr/src/WolframExpr.jl:20-30
     │
     │ ```jldoctest
     │ julia> using WolframExpr
     │
     │ julia> f = string_to_function("x+y", [:x, :y]);
     │
     │ julia> f(1, 2)
     │ 3
     │
     │ julia> f(1.2, 2)
     │ 3.2
     │ ```
     │
     │ Subexpression:
     │
     │ using WolframExpr
     │
     │ Evaluated output:
     │
     │
     │
     │ Expected output:
     │
     │
     └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:353
     ┌ Debug: Evaluating doctest REPL line from ~/.julia/dev/WolframExpr/src/WolframExpr.jl:20-30
     │   unparsed_string = "f = string_to_function(\"x+y\", [:x, :y]);\n"
     │   parsed_expression = :($(Expr(:toplevel, :(f = string_to_function("x+y", [:x, :y])))))
     └ @ Documenter.DocTests ~/.julia/dev/Documenter/src/DocTests.jl:248

src/DocTests.jl

mortenpi · 2023-07-12T23:04:52Z

I had this in an earlier version but didn't include it the initial PR. It is no noisier when each REPL line contains only one expression. (This also means that I didn't need it for what I was testing, so wasn't sure how useful it is.)

Let's keep it though. Being closer to what Documenter does internally is probably good when debugging. And we can always change this later if it turns out to be a problem 🙂

Co-authored-by: Morten Piibeleht <[email protected]>

musoke · 2023-07-13T16:19:46Z

Thanks! I have made the suggested changes

mortenpi

LGTM, thanks!

musoke · 2023-07-13T23:22:46Z

Thanks Morten! Now I'll get back to debugging the issue that started this.

musoke force-pushed the debug-hang branch from ec8d2a8 to e1e5783 Compare July 11, 2023 22:03

mortenpi reviewed Jul 12, 2023

View reviewed changes

@debug the next REPL line before evaling it

fc38d33

Add a `@debug` expression within DocTests.eval_repl to show which line is about to be evaluated. This was requested in JuliaDocs#2013

musoke force-pushed the debug-hang branch from e1e5783 to fc38d33 Compare July 12, 2023 13:10

musoke commented Jul 12, 2023

View reviewed changes

@debug REPL lines inside inner loop

da22aab

mortenpi reviewed Jul 12, 2023

View reviewed changes

src/DocTests.jl Outdated Show resolved Hide resolved

musoke and others added 2 commits July 13, 2023 11:36

clarify when line came from

76f454d

Co-authored-by: Morten Piibeleht <[email protected]>

move definition of scr_lines outside loop

8326ae2

mortenpi enabled auto-merge (squash) July 13, 2023 23:10

mortenpi approved these changes Jul 13, 2023

View reviewed changes

mortenpi merged commit b9f8c61 into JuliaDocs:master Jul 13, 2023

musoke deleted the debug-hang branch July 13, 2023 23:22

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

@debug the next REPL line before evaling it #2179

@debug the next REPL line before evaling it #2179

musoke commented Jul 11, 2023 •

edited

Loading

musoke commented Jul 11, 2023

mortenpi commented Jul 12, 2023 •

edited

Loading

musoke commented Jul 12, 2023

mortenpi left a comment

mortenpi Jul 12, 2023

musoke Jul 12, 2023

musoke Jul 12, 2023 •

edited

Loading

mortenpi Jul 12, 2023

musoke commented Jul 12, 2023

mortenpi commented Jul 12, 2023

musoke commented Jul 13, 2023

mortenpi left a comment

musoke commented Jul 13, 2023

	@debug "Evaluating REPL line" input output
	@debug "Evaluating doctest REPL line" input expected_output = output

@debug the next REPL line before evaling it #2179

@debug the next REPL line before evaling it #2179

Conversation

musoke commented Jul 11, 2023 • edited Loading

musoke commented Jul 11, 2023

mortenpi commented Jul 12, 2023 • edited Loading

musoke commented Jul 12, 2023

mortenpi left a comment

Choose a reason for hiding this comment

mortenpi Jul 12, 2023

Choose a reason for hiding this comment

musoke Jul 12, 2023

Choose a reason for hiding this comment

musoke Jul 12, 2023 • edited Loading

Choose a reason for hiding this comment

mortenpi Jul 12, 2023

Choose a reason for hiding this comment

musoke commented Jul 12, 2023

mortenpi commented Jul 12, 2023

musoke commented Jul 13, 2023

mortenpi left a comment

Choose a reason for hiding this comment

musoke commented Jul 13, 2023

musoke commented Jul 11, 2023 •

edited

Loading

mortenpi commented Jul 12, 2023 •

edited

Loading

musoke Jul 12, 2023 •

edited

Loading