Skip to content

Calibre installation failure on testing stops plinth process

Test: Install calibre on a fresh testing container.

Calibre triggers a restart of plinth's cherrypy server.

DEBUG plinth.setup         Creating operation to setup app: calibre
INFO plinth.operation     Operation: calibre: Installing app: added
DEBUG plinth.operation     Operation: calibre: Installing app: scheduling
INFO plinth.operation     Operation: calibre: Installing app: running
INFO plinth.setup         Setup run: calibre
INFO plinth.actions       » plinth..is_package_manager_busy()
INFO plinth.package       Running install for app - calibre, packages - \['calibre'\]
INFO plinth.actions       » plinth..update()
INFO plinth.actions       » plinth..install(app_id="calibre", packages=\["calibre"\], skip_recommends=false, force_configuration=null, reinstall=false, force_missing_configuration=false)
INFO cherrypy.error       \[22/Aug/2025:12:43:32\] ENGINE Restarting because /usr/lib/python3.13/http/cookiejar.py changed.
INFO cherrypy.error       \[22/Aug/2025:12:43:32\] ENGINE Stopped thread 'Autoreloader'.
INFO cherrypy.error       \[22/Aug/2025:12:43:32\] ENGINE Bus STOPPING
INFO cherrypy.error       \[22/Aug/2025:12:43:33\] ENGINE HTTP Server cherrypy.\_cpwsgi_server.CPWSGIServer(('127.0.0.1', 8000)) shut down
INFO plinth.glib          Exiting glib main loop
INFO cherrypy.error       \[22/Aug/2025:12:43:33\] ENGINE Bus STOPPED
INFO cherrypy.error       \[22/Aug/2025:12:43:33\] ENGINE Bus EXITING
INFO cherrypy.error       \[22/Aug/2025:12:43:33\] ENGINE Bus EXITED
INFO plinth.glib          Glib main loop thread exited.
INFO cherrypy.error       \[22/Aug/2025:12:43:33\] ENGINE Waiting for child threads to terminate...
INFO cherrypy.error       \[22/Aug/2025:12:43:33\] ENGINE Waiting for thread Thread-40 (\_catch_thread_errors).

Notification: Error installing app: Expecting value: line 1 column 1 (char 0)

The server was able to recover by itself, but calibre installation failed.

Stacktrace

    INFO plinth.package       Running install for app - calibre, packages - ['calibre']
    INFO plinth.actions       » plinth..update() 
    INFO plinth.actions       » plinth..install(app_id="calibre", packages=["calibre"], skip_recommends=false, force_configuration=null, reinstall=false, force_missing_configuration=false) 
    INFO cherrypy.error       [22/Aug/2025:12:43:32] ENGINE Restarting because /usr/lib/python3.13/http/cookiejar.py changed.
    INFO cherrypy.error       [22/Aug/2025:12:43:32] ENGINE Stopped thread 'Autoreloader'.
    INFO cherrypy.error       [22/Aug/2025:12:43:32] ENGINE Bus STOPPING
    INFO cherrypy.error       [22/Aug/2025:12:43:33] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('127.0.0.1', 8000)) shut down
    INFO plinth.glib          Exiting glib main loop
    INFO cherrypy.error       [22/Aug/2025:12:43:33] ENGINE Bus STOPPED
    INFO cherrypy.error       [22/Aug/2025:12:43:33] ENGINE Bus EXITING
    INFO cherrypy.error       [22/Aug/2025:12:43:33] ENGINE Bus EXITED
    INFO plinth.glib          Glib main loop thread exited.
    INFO cherrypy.error       [22/Aug/2025:12:43:33] ENGINE Waiting for child threads to terminate...
    INFO cherrypy.error       [22/Aug/2025:12:43:33] ENGINE Waiting for thread Thread-40 (_catch_thread_errors).
   ERROR plinth.actions       Error decoding action return value plinth..install(*[], **{'app_id': 'calibre', 'packages': ['calibre'], 'skip_recommends': False, 'force_configuration': None, 'reinstall': False, 'force_missing_configuration': False})
   ERROR plinth.package       Error installing package: Expecting value: line 1 column 1 (char 0)
Traceback (most recent call last):
  File "/freedombox/plinth/package.py", line 408, in install
    privileged.install(**kwargs)
    ~~~~~~~~~~~~~~~~~~^^^^^^^^^^
  File "/freedombox/plinth/actions.py", line 76, in wrapper
    return _run_privileged_method(func, module_name, action_name, args,
                                  kwargs)
  File "/freedombox/plinth/actions.py", line 85, in _run_privileged_method
    return _run_privileged_method_on_server(func, module_name, action_name,
                                            list(args), dict(kwargs))
  File "/freedombox/plinth/actions.py", line 152, in _run_privileged_method_on_server
    return _wait_for_server_response(*args)
  File "/freedombox/plinth/actions.py", line 162, in _wait_for_server_response
    return_value = _read_from_server(client_socket)
  File "/freedombox/plinth/actions.py", line 107, in _read_from_server
    return json.loads(response)
           ~~~~~~~~~~^^^^^^^^^^
  File "/usr/lib/python3.13/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ~~~~~~~~~~~~~~~~~~~~~~~^^^
  File "/usr/lib/python3.13/json/decoder.py", line 345, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.13/json/decoder.py", line 363, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
    INFO plinth.setup         Setup completed: calibre: Error installing app: {exception} Expecting value: line 1 column 1 (char 0)
   DEBUG plinth.operation     Operation: calibre: Installing app: on_complete called

Calibre is installed successfully on a retry.

I can see the setup process of some essential system apps running when calibre installation was triggered, i.e. I attempted to install an app immediately after first boot. It's possible that the package manager was busy at the time.