GCODE_BUTTON state not correctly report from python

General Discussion
1

Basic Information:

Printer Model: Hevort Based + KTCv2
MCU / Printerboard: Duet3D, Super8
Host / SBC: RPI
klippy.log

Fill out above information and in all cases attach your klippy.log file (use zip to compress it, if too big). Pasting your printer.cfg is not needed
Be sure to check our “Knowledge Base” Category first. Most relevant items, e.g. error messages, are covered there

Describe your issue:

Hi,
I’m experiencing a strange behavior with GCODE_BUTTON.
I’ve searched the thread for any similar issue but it does not seem to exist, if it is then I apologize in advance.

I have several GCODE_BUTTON in place to detect toolhead on a carriage/docks (on a DIY multi_tool 3D printer under construction).

I wanted to use these GCODE_Button to perform a sanity check on the printer. For example, if the GCODE_BUTTON of the carriage is PRESSED
(meaning a tool is engaged) then one (and only one) tool dock GCODE_BUTTON must be RELEASED (one tool is not on its dock). It also allow
me to retrieve which tool is engaged on the carriage.

The multi-tool management is based on the KTC v2 code from Andrei Ignat (TypQxQ)… amazing job by the way.

When I use a GCODE macro to test the status of the GCODE_BUTTON (from Fluidd or Mainsail) then everything works fine, the status of the
different GCODE_BUTTON is correctly retrieved).

When I call a GCODE macro from python (in the KTC callback function for the Klipper:READY state), then all GCODE_BUTTON status are retrieved
RELEASED, independently of there real states. When Fluidd is connected, then the macro retrieves the correct states again.

It seems like klipper’s extras python files are not using the same way to retrieve GCODE_BUTTON state as Fluidd and Mainsail (just guessing here, I’m not a Klipper expert)

I’ve tried different solutions:

  • Read gcode from .cfg file at KTC init phase and execute it in the Klipper:READY callback (this is the default behavior of the KTC module)
  • Using DELAYED GCODE suspecting that klipper needed more time to retrieve the correct GCODE_BUTTON status (setting the delay up to 30s)
  • Calling an existing gcode macro directly from the KLIPPER:READY callback, trying to avoid any early evaluation of the macro induced by a loading of the
    macro during the init phase (like in step 1)

All failed: RELEASED is always returned for all GCODE_BUTTON from python, the correct state is retrieved if I call the macro from Fluidd

If anyone can provide me with a track of investigation, it would be cool.

Search for === PRINT_TCHEAD_STATE === in the klippy.log file, it is the start of the output of the macro

Thanks,
(Sorry for the english, not my native language)

klippy.log.txt (1.3 MB)

2

I guess you’d better look inside the gcode_button.py and buttons.py.

Shortly speaking, the host code schedules a repeatable command to the MCU.
MCU queries the button every 2 ms and sends data back.
Host receives the current status, and after processing callbacks set the button status.

That is it, so you will see the correct status after the MCU receives commands, and after the MCU have send the status for at least N times back.
Where N >= 1.

Hope that helps,
-Timofey

3

Hi Timofey,

Thanks for your answer and the idea.

I will put some trace log in the buttons callbacks to try understand this issue. It could be that none MCU button_handler has been called when Klipper:ready callbacks are called.

Will see…

4

After a few tests, and some debug logging in the buttons.py and gcode_button.py modules I can confirm that indeed the klipper:ready callbacks are called earlier than the gcode_button’s callbacks. That’s why they are all reported as RELEASED (the default state in the initialisation of buttons).

I’ve attached an extract of the klippy.log for anyone who is interested in the gcode_button creation sequence.

The solution is to use reactor to schedule a call to another method that will perform the check on the buttons later (approx 10/15s)

self.reactor.register_async_callback(self._startup_check, self.reactor.monotonic() + 15.0)

You can see the trace in the log:

KTC->_handle_ready() === scheduling execution of XXXXXXX to 15s after [1145.009008632]

And the execution:

KTC === KTC->_startup_check() === Called at [1160.010402049]

In the log, “KTC_STARTUP: Carriage vide, tous les tools en dock.” means all the tools are on their respective dock (the switchs are PRESSED) and the carriage is empty (switch RELEASED) and that’s correct

Why did my previous tests with delayed_gcode did not work, I don’t know (maybe I did it wrong)

At least now I have the right solution!

Thanks again for your help

klippy.log (19.1 KB)