"Timer too close" at specific point in a gcode

Basic Information:

Printer Model: Voron V2.4
MCU / Printerboard: BTT Octopus, BTT EBB36, BTT MMB
Host / SBC: Raspberry Pi 3B
klippy.log

Describe your issue:

Hi, this one is quite tricky for me to figure out. Ever since I’ve finished my current setup, adding an ERCF and a Cartographer probe, I get a “timer too close” seemingly randomly during printing.

I’ve noticed the printer crashes at the exact same point while printing a specific gcode file.
I have already tried looking for info in the logs with no real success. I did notice however 2 spikes in Klipper load to several hundred percent, once right when crashing.
I’ve found a similar issue here related to overwhelming the MCU with high microstepping, but since I run 32 on XYZ and 16 on the extruder it doesn’t seem to be the case. The graphs also don’t show any excessive load, except for the “Klipper load” in Fluidd at several hundred percent at the two peaks. I’ll include all the graphs, logs and files that seem to be relevant in the zip.
logs and graphs.zip (6.1 MB)

Some maybe useful infos:
Timer too close is not the error displayed in fluidd. I found it in the klippy log as the first issue. I can not reset the printer without doing a full power cycle.
The printhead moves slightly to the right before stopping to function, so it comes off the arc path.
Arc resolution is at 0.1 in klipper, so it should not be overwhelming anything.

What I will try today or tomorrow, depending on when they arrive is to swap my microSD card and the USB cable connecting the RPi with the Octopus. After that I am out of ideas. Any suggestion will help.
Thank you very much!

Generally speaking, you will find the potential reason for this error here: Timer too close

Since you are using a heavily modified Klipper version:

  1. The error could be caused by such an additional module (or a combination thereof)
  2. No developer here will take a look at it, since it might mean spending a lot time in hunting a ghost, because the error was caused by an improper implementation of one of these 3rd party modules

Right, sorry makes sense. I’ll see what I can find myself and maybe at least narrow down a module, or thin out the installation of klipper until it might get better.

Swapping the SD card didn’t make a difference. It failed at the exact same spot. The only lead I have is the Klipper load spikes in my fluidd interface that appear frequently at ~500%.
Thanks, I’ll try looking around more then

I glanced at it out of curiosity, It’s your ERCF that’s losing connection for whatever reason. First thing to check is a loose connection.

As a semi-related side node, I was looking into the ECRF code base earlier and holy hell it’s a mess. So Sineos is definitely right on that one. I pity the poor fool who has to try and debug that.

Will check the can wiring thanks. It’s weird that it would give up at this specific point.

Just one last question, how could you tell it was caused by the ERCF? The first thing I saw in the klippy log was the MCU “mcu” giving a TTC issue. In a different attempt it was the toolhead board first. Maybe with that information I can try looking into it with someone who knows a little about the ERCF code.
Was hoping it would be a less critical part of the setup
Thanks for looking into it anyways!

Scroll up and you’ll see the error was on the mcu “mmu” which according to the rest of the config looks like your ERCF.

I did quickly look thru your logs.

From my point of view you have USB communication troubles.

Your Stats for main MCU is showing that usually klipper is sending approx 5k of payload to MCU but in same time your upcoming_bytes is indicating that most of the time there is a waiting tail of data for sending, usualy 1k-6k of payload.
Also I don’t see CPU overload which can cause this.

So most probably you have a condition where you data for main MCU constantly lagging behind because of some reason, something is holding them

By default serial connection have baud rate of 250000 bit/s which can be recalculated to 250000/8/1024=30Kbyte/s
So serial connection should be able to push up to 30k but your connections is not able to do it and constantly lagging.

This behavior can be explain by following issues:
USB Cable
USB Hub
USB Internal controller
Connector issues
OS Configuration
CPU Load
Faulty hardware

P.S. I don’t see that TTC error was caused by “MMU”, I see that first instance of TTC error was reported by main MCU.

Good luck.

2 Likes

I should clarify:

I took it as a cascading failure. The first instance was of the main mcu at line 42386 in the log.

42386: MCU 'mcu' shutdown: Timer too close
mcu dump
42591: MCU 'mmu' shutdown: Timer too close
mmu dump
42796: MCU 'EBBCan' shutdown: Timer too close
EBBCan dump

Then on reconnect attempt there were 19 different variations on:

mcu 'mmu': Wait for identify_response
Traceback (most recent call last):
  File "/home/luca0/klipper/klippy/serialhdl.py", line 68, in _get_identify_data
    params = self.send_with_response(msg, 'identify_response')
  File "/home/luca0/klipper/klippy/serialhdl.py", line 261, in send_with_response
    return src.get_response([cmd], self.default_cmd_queue)
  File "/home/luca0/klipper/klippy/serialhdl.py", line 318, in get_response
    self.serial.raw_send_wait_ack(cmds[-1], minclock, reqclock,
  File "/home/luca0/klipper/klippy/serialhdl.py", line 253, in raw_send_wait_ack
    self._error("Serial connection closed")
  File "/home/luca0/klipper/klippy/serialhdl.py", line 61, in _error
    raise error(self.warn_prefix + (msg % params))
serialhdl.error: mcu 'mmu': Serial connection closed

Where the mmu wouldn’t reconnect.

I should have been more clear on the fact that I meant the MMU was the first place I’d look since it seems to have communication issues.

The ERCF code had a string of unhandled exceptions immediately after shutdown too. Probably unrelated but adds to the fact it makes it harder to debug any issues with third party code addons.

I think you were right in your assessment.
I borrowed a RPi 4 and while the upcoming_bytes of ~5k with even peaks of 11k did not go away, the klipper load peaks went from ~500% to a maximum of 100%. The printer powered through the affected spot and is currently printing without issues.
it does feel like delaying the inevitable a bit with the peaks in both USB connection and load still existing, but it does work now, which is what matters.
I’ll be getting a RPi 5 since the prices don’t differ too much anyways sadly and be done with it for now I hope. Just need to check if I have enough 5V current available for one.

Thank you all so much, this has been impossible for me to figure out. Especially for looking into my modded setup anyways. Appreciate it

1 Like

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.