| Age | Commit message (Collapse) | Author |
|---|
|
SimpleLogger is not fully thread-safe, and all loggers that wrap it are
also not safe accordingly. this does not affect much, but in rare cases
it can cause interleaving of messages on stderr when used with the json
or raw log formats. the fix applied here is a bit of a hack, but fixing
this properly requires rearchitecting the logger infrastructure. nested
loggers are not the most natural abstraction here, and it is biting us.
Change-Id: Ifbf34fe1e85c60e73b59faee50e7411c7b5e7c12
|
|
Activities can set display attributes in their log output using the "Select
Graphics Rendition" functionality. To prevent interfering with subsequent text
displayed, these should be reset after writing the log line. The multiline
progress bar neglected to do this, resulting for example in a colorised
"building …" header in the next line. Reset the attributes properly, like the
standard progress bar already does.
Change-Id: I1dc69f4a1d747a76b83e8721a72d9bb0e5554488
|
|
not printing activities at all when no progress information is available
hides *all* progress information from e.g. flake show. this is not ideal
and needs to be fixed, but the fix *still* has problems with flake show:
in multiline mode we will overwrite all useful flake show output as soon
as the progress bar is redrawn. flake show output is also mangled in any
number of other situations (like -v being set), so we should probably be
not too worried about it and fix progress reporting properly another day
Change-Id: I6d39d670e261bbae00560b6a8e15dec8e16b35c4
|
|
Previously, the progress bar had two subtly different states in which the bar
would not actually render, both with their own shortcomings: inactive (which
was irreversible) and paused (reversible, but swallowing logs). Furthermore,
there was no way of resetting the statistics, so a very bad solution was
implemented (243c0f18dae2a08ea0e46f7ff33277c63f7506d7) that would create a new
logger for each line of the repl, leaking the previous one and discarding the
value of printBuildLogs. Finally, if stderr was not attached to a TTY, the
update thread was started even though the logger was not active, violating the
invariant required by the destructor (which is not observed because the logger
is leaked).
In this commit, the two aforementioned states are unified into a single one,
which can be exited again, correctly upholds the invariant that the update
thread is only running while the progress bar is active, and does not swallow
logs. The latter change in behavior is not expected to be a problems in the
rare cases where the paused state was used before, since other loggers (like
the simple one) don't exhibit it anyway. The startProgressBar/stopProgressBar
API is removed due to being a footgun, and a new method for properly resetting
the progress is added.
Co-Authored-By: Qyriad <qyriad@qyriad.me>
Change-Id: I2b7c3eb17d439cd0c16f7b896cfb61239ac7ff3a
|
|
this most notably affects `nix eval`: if there is no progress bar to be
shown and no activities going on we should not print anything at all. a
progress bar with no activities would print a bunch of terminal escapes
*and a space*, which is not helpful in simple cases like nix eval -E 1.
notably this does *not* affect nix eval called on non-terminal outputs,
but it is slightly confusing nevertheless (and not difficult to avoid).
fixes https://git.lix.systems/lix-project/lix/issues/424
Change-Id: Iee793c79ba5a485d6606e0d292ed2eae6dfb7216
|
|
Change-Id: Ib4b42ebea290ee575294df6b2f17a38a5d850b80
|
|
This is primarily for readability, but iwrc chaining std::string's
operator+ is also pretty scuffed performance-wise, and this was doing a
lot of operator+ chainging.
Change-Id: I9f25235df153eb2bbb491f1ff7ebbeed9a8ec985
|
|
Add the log-formats `multiline` and `multiline-with-logs` which offer
multiple current active building status lines.
Change-Id: Idd8afe62f8591b5d8b70e258c5cefa09be4cab03
|
|
Change-Id: Ica9e2ec41d99eaa196a0d535501edf45c589b2b6
|
|
Binaries were identical before and after this commit on our machine
Change-Id: I6f8bfbe3298d6c5f43d5702c7a1e05cb180226cc
|
|
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
|
|
Change-Id: Ic1f68e6af658e94ef7922841dd3ad4c69551ef56
|
|
Change-Id: I9de2296b4012d50f540124001d54d6ca3be4c6da
|
|
this was caused by the use of std::chrono::duration::max() which gets
multiplied by some ratio to calculate nanoseconds to wait. then, it
explodes because that is a signed integer overflow. this was definitely
a bug.
error below:
/nix/store/fdiknsmnnczx6brsbppyljcs9hqckawk-gcc-12.3.0/include/c++/12.3.0/bits/chrono.h:225:38: runtime error: signed integer overflow: 9223372036854775807 * 1000000 cannot be represented in type 'long'
#0 0x736d376b2b69 in std::chrono::duration<long, std::ratio<1l, 1000000000l>> std::chrono::__duration_cast_impl<std::chrono:
:duration<long, std::ratio<1l, 1000000000l>>, std::ratio<1000000l, 1l>, long, false, true>::__cast<long, std::ratio<1l, 1000l>>(
std::chrono::duration<long, std::ratio<1l, 1000l>> const&) /nix/store/fdiknsmnnczx6brsbppyljcs9hqckawk-gcc-12.3.0/include/c++/12
.3.0/bits/chrono.h:225:38
#1 0x736d376b2b69 in std::enable_if<__is_duration<std::chrono::duration<long, std::ratio<1l, 1000000000l>>>::value, std::chr
ono::duration<long, std::ratio<1l, 1000000000l>>>::type std::chrono::duration_cast<std::chrono::duration<long, std::ratio<1l, 10
00000000l>>, long, std::ratio<1l, 1000l>>(std::chrono::duration<long, std::ratio<1l, 1000l>> const&) /nix/store/fdiknsmnnczx6brs
bppyljcs9hqckawk-gcc-12.3.0/include/c++/12.3.0/bits/chrono.h:270:9
#2 0x736d376b2b69 in std::enable_if<__is_duration<std::chrono::duration<long, std::ratio<1l, 1000000000l>>>::value, std::chr
ono::duration<long, std::ratio<1l, 1000000000l>>>::type std::chrono::ceil<std::chrono::duration<long, std::ratio<1l, 1000000000l
>>, long, std::ratio<1l, 1000l>>(std::chrono::duration<long, std::ratio<1l, 1000l>> const&) /nix/store/fdiknsmnnczx6brsbppyljcs9
hqckawk-gcc-12.3.0/include/c++/12.3.0/bits/chrono.h:386:14
#3 0x736d376b2b69 in std::cv_status std::condition_variable::wait_for<long, std::ratio<1l, 1000l>>(std::unique_lock<std::mut
ex>&, std::chrono::duration<long, std::ratio<1l, 1000l>> const&) /nix/store/fdiknsmnnczx6brsbppyljcs9hqckawk-gcc-12.3.0/include/
c++/12.3.0/condition_variable:164:6
#4 0x736d376b1ee9 in std::cv_status nix::Sync<nix::ProgressBar::State, std::mutex>::Lock::wait_for<long, std::ratio<1l, 1000
l>>(std::condition_variable&, std::chrono::duration<long, std::ratio<1l, 1000l>> const&) /home/jade/lix/lix/src/libutil/sync.hh:
65:23
#5 0x736d376b1ee9 in nix::ProgressBar::ProgressBar(bool)::'lambda'()::operator()() const /home/jade/lix/lix/src/libmain/prog
ress-bar.cc:99:27
#6 0x736d36de25c2 in execute_native_thread_routine (/nix/store/a3zlvnswi1p8cg7i9w4lpnvaankc7dxx-gcc-12.3.0-lib/lib/libstdc++
.so.6+0xe05c2)
#7 0x736d36b6b0e3 in start_thread (/nix/store/1zy01hjzwvvia6h9dq5xar88v77fgh9x-glibc-2.38-44/lib/libc.so.6+0x8b0e3) (BuildId
: 287831bffdbdde0ec25dbd021d12bdfc0ab9f5ff)
#8 0x736d36bed5e3 in __clone (/nix/store/1zy01hjzwvvia6h9dq5xar88v77fgh9x-glibc-2.38-44/lib/libc.so.6+0x10d5e3) (BuildId: 28
7831bffdbdde0ec25dbd021d12bdfc0ab9f5ff)
SUMMARY: UndefinedBehaviorSanitizer: undefined-behavior /nix/store/fdiknsmnnczx6brsbppyljcs9hqckawk-gcc-12.3.0/include/c++/12.3.
0/bits/chrono.h:225:38 in
Change-Id: Ia0303242cdfd5d49385ae9e99718d709625a4633
|
|
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
|
|
Virtual methods are no longer valid once the derived destructor has
run. This means the compiler is free to optimize them to be
non-virtual.
Found using clang-tidy
|
|
Check that nix copy can copy stuff, refuses to copy unsigned paths by
default, and doesn't hide the ssh password prompt.
|
|
Add new virtual methods pause and resume to the Logger class, and
implement them in ProgressBar to allow to pause the bar refreshing.
|
|
|
|
Trivial changes from the lazy-trees branch
|
|
|
|
These only functioned if a very narrow combination of conditions held:
- The result path does not yet exist (--check did not result in
repeated builds), AND
- The result path is not available from any configured substituters, AND
- No remote builders that can build the path are available.
If any of these do not hold, a derivation would be built 0 or 1 times
regardless of the repeat option. Thus, remove it to avoid confusion.
|
|
|
|
This was caused by -L calling setLogFormat() again, which caused the
creation of a new progress bar without destroying the old one. So we
had two progress bars clobbering each other.
We should change 'logger' to be a smart pointer, but I'll do that in a
future PR.
Fixes #6931.
|
|
Some activities are numerous but usually very short (e.g. copying a
source file to the store) which would cause a lot of flickering. So
only show activities that have been running for at least 10 ms.
|
|
Fix some heap-use-after-free in progress-bar.cc
These are somewhat tricky failures here due to temporary variable
creation and string_view
|
|
Doing it as a side-effect of calling LocalStore::makeStoreWritable()
is very ugly.
Also, make sure that stopping the progress bar joins the update
thread, otherwise that thread should be unshared as well.
|
|
|
|
This makes its behaviour consistent with SimpleLogger.
|
|
|
|
When running `nix build -L` it can be fairly hard to read the output if
the build program intentionally renders whitespace on the left. A
typical example is `g++` displaying compilation errors.
With this patch, the whitespace on the left is retained to make the log
more readable:
```
foo> no configure script, doing nothing
foo> building
foo> foobar.cc: In function 'int main()':
foo> foobar.cc:5:5: error: 'wrong_func' was not declared in this scope
foo> 5 | wrong_func(1);
foo> | ^~~~~~~~~~
error: --- Error ------------------------------------------------------------------------------------- nix
error: --- Error --- nix-daemon
builder for '/nix/store/i1q76cw6cyh91raaqg5p5isd1l2x6rx2-foo-1.0.drv' failed with exit code 1
```
|
|
When having a message like `waiting for a machine to build X` and
building with `nix build -L`, the log-prefix is always colored yellow[1]
on a small terminal-width as everything (including the ANSI color-reset) is
stripped away.
To work around that problem, this patch explicitly adds an `ANSI_NORMAL`
to the end of the line.
[1] https://imgur.com/a/FjtJOk3
|
|
|
|
|
|
|
|
|
|
These are now shown in the progress bar.
Closes #3577.
|
|
|
|
|
|
|
|
Needed so that we can include it as a logger in loggers.cc without
adding a dependency on nix
This also requires moving names.hh to libutil to prevent a circular
dependency between libmain and libexpr
|
