Fail with JSONDecodeErrorwhen the derivations are already built, rather than printing a comprehensive error message to user

[yvan-sraka]

Hello @Kha,

Thanks for your works, it looks great but, I try to make this project works with nix (version 2.8.1), and a fail on the default flake template:

yvan@X230 ~ % nix shell "github:Kha/nixprof"
yvan@X230 ~ % mkdir test
yvan@X230 ~ % cd test
yvan@X230 ~/test % nix flake init
wrote: /home/yvan/test/flake.nix
yvan@X230 ~/test % nixprof record "nix build"
yvan@X230 ~/test % nixprof report            
Traceback (most recent call last):
  File "/nix/store/m65kh5rjfbc634p7jg7xp7kzjfysjf1m-nixprof/bin/.nixprof-wrapped", line 9, in <module>
    sys.exit(nixprof())
  File "/nix/store/s6a73ssai10wpz50nnk2cy3k48wydl05-python3.8-click-8.0.1/lib/python3.8/site-packages/click/core.py", line 1137, in __call__
    return self.main(*args, **kwargs)
  File "/nix/store/s6a73ssai10wpz50nnk2cy3k48wydl05-python3.8-click-8.0.1/lib/python3.8/site-packages/click/core.py", line 1062, in main
    rv = self.invoke(ctx)
  File "/nix/store/s6a73ssai10wpz50nnk2cy3k48wydl05-python3.8-click-8.0.1/lib/python3.8/site-packages/click/core.py", line 1668, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/nix/store/s6a73ssai10wpz50nnk2cy3k48wydl05-python3.8-click-8.0.1/lib/python3.8/site-packages/click/core.py", line 1404, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/nix/store/s6a73ssai10wpz50nnk2cy3k48wydl05-python3.8-click-8.0.1/lib/python3.8/site-packages/click/core.py", line 763, in invoke
    return __callback(*args, **kwargs)
  File "/nix/store/m65kh5rjfbc634p7jg7xp7kzjfysjf1m-nixprof/lib/python3.8/site-packages/nixprof.py", line 112, in report
    drv_data = json.loads(subprocess.run(["nix", "--experimental-features", "nix-command", "path-info", "--json", "--derivation"] + list(g), capture_output=True, check=True).stdout)
  File "/nix/store/2nhfiak8a30vw67mxksc2kdb69np2jcw-python3-3.8.9/lib/python3.8/json/__init__.py", line 357, in loads
    return _default_decoder.decode(s)
  File "/nix/store/2nhfiak8a30vw67mxksc2kdb69np2jcw-python3-3.8.9/lib/python3.8/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/nix/store/2nhfiak8a30vw67mxksc2kdb69np2jcw-python3-3.8.9/lib/python3.8/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

Here's the content of the generated nixprof.log:

[0.000020] @nix {"action":"start","id":295781512773632,"level":4,"text":"copying '/home/yvan/test'","type":0}
[0.010800] @nix {"action":"stop","id":295781512773632}
[0.013265] @nix {"action":"msg","level":1,"msg":"\u001b[35;1mwarning:\u001b[0m creating lock file '/home/yvan/test/flake.lock'"}
[0.013330] @nix {"action":"start","id":295781512773633,"level":4,"text":"copying '/home/yvan/test'","type":0}
[0.014548] @nix {"action":"stop","id":295781512773633}
[0.356075] @nix {"action":"start","id":5617817223168,"level":6,"text":"querying info about missing paths","type":0}
[0.356168] @nix {"action":"stop","id":5617817223168}
[0.356206] @nix {"action":"start","id":5617817223169,"level":0,"text":"","type":102}
[0.356236] @nix {"action":"start","id":5617817223170,"level":0,"text":"","type":104}
[0.356266] @nix {"action":"start","id":5617817223171,"level":0,"text":"","type":103}
[0.356298] @nix {"action":"result","fields":[0,1,0,0],"id":5617817223170,"type":105}
[0.356328] @nix {"action":"result","fields":[0,0,0,0],"id":5617817223171,"type":105}
[0.356357] @nix {"action":"result","fields":[101,0],"id":5617817223169,"type":106}
[0.356384] @nix {"action":"result","fields":[100,0],"id":5617817223169,"type":106}
[0.356411] @nix {"action":"start","id":5617817223172,"level":6,"text":"querying info about missing paths","type":0}
[0.356439] @nix {"action":"stop","id":5617817223172}
[0.369414] @nix {"action":"result","fields":[0,0,0,0],"id":5617817223170,"type":105}
[0.369466] @nix {"action":"result","fields":[0,0,0,0],"id":5617817223171,"type":105}
[0.369484] @nix {"action":"result","fields":[101,0],"id":5617817223169,"type":106}
[0.369505] @nix {"action":"result","fields":[100,0],"id":5617817223169,"type":106}
[0.369533] @nix {"action":"stop","id":5617817223171}
[0.369554] @nix {"action":"stop","id":5617817223170}
[0.369570] @nix {"action":"stop","id":5617817223169}
[0.399775] 0.30user 0.05system 0:00.43elapsed 80%CPU (0avgtext+0avgdata 84844maxresident)k
[0.399852] 0inputs+72outputs (0major+17342minor)pagefaults 0swaps

Do you have any clue of what is happening here?

Best, Yvan

[Kha]

Your log does not seem to actually contain a derivation build ("action":"start","type":105), which apparently crashes nixprof. You need to make sure the derivations are not already built, see https://github.com/Kha/nixprof#usage.

[yvan-sraka]

Okay, makes sense! I will edit the issue 😉