JuliaLang / julia

The Julia Programming Language
https://julialang.org/
MIT License
45.63k stars 5.48k forks source link

What's needed to include ClearStacktrace.jl in Base? #36026

Closed jkrumbiegel closed 4 years ago

jkrumbiegel commented 4 years ago

The title says it all. I think I figured out a good format to present stack traces, and I think all users could benefit from it. It's currently in ClearStacktrace.jl and depends on Crayons.jl for the colors.

I want to know what I can do to make this PR-ready. I don't know how Julia Base handles REPL colors, which ones I'm allowed to use, how I access them without Crayons etc. I also don't know if there might be system-specific intricacies of stack traces that I have overlooked, testing this only a Windows and a Mac machine.

The basic idea is to have three columns, function, module and signature. Function and module together should basically always fit in a REPL horizontally, while signatures can be very long and are therefore allowed to overflow into new lines, while staying intact when resizing the REPL (compared to more complex but brittle table layouting). The code paths get a new line each, and are also allowed to overflow if they are too long. This keeps clickable links in Atom / VSCode and the like intact.

Just for reference, here is the before and after comparison from the README: Before: grafik After: grafik

cossio commented 4 years ago

This would be really nice to have. Or at least maybe a trimmed down version which improves printing of stacktraces by default in Base.

JeffBezanson commented 4 years ago

I'm all in favor. The main thing I don't get is the colors in the signatures. They seem...random? I guess the different colors are there to make it easier to pick out different elements, but it's a bit weird. How about color == nesting depth? I think the main weirdness is in e.g. Tuple{Symbol,Symbol} where the two Symbols are different colors.

timholy commented 4 years ago

There's another thing I'd really like to see:

julia> foo(x::T, y::T) where T = error("whoops")
foo (generic function with 1 method)

julia> function bar()
           a = rand(3, 5)
           b = view(a, :, 2:3)
           c = reinterpret(Float32, b)
           foo(c, c)
       end
bar (generic function with 1 method)

julia> bar()
ERROR: whoops
Stacktrace:
 [1] error(::String) at ./error.jl:33
 [2] foo(::Base.ReinterpretArray{Float32,2,Float64,SubArray{Float64,2,Array{Float64,2},Tuple{Base.Slice{Base.OneTo{Int64}},UnitRange{Int64}},true}}, ::Base.ReinterpretArray{Float32,2,Float64,SubArray{Float64,2,Array{Float64,2},Tuple{Base.Slice{Base.OneTo{Int64}},UnitRange{Int64}},true}}) at ./REPL[1]:1
 [3] bar() at ./REPL[2]:5
 [4] top-level scope at REPL[3]:1

but since

julia> m = first(methods(foo))
foo(x::T, y::T) where T in Main at REPL[1]:1

julia> m.sig
Tuple{typeof(foo),T,T} where T

it seems that we should be able to print entry 2 as something like

[2] foo(::T, ::T) where T = Base.ReinterpretArray{Float32,2,Float64,SubArray{Float64,2,Array{Float64,2},Tuple{Base.Slice{Base.OneTo{Int64}},UnitRange{Int64}},true}}
KristofferC commented 4 years ago

A small comment, but to me it is currently maybe a bit too much color "salad". The stackframe counter being blue, all the different colors in the signature etc. For Base colors so far, we've only used the 16 system colors (8 + 8 bright ones) and that makes fancy coloring a bit harder.

jkrumbiegel commented 4 years ago

Good suggestions overall. Maybe a couple comments why I made the color choices so far:

The numbers are blue because they are important, so shouldn't be grayed out, but making them white felt to me like they were fighting for attention with the function names.

The modules use the primary colors in a cycle, I think this is very useful because it allows to quickly filter the trace for relevant modules. This is something that is very to do with the current stack trace format. The idea is that people should be forced to read as little as possible to find what they’re looking for. (I mostly did eye movement and attention research in my academic life so far, so those aspects are important to me ;) )

The colors for the signatures are very debatable. The ones on the screenshot above were chosen to be only slightly different from dark gray. At the same time, I wanted the different semantic components to be discriminable. That’s why all types and type parameters (curly braces and commas) cause a color switch. There are three colors which means there won’t be two neighbors with the same color. I found that it’s quite difficult to make out single words in huge type signatures if they are all just white. The slightly different shades help a lot but also make everything a bit more noisy, visually.

As the 16 color set doesn’t have colors that are only marginally different from dark gray, it’s probably not something that can be included in Base. In a recent update, I replaced the colors with three slightly different shades of gray from the ANSI set, but even that will not be supported everywhere I guess.

jkrumbiegel commented 4 years ago

Oh also the stack frame color and the module colors as well as the dark gray and white are all system colors. It’s just my particular VSCode theme that renders them like you see here.

mcabbott commented 4 years ago

This would be great to have.

When scanning argument types, often it's pretty hard to figure out where one stops and the next starts. Colouring the top level differently might be very helpful here, and perhaps even numbering the arguments:

[3]   (_1::DataFrames.var"#fun##309#"{...lighter...}, _2::NamedTuple{...lighter...}, _3::Int64})
JeffBezanson commented 4 years ago

We should be able to show the argument names, like we do in the printing of methods(f).

jkrumbiegel commented 4 years ago

how's this? I've replaced the signature colors with dark gray, but the :: is white so it's salient where argument types begin. especially helpful with the type monster at position 11

grafik
JeffBezanson commented 4 years ago

I like it. Will be even better with argument names.

It's too bad that the order "function - module - arguments" works so well for the layout but doesn't really make sense semantically. I don't have a solution though; clearly it's best for the function to come first. Maybe the module could go on the next line before the file location? It is part of the location after all. Then maybe we wouldn't need the header either.

I think we could also put the numbers in normal text, and the function names in bold and/or white.

timotaularson commented 4 years ago

Could the filename at the end of the codepath (and possibly the line number) get their own lighter color too?

jkrumbiegel commented 4 years ago

Maybe the module could go on the next line before the file location? It is part of the location after all. Then maybe we wouldn't need the header either.

I'll try out a couple things with these suggestions.

Could the filename at the end of the codepath (and possibly the line number) get their own lighter color too?

It technically can of course ;) It's always a tradeoff between better visibility and attention-grabbing noise.

mcabbott commented 4 years ago

Why not write the modules first, since they are part of the function's full name? Perhaps with colour it may be clear enough just to write Core.eval etc, or they could still be aligned as columns. (Or perhaps you tried this and it looked awful.)

timholy commented 4 years ago

Really crazy thought: if printing the argument types would take up more than one line, print the signature in folded form and then use REPL.TerminalMenus to allow viewers to expand it. Something like:

julia> run_command(args...)
    Function    Arguments              Location
[1] f           (x::Int, y::Float64)   MyModule1, /path/to/file1.jl: 15
[2] g          +(...)                  MyModule2, /path/to/file2.jl: 64
...

julia> lasttrace()
# presents the above in menu form, allowing user to expand line 2

Related: #35915 (which I plan to use to create a folded-tree menu, https://github.com/JuliaCollections/FoldingTrees.jl).

timotaularson commented 4 years ago

How does it look with codepath rearranged in this order: LineNumber Filename Path Then your eyes have a stable location to look for the line number and filename with no extra color needed for them (I seem to always be searching for the filename and line number buried in the details, can you tell?) And for interactive REPL work I love the folded idea above :)

jkrumbiegel commented 4 years ago

Why not write the modules first, since they are part of the function's full name

Yeah I kind of like the idea, I think I started out without color and that didn't work so well, but like this it's actually quite readable. I'll try without columns next, although columns are always nice because they guide your eyes.

grafik
JeffBezanson commented 4 years ago

Not sure about that; the function name is a vastly more important piece of information than the module. For me at least, the most important info is definitely the function name, file name, and line number. Also for scripts the left column would be lots of Main or blank, which is not ideal for that use case.

ericphanson commented 4 years ago

I think when I’m reading stacktraces, I’m mostly looking for the last call in my code before it goes to Base/package code, since usually the bug is in my code. So in that case the module is pretty important and the function call isn’t what I’m scanning first.

JeffBezanson commented 4 years ago

How about this:

[1]  get_ticklabels   ::AbstractPlotting.Automatic, ::Int64
     in MakieLayout at ~/.julia/packages/MakieLayout/COfBu/src/lineaxis.jl:372

Module names would still line up so they would be easy to scan.

jkrumbiegel commented 4 years ago

I had actually just tried out something close to that. I colored the function names themselves this time, so they are still the most salient but carry the Module information in their color. So there's still an obvious grouping, but with less focus on all the module names.

grafik
JeffBezanson commented 4 years ago

The first time I saw that I'd probably go nuts trying to figure out what the colors meant :joy: If there are going to be per-module colors, seems better to just apply the color to the module name.

mcabbott commented 4 years ago

I like the module names, they get a bit lost in this latest picture.

If they are at the bottom, perhaps making them the same bright colour would connect things? (And make clear where you cross a module boundary.) And, perhaps, if the module name appears in the path, it could simply be highlighted there instead -- that would also move the colourful name off the left edge where the functions are.

KristofferC commented 4 years ago

For some inspiration, I post a few images from the last time tweaking the stacktrace formatting came up.

bild

bild

antoine-levitt commented 4 years ago

Often the exact package is not so much of interest as the nature of the code: is it core julia, a library I'm using, the library I'm developing, or a script? We could have four colors: core/base/dev/stdlib, packages, packages currently ]deved, and all the rest (including script/REPL). Some of these distinctions are pretty arbitrary and the classification is a bit brittle, but coloring the method based on this would (at least for me) maximize the information without displaying any extra text and keeping a small, easy to memorize set of colors.

jkrumbiegel commented 4 years ago

For me, the colors are more about boundary changes, where code from one module begins and the other ends. That's why I probably wouldn't assign inherent meaning to them. On the other hand, that might be confusing.

I've tried to simplify more, and removed columns again because without the module column they are not so useful anymore. Then first I colored only line number by modules, but this still left the file name not so visible, which many comments said is important. So I colored that in the module color as well. The module name itself is not colored because it's too close to the function name and that's too noisy.

Here is the version with both numbers and filenames colored:

grafik
jkrumbiegel commented 4 years ago

here without filenames colored

grafik
kmsquire commented 4 years ago

Can you also try coloring the full file path?

timotaularson commented 4 years ago

Some ideas... Filename and line number in a consistent location with double spaces to set them off. Stack level color and module color match each other to visually pair the related lines. Filename, line number, and path in slightly different hue than parameter types to distinguish without clutter. stacktrace [Colors in this example are arbitrary, more thinking about how their positions relate. Missing stack levels in example and shortened parameter type list on last item are because I typed example by hand.]

timotaularson commented 4 years ago

Code used to produce the sample above in case anyone wants to play with it:

function main()

    errors = [
              ("1", "get_ticklabels", ("AbstractPlotting.Automatic", "Int64"), "372", "lineaxis.jl", "MakieLayout", "~/.julia/packages/MakieLayout/COfBu/src")
              ("2", "get_ticklabels", ("AbstractPlotting.Automatic", "Int64"), "351", "lineaxis.jl", "MakieLayout", "~/.julia/packages/MakieLayout/COfBu/src")
              ("3", "#105", ("AbstractPlotting.Automatic",), "152", "lineaxis.jl", "MakieLayout", "~/.julia/packages/MakieLayout/COfBu/src")
              ("8", "OnUpdate", ("Tuple{Float32,Float32}",), "218", "Observables.jl", "Observables", "~/.julia/packages/Observables/0wrF6/src")
              ("9", "#setindex!#5", ("Observables.var\"#6#8\"",), "138", "Observables.jl", "Observables", "~/.julia/packages/Observables/0wrF6/src")
              ("10", "setindex!", ("Observables.Observable{Any}",), "126", "Observables.jl", "Observables", "~/.julia/packages/Observables/0wrF6/src")
              ("11", "#LineAxis#95", ("Base.Iterators.Pairs{Symbol,Observables.Observable,NTuple{28,Symbol},NamedTuple{(:endpoints, :limits, :flipped, :ticklabelrotation, :ticklabelalign, :lables
ize, :labelpadding, :ticklabelpad, :labelvisible, :label, :labelfont, :ticklabelfont, :ticklabelcolor}",), "270", "lineaxis.jl", "MakieLayout", "~/.julia/packages/MakieLayout/COfBu/src/lobjects")
    ]

    println()
    for (idx, err) in enumerate(errors)
        # Module color
        mc = idx <= 3 ? :light_red : (idx >= 7 ? :light_red : :light_yellow)
        # Path color
        pc = :blue
        printstyled("[", color=mc)
        printstyled("$(err[1])", color=mc)     # errorno
        printstyled("]  ", color=mc)
        printstyled("$(err[5])", color=pc)     # filename
        printstyled(":", color=pc)             # colon
        printstyled("$(err[4])", color=pc)     # lineno
        printstyled("  $(err[7])", color=pc)   # path
        println()
        printstyled("$(err[6]) ", color=mc)    # module
        printstyled("$(err[2]) ", color=:bold) # function
        printstyled("(", color=:light_blue)    # param types
        for t in err[3]
            printstyled("::", color=:white)
            printstyled("$t", color=:light_blue)
        end
        printstyled(")", color=:light_blue)
        println()
    end
end
jkrumbiegel commented 4 years ago

The problem with this is that this doesn't leave the links clickable in Atom / VSCode, etc. This is something I use very often and I believe others do as well. In fact, I even explicitly expand the base paths to make them clickable. This does of course print more. But I think it increases utility. I know there's some way to jump to stack trace entries by number in the REPL with some shortcut, but this is far less intuitive than just clicking on a link in my opinion.

KristofferC commented 4 years ago

It might make sense to take the opportunity to unify the way line info is printed with the logging system, for example:

bild

Also, note that the logging system does contract the homedir

julia> include("foo.jl")
┌ Warning: foo
└ @ Main ~/julia/foo.jl:1
KristofferC commented 4 years ago

I think there are two core ideas in the proposal here:

So here is a slightly more conservative attempt with both those ideas:

bild

mcabbott commented 4 years ago

A version with variable names added in, and colour just on the module names (but otherwise matching how @info prints paths):

Screenshot 2020-05-28 at 15 55 56

This one doesn't have very long type signatures, but perhaps having variable names like this (if that's possible?) will make it easier to spot the outermost type of each argument.

If there are three levels of neutral available (like bold/normal/grey), then printing the file path more lightly than the signature seems (IMO) like a good way to stop things running together. (This is also what @info does.)

Adapting @timotaularson 's code
let
    printstyled("\njulia> ", color=:green)
    println("f()")
    printstyled("""ERROR: DimensionMismatch("A has dimensions (1,2) but B has dimensions (3,4)")""", color=:light_red)
    println("\nStacktrace:")
    for (idx, err) in enumerate(errors)
        mc = idx <= 3 ? :blue : (idx >= 7 ? :blue : :yellow) # Module color
        printstyled("[$(err[1])] ", color=:normal, bold=true) # errorno
        printstyled(err[2], color=:normal, bold=true) # function
        printstyled("(", color=:normal)    # param types
        for (i,t) in enumerate(err[3])
            i != 1 && printstyled(", ", color=:normal)
            printstyled(rand('a':'z')^2, color=:light_black)
            printstyled("::", color=:normal)
            printstyled("$t", color=:normal)
        end
        printstyled(")", color=:normal)
        println()
        printstyled("  @ ", color=:light_black)
        printstyled(err[6], color=mc)    # module
        printstyled(" $(err[7])/$(err[5]):$(err[4])", color=:light_black)   # path
        println()
    end
end
jkrumbiegel commented 4 years ago

I think there are two core ideas in the proposal here:

* Have the line info on a separate line from the signature (and perhaps delimited it with some color to make it easier to find).

* Show the module.

So here is a slightly more conservative attempt with both those ideas:

I like this. I think the term is "kill your darlings", and my darling might be the color. But I can see how something toned-down might be better suited for something so basic. I changed it a bit so that the module name and the function name line up, which creates an almost column-like vertical contrast line. That should help to find the relevant information. Though I still think I wouldn't put the types in white, because they get so messy. If we had variable names, maybe those in white would look good.

grafik
KristofferC commented 4 years ago

I like this. I think the term is "kill your darlings", and my darling might be the color.

Just so you know that I know your situation, https://github.com/JuliaLang/julia/pull/18228. This is a topic that is very fun to bikeshed and everyone has a bucket of paint, heh. As you can see, that PR also started quite ambitiously but slowly got more and more conservative heh.

To me, the last proposal is definitely an improvement over status quo. Two things I am thinking:

JeffBezanson commented 4 years ago

I like it, I think we're getting somewhere. Being judicious with colors is always good, since that exposes less surface area for bikeshedding, plus decreases the risk that a color will be unreadable on somebody's terminal.

Spacing things out is good, but unfortunately the syntax f (...) is explicitly disallowed, so I think we need to either remove the space or remove the parens.

timotaularson commented 4 years ago

The most recent sample generally looks good, but I second the idea:

If possible, it would be nice to have some kind of "hook" for your eyes for the line information because it tend to blend together with the signature when the signature is long.

And I hope that hook is a different color or (preferably) brightness.

timotaularson commented 4 years ago

Maybe you could do the cycle of colors for the modules but only apply it to the [ ] on either side of the stack level number so if you cannot see the colors for some reason not much is lost.

jkrumbiegel commented 4 years ago

Maybe you could do the cycle of colors for the modules but only apply it to the [ ]

It's hard to even see the color correctly if it's only brackets and they are in a contrasty area, so I don't think that works too well..

the syntax f (...) is explicitly disallowed

I think it works well even without the space, because of the contrast difference.

If possible, it would be nice to have some kind of "hook" for your eyes for the line information

I agree, I think it works well to leave the line numbers gray but bold them, that makes them just slightly salient if you look for them but the next step of making them white is way too noisy in my opinion.

We should probably align the stackframe numbers

I tried it with spaces inside the brackets like in your example but found that looked a bit weird, so now I'm just right aligning the bracketed numbers. I think that works pretty well.

Here's the newest version with all those ideas incorporated:

grafik
jkrumbiegel commented 4 years ago

And as a bonus, here's how it could look with (random) variable names. Again I'm just using bold gray because all these variable names should not fight for your attention, but should be a bit discernible if you look for them

grafik
StefanKarpinski commented 4 years ago

I do like where this is going too. I want to just put a vote in for some kind of highlighting of the module name. I actually quite like the style where the same module is colored the same way and it cycles through the colors (there's a graph color problem in here if you consider two stack trace lines being adjacent as a graph edge between their modules). It is, unfortunately, pretty non-obvious what that color mean, however. Perhaps coloring all the module names in a single color?

mcabbott commented 4 years ago

This alignment looks good to me.

I still think that having the paths more clearly distinct from the signatures would help break things up -- 3 levels of importance, name/signature/path. Logging macros @info etc. print them ligher than other lines.

Variable names would be extremely nice to have. Would vote that they be less significant than signature information, probably?

Having the module names lined up at the left does help you scan them, although I'm sad to see colours go.

timotaularson commented 4 years ago

My eyes seem to know where to find things on this one :) Would a blank line between modules use too much vertical space?

ViralBShah commented 4 years ago

Coloring rows with 2 different colors so that alternate rows have the same color - as is often done in tables might help readability.

timotaularson commented 4 years ago

Color cycling the @ next to the module name instead of the module name itself stands out (because @ is a pretty big character) without competing with the highlighted function name too much.

I have often wished for the parameter names since they help you find the right parameter type without having to count through them.

Could the path (and perhaps the module name next to it) be a different brightness than the types? Maybe just matching the parameter names? (Or all low-lighted together if you do mcabbott's suggestion of making the names dimmer than the types)

mcabbott commented 4 years ago

You could explicitly mirror what logging uses, although ideally with different colours:

for i in 1:3
    printstyled("┌[", color=:magenta, bold=true); print(i); printstyled("] ", color=:magenta, bold=true)
    printstyled("get_ticklabels", bold=true); print("("); printstyled("style", color=:light_black); print("::AbstractPlotting.Automatic, "); printstyled("n", color=:light_black); print("::Int64")
    i!=2 ? println(")") : begin print(", "); printstyled("xs", color=:light_black);  print("::Array{Float64,2}, ");  printstyled("ys", color=:light_black);  print("::Array{Float64,1}, ");  printstyled("yes", color=:light_black);  print("::Bool, ");  printstyled("no", color=:light_black);  println("::Bool)") end
    printstyled("└ @ ", color=:magenta, bold=true); printstyled("MakieLayout", color=:magenta); printstyled(" ~/.julia/packages/MakieLayout/COfBu/src/lineaxis.jl:372", color=:light_black); println();
end
@error join([join(rand('a':'z', rand(1:9))) for _ in 1:25]," ") pi

Edit: now with one longer line which wraps, and a picture:

Screenshot 2020-05-28 at 20 21 48
jkrumbiegel commented 4 years ago

You could explicitly mirror what logging uses

The thing that I don't like so much about this is that line breaks that are only there because of the specific REPL width don't transfer well if you resize your window / REPL (if you want to make room for longer lines for example) or copy / paste the text into windows of different width

mcabbott commented 4 years ago

Yes, I would not propose explicitly breaking the lines to make the markers continuous. In fact it may be a good thing to let wrapped lines break through, and hence look different. Mostly a thought on how to tie the colour to the function name, and how to make it perhaps less obtrusive, if it's part of the border instead of looking like the most important heading.

karajan9 commented 4 years ago

I must say I liked the colour but I can understand the preference to be conservative with it.

I want, however, to throw my support behind something like

Often the exact package is not so much of interest as the nature of the code: is it core julia, a library I'm using, the library I'm developing, or a script? We could have four colors: core/base/dev/stdlib, packages, packages currently ]deved, and all the rest (including script/REPL). [...]

Since I'm not hacking on base and rarely on packages (as most people do, I presume), 90% of errors need to be fixed in my script, 9% in a package and 1% in base. If I made a mistake calling a function I don't need to know here exactly in base the error was thrown since I'm not going in there to fix it anyway, I need to fix my code.

So I'd appreciate some visual helper to see where I'm leaving my code (and maybe also where I'm leaving package code, going into base) because in most cases anything after that I can safely ignore for now. If not via colour, maybe with -------------------------------------------- or something? There should only ever be 2-3 of those.

mcabbott commented 4 years ago

If modules get coloured, then perhaps Base/Core should be left out and given no colour.