Moonraker is starting over and over #9

Jodameister · 2022-02-25T18:51:17Z

Hello,
the moon raker is starting over and over. The docker runs on a raspy 3B+ with buster. I use the nightly build.

Here are the log:

--------------------Moonraker Log Start--------------------
config_file: cfg/moonraker.cfg
log_file: log/moonraker.log
software_version: ?
python_version: 3.10.2 (main, Jan 29 2022, 05:43:04) [GCC 10.2.1 20210110]
2022-02-25 18:39:59,921 [utils.py:setup_logging()] - config_file: cfg/moonraker.cfg
2022-02-25 18:39:59,922 [utils.py:setup_logging()] - log_file: log/moonraker.log
2022-02-25 18:39:59,922 [utils.py:setup_logging()] - software_version: ?
2022-02-25 18:39:59,922 [utils.py:setup_logging()] - python_version: 3.10.2 (main, Jan 29 2022, 05:43:04) [GCC 10.2.1 20210110]

This is the moonraker.cfg:

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

[file_manager]
config_path: /opt/cfg

[machine]
provider: none

[database]
database_path: /opt/db

[authorization]
trusted_clients:
0.0.0.0/0
cors_domains:
*

[octoprint_compat]

[history]

mkuf · 2022-02-25T20:12:27Z

Hi there,

I could not reproduce the described behaviour with the current nightly build, which is 0a2c190 as of writing this comment.
Please execute the following commands to find out which Image Tags you are actually using and add them to your reply:

docker exec klipper cat /opt/klipper/.git/HEAD | cut -c 1-7
docker exec moonraker cat /opt/moonraker/.git/HEAD | cut -c 1-7

Please also attach your klippy.log and moonraker.log.
These Files should be located in /var/lib/docker/volumes/prind_log/_data/ on your machine.

-Markus

Jodameister · 2022-02-25T20:40:01Z

Thank you for the fast reply.

docker exec klipper cat /opt/klipper/.git/HEAD | cut -c 1-7:

7c964e5

docker exec moonraker cat /opt/moonraker/.git/HEAD | cut -c 1-7:

Error response from
daemon: Container 2a62ea877bfb45cef5864497c56de4b7038b3ea29217c33ca4b0aab510a39194 is restarting, wait until the container is running

klippy.log
moonraker.log

Jodameister · 2022-02-25T20:48:18Z

Image from moonraker was created on 2022-02-25 03:55:45 (Info from Portainer)

mkuf · 2022-02-25T21:16:52Z

Moonraker restarting is a symptom of a nonworking klipper process.
Looking at the provided klippy.log, we can see the following error in line 7 and no further logs.

[...]
Unable to build C code module (error=32512)

This is unusual, as the C code modules are compiled when building the klipper image.

prind/docker/klipper/Dockerfile

Lines 15 to 16 in df3199f

    
           && venv/bin/python -m compileall klipper/klippy \ 
        
           && venv/bin/python klipper/klippy/chelper/__init__.py

I started mkuf/klipper:7c964e5 (the same image as yours) and it worked as expected.
I'm currently not able to reproduce this error.

You could try to stop your stack, prune all Images and re-pull them again but this is grasping for straws.

mkuf · 2022-02-25T21:28:58Z

@Jodameister
Are you using a 64bit OS on your Pi?

Jodameister · 2022-02-25T21:45:52Z

32bit

mkuf · 2022-02-25T22:03:24Z

Try to run the Image without any volumes or config.

docker run --rm mkuf/klipper:7c964e5

This should yield the following error message, without any mention of C builds.

INFO:root:Starting Klippy...
WARNING:root:No log file specified! Severe timing issues may result!
INFO:root:Start printer at Fri Feb 25 21:56:27 2022 (1645826187.4 7756.3)
ERROR:root:Unable to open config file cfg/printer.cfg
Traceback (most recent call last):
  File "/opt/klipper/klippy/configfile.py", line 153, in _read_config_file
    f = open(filename, 'r')
IOError: [Errno 2] No such file or directory: 'cfg/printer.cfg'
ERROR:root:Config error
Traceback (most recent call last):
  File "klipper/klippy/klippy.py", line 157, in _connect
    self._read_config()
  File "klipper/klippy/klippy.py", line 134, in _read_config
    config = pconfig.read_main_config()
  File "/opt/klipper/klippy/configfile.py", line 274, in read_main_config
    data = self._read_config_file(filename)
  File "/opt/klipper/klippy/configfile.py", line 159, in _read_config_file
    raise error(msg)
Error: Unable to open config file cfg/printer.cfg

mkuf · 2022-02-25T22:10:49Z

For the sake of testing, I removed the two lines from the klipper dockerfile that are responsible for compiling the C code in my local branch and built an image for 7c964e5.
Running this image without any config yields the following error

markus@colossus:~/prind$ docker run --rm -it 11ea364c0312
INFO:root:Starting Klippy...
WARNING:root:No log file specified! Severe timing issues may result!
INFO:root:Building C code module c_helper.so
sh: 1: gcc: not found
ERROR:root:Unable to build C code module (error=32512)
Traceback (most recent call last):
  File "klipper/klippy/klippy.py", line 369, in <module>
    main()
  File "klipper/klippy/klippy.py", line 351, in main
    main_reactor = reactor.Reactor(gc_checking=True)
  File "/opt/klipper/klippy/reactor.py", line 288, in __init__
    SelectReactor.__init__(self, gc_checking)
  File "/opt/klipper/klippy/reactor.py", line 99, in __init__
    self.monotonic = chelper.get_ffi()[1].get_monotonic
  File "/opt/klipper/klippy/chelper/__init__.py", line 270, in get_ffi
    do_build_code(cmd % (destlib, ' '.join(srcfiles)))
  File "/opt/klipper/klippy/chelper/__init__.py", line 246, in do_build_code
    raise Exception(msg)
Exception: Unable to build C code module (error=32512)

The actual errorcode seems to be the same, but your provided log is missing the line about gcc that is used to compile the modules.

[...]
INFO:root:Building C code module c_helper.so
sh: 1: gcc: not found
ERROR:root:Unable to build C code module (error=32512)
[...]

Jodameister · 2022-02-26T06:33:09Z

Try to run the Image without any volumes or config.

docker run --rm mkuf/klipper:7c964e5

This should yield the following error message, without any mention of C builds.

INFO:root:Starting Klippy...
WARNING:root:No log file specified! Severe timing issues may result!
INFO:root:Start printer at Fri Feb 25 21:56:27 2022 (1645826187.4 7756.3)
ERROR:root:Unable to open config file cfg/printer.cfg
Traceback (most recent call last):
  File "/opt/klipper/klippy/configfile.py", line 153, in _read_config_file
    f = open(filename, 'r')
IOError: [Errno 2] No such file or directory: 'cfg/printer.cfg'
ERROR:root:Config error
Traceback (most recent call last):
  File "klipper/klippy/klippy.py", line 157, in _connect
    self._read_config()
  File "klipper/klippy/klippy.py", line 134, in _read_config
    config = pconfig.read_main_config()
  File "/opt/klipper/klippy/configfile.py", line 274, in read_main_config
    data = self._read_config_file(filename)
  File "/opt/klipper/klippy/configfile.py", line 159, in _read_config_file
    raise error(msg)
Error: Unable to open config file cfg/printer.cfg

I can confirm there is no C-builds error, when I do this:

INFO:root:Starting Klippy...
WARNING:root:No log file specified! Severe timing issues may result!
INFO:root:Start printer at Sat Feb 26 06:25:32 2022 (1645856732.9 120846.2)
ERROR:root:Unable to open config file cfg/printer.cfg
Traceback (most recent call last):
  File "/opt/klipper/klippy/configfile.py", line 153, in _read_config_file
    f = open(filename, 'r')
IOError: [Errno 2] No such file or directory: 'cfg/printer.cfg'
ERROR:root:Config error
Traceback (most recent call last):
  File "klipper/klippy/klippy.py", line 157, in _connect
    self._read_config()
  File "klipper/klippy/klippy.py", line 134, in _read_config
    config = pconfig.read_main_config()
  File "/opt/klipper/klippy/configfile.py", line 274, in read_main_config
    data = self._read_config_file(filename)
  File "/opt/klipper/klippy/configfile.py", line 159, in _read_config_file
    raise error(msg)
Error: Unable to open config file cfg/printer.cfg

Jodameister · 2022-02-26T06:36:36Z

Here is my printer.cfg:

# This file is an example config file.
# See https://github.com/Klipper3d/klipper/blob/master/docs/Config_Reference.md for a description of parameters.

###### Printer Config
[stepper_x]
step_pin: PC2
dir_pin: PB9
enable_pin: !PC3
microsteps: 16
rotation_distance: 40
endstop_pin: ^PA5
position_endstop: 0
position_max: 235
homing_speed: 50

[stepper_y]
step_pin: PB8
dir_pin: PB7
enable_pin: !PC3
microsteps: 16
rotation_distance: 40
endstop_pin: ^PA6
position_endstop: 0
position_max: 235
homing_speed: 50

[stepper_z]
step_pin: PB6
dir_pin: !PB5
enable_pin: !PC3
microsteps: 16
rotation_distance: 8
endstop_pin: ^PA7
position_endstop: 0.0
position_max: 250

[extruder]
max_extrude_only_distance: 100.0
step_pin: PB4
dir_pin: PB3
enable_pin: !PC3
microsteps: 16
rotation_distance: 34.406
nozzle_diameter: 0.400
filament_diameter: 1.750
heater_pin: PA1
sensor_type: EPCOS 100K B57560G104F
sensor_pin: PC5
control: pid
# tuned for stock hardware with 200 degree Celsius target
pid_Kp: 21.527
pid_Ki: 1.063
pid_Kd: 108.982
min_temp: 0
max_temp: 250

[heater_bed]
heater_pin: PA2
sensor_type: EPCOS 100K B57560G104F
sensor_pin: PC4
control: pid
# tuned for stock hardware with 50 degree Celsius target
pid_Kp: 54.027
pid_Ki: 0.770
pid_Kd: 948.182
min_temp: 0
max_temp: 130

[fan]
pin: PA0

[mcu]
serial: /dev/serial/by-id/usb-1a86_USB_Serial-if00-port0
restart_method: command

[printer]
kinematics: cartesian
max_velocity: 300
max_accel: 3000
max_z_velocity: 5
max_z_accel: 100



###### Klipper
[virtual_sdcard]
path: /opt/gcode

[display_status]

[pause_resume]

[gcode_macro PAUSE]
description: Pause the actual running print
rename_existing: PAUSE_BASE
# change this if you need more or less extrusion
variable_extrude: 1.0
gcode:
  ##### read E from pause macro #####
  {% set E = printer["gcode_macro PAUSE"].extrude|float %}
  ##### set park positon for x and y #####
  # default is your max posion from your printer.cfg
  {% set x_park = printer.toolhead.axis_maximum.x|float - 5.0 %}
  {% set y_park = printer.toolhead.axis_maximum.y|float - 5.0 %}
  ##### calculate save lift position #####
  {% set max_z = printer.toolhead.axis_maximum.z|float %}
  {% set act_z = printer.toolhead.position.z|float %}
  {% if act_z < (max_z - 2.0) %}
      {% set z_safe = 2.0 %}
  {% else %}
      {% set z_safe = max_z - act_z %}
  {% endif %}
  ##### end of definitions #####
  PAUSE_BASE
  G91
  {% if printer.extruder.can_extrude|lower == 'true' %}
    G1 E-{E} F2100
  {% else %}
    {action_respond_info("Extruder not hot enough")}
  {% endif %}
  {% if "xyz" in printer.toolhead.homed_axes %}
    G1 Z{z_safe} F900
    G90
    G1 X{x_park} Y{y_park} F6000
  {% else %}
    {action_respond_info("Printer not homed")}
  {% endif %}

[gcode_macro RESUME]
description: Resume the actual running print
rename_existing: RESUME_BASE
gcode:
  ##### read E from pause macro #####
  {% set E = printer["gcode_macro PAUSE"].extrude|float %}
  #### get VELOCITY parameter if specified ####
  {% if 'VELOCITY' in params|upper %}
    {% set get_params = ('VELOCITY=' + params.VELOCITY)  %}
  {%else %}
    {% set get_params = "" %}
  {% endif %}
  ##### end of definitions #####
  {% if printer.extruder.can_extrude|lower == 'true' %}
    G91
    G1 E{E} F2100
  {% else %}
    {action_respond_info("Extruder not hot enough")}
  {% endif %}  
  RESUME_BASE {get_params}

[gcode_macro CANCEL_PRINT]
description: Cancel the actual running print
rename_existing: CANCEL_PRINT_BASE
gcode:
  TURN_OFF_HEATERS
  CANCEL_PRINT_BASE

mkuf · 2022-02-26T15:27:52Z

I can confirm there is no C-builds error, when I do this:

This is really strange. The C modules are compiled before the config file is even loaded, so it should should trigger the same error on your system as with starting it through compose.

I had to rebuild the current nightly Image for klipper because of an unrelated issue.

Would you mind trying to start klipper with the image explicitly set to mkuf/klipper:7c964e5?
Please make sure that you delete all klipper images on your machine beforehand, as the new Image is using the same Tag as before, docker would otherwise not re-pull it from the registry.

docker compose --profile fluidd down
docker image prune -af
docker compose --profile fluidd up -d klipper

Let me know if anything in the klippy.log file changed with the new Image.

-Markus

mkuf · 2022-03-05T16:14:47Z

Is this still relevant @Jodameister ?

mkuf closed this as completed Mar 12, 2022

shaunmulligan pushed a commit to projectquine/prind that referenced this issue Feb 6, 2023

Merge pull request mkuf#9 from ahalekelly/patch-1

c10db67

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Moonraker is starting over and over #9

Moonraker is starting over and over #9

Jodameister commented Feb 25, 2022 •

edited

Loading

mkuf commented Feb 25, 2022

Jodameister commented Feb 25, 2022

Jodameister commented Feb 25, 2022

mkuf commented Feb 25, 2022

mkuf commented Feb 25, 2022

Jodameister commented Feb 25, 2022

mkuf commented Feb 25, 2022

mkuf commented Feb 25, 2022 •

edited

Loading

Jodameister commented Feb 26, 2022 •

edited

Loading

Jodameister commented Feb 26, 2022

mkuf commented Feb 26, 2022

mkuf commented Mar 5, 2022

Moonraker is starting over and over #9

Moonraker is starting over and over #9

Comments

Jodameister commented Feb 25, 2022 • edited Loading

mkuf commented Feb 25, 2022

Jodameister commented Feb 25, 2022

Jodameister commented Feb 25, 2022

mkuf commented Feb 25, 2022

mkuf commented Feb 25, 2022

Jodameister commented Feb 25, 2022

mkuf commented Feb 25, 2022

mkuf commented Feb 25, 2022 • edited Loading

Jodameister commented Feb 26, 2022 • edited Loading

Jodameister commented Feb 26, 2022

mkuf commented Feb 26, 2022

mkuf commented Mar 5, 2022

Jodameister commented Feb 25, 2022 •

edited

Loading

mkuf commented Feb 25, 2022 •

edited

Loading

Jodameister commented Feb 26, 2022 •

edited

Loading