Failed print - XYZ motors appear stopped, filament still extruding
Has anyone had XYZ motors stop but extruding continues? Luckily caught it in time. I had 3 successful prints of the same model before this failure. See video:
Here's the model:
https://www.myminifactory.com/object/angel-stormtrooper-16481
Running 3.1.1 RC2 B137 with Octoprint 1.36. I was able to grab some of the terminal output from Octoprint (see below). There are some strange "Recv: echo:busy: processing" messages in the terminal. I wasn't able to stop the print via Octoprint...eventually just reset the printer.
Any ideas?
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: ok
Send: N161832 M105*24
Recv: ok T:209.5 /210.0 B:60.2 /60.0 T0:209.5 /210.0 @:99 B@:0 P:45.2 A:42.0
Send: N161833 M117 30.10p complete*111
Recv: ok
Send: N161834 M117 ETL 02h29m23s*62
Recv: ok
Send: N161835 M117 ETA 00 05 22 Day 21*22
Recv: ok
Send: N161836 M117 30.10p complete*106
Recv: ok
Send: N161837 M117 ETL 02h29m23s*61
Recv: ok
Send: N161838 M117 ETA 00 05 40 Day 21*31
Recv: ok
Send: N161839 M117 30.10p complete*101
Recv: ok
Send: N161840 M117 ETL 02h29m23s*61
Recv: ok
Send: N161841 M117 ETA 00 05 52 Day 21*18
Recv: ok
Send: N161842 M117 30.10p complete*105
Recv: ok
Send: N161843 M117 ETL 02h29m23s*62
Recv: ok
Send: N161844 M117 ETA 00 06 10 Day 21*18
Recv: ok
Send: N161845 M117 30.10p complete*110
Recv: ok
Send: N161846 M117 ETL 02h29m23s*59
Recv: ok
Send: N161847 M117 ETA 00 06 22 Day 21*16
Recv: ok
Send: N161848 M117 30.10p complete*99
Recv: ok
Send: N161849 G1 X111.885 Y85.811 E0.00754*102
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: ok
Send: N161850 M105*28
Recv: ok T:211.3 /210.0 B:60.0 /60.0 T0:211.3 /210.0 @:73 B@:29 P:46.2 A:41.8
Send: N161851 M117 ETL 02h28m02s*63
Recv: ok
Send: N161852 M117 ETA 00 05 19 Day 21*31
Recv: ok
Send: N161853 M117 30.10p complete*105
Recv: ok
Send: N161854 M117 ETL 02h28m02s*58
Recv: ok
Send: N161855 M117 ETA 00 05 31 Day 21*18
Recv: ok
Send: N161856 M117 30.10p complete*108
Recv: ok
Send: N161857 M117 ETL 02h28m02s*57
Recv: ok
Send: N161858 M117 ETA 00 05 49 Day 21*16
Recv: ok
Send: N161859 M117 30.10p complete*99
Recv: ok
Send: N161860 M117 ETL 02h28m02s*61
Recv: ok
Send: N161861 M117 ETA 00 06 01 Day 21*21
Recv: ok
Send: N161862 M117 30.10p complete*107
Recv: ok
Send: N161863 M117 ETL 02h28m02s*62
Recv: ok
Send: N161864 M117 ETA 00 06 19 Day 21*25
Recv: ok
Send: N161865 M117 30.10p complete*108
Recv: ok
Send: N161866 M117 ETL 02h28m02s*59
Recv: ok
Send: N161867 M117 ETA 00 06 31 Day 21*16
Recv: ok
Send: N161868 M117 30.10p complete*97
Recv: ok
Send: N161869 M117 ETL 02h28m02s*52
Recv: ok
Send: N161870 G1 X111.824 Y85.786 E0.00223*99
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: ok
Send: N161871 M105*31
Recv: ok T:209.9 /210.0 B:60.2 /60.0 T0:209.9 /210.0 @:77 B@:0 P:44.2 A:41.8
Send: N161872 M117 ETA 00 05 17 Day 21*19
Recv: ok
Send: N161873 M117 30.10p complete*107
Recv: ok
Send: N161874 M117 ETL 02h26m30s*55
Recv: ok
Send: N161875 M117 ETA 00 05 29 Day 21*25
Recv: ok
Send: N161876 M117 30.10p complete*110
Recv: ok
Send: N161877 M117 ETL 02h26m30s*52
Recv: ok
Send: N161878 M117 ETA 00 05 47 Day 21*28
Recv: ok
Send: N161879 M117 30.10p complete*97
Recv: ok
Send: N161880 M117 ETL 02h26m30s*60
Recv: ok
Send: N161881 M117 ETA 00 05 59 Day 21*21
Recv: ok
Send: N161882 M117 30.10p complete*101
Recv: ok
Send: N161883 M117 ETL 02h26m30s*63
Recv: ok
Send: N161884 M117 ETA 00 06 17 Day 21*25
Recv: ok
Send: N161885 M117 30.10p complete*98
Recv: ok
Send: N161886 M117 ETL 02h26m30s*58
Recv: ok
Send: N161887 M117 ETA 00 06 29 Day 21*23
Recv: ok
Send: N161888 M117 30.10p complete*111
Recv: ok
Send: N161889 M117 ETL 02h26m30s*53
Recv: ok
Send: N161890 G1 X111.692 Y85.784 E0.00448*103
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Changing monitoring state from 'Printing' to 'Operational'
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: ok
Send: M400
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: echo:busy: processing
Recv: \x00start
Printer sent 'start' while already operational. External reset? Resetting line numbers to be on the safe side
Recv: echo:echo: Last Updated: Dec 15 2017 18:45:44 | Author: (none, default config)
Recv: Compiled: Dec 15 2017
Recv: echo: Free Memory: 1549 PlannerBufferBytes: 1392
Recv: echo:Hardcoded Default Settings Loaded
Recv: crashdet_enable
Recv: CrashDetect ENABLED!
Recv: PAT9125_init:1
Recv: FSensor
Recv: DISABLED
Recv:
Recv: fsensor_disable
Recv:
Recv: tmc2130_init(), mode=STEALTH
Recv: initial zsteps on power up: 904
Recv: initial zsteps after reset: 1016
Recv: echo:SD card ok
Re: Failed print - XYZ motors appear stopped, filament still extruding
Similar things happen to me.
I haven't had a successful print since I updated my firmware and plugged in my pi zero.
busy spam then a retry of the last command (usually a move) and then more busy spam, repeat.
edit*
Sitting here with it spamming processing, I was googling for answers (first time using a printer with marlin) and it started moving again... but not extruding. It jams up the extruder some how, maybe it just doesn't run the extruder motor...
edit2*
I confirmed it didn't jam, just retracted a ton... maybe instead of extruding? Kinda sad, was really looking forward to this printer, but so far, I can only really print the preloaded prints and something that has <30 layers.
Re: Failed print - XYZ motors appear stopped, filament still extruding
Same thing happened again this morning.
I was able to grab more of the terminal session from Octoprint (see below). Looks like the printer detected a crash. I'm guessing OctoPrint can't handle that correctly yet? It seems to handle filament running out much better...it actually stops the print. For now I've disabled Crash Detection on the printer. Hopefully Prusa support will see this and comment on a better solution.
Send: N186199 G1 X133.801 Y100.373 E0.02948*85
Recv: ok
Send: N186200 G1 X134.183 Y101.232 E0.03184*94
Recv: echo:enqueing "G1 Z 49.199 E 0.000 F 800.000"
Recv: echo:enqueing "CRASH_DETECTED"
Recv: echo:Unknown command: "188"(2)
Recv: ok
Send: N186201 G1 X134.487 Y102.147 E0.03262*87
Recv: Error:Line Number is not Last Line Number+1, Last Line: 186199
Recv: Resend: 186200
Recv: echo:enqueing "G28 X"
Recv: echo:enqueing "G28 Y"
Recv: echo:enqueing "CRASH_RECOVER"
Recv: G28, initial world coordinates: (131.672, 93.974, 49.199)
Recv: G28, initial physical coordinates: (130.630, 94.310, 49.730)
Recv: echo:busy: processing
Recv: G28, final world coordinates: (1.042, 93.856, 49.628)
Recv: G28, final physical coordinates: (0.000, 94.310, 49.730)
Recv: G28, final mesh bed leveling: 0.142 0.266 0.350 0.396 0.402 0.369 0.297 0.197 0.318 0.408 0.466 0.494 0.490 0.455 0.230 0.354 0.450 0.519 0.561 0.576 0.563 0.240 0.373 0.478 0.555 0.605 0.627 0.622 0.228 0.375 0.490 0.573 0.625 0.644 0.631 0.194 0.361 0.488 0.574 0.620 0.626 0.592 0.137 0.330 0.470 0.558 0.592 0.574 0.503
Recv: G28, initial world coordinates: (1.042, 93.856, 49.628)
Recv: G28, initial physical coordinates: (0.000, 94.310, 49.730)
Recv: echo:busy: processing
Recv: G28, final world coordinates: (1.131, -4.454, 49.734)
Recv: G28, final physical coordinates: (0.000, -4.000, 49.730)
Recv: G28, final mesh bed leveling: 0.142 0.266 0.350 0.396 0.402 0.369 0.297 0.197 0.318 0.408 0.466 0.494 0.490 0.455 0.230 0.354 0.450 0.519 0.561 0.576 0.563 0.240 0.373 0.478 0.555 0.605 0.627 0.622 0.228 0.375 0.490 0.573 0.625 0.644 0.631 0.194 0.361 0.488 0.574 0.620 0.626 0.592 0.137 0.330 0.470 0.558 0.592 0.574 0.503
Recv: echo:busy: processing
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N186199 G1 X133.801 Y100.373 E0.02948*85
Recv: Error:Line Number is not Last Line Number+1, Last Line: 186199
Recv: Resend: 186200
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N186199 G1 X133.801 Y100.373 E0.02948*85
Recv: Error:Line Number is not Last Line Number+1, Last Line: 186199
Recv: Resend: 186200
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N186199 G1 X133.801 Y100.373 E0.02948*85
Recv: Error:Line Number is not Last Line Number+1, Last Line: 186199
Recv: Resend: 186200
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N186199 G1 X133.801 Y100.373 E0.02948*85
Recv: Error:Line Number is not Last Line Number+1, Last Line: 186199
Recv: Resend: 186200
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N186199 G1 X133.801 Y100.373 E0.02948*85
Recv: Error:Line Number is not Last Line Number+1, Last Line: 186199
Recv: Resend: 186200
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N186199 G1 X133.801 Y100.373 E0.02948*85
Recv: Error:Line Number is not Last Line Number+1, Last Line: 186199
Recv: Resend: 186200
Re: Failed print - XYZ motors appear stopped, filament still extruding
Good find!
Too bad. I wonder and hope that the Prusa team is looking into better octoprint support. It’s really the only way I’ll use the printer, and what I expected from the pi zero features.
Re: Failed print - XYZ motors appear stopped, filament still extruding
Same thing here, I went back to RPi3
