I have two Ender 2 Pro printers, one with HC32F460 MCU and one with STM32f103xe.
With the SAME gcode file and almost identical printer.cfg, they show a clear difference in speed.
I suspect the CLOCK_FREQ setting of 200 MHz in Kconfig for HC32F460 mcu is incorrect for Ender 2 Pro. I changed the value to 168 MHz and now both printers print at identical speeds and the measured long move speed matches the slicer configuration.
I have a new Ender 2 Pro with the S4 MB and it did not feel as snappy as I would have expected, so I printed a cylinder in vase mode that should have taken 30 seconds but took 36, so we have similar experiences. Maybe @SteveGotthardt could take a look when he has time.
The clock freq should be correct or the BAUD rate for the serial interface would not work if it was 20% off
That would only be the case if the serial transmission were implemented in software. The clock for the serial port is obviously generated by the hardware and does not change with a change in CLOCK_FREQ. I guess, CLOCK_FREQ is only relevant for klipper - it probably creates longer wait cycles when it thinks the processor is faster.
My printer works with both CLOCK_FREQ values, but only the 168 MHz value prints at the correct speed.
For what reason did you use the value of 200 Mhz?
Edit:
By the way - the data sheet of the HC32F460 mentions a clock frequency of 168 Mhz:
The Klipper log file will report what it actually measures the frequency as - so if you think there is an issue, please attach the full klipper log file here.
-Kevin
I guess, these are the relevant log file entries:
MCU 'mcu' config: ADC_MAX=4095 CLOCK_FREQ=168000000 MCU=HC32F460 PWM_MAX=65535 RECEIVE_WINDOW=192 RESERVE_PINS_serial=PA7,PA8 SERIAL_BAUD=250000 STATS_SUMSQ_BASE=256 STEPPER_BOTH_EDGE=1
=============== Log rollover at Tue May 23 09:30:41 2023 ===============
Stats 32.5: gcodein=0 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=3855 bytes_read=4110 bytes_retransmit=9 bytes_invalid=0 send_seq=167 receive_seq=167 retransmit_seq=2 srtt=0.004 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=167997278 heater_bed: target=0 temp=23.4 pwm=0.000 sysload=0.70 cputime=4.921 memavail=1727160 print_time=0.008 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.8 pwm=0.000
Stats 33.5: gcodein=0 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=3861 bytes_read=4231 bytes_retransmit=9 bytes_invalid=0 send_seq=168 receive_seq=168 retransmit_seq=2 srtt=0.004 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=168002267 heater_bed: target=0 temp=23.4 pwm=0.000 sysload=0.70 cputime=4.952 memavail=1702140 print_time=0.008 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.8 pwm=0.000
Stats 34.5: gcodein=0 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=3867 bytes_read=4337 bytes_retransmit=9 bytes_invalid=0 send_seq=169 receive_seq=169 retransmit_seq=2 srtt=0.004 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=168003190 heater_bed: target=0 temp=23.4 pwm=0.000 sysload=0.70 cputime=4.975 memavail=1714884 print_time=0.008 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.8 pwm=0.000
Just out of curiosity: if klipper measures the frequency anyway - why is CLOCK_FREQ used at all instead?
The Klipper code has to correlate the host clock with the mcu clock in order to properly schedule events on the mcu. As for using CLOCK_FREQ - there is no reason to presume that the host clock is more accurate than the mcu clock, so we use the clock on the main mcu ([mcu]) as the main clock for scheduling print actions (ie, print_time).
-Kevin
Here is what’s in my log.
mcu ‘mcu’: Starting serial connect
webhooks client 140247905106688: New connection
webhooks client 140247905106688: Client info {‘program’: ‘Moonraker’, ‘version’: ‘v0.8.0-32-g31e589a’}
Resetting prediction variance 66092.193: freq=200000000 diff=-1751733 stddev=200000.000
mcu ‘mcu’: got {‘#receive_time’: 66092.257478719, u’next_clock’: 2751349632, u’oid’: 11, u’value’: 25406, ‘#name’: u’analog_in_state’, ‘#sent_time’: 66092.247262215}
mcu ‘mcu’: got {‘#receive_time’: 66092.352533544, u’next_clock’: 2767349632, u’oid’: 19, u’value’: 31208, ‘#name’: u’analog_in_state’, ‘#sent_time’: 66092.302166543}
Loaded MCU ‘mcu’ 73 commands (v0.11.0-173-ga8b1b0ef / gcc: (15:7-2018-q2-6) 7.3.1 20180622 (release) [ARM/embedded-7-branch revision 261907] binutils: (2.31.1-12+11) 2.31.1)
This is quite a serious message. Post a full log, hoping that @koconnor can have a look.
Sometimes it helped to make sure your host clock is correct
Alas, a snippet from a log doesn’t provide much value. I’d need the full unmodified log attached to this thread. It’s a good idea to run a print (or at least initiate some toolhead movement) and then issue an M112 or emergency stop.
-Kevin
@koconnor
Hi Kevin, here’s a log of the test print that should have taken about 30s plus the priming lines but takes 36s+ instead. The host is a laptop running Debian 10 & Octoprint in virtual SD mode.
e2p_klippy.zip (23.7 KB)
Okay. The log seems to be missing the version information though. Not sure why that is.
In any case, your log does indicate that the mcu is compiled for 200Mhz frequency, but is actually running at 168Mhz. So, the timing does look incorrect.
Maybe @SteveGotthardt knows why.
-Kevin
I used the 200MHz as CLOCK_FREQ because the bootloader seems to leave it there - that was my bootloader. Maybe there is a new bootloader that leaves it at 168 (voxelabs do that).
My implementation does not set the clock after the boot loader handoff. At system startup the code reads what is in the registers and determines what the clock is.
So… I could set clock freq explicitly, or find out if there is a new bootloader or I made an error reading the registers myself, or the code is wrong converting to system speed.
I am going to check the last one first to see if the code gets the system speed correct.
Uhhh - found out that my board now reports CMU_PLLCFGR: 0x 11 10 29 00
pllp = 1d → /2
pllq = 1d → /2
pllr = 1d → /2
plln = 41d → * 42
pllm = 0 → / 1
so sys freq = 8MHz / 1 * 42 / 2 = 168MHz !!
I will submit PR.
Thank you guys and thanks @flashy for being vigilant. For the time being I also edited Kconfig for 168MHz and ran Make again and the timing seems to be spot on now.