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

OctoPrint web interface becomes very sluggish (but print continues) #1065

Closed
jminardi opened this issue Sep 17, 2015 · 38 comments
Closed

OctoPrint web interface becomes very sluggish (but print continues) #1065

jminardi opened this issue Sep 17, 2015 · 38 comments
Labels
needs testing Testing from the community is needed

Comments

@jminardi
Copy link
Contributor

  1. What were you doing?

Running a print through the web interface

  1. What did you expect to happen?

Octoprint to stay responsive

  1. What happened instead?

The interface was responsive but any request was very sluggish. (I have the request spinner plugin installed so I could see the requests hanging for minutes) The terminal tab did not show the GCode as it was streaming (the print was running though so GCode was streaming.) Reloading the page happened at the usual speed, and after reload the terminal tab would show gcode streaming for a few seconds before freezing again. Manually sending gcode did not display on the UI, but a few minutes after sending the command would actually execute on the printer. Cancel button worked after some time. A restart of the raspberry pi brought OctoPrint into normal working order.

  1. Branch & Commit or Version of OctoPrint:

Version: 1.2.6 (master branch)

  1. Printer model & used firmware incl. version
    (if applicable - always include if unsure):

Marlin Integration branch

  1. Browser and Version of Browser, Operating
    System running Browser (if applicable - always
    include if unsure):

Chrome on OS X

  1. Link to octoprint.log on gist.github.com or pastebin.com
    (ALWAYS INCLUDE AND DO NOT TRUNCATE):
2015-09-16 15:33:17,751 - tornado.general - ERROR - Error in periodic callback
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/sockjs_tornado-1.0.1-py2.7.egg/sockjs/tornado/periodic.py", line 69, in _run
    next_call = self.callback()
  File "/home/pi/oprint/local/lib/python2.7/site-packages/sockjs_tornado-1.0.1-py2.7.egg/sockjs/tornado/session.py", line 409, in _heartbeat
    self.handler.send_pack(proto.HEARTBEAT)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/sockjs_tornado-1.0.1-py2.7.egg/sockjs/tornado/transports/websocket.py", line 86, in send_pack
    self.write_message(message, binary)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/websocket.py", line 201, in write_message
    self.ws_connection.write_message(message, binary=binary)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/websocket.py", line 491, in write_message
    self._write_frame(True, opcode, message)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/websocket.py", line 480, in _write_frame
    self.stream.write(frame)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 348, in write
    self._handle_write()
  File "/home/pi/oprint/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 801, in _handle_write
    self._write_buffer.popleft()
IndexError: pop from an empty deque
2015-09-16 15:35:29,627 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.77
2015-09-16 15:36:18,229 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.77
2015-09-16 15:36:19,600 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.77
2015-09-16 15:37:01,018 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.77
2015-09-16 15:37:02,628 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.77
2015-09-16 15:37:06,782 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.77
2015-09-16 15:37:08,189 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.77
2015-09-16 15:37:10,958 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.77
2015-09-16 15:37:12,292 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.77
2015-09-16 15:37:45,617 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.77
2015-09-16 15:37:47,030 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.77
2015-09-16 15:38:13,371 - octoprint.server.util.sockjs - WARNING - Could not send message to client 10.24.1.72: 'utf8' codec can't decode byte 0xc5 in position 1: invalid continuation byte
2015-09-16 15:38:13,374 - octoprint.server.util.sockjs - WARNING - Could not send message to client 127.0.0.1: 'utf8' codec can't decode byte 0xc5 in position 1: invalid continuation byte
2015-09-16 15:38:13,376 - octoprint.server.util.sockjs - WARNING - Could not send message to client 10.24.1.77: 'utf8' codec can't decode byte 0xc5 in position 1: invalid continuation byte
2015-09-16 15:38:38,639 - octoprint.filemanager.analysis - INFO - Starting analysis of local:sld_quad_11.gcode
2015-09-16 15:50:26,218 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.72
2015-09-16 15:51:24,876 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.38
2015-09-16 15:51:24,880 - octoprint.server.util.sockjs - WARNING - Could not send message to client 10.24.1.38: 'utf8' codec can't decode byte 0xc5 in position 1: invalid continuation byte
2015-09-16 15:51:52,010 - octoprint.filemanager.analysis - INFO - Starting analysis of local:sld_quad_12.gcode
2015-09-16 16:42:28,560 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.77
2015-09-16 17:24:56,302 - octoprint.filemanager.analysis - INFO - Starting analysis of local:sld_quad_12.gcode
2015-09-16 17:51:14,500 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.72
2015-09-16 19:40:47,872 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.38
2015-09-16 19:40:52,097 - octoprint.server.util.sockjs - INFO - New connection from client: 10.24.1.38
2015-09-16 21:22:44,818 - octoprint.server.util.sockjs - INFO - Client connection closed: 10.24.1.38
  1. Link to contents of terminal tab or serial.log on
    gist.github.com or pastebin.com (if applicable - always
    include if unsure or reporting communication issues AND
    DO NOT TRUNCATE):

Not logged - Lost after reboot

  1. Link to contents of Javascript console in the browser
    on gist.github.com or pastebin.com or alternatively a
    screenshot (if applicable - always include if unsure
    or reporting UI issues):

Not recorded

  1. Screenshot(s) showing the problem (if applicable - always
    include if unsure or reporting UI issues):

I have read the FAQ.

@jminardi
Copy link
Contributor Author

I had custom controls set in the config that are now missing, not sure if that is related.

@foosel
Copy link
Member

foosel commented Sep 22, 2015

That sounds like something in the websocket was acting up, blocking stuff on the network layer in the process.

Did the starting of the observed behaviour happen along the same time the IndexError: pop from an empty deque stack trace in your log got produced? Is it reproducible? What was the load on the server machine when it happened?

Also please provide the full octoprint.log - the above one is only a truncated snippet. You might have to look at the archived/rolled over version too.

@foosel foosel added the needs information More information is needed to further process this issue or PR label Sep 22, 2015
@foosel foosel changed the title OctoPrint becomes very sluggish (but print continues) OctoPrint web interface becomes very sluggish (but print continues) Sep 22, 2015
@jminardi
Copy link
Contributor Author

@foosel, sorry, I can't say for sure if the behavior happened along the same time as the error, this error report came from one of our users. Regarding the whole log, unfortunately it is gone now, but when I copied and pasted the above there was nothing else in there except the startup lines.

Regarding reproducibility, I might have captured it again (And this time I have the full logs and terminal tab).

Similar behavior where the terminal tab stopped showing lines go by, but the print was still running. The time remaining stopped going up as well. Reloading the page did not fix the issue. I looked at the javascript console and no errors were reported. I then loaded OctoPrint on another machine and everything seemed fine there. I reloaded OctoPrint on the original machine and everything was working as expected. However after about 2 more minutes the printer stopped moving and the terminal tab repeatedly said: "Communication timeout during printing, forcing a line".

I had also SSH'd into the pi running octoprint to check system status. top did not show any exessive memory or CPU usage.

octoprint.log: http://pastebin.com/jkWiFnqN
terminal tab: http://pastebin.com/3e6pdjQ3

The IndexError did not show up, so that may have been a red herring.

Please let me know if there is any other data I can collect that could be useful.

@normanclanger
Copy link

I'm experiencing very similar symptoms, after upgrading to the latest 1.2.7 update available for the raspberry pi Octoprint distribution. The interface is perfect - until I hit the print button. Then, during the printing (which also appears fine), network connectivity to the pi fails. The web interface becomes unresponsive & I cannot ssh to the pi. As soon as printing finishes, everything returns to normal. This did not happen on previous versions of the distribution. Happy to help diagnose - what can I capture to help here? Thanks Tim

@foosel
Copy link
Member

foosel commented Oct 26, 2015

@normanclanger that sounds like a different issue than what @jminardi is reporting, considering that apparently for him it was the interface not getting data pushed from the server but the Pi still being responsive, whereas your symptoms more sound like the whole Pi is under such a heavy load that it no longer can respond in time to anything else (e.g. SSH login, serving web requests etc).

The question is what the load is on your server when that happens - considering that you cannot login that might be a bit tricky to figure out though.

Just a guess but: make sure you do not have the "Log communication to serial.log" checkbox checked (in Settings > Serial Connection). If you happen to have a webcam connected, try if the same issue occurs if you don't. Also try without any non-bundled plugins being enabled.

@foosel foosel added unreproduced No reproduction in a dev setting yet, further analysis blocked by that and removed needs information More information is needed to further process this issue or PR labels Oct 26, 2015
@foosel
Copy link
Member

foosel commented Oct 26, 2015

Oh, and of course: logs, logs, logs ;)

@normanclanger
Copy link

Thanks. I've checked the "Log Communication to serial log" - that is not checked. I have the pi camera attached, but it wasn't enabled. I haven't any bundled plugins installed. octoprint.log below - of significance is the statement 'error: [Errno 113] No route to host' - could this be causing the loss of connectivity?

2015-10-26 09:33:28,207 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.2.21
2015-10-26 09:37:23,835 - octoprint.server.util.sockjs - INFO - Client connection closed: 192.168.2.21
2015-10-26 10:31:05,630 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.2.19
2015-10-26 10:44:20,137 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.2.25
2015-10-26 10:44:21,331 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.2.25
2015-10-26 11:17:58,834 - tornado.general - WARNING - error on read
Traceback (most recent call last):
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 601, in _handle_read
pos = self._read_to_buffer_loop()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 571, in _read_to_buffer_loop
if self._read_to_buffer() == 0:
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 683, in _read_to_buffer
chunk = self.read_from_fd()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 947, in read_from_fd
chunk = self.socket.recv(self.read_chunk_size)
error: [Errno 113] No route to host
2015-10-26 11:17:58,847 - octoprint.server.util.sockjs - INFO - Client connection closed: 192.168.2.25
2015-10-26 11:18:59,954 - tornado.general - WARNING - error on read
Traceback (most recent call last):
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 601, in _handle_read
pos = self._read_to_buffer_loop()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 571, in _read_to_buffer_loop
if self._read_to_buffer() == 0:
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 683, in _read_to_buffer
chunk = self.read_from_fd()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 947, in read_from_fd
chunk = self.socket.recv(self.read_chunk_size)
error: [Errno 113] No route to host
2015-10-26 11:18:59,959 - octoprint.server.util.sockjs - INFO - Client connection closed: 192.168.2.25
2015-10-26 11:37:05,714 - tornado.general - WARNING - error on read
Traceback (most recent call last):
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 601, in _handle_read
pos = self._read_to_buffer_loop()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 571, in _read_to_buffer_loop
if self._read_to_buffer() == 0:
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 683, in _read_to_buffer
chunk = self.read_from_fd()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 947, in read_from_fd
chunk = self.socket.recv(self.read_chunk_size)
error: [Errno 113] No route to host
2015-10-26 11:37:05,721 - octoprint.server.util.sockjs - INFO - Client connection closed: 192.168.2.19
2015-10-26 11:45:47,066 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.2.25
2015-10-26 11:46:37,411 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.2.25
2015-10-26 12:26:20,274 - tornado.general - WARNING - error on read
Traceback (most recent call last):
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 601, in _handle_read
pos = self._read_to_buffer_loop()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 571, in _read_to_buffer_loop
if self._read_to_buffer() == 0:
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 683, in _read_to_buffer
chunk = self.read_from_fd()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 947, in read_from_fd
chunk = self.socket.recv(self.read_chunk_size)
error: [Errno 113] No route to host
2015-10-26 12:26:20,279 - octoprint.server.util.sockjs - INFO - Client connection closed: 192.168.2.25
2015-10-26 12:26:26,354 - tornado.general - WARNING - error on read
Traceback (most recent call last):
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 601, in _handle_read
pos = self._read_to_buffer_loop()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 571, in _read_to_buffer_loop
if self._read_to_buffer() == 0:
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 683, in _read_to_buffer
chunk = self.read_from_fd()
File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/tornado-4.0.1-py2.7-linux-armv7l.egg/tornado/iostream.py", line 947, in read_from_fd
chunk = self.socket.recv(self.read_chunk_size)
error: [Errno 113] No route to host
2015-10-26 12:26:26,360 - octoprint.server.util.sockjs - INFO - Client connection closed: 192.168.2.25

@foosel
Copy link
Member

foosel commented Oct 27, 2015

That indeed sounds like the pi simply losing its network connection (hence no route to the client) but happily churning along otherwise. Are you sure the network connection is solid? When you start a print, the traffic increases due to the amount of data pushed to the client (terminal tab contents, progress). If the network can't handle that increase in traffic, I could imagine connectivity of the client to the server breaking down altogether being a symptom of that.

@jneilliii
Copy link
Contributor

I'm having a similar issue since the upgrade to 1.2.7 on my OctoPi image. Used the standard upgrade option to install the update and nothing seemed out of the ordinary. What I experience is after it prints for a while the web interface just decides to not update for a while and in some cases causes Chrome in Windows 10 to give the Aw Snap error, something went wrong. It never seems to cause the print to mess up and a page refresh always brings it back to being responsive again. Not sure I have my settings set correctly for good debugging on this issue, as there were only errors related to urllib3 and ssl connections. Only custom thing I have set-up on my OctoPi install is ssl configuration in haproxy, client certificate verification in haproxy config and user authentication in haproxy. OctoPrint settings set to disable users completely since I handle it all through haproxy. I use events in config to email snapshots, upload video to youtube, as described in the wiki. The only non-foosel plugins I have installed is FlashArduino (0.1).

@foosel
Copy link
Member

foosel commented Nov 5, 2015

I really wish I'd see this myself, I have absolutely no idea to tackle it right now :(

What you could try is downgrading to an earlier version by checking out the tag, e.g. git checkout 1.2.6 (or 1.2.5 or what ever) in ~/OctoPrint and then ~/oprint/bin/python setup.py install and see if the problem then vanishes again. Then we could try to narrow it down. But other than that I have absolutely no way to solve this at the moment since I cannot reproduce it.

@normanclanger
Copy link

Can you suggest a script to run to capture some diagnostics while we print? For example, I left a ping going writing to a file and this continued to work. Are there any http server metrics we could gather?

Sent from my HTC

----- Reply message -----
From: "Gina Häußge" notifications@github.com
To: "foosel/OctoPrint" OctoPrint@noreply.github.com
Cc: "normanclanger" normanclanger@gmail.com
Subject: [OctoPrint] OctoPrint web interface becomes very sluggish (but print continues) (#1065)
Date: Thu, Nov 5, 2015 17:14

I really wish I'd see this myself, I have absolutely no idea to tackle it right now :(

What you could try is downgrading to an earlier version by checking out the tag, e.g. git checkout 1.2.6 (or 1.2.5 or what ever) in ~/OctoPrint and then ~/oprint/bin/python setup.py install and see if the problem then vanishes again. Then we could try to narrow it down. But other than that I have absolutely no way to solve this at the moment since I cannot reproduce it.


Reply to this email directly or view it on GitHub:
#1065 (comment)

@foosel
Copy link
Member

foosel commented Nov 5, 2015 via email

@normanclanger
Copy link

I've experienced it from 3 different browsers on 3 different os. Plus ssh fails. Will try ping.

Sent from my HTC

----- Reply message -----
From: "Gina Häußge" notifications@github.com
To: "foosel/OctoPrint" OctoPrint@noreply.github.com
Cc: "normanclanger" normanclanger@gmail.com
Subject: [OctoPrint] OctoPrint web interface becomes very sluggish (but print continues) (#1065)
Date: Thu, Nov 5, 2015 18:51

The issue is most likely client side from how it is described, so there's
nothing server side to track by a script.

If there are no errors in the javascript error console (that's something
that could be checked) or constant disconnects of the websocket visible in
the network tab, it boils down to trying to find a way to reliably
reproduce it and then poke with a stick from all sides, see if it manifests
in earlier versions, etc.

You could check if a continuous ping from the client to the server during
printing behaves properly, that at least would rule out any general
connectivity issues causing this.

It might also be interesting to know the exact browser versions this is
happening with and whether the tab is in the foreground when it happens or
is not visible (maybe some overly eager tab suspending?).


Reply to this email directly or view it on GitHub:
#1065 (comment)

@jneilliii
Copy link
Contributor

Ok, so I was able to reproduce the aw snap error in chrome with developer tools open. There's nothing that seems out of the ordinary in network tab, the server is still responsive to pings on the network and as stated before a simple refresh of the browser reloads OctoPrint without any issues. The only error in console is as follows:

Synchronous XMLHttpRequest on the main thread is deprecated because of its detrimental effects to the end user's experience. For more help, check http://xhr.spec.whatwg.org/. less.min.js:8

@Salandora
Copy link
Contributor

Can you give more information about how you reproduced the bug. Any other plugin installed then FlashArduino? What were you doing? What Terminal settings were set? What filters were activated?

@jneilliii
Copy link
Contributor

It happens extremely randomly, so not really sure if it's specifically reproducible. But this time it was on the third print of the day that it happened. I've disabled timelapse completely to insure the pi wasn't getting over taxed. The following plugins are the only ones that aren't listed as "bundled'.

Yamlpatcher (0.1.0), Flash Arduino (0.1)

Other customization are as follows:

  • haproxy configured for ssl, user auth, certificate auth,
  • accessControl disabled.
  • youtube upload on timelapse complete
  • email image on print done

Connecting to RAMBo board at 250000 baud.

I just looked and octoprint.log is non-existant as I deleted it the last time to start from scratch.

I was going to try Foosels downgrade procedure but have been printing pretty regular the whole time. As stated before, it doesn't effect the print at all it just seems the web interface chokes up or causes some memory issue with Chrome running in Windows 10 (for me). I haven't personally tried in another browser.

@jneilliii
Copy link
Contributor

So with the developer tools opened this time and network tab active i noticed the Aw snap error on the page and the developer tools has an error "inspected target disconnected". I had a ping running from the same client and once the problem happened I started getting much higher latency (300-600+ms) on the ping results, along with a couple of time outs. If I try to refresh while the developer tools is open and print ongoing I get a line in the status bar of chrome stating waiting for available socket. Closed developer tools and refreshed the page and ping latency dropped below 10ms and no timeouts.

@normanclanger
Copy link

I'm seeing similar responses. Ping goes from 3ms to 1000-3000ms - or just reports host unresponsive. Nmap detects ssh and port 5000 prior to printing, but nothing when printing.

The network becomes unresponsive almost as soon as the printer head starts moving; while heating it is fine.

My router reports no traffic from the pi, so the network card isn't saturated. I'm pinging from a machine not running a web browser, so there is no client side interaction.

Thanks

Tim

On 7 Nov 2015, at 04:35, jneilliii notifications@github.com wrote:

So with the developer tools opened this time and network tab active i noticed the Aw snap error on the page and the developer tools has an error "inspected target disconnected". I had a ping running from the same client and once the problem happened I started getting much higher latency (300-600+ms) on the ping results, along with a couple of time outs. If I try to refresh while the developer tools is open and print ongoing I get a line in the status bar of chrome stating waiting for available socket. Closed developer tools and refreshed the page and ping latency dropped below 10ms and no timeouts.


Reply to this email directly or view it on GitHub.

@Grogyan
Copy link

Grogyan commented Nov 8, 2015 via email

@normanclanger
Copy link

I know this is off topic, so apologies. However, when I try to roll back to a previous version, I can only get OctoPrint to upgrade (to 1.3 devel). The screen output is as follows:

pi@pi2 ~/OctoPrint $ git checkout 1.2.6
Previous HEAD position was 96fc70b... Preparing release of 1.2.5
HEAD is now at 536bb31... Forgot the commit link in the changelog

pi@pi2 ~/OctoPrint $ ./venv/bin/python setup.py install

Using /home/pi/OctoPrint/venv/lib/python2.7/site-packages/pytz-2015.4-py2.7.egg
Finished processing dependencies for OctoPrint==1.3.0-dev-128-g536bb31

Why can I not roll back?

Thanks,

Tim

@foosel
Copy link
Member

foosel commented Nov 14, 2015

You are rolling back, but apparently there is still a bug in the part that generates the version number during install off the checkout. It doesn't recognize that a tag is checked out and so it falls back on the default for unrecognized "branches", which is 1.3.0

Notice how the part after the g is the exact commit hash the tag represents. So you have 1.2.6 checked out and installed just fine, it's just reporting wrong. I'll need to fix that, but can't do that retroactively, so just ignore it for now.

foosel added a commit that referenced this issue Nov 18, 2015
…visible

This might help with #1065 if indeed is related to background tab suspending behaviours in
browsers, but is a completely blind guess at this point since I still have not been able to
reproduce that issue myself.
foosel added a commit that referenced this issue Nov 20, 2015
…visible

This might help with #1065 if indeed is related to background tab suspending behaviours in
browsers, but is a completely blind guess at this point since I still have not been able to
reproduce that issue myself.

Backported.

(cherry picked from commit 720cdad)
@foosel
Copy link
Member

foosel commented Nov 20, 2015

Ok, after @Salandora could reproduce the problem, we took a guess at what might be causing it and I created a fix for that. At least for @Salandora the problem didn't reproduce any more, but I'd feel more confident marking this issue as closed if other people seeing this behaviour also got better results with the current maintenance branch (future 1.2.8 release).

So - could you guys please update to the maintenance branch and see if the issue still manifests there? Instructions for OctoPi:

cd ~/OctoPrint
git pull
git checkout maintenance
source ~/oprint/bin/activate
python setup.py install
sudo service octoprint restart

(For custom installations, change the path to your OctoPrint checkout folder (here: ~/OctoPrint) and your virtual environment (here: ~/oprint) accordingly)

Anything above 1.2.8.dev39 should include the patch (full version string of first version with the patch: 1.2.8.dev39+ga52a5ca).


Background: It might be caused by a combination of background tab suspending and how the GCODE viewer reacts to progress updates. There might be a backup in updates when the tab is backgrounded, causing the viewer to try to render hundreds of updates once the tab regains focus. The patch changes the behaviour such that OctoPrint now tracks if the browser tab containing OctoPrint and the tab within OctoPrint with the GCODE viewer are in focus, only trying to update the viewer if both is the case. While at it I also made the webcam view unload the webcam stream if the browser tab loses focus, no need to transfer that much data if nobody is watching.

That change should improve performance in general, even if it doesn't fix that specific issue you are observing (I still haven't been able to reproduce it myself, making it somewhat tricky to debug it...)

@foosel foosel added needs testing Testing from the community is needed and removed unreproduced No reproduction in a dev setting yet, further analysis blocked by that labels Nov 20, 2015
@normanclanger
Copy link

Hi - I'm still seeing the same I'm afraid - here is the capture in from the
terminal window of a print I'm trying now - it started happily displaying
the commands being sent, but then stopped. Still printing away, but pi not
responding to http, ping or ssh.

Recv: ok T:79.9 /80.0 B:62.7 /64.0 @:20 B@:128
Send: M105
Recv: ok T:79.7 /80.0 B:62.8 /64.0 @:30 B@:128
Send: M105
Recv: ok T:80.0 /80.0 B:62.9 /64.0 @:0 B@:128
Send: M105
Recv: ok T:80.1 /80.0 B:63.1 /64.0 @:3 B@:128
Send: M105
Recv: ok T:79.8 /80.0 B:63.2 /64.0 @:29 B@:128
Send: M105
Recv: ok T:79.8 /80.0 B:63.3 /64.0 @:12 B@:128
Send: M105
Recv: ok T:80.3 /80.0 B:63.4 /64.0 @:0 B@:128
Send: M105
Recv: ok T:80.1 /80.0 B:63.5 /64.0 @:15 B@:128
Send: M105
Recv: ok T:79.7 /80.0 B:63.7 /64.0 @:39 B@:128
Send: M105
Recv: ok T:80.0 /80.0 B:63.9 /64.0 @:0 B@:128
Send: M105
Recv: ok T:80.4 /80.0 B:64.0 /64.0 @:0 B@:128
Send: M104 S180.000000
Recv: ok
Send: M105
Recv: ok T:80.1 /180.0 B:64.0 /64.0 @:128 B@:0
Send: M105
Recv: ok T:80.7 /180.0 B:64.0 /64.0 @:128 B@:0
Send: M105
Recv: ok T:84.7 /180.0 B:63.7 /64.0 @:128 B@:128
Send: M105
Recv: ok T:90.2 /180.0 B:63.3 /64.0 @:128 B@:128
Send: M105
Recv: ok T:95.9 /180.0 B:63.2 /64.0 @:128 B@:128
Send: M105
Recv: ok T:101.9 /180.0 B:63.2 /64.0 @:128 B@:128
Send: M105
Recv: ok T:107.5 /180.0 B:63.2 /64.0 @:128 B@:128
Send: M105
Recv: ok T:113.0 /180.0 B:63.2 /64.0 @:128 B@:128
Send: M105
Recv: ok T:118.3 /180.0 B:63.4 /64.0 @:128 B@:128
Send: M105
Recv: ok T:123.6 /180.0 B:63.5 /64.0 @:128 B@:128
Send: M105
Recv: ok T:128.5 /180.0 B:63.5 /64.0 @:128 B@:128
Send: M105
Recv: ok T:133.4 /180.0 B:63.7 /64.0 @:128 B@:128
Send: M105
Recv: ok T:138.2 /180.0 B:63.9 /64.0 @:128 B@:128
Send: M105
Recv: ok T:142.8 /180.0 B:64.0 /64.0 @:128 B@:128
Send: M105
Recv: ok T:147.5 /180.0 B:64.0 /64.0 @:128 B@:0
Send: M105
Recv: ok T:152.2 /180.0 B:63.8 /64.0 @:128 B@:0
Send: M105
Recv: ok T:156.3 /180.0 B:63.4 /64.0 @:128 B@:128
Send: M105
Recv: ok T:160.2 /180.0 B:63.2 /64.0 @:128 B@:128
Changing monitoring state from 'Operational' to 'Printing'
Send: N0 M110 N0_125
Recv: ok
Send: N1 M107_36
Recv: ok
Send: N2 M190 S65_89
Recv: T:161.47 E:0 B:63.2
Recv: T:162.35 E:0 B:63.2
Recv: T:163.24 E:0 B:63.2
Recv: T:163.84 E:0 B:63.2
Recv: T:164.71 E:0 B:63.2
Recv: T:165.42 E:0 B:63.2
Recv: T:166.18 E:0 B:63.2
Recv: T:166.86 E:0 B:63.2
Recv: T:167.65 E:0 B:63.2
Recv: T:168.24 E:0 B:63.2
Recv: T:168.93 E:0 B:63.2
Recv: T:169.45 E:0 B:63.2
Recv: T:170.46 E:0 B:63.3
Recv: T:171.44 E:0 B:63.3
Recv: T:172.01 E:0 B:63.4
Recv: T:172.69 E:0 B:63.4
Recv: T:173.33 E:0 B:63.4
Recv: T:173.70 E:0 B:63.4
Recv: T:173.73 E:0 B:63.4
Recv: T:173.82 E:0 B:63.4
Recv: T:173.75 E:0 B:63.4
Recv: T:173.56 E:0 B:63.5
Recv: T:172.96 E:0 B:63.5
Recv: T:172.80 E:0 B:63.5
Recv: T:172.57 E:0 B:63.5
Recv: T:172.22 E:0 B:63.5
Recv: T:172.22 E:0 B:63.5
Recv: T:172.22 E:0 B:63.6
Recv: T:172.43 E:0 B:63.7
Recv: T:172.62 E:0 B:63.7
Recv: T:173.03 E:0 B:63.7
Recv: T:173.59 E:0 B:63.7
Recv: T:174.07 E:0 B:63.7
Recv: T:174.81 E:0 B:63.8
Recv: T:175.19 E:0 B:63.9
Recv: T:175.93 E:0 B:63.9
Recv: T:176.76 E:0 B:63.9
Recv: T:177.55 E:0 B:63.9
Recv: T:178.36 E:0 B:64.0
Recv: T:179.00 E:0 B:64.0
Recv: T:179.63 E:0 B:64.0
Recv: T:180.00 E:0 B:64.0
Recv: T:180.45 E:0 B:64.0
Recv: T:180.68 E:0 B:64.2
Recv: T:180.85 E:0 B:64.2
Recv: T:180.71 E:0 B:64.1
Recv: T:180.40 E:0 B:64.2
Recv: T:180.00 E:0 B:64.2
Recv: T:180.00 E:0 B:64.2
Recv: T:179.63 E:0 B:64.2
Recv: T:179.63 E:0 B:64.2
Recv: T:179.63 E:0 B:64.3
Recv: T:179.86 E:0 B:64.4
Recv: T:180.09 E:0 B:64.4
Recv: T:180.74 E:0 B:64.4
Recv: T:181.36 E:0 B:64.5
Recv: T:181.82 E:0 B:64.5
Recv: T:182.27 E:0 B:64.5
Recv: T:182.73 E:0 B:64.5
Recv: T:182.81 E:0 B:64.5
Recv: T:183.13 E:0 B:64.6
Recv: T:183.15 E:0 B:64.7
Recv: T:182.70 E:0 B:64.7
Recv: T:182.64 E:0 B:64.6
Recv: T:181.99 E:0 B:64.7
Recv: T:181.59 E:0 B:64.7
Recv: T:181.19 E:0 B:64.7
Recv: T:180.88 E:0 B:64.8
Recv: T:180.45 E:0 B:64.8
Recv: T:180.45 E:0 B:64.8
Recv: T:180.40 E:0 B:64.8
Recv: T:180.54 E:0 B:64.9
Recv: T:180.68 E:0 B:64.9
Recv: T:181.34 E:0 B:65.0
Recv: ok
Send: N3 M104 S205_97
Recv: ok
Send: N4 G28_23
Recv: ok
Send: N5 G1 Z5 F5000_1
Recv: ok
Send: N6 M109 S205_105
Recv: T:185.1 E:0 W:?
Recv: T:185.7 E:0 W:?
Recv: T:186.4 E:0 W:?
Recv: T:186.9 E:0 W:?
Recv: T:187.5 E:0 W:?
Recv: T:188.2 E:0 W:?
Recv: T:188.6 E:0 W:?
Recv: T:189.1 E:0 W:?
Recv: T:189.8 E:0 W:?
Recv: T:190.4 E:0 W:?
Recv: T:191.0 E:0 W:?
Recv: T:191.6 E:0 W:?
Recv: T:192.3 E:0 W:?
Recv: T:193.1 E:0 W:?
Recv: T:193.7 E:0 W:?
Recv: T:194.3 E:0 W:?
Recv: T:195.1 E:0 W:?
Recv: T:195.9 E:0 W:?
Recv: T:196.7 E:0 W:?
Recv: T:197.3 E:0 W:?
Recv: T:197.4 E:0 W:?
Recv: T:197.8 E:0 W:?
Recv: T:197.4 E:0 W:?
Recv: T:197.4 E:0 W:?
Recv: T:197.4 E:0 W:?
Recv: T:197.3 E:0 W:?
Recv: T:197.3 E:0 W:?
Recv: T:197.3 E:0 W:?
Recv: T:197.4 E:0 W:?
Recv: T:197.6 E:0 W:?
Recv: T:197.9 E:0 W:?
Recv: T:198.2 E:0 W:?
Recv: T:198.6 E:0 W:?
Recv: T:199.0 E:0 W:?
Recv: T:199.5 E:0 W:?
Recv: T:200.0 E:0 W:?
Recv: T:200.7 E:0 W:?
Recv: T:201.3 E:0 W:?
Recv: T:202.0 E:0 W:?
Recv: T:203.0 E:0 W:?
Recv: T:203.7 E:0 W:?
Recv: T:204.5 E:0 W:9
Recv: T:205.0 E:0 W:8
Recv: T:205.3 E:0 W:7
Recv: T:205.7 E:0 W:6
Recv: T:205.5 E:0 W:5
Recv: T:205.2 E:0 W:4
Recv: T:205.0 E:0 W:3
Recv: T:205.0 E:0 W:2
Recv: T:204.5 E:0 W:1
Recv: T:204.3 E:0 W:0
Recv: ok
Send: N7 G21_29
Recv: ok
Send: N8 G90_24
Recv: ok
Send: N9 M82_16
Recv: ok
Send: N10 G92 E0_118
Recv: ok
Send: N11 G1 Z0.500 F7800.000_62
Recv: ok
Send: N12 G1 E-2.00000 F2400.00000_1
Recv: ok
Send: N13 G92 E0_117
Recv: ok
Send: N14 G1 X74.197 Y59.889 F7800.000_98
Recv: ok
Send: N15 G1 E2.00000 F2400.00000_43
Recv: ok
Send: N16 G1 X74.965 Y58.964 E2.08408 F1200.000_39
Recv: ok
Send: N17 G1 X75.802 Y58.013 E2.17277_85
Recv: ok
Send: N18 G1 X76.813 Y56.941 E2.27582_87
Recv: ok
Send: N19 G1 X77.542 Y56.215 E2.34781_87
Recv: ok
Send: N20 G1 X78.441 Y55.369 E2.43421_80
Recv: ok
Send: N21 G1 X79.531 Y54.414 E2.53563_92
Recv: ok
Send: N22 G1 X80.297 Y53.787 E2.60485_85
Recv: ok
Send: N23 G1 X81.251 Y53.051 E2.68915_95
Recv: ok
Send: N24 G1 X82.414 Y52.220 E2.78916_91
Recv: ok
Send: N25 G1 X83.208 Y51.693 E2.85584_90
Recv: ok
Send: N26 G1 X84.209 Y51.072 E2.93829_91
Recv: ok
Send: N27 G1 X85.224 Y50.489 E3.02018_86
Recv: ok
Send: N28 G1 X86.253 Y49.946 E3.10156_84
Recv: ok
Send: N29 G1 X87.294 Y49.443 E3.18245_94
Recv: ok
Send: N30 G1 X88.346 Y48.980 E3.26290_81
Recv: ok
Send: N31 G1 X89.644 Y48.470 E3.36051_90
Recv: ok
Send: N32 G1 X90.481 Y48.175 E3.42258_82
Recv: ok
Send: N33 G1 X91.563 Y47.834 E3.50192_90
Recv: ok
Send: N34 G1 X92.652 Y47.535 E3.58093_91
Recv: ok
Send: N35 G1 X93.747 Y47.276 E3.65970_84
Recv: ok
Send: N36 G1 X94.849 Y47.060 E3.73825_82
Recv: ok
Send: N37 G1 X95.955 Y46.886 E3.81662_95
Recv: ok
Send: N38 G1 X97.325 Y46.728 E3.91308_92
Recv: ok
Send: N39 G1 X98.178 Y46.663 E3.97296_86
Recv: ok
Send: N40 G1 X99.293 Y46.615 E4.05102_92
Recv: ok
Send: N41 G1 X100.684 Y46.615 E4.14835_99
Recv: ok
Send: N42 G1 X101.922 Y46.670 E4.23506 F1200.000_19
Recv: ok
Send: N43 G1 X102.870 Y46.747 E4.30156_106
Recv: ok
Send: N44 G1 X104.388 Y46.936 E4.40865_97
Recv: ok
Send: N45 G1 X105.614 Y47.147 E4.49566_105
Recv: ok
Send: N46 G1 X106.555 Y47.344 E4.56291_111
Recv: ok
Send: N47 G1 X108.043 Y47.722 E4.67036_107
Recv: ok
Send: N48 G1 X109.244 Y48.086 E4.75817_110
Recv: ok
Send: N49 G1 X110.173 Y48.404 E4.82683_101
Recv: ok
Send: N50 G1 X111.613 Y48.964 E4.93494_98
Recv: ok
Send: N51 G1 X112.778 Y49.478 E5.02402_107
Recv: ok
Send: N52 G1 X113.687 Y49.918 E5.09472_111
Recv: ok
Send: N53 G1 X114.830 Y50.521 E5.18513_99
Recv: ok
Send: N54 G1 X115.956 Y51.173 E5.27619_99
Recv: ok
Send: N55 G1 X117.282 Y52.016 E5.38613_103
Recv: ok
Send: N56 G1 X118.364 Y52.770 E5.47835_103
Recv: ok
Send: N57 G1 X119.225 Y53.414 E5.55361_106

On Fri, Nov 20, 2015 at 11:03 AM, Gina Häußge notifications@github.com
wrote:

Ok, after @Salandora https://github.com/Salandora could reproduce the
problem, we took a guess at what might be causing it and I created a fix
for that. At least for @Salandora https://github.com/Salandora the
problem didn't reproduce any more, but I'd feel more confident marking this
issue as closed if other people seeing this behaviour also got better
results with the current maintenance branch (future 1.2.8 release).

So - could you guys please update to the maintenance branch and see if
the issue still manifests there? Instructions for OctoPi:

cd ~/OctoPrint
git pull
git checkout maintenance
source ~/oprint/bin/activate
python setup.py install
sudo service octoprint restart

(For custom installations, change the path to your OctoPrint checkout
folder (here: ~/OctoPrint) and your virtual environment (here: ~/oprint)
accordingly)

Anything above 1.2.8.dev39 should include the patch (full version string

of first version with the patch: 1.2.8.dev39+ga52a5ca).

Background: It might be caused by a combination of background tab
suspending and how the GCODE viewer reacts to progress updates. There might
be a backup in updates when the tab is backgrounded, causing the viewer to
try to render hundreds of updates once the tab regains focus. The patch
changes the behaviour such that OctoPrint now tracks if the browser tab
containing OctoPrint and the tab within OctoPrint with the GCODE viewer are
in focus, only trying to update the viewer if both is the case. While at it
I also made the webcam view unload the webcam stream if the browser tab
loses focus, no need to transfer that much data if nobody is watching.

That change should improve performance in general, even if it doesn't fix
that specific issue you are observing (I still haven't been able to
reproduce it myself, making it somewhat tricky to debug it...)


Reply to this email directly or view it on GitHub
#1065 (comment).

@normanclanger
Copy link

Meant also to say however that the interface is more responsive & I could flick between the different tabs - although they weren't being updated. As soon as I reloaded though, got page not available. The clock stops ticking even on the lh print panel.

@foosel
Copy link
Member

foosel commented Nov 21, 2015

Ok, so more debugging output needed for the socket connection I guess. No chance to figure this out otherwise. @Salandora does this match what you were observing at all, or is it another kind of behaviour? I'm getting the sneaking suspicion that we have more than one type of problem here and are mixing up between them.

@Salandora
Copy link
Contributor

That's another kind of problem.
@normanclanger said that even ping and ssh was unresponsive, so I would say it's a completely different problem, my guess is that the pi, for what ever reason, stopped the network communication, otherwise you could ping or ssh into it, shot in the dark, try to ping/ssh to the ip of your pi directly not to octopi.local(if this applies to you). Also check if your wifi connection(if it applies) is good.

EDIT: well after a fast read through the history, I guess the problem normanclanger has is a complete different to this one here. As @foosel already stated it more looks like there is some overload done on the pi while printing, while the original problem here sound like a broken websocket connection after some time.

@normanclanger
Copy link

Yes, I'll try and alternative route to my router via a wired connection
& my even take a monitor and keyboard out to the garage to see what is
happening locally during a print. Will update the thread with any findings.

Salandora mailto:notifications@github.com
21 November 2015 11:28 AM

That's another kind of problem.
@normanclanger https://github.com/normanclanger said that even ping
and ssh was unresponsive, so I would say it's a completely different
problem, my guess is that the pi, for what ever reason, stopped the
network communication, otherwise you could ping or ssh into it, shot
in the dark, try to ping/ssh to the ip of your pi directly not to
octopi.local(if this applies to you). Also check if your wifi
connection(if it applies) is good.


Reply to this email directly or view it on GitHub
#1065 (comment).

@jneilliii
Copy link
Contributor

For me ping would still respond and ssh would work, and so far so good. After applying the maintenance release chrome hasn't yet given me the aw snap error after several long prints. I have seen where the browser will be in kind of a frozen state, but shortly after clicking in the white space on the page it "catches up" and starts responding again. I think long term this is a good change no matter what, because it doesn't make sense to consume processing when the tab isn't active anyway. Specifically video streams as that seems like it would consume a lot of memory.

@foosel
Copy link
Member

foosel commented Nov 22, 2015

@jneilliii that's good new I guess, thanks. Also, I was going to leave this change in no matter what, even if it doesn't solve this specific problem here - it indeed makes too much sense.

@normanclanger
Copy link

Hi - after testing the ethernet over power connection I was using, I was shocked by the low bandwidth I was getting. The printer is in the garage - perhaps the wiring is too much of a challenge. Switching to wlan ironically, significantly improved the situation. Ping & ssh back & the web experience similar to jneiliii - periods of inactivity, but it catches up eventually, or on a reload.

Something changed after upgrading to 1.2.7 to cause my ethernet over power link to become unsuitable, as it was fine before that (and I haven't had the garage rewired). Now I can ssh to the pi, I don't see excessive bandwidth utilisation. Is these something which is latency sensitive in the scripts, which might cause it to freeze if a packet is dropped?

Thanks Tim

@foosel
Copy link
Member

foosel commented Nov 22, 2015 via email

@normanclanger
Copy link

Ok thanks - that makes sense. Happy to write my particular experience down to poor network connectivity,

@foosel
Copy link
Member

foosel commented Jan 25, 2016

Anyone still seeing this?

@jminardi
Copy link
Contributor Author

I have not seen it recently.

@jneilliii
Copy link
Contributor

I still have been running smoothly since upgrading to 1.2.8.

@normanclanger
Copy link

Yes same for me - all fine.

Thanks
Tim

Sent from my HTC

----- Reply message -----
From: "jneilliii" notifications@github.com
To: "foosel/OctoPrint" OctoPrint@noreply.github.com
Cc: "normanclanger" normanclanger@gmail.com
Subject: [OctoPrint] OctoPrint web interface becomes very sluggish (but print continues) (#1065)
Date: Mon, Jan 25, 2016 18:50

I still have been running smoothly since upgrading to 1.2.8.


Reply to this email directly or view it on GitHub:
#1065 (comment)

@foosel
Copy link
Member

foosel commented Jan 25, 2016

Ok, then I dare to close this now. Thanks everyone for the input!

@foosel
Copy link
Member

foosel commented Feb 15, 2016

Says she'll close it now, forgets to hit the close button... \o/

@foosel foosel closed this as completed Feb 15, 2016
@github-actions github-actions bot locked as resolved and limited conversation to collaborators May 30, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
needs testing Testing from the community is needed
Projects
None yet
Development

No branches or pull requests

6 participants