aboutsummaryrefslogtreecommitdiff
path: root/src/libutil/logging.cc
AgeCommit message (Collapse)Author
2024-05-29Remove 100s of CPU time (10%) from build times (1465s -> 1302s)Jade Lovelace
I saw that boost/lexical_cast was costing about 100s in CPU time on our compiles. We can fix this trivially by doing explicit template instantiation in exactly one place and eliminating all other includes of it, which is a code improvement anyway by hiding the boost. Before: ``` lix/lix2 » ClangBuildAnalyzer --analyze buildtimeold.bin Analyzing build trace from 'buildtimeold.bin'... **** Time summary: Compilation (551 times): Parsing (frontend): 1465.3 s Codegen & opts (backend): 1110.9 s <snip> **** Expensive headers: 178153 ms: ../src/libcmd/installable-value.hh (included 52 times, avg 3426 ms), included via: 40x: command.hh 5x: command-installable-value.hh 3x: installable-flake.hh 2x: <direct include> 2x: installable-attr-path.hh 176217 ms: ../src/libutil/error.hh (included 246 times, avg 716 ms), included via: 36x: command.hh installable-value.hh installables.hh derived-path.hh config.hh experimental-features.hh 12x: globals.hh config.hh experimental-features.hh 11x: file-system.hh file-descriptor.hh 6x: serialise.hh strings.hh 6x: <direct include> 6x: archive.hh serialise.hh strings.hh ... 173243 ms: ../src/libstore/store-api.hh (included 152 times, avg 1139 ms), included via: 55x: <direct include> 39x: command.hh installable-value.hh installables.hh 7x: libexpr.hh 4x: local-store.hh 4x: command-installable-value.hh installable-value.hh installables.hh 3x: binary-cache-store.hh ... 170482 ms: ../src/libutil/serialise.hh (included 201 times, avg 848 ms), included via: 37x: command.hh installable-value.hh installables.hh built-path.hh realisation.hh hash.hh 14x: store-api.hh nar-info.hh hash.hh 11x: <direct include> 7x: primops.hh eval.hh attr-set.hh nixexpr.hh value.hh source-path.hh archive.hh 7x: libexpr.hh value.hh source-path.hh archive.hh 6x: fetchers.hh hash.hh ... 169397 ms: ../src/libcmd/installables.hh (included 53 times, avg 3196 ms), included via: 40x: command.hh installable-value.hh 5x: command-installable-value.hh installable-value.hh 3x: installable-flake.hh installable-value.hh 2x: <direct include> 1x: installable-derived-path.hh 1x: installable-value.hh ... 159740 ms: ../src/libutil/strings.hh (included 221 times, avg 722 ms), included via: 37x: command.hh installable-value.hh installables.hh built-path.hh realisation.hh hash.hh serialise.hh 19x: <direct include> 14x: store-api.hh nar-info.hh hash.hh serialise.hh 11x: serialise.hh 7x: primops.hh eval.hh attr-set.hh nixexpr.hh value.hh source-path.hh archive.hh serialise.hh 7x: libexpr.hh value.hh source-path.hh archive.hh serialise.hh ... 156796 ms: ../src/libcmd/command.hh (included 51 times, avg 3074 ms), included via: 42x: <direct include> 7x: command-installable-value.hh 2x: installable-attr-path.hh 150392 ms: ../src/libutil/types.hh (included 251 times, avg 599 ms), included via: 36x: command.hh installable-value.hh installables.hh path.hh 11x: file-system.hh 10x: globals.hh 6x: fetchers.hh 6x: serialise.hh strings.hh error.hh 5x: archive.hh ... 133101 ms: /nix/store/644b90j1vms44nr18yw3520pzkrg4dd1-boost-1.81.0-dev/include/boost/lexical_cast.hpp (included 226 times, avg 588 ms), included via : 37x: command.hh installable-value.hh installables.hh built-path.hh realisation.hh hash.hh serialise.hh strings.hh 19x: file-system.hh 11x: store-api.hh nar-info.hh hash.hh serialise.hh strings.hh 7x: primops.hh eval.hh attr-set.hh nixexpr.hh value.hh source-path.hh archive.hh serialise.hh strings.hh 7x: libexpr.hh value.hh source-path.hh archive.hh serialise.hh strings.hh 6x: eval.hh attr-set.hh nixexpr.hh value.hh source-path.hh archive.hh serialise.hh strings.hh ... 132887 ms: /nix/store/h2abv2l8irqj942i5rq9wbrj42kbsh5y-gcc-12.3.0/include/c++/12.3.0/memory (included 262 times, avg 507 ms), included via: 36x: command.hh installable-value.hh installables.hh path.hh types.hh ref.hh 16x: gtest.h 11x: file-system.hh types.hh ref.hh 10x: globals.hh types.hh ref.hh 10x: json.hpp 6x: serialise.hh ... done in 0.6s. ``` After: ``` lix/lix2 » maintainers/buildtime_report.sh build Processing all files and saving to '/home/jade/lix/lix2/maintainers/../buildtime.bin'... done in 0.6s. Run 'ClangBuildAnalyzer --analyze /home/jade/lix/lix2/maintainers/../buildtime.bin' to analyze it. Analyzing build trace from '/home/jade/lix/lix2/maintainers/../buildtime.bin'... **** Time summary: Compilation (551 times): Parsing (frontend): 1302.1 s Codegen & opts (backend): 956.3 s <snip> **** Expensive headers: 178145 ms: ../src/libutil/error.hh (included 246 times, avg 724 ms), included via: 36x: command.hh installable-value.hh installables.hh derived-path.hh config.hh experimental-features.hh 12x: globals.hh config.hh experimental-features.hh 11x: file-system.hh file-descriptor.hh 6x: <direct include> 6x: serialise.hh strings.hh 6x: fetchers.hh hash.hh serialise.hh strings.hh ... 154043 ms: ../src/libcmd/installable-value.hh (included 52 times, avg 2962 ms), included via: 40x: command.hh 5x: command-installable-value.hh 3x: installable-flake.hh 2x: <direct include> 2x: installable-attr-path.hh 153593 ms: ../src/libstore/store-api.hh (included 152 times, avg 1010 ms), included via: 55x: <direct include> 39x: command.hh installable-value.hh installables.hh 7x: libexpr.hh 4x: local-store.hh 4x: command-installable-value.hh installable-value.hh installables.hh 3x: binary-cache-store.hh ... 149948 ms: ../src/libutil/types.hh (included 251 times, avg 597 ms), included via: 36x: command.hh installable-value.hh installables.hh path.hh 11x: file-system.hh 10x: globals.hh 6x: fetchers.hh 6x: serialise.hh strings.hh error.hh 5x: archive.hh ... 144560 ms: ../src/libcmd/installables.hh (included 53 times, avg 2727 ms), included via: 40x: command.hh installable-value.hh 5x: command-installable-value.hh installable-value.hh 3x: installable-flake.hh installable-value.hh 2x: <direct include> 1x: installable-value.hh 1x: installable-derived-path.hh ... 136585 ms: ../src/libcmd/command.hh (included 51 times, avg 2678 ms), included via: 42x: <direct include> 7x: command-installable-value.hh 2x: installable-attr-path.hh 133394 ms: /nix/store/h2abv2l8irqj942i5rq9wbrj42kbsh5y-gcc-12.3.0/include/c++/12.3.0/memory (included 262 times, avg 509 ms), included via: 36x: command.hh installable-value.hh installables.hh path.hh types.hh ref.hh 16x: gtest.h 11x: file-system.hh types.hh ref.hh 10x: globals.hh types.hh ref.hh 10x: json.hpp 6x: serialise.hh ... 89315 ms: ../src/libstore/derived-path.hh (included 178 times, avg 501 ms), included via: 37x: command.hh installable-value.hh installables.hh 25x: store-api.hh realisation.hh 7x: primops.hh eval.hh attr-set.hh nixexpr.hh value.hh context.hh 6x: eval.hh attr-set.hh nixexpr.hh value.hh context.hh 6x: libexpr.hh value.hh context.hh 6x: shared.hh ... 87347 ms: /nix/store/h2abv2l8irqj942i5rq9wbrj42kbsh5y-gcc-12.3.0/include/c++/12.3.0/ostream (included 273 times, avg 319 ms), included via: 35x: command.hh installable-value.hh installables.hh path.hh types.hh ref.hh memory unique_ptr.h 12x: regex sstream istream 10x: file-system.hh types.hh ref.hh memory unique_ptr.h 10x: gtest.h memory unique_ptr.h 10x: globals.hh types.hh ref.hh memory unique_ptr.h 6x: fetchers.hh types.hh ref.hh memory unique_ptr.h ... 85249 ms: ../src/libutil/config.hh (included 213 times, avg 400 ms), included via: 37x: command.hh installable-value.hh installables.hh derived-path.hh 20x: globals.hh 20x: logging.hh 16x: store-api.hh logging.hh 6x: <direct include> 6x: eval.hh attr-set.hh nixexpr.hh value.hh context.hh derived-path.hh ... done in 0.5s. ``` Change-Id: I27f0a2d566db17832cd9be935f12efe7f95b92d0
2024-05-29util.hh: Delete remaining file and clean up headersTom Hubrecht
Change-Id: Ic1f68e6af658e94ef7922841dd3ad4c69551ef56
2024-05-29util.{hh,cc}: Split out file-descriptor.{hh,cc}Tom Hubrecht
Change-Id: I0dd0f9a9c2003fb887e076127e7f825fd3289c76
2024-05-29util.{hh,cc}: Split out terminal.{hh,cc}Tom Hubrecht
Change-Id: I9de2296b4012d50f540124001d54d6ca3be4c6da
2024-05-28util.{hh,cc}: Split out environment-variables.{hh,cc}Tom Hubrecht
Change-Id: Icff0aa33fda5147bd5dbe256a0b9d6a6c8a2c3f6
2024-03-29Fix various clang-tidy lintsJade Lovelace
* some things that can throw are marked noexcept yet the linter seems to think not. Maybe they can't throw in practice. I would rather not have the UB possibility in pretty obvious cold paths. * various default-case-missing complaints * a fair pile of casts from integer to character, which are in fact deliberate. * an instance of <https://clang.llvm.org/extra/clang-tidy/checks/bugprone/move-forwarding-reference.html> * bugprone-not-null-terminated-result on handing a string to curl in chunks of bytes. our usage is fine. * reassigning a unique_ptr by CRIMES instead of using release(), then using release() and ignoring the result. wild. let's use release() for its intended purpose. Change-Id: Ic3e7affef12383576213a8a7c8145c27e662513d
2024-03-17Delete hasPrefix and hasSuffix from the codebaseJade Lovelace
These now have equivalents in the standard lib in C++20. This change was performed with a custom clang-tidy check which I will submit later. Executed like so: ninja -C build && run-clang-tidy -checks='-*,nix-*' -load=build/libnix-clang-tidy.so -p .. -fix ../tests | tee -a clang-tidy-result Change-Id: I62679e315ff9e7ce72a40b91b79c3e9fc01b27e9
2024-03-09libexpr: Support structured error classeseldritch horrors
While preparing PRs like #9753, I've had to change error messages in dozens of code paths. It would be nice if instead of EvalError("expected 'boolean' but found '%1%'", showType(v)) we could write TypeError(v, "boolean") or similar. Then, changing the error message could be a mechanical refactor with the compiler pointing out places the constructor needs to be changed, rather than the error-prone process of grepping through the codebase. Structured errors would also help prevent the "same" error from having multiple slightly different messages, and could be a first step towards error codes / an error index. This PR reworks the exception infrastructure in `libexpr` to support exception types with different constructor signatures than `BaseError`. Actually refactoring the exceptions to use structured data will come in a future PR (this one is big enough already, as it has to touch every exception in `libexpr`). The core design is in `eval-error.hh`. Generally, errors like this: state.error("'%s' is not a string", getAttrPathStr()) .debugThrow<TypeError>() are transformed like this: state.error<TypeError>("'%s' is not a string", getAttrPathStr()) .debugThrow() The type annotation has moved from `ErrorBuilder::debugThrow` to `EvalState::error`. (cherry picked from commit c6a89c1a1659b31694c0fbcd21d78a6dd521c732) Change-Id: Iced91ba4e00ca9e801518071fb43798936cbd05a
2024-03-05Merge pull request #9634 from 9999years/combine-abstract-pos-and-poseldritch horrors
Combine `AbstractPos`, `PosAdapter`, and `Pos` (cherry picked from commit 113499d16fc87d53b73fb62fe6242154909756ed) === this is a bit cursed because originally it was based on InputAccessor code that we don't have and moved/patched features we likewise don't have (fetchToStore caching, all the individual accessors, ContentAddressMethod). the commit is adjusted accordingly to match (remove caching, ignore accessors, use FileIngestionMethod). note that `state.rootPath . CanonPath == abs` and computeStorePathForPath works relative to cwd, so the slight rewrite in the moved fetchToStore is legal. Change-Id: I05fd340c273f0bcc8ffabfebdc4a88b98083bce5
2023-09-09Print parent activity field in json logmaralorn
2023-08-11SimpleLogger::log: fix unintended fallthroughYorick van Pelt
2023-04-03Enable -Werror=switch-enumRobert Hensing
switch statements must now match all enum values or disable the warning. Explicit is good. This has helped us find two bugs, after solving another one by debugging. From now on, adding to an enum will raise errors where they are not explicitly handled, which is good for productivity, and helps us decide the correct behavior in all usages. Notably still excluded from this though are the cases where the warning is disabled by local pragmas. fromTOML.cc did not build despite a top-level pragma, so I've had to resort to a makefile solution for that.
2023-04-03Add explicit case statements where -Wswitch-enum would report themRobert Hensing
2023-04-03Fix systemd logging for lvlNotice: eqv to lvlInfo, not lvlVomitRobert Hensing
2023-03-02Remove FormatOrString and remaining uses of format()Eelco Dolstra
2023-03-02Logger::writeToStdout(): Use writeFull()Eelco Dolstra
This ensures that write errors do not get ignored.
2022-12-13Introduce AbstractPosEelco Dolstra
This makes the position object used in exceptions abstract, with a method getSource() to get the source code of the file in which the error originated. This is needed for lazy trees because source files don't necessarily exist in the filesystem, and we don't want to make libutil depend on the InputAccessor type in libfetcher.
2022-12-07Trivial changes from the lazy-trees branchEelco Dolstra
2022-02-28libstore/derivation-goal: avoid double-parsing of JSON messagesMaximilian Bosch
To avoid that JSON messages are parsed twice in case of remote builds with `ssh-ng://`, I split up the original `handleJSONLogMessage` into three parts: * `parseJSONMessage(const std::string&)` checks if it's a message in the form of `@nix {...}` and tries to parse it (and prints an error if the parsing fails). * `handleJSONLogMessage(nlohmann::json&, ...)` reads the fields from the message and passes them to the logger. * `handleJSONLogMessage(const std::string&, ...)` behaves as before, but uses the two functions mentioned above as implementation. In case of `ssh-ng://`-logs the first two methods are invoked manually.
2022-02-25Remove std::string alias (for real this time)Eelco Dolstra
Also use std::string_view in a few more places.
2021-09-14ANSI_YELLOW -> ANSI_WARNINGEelco Dolstra
2021-08-22Replace invalid characters in json loggerYaroslav Bolyukin
Fixes #5159 Signed-off-by: Yaroslav Bolyukin <iam@lach.pw>
2021-07-01Respect TERM=dumb more consistentlyYestin L. Harrison
2021-01-21Improve error formattingEelco Dolstra
Changes: * The divider lines are gone. These were in practice a bit confusing, in particular with --show-trace or --keep-going, since then there were multiple lines, suggesting a start/end which wasn't the case. * Instead, multi-line error messages are now indented to align with the prefix (e.g. "error: "). * The 'description' field is gone since we weren't really using it. * 'hint' is renamed to 'msg' since it really wasn't a hint. * The error is now printed *before* the location info. * The 'name' field is no longer printed since most of the time it wasn't very useful since it was just the name of the exception (like EvalError). Ideally in the future this would be a unique, easily googleable error ID (like rustc). * "trace:" is now just "…". This assumes error contexts start with something like "while doing X". Example before: error: --- AssertionError ---------------------------------------------------------------------------------------- nix at: (7:7) in file: /home/eelco/Dev/nixpkgs/pkgs/applications/misc/hello/default.nix 6| 7| x = assert false; 1; | ^ 8| assertion 'false' failed ----------------------------------------------------- show-trace ----------------------------------------------------- trace: while evaluating the attribute 'x' of the derivation 'hello-2.10' at: (192:11) in file: /home/eelco/Dev/nixpkgs/pkgs/stdenv/generic/make-derivation.nix 191| // (lib.optionalAttrs (!(attrs ? name) && attrs ? pname && attrs ? version)) { 192| name = "${attrs.pname}-${attrs.version}"; | ^ 193| } // (lib.optionalAttrs (stdenv.hostPlatform != stdenv.buildPlatform && !dontAddHostSuffix && (attrs ? name || (attrs ? pname && attrs ? version)))) { Example after: error: assertion 'false' failed at: (7:7) in file: /home/eelco/Dev/nixpkgs/pkgs/applications/misc/hello/default.nix 6| 7| x = assert false; 1; | ^ 8| … while evaluating the attribute 'x' of the derivation 'hello-2.10' at: (192:11) in file: /home/eelco/Dev/nixpkgs/pkgs/stdenv/generic/make-derivation.nix 191| // (lib.optionalAttrs (!(attrs ? name) && attrs ? pname && attrs ? version)) { 192| name = "${attrs.pname}-${attrs.version}"; | ^ 193| } // (lib.optionalAttrs (stdenv.hostPlatform != stdenv.buildPlatform && !dontAddHostSuffix && (attrs ? name || (attrs ? pname && attrs ? version)))) {
2020-10-28Capitalize JSON for consistencyMatthew Kenigsberg
2020-10-06Remove static variable name clashesEelco Dolstra
This was useful for an experiment with building Nix as a single compilation unit. It's not very useful otherwise but also doesn't hurt...
2020-07-26libutil/logging: extend `internal-json` logger to make it more machine-readableMaximilian Bosch
The new error-format is pretty nice from a UX point-of-view, however it's fairly hard to parse the output e.g. for editor plugins such as vim-ale[1] that use `nix-instantiate --parse` to determine syntax errors in Nix expression files. This patch extends the `internal-json` logger by adding the fields `line`, `column` and `file` to easily locate an error in a file and the field `raw_msg` which contains the error-message itself without code-lines and additional helpers. An exemplary output may look like this: ``` [nix-shell]$ ./inst/bin/nix-instantiate ~/test.nix --log-format minimal {"action":"msg","column":1,"file":"/home/ma27/test.nix","level":0,"line":4,"raw_msg":"syntax error, unexpected IF, expecting $end","msg":"<full error-msg with code-lines etc>"} ``` [1] https://github.com/dense-analysis/ale
2020-07-08Fix 'got unknown message type 1 from Nix daemon'Eelco Dolstra
Example: $ nix-build -E 'with import <nixpkgs> {}; runCommand "foo" { x = runCommand "bar" {} "exit 1"; } "echo foo; exit 1"' warning: unknown setting 'auto-allocate-uids' these 2 derivations will be built: /nix/store/v4fbdbhcdi949929a67g8farwf72zgam-bar.drv /nix/store/k4fsvrjl7cp2xpz7927iv7g0dqj1zyhs-foo.drv warning: unknown setting 'auto-allocate-uids' building '/nix/store/v4fbdbhcdi949929a67g8farwf72zgam-bar.drv'... error: --- Error ----------------------------------------------------------------------------------------------------------------------------------------------------------------- nix-daemon builder for '/nix/store/v4fbdbhcdi949929a67g8farwf72zgam-bar.drv' failed with exit code 1 error: --- Error ------------------------------------------------------------------------------------------------------------------------------------------------------------------ nix-build got unknown message type 1 from Nix daemon
2020-07-02move showTrace to new loggerSettingsBen Burdette
2020-07-01non-pos trace testBen Burdette
2020-06-30comments and cleanupBen Burdette
2020-06-29showTrace flag in loggersBen Burdette
2020-06-15Remove trailing whitespaceEelco Dolstra
2020-06-11Merge remote-tracking branch 'upstream/master' into errors-phase-2Ben Burdette
2020-06-08Unify the printing of the logs between bar-with-logs and rawregnat
Make the printing of the build logs systematically go through the logger, and replicate the behavior of `no-build-output` by having two different loggers (one that prints the build logs and one that doesn't)
2020-06-08Make the logger customisableregnat
Add a new `--log-format` cli argument to change the format of the logs. The possible values are - raw (the default one for old-style commands) - bar (the default one for new-style commands) - bar-with-logs (equivalent to `--print-build-logs`) - internal-json (the internal machine-readable json format)
2020-06-02elide the 'ErrorInfo' in logError and logWarning callsBen Burdette
2020-05-13change status messages to info levelBen Burdette
2020-05-12remove unused extra json fieldsBen Burdette
2020-05-11Merge branch 'master' into errors-phase-2Ben Burdette
2020-05-08add pos to errorinfo, remove from hintsBen Burdette
2020-05-06Revert "Merge pull request #3558 from LnL7/ssh-ng-stderr"Eelco Dolstra
This reverts commit 3ebfbecdd187002569257f7cb183bf9e0b39af1e, reversing changes made to c089c52d5f1cff888552f485775b74226dcbe618. https://github.com/NixOS/nix/pull/3558
2020-05-02logging: handle build log lines in simple loggerDaiderd Jordan
The raw stderr output isn't logged anymore so the build logs need to be printed by the default logger in order for the old commands like nix-build to still show build output.
2020-04-29uncrustify formattingBen Burdette
2020-04-17demoing other error levels than warn/error; rename line and file fields in ↵Ben Burdette
errPos
2020-04-17logError, logWarning; Logger functions; switch to Verbosity enumBen Burdette
2020-04-16Logger: Add method for writing to stdoutEelco Dolstra
Usually this just writes to stdout, but for ProgressBar, we need to clear the current line, write the line to stdout, and then redraw the progress bar. (cherry picked from commit 696c026006a6ac46adc990ed5cb0f31535bac076)
2020-04-08DataTransfer -> FileTransferNikola Knezevic
2020-04-08actDownload -> actDataTransferNikola Knezevic
2020-02-01Show "warning:" in yellow instead of redEelco Dolstra