Octoprint causes faulty start, despite Terminal reflecting normal

Get Help
1

What is the problem?
I've been having this problem for a while, and I've run out of things to try.

When starting any print, it seems as if the printer has a mind of its own, while the Terminal tab in Octoprint seems to be reflecting a normal print. It always happens part way through my start Gcode, which is below.

G28 ; Home all axes
G92 E0 ; Reset Extruder
G1 Z2.0 F3000 ; Move Z Axis up little to prevent scratching of Heat Bed
G1 X0.1 Y20 Z0.3 F5000.0 ; Move to start position
G1 X0.1 Y200.0 Z0.3 F1500.0 E15 ; Draw the first line
G1 X0.4 Y200.0 Z0.3 F5000.0 ; Move to side a little
G1 X0.4 Y20 Z0.3 F1500.0 E30 ; Draw the second line
G92 E0 ; Reset Extruder
G1 Z2.0 F3000 ; Move Z Axis up little to prevent scratching of Heat Bed
; End of custom start GCode

My printer homes to X0,Y0,Z0 then moves to X0.1 Y20 Z0.3 and then extrudes filament to prime the nozzle as it moves to X0.1 Y200 Z0.3. Suddenly, it speeds up and goes beyond X0.1 Y200 to Y310, then changes direction and proceeds to X310 Y310 Z5.0 (maybe higher, its an estimate of the Z axis change) and just extrudes filament nonstop until I turn the printer off or cancel the print via Octoprint. If I cancel the print via Octoprint and try to print again, the issue will happen immediately. If I turn off the printer and unplug the USB cable, I may have a few prints before it returns.

What did you already try to solve it?
I tried different STL files, old files, newly sliced files, there was no change.
I tried running Octoprint in Safe Mode (if you need to know when, I believe it was somewhere just after midnight on Feb 12th in the log). There was no change.
I tried opening up my control box and added an external fan to determine if the printer was overheating, there was no change.
I added this external fan to my Pi, there was no change.
I upgraded my Motherboard from stock CR10 to CR10s, which also resulted in changing my printers firmware, there was no change.
I checked my gcode files and confirmed, the start gcode I posted is what is in the file...however, I just checked the Terminal output from the most recent incident, and I noticed this, please see the lines in BOLD.
Recv: T:208.91 /210.00 B:50.36 /50.00 @:103 B@:0
Recv: echo:busy: processing
Recv: T:208.91 /210.00 B:50.15 /50.00 @:98 B@:0
Recv: X:-3.00 Y:-9.00 Z:0.00 E:731.05 Count X:-240 Y:-719 Z:0
Recv: ok
Send: N9 G92 E078
Recv: X:-3.00 Y:-9.00 Z:0.00 E:0.00 Count X:-240 Y:-719 Z:0
Recv: ok
Send: N10 G1 Z2.0 F300042
Recv: ok
Send: N11 G1 X0.1 Y20 Z0.3 F5000.030
Recv: ok
Send: N12 G1 X0.1 Y200.0 Z0.3 F1500.0 E1583
Recv: ok
Send: N13 G1 X0.4 Y200.0 Z0.3 F5000.055
Recv: ok
Send: N14 G1 X0.4 Y20 Z0.3 F1500.0 E30121
Recv: ok
Send: N15 G92 E0115
Recv: X:-2.00 Y:300.00 Z:3.20 E:0.00 Count X:-240 Y:-719 Z:9
Recv: ok
Send: N16 G1 Z2.0 F300044
Recv: ok
Send: N17 G92 E0113
Recv: X:-2.00 Y:300.00 Z:5.20 E:0.00 Count X:-240 Y:-719 Z:303
Recv: ok
Send: N18 G1 F2400 E-413
Recv: ok
Send: N19 M10729
Recv: ok
Send: N20 M204 S500097
Recv: ok
Send: N21 G0 F3750 X169.798 Y159.798 Z0.24*29

Additional information about your setup
OctoPrint 1.3.12 running on OctoPi 0.16.0 (Running on RP3B+, dedicated power supply from Adafruit).
CR10/CR10S (swapped boards thinking it was a MB issue) with TH3D firmware U1.R2.A3 (just updated from U1.R2.12)

Accessing Octoprint on Windows 10 PC using Firefox version 72.0.2

Logs
Octoprint Log, I believe this latest episode started around 10pm on October 11th, just because I see that file is rather long. (If this doesn't attach properly, I will post a response and paste it.
octoprint.log (429.4 KB)

I have not turned on the serial.log, but can if its deemed necessary. Here is the Terminal ouput I cut and pasted. Please note, the Cancelling at the end was because I saw the issue taking place and cancelled it in Octoprint.

Send: N9 G92 E0*78
Recv: X:-3.00 Y:-9.00 Z:0.00 E:0.00 Count X:-240 Y:-719 Z:0
Recv: ok
Send: N10 G1 Z2.0 F3000*42
Recv: ok
Send: N11 G1 X0.1 Y20 Z0.3 F5000.0*30
Recv: ok
Send: N12 G1 X0.1 Y200.0 Z0.3 F1500.0 E15*83
Recv: ok
Send: N13 G1 X0.4 Y200.0 Z0.3 F5000.0*55
Recv: ok
Send: N14 G1 X0.4 Y20 Z0.3 F1500.0 E30*121
Recv: ok
Send: N15 G92 E0*115
Recv: X:-2.00 Y:300.00 Z:3.20 E:0.00 Count X:-240 Y:-719 Z:59
Recv: ok
Send: N16 G1 Z2.0 F3000*44
Recv: ok
Send: N17 G92 E0*113
Recv: X:-2.00 Y:300.00 Z:5.20 E:0.00 Count X:-240 Y:-719 Z:194
Recv: ok
Send: N18 G1 F4200 E-4*13
Recv: ok
Send: N19 M107*29
Recv: ok
Send: N20 M204 S5000*97
Recv: ok
Send: N21 G0 F3750 X169.798 Y159.798 Z0.24*29
Recv: ok
Send: N22 M204 S400*82
Recv: ok
Send: N23 G1 F4200 E0*44
Recv: ok
Send: N24 G1 F1500 X130.202 Y159.798 E1.61213*57
Recv: ok
Send: N25 G1 X130.202 Y140.202 E2.40997*83
Recv: ok
Send: N26 G1 X169.798 Y140.202 E4.02209*86
Recv: ok
Send: N27 G1 X169.798 Y159.14 E4.79314*107
Recv: ok
Send: N28 G0 F1350 X169.798 Y159.798*112
Recv: ok
Send: N29 M204 S5000*104
Recv: ok
Send: N30 G0 F3750 X169.598 Y159.798*125
Recv: ok
Send: N31 G0 X169.394 Y159.394*25
Recv: ok
Send: N32 M204 S400*83
Recv: ok
Send: N33 G1 F4200 E4.81993*61
Recv: ok
Send: N34 G1 F1500 X130.606 Y159.394 E6.39916*52
Recv: ok
Send: N35 G1 X130.606 Y140.606 E7.16411*87
Recv: ok
Send: N36 G1 X169.394 Y140.606 E8.74334*93
Recv: ok
Send: N37 G1 X169.394 Y158.736 E9.48149*81
Recv:  T:208.83 /210.00 B:50.10 /50.00 @:106 B@:0
Recv: echo:busy: processing
Recv:  T:210.51 /210.00 B:50.23 /50.00 @:52 B@:0
Recv: echo:busy: processing
Recv:  T:210.94 /210.00 B:50.09 /50.00 @:43 B@:0
Recv: echo:busy: processing
Recv:  T:211.72 /210.00 B:50.00 /50.00 @:29 B@:0
Recv: ok
Send: N38 G0 F1350 X169.394 Y159.394*113
Recv:  T:209.26 /210.00 B:50.17 /50.00 @:102 B@:0
Recv: ok
Send: N39 M204 S5000*105
Recv: ok
Send: N40 G0 F3750 X168.99 Y158.99*120
Recv: ok
Send: N41 M204 S400*87
Recv: ok
Send: N42 G1 F4200 E9.50828*59
Recv: ok
Send: N43 G1 F1500 X131.01 Y158.99 E11.05461*15
Recv: ok
Send: N44 G1 X131.01 Y141.01 E11.78665*111
Recv: ok
Send: N45 G1 X168.99 Y141.01 E13.33299*105
Recv: ok
Send: N46 G1 X168.99 Y158.332 E14.03824*89
Recv: ok
Send: N47 G0 F1350 X168.99 Y158.99*121
Recv:  T:208.98 /210.00 B:50.11 /50.00 @:103 B@:0
Recv: echo:busy: processing
Recv: ok
Send: N48 M204 S5000*111
Recv:  T:209.34 /210.00 B:50.27 /50.00 @:84 B@:127
Recv: ok
Send: N49 G0 F3750 X168.586 Y158.586*113
Recv: ok
Send: N50 M204 S400*87
Recv: ok
Send: N51 G1 F4200 E14.06503*2
Recv: ok
Send: N52 G1 F1500 X131.414 Y158.586 E15.57847*15
Recv:  T:209.92 /210.00 B:50.15 /50.00 @:64 B@:0
Recv: echo:busy: processing
Recv:  T:210.70 /210.00 B:49.91 /50.00 @:52 B@:127
Recv: echo:busy: processing
Recv: ok
Send: N53 G1 X131.414 Y141.414 E16.27762*98
Recv: ok
Send: N54 G1 X168.586 Y141.414 E17.79105*110
Recv: ok
Send: N55 G1 X168.586 Y157.928 E18.46341*107
Recv: ok
Send: N56 G0 F1350 X168.586 Y158.586*121
Recv: ok
Send: N57 M204 S5000*97
Recv: ok
Send: N58 G0 F3750 X168.192 Y158.192*113
Recv:  T:210.51 /210.00 B:50.12 /50.00 @:67 B@:0
Recv: ok
Send: N59 M204 S400*94
Recv: ok
Send: N60 G1 F4200 E18.4902*51
Recv: ok
Send: N61 G1 F1500 X131.808 Y158.192 E19.97155*5
Recv: ok
Send: N62 G1 X131.808 Y141.808 E20.63862*106
Recv: ok
Send: N63 G1 X168.192 Y141.808 E22.11997*97
Recv: ok
Send: N64 G1 X168.192 Y157.534 E22.76024*99
Recv: ok
Send: N65 G0 F1350 X168.192 Y158.192*121
Recv: ok
Send: N66 M204 S5000*99
Recv: ok
Send: N67 G0 F3750 X168.476 Y158.192*114
Recv: ok
Send: N68 G0 X168.476 Y142.298*24
Recv: ok
Send: N69 G0 X168.009 Y142.298*21
Recv: ok
Send: N70 M204 S400*85
Recv: ok
Send: N71 G1 F4200 E22.78703*14
Recv: ok
Send: N72 G1 F1500 X167.7 Y141.99 E22.8048*2
Recv: ok
Send: N73 M204 S5000*103
Recv: ok
Send: N74 G0 F3750 X167.129 Y141.99*66
Recv:  T:210.59 /210.00 B:49.84 /50.00 @:63 B@:0
Recv: ok
Send: N75 M204 S400*80
Recv: ok
Send: N76 G1 F1500 X168.009 Y142.87 E22.85547*52
Recv: ok
Send: N77 M204 S5000*99
Recv: ok
Send: N78 G0 F3750 X168.009 Y143.441*113
Recv: ok
Send: N79 M204 S400*92
Recv: ok
Send: N80 G1 F1500 X166.558 Y141.99 E22.93901*55
Recv: ok
Send: N81 M204 S5000*106
Recv: ok
Send: N82 G0 F3750 X165.986 Y141.99*68
Recv: ok
Send: N83 M204 S400*89
Recv: ok
Send: N84 G1 F1500 X168.009 Y144.012 E23.05547*10
Recv: ok
Send: N85 M204 S5000*110
Recv: ok
Send: N86 G0 F3750 X168.009 Y144.584*127
Recv: ok
Send: N87 M204 S400*93
Recv: ok
Send: N88 G1 F1500 X165.415 Y141.99 E23.20483*58
Recv: ok
Send: N89 M204 S5000*98
Recv: ok
Send: N90 G0 F3750 X164.844 Y141.99*73
Recv:  T:208.95 /210.00 B:50.27 /50.00 @:97 B@:0
Recv: ok
Send: N91 M204 S400*90
Recv: ok
Send: N92 G1 F1500 X168.009 Y145.155 E23.38706*7
Recv: ok
Send: N93 M204 S5000*105
Recv: ok
Send: N94 G0 F3750 X168.009 Y145.726*119
Recv: ok
Send: N95 M204 S400*94
Recv: ok
Send: N96 G1 F1500 X164.272 Y141.99 E23.60221*57
Recv: ok
Send: N97 M204 S5000*109
Recv: ok
Send: N98 G0 F3750 X163.701 Y141.99*72
Recv: ok
Send: N99 M204 S400*82
Recv: ok
Send: N100 G1 F1500 X168.009 Y146.298 E23.85026*63
Recv: ok
Send: N101 M204 S5000*83
Recv: ok
Send: N102 G0 F3750 X168.009 Y146.869*78
Recv:  T:207.46 /210.00 B:50.11 /50.00 @:127 B@:0
Recv: ok
Send: N103 M204 S400*96
Recv: ok
Send: N104 G1 F1500 X163.13 Y141.99 E24.13118*59
Recv: ok
Send: N105 M204 S5000*87
Recv: ok
Send: N106 G0 F3750 X162.558 Y141.99*113
Recv: ok
Send: N107 M204 S400*100
Recv: ok
Send: N108 G1 F1500 X168.009 Y147.44 E24.44502*12
Recv: ok
Send: N109 M204 S5000*91
Recv: ok
Send: N110 G0 F3750 X168.009 Y148.012*71
Recv: ok
Send: N111 M204 S400*99
Recv: ok
Send: N112 G1 F1500 X161.987 Y141.99 E24.79176*14
Recv: ok
Send: N113 M204 S5000*80
Recv: ok
Send: N114 G0 F3750 X161.416 Y141.99*122
Recv:  T:208.95 /210.00 B:50.04 /50.00 @:84 B@:127
Recv: ok
Send: N115 M204 S400*103
Recv: ok
Send: N116 G1 F1500 X168.009 Y148.583 E25.17137*55
Recv: ok
Send: N117 M204 S5000*84
Recv: ok
Send: N118 G0 F3750 X168.009 Y149.154*77
Recv: ok
Send: N119 M204 S400*107
Recv: ok
Send: N120 G1 F1500 X160.844 Y141.99 E25.5839*56
Recv: ok
Send: N121 M204 S5000*81
Recv: ok
Send: N122 G0 F3750 X160.273 Y141.99*123
Recv: ok
Send: N123 M204 S400*98
Recv: ok
Send: N124 G1 F1500 X168.009 Y149.726 E26.02933*49
Recv:  T:210.51 /210.00 B:50.00 /50.00 @:45 B@:0
Recv: ok
Send: N125 M204 S5000*85
Recv: ok
Send: N126 G0 F3750 X168.009 Y150.297*68
Recv: ok
Send: N127 M204 S400*102
Recv: ok
Send: N128 G1 F1500 X159.702 Y141.99 E26.50763*4
Recv: ok
Send: N129 M204 S5000*89
Recv: ok
Send: N130 G0 F3750 X159.13 Y141.99*70
Recv: ok
Send: N131 M204 S400*97
Recv: ok
Send: N132 G1 F1500 X168.009 Y150.869 E27.01888*57
Recv: ok
Send: N133 M204 S5000*82
Recv: ok
Send: N134 G0 F3750 X168.009 Y151.44*122
Recv:  T:210.04 /210.00 B:49.98 /50.00 @:69 B@:0
Recv: ok
Send: N135 M204 S400*101
Recv: ok
Send: N136 G1 F1500 X158.559 Y141.99 E27.563*0
Recv: ok
Send: N137 M204 S5000*86
Recv: ok
Send: N138 G0 F3750 X157.988 Y141.99*123
Changing monitoring state from "Printing" to "Cancelling"
Recv: ok
2

On a whim, I tried swapping my start gcode to extrude along the X axis instead of Y and printed a different model. The outcome was the same, yet different. The issue happened, but since the instructions were to proceed along the X axis, the issue arose and took the nozzle to X299.2 where I cancelled the print via Octoprint web access.

Here is from the Terminal, please see the BOLD lines.

Send: N9 G92 E078
Recv: X:-3.00 Y:-9.00 Z:0.00 E:0.00 Count X:-240 Y:-719 Z:0
Recv: ok
Send: N10 G1 Z2.0 F300042
Recv: ok
Send: N11 G1 X2.0 Y5.0 Z0.3 F5000.052
Recv: ok
Send: N12 G1 X150.0 Y5.0 Z0.3 F1500.0 E1581
Recv: ok
Send: N13 G1 X150.0 Y4.8 Z0.3 F5000.057
Recv: ok
Send: N14 G1 X0.2.0Y4.8 Z0.3 F1500.0 E3097
Recv: ok
Send: N15 G92 E0115
Recv: X:299.20 Y:10.60 Z:3.20 E:0.00 Count X:-240 Y:-719 Z:11
Recv: ok
Send: N16 G1 Z2.0 F300044
Recv: ok
Send: N17 G92 E0113
Recv: X:299.20 Y:10.60 Z:5.20 E:0.00 Count X:-240 Y:-719 Z:216
Recv: ok
Send: N18 G1 F2400 E-413
Recv: ok
Send: N19 M10729
Recv: ok
Send: N20 M204 S500097
Recv: ok
Send: N21 G0 F3750 X169.798 Y159.798 Z0.2429
Recv: ok
Send: N22 M204 S40082

3

I find it very weird that what feels like every second line is an M204. Stock OctoPrint doesn't inject that.

Can you share a sliced gcode file please, ideally the one from your terminal dump? Also please enable serial.log and share that after a reproduction, just in case something relevant was cut off from the terminal.

Also try printing one of your files that are giving you trouble from your printer's SD.

I see a bunch of finished prints in your log - is the issue intermittent, did it just start occurring, does it depend on your files?

In general OctoPrint will stream whatever files you give it more or less 1:1 to your printer. On especially noisy lines it can happen that commands are misreceived by the firmware but usually the checksumming should prevent this from causing harm. I don't see communication errors so far, that's unsymptomatic for a really noisy line.

4

Hi Foosel!

I have had this issue for probably about 6 months, which is why I have tried so many things in regards to hardware changes and only now submitted this issue. The issue does seem to be intermittent, until it strikes. It seems to only stop once I turn off the printer and unplug the USB cable from the Pi. Trying to replicate the issue, I had a clog I needed to clear so turned off the printer and disconnected the PI, and upon the next print, there was no issue. Upon subsequent prints, it returned.

I can not determine when this issue will strike. I had not been afflicted in quite a few days because I just swapped my printers mainboard out for a new one (thinking my board was going bad and was not correctly reading gcode) and was calibrating it. I have tried slicing different models, using old gcode from files over a year ago, even switched over to Simply3D instead of my usual Cura slicer, and once it strikes, it doesn't matter what changes, it will happen again. I have even ordered a new USB cable thinking perhaps that was causing something (it will be here tomorrow).

The gcode file I have attached, CR10_Stringing_Test.gcode (521.7 KB) is the same gcode which encountered the issue, yet immediately printed fine (without a printer restart/disconnecting the USB) by SD Card.

Here are the serial log and octoprint log (I wasn't sure if attaching a new one with the data since my last upload would help or not).
octoprint.log (589.9 KB)
serial.log (2.2 MB)

I edited the Serial log to save space as it was too large originally. I found the entries around when I fixed my clogging issue and only loaded what followed when I was back up and printing.

Quick update. It now seems that when I cancel the print in Octoprint, and immediately try the print again, its successful. I'm very confused. I've done this 2 times now (issue is encountered, stop the print and print it again) and once the print completes, I will attach the logs again.

5

I never got any further advice, so I decided to bite the bullet and start from scratch again. I used a different SD card and installed Octoprint again.

So far, the issue has not returned. I was thinking perhaps the old SD card could have been an issue, but it was a SanDisk Ultra card, 16gb and not that old. I'm not sure what the ultimate cause was, but figured for anyone else who might hit this, a follow up of the 'cure' so far might be wanted.

1 Like
6

Ok, as soon as I wrote I was good....it happened. What I found was that the issue seems to be resolved by simply restarting the Printer. Since i have a TP Link plug, and I installed the plugin, I just have an end script that shuts off the plug, so the power is killed. Once I go to print, it turns the plug on, connects and all is well!

Still a really weird issue.

7

Make sure it's also gracefully shutting down Raspbian before it kills power.