Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Quote source as part of error messages #3020

Merged
merged 1 commit into from
Feb 10, 2021
Merged

Conversation

richcarl
Copy link
Contributor

@richcarl richcarl commented Feb 1, 2021

Provides one or more additional lines of context for compiler messages, showing the relevant source code with the error position indicated by ^, like this:

foo.erl:13:10: variable 'X' is unbound
%   13|     case X of
%     |          ^

foo.erl:18:16: illegal guard expression
%   18| foo(A, B) when is_lit(A), is_list(B) ->
%     |                ^

foo.erl:23:22: function bar/1 undefined
%   23|             {ok, {H, bar(T)}}
%     |                      ^

foo.erl:27:5: record foo undefined
%   26| bar(X, Y) ->
%   27|     #foo{a = baz(X, Y),
%     |     ^
%   28|          b = f(),
%     | ...
%   31|          y = false,
%   32|          z = true}.

These long messages can be suppressed with the 'brief' compiler option.
The message formatting code is moved out to a separate module.

The followup PR #3026 also adds end position to the parser, allowing the error ranges to be underlined.

@mheiber
Copy link
Contributor

mheiber commented Feb 1, 2021

I'm so excited for this change, I think it will be a huge devX improvement 🎉.

Some small bugs with +deterministic:

  • With +deterministic, when there is a file with the same basename as the source file in the current directory, lines from the file in the current directory are displayed instead of in the source file. You can see this with an example.erl in .., then yes > example.erl CTRL-C then erlc +deterministic ../example.erl. Any errors in the source file show up with the quoted source line as yes.
  • With +deterministic, when there is no file with the same name in the current directory, there are no error lines displayed. We hit the error-swallowing case here.

The root cause seems to be that SourceName has two incompatible meanings:

  • thing used for display, which can be shortened
  • thing used for reading from the fs, which must be accurate

quote_source_1(File, Loc1, Line) when is_integer(Line) ->
quote_source_1(File, Loc1, {Line, -1});
quote_source_1(File, {StartLine, StartCol}, {EndLine, EndCol}) ->
case file:read_file(File) of
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks like we are re-reading the source file for each error line. Is there a way to do fewer reads?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Absolutely, this was a simplistic implementation. Considering OS file caches, it's probably not too bad as it is even for a hundred or more errors, but you could implement a caching system (which would have to handle include files as well, not just the main source file).

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems to be fast enough when compiling the compiler test suite (which has many warnings). In real code, there is probably very few warnings, as many projects use -Werror nowadays.

@rickard-green rickard-green added the team:VM Assigned to OTP team VM label Feb 1, 2021
@uabboli uabboli self-assigned this Feb 2, 2021
@richcarl
Copy link
Contributor Author

richcarl commented Feb 2, 2021

To make things easier for upstream adoption, I am splitting this into two separate parts. This part now only adds the messages and points out the start position, so it does not affect the parser annotations.

Copy link
Contributor

@bjorng bjorng left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

compile_SUITE:app_test/1 fails because you have not included compile_messages in the app file.

Found two minor style issues.

Otherwise, looks good to me.

lib/compiler/src/compile_messages.erl Outdated Show resolved Hide resolved
lib/compiler/src/compile_messages.erl Outdated Show resolved Hide resolved
@richcarl
Copy link
Contributor Author

richcarl commented Feb 3, 2021

Otherwise, looks good to me.

Any suggestion for a different module name than "compile_messages", or is it ok for you?

@garazdawi
Copy link
Contributor

Should there be tests for this? or are the existing tests sufficient?

@ranjanified
Copy link
Contributor

Otherwise, looks good to me.

Any suggestion for a different module name than "compile_messages", or is it ok for you?

If you can make it sound like a "object", that will be good. Modules probably are well-suited with a notion of a "subject". "compile_messages" sound more like a verb. Just my thoughts. Honestly haven't gone through the details of the PR, so excuse me for being shallow.

@uabboli uabboli removed their assignment Feb 3, 2021
@richcarl
Copy link
Contributor Author

richcarl commented Feb 3, 2021

"compile_messages" sound more like a verb.

That's basically why I'm asking (and also because someone out there might be using this name for something else already). The main point with the current name is that it indicates its relation to the "compile" module.

@bjorng
Copy link
Contributor

bjorng commented Feb 3, 2021

Any suggestion for a different module name than "compile_messages", or is it ok for you?

Traditionally, Robert and Joe use sys_ as a prefix for compiler modules, and it is still used for some compiler modules.

So, perhaps, sys_messages.

@richcarl
Copy link
Contributor Author

richcarl commented Feb 3, 2021

Fixed style issues and renamed to sys_messages.

@richcarl
Copy link
Contributor Author

richcarl commented Feb 3, 2021

Tried rebasing on master as well to trigger another rebuild, but it's still failing. Docker trouble?

@bjorng bjorng added enhancement testing currently being tested, tag is used by OTP internal CI labels Feb 3, 2021
@bjorng
Copy link
Contributor

bjorng commented Feb 3, 2021

Tried rebasing on master as well to trigger another rebuild, but it's still failing. Docker trouble?

Yes, seems to be. It builds fine on our Jenkins server, though.

@bjorng
Copy link
Contributor

bjorng commented Feb 4, 2021

There are failed test cases in erlc_SUITE (system) and escript_SUITE (stdlib).

@bjorng bjorng removed the testing currently being tested, tag is used by OTP internal CI label Feb 4, 2021
bjorng added a commit to bjorng/otp that referenced this pull request Feb 4, 2021
Consider this module:

    -module(w).
    -export([ll/0, sum/0, tt/0, ignored/2]).

    ll() ->
        L = {a,b,c},
        length(L).

    sum() ->
        A = a,
        B = b,
        A + B.

    tt() ->
        (try nan after whatever end) + 42.

    ignored(X, Y) ->
        X + Y,
        ok.

When compiling this module using erlang#3020,
the following warnings are emitted:

    w.erl:6:5: Warning: this expression will fail with a 'badarg' exception
    %    6|     length(L).
    %     |     ^

    w.erl:11:7: Warning: this expression will fail with a 'badarith' exception
    %   11|     A + B.
    %     |       ^

    w.erl:14:34: Warning: this expression will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

    w.erl:17:7: Warning: the result of the expression is ignored (suppress the warning by assigning the expression to the _ variable)
    %   17|     X + Y,
    %     |       ^

The last three warnings are slightly confusing, because the warnings
say "this expression" or "the expression", but the column position
points out the `+` operator in the middle of the expresson instead
of the beginning of the expression.

For the second warning, it would be better to point out the variable `A`:

    w.erl:11:5: Warning: this expression will fail with a 'badarith' exception
    %   11|     A + B.
    %     |     ^

However, to produce that warning would need a major rethinking of the
compiler pass, `sys_core_fold`, that produces that kind of warning.
`sys_core_fold` is an optimization pass that opportunistically emits
warnings while optimizing the code. When the warning for line 11 is
emitted, the original code has been lost and the line and column
number for the variable `A` is no longer available.

The third warning does not seem possible to fix by moving the position of the caret:

    w.erl:14:34: Warning: this expression will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

Pointing to the atom `nan` would be confusing.

Considering that the second warning would need a lot of work and that there is no good
solution for the third warning, I instead chose to rephrase the warnings like this:

    w.erl:6:5: Warning: the call to length/1 will fail with a 'badarg' exception
    %    6|     length(L).
    %     |     ^

    w.erl:11:7: Warning: evaluation of operator '+'/2 will fail with a 'badarith' exception
    %   11|     A + B.
    %     |       ^

    w.erl:14:34: Warning: evaluation of operator '+'/2 will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

    w.erl:17:7: Warning: the result of an expression is ignored (suppress the warning by assigning the expression to the _ variable)
    %   17|     X + Y,
    %     |       ^

I did not come up with a great solution for the fourth warning, so I
only changed "the expression" to "an expression".
bjorng added a commit to bjorng/otp that referenced this pull request Feb 4, 2021
Consider this module:

    -module(w).
    -export([ll/0, sum/0, tt/0, ignored/2]).

    ll() ->
        L = {a,b,c},
        length(L).

    sum() ->
        A = a,
        B = b,
        A + B.

    tt() ->
        (try nan after whatever end) + 42.

    ignored(X, Y) ->
        X + Y,
        ok.

When compiling this module using erlang#3020,
the following warnings are emitted:

    w.erl:6:5: Warning: this expression will fail with a 'badarg' exception
    %    6|     length(L).
    %     |     ^

    w.erl:11:7: Warning: this expression will fail with a 'badarith' exception
    %   11|     A + B.
    %     |       ^

    w.erl:14:34: Warning: this expression will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

    w.erl:17:7: Warning: the result of the expression is ignored (suppress the warning by assigning the expression to the _ variable)
    %   17|     X + Y,
    %     |       ^

The last three warnings are slightly confusing, because the warnings
say "this expression" or "the expression", but the column position
points out the `+` operator in the middle of the expresson instead
of the beginning of the expression.

For the second warning, it would be better to point out the variable `A`:

    w.erl:11:5: Warning: this expression will fail with a 'badarith' exception
    %   11|     A + B.
    %     |     ^

However, to produce that warning would need a major rethinking of the
compiler pass, `sys_core_fold`, that produces that kind of warning.
`sys_core_fold` is an optimization pass that opportunistically emits
warnings while optimizing the code. When the warning for line 11 is
emitted, the original code has been lost and the line and column
number for the variable `A` is no longer available.

The third warning does not seem possible to fix by moving the position of the caret:

    w.erl:14:34: Warning: this expression will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

Pointing to the atom `nan` would be confusing.

Considering that the second warning would need a lot of work and that there is no good
solution for the third warning, I instead chose to rephrase the warnings like this:

    w.erl:6:5: Warning: the call to length/1 will fail with a 'badarg' exception
    %    6|     length(L).
    %     |     ^

    w.erl:11:7: Warning: evaluation of operator '+'/2 will fail with a 'badarith' exception
    %   11|     A + B.
    %     |       ^

    w.erl:14:34: Warning: evaluation of operator '+'/2 will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

    w.erl:17:7: Warning: the result of evaluating operator '+'/2 is ignored (suppress the warning by assigning the expression to the _ variable)
    %   17|     X + Y,
    %     |       ^
bjorng added a commit to bjorng/otp that referenced this pull request Feb 4, 2021
Consider this module:

    -module(w).
    -export([ll/0, sum/0, tt/0, ignored/2]).

    ll() ->
        L = {a,b,c},
        length(L).

    sum() ->
        A = a,
        B = b,
        A + B.

    tt() ->
        (try nan after whatever end) + 42.

    ignored(X, Y) ->
        X + Y,
        ok.

When compiling this module using erlang#3020,
the following warnings are emitted:

    w.erl:6:5: Warning: this expression will fail with a 'badarg' exception
    %    6|     length(L).
    %     |     ^

    w.erl:11:7: Warning: this expression will fail with a 'badarith' exception
    %   11|     A + B.
    %     |       ^

    w.erl:14:34: Warning: this expression will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

    w.erl:17:7: Warning: the result of the expression is ignored (suppress the warning by assigning the expression to the _ variable)
    %   17|     X + Y,
    %     |       ^

The last three warnings are slightly confusing, because the warnings
say "this expression" or "the expression", but the column position
points out the `+` operator in the middle of the expresson instead
of the beginning of the expression.

For the second warning, it would be better to point out the variable `A`:

    w.erl:11:5: Warning: this expression will fail with a 'badarith' exception
    %   11|     A + B.
    %     |     ^

However, to produce that warning would need a major rethinking of the
compiler pass, `sys_core_fold`, that produces that kind of warning.
`sys_core_fold` is an optimization pass that opportunistically emits
warnings while optimizing the code. When the warning for line 11 is
emitted, the original code has been lost and the line and column
number for the variable `A` is no longer available.

The third warning does not seem possible to fix by moving the position of the caret:

    w.erl:14:34: Warning: this expression will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

Pointing to the atom `nan` would be confusing.

Considering that the second warning would need a lot of work and that there is no good
solution for the third warning, I instead chose to rephrase the warnings like this:

    w.erl:6:5: Warning: the call to length/1 will fail with a 'badarg' exception
    %    6|     length(L).
    %     |     ^

    w.erl:11:7: Warning: evaluation of operator '+'/2 will fail with a 'badarith' exception
    %   11|     A + B.
    %     |       ^

    w.erl:14:34: Warning: evaluation of operator '+'/2 will fail with a 'badarith' exception
    %   14|     (try nan after whatever end) + 42.
    %     |                                  ^

    w.erl:17:7: Warning: the result of evaluating operator '+'/2 is ignored (suppress the warning by assigning the expression to the _ variable)
    %   17|     X + Y,
    %     |       ^
@garazdawi
Copy link
Contributor

foo() ->
    A = <<"a𐐀b"/utf16>>, <<"hello">>,
    A.

On my machine this prints:

t.erl:14:26: Warning: a term is constructed, but never used
%   14|     A = <<"a\x{10400}b"/utf16>>, <<"hello">>,
%     |                          ^

@bjorng
Copy link
Contributor

bjorng commented Feb 4, 2021

@garazdawi The problem you found is a problem with erlc. I have known about it, but haven't got around to fix it. I might try to fix it for OTP 24.

If you compile your function with the erl shell, it will work:

1> c(t).
t.erl:5:26: Warning: a term is constructed, but never used
%    5|     A = <<"a𐐀b"/utf16>>, <<"hello">>,
%     |                          ^

There should be no need take any coding into account, because the column position is the number of graphemes. Here is another example:

bar() ->
    A = <<"привет"/utf8>>, <<"hello">>,
    B = <<"abcdef"/utf8>>, <<"hello">>,
    {A,B}.

The carets are placed in the correct place:

t.erl:9:28: Warning: a term is constructed, but never used
%    9|     A = <<"привет"/utf8>>, <<"hello">>,
%     |                            ^

t.erl:10:28: Warning: a term is constructed, but never used
%   10|     B = <<"abcdef"/utf8>>, <<"hello">>,
%     |                            ^

@bjorng bjorng added the testing currently being tested, tag is used by OTP internal CI label Feb 4, 2021
@garazdawi
Copy link
Contributor

Great!

@bjorng
Copy link
Contributor

bjorng commented Feb 4, 2021

@richcarl We found that int_SUITE:init_per_suite/1 in the debugger applications fails with a timetrap timeout on some of our test machines. That test case compiles a huge file with many warnings. On my Mac it needs 25 seconds. Some of our test machines needs more than one minute, which is the current timetrap limit.

Could you fix this in one of two ways?

  • Raise the timetrap limit, for example to ten minutes.
    {timetrap,{minutes,1}}].
  • Implement some sort of caching, for example by spawning off a caching process the first time an error or warning is printed.

@richcarl
Copy link
Contributor Author

richcarl commented Feb 4, 2021

@richcarl We found that int_SUITE:init_per_suite/1 in the debugger applications fails with a timetrap timeout on some of our test machines. That test case compiles a huge file with many warnings. On my Mac it needs 25 seconds. Some of our test machines needs more than one minute, which is the current timetrap limit.

Bumped to 10 min. Caching can wait until later.

@richcarl
Copy link
Contributor Author

richcarl commented Feb 4, 2021

Also, does this need to take %% coding: latin-1 into consideration?

Found that the underlining was too naive, and could get out of sync with tabs in combination with utf-8 multibytes. Now treats lines as sequences of codepoints, respecting the file encoding. This should always correspond to the column number computed by the scanner. (Forced edit: handle broken encodings in a sensible way instead of crashing.)

@bjorng
Copy link
Contributor

bjorng commented Feb 5, 2021

Found that the underlining was too naive, and could get out of sync with tabs in combination with utf-8 multibytes. Now treats lines as sequences of codepoints, respecting the file encoding. This should always correspond to the column number computed by the scanner. (Forced edit: handle broken encodings in a sensible way instead of crashing.)

Do you think you could add a test case to test those things you just fixed? To avoid have to constantly update that test case, it would probably be best to call sys_messages directly with a faked list of errors and warnings so that the output will not change if other parts of the compiler are updated.

@richcarl
Copy link
Contributor Author

richcarl commented Feb 5, 2021

Do you think you could add a test case to test those things you just fixed?

Added test case. Running the full compiler to ensure that encodings are checked properly.

@bjorng
Copy link
Contributor

bjorng commented Feb 8, 2021

There are still two failing test cases in erlc_SUITE (make_dep_options).

@richcarl
Copy link
Contributor Author

richcarl commented Feb 8, 2021

See if you like this solution better before I squash. Also added a fix for the hardcoded paths preventing you from running erlc_SUITE directly from make under erts.

@uabboli
Copy link
Contributor

uabboli commented Feb 8, 2021

The followup PR #3026 also adds end position to the parser, allowing
the error ranges to be underlined.

I think all traces of ranges (#3026) should be removed in this PR.
erl_lint should not be updated at all, and the code in sys_messages,
starting with

StartLoc = erl_anno:location(Loc).

should not try to be forward compatible with ranges. It breaks the
erl_anno abstraction (the current code will crash if the erl_anno
module is compiled with DEBUG=true).

@richcarl
Copy link
Contributor Author

richcarl commented Feb 8, 2021

I think all traces of ranges (#3026) should be removed in this PR.
erl_lint should not be updated at all, and the code in sys_messages,
starting with

StartLoc = erl_anno:location(Loc).

should not try to be forward compatible with ranges. It breaks the
erl_anno abstraction (the current code will crash if the erl_anno
module is compiled with DEBUG=true).

I agree, so I'll try to remove stuff that shouldn't have been in this part to begin with.

Something is weird with the types, though. in compile.erl, a comp_ret(), which is the return type for compile:file() and compile:forms(), is defined as reporting errors and warnings that contain err_info() :: {erl_anno:line() | 'none', module(), term()}. Note that it says line(), which is defined in erl_anno as non_neg_integer(), and this should be changed to location() to reflect the new support for column numbers, which might fix the DEBUG compilation problem.

Meanwhile, internally in compile.erl the errors and warnings fields of the #compile{} record use the type err_warn_info() which is just defined as tuple(). The messages_per_file() function takes the internal err_warn_info() representation and produces the err_info() version.

I don't really want to start on a type annotation whack-a-mole to try to clean up that stuff myself, since it might cause some cascading type issues, at least not until I know what you think how it should look.

@bjorng
Copy link
Contributor

bjorng commented Feb 8, 2021

See if you like this solution better before I squash. Also added a fix for the hardcoded paths preventing you from running erlc_SUITE directly from make under erts.

Looks good to me, and the test cases now run clean.

@bjorng
Copy link
Contributor

bjorng commented Feb 8, 2021

I think you can squash it now. (I would prefer down to a single commit.) If everything goes well in our nightly tests, I intend to merge this PR tomorrow.

@uabboli
Copy link
Contributor

uabboli commented Feb 8, 2021

I think all traces of ranges (#3026) should be removed in this PR.
erl_lint should not be updated at all, and the code in sys_messages,
starting with

I see that you've reverted erl_lint. Looks OK.

StartLoc = erl_anno:location(Loc).

should not try to be forward compatible with ranges. It breaks the
erl_anno abstraction (the current code will crash if the erl_anno
module is compiled with DEBUG=true).

You've haven't fixed this, as far as I can see.

Note that it says line(), which is defined in erl_anno as
non_neg_integer(), and this should be changed to location() to reflect
the new support for column numbers, which might fix the DEBUG
compilation problem.

No, the erl_anno-abstraction is broken in a more fundamental way.

The quoted line,

StartLoc = erl_anno:location(Loc).

breaks the erl_anno abstraction.

format_messages(F, P, [{Loc, Mod, E} | Es], Opts) ->
    Src = quote_source(F, Loc, Loc, Opts),

should suffice.

lists_errors also breaks the erl_anno-abstraction:

list_errors(F, [{StartLoc, Mod, E} | Es], Opts) ->
    list_errors(F, [{{StartLoc, StartLoc}, Mod, E} | Es], Opts);

I suppose you can keep the EndLoc in quote_source as long it's
correct, although it's not needed in this PR.

@richcarl
Copy link
Contributor Author

richcarl commented Feb 8, 2021

Squashed. Working on a cleanup of type usages, but I can put that in a separate PR after this is merged.

@richcarl richcarl mentioned this pull request Feb 8, 2021
@richcarl
Copy link
Contributor Author

richcarl commented Feb 8, 2021

@uabboli Check out #3045 for a patch that tries to unify the type annotations for errors/warnings over the compiler modules.

@bjorng bjorng removed the testing currently being tested, tag is used by OTP internal CI label Feb 8, 2021
Can be suppressed with the 'brief' compiler option.
Moves message formatting code to a separate module.
@richcarl
Copy link
Contributor Author

richcarl commented Feb 8, 2021

Accidentally deleted a clause that was actually used. Also finally saw what @uabboli meant, so I removed the calls to erl_anno on a location type.

@bjorng bjorng added the testing currently being tested, tag is used by OTP internal CI label Feb 8, 2021
@bjorng
Copy link
Contributor

bjorng commented Feb 8, 2021

Thanks, I can confirm that it works with erl_anno debugging activated (by uncommenting the defines for DEBUG in erl_anno, erl_parse, and erl_pp). Added to our daily builds.

@bjorng bjorng merged commit d3c315b into erlang:master Feb 10, 2021
@bjorng
Copy link
Contributor

bjorng commented Feb 10, 2021

Thanks for your pull request.

@richcarl richcarl deleted the quote-source branch February 10, 2021 08:19
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement team:VM Assigned to OTP team VM testing currently being tested, tag is used by OTP internal CI
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants