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

nix errors phase 2 #3590

Merged
merged 63 commits into from Jun 15, 2020
Merged

nix errors phase 2 #3590

merged 63 commits into from Jun 15, 2020

Conversation

@bburdette
Copy link
Contributor

@bburdette bburdette commented May 13, 2020

This PR is for phase 2 of the nix-error-proposal project.

Overall the idea is to enhance the format of error messages, and their content. This phase is just for the formatting part, the content of error messages is largely left alone.

To use the new format there are some new macros in logging.hh:

    logError
    logWarning

These require an ErrorInfo struct as an argument instead of a format string. In the default logger, the ErrorInfo is used to print errors to cerr. This late conversion of ErrorInfo to string should help with future language server support, or other similar efforts.

These macros prevent creating unnecessary ErrorInfo structs, similar to the printInfo and printError macros. That is, filtering takes place before the struct is created, not after.

ErrorInfo uses a special fmt - 'hintfmt' - that highlights templated values in yellow. For consistency, I changed the printError/warn/printInfo macros to use the same format style. That also required removing the remaining calls to boost::format.

ErrorInfo usage fits into two big categories: BaseError descendants, and converted printError messages.

Exceptions

BaseError descendants - Error, SysError, and so forth, all use the new format now. The MakeError macro uses the class name as the error name, so SysError will print:

  error: --- SysError ------------------------------------------ error-demo
  statting file : Bad file descriptor

Pos goes into ErrorInfo as a special field, and gets printed at a standardized place in the message. It got removed from the string templates so as not to duplicate information.

printError

For printError messages, there were more decisions to make. The ErrorInfo format is pretty heavy and not always appropriate. I categorized printError calls as follows:

  1. Problems. reporting a problem that may require user intervention.
    - converted to ErrorInfo format.
  2. Status. printing status messages that inform the user of progress.
    - converted to printInfo.
  3. Warnings. printing warnings with error verbosity, as in printError("warning: ...
    - converted to logWarning()
  4. Other. technical uses, like forwarding remote build messages to cerr.
    - left alone.

warn() messages.
these I left alone for now; reasoning that the printError("warning..." ones are more important, so those are distiguished by logWarning calls. warn() calls are intact other than converting from boost::format.

What's missing

This is already a huge PR, so I'm leaving some things out that belong in phase 2.

  • show-trace is not included in ErrorInfo. It still works as it has in the past, but its printed to cerr and doesn't make it into the logger except as strings.

  • lines of code. This is a big part of the new format! But I think there's enough to look at in this PR. Its next on my list.

Moving code around.

BaseError and descendants got moved out of types.hh (and util.cc) and into error.hh.

ErrorInfo now uses Verbosity instead of its own ErrLevel type. Consequently, Verbosity was moved from logging.hh to error.hh.

Theres a new header, fmt.hh, where fmt, FormatOrString, hintfmt, and so forth are defined.

Misc

In eval.cc and eval-inline are some functions like throwEvalError, that used pos in a string template. With pos being passed to ErrorInfo instead, I found it confusing to leave pos as the last argument in the function:

// old version: pos used as a value in the string template
throwTypeError("value is %1% while a list was expected, at %2%", v, pos);

// new version: pos is the first argument, indicating that its not used 
// in the template.
throwTypeError(pos, "value is %1% while a list was expected", v);

It seems like cpu affinity was meant to be printed in affinity.cc, but wasn't. I added an ostream operator<< for affinity, so I could print it:

{
        std::ostringstream oss;
        oss << savedAffinity;
        printError("failed to restore CPU affinity %1%", oss.str());
}
@bburdette
Copy link
Contributor Author

@bburdette bburdette commented May 29, 2020

So I've been working on the lines-of-code feature, but I've been cautioned about including yet more changes in this PR! Still, a preview:

Selection_042

Thankfully this will be a much smaller PR than the current one.

@edolstra
Copy link
Member

@edolstra edolstra commented Jun 2, 2020

Looks great, thanks!

Style note: In logError calls, we can omit the ErrorInfo constructor since it can be inferred. This makes these calls less verbose and less deeply nested. For example:

diff --git a/src/build-remote/build-remote.cc b/src/build-remote/build-remote.cc
index 0caa97fa..d0d2c1b1 100644
--- a/src/build-remote/build-remote.cc
+++ b/src/build-remote/build-remote.cc
@@ -200,12 +200,11 @@ static int _main(int argc, char * * argv)
 
                 } catch (std::exception & e) {
                     auto msg = chomp(drainFD(5, false));
-                    logError(
-                        ErrorInfo { 
-                            .name = "Remote build",
-                            .hint = hintfmt("cannot build on '%s': %s%s",
-                        bestMachine->storeUri, e.what(),
-                        (msg.empty() ? "" : ": " + msg))
+                    logError({
+                        .name = "Remote build",
+                        .hint = hintfmt("cannot build on '%s': %s%s",
+                            bestMachine->storeUri, e.what(),
+                            (msg.empty() ? "" : ": " + msg))
                     });
                     bestMachine->enabled = false;
                     continue;

Given that there are so many of these calls I think that's worthwhile.

Some nitpicks about the output: there are multiple trailing empty lines for some error messages, e.g.

$ nix build /foo
error: --- SysError ------------------------------------------------- nix
getting status of '/foo' : No such file or directory



and there shouldn't be a space in front of the colon ('/foo' :).


// In each program where errors occur, this has to be set.
ErrorInfo::programName = std::optional("error-demo");

// 'DemoError' appears as error name.

This comment has been minimized.

@gilligan

gilligan Jun 3, 2020
Contributor

I wonder if it would be possible to turn this demo file into unit tests instead? Would that be feasible? WDYT @bburdette ?

This comment has been minimized.

@bburdette

bburdette Jun 3, 2020
Author Contributor

I am not opposed. What do you envision as tests? String comparison of predicted vs actual output?

This comment has been minimized.

@gilligan

gilligan Jun 3, 2020
Contributor

Yes i think that is what I would envision. I have to admit i didn’t yet find the time to take a closer look so maybe some parts might be hard(er) to test when log functions just print to stderr bur whenever an Exception is thrown with a message that encodes information in a certain format that could be tested.

This comment has been minimized.

@gilligan

gilligan Jun 5, 2020
Contributor

I actually just spent some time on this and am almost done converting everything from your error-demo.cc into a unit test. I'll probably have it done later this evening for you to check out.

This comment has been minimized.

@bburdette

bburdette Jun 5, 2020
Author Contributor

Wow just saw this! I've been working on it too, but sounds like you're further along. I'll look for that!

This comment has been minimized.

@gilligan

gilligan Jun 6, 2020
Contributor

Please have a look at:
gilligan@952e72c

I would suggest to remove error-demo and replace it with that. Some notes:

  • Shortly after i started i realized that this would really be tests for logging.h
  • I am using the google test to capture output and assert that. That seemed like the best approach to me
  • You will see notes with XXX where i don't quite understand why description is not set.
  • The asserts do look a bit ugly. It might be nicer to use c++ raw strings so the expected output is actually human readable. Using those in the json.hh tests:
        ASSERT_EQ(out.str(),
R"#({
  "list": [
    "element"
  ]
})#");

I was using those at first but then realized that because of the escape codes for coloring they wouldn't work. I guess ideally we'd still use those and add the escape codes (?). Or we leave that as an improvement for later. I'll leave it up to you.

This comment has been minimized.

@bburdette

bburdette Jun 6, 2020
Author Contributor

Nice! The testing::internal::CaptureStderr() is helpful. My approach was doing a test in bash; this is better I think.

I do wonder about the empty strings on Talkative and etc. On the plus side, its only the logError and logWarning that are used in actual code at this point. Seems like a problem with the stderr capture somehow? "Chatty" still has a "talkative" description; I made a note.

Anyway overall LGTM. Thanks for expediting this!

Copy link
Contributor

@gilligan gilligan left a comment

I’m super excited about this. Very much looking forward to this getting over the finishing line! Would be cool if my comments on testing and documentation could be incorporated.

const std::string nativeSystem = SYSTEM;


BaseError & BaseError::addPrefix(const FormatOrString & fs)

This comment has been minimized.

@gilligan

gilligan Jun 4, 2020
Contributor

Can you add a short comment documenting this method?

This comment has been minimized.

@bburdette

bburdette Jun 4, 2020
Author Contributor

comment added!

return *this;
}

const string& BaseError::calcWhat() const

This comment has been minimized.

@gilligan

gilligan Jun 4, 2020
Contributor

Can you add a short comment documenting this method?

This comment has been minimized.

@bburdette

bburdette Jun 4, 2020
Author Contributor

done

}

void printCodeLines(const string &prefix, const NixCode &nixCode)
void printCodeLines(std::ostream &out, const string &prefix, const NixCode &nixCode)

This comment has been minimized.

@gilligan

gilligan Jun 4, 2020
Contributor

Can you add a short comment documenting this method?

This comment has been minimized.

@bburdette

bburdette Jun 4, 2020
Author Contributor

comment added!

// format function for hints. same as fmt, except templated values
// are always in yellow.
// -------------------------------------------------
// ErrorInfo.

This comment has been minimized.

@gilligan

gilligan Jun 4, 2020
Contributor

Repeating the name of the structure isn’t a very helpful comment 😅

I wonder if you could possibly add a brief description to this header file that would enable someone to grasp the overall design of this “error api”?

The Nix code base mostly doesn’t have a lot of inline comments/documentation but i think it would be fantastic if we could slowly improve that.

Edit: i guess slightly changed parts of the PR description would be a good fit?

This comment has been minimized.

@bburdette

bburdette Jun 4, 2020
Author Contributor

Ok added some comments at the top and removed the "ErrorInfo."

bburdette and others added 3 commits Jun 4, 2020
The logging.hh superseeds the demo
@bburdette

This comment has been minimized.

Copy link
Contributor

@bburdette bburdette commented on 952e72c Jun 6, 2020

i have a patch you can apply to fix the high verbosity tests: https://gist.github.com/bburdette/aaffa0a4f69c7ab2f85e756be5217b6d

This comment has been minimized.

Copy link
Contributor Author

@gilligan gilligan replied Jun 6, 2020

@gilligan
Copy link
Contributor

@gilligan gilligan commented Jun 8, 2020

@bburdette thanks for incorporating the tests!

@gilligan gilligan mentioned this pull request Jun 8, 2020
0 of 16 tasks complete
@Ericson2314
Copy link
Member

@Ericson2314 Ericson2314 commented Jun 13, 2020

Hope we can get this merged soon! The status quo with the demo merged but not integrated is perfectly understandable as an intermediate step, but not something we should leave around!

@Ericson2314
Copy link
Member

@Ericson2314 Ericson2314 commented Jun 13, 2020

Also, I was just ad-hoc adding some strerr(errno) to help myself debug something, which is a real bummer this PR systematically does that.

@gilligan
Copy link
Contributor

@gilligan gilligan commented Jun 15, 2020

@edolstra is there anything that in your view makes this PR not ready to be merged?

@edolstra edolstra merged commit 7a77762 into NixOS:master Jun 15, 2020
2 checks passed
2 checks passed
tests (ubuntu-latest)
Details
tests (macos-latest)
Details
@edolstra
Copy link
Member

@edolstra edolstra commented Jun 15, 2020

@bburdette Thanks, merged!

@bburdette
Copy link
Contributor Author

@bburdette bburdette commented Jun 15, 2020

Awesome, thanks for the merge!!

Ma27 added a commit to Ma27/ale that referenced this pull request Jul 6, 2020
In the (unreleased) Nix 2.4 the error-messages have been reformatted[1].
This patch aims to retain proper `.nix`-support in `ale`, but is only
targeted for folks using an unstable Nix version.

Also, this improved-error-message feature is still work in progress, so
the behavior of `nix-instantiate` is still subject to change.

[1] NixOS/nix#3590
Ma27 added a commit to Ma27/ale that referenced this pull request Jul 22, 2020
In the (unreleased) Nix 2.4 the error-messages have been reformatted[1].
This patch aims to retain proper `.nix`-support in `ale`, but is only
targeted for folks using an unstable Nix version.

Please note that this currently depends on a pending PR[2] which adds
support for minimal JSON error-outputs.

[1] NixOS/nix#3590
[2] NixOS/nix#3847
Ma27 added a commit to Ma27/ale that referenced this pull request Jul 22, 2020
In the (unreleased) Nix 2.4 the error-messages have been reformatted[1].
This patch aims to retain proper `.nix`-support in `ale`, but is only
targeted for folks using an unstable Nix version.

Please note that this currently depends on a pending PR[2] which adds
support for minimal JSON error-outputs.

[1] NixOS/nix#3590
[2] NixOS/nix#3847
Ma27 added a commit to Ma27/ale that referenced this pull request Sep 27, 2020
In the (unreleased) Nix 2.4 the error-messages have been reformatted[1].
This patch aims to retain proper `.nix`-support in `ale`, but is only
targeted for folks using an unstable Nix version.

Please note that this currently depends on a pending PR[2] which adds
support for minimal JSON error-outputs.

[1] NixOS/nix#3590
[2] NixOS/nix#3847
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked issues

Successfully merging this pull request may close these issues.

None yet

5 participants
You can’t perform that action at this time.