Host buffer: buffer_time bigger than BUFFER_TIME_HIGH

General Discussion
1

Basic Information:

Printer Model: Creality CR-10S
MCU / Printerboard: FYSETC S6
Host / SBC: Raspberry Pi 3
klippy.log (1.6 MB)

Thanks to this [1] description, I understand that buffer_time in the Stats line of the log represents the time of the upcoming printer moves up to 2 seconds ahead.

During printing, my buffer_time values in the log file are above BUFFER_TIME_HIGH (= 2.0). My prints are coming out nicely and as of my understanding this indicates just that “too much” moves are in the queue. Anyways, I would like to understand the background and whether I am doing somthing wrong or not.

Plotting the buffer_time as Host Buffer by graphstats.py, shows zeroed-out data due to limiting it to MAXBUFFER (= BUFFER_TIME_HIGH).
[2]

Plotting the raw buffer_time values from the log shows that they are above BUFFER_TIME_HIGH during the entire print.

buffer_time
buffer_time1746×772 131 KB

Is this intended behaviour, or should the buffer_time be in range [0 … 2]?

Sorry for the non-clickable references, but rules here dont allow more than 2 links in first post…
[1] h t t p s://klipper.discourse.group/t/advanced-trouble-shooting-graphing-klipper/6613#graphing-the-mcu-7
[2] see post below

2

[2]

host_buffer
host_buffer1846×1135 168 KB

3

It seems you are using a modified Klipper version both on the host and flashed to the MCUs.
Please reproduce with a pristine Klipper and post the corresponding log.

4

Thank you for checking my issue.

I understand that the dirty suffix on the controllers look suspicious, but this was only during klipper installation phase for some changes to install-debian.sh to make it compatible to bookworm & Pyhton 3. Anyways, I flashed all controllers to vanilla.

I do not understand your statement that my host software is not pristine. As of my understanding it is vanilla.

Now, host as well as all controllers run klipper 01c7befa – at least this is what I’m thinking.
Log file with this version shows buffer_time values > 2.0.
klippy.log (854.3 KB)

Furthermore, this is not limited to my setup. I have checked three recent posts here and the klipper logs given there also have buffer_time values > 2.0.
Examples:

5

Well, usually I would see no need for something like:

Git version: 'v0.12.0-143-g01c7befa'
Branch: master_mirror
Remote: origin
Tracked URL: matthias@homeserver.lan:git/klipper.git

in a regular install unless I intend to run modifications. But your 01c7befa is a legitimate hash from Klipper

All these linked topics deal with other issues and are not related to your error message.

Your log file does not show the described error, unless I’m missing it.

6

The following is based on the klippy.log from my previous post.

  • in the entire log, about 2/3 (400 out of 599) of non-zero buffer_time values are above 2.0
  • first buffer_time value bigger than 2.0 at line 978 (buffer_time=3.464)
  • max buffer_time value at line 1381 (buffer_time=5.699)
  • most (400 out of 407) of non-zero buffer_time values between line 978 and line 1386 are above 2.0

Host Buffer graphed by graphstats.py shows zero-out values.

Host_Buffer
Host_Buffer1846×1135 118 KB

7

Please provide a log. I cannot find the mentioned error in the attached logs.

8

I am confused…
I downloaded the log file and double checked. I see values as decribed in my previous post.

Maybe there is something wrong with the file upload/download. Uploading again:
klippy.log (854.3 KB)

Are you saying you do not see these values in the log file?

screenshot
screenshot1024×768 106 KB

9

Maybe, I’m confused. Where do you get an error message that is telling you that the buffer_time bigger than BUFFER_TIME_HIGH?

Apart from this, it is my (very weak) understanding that:

  • Klipper tries to buffer at least 2 seconds
  • As long as buffer_time stays above BUFFER_TIME_LOW everything is fine
  • When buffer_time minus BUFFER_TIME_HIGH is below 0 then Klipper might decide to pause the print to regenerate the buffer, i.e. there would be stuttering
10

There is no error message buffer_time bigger than BUFFER_TIME_HIGH. This is just the title of this thread.

My question is

Regarding

I took a brief look into the code and have different understanding. Please be aware that I just took a glimpse at the code and do not understand the full functional scope, so my understand may be wrong.

In graphstats.py, buffer_time values > 2 are reset to 0.
If buffer_time values > 2 are expected, than 100(%) would be a better replacement value from my point of view.

In _check_pause method in toolhead.py, pause is called if buffer_time > 2

        ...
        # Check if there are lots of queued moves and pause if so
        while 1:
            pause_time = buffer_time - BUFFER_TIME_HIGH
            if pause_time <= 0.:
                break
            if not self.can_pause:
                self.need_check_pause = self.reactor.NEVER
                return
            eventtime = self.reactor.pause(eventtime + min(1., pause_time))
            ...

Is there a chance to get a short statement from a developer?

11

It is the intended behavior. The goal is to calculate movements so that the host is at least 2 seconds ahead of the toolhead movement. So, it’s normal to be more than 2 seconds ahead. There is only a concern if the host falls under 2 seconds (which could indicate that the host can’t keep up).

Hope that helps,
-Kevin

1 Like
12

Thank you for confirmation.