search

fieldOfView / Cura-OctoPrintPlugin

Cura plugin which enables printing directly to OctoPrint and monitoring the process
GNU Affero General Public License v3.0
493 stars 74 forks source link

Unable to connect to OctoPrint after 1.5.0 update #211

Closed Misterke closed 3 years ago

Misterke commented 3 years ago

The 1.5.0 update somehow broke all my API keys (probably linked to a change in user being shown for the keys being "_admin" for old ones and "admin" for new ones). Anyhow, that meant creating new API keys and adding them to all clients. No problem, until I got to Cura (4.8, but tested also 4.7 and was also broken there). The OctoPrint connection would always fail. I tried getting the settings with curl using the same API key and that worked, but I did notice it took quite some time. Together with the Cura.log showing that the problem might be timeout, I got to the following fix:

In DiscoverOctoPrintAction.py in function testApiKey, I changed

            self._settings_reply_timeout = NetworkReplyTimeout(
                self._settings_reply, 5000, self._onRequestFailed
            )

to

            self._settings_reply_timeout = NetworkReplyTimeout(
                self._settings_reply, 30000, self._onRequestFailed
            )

and that fixed the problem. I would expect this to be anyhow a good move, since having a 30s timeout instead of 5s here wouldn't harm if I'm not mistaken ...

fieldOfView commented 3 years ago

I would be concerned why it takes your OctoPrint instance more than 5 seconds to respond to a simple API request.

How long does it take to open octopi.local/api/settings?apikey=[you api key] in your browser?

I don't know what would have changed in OctoPrint 1.5.0 that makes it slower to respond.

vogler commented 3 years ago

@fieldOfView octopi.local/api/settings?apikey=[you api key] takes ~2s for me. @Misterke Do you also use the plugin UltimakerFormatPackage? I don't know if it threw this exception before, maybe it's the reason for the timeout. Haven't tried disabling the plugin, but changing the timeout to 30s also fixed it for me for now.

2020-12-03 12:28:07,971 - octoprint.filemanager - ERROR - Error when calling preprocessor hook for plugin UltimakerFormatPackage, ignoring
Traceback (most recent call last):
  File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/filemanager/__init__.py", line 713, in add_file
    allow_overwrite=allow_overwrite,
  File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/util/__init__.py", line 1890, in wrapper
    return f(*args, **kwargs)
  File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_ultimakerformatpackage/__init__.py", line 226, in ufp_upload
    thumbnail.write(zipObj.read("/Metadata/thumbnail.png"))
  File "/usr/lib/python3.7/zipfile.py", line 1428, in read
    with self.open(name, "r", pwd) as fp:
  File "/usr/lib/python3.7/zipfile.py", line 1467, in open
    zinfo = self.getinfo(name)
  File "/usr/lib/python3.7/zipfile.py", line 1395, in getinfo
    'There is no item named %r in the archive' % name)
KeyError: "There is no item named '/Metadata/thumbnail.png' in the archive"
2020-12-03 12:28:07,981 - octoprint - ERROR - Exception on /api/files/local [POST]
fieldOfView commented 3 years ago

@vogler, it is not entirely clear to me if you also get the timeout issue when connecting via the Connect to OctoPrint dialog.

vogler commented 3 years ago

@fieldOfView yes, same issue, same fix as above.

fieldOfView commented 3 years ago

The hunch I have is that due to changes in the discovery plugin on the OctoPrint side, the Cura plugin may be using an IPv6 address instead of IPv4. I have seen in the past on my own systems that IPv6 was a lot slower to respond than IPv4. A cura.log would be helpful to diagnose this.

vogler commented 3 years ago

Here's some of my cura.log. The UI also just showed this HTML response with Internal Server Error. Lots of type errors around but no mention of a timeout. However, changing it made the problem go away. rpi4 only resolves to an IPv4 address.

...
2020-12-03 12:28:06,483 - ERROR - [MainThread] UM.View.RenderBatch.render [225]: VAO not created. Hell breaks loose
2020-12-03 12:28:06,542 - DEBUG - [MainThread] UFPWriter.UFPWriter.write [92]: Thumbnail not created, cannot save it
2020-12-03 12:28:06,636 - DEBUG - [MainThread] UM.Controller.setActiveStage [180]: Setting active stage to MonitorStage
2020-12-03 12:28:07,543 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Applications/Ultimaker Cura.app/Contents/MacOS/resources/qml/RoundedRectangle.qml:68: TypeError: Cannot read property of null
2020-12-03 12:28:07,640 - INFO - [MainThread] SliceInfoPlugin.SliceInfo._onRequestFinished [284]: SliceInfo sent successfully
2020-12-03 12:28:07,880 - ERROR - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice._onUploadFinished [1104]: OctoPrintOutputDevice got an 500 error uploading to http://rpi4:5000/api/files/local
2020-12-03 12:28:07,881 - ERROR - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice._onUploadFinished [1105]: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2 Final//EN">
<title>500 Internal Server Error</title>
<h1>Internal Server Error</h1>
<p>The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application.</p>

2020-12-03 12:28:10,863 - DEBUG - [MainThread] UM.Controller.setActiveStage [180]: Setting active stage to PrepareStage
2020-12-03 12:28:10,890 - DEBUG - [MainThread] cura.Machines.Models.NozzleModel._update [28]: Updating NozzleModel.
2020-12-03 12:28:10,951 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Applications/Ultimaker Cura.app/Contents/MacOS/resources/qml/Menus/ConfigurationMenu/CustomConfiguration.qml:234: TypeError: Cannot read property 'activeStack' of undefined
2020-12-03 12:28:11,108 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:88: ReferenceError: stop is not defined
2020-12-03 12:28:11,112 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:72: TypeError: Cannot read property of null
...
fieldOfView commented 3 years ago

Could you please upload the entire thing somewhere and a link here?

I really don't think the thumbnail plugin issue is relevant here. Please open a new issue for that.

vogler commented 3 years ago

https://privatebin.net/?8f915520f77eb906#738QzfajnqMbjEwixYhVpwondk7QaYtWD16KfTinBGdo - will expire in 1 day, other services all had some size limit which was too low.

First time the issue occured was 2020-12-03 12:16:37 which was the first print after upgrading to OctoPrint 1.5.0.

fieldOfView commented 3 years ago

Thanks for the log. I see that you are not using an automatically discovered instance, but a manually Added one, so discovery should not be the issue here. @Misterke is that the case for you too?

Finally, this is off-topic, but there's an update available for the LinearAdvance plugin that will prevent all those errors about name 'support_tree_enable' not being defined.

vogler commented 3 years ago

Finally, this is off-topic, but there's an update available for the LinearAdvance plugin that will prevent all those errors about name 'support_tree_enable' not being defined.

I don't have that installed. You mean I should install 'Linear Advance Settings' in Cura?

fieldOfView commented 3 years ago

No, sorry, I see that the Ultimaker devs made a booboo when adding new profiles to Cura, making a mess of the logs (and resulting in broken profiles for the new Ultimaker 2 Plus Connect).

spence572 commented 3 years ago

@fieldOfView I am having the same issue but I can't find the py file mentioned above to adjust the timeout.

mmo31 commented 3 years ago

@fieldOfView I have have this issue. I update today octopi from 1.4.x to 1.5. Then i reconfigure the key associated to a octopi user (mandatory now in v1.5). The request to API key is working. But, when i click on print with octoprint, I'm stuck on " Waiting for OctoPrint to connect with printer" ; knowing that octoprint is already connected, and pushing gcode throu octoprint ui is working.

Tell me if you need any logs.

Thx a lot for the work already done and your support.

spence572 commented 3 years ago

@fieldOfView I am having the same issue but I can't find the py file mentioned above to adjust the timeout.

@fieldOfView I managed to resolve the issue by removing some plugins from OctoPrint. Sorry, I can't tell you if it was down to one particular plugin as I went through and removed about 5.

Thanks

fieldOfView commented 3 years ago

@vogler, @Misterke what 3rd party plugins do you have installed? After what @spence572, I wonder if there may be a plugin issue influencing loading the settings from the API.

vogler commented 3 years ago 
2020-12-03 12:26:09,573 - octoprint.plugin.core - INFO - 49 plugin(s) registered with the system:
|  Access Anywhere - The Spaghetti Detective (1.4.4) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_thespaghettidetective
|  Action Command Notification Support (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/action_command_notification
|  Action Command Prompt Support (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/appkeys
|  Autoscroll (0.0.3) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_autoscroll
|  Autoselect Plugin (0.3.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_autoselect
|  Backup & Restore (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/backup
|  Cancel Objects (0.4.4) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_cancelobject
|  Consolidated Tabs (0.1.3) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_consolidatedtabs
| !Continuous Print (1.1.2) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/continuousprint
|  Core Wizard (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/corewizard
|  Cost Estimation (3.1.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_costestimation
|  Cura Thumbnails (0.2.1) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_ultimakerformatpackage
| !Dashboard (1.14.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_dashboard
|  Discovery (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/discovery
|  DisplayLayerProgress Plugin (1.24.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_DisplayLayerProgress
|  Error Tracking (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/errortracking
|  Filament Manager (1.6.3) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_filamentmanager
|  File Check (2020.8.7) (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_file_check
|  FileManager (0.1.4) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_filemanager
|  Firmware Check (2020.9.23) (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.7.3) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_firmwareupdater
|  GCode Viewer (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/gcodeviewer
| #GcodeEditor (0.2.8) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_GcodeEditor
|  Logging (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/logging
|  Marlin GCode Documentation (0.11.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_marlingcodedocumentation
|  MQTT (0.8.7) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_mqtt
|  MultiCam (0.2.8) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_multicam
| !OctoEverywhere! (0.2.1) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_octoeverywhere
|  Octolapse (0.4.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_octolapse
|  Pi Support Plugin (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/pi_support
|  Plugin Manager (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/pluginmanager
|  Preheat Button (0.5.1) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_preheat
|  PrettyGCode (1.2.2) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_prettygcode
|  PrintJobHistory (1.10.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_PrintJobHistory
|  PrintTimeGenius Plugin (2.2.6) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_PrintTimeGenius
|  PrusaSlicer Thumbnails (0.1.3) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_prusaslicerthumbnails
|  Resource Monitor (0.2.6) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_resource_monitor
|  Software Update (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/softwareupdate
|  SpoolManager Plugin (1.0.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_SpoolManager
|  STL Viewer (0.4.2) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_stlviewer
|  Tab Order (0.5.12) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_taborder
|  Tasmota-MQTT (0.3.8) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_tasmota_mqtt
|  Terminal Commands Extended (0.1.6) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_terminalcommandsextended
|  Terminal Messaging (0.1.0) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_terminalmessaging
| !UI Customizer (0.0.9.5) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_uicustomizer
|  Virtual Printer (bundled) = /home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
fieldOfView commented 3 years ago

212 was marked as a duplicate of this bug. @ctwise, do you have a lot of plugins, like @vogler?

Something else I want to rule out is if it was really the 1.5.x update that necessitates the longer timeout, or if it was just a long time ago that you last had to connect the OctoPrint instance to Cura; I see most of you mentioning key issues as well. If previous updates of Cura, OctoPrint and Cura did not require you to visit the Connect to OctoPrint dialog, then that dialog may have been "broken" for longer.

ctwise commented 3 years ago

This was an initial install of Octoprint. It’s never even been used yet. The only plug-in I’ve installed is the print time genius plugin. Nothing else.

On Mon, Dec 7, 2020 at 11:08 AM Aldo Hoeben notifications@github.com wrote:

212 https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/212 was

marked as a duplicate of this bug. @ctwise https://github.com/ctwise, do you have a lot of plugins, like @vogler https://github.com/vogler?

Something else I want to rule out is if it was really the 1.5.x update that necessitates the longer timeout, or if it was just a long time ago that you last had to connect the OctoPrint instance to Cura; I see most of you mentioning key issues as well. If previous updates of Cura, OctoPrint and Cura did not require you to visit the Connect to OctoPrint dialog, then that dialog may have been "broken" for longer.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/211#issuecomment-740014049, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAABLBTXNBMUTVPWWRZMMB3STT4WRANCNFSM4ULR4TWQ .

vogler commented 3 years ago

or if it was just a long time ago that you last had to connect the OctoPrint instance to Cura

What do you mean by connect? It has to connect every time I open Cura or print, no? Everything worked fine before OctoPrint 1.5. I had to create a new user (before it was _admin) and update the key for it. No problems in the 'Connect to OctoPrint' window - it says it's connected. Only when I clicked 'Print with OctoPrint' it failed with 'Internal Server Error'.

vogler commented 3 years ago

It somehow works now, even with the original 5s timeout. I upgraded to OctoPrint 1.5.1 and deselected 'Automatically discover local OctoPrint instances' in Cura.

OctoPrint log ~~~ 2020-12-07 20:45:11,624 - octoprint.server.util.flask - INFO - Passively logging in user voglerr from 192.168.178.25 2020-12-07 20:45:11,625 - octoprint.access.users - INFO - Logged in user: voglerr qqqqqqqqqqqqqqqqqqqqqqqqqqqqq 2020-12-07 20:45:42,534 - octoprint.plugins.DisplayLayerProgress - INFO - FilePreProcessor. Checking LayerExpressions. 2020-12-07 20:45:42,534 - octoprint.plugins.DisplayLayerProgress - INFO - FilePreProcessor. LayerExpression valid. Start processing... 2020-12-07 20:45:43,124 - octoprint.filemanager.analysis - INFO - Starting analysis of local:AG_fan_test.gcode 2020-12-07 20:45:43,140 - octoprint.plugins.autoselect - INFO - Selecting AG_fan_test.gcode on local that was just uploaded grep: Invalid content of \{\} 2020-12-07 20:45:43,373 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: AG_fan_test.gcode, owner: None, user: None 2020-12-07 20:45:43,536 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile 2020-12-07 20:45:43,726 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile 2020-12-07 20:45:43,824 - octoprint.plugins.DisplayLayerProgress - INFO - File '/home/pi/.octoprint/uploads/AG_fan_test.gcode' selected. Determining number of layers. 2020-12-07 20:45:43,828 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile 2020-12-07 20:45:43,830 - octoprint.plugins.DisplayLayerProgress - INFO - Total height not found in MetaFile 2020-12-07 20:45:43,958 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile 2020-12-07 20:45:44,082 - octoprint.plugins.DisplayLayerProgress - INFO - File select-event processing done!' 2020-12-07 20:45:44,085 - octoprint.plugin - ERROR - Error while calling plugin SpoolManager Traceback (most recent call last): File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugin/__init__.py", line 271, in call_plugin result = getattr(plugin, method)(*args, **kwargs) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/util/__init__.py", line 1890, in wrapper return f(*args, **kwargs) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_SpoolManager/__init__.py", line 401, in on_event self._on_file_selectionChanged(payload) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_SpoolManager/__init__.py", line 349, in _on_file_selectionChanged allFilemants = metadata["analysis"]["filament"] KeyError: 'filament' 2020-12-07 20:45:44,316 - octoprint.plugins.autoselect - INFO - Selecting AG_fan_test.ufp on local that was just uploaded 2020-12-07 20:45:44,320 - octoprint.plugin - ERROR - Error while calling plugin autoselect Traceback (most recent call last): File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/plugin/__init__.py", line 271, in call_plugin result = getattr(plugin, method)(*args, **kwargs) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/util/__init__.py", line 1890, in wrapper return f(*args, **kwargs) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint_autoselect/__init__.py", line 49, in on_event self._printer.select_file(path, sd, False) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/__init__.py", line 415, in wrapper return f(*args, **kwargs) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/printer/standard.py", line 644, in select_file self._validateJob(path, sd) File "/home/pi/OctoPrint/venv/lib/python3.7/site-packages/octoprint/printer/standard.py", line 1205, in _validateJob filename octoprint.printer.InvalidFileLocation: /home/pi/.octoprint/uploads/AG_fan_test.ufp does not exist in local storage, cannot select for printing 2020-12-07 20:45:44,698 - octoprint.filemanager.analysis - INFO - Analysis of entry local:AG_fan_test.gcode finished, needed 1.57s 2020-12-07 20:45:44,706 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile 2020-12-07 20:45:44,915 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile 2020-12-07 20:45:44,971 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile 2020-12-07 20:45:45,147 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile 2020-12-07 20:45:45,344 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: AG_fan_test.gcode, owner: voglerr, user: voglerr 2020-12-07 20:45:45,352 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-12-07 20:45:45,355 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: AG_fan_test.gcode, owner: voglerr, user: voglerr 2020-12-07 20:45:45,361 - octoprint.plugins.DisplayLayerProgress - INFO - File '/home/pi/.octoprint/uploads/AG_fan_test.gcode' selected. Determining number of layers. 2020-12-07 20:45:45,370 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile 2020-12-07 20:45:45,395 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-12-07 20:45:45,464 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile 2020-12-07 20:45:45,505 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-12-07 20:45:45,656 - octoprint.plugins.DisplayLayerProgress - INFO - File select-event processing done!' 2020-12-07 20:45:45,772 - octoprint.plugins.DisplayLayerProgress - INFO - Printing started. Detailed progress started.{'name': 'AG_fan_test.gcode', 'path': 'AG_fan_test.gcode', 'origin': 'local', 'size': 478317, 'owner': 'voglerr', 'user': 'voglerr'} 2020-12-07 20:45:45,774 - octoprint.plugins.PrintJobHistory - INFO - Try reading Temperature from PreHeat-Plugin... 2020-12-07 20:45:45,782 - octoprint.plugins.PrintJobHistory - INFO - ... Temperature found '65.0' ' Tool 'tool0' '200.0' 2020-12-07 20:46:05,454 - octoprint.util.comm - INFO - Cancelling job on behalf of user voglerr 2020-12-07 20:46:05,458 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2020-12-07 20:46:05,484 - octoprint.plugins.filamentmanager - INFO - Filament used: 0.0 mm (tool0) 2020-12-07 20:46:05,495 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: AG_fan_test.gcode, owner: voglerr, user: voglerr 2020-12-07 20:46:05,615 - octoprint.plugins.DisplayLayerProgress - INFO - Printing stopped. Detailed progress stopped. 2020-12-07 20:46:05,637 - octoprint.plugins.PrintJobHistory - INFO - Print result:canceled, CaptureMode:always 2020-12-07 20:46:05,637 - octoprint.plugins.PrintJobHistory - INFO - Start capturing print job 2020-12-07 20:46:05,661 - octoprint.plugins.PrintJobHistory.SlicerSettingsParser - INFO - Start parsing Slicer-Settings 2020-12-07 20:46:05,758 - octoprint.plugins.PrintJobHistory.SlicerSettingsParser - INFO - Finished parsing Slicer-Settings 2020-12-07 20:46:05,761 - octoprint.plugins.PrintJobHistory.CameraManager - INFO - Thumbnail is present 2020-12-07 20:46:05,766 - octoprint.plugins.PrintJobHistory.CameraManager - INFO - Try converting thumbnail '/home/pi/.octoprint/data/PrintJobHistory/../UltimakerFormatPackage/AG_fan_test.png' to '/home/pi/.octoprint/data/PrintJobHistory/snapshots/20201207-204545.jpg' 2020-12-07 20:46:05,778 - octoprint.plugins.PrintJobHistory.CameraManager - INFO - Converting successfull! 2020-12-07 20:46:06,077 - octoprint.plugins.SpoolManager - INFO - Extruded filament length: 0.0 2020-12-07 20:46:06,077 - octoprint.plugins.SpoolManager - INFO - Current Spool filament length: 47125 2020-12-07 20:46:06,077 - octoprint.plugins.SpoolManager - INFO - New Spool filament length: 47125.0 2020-12-07 20:46:06,114 - octoprint.plugins.DisplayLayerProgress - INFO - Printing stopped. Detailed progress stopped. 2020-12-07 20:46:28,614 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Offline" ~~~
cura.log ~~~ 2020-12-07 20:45:10,393 - DEBUG - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice.connect [341]: Connection with instance rpi4 with url http://rpi4:5000/ started ... 2020-12-07 20:45:11,846 - DEBUG - [MainThread] OctoPrintPlugin.DiscoverOctoPrintAction._createAdditionalComponentsView [426]: Creating additional ui components for OctoPrint-connected printers. ... 2020-12-07 20:45:12,173 - DEBUG - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice.parseSettingsData [1178]: Instance needs time after uploading to analyse gcode 2020-12-07 20:45:12,182 - DEBUG - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice.parseSettingsData [1189]: Instance supports uploading .ufp instead of .gcode ... 2020-12-07 20:45:43,798 - DEBUG - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice._onUploadFinished [1109]: Resource created on OctoPrint instance: http://rpi4:5000/api/files/local/AG_fan_test.ufp 2020-12-07 20:45:45,166 - DEBUG - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice._onRequestFinished [944]: PrintTimeGenius analysis of files/local/AG_fan_test.gcode is done 2020-12-07 20:45:45,171 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Applications/Ultimaker Cura.app/Contents/MacOS/resources/qml/RoundedRectangle.qml:68: TypeError: Cannot read property of null 2020-12-07 20:45:45,175 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Applications/Ultimaker Cura.app/Contents/MacOS/resources/qml/RoundedRectangle.qml:68: TypeError: Cannot read property of null 2020-12-07 20:45:45,364 - DEBUG - [MainThread] OctoPrintPlugin.OctoPrintOutputDevice._onRequestFinished [961]: OctoPrint file command accepted 2020-12-07 20:45:51,917 - DEBUG - [MainThread] cura.AutoSave._onTimeout [59]: Autosaving preferences, instances and profiles 2020-12-07 20:45:58,116 - DEBUG - [MainThread] UM.Controller.setActiveStage [180]: Setting active stage to PrepareStage 2020-12-07 20:45:58,143 - DEBUG - [MainThread] cura.Machines.Models.NozzleModel._update [28]: Updating NozzleModel. 2020-12-07 20:45:58,242 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Applications/Ultimaker Cura.app/Contents/MacOS/resources/qml/Menus/ConfigurationMenu/CustomConfiguration.qml:234: TypeError: Cannot read property 'activeStack' of undefined 2020-12-07 20:45:58,331 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:88: ReferenceError: stop is not defined 2020-12-07 20:45:58,336 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:72: TypeError: Cannot read property of null 2020-12-07 20:45:58,341 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:156: TypeError: Cannot read property of null 2020-12-07 20:45:58,344 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:167: TypeError: Cannot read property of null 2020-12-07 20:45:58,348 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:168: TypeError: Cannot read property of null 2020-12-07 20:45:58,352 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:204: TypeError: Cannot read property of null 2020-12-07 20:45:58,358 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:205: TypeError: Cannot read property of null 2020-12-07 20:45:58,364 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:118: TypeError: Cannot read property of null 2020-12-07 20:45:58,368 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:118: TypeError: Cannot read property of null 2020-12-07 20:45:58,372 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:185: TypeError: Cannot read property of null 2020-12-07 20:45:58,377 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [406]: file:///Users/voglerr/Library/Application Support/cura/4.8/plugins/OctoPrintPlugin/OctoPrintPlugin/qml/MonitorItem4x.qml:187: TypeError: Cannot read property of null ... ~~~
fieldOfView commented 3 years ago

It has to connect every time I open Cura or print, no?

The timeout we're talking about is only ever used when checking the API key in the "Connect to OctoPrint" dialog.

vogler commented 3 years ago

Ah, ok, then it was maybe just the change in authentication.

fieldOfView commented 3 years ago

Sofar I have one reporter who is no longer responding, and one that attributed something not working to a timeout that seems to have been irrelevant to his problem.

I prefer not to just change a timeout to what I think is an unrealistic value without knowing why the longer timeout is needed and if this is indeed because of changes in OctoPrint 1.5.x, or if there is something else broken.

ctwise commented 3 years ago

It failed with a from scratch install of Octoprint 1.5. Increasing the timeout fixed it.

On Tue, Dec 8, 2020 at 3:59 PM Aldo Hoeben notifications@github.com wrote:

Sofar I have one reporter who is no longer responding, and one that attributed something not working to a timeout that seems to have been irrelevant to his problem.

I prefer not to just change a timeout to what I think is an unrealistic value without knowing why the longer timeout is needed and if this is indeed because of changes in OctoPrint 1.5.x, or if there is something else broken.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/211#issuecomment-741021316, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAABLBQRIYXQU5AZCL6JDITST2HSDANCNFSM4ULR4TWQ .

fieldOfView commented 3 years ago

@ctwise 1.5.0 or 1.5.1? Does a from scratch install of OctoPrint 1.4 fail in the same way?

ctwise commented 3 years ago

1.5.1. Never even tried 1.4. It’s my first printer and a virgin install of Octoprint.

On Tue, Dec 8, 2020 at 4:17 PM Aldo Hoeben notifications@github.com wrote:

@ctwise https://github.com/ctwise 1.5.0 or 1.5.1? Does a from scratch install of OctoPrint 1.4 fail in the same way?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/211#issuecomment-741045927, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAABLBXSJZU5IAVUMG45JMTST2JVTANCNFSM4ULR4TWQ .

fieldOfView commented 3 years ago

@ctwise How long does it take to open octopi.local/api/settings?apikey=[your api key] in your browser?

ctwise commented 3 years ago

15 seconds

On Tue, Dec 8, 2020 at 4:24 PM Aldo Hoeben notifications@github.com wrote:

@ctwise https://github.com/ctwise How long does it take to open octopi.local/api/settings?apikey=[your api key] in your browser?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/211#issuecomment-741055084, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAABLBSDYMYN3XY46UGUL4TST2KPNANCNFSM4ULR4TWQ .

fieldOfView commented 3 years ago

Does reloading the same page take as long?

Do all API calls take this long? Eg octopi.local/api/version?apikey=[your api key] or octopi.local/api/printer?apikey=[your api key]

ctwise commented 3 years ago

It's variable. The longest time was 15 seconds (the initial settings call). The calls are instant to up to 8 seconds.

On Tue, Dec 8, 2020 at 4:36 PM Aldo Hoeben notifications@github.com wrote:

Does reloading the same page take as long?

Do all API calls take this long? Eg octopi.local/api/version?apikey=[your api key] or octopi.local/api/printer?apikey=[your api key]

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/211#issuecomment-741072347, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAABLBXATEB5BOSB4I4TTHLST2L7XANCNFSM4ULR4TWQ .

kylenahas commented 3 years ago

I'm also having this issue. I am currently using Octoprint 1.5.1. This a mostly fresh install, I installed 1.3 on the SD card, and updated it immediately after configuring my printer.. I'm using a RPi 3B. The only plugin I've got installed is PSU Control.

I've noticed this version of Octoprint is very slow loading the Web UI. Maybe there have been upstream changes that impacted performance.

Increasing the timeout also was necessary for me to connect Cura to Octoprint.

fieldOfView commented 3 years ago

I've noticed this version of Octoprint is very slow loading the Web UI.

It would be great if this were reported on the OctoPrint issue queue, and if the participants of this thread could actively work with @foosel to get to the bottom of the issue. I can't reproduce it, so there's no use in me reporting it.

I'll be increasing the timeout to 20 seconds for now. You might be wondering why I'm not "just" set the timeout to 30 seconds and be done with it, or remove the timeout entirely. I put the timeout there for a reason; previous versions had no timeout, and people were waiting for minutes because the interface still said "waiting for OctoPrint to respond" while the request had already failed and would never return.

The plugin can make multiple requests every 2 seconds in normal use. If those requests take >10 seconds each to get a reply, then things are bound to get messy. I thought the 5 seconds was being generous.

fieldOfView commented 3 years ago

See d87df09

I'm adding a "fixed" label to this for my housekeeping, but will keep this issue open until a version containing this fix is available in the Marketplace.

mmo31 commented 3 years ago

@fieldOfView I have have this issue. I update today octopi from 1.4.x to 1.5. Then i reconfigure the key associated to a octopi user (mandatory now in v1.5). The request to API key is working. But, when i click on print with octoprint, I'm stuck on " Waiting for OctoPrint to connect with printer" ; knowing that octoprint is already connected, and pushing gcode throu octoprint ui is working.

Tell me if you need any logs.

Thx a lot for the work already done and your support.

Timeout increase fixed the issue on my side.

fieldOfView commented 3 years ago

Let me make this clear one more time: the timeout we are talking about in this issue ONLY affects checking the API key in the "Connect to OctoPrint" dialog. Anything that happens outside that dialog can not be affected by that timeout.

So if you see the "Waiting for OctoPrint to connect with printer" message, that has nothing to do with the timeout. It may have something to do with your OctoPrint instance taking unrealistically long to respond to API requests, but that cannot be fixed by changing this single timeout.

ctwise commented 3 years ago

Can’t speak for everyone, but I appreciate it.

On Wed, Dec 9, 2020 at 4:22 AM Aldo Hoeben notifications@github.com wrote:

I've noticed this version of Octoprint is very slow loading the Web UI.

It would be great if this were reported on the OctoPrint issue queue https://github.com/OctoPrint/OctoPrint/issues, and if the participants of this thread could actively work with @foosel https://github.com/foosel to get to the bottom of the issue. I can't reproduce it, so there's no use in me reporting it.

I'll be increasing the timeout to 20 seconds for now. You might be wondering why I'm not "just" set the timeout to 30 seconds and be done with it, or remove the timeout entirely. I put the timeout there for a reason; previous versions had no timeout, and people were waiting for minutes because the interface still said "waiting for OctoPrint to respond" while the request had already failed and would never return.

The plugin can make multiple requests every 2 seconds in normal use. If those requests take >10 seconds each to get a reply, then things are bound to get messy https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/136. I thought the 5 seconds was being generous.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/fieldOfView/Cura-OctoPrintPlugin/issues/211#issuecomment-741645443, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAABLBQFSCEZILFNF73WCWLST46W7ANCNFSM4ULR4TWQ .

rbotte commented 3 years ago

Having the same issue, Cura 4.7 and 4.8. after Octoprint update loading the UI I noticed this slowly load of the UI. Editing NetworkReplyTimeout as OP did, fixed the connection issue.

fieldOfView commented 3 years ago

after Octoprint update loading the UI I noticed this slowly load of the UI

This needs to be reported on the OctoPrint issue queue, or it will never be fixed. Just changing this timeout is like sweeping the problem under the carpet.

thilbig commented 3 years ago

I can confirm that setting the NetworkReplyTimeout from 5000 to 30000 solve the problem when using Cura 4.8.0 with OctoPrint Connection 3.5.17 and OctoPrint 1.5.2. Thanks to @Misterke!

pukakuka commented 3 years ago

Had the same problem, increasing the Timeout time solved it!

fieldOfView commented 3 years ago

Please help me test a fixed version by downloading this development snapshot and dropping the file onto the buildplate in Cura like you would open a 3d model.

3msKurWJAdttsjd commented 3 years ago

edited The development snapshot fixed the issue for me. I was having the issue on one of two octopi using the same instance of Cura only.

TWIISTED-STUDIOS commented 3 years ago

Please help me test a fixed version by downloading this development snapshot and dropping the file onto the buildplate in Cura like you would open a 3d model.

This Fix has worked perfectly without needing to do the original fix posted near the top thank you very much.

fieldOfView commented 3 years ago

A new version including a fix for this issue is available from the Marketplace.

lloydbigoil commented 3 years ago

still having this issue