Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Upload via watched folder does not reset job data, leading to wrong progress reporting #1760

Closed
caffeineflo opened this issue Feb 8, 2017 · 12 comments

Comments

Projects
None yet
5 participants
@caffeineflo
Copy link

commented Feb 8, 2017

First and foremost, I think similar activity has been reported in #1603 and other issues that have been opened. It was mentioned that more information might be helpful, so here I am trying to provide that information.

What were you doing?

Had a smaller print (GCODE file size: ~300kb) with the Filename "Dupont_Mount-PLA.gcode" that printed well. I later created a new GCODE file that was significantly larger (2.7MB) that had the same filename and got uploaded to my octoprint server to the watched folder. At this time, the 300kb file was still "loaded and armed" but finished on Octoprint.
I started the new file by clicking the print button in the 'state' box, which printed the new 2.7MB file, yet didn't update the state's GCODE file size indicator.

The print started to print with the 0-100% status bar going to 740%, then stopped before the GCODE file ended with the fans on and the both the heater 1 and the HBP going. No disconnect or anything that would further indicate the situation.
Had to cancel the print to get it to stop. As I was printing over night, the print was left at 740% for about 6 hrs at least.

What did you expect to happen?

The print to finish normally

What happened instead?

Stopped at the last position that was sent to the printer.

Branch & Commit or Version of OctoPrint

origin/master 1.3.1

Printer model & used firmware incl. version

Latest version of marlin on their RCBugFix Branch (commit 9b55159)

Browser and Version of Browser, Operating System running Browser

Latest Chrome, latest macOS (still a stupid name, os x was soo much better)

Link to octoprint.log

https://gist.github.com/caffeineflo/7c7e09eecee67cf6ed8c3ddac740f06c

Link to contents of terminal tab or serial.log

https://gist.github.com/caffeineflo/7c7e09eecee67cf6ed8c3ddac740f06c

Link to contents of Javascript console in the browser

Not applicable

Screenshot(s) showing the problem:

N/A

I have read the FAQ.

@gu1234

This comment has been minimized.

Copy link

commented Feb 8, 2017

Had a similar issue, I noticed that the screen on my Prusa MK2 goes blank for a second (as if the RAMBO board restarts). This happens usually early in the prints and some times on the first layer. Never happened to me when printing directly from the SD card.

The log on octoprint didn't have anything out of the ordinary

@nophead

This comment has been minimized.

Copy link
Contributor

commented Feb 8, 2017

@caffeineflo

This comment has been minimized.

Copy link
Author

commented Feb 8, 2017

@nophead Where in my log files did you see that the USB connection was lost?
I couldn't find anything pointing towards a lost connection.

@nophead

This comment has been minimized.

Copy link
Contributor

commented Feb 9, 2017

Sorry, I was replying to @gu1234

I think your issue is the firmware and OctoPrint don't agree what the checksum is for this line.

N83671 M117 [##########################################################################] 740%*63

How it got to 740% seems like a bug as well.

@Blue-Marlin

This comment has been minimized.

Copy link

commented Feb 9, 2017

That many '#' are a challenge for firmwares (Marlin). The status line is usually not longer than 22 chars, the reserved space not more than 22*3+1 (utf8).

@caffeineflo

This comment has been minimized.

Copy link
Author

commented Feb 9, 2017

You just killed that plugin ... we'll see if that's getting better now ;) Thanks!

@foosel

This comment has been minimized.

Copy link
Owner

commented Feb 9, 2017

While that plugin should not produce lines like this (and I'll have to take a look at some error checks to make it so that it ignores faulty progress data), the more concerning issue here is that apparently your printed file kept growing in size even after you started the job, which would explain how it could even go past 100%. The size of and position in the file is all that OctoPrint has for tracking progress here. It assumes the size to not change after start. Apparently that is not the case here and the question is why.

From your description it sounds like overwriting it via the watched folder for some reason didn't trigger the job data to be refreshed. Which would be a bug. I'll have to look into this, I'm currently still out of commission though, so this will take at least until next week.

In any case, this looks like it's caused by a combination of wrong progress reporting and the Display Progress plugin not being resilient against that leading to a way too long M117 line to be produced which then caused the communication issue. Disabling the plugin or reselecting the equally named file uploaded through the watched folder prior to a second print should be a workaround until this is fixed.

@foosel foosel added this to the 1.3.2 milestone Feb 9, 2017

@foosel foosel changed the title Printer Stops with Heater Running Upload via watched folder does not reset job data, leading to wrong progress reporting Feb 9, 2017

@caffeineflo

This comment has been minimized.

Copy link
Author

commented Feb 9, 2017

Disabling the plugin or reselecting the equally named file uploaded through the watched folder prior to a second print should be a workaround until this is fixed.

This is what I usually did and never had this issue before. I also never experienced the issue when the new file was only slightly larger than the original file. This was the first case where the new file was larger by a multiple of 10 and more.

foosel added a commit that referenced this issue Feb 17, 2017

Refactored upload/watched to use file check methods in PrinterInterface
Extracted methods to check if modification of a file is possible and
to determine if a specific file is currently select to take care of
denying upload and re-selecting file after upload.

Refactored watched folder handler to use the same methods and mirror
behaviour of file upload via API.

Should solve #1760

foosel added a commit that referenced this issue Feb 17, 2017

foosel added a commit that referenced this issue Feb 17, 2017

Fixed size checking in watchdog growth check
It helps to actually update the last checked file size on each
iteration 🤦‍♀️

Related to #1760
@foosel

This comment has been minimized.

Copy link
Owner

commented Feb 17, 2017

Ok, so I found two things. One was that as expected the upload via the watched folder was actually missing the reselect that is necessary to refresh the data about the current job. So that's fixed now.

The other was that contrary to what I assumed the used library for detecting file creation did trigger immediately on file creation, not when the file was fully there - that was something that came up in the discussions in #1765 and turned out to be right (thanks @nophead). So OctoPrint could move the file over to the uploads folder while it was still being written. And the way how linux file systems work caused that to not cause any obvious issues at all, other than immediately selecting it then could cause the wrong file size to still be reported. Windows behaves differently here again and at least so far I couldn't reproduce that specific scenario there, even when copying a file from a network source.

In any case, what it will now do on a creation event is not trigger the move immediately but instead polling the file size every second. Once it is stable for the past five polls, it will trigger the move. We still might have to experiment with those values, but at least in my initial tests they looked fine.

Example (started circling with the cursor once the file was copied fully to the watched folder):

watched

Update in the file list after upload takes a smidge longer because that requires a full fetch of the whole file list and that simply takes longer than just pushing a new size to the client, especially with a long file list.

As you see above I pushed these changes to the maintenance branch and will also merge them to devel ASAP. They'll be released with 1.3.2.

@caffeineflo

This comment has been minimized.

Copy link
Author

commented Feb 17, 2017

Great! Thanks @foosel

I'll give it a try tonight

@caffeineflo

This comment has been minimized.

Copy link
Author

commented Feb 23, 2017

@foosel Tried it again and had no issues whatsoever! Thanks for the fix

@foosel

This comment has been minimized.

Copy link
Owner

commented Mar 16, 2017

1.3.2 was just released.

@foosel foosel closed this Mar 16, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.