Home Creators Posts Import Register Favorites Logout

Content

So, I've been trying to make sense of issue #1946 on the issue tracker. Some people are reporting that cancelling a print takes ages with the current stable version, and that back on 1.3.2 all was still fine.

I cannot reproduce this issue myself (my prints cancel just fine). First logs hint at some delay in printer communication, possibly caused by firmware. Thing is, I'm not seeing this either. I've now prepared a test branch without cancel position logging since the commands used for that seemed to be the most likely culprit but those were in there since 1.3.0 already, so that wouldn't explain any change in behaviour between 1.3.2 and 1.3.4.

So my question to you: Have you observed anything like that as well? If so, could you provide serial.logs and information on "cancel clicked, state change observed" timings in the linked ticket? I figure that there MUST be some kind of issue here considering the amount of people who already chimed in on the ticket, but I'm completely stumped what change between 1.3.2 and 1.3.3/1.3.4 could have caused that since I didn't touch anything cancel related, and not being able to reproduce it myself certainly doesn't help either. I'm hoping that even more data points might shed some light on this.

Thanks in advance!

Update: Thanks to the help of Bryan who thankfully could reproduce the issue and managed to pin it down I was able to push a fix for the observed problems to the maintenance branch yesterday evening which will be released with 1.3.5. It turns out that a relocation of a piece of code that could take a long while if you had a lot of files in your upload folder was the culprit, because due to an oversight on my end it ended up being able to block the receiving thread for the serial connection to the printer. Meaning that OctoPrint was simply doing some stuff it shouldn't have been doing instead of listening to what the firmware might have to say ;) I hope that this was the only culprit here :D

Comments

Anonymous

I didn't see any changes between v1.3.3 and v1.3.4, no more delay when cancelling. In my own case, it only depends on the firmware (instantaneous on a printer, takes more time with another one, regarless the OctoPrint version)

Rene Jurack

works like a charm for me with smoothieware-based boards.

Anonymous

Works fine for me.

Anonymous

Works as usual (small delay), no change with 1.3.4. Wanhao i3 plus, stock firmware

Jonathan Charnas

Same delay for me as well, due to printer firmware (replicape boards has octoprint embedded in the printer). The delay is due to the firmware implementation where it has a lag emptying the move buffer...

Anonymous

I have not noticed any issues here.

Anonymous

The only thing i noticed is that after running octopi over night and then trying to turn the printer on the next day , it takes 5-10 seconds for the Commands to execute. But canceling has not been an issue here.

Anonymous

Yes, I have also observed this. It'll keep printing for quite some time after confirming the cancel request. A few times, I've cancelled more than once because I didn't know if I said yes at the cancel confirmation dialog. I'll save logs next time it happens.

M. Eric Carr

My impression is that Octoprint cancels right away, but the printer buffers several dozen commands, so if it's printing long lines, it could take a long time to finally get around to clearing the buffer. Perhaps Octoprint could default to setting a smaller buffer size, if this is supported by printer firmware?

foosel

Some more lines (depending on your firmware's buffer size) are normal. That can take a long time if you are printing slow and long moves and sadly there's no way for OctoPrint to tell your firmware "hey, please don't execute those lines you've queued up, just throw them away", at least not without to also tell it "and also please perform a complete lock down and emergency stop which will need a restart". But the behaviour here shouldn't have changed between 1.3.2 and 1.3.4.

foosel

A larger buffer is actually what you want to be able to handle fast short moves or communication errors better. So just in general reducing it would be a bad idea I fear. And I can't anticipate when people click on cancel so I can't do it just before that. Premonition mode ;)

Nathan Brandeburg

I am having this issue with my TAZ 6 but only on specific sections of a print. Ex. large infill area; if just started and cancel is pressed then there is a good 5-10 second delay before it actually stops the print. It does seem like the buffer is just large and the printer firmware is also buffering some commands which I have noticed by a desync between the gcode viewer and the actual nozzle position on the print (~5 second delay). I don't have terminal and logs saved from the last time this happened but I will try to recreate it today and capture the logs.

M. Eric Carr

Hmm. Could the buffer be changed on the fly, so as to always leave, say, at least 500ms of move instructions in the pipe? That way, on long moves you could only send two or three, and if you had a couple hundred short moves, you could send more.

foosel

Nathan: 5-10 seconds of it finishing the queued moves, especially on long slow moves, sounds normal and sadly unavoidable (it's due to how the firmware's buffering movement commands to plan acceleration and such through look ahead). But if you suddenly started seeing 30sec or more -> logs please :)

foosel

Eric: For that I'd need to know completely reliably how long a move will take to process on the firmware side and I can't know that reliably (too many factors that play into this, and stuff would get completely shot in case of a resend request). When it comes to communication with the firmware, in general I want to push data to it as fast as possible so that its buffers never run dry. And the larger its buffers the better. I'd rather see a command introduced in firmware (reported via the capability protocol) that would allow me to clear the buffer and which would tell me which or at least how many commands it removed from there (so that I could resend them later). That's less fragile I think :)

Nathan Brandeburg

@Gina, I just had that exact 5-10 second delay with a cancel while the first layer of support base was being printed. So that seems to fit with the firmware queue + octoprint queue. The support commands are simple, long lines which makes sense as to the actual time (seconds) to stop with the buffer would be a few seconds. I pulled the log files down and there is nothing in there but connection happiness so there doesn't seem to be a problem here! Let me know if you have something you want me to test to try and reproduce what others are seeing who have the issue (i.e. if they shared the gcode file and approximately when they tried to cancel the print).

M. Eric Carr

Sounds good. I've always considered the cancel delay to be a printer thing, not an Octoprint thing, anyway. So if anything this would be a feature request to compensate for a printer shortcoming. FWIW, all the delays I've seen have been attributable to the printer simply running the buffer dry after cancelling. I have seen this take >30s or so, but only because it was doing brims sliced by Simplify3D, and 5-6 of those took that long to execute. It doesn't seem to be an Octoprint issue from what I can tell.

foosel

@Nathan, thanks, will do! Currently playing hunt-the-issue with a buddy who can reliably reproduce it (and there it doesn't appear to be caused by the firmware buffers) and is now throwing a git bisect at it, maybe that will get us closer :D @Eric, yeah, those lines in the buffer are definitely a printer thing and depending on the print job and location therein can take a quite a while. What made me go "huh" was that the people reporting that issue in that ticket said it started with 1.3.3/1.3.4 and wasn't yet there in 1.3.2. The tests of my buddy confirm that there is something there that I cannot reproduce for some reason but which is definitely causing delays. Only around 4s in that case, but it might be more for other people. I hope to understand this problem soon, right now it's still a case of poking at it with a stick and hoping something squeaks. Trying to debug issues that I cannot reproduce myself is always tricky, and timing sensitive ones make that even worse.

Anonymous

No issue from my side. Using a Dagoma Discovery 200 printer with the corresponding Marlin fw.

foosel

I've just added an update to the post. In a nutshell: The problem has been identified and a fix has been prepared to be released with 1.3.5. Phew :)