Basic Information:
Printer Model: Twotrees SK1
MCU / Printerboard: proprietary, MKS based. Printhead board RP2040 based
Host / SBC: proprietary, MKS OEM, similar to MKS PI
klippy.log.zip (2.3 MB)
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:
… My printer spontaneously halts while printing. No specific timing - it can print whole day normally, but next day halt 30 min after print start. I know that boards on this printer are poor quality, but I need to understand what part is really fail the print and avoid replacing everything.
Can someone take a look at the log and guess the reason of failure? What exactly went wrong? Unfortunately these logs a bit obscure for me. See shutdown messages closer to the end of the log.
===== Config file =====
[mcu MKS_THR]
serial = /dev/ttyS0
baud = 250000
restart_method = command
...
Stats 18761.2: gcodein=0 mcu: mcu_awake=0.046 mcu_task_avg=0.000033 mcu_task_stddev=0.000026 bytes_write=64564222 bytes_read=9511015 bytes_retransmit=9 bytes_invalid=0 send_seq=1147103 receive_seq=1147103 retransmit_seq=2 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=21 upcoming_bytes=7127 freq=84002270 MKS_THR: mcu_awake=0.005 mcu_task_avg=0.000018 mcu_task_stddev=0.000016 bytes_write=10189494 bytes_read=2785646 bytes_retransmit=29687 bytes_invalid=8724 send_seq=205952 receive_seq=205951 retransmit_seq=205936 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000305 adj=11999980 heater_bed: target=60 temp=60.0 pwm=0.109 sd_pos=11672967 sysload=0.48 cputime=2764.133 memavail=579980 print_time=18768.951 buffer_time=2.227 print_stall=12 extruder: target=200 temp=200.2 pwm=0.410
Stats 18762.2: gcodein=0 mcu: mcu_awake=0.047 mcu_task_avg=0.000033 mcu_task_stddev=0.000026 bytes_write=64571652 bytes_read=9511881 bytes_retransmit=9 bytes_invalid=0 send_seq=1147226 receive_seq=1147226 retransmit_seq=2 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=8622 freq=84002270 MKS_THR: mcu_awake=0.005 mcu_task_avg=0.000018 mcu_task_stddev=0.000016 bytes_write=10189921 bytes_read=2785693 bytes_retransmit=30028 bytes_invalid=8789 send_seq=205959 receive_seq=205957 retransmit_seq=205957 srtt=0.001 rttvar=0.001 rto=0.400 ready_bytes=320 upcoming_bytes=521 freq=12000305 adj=12000015 heater_bed: target=60 temp=60.0 pwm=0.120 sd_pos=11676736 sysload=0.48 cputime=2764.378 memavail=579980 print_time=18769.933 buffer_time=2.208 print_stall=12 extruder: target=200 temp=199.9 pwm=0.468
...
MCU 'MKS_THR' shutdown: Timer too close
clocksync state: mcu_freq=12000000 last_clock=38238132559 clock_est=(21920.204 37731892818 12000309.902) min_half_rtt=0.000260 min_rtt_time=20475.198 time_avg=21920.203(1702.676) clock_avg=37731892818.741(20432643713.371) pred_variance=2187336.857 clock_adj=(-0.021 11999998.773)
Dumping serial stats: bytes_write=1926574 bytes_read=477182 bytes_retransmit=30558 bytes_invalid=7492 send_seq=37892 receive_seq=37890 retransmit_seq=37889 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=3361
...
Sent 98 21959.560318 21959.555518 58: seq: 10, queue_step oid=5 interval=13955 count=2 add=5649, queue_step oid=5 interval=27008 count=2 add=-4924, queue_step oid=5 interval=14790 count=2 add=-3163, queue_step oid=5 interval=9175 count=4 add=-610, queue_step oid=5 interval=7120 count=7 add=107, queue_step oid=5 interval=8099 count=7 add=424, queue_step oid=5 interval=11497 count=2 add=1497
Sent 99 21962.388563 21962.386123 61: seq: 11, tmcuart_send oid=0 write='\xea\x03\xe8\xad\xe1' read=10, get_clock, get_clock, get_clock, queue_step oid=5 interval=16206 count=1 add=0, set_next_step_dir oid=5 dir=0, queue_step oid=5 interval=60742 count=1 add=0, queue_step oid=5 interval=26852 count=1 add=0, set_next_step_dir oid=5 dir=1, queue_step oid=5 interval=38789 count=2 add=-15494, queue_step oid=5 interval=15643 count=3 add=-2223
...
Receive: 97 21962.385578 0.000000 14: seq: 11, analog_in_state oid=8 next_clock=3881863387 value=3416
Receive: 98 21962.390770 21962.388563 11: seq: 12, clock clock=3878394191
Receive: 99 21962.390742 21962.388563 12: seq: 12, shutdown clock=3878394312 static_string_id=Timer too close
bytes_retransmit=29687 bytes_invalid=8724
Increasing over time in the log.
Right before TTC, there is several get_clock
commands.
That means previous commands was not delivered/answered in time.
So, queue_step is also arrived too late, which cause TTC in the end.
Most probably, there is a UART communication issue.
Make sure that SBC and MCU have common ground, like the GND pin connected.
Also, it is possible there is an electrical noise from the PSU if there is no grounding in the wall socket and the board and PSU are connected to the shared metallic parts.
Or try to use USB.
Hope that helps.
Thank you for suggestions. I’ll try to check PSU, grounding, and other connections.
A few additional questions:
- How the USB connectivity will help here?
- Could you please explain ‘timer too close’ concept, and how it is related to data transfer issues?
How the USB connectivity will help here?
Magic trick, change something to something.
This is a hard-to-diagnose hardware issue online. 
Technically, it is a differential signal, it is slightly better at electrical noise handling, there is always a ground, and there are slightly more logs at kernel level.
With hardware GPIO UART, most probably there is no diagnostic information AFAIK.
Could you please explain ‘timer too close’ concept, and how it is related to data transfer issues?
In simple words, klipper consists of 2 parts, klippy and klipper.
The first is the Python host, and the second is the MCU firmware.
Python host tracks MCU time and schedules simple commands, like toggle this pin 5 times.
To make everything work, those commands should be executed in some order and at a specific time.
If the command arrives too late, it tries to be executed in the past. This is not possible, so the MCU does an emergency shutdown.
In your specific case, it looks like because of transmission errors and retries, the command arrives too late. There is no way to know for sure, but first, it is better to fix the network issue before investing time in something else.
There is the precise explanation: Timer too close