search

mkuf / prind

print in docker - Deploy a containerized Klipper Stack for your 3D Printer
GNU General Public License v3.0
321 stars 82 forks source link

Moonraker crash after update #148

Closed tyler43636 closed 4 months ago

tyler43636 commented 4 months ago

I performed an update a few hours ago and now moonraker appears to be crashing every few seconds. A consistent experience across browsers is that the Mainsail or Fluidd interface will load, allow for full interaction with klipper (set temps, home axis, etc.) and then Mainsail or Fluidd will loose connection to moonraker and reload within a couple seconds.

Below is my moonraker log. Any ideas?

-------------------- Log Start | Thu Apr 11 10:01:16 2024 --------------------
platform: Linux-5.15.111-1-pve-x86_64-with-glibc2.36
data_path: /opt/printer_data
is_default_data_path: False
config_file: /opt/printer_data/config/moonraker.conf
startup_warnings: []
verbose: False
debug: False
asyncio_debug: False
is_backup_config: False
is_python_package: False
instance_uuid: 814d0179c6fd4eb9ad7248b6c6b79fa6
unix_socket_path: /opt/printer_data/comms/moonraker.sock
software_version: ?
log_file: /opt/printer_data/logs/moonraker.log
python_version: 3.11.8 (main, Mar 12 2024, 11:52:02) [GCC 12.2.0]
launch_args: /opt/venv/bin/python moonraker/moonraker/moonraker.py -d /opt/printer_data
msgspec_enabled: False
uvloop_enabled: False
2024-04-11 10:01:16,997 [confighelper.py:read_file()] - Configuration File '/opt/printer_data/config/moonraker.conf' parsed, total size: 439 B
2024-04-11 10:01:16,997 [server.py:add_log_rollover_item()] - 
#################### Moonraker Configuration ####################

[server]
host = 0.0.0.0
port = 7125
klippy_uds_address = /opt/printer_data/run/klipper.sock

[machine]
provider = systemd_cli
validate_service = False

[authorization]
trusted_clients = 
    0.0.0.0/0
cors_domains = 
    *

[octoprint_compat]

[history]

#################################################################
All Configuration Files:
/opt/printer_data/config/moonraker.conf
#################################################################
2024-04-11 10:01:17,062 [server.py:load_component()] - Component (secrets) loaded
2024-04-11 10:01:17,074 [server.py:load_component()] - Component (template) loaded
2024-04-11 10:01:17,077 [server.py:load_component()] - Component (klippy_connection) loaded
2024-04-11 10:01:17,717 [server.py:load_component()] - Component (application) loaded
2024-04-11 10:01:17,749 [server.py:load_component()] - Component (websockets) loaded
2024-04-11 10:01:17,890 [server.py:load_component()] - Component (dbus_manager) loaded
2024-04-11 10:01:17,909 [server.py:add_log_rollover_item()] - 
Database Versions: pylmdb = 1.4.1, lmdb = (0, 9, 29)
Unsafe Shutdown Count: 0
2024-04-11 10:01:17,915 [server.py:load_component()] - Component (database) loaded
2024-04-11 10:01:17,979 [file_manager.py:__init__()] - Using File System Observer: inotify
2024-04-11 10:01:17,985 [server.py:load_component()] - Component (file_manager) loaded
2024-04-11 10:01:18,005 [authorization.py:__init__()] - Authorization Configuration Loaded
Trusted Clients:
0.0.0.0/0
CORS Domains:
.*
2024-04-11 10:01:18,006 [server.py:load_component()] - Component (authorization) loaded
2024-04-11 10:01:18,012 [server.py:load_component()] - Component (klippy_apis) loaded
2024-04-11 10:01:18,091 [server.py:add_log_rollover_item()] - 
System Info:

***python***
  version: (3, 11, 8, 'final', 0)
  version_string: 3.11.8 (main, Mar 12 2024, 11:52:02) [GCC 12.2.0]

***cpu_info***
  cpu_count: 2
  bits: 64bit
  processor: x86_64
  cpu_desc: Intel(R) Celeron(R) J4005 CPU @ 2.00GHz
  serial_number: 
  hardware_desc: 
  model: 
  total_memory: 15980644
  memory_units: kB

***sd_info***

***distribution***
  name: Debian GNU/Linux 12 (bookworm)
  id: debian
  version: 12
  version_parts: {'major': '12', 'minor': '', 'build_number': ''}
  like: 
  codename: bookworm
  release_info: {}
  kernel_version: 5.15.111-1-pve

***virtualization***
  virt_type: none
  virt_identifier: none

***network***

***canbus***

***Allowed Services***
  klipper_mcu
  webcamd
  MoonCord
  KlipperScreen
  moonraker-telegram-bot
  moonraker-obico
  sonar
  crowsnest
  octoeverywhere
  ratos-configurator
2024-04-11 10:01:18,099 [server.py:load_component()] - Component (shell_command) loaded
2024-04-11 10:01:18,099 [machine.py:__init__()] - Using System Provider: systemd_cli
2024-04-11 10:01:18,102 [server.py:add_log_rollover_item()] - Module libcamera unavailble, import failed
2024-04-11 10:01:18,102 [server.py:load_component()] - Component (machine) loaded
2024-04-11 10:01:18,106 [server.py:load_component()] - Component (data_store) loaded
2024-04-11 10:01:18,112 [proc_stats.py:__init__()] - Unable to find 'vcgencmd', throttle checking disabled
2024-04-11 10:01:18,113 [server.py:load_component()] - Component (proc_stats) loaded
2024-04-11 10:01:18,115 [server.py:load_component()] - Component (job_state) loaded
2024-04-11 10:01:18,121 [server.py:load_component()] - Component (job_queue) loaded
2024-04-11 10:01:18,131 [server.py:load_component()] - Component (http_client) loaded
2024-04-11 10:01:18,141 [server.py:load_component()] - Component (announcements) loaded
2024-04-11 10:01:18,150 [server.py:load_component()] - Component (webcam) loaded
2024-04-11 10:01:18,155 [server.py:load_component()] - Component (extensions) loaded
2024-04-11 10:01:18,162 [server.py:load_component()] - Component (octoprint_compat) loaded
2024-04-11 10:01:18,171 [server.py:load_component()] - Component (history) loaded
2024-04-11 10:01:18,172 [server.py:_initialize_component()] - Performing Component Post Init: [dbus_manager]
2024-04-11 10:01:18,174 [dbus_manager.py:component_init()] - Unable to Connect to D-Bus
2024-04-11 10:01:18,174 [server.py:_initialize_component()] - Performing Component Post Init: [file_manager]
2024-04-11 10:01:18,175 [server.py:_initialize_component()] - Performing Component Post Init: [authorization]
2024-04-11 10:01:18,176 [server.py:_initialize_component()] - Performing Component Post Init: [machine]
2024-04-11 10:01:18,176 [machine.py:validation_init()] - Installation version in database up to date
2024-04-11 10:01:18,177 [machine.py:update_usb_ids()] - Fetching latest usb.ids file...
2024-04-11 10:01:18,191 [shell_command.py:_check_proc_success()] - Command (systemctl list-units --all --type=service --plain --no-legend) exited with return code 1
2024-04-11 10:01:18,726 [shell_command.py:_check_proc_success()] - Command (systemd-detect-virt) successfully finished
2024-04-11 10:01:18,743 [shell_command.py:_check_proc_success()] - Command (systemd-detect-virt --container) successfully finished
2024-04-11 10:01:18,743 [machine.py:check_virt_status()] - Virtualized Environment Detected, Type: container id: docker
2024-04-11 10:01:18,752 [machine.py:_find_public_ip()] - Detected Local IP: 192.168.112.7
2024-04-11 10:01:18,755 [webcam.py:_set_default_host_ip()] - Default public webcam address set: http://192.168.112.7
2024-04-11 10:01:18,785 [shell_command.py:_check_proc_success()] - Command (systemctl status 216055) exited with return code 1
2024-04-11 10:01:18,844 [machine.py:update_usb_ids()] - Writing usb.ids file...
2024-04-11 10:01:19,288 [machine.py:extract_service_info()] - Error extracting service info
Traceback (most recent call last):
  File "/opt/moonraker/moonraker/components/machine.py", line 1097, in extract_service_info
    resp: str = await self.shell_cmd.exec_cmd(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/moonraker/moonraker/components/shell_command.py", line 277, in run_with_response
    raise ShellCommandError(
moonraker.components.shell_command.ShellCommandError: Error running shell command: 'systemctl status 216055'
2024-04-11 10:01:19,289 [server.py:_initialize_component()] - Performing Component Post Init: [proc_stats]
2024-04-11 10:01:19,290 [server.py:_initialize_component()] - Performing Component Post Init: [announcements]
2024-04-11 10:01:19,297 [server.py:_initialize_component()] - Performing Component Post Init: [webcam]
2024-04-11 10:01:19,297 [webcam.py:_set_default_host_ip()] - Default public webcam address set: http://192.168.112.7
2024-04-11 10:01:19,299 [server.py:_initialize_component()] - Performing Component Post Init: [klippy_connection]
2024-04-11 10:01:19,299 [server.py:_initialize_component()] - Performing Component Post Init: [history]
2024-04-11 10:01:19,343 [extensions.py:start_unix_server()] - Creating Unix Domain Socket at '/opt/printer_data/comms/moonraker.sock'
2024-04-11 10:01:19,351 [server.py:start_server()] - Starting Moonraker on (0.0.0.0, 7125), Hostname: abfa52165738
2024-04-11 10:01:19,351 [application.py:listen()] - SSL Certificate/Key not configured, aborting HTTPS Server startup
2024-04-11 10:01:19,604 [klippy_connection.py:_do_connect()] - Klippy Connection Established
2024-04-11 10:01:19,616 [shell_command.py:_check_proc_success()] - Command (systemctl status 215973) exited with return code 1
2024-04-11 10:01:20,118 [machine.py:extract_service_info()] - Error extracting service info
Traceback (most recent call last):
  File "/opt/moonraker/moonraker/components/machine.py", line 1097, in extract_service_info
    resp: str = await self.shell_cmd.exec_cmd(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/moonraker/moonraker/components/shell_command.py", line 277, in run_with_response
    raise ShellCommandError(
moonraker.components.shell_command.ShellCommandError: Error running shell command: 'systemctl status 215973'
2024-04-11 10:01:20,373 [server.py:add_log_rollover_item()] - Klipper Version: ?
2024-04-11 10:01:20,386 [shell_command.py:_check_proc_success()] - Command (systemctl status 1) exited with return code 1
2024-04-11 10:01:20,888 [machine.py:extract_service_info()] - Error extracting service info
Traceback (most recent call last):
  File "/opt/moonraker/moonraker/components/machine.py", line 1097, in extract_service_info
    resp: str = await self.shell_cmd.exec_cmd(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/moonraker/moonraker/components/shell_command.py", line 277, in run_with_response
    raise ShellCommandError(
moonraker.components.shell_command.ShellCommandError: Error running shell command: 'systemctl status 1'
2024-04-11 10:01:21,176 [klippy_connection.py:_request_initial_subscriptions()] - Webhooks Subscribed
2024-04-11 10:01:21,179 [klippy_connection.py:_request_initial_subscriptions()] - GCode Output Subscribed
2024-04-11 10:01:21,428 [job_state.py:_handle_started()] - Job state initialized: standby
2024-04-11 10:01:21,678 [base_events.py:default_exception_handler()] - Future exception was never retrieved
future: <Future finished exception=EOFError()>
Traceback (most recent call last):
  File "/opt/venv/lib/python3.11/site-packages/dbus_next/aio/message_bus.py", line 158, in on_hello
    raise err
  File "/opt/venv/lib/python3.11/site-packages/dbus_next/aio/message_bus.py", line 365, in _message_reader
    if self._unmarshaller.unmarshall():
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/dbus_next/_private/unmarshaller.py", line 304, in unmarshall
    self._unmarshall()
  File "/opt/venv/lib/python3.11/site-packages/dbus_next/_private/unmarshaller.py", line 243, in _unmarshall
    self.read(16, prefetch=True)
  File "/opt/venv/lib/python3.11/site-packages/dbus_next/_private/unmarshaller.py", line 91, in read
    raise EOFError()
EOFError
2024-04-11 10:01:21,686 [klippy_connection.py:_check_ready()] - Klippy ready
2024-04-11 10:01:22,181 [data_store.py:_init_sensors()] - Configuring available sensors: ['heater_bed', 'extruder']
mkuf commented 4 months ago

Hey there,

please run scripts/get-info.sh and share the generated archive.

-Markus

tyler43636 commented 4 months ago

Thanks Markus. When I return and ran another docker pull everything was working again. I’ll close this issue.