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

[1.3.9-1.3.11rc2] Print started from printer's LCD panel renders web interface inoperable #3116

Closed
kazibole opened this issue Apr 9, 2019 · 10 comments

Comments

Projects
None yet
3 participants
@kazibole
Copy link

commented Apr 9, 2019

What were you doing?

Started a print from the printer's SD card via the printer's LCD panel.

What did you expect to happen?

The temperature, progress and terminal updating in real time.

What happened instead?

The temperature, progress and terminal briefly updated then stopped. Lost control of printer.

In all occurrences of the problem, I see the following error in octoprint.log:

2019-04-08 17:22:53,104 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1346, in _work
    data = self.get_current_data()
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1356, in get_current_data
    self._progress = self._get_current_progress()
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1282, in _get_current_progress
    return self._on_get_progress()
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 793, in _updateProgressDataCallback
    statisticalTotalPrintTimeType)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
    estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
    return self._data.update(printTime / progress)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
    if -1.0 * self._threshold < self.average_distance < self._threshold:
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
    return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero

Did the same happen when running OctoPrint in safe mode?

Yes.

Version of OctoPrint

Problem occurred in 1.3.9-1.3.11rc2
Problem did not occur in 1.3.8

  1. Deployed new install of OctoPi 0.16.0 with OctoPrint 1.3.10 - problem occurred
  2. Tried 1.3.10 safe mode - problem occurred
  3. Upgraded to 1.3.11rc1 - problem occurred
  4. Upgraded to 1.3.11rc2 - problem occurred
  5. Tried 1.3.11rc2 safe mode - problem occurred
  6. Downgraded to 1.3.9 - problem occurred
  7. Downgraded to 1.3.8 - problem did not occur
  8. Upgraded to 1.3.11rc2 - problem occurred

Sentry.io UUID when running 1.3.11rc1/rc2: c5549751-a79a-482c-a003-8ff57a5b67b1

Operating System running OctoPrint

OctoPi 0.16.0

Printer model & used firmware incl. version

Prusa MK3 firmware 3.7.0

Browser and version of browser, operating system running browser

Chrome 73.0.3683.86 (64-bit)
Windows 10 1809

Link to octoprint.log

  1. octoprint_1.3.10.log https://gist.github.com/kazibole/8229c8b72f802fed6b5dc34bc2122bd7
  2. octoprint_1.3.10_safe.log https://gist.github.com/kazibole/c40d53531689e863a5ee1e68c1ca6545
  3. octoprint_1.3.11rc1.log https://gist.github.com/kazibole/f8e61b45cbeba44e10ab7b95c352557c
  4. octoprint_1.3.11rc2.log https://gist.github.com/kazibole/055ef8ab07b0c575b9d9783008827bcb
  5. octoprint_1.3.11rc2_safe.log https://gist.github.com/kazibole/ec267c6019694e9e89596e563b5e383a
  6. octoprint_1.3.9.log https://gist.github.com/kazibole/7d967372eab3f51f9753541f3ed538f3
  7. octoprint_1.3.8.log https://gist.github.com/kazibole/e6f1cb22ba3d33c41ac0240a3e9de888
  8. octoprint_1.3.11rc2_02.log https://gist.github.com/kazibole/faf49b88ed881bd7889fcaf590ea18a4

Link to contents of terminal tab or serial.log

  1. serial_1.3.10.log https://gist.github.com/kazibole/e84e4f6bca172cbcbef620f62d6ebd85
  2. serial_1.3.10_safe.log https://gist.github.com/kazibole/11e3eba84b30655f7e558fde85ab78f1
  3. serial_1.3.11rc1.log https://gist.github.com/kazibole/b18f730713c044cb144ba7bef61fb24c
  4. serial_1.3.11rc2.log https://gist.github.com/kazibole/0319511f8755888d1f94e719c1a75643
  5. serial_1.3.11rc2_safe.log https://gist.github.com/kazibole/3fec066a4d1f63961a3f452168bb0ccb
  6. serial_1.3.9.log https://gist.github.com/kazibole/218b4698828543179407e61db7540a49
  7. serial_1.3.8.log https://gist.github.com/kazibole/26ce43be1064828490b631ec15ef9179
  8. serial_1.3.11rc2_02.log https://gist.github.com/kazibole/5816bdbe0ffe412d5403a0b8b632c064

Link to contents of Javascript console in the browser

Did not capture. Let me know if required.

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

Did not capture. Let me know if required.

I have read the FAQ.

@foosel

This comment has been minimized.

Copy link
Owner

commented Apr 9, 2019

Let me just quickly say that this is one of the most beautifully thorough bug reports I've ever gotten. Thank you so much for that, and even figuring out when this was introduced, that will make analysis way way easier.

I understand what is happening, what I haven't yet figured out is why it is happening. A fix of the what is trivial, but I'll rather spend some time on figuring out the why.

@foosel foosel added this to the 1.3.11 milestone Apr 9, 2019

@foosel

This comment has been minimized.

Copy link
Owner

commented Apr 9, 2019

I'm also tentatively adding this to 1.3.11. It isn't a regression, but the effects of the bug are fairly severe considering that it nukes the state updater. So I'll at the very least make sure that the trivial fix makes it in.

@kazibole

This comment has been minimized.

Copy link
Author

commented Apr 9, 2019

Thanks Gina! If you need me to test anything please let me know. I have an instance of OctoPrint set up on a spare SD card that I can play around.

@kazibole

This comment has been minimized.

Copy link
Author

commented Apr 9, 2019

My memory is foggy, but I am almost certain that I was printing via the printer's SD card successfully in 1.3.9, at the very least 1.3.9rc2 judging by my comments in the issue tracking thread. It looks like my MK3 was running firmware 3.3.0 back then, so I wonder if something changed since. Perhaps the way they format their response to M105 or M27.

Since 1.3.9 I had transitioned to printing exclusively from OctoPrint until just now, where I tried an SD card print in 1.3.11rc1.

@foosel

This comment has been minimized.

Copy link
Owner

commented Apr 9, 2019

I still haven't figured out how this happens... And I can't seem to reproduce it with stock settings, against real or virtual printer.

There's one thing though that might explain it - a high sd status query interval. Could you tell me what you have set for Settings > Serial > Intervals > SD status interval (polling)?

@kazibole

This comment has been minimized.

Copy link
Author

commented Apr 9, 2019

Attached are my intervals and timeouts. I did change them after the fresh install of OctoPi 0.16.0 so they are not stock. I can try again with stock settings if that would help.

octoprint_intervals

@foosel

This comment has been minimized.

Copy link
Owner

commented Apr 9, 2019

Hah... that 30s status interval is probably the reason. I'll test with that.

@kazibole

This comment has been minimized.

Copy link
Author

commented Apr 9, 2019

I apologize for leaving that out from my notes. It completely slipped my mind that I changed it! No detail is too small to mention!

foosel added a commit that referenced this issue Apr 9, 2019

foosel added a commit that referenced this issue Apr 9, 2019

@foosel

This comment has been minimized.

Copy link
Owner

commented Apr 9, 2019

Could reproduce now 🎉 so the why is also explained. Fix is ready for 1.3.11rc3 (see 0a04043), and I also hardened things a bit more against high intervals (f389773) and general estimation exceptions (323131c).

@foosel foosel added the status:solved label Apr 9, 2019

@foosel

This comment has been minimized.

Copy link
Owner

commented Apr 11, 2019

1.3.11rc3 is out which should fix this.

@foosel foosel closed this Apr 11, 2019

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.