OctoPrint / OctoPrint

OctoPrint is the snappy web interface for your 3D printer!
https://octoprint.org
GNU Affero General Public License v3.0
8.31k stars 1.67k forks source link

Unwanted Tool Change - Delta, Rostock MAX v3, dual extruder, Using Single, OctoPi, USB Printing #3031

Closed EliW closed 5 years ago

EliW commented 5 years ago

What were you doing?

I recently had my connected old-windows machine that I used to use for printing on my Rostock Max V3 via Simplify3D die ... instead of replacing it, I decided it would be cheaper/better to just replace it with an OctoPi, and then use S3D from wherever I wanted, drop files up to the OctoPi, and go. Cheaper, and no separate machine to maintain. But my first prints are having these issues.

Steps to reproduce:

  1. Sliced Gcode for a single color, Tool 0, print using S3D (gcode attached)
  2. Ensure it is a 'big enough' print. IE: Attached gcode or other 'normal size' prints show this issue. A tiny calibration test, will complete.
  3. Upload it to local storage on OctoPi
  4. Begin printing (over USB via OctoPi)

What did you expect to happen?

Expected complete print, of a single color filament.

What happened instead?

Four times I tried this and found that it just stopped printing after a certain height. (Did not measure but was consistent ... perhaps 2-3mm). After enough times, thinking that I had a clogged nozzle, but now getting suspicious about it stopping at a fairly consistent spot. I watched closer.

And I realized that it was doing a tool change at that point. And trying to extrude with the second extruder (which had no filament in it). I couldn't find any information about this via googling, to figure out why this would exist. But appears to have only been caused by using the OctoPrint.

I did reach out on a forum, where someone told me: "Oh yeah, it's a bug with OctoPrint, you can't use it with Y-based dual extruders". Being a computer programmer myself, my response to that was: "Well I hope someone told them, because that obviously should be fixable". And hence filing this.

Did the same happen when running OctoPrint in safe mode?

Did not run in Safe Mode, because I've not installed anything else. Just a stock install of OctoPi and then upgraded.

Version of OctoPrint

Operating System running OctoPrint

OctoPrint 1.3.10 running on OctoPi 0.15.1

Printer model & used firmware incl. version

Rostock Max V3 - Rambo board Dual Extruder upgrade (Y-tube w/ Bowden)

Send: N135460 M115*19 Recv: ok Recv: FIRMWARE_NAME:Repetier_0.92.2 FIRMWARE_DATE:20171204 MACHINE_TYPE:Rostock MAX v3 Dual Recv: Printed filament:20458.52m Printing time:51 days 12 hours 9 min

Browser and version of browser, operating system running browser

n/a

Link to octoprint.log

Do not have one of exact failure point. Just finished a print from SD card instead of from Local, and that worked fine. So seems to be some issue with USB communication through OctoPi

Link to contents of terminal tab or serial.log

n/a

Link to contents of Javascript console in the browser

n/a

Screenshot(s)/video(s) showing the problem:

Do not have

I have read the FAQ.

foosel commented 5 years ago

Thank you for reporting this!

Sadly your report lacks some of the information that is needed in order to look into this issue:

(If you need help with locating this stuff, please take a look into the Contribution Guidelines which explains everything - and if anything is still unclear then just ask)

Could you please provide that so this issue can be analyzed and ideally reproduced and fixed? Thank you!

EliW commented 5 years ago

I was 90% sure that I provided the GCODE ... but it's not attached is it. Reattaching. (aaaah! It had disallowed it since it was a .gcode -- I zipped it this time)

3Raspberry_Pi_3_B+Case-_Base.gcode.zip

EliW commented 5 years ago

Attaching Octoprint.log that includes the timeframe this happened. octoprint.log

EliW commented 5 years ago

I do not have a serial.log nor terminal capture from that point in time.

Do you need me to start another print in the 'failure mode' and capture that? (Buh-bye $1 of filament, but worth it if you feel it will help debug)

foosel commented 5 years ago

Do you need me to start another print in the 'failure mode' and capture that?

Yes, please. OctoPrint by default doesn't happily inject tool change commands into the ongoing print, so if that happened here, I need to see what happened around it and if there even was a tool change command sent by OctoPrint.

Also, could you please specify the timeframe that happened in in your octoprint.log?

Side note: You run into an unusually high amount of resend requests according to your log which indicates noise on the line which might also cause misinterpretations on the firmware side (the checksum mechanism built into firmwares isn't exactly collision free). You should check your wiring setup, make sure Pi & printer are getting sufficient power and that the connection between the two is a good quality cable with shielding. It constantly running into Format error or checksum problems is definitely not normal.

EliW commented 5 years ago

Yes, please. OctoPrint by default doesn't happily inject tool change commands into the ongoing print, so if that happened here, I need to see what happened around it and if there even was a tool change command sent by OctoPrint.

nod

Also, could you please specify the timeframe that happened in in your octoprint.log?

Good question. And that's why I didn't originally include it. Over the course of multiple days I kept trying to print, having the failure, assuming clogged nozzle or something else, etc. I wasn't looking at timestamps in particular because I assumed it was a machine issue - and was chatting with my Rostock forum about that.

Looking at the log file actually, and realizing that my Pi is on GMT (and I'm on EST). I think the log I included only has the WORKING print (from SD card) in it.

However looking at the older logs, during any period I would have been printing. It's just full of "server heartbeat" and "tracking event payload {}" messages. Literally nothing of interest.

When I do a reprint-to-failure, I'll include a new log with timestamps..

Side note: You run into an unusually high amount of resend requests [...] You should check your wiring setup, make sure Pi & printer are getting sufficient power and that the connection between the two is a good quality cable with shielding. It constantly running into Format error or checksum problems is definitely not normal.

I'll swap out a different USB cable, in case that's it. But this cable was one that I'd used for a long-time before without incident. It looks like all those resend requests were while I was uploading to the SD card? (that painfully slow process)

EliW commented 5 years ago

Started print at 8:10pm -- Actually started by 8:20pm -- At 9:20pm I noticed via camera that the head was floating (probably by around double the height it went), and killed it.

Log(s) attached

octoprint (1).log serial (1).log

EliW commented 5 years ago

Documenting some times in the serial.log:

Started printing: 2019-02-07 01:11:04,469 Looks like everything was heated up and it started: 2019-02-07 01:15:02,352 I hit the reset button to stop the printer: 2019-02-07 02:21:11,049

foosel commented 5 years ago

The only tool change commands that I see anywhere in the commands sent to your printer through OctoPrint according to that serial.log is a T0 at 2019-02-07 01:15:02,435 and its resend at 2019-02-07 01:15:02,534. I don't know why your printer decides to perform a tool change later, but it's not due to a tool change command that was sent through or by OctoPrint that did it - it appears to happen only in firmware.

I'm also still seeing some wrong checksum and format errors, hinting at some communication issues still being present. Sadly your firmware doesn't appear to report tool changes back via serial as far as I can see, or it would be possible to determine the precise moment things took a turn for the worse.

Going by what I see in the serial.log though, there really is nothing that OctoPrint is doing wrong. It's sending your GCODE file, said file contains one single tool change to T0 right at the beginning of the print, and no other such commands are present anywhere else in the serial.log. Honestly, at this point my money would be on some communication issue leading to the printer thinking it received a tool change command when in fact it didn't, but even then I would expect a notification about the tool change from Repetier Firmware which doesn't happen here. Then again, maybe that particular firmware build is simply too old for that.

Also, I forgot to answer that:

It looks like all those resend requests were while I was uploading to the SD card? (that painfully slow process)

They definitely happened also while printing from the SD, and while streaming a file from OctoPrint through the printer for direct printing.

DanielJoyce commented 5 years ago

To me this sounds like maybe a brownout issue, or problems with floating ground.

EliW commented 5 years ago

So some additional testing I'm doing:

Same USB-cable, works fine printing direct from S3D ... export the S3D and upload to Octoprint, and it has this happen, consistently. Print direct from Octoprint, and this happens.

I did do a test, printing only on T1 ... that worked flawlessly. Print on T0, it switches to T1 at some point. Print on T1, it just works.

Going to be switching to a different USB cable soon. To test that.

EliW commented 5 years ago

To me this sounds like maybe a brownout issue, or problems with floating ground.

@DanielJoyce Can you describe a bit more for me? Given this is consistent, I'm not sure it could be a brownout? (Unless you have a different definition than I do). Can you elaborate on the floating ground/etc as to where you think that would be? You talking about the printer and/or Pi not being grounded properly?

Or the USB cable itself between them?

etc.

foosel commented 5 years ago

Could be that you Pi sinks power into the printer. Could be that you have the USB cable wired slightly differently so that it is more exposed to interference. Could be a grounding issue. Could be a ton of factors. The fact of the matter is, OctoPrint is not initiating that tool change according to your log. Which means it's either the printer, or it's the printer misreading what it gets sent over serial, possibly due to data corruption.

In any case, it's not a bug that can be fixed or even mitigated in OctoPrint, it's an environmental issue. Which is why I'm now closing this, so I know this isn't an open task here. Comments are still open though if you want to discuss things - though, the community is probably better suited for that.

EliW commented 5 years ago

@foosel @DanielJoyce

Some updates:

1) I have tested and found that if I print solely using the 2nd extruder, that it works fine. The problem only happens when printing on the 1st extruder.

2) I have also been using a different USB cable, and those communication errors disappeared.

3) The bug, in this case, is not just environmental IMO - Because of what I said when I first opened this. This came up because there is an entire usergroup for the SeeMeCNC brand of printers - spreading the knowledge that "Yeah, OctoPrint doesn' work with Dual Extrusion Machines, it's a bug, just move on to something else". Because many of them have/had tried it. And ran into this problem in the past. Hence I was wanting to try to help you all solve this. Not only for myself (as I really want to use OctoPrint) ... But also because, as a software developer, I'm sure there's a solution here once the final culprit can be found.

So current summation of situation:

SeeMeCNC - Rostock - Rambo board, Repitier code:

Printing from SD Card:

Using Simplify3D to print directly connected:

Using OctoPrint directly connected, with Gcode from Simplify3D

I guess it could still be an environmental issue, but environment in this case being 'the machine', since it's affecting other people's machines as well. But the fact that Simplify3D can print successfully over a USB connection, and Octoprint cannot. Seems to imply that there is 'something' that can be changed in OctoPrint. -- Though tracking down the exact issue of course is the bigger task.

foosel commented 5 years ago

It might be something in the firmware. But as I said - OctoPrint isn't sending a tool change command to your printer according to your logs. Maybe it's some combination of the (run of the mill) commands that it fetches from your file combined with regular temperature polls or something like that that makes the firmware decide "tool switch", but I sadly cannot do anything for you here considering that OctoPrint isn't sending any kind of tool change commands and the commands it is sending are also not looking suspicious in any way. I also know that OctoPrint runs without problems for a lot of people out there with multi extruder setups, so it's also not a general problem. It really sounds more like it's a problem specific to the SeeMeCNC printers, which makes it sound like firmware.

EliW commented 5 years ago

Yup, understood @foosel ... Just so weird that it seems to be this specific issue. If I get a chance (Currently in production printing mode). I'll attempt another 'normal' print from T0 and sit there the entire time (and/or perhaps set up a video recording so I can rewind to the exact time when the change happens) ... so that I can see exactly the sequence of events that occur then. Isolate them, and then try to repeat it more to see what causes it.

At least at the moment I can just keep printing on T1 all the time unless I'm doing a dual extrude anyway :)

EliW commented 5 years ago

So, new twist. After my 'everythings is working great' discussion (on T1 only) ... I just had a communications failure on at 90% done on a 16hr print.

The error was: State: Offline (Error: Printer requested line 276730 but no sufficient history is available, can't resend)

I'll past the GCODE Viewer window below. But now my question is -- What's the chance that: 1) This is still a USB-cable issue and I should get a brand new one? 2) This is a firmware issue w/ the printer and unsolvable? 3) This is an issue with the new Pi I got (after reading the one story of "tried a different Pi, that works").

Just wondering where I should be focusing my debugging efforts? If you have any advice. (Not that I want to buy another Pi 'just for testing' mind you, but)

It appears to my untrained eye that: 1) OctoPrint sends line N2767304 2) Printer happens to send back a temp update at that moment 3) Printer says 'OK' 4) Printer suddenly says wait wait, wrong checksum. Please resend x304 again. 5) OctoPrint starts sending line x305 through x319 ... 6) Printer each time goes 'skip that', I assume because it's still waiting for that x304 resend. 7) Printer finally goes 'WTF' and sends an error saying 'WANTED x304 OctoPrint . You send me x319 8) Then we get a garbled communication, where I assume the printer was trying to say send me x304. But it came out: "Resend: 276730N276732skip 2767320" ...

And the OctoPrint went 'wtf'.

Send: N2767300 G1 X35.186 Y74.216 E3.0003*90
Recv: ok
Send: N2767301 G1 X34.826 Y74.610 E3.0214*95
Recv: ok
Send: N2767302 M105*34
Recv: ok
Send: N2767303 G1 X34.728 Y74.697 E3.0265*85
Recv: ok
Send: N2767304 G1 X34.316 Y74.875 E3.0443*91
Recv: T:238.13 /240 B:70.25 /70 B@:0 @:244 T0:238.50 /240 @0:170 T1:238.13 /240 @1:244
Recv: ok
Recv: Error:Wrong checksum
Recv: 
Recv: Resend:2767304
Send: N2767305 G1 X34.153 Y74.880 E3.0507*82
Recv: ok
Send: N2767305 G1 X34.153 Y74.880 E3.0507*82
Recv: skip 2767305
Recv: ok
Send: N2767306 G1 X33.237 Y75.006 E3.0872*95
Recv: skip 2767305
Recv: ok
Send: N2767307 G1 X32.623 Y75.165 E3.1123*86
Recv: skip 2767306
Recv: ok
Send: N2767308 G1 X31.764 Y75.342 E3.1469*84
Recv: skip 2767307
Recv: ok
Send: N2767309 G1 X31.082 Y75.296 E3.1739*84
Recv: skip 2767308
Recv: ok
Send: N2767310 G1 X31.080 Y75.216 E3.1771*90
Recv: skip 2767309
Recv: ok
Send: N2767311 G1 X30.978 Y74.854 E3.1919*89
Recv: skip 2767310
Recv: ok
Send: N2767312 G1 X30.862 Y74.656 E3.2010*95
Recv: skip 2767311
Recv: ok
Send: N2767313 G1 X30.581 Y74.416 E3.2156*91
Recv: skip 2767312
Recv: ok
Send: N2767314 G1 X30.173 Y74.280 E3.2326*89
Recv: skip 2767313
Recv: ok
Send: N2767315 G1 X30.169 Y74.083 E3.2403*82
Recv: skip 2767314
Recv: ok
Send: N2767316 G1 X30.200 Y73.922 E3.2468*85
Recv: skip 2767315
Recv: ok
Send: N2767317 G1 X30.193 Y73.542 E3.2618*82
Recv: skip 2767316
Recv: ok
Send: N2767318 G1 X30.152 Y73.206 E3.2752*88
Recv: skip 2767317
Recv: ok
Send: N2767319 G1 X30.189 Y72.474 E3.3041*89
Recv: skip 2767318
Recv: ok
Send: N2767320 G1 X30.102 Y71.598 E3.3389*87
Recv: Error:expected line 2767304 got 2767319
Recv: 
Recv: Resend:276730N276732skip 2767320
Printer requested line 276730 but no sufficient history is available, can't resend
Changing monitoring state from "Printing" to "Error: Printer requested line 276730 but no sufficient history is available, can't resend"
Changing monitoring state from "Error: Printer requested line 276730 but no sufficient history is available, can't resend" to "Offline (Error: Printer requested line 276730 but no sufficient history is available, can't resend)"
Connection closed, closing down monitor

/cc @foosel @DanielJoyce

DanielJoyce commented 5 years ago

This looks really weird I admint:

Send: N2767304 G1 X34.316 Y74.875 E3.0443*91
Recv: T:238.13 /240 B:70.25 /70 B@:0 @:244 T0:238.50 /240 @0:170 T1:238.13 /240 @1:244
Recv: ok
Recv: Error:Wrong checksum
Recv: 
Recv: Resend:2767304
Send: N2767305 G1 X34.153 Y74.880 E3.0507*82

The printer says its ok, then says wrong checksum, then tells it to resend 2767304 which octoprint seemingly ignores.

Send: N2767318 G1 X30.152 Y73.206 E3.2752*88
Recv: skip 2767317
Recv: ok

Plus this is weird. Is the firmware that wonky? Or is octoprint confused by the skip X followed by OK? If sent the wrong line I'd expect the firmware to reject it immediately.

That said, given how your problems seem to come and go depending on who prints the file, I still think the first problem is a lack of sufficient power and possibly a bad cable.

1) I assume when you printed from S3D you hosted via your laptop? 2) Octoprint is running, on a PI yes? Does it have a big enough power supply? 3) Are your octopi and printer plugged into the same power strip/outlet/wall circuit? Older homes could have poor wiring, if you are in a older home on two different circuits you might be getting ground loops, floating, grounds, etc. Try ensuring they are both plugged into the same outlet or power strip, 4) The fact you've seen this work fine when one extruder is used vs the other, or usb cable, still smells like an electrical / power problem.

DanielJoyce commented 5 years ago

Its weirdly infuriating that these protocols don't seem to send the line number with OKs, or a sequence number. If they did all of this nonsense would go away. Its what TCP/IP does.

foosel commented 5 years ago

I've tried to annotate the log:

Send: N2767302 M105*34
Recv: ok                                                                                <- N2767301
Send: N2767303 G1 X34.728 Y74.697 E3.0265*85
Recv: ok                                                                                <- N2767302, M105
Send: N2767304 G1 X34.316 Y74.875 E3.0443*91
Recv: T:238.13 /240 B:70.25 /70 B@:0 @:244 T0:238.50 /240 @0:170 T1:238.13 /240 @1:244  <- N2767302, M105
Recv: ok                                                                                <- N2767303
Recv: Error:Wrong checksum                                                              <- N2767304
Recv:                                                                                   <- N2767304
Recv: Resend:2767304                                                                    <- N2767304
Send: N2767305 G1 X34.153 Y74.880 E3.0507*82                                            <- probably already enqueued
Recv: ok                                                                                <- N2767304
Send: N2767305 G1 X34.153 Y74.880 E3.0507*82                                            <- off by one?
Recv: skip 2767305                                                                      <- 1st N2767305
Recv: ok                                                                                <- 1st N2767305
Send: N2767306 G1 X33.237 Y75.006 E3.0872*95                                            <- OctoPrint assumes everything's fine
Recv: skip 2767305                                                                      <- 2nd N2767305
Recv: ok                                                                                <- 2nd N2767305

What I find weird is that OctoPrint indeed doesn't send N2767304 as asked but instead sends N2767305. That sounds like an off-by-one error, which I haven't seen in a while and don't understand. So this is definitely wrong on OctoPrint's side, but right now I don't understand how that could happen.

The skip parts are something new though as well - on other firmwares, when the host resends the wrong line, the firmware will immediately send another resend request. My guess is these skip lines are a protocol addition used here to inform the host that any sent lines that are out of order and might still have been enqueued before a resend request was received are simply thrown away. Which is nice and all, but it doesn't tell the host that something's seriously off. In fact, the accommodating oks make it seem like everything is fine. This makes handling way more tricky - the firmware screaming into my ear until I send it the right line is certainly what I'd rather expect here.

What kind of firmware is that? The ok order with other command output suggests this is a variant of the Repetier firmware, but has it been customized in any way by SeeMeCNC or not? The skip stuff certainly is something I so far didn't know about being a possibility and to accommodate that I'd need to adjust some things (or at least look into if I even can adjust some things). @repetier can you maybe shed some light on this? Is this regular Repetier Firmware behavious that I simply didn't know about yet?

EliW commented 5 years ago

@DanielJoyce wrote:

  1. I assume when you printed from S3D you hosted via your laptop?

Hosted via an old desktop that I used to have. The desktop recently died (powersupply went boom). And I decided instead of buying a cheap $300 desktop to replace it. I'd switch over to running Octoprint on a Pi instead for a lot less, and get some benefits. (didn't expect the troubles of course).

  1. Octoprint is running, on a PI yes? Does it have a big enough power supply?

I specifically went and bought one of the special 2.5a 'meant for pi' power supplies instead of running it off a phone charger, after reading a lots of troubles people had when doing that. This one: https://www.amazon.com/gp/product/B07GZZT7DN/

  1. Are your octopi and printer plugged into the same power strip/outlet/wall circuit? Older homes could have poor wiring, if you are in a older home on two different circuits you might be getting ground loops, floating, grounds, etc. Try ensuring they are both plugged into the same outlet or power strip,

They are plugged into the same power strip

  1. The fact you've seen this work fine when one extruder is used vs the other, or usb cable, still smells like an electrical / power problem.

Well, just to re-clarify in case it helps.

EliW commented 5 years ago

@foosel wrote:

What kind of firmware is that? The ok order with other command output suggests this is a variant of the Repetier firmware, but has it been customized in any way by SeeMeCNC or not? The skip stuff certainly is something I so far didn't know about being a possibility and to accommodate that I'd need to adjust some things (or at least look into if I even can adjust some things). @repetier can you maybe shed some light on this? Is this regular Repetier Firmware behavious that I simply didn't know about yet?

It is Repetier, but yes, the SeeMeCNC specific variant to work with their Deltas. You can find it here: https://github.com/seemecnc/Firmware/

Interestingly enough -- I just found that on their own Github ... they have a similar/identical bug being discussed: https://github.com/seemecnc/Firmware/issues/16 - as recently as a couple weeks ago. With OctoPrint causing random tool changes after about an hour+ of printing.

foosel commented 5 years ago

I find this comment quite eye opening:

// WARNING: There is a known bug in Repetier that causes random tool changes when using dual
// extrusion if you have the USB cable connected. In order to avoid this, only print from
// the SD card if you are running two extruders.

I just wish there were more details there, as in, how far is that bug known, and in which firmware variants, and where is it documented, and and and... But it might just be referring to the ticket you already linked.

There also this thread where @repetier also assumes it to be the cause of a communication error. As far as your serial.log goes we didn't even get a notification about the extruder switch, though that might simply have been removed from SeeMeCNC's variant.

EliW commented 5 years ago

Yes, I'd seen that as well (the random tool change over USB) comment. However what was interesting to me, was that I (originally) assumed that warning to be 'obviously old' because when I installed the dual extrusion addon -- I then tested with a direct print from S3D, had zero issues, and continued to print for a month solid without issues. (And I mean solid. This printer tends to be running 24/7 with only small breaks when I forget to start a new print for an hour or two).

And it was only upon switching to Octoprint (on a Pi) vs S3D that the problems began.

HOWEVER: A huge new twist. I've now been printing exclusively from the SD card (which is sad, as it removes a lot of the benefit of using Octprint & the Pi) ... And it's been working.

Until:

A couple days ago I came back to a long print, to find that the extruder had changed over mid-print . (again, while printing from SD card). I kept going on my SD card prints. Next few were fine. And then just this morning, it happened again after an overnight print.

So now my printer is 'sometimes' making the extruder switch. even when printing from the SD card itself :(

Now, I DO still have the USB connected to the Pi of course. So if the bug is purely caused by 'being connected'. That would happen. But #sigh ... At that point, it's definitely not an Octoprint bug. (Unless literally something by the fact that the Octoprint is listening to the USB traffic is causing the issue is a legit thing)

I did notice in the other thread that someone mentioned they solved the problem by cutting the data rate in half. I might experiment with that. Or I might just consider my dual print/extrusion upgrade to be trash, and disable it to have a stable printer again.

EliW commented 5 years ago

@foosel Attaching this here in case it means anything to this bug (or is another one).

A few times now I've started prints from the SD card, with Octoprint attached just so I could control/monitor ... and Octoprint has disconnected for random reasons.

Tonight, got a "Offline (Error: See octoprint.log for details)" error ... and the log itself says that "You should report this bug".

Looks like even though we weren't printing from octoprint, just hanging out. That 'bad checksum' and resend requests started happening. octoprint (2).log

foosel commented 5 years ago

The switch to offline sounds like it got something really unexpected back from the printer in a reply to M27. You wouldn't happen to have serial.log or the terminal contents from that? Would be interesting. Still, I can look into hardening that so that at least this kind of issues doesn't arise (edit done, see 8866ed7).

The communication errors don't surprise me. A connection prone to these issues keeps being prone to it, no matter what and how much you send over it. Printing from SD just makes it less likely to ruin a print, but it's still an ongoing issue as you can see.