asciinema/asciinema

asciinema 2.3 gives me a JSONDecodeError when run as a subprocess

simonmichael opened this issue · 8 comments

simonmichael commented

Cc'ing from chat: at simonmichael/hledger#2094 we see some strange new behaviour with asciinema 2.3: running it as a subprocess, it plays the cast successfully, but then gives the traceback below. When I run the same asciinema command myself at the CLI, this doesn't happen. Running asciinema 2.2 as a subprocess also works normally.

Traceback (most recent call last):
  File "/opt/homebrew/bin/asciinema", line 8, in <module>
    sys.exit(main())
             ^^^^^^
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/__main__.py", line 254, in main
    code = command.execute()
           ^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/commands/play.py", line 33, in execute
    code = self.play()
           ^^^^^^^^^^^
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/commands/play.py", line 44, in play
    self.player.play(
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/player.py", line 71, in play
    self._play(
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/player.py", line 187, in _play
    time_, event_type, text = next_event()
                              ^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/player.py", line 127, in next_event
    return events_iter.__next__()
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/asciicast/events.py", line 41, in <genexpr>
    return ([delay / speed, type_, data] for delay, type_, data in events)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/asciicast/events.py", line 21, in to_absolute_time
    for frame in events:
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/asciicast/events.py", line 31, in <genexpr>
    return (
           ^
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/asciicast/events.py", line 9, in to_relative_time
    for frame in events:
  File "/opt/homebrew/Cellar/asciinema/2.3.0/libexec/lib/python3.11/site-packages/asciinema/asciicast/v2.py", line 39, in events
    yield json.loads(line)
          ^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 2 column 1 (char 1)
ku1ik commented

I tried to reproduce this by running asciinema play as a subprocess in Python like this:

import subprocess
subprocess.run(['asciinema', 'play', 'demo.cast'])

But it works fine here.

Can you attach a file you're trying to play? Like the /tmp/hledger-cast1551302-0 from the issue in your repo.

ku1ik commented

Thanks. Using above Python subprocess example I couldn't reproduce it against the print.cast (I extracted actual asciicast from it with jq '.payload.blob.rawLines[]' --raw-output print.cast >print1.cast).

But I installed hledger and ran hledger demo 1 and got the error.

simonmichael commented

hledger demo 2 -s100 is a quicker reproducer. I have tried printing debug info and comparing 2.2.0 with 2.3.0, but haven't yet seen a difference other than the traceback.

simonmichael commented

I've been able to reproduce it this way: add an extra blank line at the end of the cast file - this causes 2.3.0 to give a decode error.

ku1ik commented

Yes, got to the same conclusion using git bisect, which points to this commit: f06e4a0

Previously it swallowed the actual problem with JSON decoding of blank line, and since I made the exception catching more directed in 2.3 this thing surfaced. The fix is simple and is on the way.

simonmichael commented

Thanks @ku1ik ! I have also fixed the newline-adding in hledger for folks who happen to have 2.3.0.