NixOS / nix

Nix, the purely functional package manager
https://nixos.org/
GNU Lesser General Public License v2.1
12.13k stars 1.47k forks source link

Build output wrapping strangely on nix 1.12 #1691

Closed catern closed 3 years ago

catern commented 6 years ago

This happens for any builds at all. Here is an example:

*** Downloading ‘http://cache.nixos.org/nar/0rg7ay0gq47g51fbvmrvm75dddg1nps3h3s3sw4s1gbg77rhlzpy.nar.xz’ to ‘/nix/store/vg0i8d25492xgighz1njszhlyxhrvns7-perl-libwww-perl-6.15’...
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                              D
load
Uploa
d   T
otal
   S
pent    Left  Speed
0     0
0
 0
  0
   0
      0

0 --
:--:
-- --:--:
-- -
-:-
-:--
    0
100 75184  100 75184    0     0   554k      0 --:--:--
--:--:-- --:--:--  560k
dtzWill commented 6 years ago

I've seen this as well, upon occasion.

I think this can be refined a bit in the following two ways, at least from what I can tell. Does this match your experiences, @catern ?

1) Using 1.12 with 1.11 daemon (1.12 daemon reports to the progress bar thing) 2) Only curl progress output does this, not output from build itself

I'm not sure if it's wrapping--offhand it looks more like it expects to be able to read a full line at a time or something, but instead gets partial lines? Mostly I mean that it doesn't exactly look like any "wrapping" behavior that would be intentionally created by curl :).

catern commented 6 years ago

I am using 1.12 with a 1.11 daemon, that's correct.

But I also see this with build output as well. Only when there is a delay between printing the start of a line and the rest of it, though. (I haven't tested this, I just noticed it happening on ./configure runs, where the configure test result gets put on the next line).

I think your guess is correct, I think this is due to Nix expecting to read a full line and only getting partial lines. Most build tools write line-at-a-time, and small writes are atomic, so that's usually fine, but I guess curl does not write line-at-a-time.

copumpkin commented 6 years ago

Happening to me too

catern commented 6 years ago

In case anyone wants to debug this, here's something I noticed in an unrelated investigation of nix-daemon (writing a protocol dissector for its protocol). It looks the stderr messages are already mangled when they come from nix-daemon:

< Container: 
    type = STDERR_NEXT
    data = Dloa (total 4)
< Container: 
    type = STDERR_NEXT
    data = d  Up (total 5)
< Container: 
    type = STDERR_NEXT
    data = load (total 4)
< Container: 
    type = STDERR_NEXT
    data =    T (total 4)
< Container: 
    type = STDERR_NEXT
    data = otal (total 4)
< Container: 
    type = STDERR_NEXT
    data =    S (total 4)
< Container: 
    type = STDERR_NEXT
    data = pent (total 4)

This is printed by Nix 1.11 as one STDERR_NEXT per line. I believe Nix 1.12 also prints one per line. Somewhat confusing...

stale[bot] commented 3 years ago

I marked this as stale due to inactivity. → More info

catern commented 3 years ago

I never figured out what was causing this, but I think it was just an issue with having a nix-daemon and nix client tools with different versions. 1.12 is now long out of date anyway.