Communication Issues causing printer to set high temperatures

Festivejelly

I awoke this morning to find a failed print, I couldnt figure out why until I looked at the logs...

My print should have been printing at 215c on the hotend and 55c on the bed, but looking at this section of the log:

Recv: 6:03:57.276: T:215.57 /215.00 B549 /5500 @41 B@:22

Recv: 6:03:58.281: T:15.36 /215.00 B:54.99 55.00 @44 B@:22

Recv: 6:03:59.280: T:215.62 /215.00 B:55.03 /5500 @:41 B@:17

Recv: 6:04:00.280: :215.57 /215.00 B:55.03 /55.00 @:41 B@17

Mesg: 6:04:01.110: Warning: Communication timeout - resetting communication buffer.

Mesg: 6:04:01.110: Connection status: Buffered:82, Manual Commands: 2, Job Commands: 5000

Mesg: 6:04:01.110: Buffer used:82 Enforced free byte:22 lines stored:2

Send: 6:04:01.111: N6237 M104 S285 T0

Send: 6:04:01.111: N6238 M140 S110

Send: 6:04:01.111: N6239 G1 X73.256 Y112.854 E2349.35695

Recv: 6:04:01.124: Error:Line Number is not Last Line Number+1, Last Line: 6236

Recv: 6:04:01.126: Resend: 6237

Recv: 6:04:01.127: Ignore due to resend: ok

Recv: 6:04:01.131: Ignore due to resend: echo:Unknown command: "~"

Recv: 6:04:01.132: Ignore due to resend: ok

Send: 6:04:01.213: Resend: N6237 M104 S285 T0

Recv: 6:04:01.215: ok

Send: 6:04:01.215: Resend: N6239 G1 X73.256 Y112.854 E2349.35695

Recv: 6:04:01.228: Error:Line Number is not Last Line Number+1, Last Line: 6237

Recv: 6:04:01.231: Resend: 6238

Recv: 6:04:01.231: Ignore due to resend: ok

Recv: 6:04:01.280: Ignore due to resend: T:215.52 /285.00 B:55.00 /55.00 @:42 B@:21
Send: 6:04:01.321: Resend: N6238 M140 S110

I can see its setting the hotend to its max temp (285c) and the bed to its max (110c)

I've scoured the Gcode and its definitely not setting the temps in there which leads me to believe that a communication error caused this. This is worrying because it means theres no sort of checking done on the commands that are sent.

It could be a grounding issue on the printer causing the comms to drop out, but I thought repetier would have some sort of error checking in there. I'm on 1.0.4 at the moment and im concerned about continuing to use it.

Repetier

Actually it seems no com error. It is the only line mentioned here as it failed:
Send: 6:04:01.111: N6237 M104 S285 T0
Same with bed
Send: 6:04:01.321: Resend: N6238 M140 S110

That is what has set the temperature. All send commands end with checksum so printer can verify there are no com errors.

From the small part of log it is unclear where it came from. Can be in gcode you send or you selected it in manual controls. But from the fast sequence it does not look like manual action.

Repetier

Just had other idea what it can be. Go in printer menu to printer setup and check if you have defined offset temperatures. Make sure they are all 0. Currently there is a bug that they get only sometimes applied and then you get your set temperature plus offset or when bug triggers the original temperature. Next release will always add the value.

Festivejelly

Its definitely not the gcode as ive scoured it for anything changing the temps, and I ran it again last night and it printed fine.

Temp offsets are set to 0 already. I've updated to the latest version of repetier server now. I wonder if intererence on the USB could have caused this?

Ive made sure everything is grounded now, but it does point to it being a server error:

Send: 6:04:01.213: Resend: N6237 M104 S285 T0

Why would it ever send that when theres no instruction to do so in the gcode?

Repetier

I also think it is no com error. As the line shows the server did send 285°C as temperature. The only question is when any why. So first question is when? Start of print or end print or mid print? Do any gcodes in gcode tab of printer configuration exist that set this temperature so it could be added as response to some event or button? Server never sends anything just for fun - the assignment does exist somewhere.
There is one thing you should know - when you send a temperature too high or printer sets it on it's own server would reduce it to max. temperature. If this happens frequently you should enable logging so it is easier to see what happens at that point. In your log most of the communication especially the crucial part how that happened is missing, so all is just speculation.

Festivejelly

This happened again and caused the printer to go to max temps one more

I have enabled logging and this is the output

Recv:1:47:35.466: T:215.00 /215.00 B:65.77 /110.00 @:39 B@:127

Recv:1:47:36.475: T:215.26 /21500 B:65.97 /110.00 @:37 B@127

Recv:1:47:36.913: cho:Unknown command"AT"

Recv:1:47:36.914: o

Recv:1:47:37.474: :215.21 /215.00 B:66.19 /110.00 @:38 B@:127

Recv:1:47:38.474: :215.52/215.00 B:66.34 /110.00 @:35 B@:127

Mesg:1:47:38.545: Warning: Communication timeout - resetting communication buffer.

Mesg:1:47:38.545: Connection status: Buffered:92, Manual Commands: 1, Job Commands: 5000

Mesg:1:47:38.545: Buffer used:92 Enforced free byte:43 lines stored:2

Send:1:47:38.545: M117 ETA 09:21:20 day 24

Send:1:47:38.545: N14754 G1 X140.586 Y132.639 E1394.14889

Recv:1:47:38.549: ok

Send:1:47:38.549: N14755 G1 X140.586 Y132.073 E1394.17525

Recv:1:47:38.551: ok

Send:1:47:38.551: N14756 G1 X140.458 Y132.201 E1394.18367

Recv:1:47:38.553: ok

Send:1:47:38.553: N14757 G1 X140.458 Y131.635 E1394.21003

Recv:1:47:38.554: ok

Send:1:47:38.554: N14758 G1 X140.586 Y131.507 E1394.21846

Recv:1:47:38.557: k

Send:1:47:38.557: N14759 G1 X140.586 Y130.942 E1394.24477

Recv:1:47:40.475: T:215.83 /215.00 B:66.51 /110.00 @:31 B@:7 T:215.89 /215.00 B:66.70 /11000 @:32 B@:127

Recv:1:47:41.475: :215.78 /215.00 B:66.82 /110.00 @:33 B@:127

Recv:1:47:42.475: T:215.89 /215.00 B:67.06 /10.00 @:32 B@:127

Mesg:1:47:42.566: Warning: Communication timeout - resetting communication buffer.

Mesg:1:47:42.566: Connection status: Buffered:86, Manual Commands: 1, Job Commands: 5000

Mesg:1:47:42.566: Buffer used:86 Enforced free byte:23 lines stored:2

Send:1:47:42.567: N14760 M104 S285 T0

Send:1:47:42.569: N14761 G1 X140.458 Y131.07 E1394.2532

Recv:1:47:42.572: echo:Unknown command: "~"

Recv:1:47:42.572: ok

Send:1:47:42.573: N14762 G1 X140.458 Y130.504 E1394.27955

Recv:1:47:42.584: ror:Line Number is not Last LiNumber+1, Last Line: 14759

Recv:1:47:43.475: Rse T:15.83 /215.00 B:67.16 10.00 @:33 B@:127

Recv:1:47:44.475: :215.83/15.00 B:67.39 /110.00 @:33 B@:127

Send:1:47:45.285: M117 ETE 07:33:45

Recv:1:47:45.291: eho:Unknwn command: "~"

Recv:1:47:45.291: ok

Recv:1:47:45.474: T:215.68 /215.00 B:67.53 /110.00 @:34 B@:127

Recv:1:47:46.474: T:215.62 /215.00 B:67.78 /110.00 @:35 B@:127

Recv:1:47:47.474: T:215.73 /215.00 B:67.93 /110.00 @:33 B@:127

Recv:1:47:48.474: T:215.21 /215.00 B:68.12 /110.00 @:39 B@:127

Mesg:1:47:49.293: Warning: Communication timeout - resetting communication buffer.

Mesg:1:47:49.293: Connection status: Buffered:61, Manual Commands: 0, Job Commands: 5000

Mesg:1:47:49.293: Buffer used:61 Enforced free byte:43 lines stored:2

Send:1:47:49.293: N14763 G1 X140.586 Y130.376 E1394.28798

Send:1:47:49.293: N14764 G1 X140.586 Y129.81 E1394.31434

Recv:1:47:49.305: Error:Line Number is not Last Line Number+1, Last Line: 14759

Recv:1:47:49.309: Resend: 14760

Recv:1:47:49.327: Waiting for resend requests finished. Starting resends ...

Send:1:47:49.327: Resend: N14760 M104 S285 T0

Recv:1:47:49.329: ok

Send:1:47:49.329: Resend: N14761 G1 X140.458 Y131.07 E1394.2532

Recv:1:47:49.331: ok

Send:1:47:49.331: Resend: N14762 G1 X140.458 Y130.504 E1394.27955

Recv:1:47:49.332: ok

Send:1:47:49.333: M117 ETE 07:33:45

Recv:1:47:49.334: ok

Send:1:47:49.334: Resend: N14763 G1 X140.586 Y130.376 E1394.28798

Recv:1:47:49.336: ok

Send:1:47:49.336: Resend: N14764 G1 X140.586 Y129.81 E1394.31434

Send:1:47:49.336: N14765 G1 X140.458 Y129.938 E1394.32276

Recv:1:47:49.339: ok

Send:1:47:49.339: N14766 G1 X140.458 Y129.372 E1394.34912

Recv:1:47:49.341: ok

Send:1:47:49.341: N14767 G1 X140.586 Y129.244 E1394.35755

Recv:1:47:49.343: ok

Send:1:47:49.343: N14768 G1 X140.586 Y128.679 E1394.38386

Recv:1:47:49.345: ok

Send:1:47:49.345: N14769 G1 X140.458 Y128.807 E1394.39229

Recv:1:47:49.347: ok

Send:1:47:49.347: N14770 G1 X140.458 Y128.241 E1394.41864

Recv:1:47:49.349: ok

Send:1:47:49.349: N14771 G1 X140.586 Y128.113 E1394.42707

Recv:1:47:49.351: ok

Send:1:47:49.351: N14772 G1 X140.586 Y127.547 E1394.45343

Recv:1:47:49.352: ok

Send:1:47:49.353: N14773 G1 X140.458 Y127.675 E1394.46186

Recv:1:47:49.354: ok

Send:1:47:49.354: N14774 G1 X140.458 Y127.11 E1394.48816

Recv:1:47:49.356: ok

Send:1:47:49.356: N14775 G1 X140.586 Y126.982 E1394.49659

Recv:1:47:49.358: ok

Send:1:47:49.358: N14776 G1 X140.586 Y126.416 E1394.52295

Recv:1:47:49.360: ok

Send:1:47:49.360: N14777 G1 X140.458 Y126.544 E1394.53138

Recv:1:47:49.362: ok

Send:1:47:49.362: N14778 G1 X140.458 Y125.978 E1394.55773

Recv:1:47:49.392: ok

Send:1:47:49.392: N14779 G1 X140.586 Y125.85 E1394.56616

Recv:1:47:49.411: ok

Send:1:47:49.411: N14780 G1 X140.586 Y125.285 E1394.59247

Recv:1:47:49.439: ok

Send:1:47:49.439: N14781 G1 X140.458 Y125.413 E1394.6009

Recv:1:47:49.454: ok

Send:1:47:49.454: N14782 G1 X140.458 Y124.847 E1394.62726

Recv:1:47:49.475: T:215.26 /285.00 B:68.25 /110.00 @:127 B@:127

Festivejelly

The key point is that the server seems to be sending this command?

Send:1:47:42.567: N14760 M104 S285 T0

I dont understand why the server would be doing that all of a sudden.

Repetier

Reason is this response

Recv:1:47:36.475: T:215.26 /21500 B:65.97 /110.00 @:37 B@127

Printer reported a temperature 21500°C so it took that value. Now when the knob in webbrowser gets that it sees it is > max temp. and reduces it to set max. temperature which seems to be 285°C.

As this does not make sense I will modify server temperature handling and prevent assuming temperatures > max temperature when reported from firmware. Should at least fix obvious errors that are impossible. Here from missing dot.

Festivejelly

Got more issues with this, I think because of communication issues it doesnt get the correct message so sets the temp to max on both which ruins the print. PLA does not like 285 max and 110c max.

I kinda feel like there should be some validation of the commands. As I understand it, the server reads the gcode line by line, and sends it and looks for an ok.

But I guess this is the stuff that needs to be done on firmware on the printer. To validate the communication it was sent was valid.

Repetier

Didn't you upgrade to latest version. Checking the code I see I had already fixed the issue by ignoring all temperatures reported being higher than max temperature, so a wrong send temperature that is too high would not be possible with current release. Only thing that can go wrong is, if reported temperature is inside allowed area, but that would not trigger a new set temp so should do no harm and get corrected with next temperature report.

Festivejelly

I have now updated and the problem I got was that it was trying to cold extrude. I narrowed the issues down to the USB or maybe the screen on my machine contacting the enclosure of the printer and causing some sort of disruption in the communication. I think Marlin as at fault ultimately as its clearly not validating the commands using the checksum. If it did then it couldnt get the wrong commands because the communication was interrupted (I thought that was the whole point of a checksum).

I solved this by basically wrapping the screen and USB cable in non conductive material, problem gone. (For reference the printer is an ender 5 with SKR Mini).

I appreciate the update though for limiting the temperature, it certainly has saved messy cleanups on the hotend. I think ill raise a bug report on the marlin github.

Repetier

In this case the problem was answer from marlin. Unfortunately the protocol does not support checksums in answers, so it is uncertain if they are correct or not.

But it is from com errors and better shielding is often a solution here.