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

Cura hangs completely during "add printer" wizard #15263

Closed
2 tasks
faern opened this issue Apr 16, 2023 · 38 comments
Closed
2 tasks

Cura hangs completely during "add printer" wizard #15263

faern opened this issue Apr 16, 2023 · 38 comments
Labels
Status: Under Investigation The issue has been confirmed or is assumed to be likely to be a real issue. It's pending discussion. Type: Bug The code does not produce the intended behavior.

Comments

@faern
Copy link

faern commented Apr 16, 2023

Application Version

5.3.0 (and 5.4.0-alpha)

Platform

Fedora Linux 37

Printer

Voron 2.4 350mm (and many others)

Reproduction steps

  1. Clean install of Cura 5.3.0 from either flatpak or the AppImage
  2. Go to "Add printer" -> "Non UltiMaker printer" -> "Add a non-networked printer"
  3. Select almost any printer (I have reproduced this hang with "Ultimaker 2", "Voron 2 350mm" and "Prusa i3") and hit next.

Actual results

Cura will lock up completely at this stage. Or if lucky it will add the printer, go back to show the print bed and then lock up a few seconds later.

Expected results

I should be able to add printers without issue.

Checklist of files to include

  • Log file
  • Project file

Additional information & file uploads

I'm on Fedora 37. I have tried:

There is no cura.log stored at ~/.local/share/cura/5.3/cura.log. I don't know what happened. I had one, but then I deleted it to get a new fresh log to upload. But now no new logs are generated.

When running from a terminal I have the following output from Cura. But all this output is printed long before the lockup:

PyInstaller/loader/pyimod02_importers.py:352: DeprecationWarning: the imp module is deprecated in favour of importlib and slated for removal in Python 3.12; see the module's documentation for alternative uses
Cyclic dependency detected between "file:///tmp/.mount_UltiMaL9H4Qv/share/cura/resources/qml/Actions.qml" and "file:///tmp/.mount_UltiMaL9H4Qv/share/cura/resources/qml/Actions.qml"
QQmlEngine::setContextForObject(): Object already has a QQmlContext
file:///tmp/.mount_UltiMaL9H4Qv/share/cura/resources/qml/PrintSetupSelector/Recommended/RecommendedPrintSetup.qml:96:17: QML QQuickItem: Binding loop detected for property "height"
file:///tmp/.mount_UltiMaL9H4Qv/share/cura/resources/qml/PrintSetupSelector/Recommended/RecommendedPrintSetup.qml:96:17: QML QQuickItem: Binding loop detected for property "height"
@faern faern added Status: Triage This ticket requires input from someone of the Cura team Type: Bug The code does not produce the intended behavior. labels Apr 16, 2023
@faern
Copy link
Author

faern commented Apr 17, 2023

I tried the flatpak install on two other machines now. One with Fedora 36 and one with fedora 37. It works fine on both. So not sure what's broken on my main desktop machine. Could it be something regarding GPU drivers? Because the desktop has a dedicated AMD graphics card, but the other two machines just have intel graphics.

@nouspiro
Copy link

nouspiro commented Apr 18, 2023

I think I have same issue. It is quite possible that it get stuck in USB printing. Because after deleting config I managed to get it working once. But after one reboot I get this message and right after that it get stuck. That one time that it worked I could see that it was trying different baud rates on /dev/ttyS0
[JobQueueWorker [1]] USBPrinting.AutoDetectBaudJob.run [24]: Auto detect baud rate started

After I run sudo chmod 600 /dev/ttyS0 cura started correctly. It just throw error about permision error to /dev/ttyS0

@eloo
Copy link

eloo commented Apr 29, 2023

Same for me.
The wizard is freezing when i try to add my printer.
Here are the logs

PyInstaller/loader/pyimod02_importers.py:352: DeprecationWarning: the imp module is deprecated in favour of importlib and slated for removal in Python 3.12; see the module's documentation for alternative uses
Warning: Ignoring WAYLAND_DISPLAY on Gnome. Use QT_QPA_PLATFORM=wayland to run on Wayland anyway.
Cyclic dependency detected between "file:///opt/ultimaker-cura/share/cura/resources/qml/Actions.qml" and "file:///opt/ultimaker-cura/share/cura/resources/qml/Actions.qml"
QQmlEngine::setContextForObject(): Object already has a QQmlContext
file:///opt/ultimaker-cura/share/cura/resources/qml/PrintSetupSelector/Recommended/RecommendedPrintSetup.qml:96:17: QML QQuickItem: Binding loop detected for property "height"
file:///opt/ultimaker-cura/share/cura/resources/qml/PrintSetupSelector/Recommended/RecommendedPrintSetup.qml:96:17: QML QQuickItem: Binding loop detected for property "height"

** (UltiMaker-Cura:39963): WARNING **: 21:06:33.020: atk-bridge: get_device_events_reply: unknown signature
QObject::startTimer: Timers cannot be started from another thread
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/SimpleCheckBox.qml:24:5: QML SimpleCheckBox: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/ComboBoxWithOptions.qml:24:5: QML ComboBoxWithOptions: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/ComboBoxWithOptions.qml:24:5: QML ComboBoxWithOptions: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/SimpleCheckBox.qml:24:5: QML SimpleCheckBox: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/SimpleCheckBox.qml:24:5: QML SimpleCheckBox: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/SimpleCheckBox.qml:24:5: QML SimpleCheckBox: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/ComboBoxWithOptions.qml:24:5: QML ComboBoxWithOptions: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/ComboBoxWithOptions.qml:24:5: QML ComboBoxWithOptions: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML PrintHeadMinMaxTextField: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/ComboBoxWithOptions.qml:24:5: QML ComboBoxWithOptions: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/ComboBoxWithOptions.qml:24:5: QML ComboBoxWithOptions: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"
file:///opt/ultimaker-cura/share/cura/resources/qml/MachineSettings/NumericTextFieldWithUnit.qml:21:5: QML NumericTextFieldWithUnit: Binding loop detected for property "width"

Systeminfo:
Linux Manjaro Gnome with Wayland
Cura: 5.3.1 AppImage (first seen in 5.3.0)
Printer: Ender 3 V2 (but happens with other printers as well)

@nouspiro
Copy link

Try run sudo chmod 600 /dev/ttyS0 this workaround helped me.

@eloo
Copy link

eloo commented Apr 30, 2023

I have tried this already but did not work.. also when I run cura as sudo it's not working.

Further my printer is not connected to my PC

@MariMakes
Copy link
Contributor

Hey @faern,

Thanks for your super detailed report 👍
I'm on Windows myself but we have some Linux Developers that might have a better grip on what is happening.
I'll bring it up to the team to see what they can do.
Fingers crossed 🤞

@MariMakes MariMakes added Status: Under Investigation The issue has been confirmed or is assumed to be likely to be a real issue. It's pending discussion. and removed Status: Triage This ticket requires input from someone of the Cura team labels May 5, 2023
@eloo
Copy link

eloo commented May 19, 2023

@MariMakes
any updates here since the last two weeks?

It really a shame that the Linux support is that bad for Cura.
With nearly every minor update of Cura its not working again :(

@faern
Copy link
Author

faern commented May 22, 2023

Try run sudo chmod 600 /dev/ttyS0 this workaround helped me.

This does not work for me. But I'm not ruling out the possibility that it's a USB issue in some way. One of the differences between my working and my non-working computer is the hardware/connected peripherals.

@piontec
Copy link

piontec commented Jun 22, 2023

Same here. 5.2.1 was the last release that worked for me. 5.3.x and 5.4.0-beta have the same behavior: when I try to add my ender 3 (without the printer being connected to the PC, as it's a wireless with octoprint), the "add printer" dialog freezes and cure is dead. Tested with adding it as 'ender 3/ v2' and 'ender 3 pro'. I'm on ubuntu 23.04 with wayland.

@MariMakes
Copy link
Contributor

Hey @piontec,

I recognize your Ubuntu version 🤔
Ubuntu does not ship FUSE 2 anymore on 23.04. This is required to run our appimages.
We have reports that Cura 5.4 runs if you install FUSE 2 with sudo apt install libfuse2

Can you let us know if installing this library works for you?

@piontec
Copy link

piontec commented Jun 26, 2023

I had it installed all the time - unfortunately, this changes nothing :|

@eloo
Copy link

eloo commented Jun 27, 2023

Still not working with 5.4.0-beta.1-linux-modern.AppImage

system: manjaro
linux: 6.1

logs from fresh (no ~/.config/cura and ~/.local/share/cura dirs)

                                                                                                                                                            14:32:49   
trimesh/curvature.py:12: DeprecationWarning: Please use `coo_matrix` from the `scipy.sparse` namespace, the `scipy.sparse.coo` namespace is deprecated.
  from scipy.sparse.coo import coo_matrix
UM/Qt/QtApplication.py:697: DeprecationWarning: QEvent constructor is deprecated
  super().__init__(self.QtFunctionEvent)
2023-06-27 14:31:50,804 - DEBUG - [MainThread] UM.Application.initialize [163]: Initializing UltiMaker Cura
2023-06-27 14:31:50,804 - DEBUG - [MainThread] UM.Application.initialize [164]: App Version 5.4.0-beta.1
2023-06-27 14:31:50,804 - DEBUG - [MainThread] UM.Application.initialize [165]: Api Version 8.4.0
2023-06-27 14:31:50,805 - DEBUG - [MainThread] UM.Application.initialize [166]: Build type None
2023-06-27 14:31:50,805 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/lib/uranium must be a folder.
2023-06-27 14:31:50,805 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/lib64/uranium must be a folder.
2023-06-27 14:31:50,805 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/lib32/uranium must be a folder.
2023-06-27 14:31:50,805 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/.mount_UltiMaoYKRN8/plugins must be a folder.
2023-06-27 14:31:50,805 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/Resources/uranium/plugins must be a folder.
2023-06-27 14:31:50,806 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/Resources/cura/plugins must be a folder.
2023-06-27 14:31:50,806 - DEBUG - [MainThread] UM.Resources.__initializeStoragePaths [481]: Initializing storage paths
2023-06-27 14:31:50,806 - DEBUG - [MainThread] UM.Resources.__initializeStoragePaths [491]: Config storage path is /home/joseph/.config/cura/5.4
2023-06-27 14:31:50,806 - DEBUG - [MainThread] UM.Resources.__initializeStoragePaths [499]: Data storage path is /home/joseph/.local/share/cura/5.4
2023-06-27 14:31:50,806 - DEBUG - [MainThread] UM.Resources.__initializeStoragePaths [511]: Cache storage path is /home/joseph/.cache/cura/5.4
2023-06-27 14:31:50,807 - DEBUG - [MainThread] UM.Resources._copyLatestDirsIfPresent [536]: Found config: ['/home/joseph/.config/cura'] and data: ['/home/joseph/.local/share/cura']
2023-06-27 14:31:50,807 - DEBUG - [MainThread] UM.Resources._copyLatestDirsIfPresent [540]: Latest config path: None and latest data path: None
2023-06-27 14:31:50,807 - INFO - [MainThread] UM.Qt.QtApplication.initialize [164]: Preferences file not found, ignore and use default language 'en_US'
2023-06-27 14:31:50,807 - INFO - [MainThread] UM.PackageManager.__init__ [56]: Found bundled packages JSON file: /tmp/.mount_UltiMaoYKRN8/share/uranium/resources/bundled_packages/uranium.json
2023-06-27 14:31:50,807 - INFO - [MainThread] UM.PackageManager.__init__ [56]: Found bundled packages JSON file: /tmp/.mount_UltiMaoYKRN8/share/cura/resources/bundled_packages/cura.json
2023-06-27 14:31:50,807 - DEBUG - [MainThread] UM.View.GL.OpenGLContext.detectBestOpenGLVersion [124]: Trying OpenGL context 4.1...
2023-06-27 14:31:50,808 - DEBUG - [MainThread] UM.View.GL.OpenGLContext.detectBestOpenGLVersion [132]: Yay, we got at least OpenGL 4.1 core: 4.6 Core profile
2023-06-27 14:31:50,808 - DEBUG - [MainThread] UM.Qt.QtApplication.initialize [192]: Detected most suitable OpenGL context version: 4.1 Core profile
2023-06-27 14:31:50,808 - INFO - [MainThread] UM.Qt.QtApplication.initialize [199]: Initializing job queue ...
2023-06-27 14:31:50,808 - INFO - [MainThread] UM.Qt.QtApplication.initialize [203]: Initializing version upgrade manager ...
2023-06-27 14:31:50,808 - INFO - [MainThread] UM.PackageManager._loadManagementData [174]: Loaded bundled packages data from /tmp/.mount_UltiMaoYKRN8/share/uranium/resources/bundled_packages/uranium.json
2023-06-27 14:31:50,809 - INFO - [MainThread] UM.PackageManager._loadManagementData [174]: Loaded bundled packages data from /tmp/.mount_UltiMaoYKRN8/share/cura/resources/bundled_packages/cura.json
2023-06-27 14:31:50,809 - INFO - [MainThread] UM.PackageManager._loadManagementData [203]: User package management file /home/joseph/.local/share/cura/5.4/packages.json doesn't exist, do nothing
2023-06-27 14:31:50,809 - INFO - [MainThread] UM.PackageManager._removeAllScheduledPackages [280]: Attempting to remove the following scheduled packages: - 
2023-06-27 14:31:50,809 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/lib/cura must be a folder.
2023-06-27 14:31:50,809 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/lib64/cura must be a folder.
2023-06-27 14:31:50,809 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/libx32/cura must be a folder.
2023-06-27 14:31:50,810 - WARNING - [MainThread] UM.PluginRegistry.addPluginLocation [202]: Plugin location /tmp/lib32/cura must be a folder.
2023-06-27 14:31:50,810 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin ConsoleLogger 1.0.1
2023-06-27 14:31:50,820 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin OBJReader 1.0.1
2023-06-27 14:31:50,830 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin OBJWriter 1.0.1
2023-06-27 14:31:50,846 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin STLReader 1.0.1
2023-06-27 14:31:50,857 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin STLWriter 1.0.1
2023-06-27 14:31:50,870 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin FileLogger 1.0.1
2023-06-27 14:31:50,878 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin LocalContainerProvider 1.0.1
2023-06-27 14:31:50,885 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin LocalFileOutputDevice 1.0.1
2023-06-27 14:31:50,892 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin CameraTool 1.0.1
2023-06-27 14:31:50,900 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin MirrorTool 1.0.1
2023-06-27 14:31:50,910 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin RotateTool 1.0.1
2023-06-27 14:31:50,922 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin ScaleTool 1.0.1
2023-06-27 14:31:50,926 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin SelectionTool 1.0.1
2023-06-27 14:31:50,934 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin TranslateTool 1.0.1
2023-06-27 14:31:50,947 - INFO - [MainThread] UpdateChecker.UpdateChecker.checkNewVersion [69]: Checking for new version
UM/TaskManagement/TaskManager.py:20: DeprecationWarning: QEvent constructor is deprecated
  super().__init__(task_manager.event_type)
2023-06-27 14:31:50,954 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin UpdateChecker 1.0.1
2023-06-27 14:31:51,055 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin SimpleView 1.0.1
2023-06-27 14:31:51,117 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin 3MFReader 1.0.1
2023-06-27 14:31:51,141 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin 3MFWriter 1.0.1
2023-06-27 14:31:51,152 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin AMFReader 1.0.0
2023-06-27 14:31:51,176 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin CuraDrive 1.2.0
2023-06-27 14:31:51,217 - INFO - [MainThread] CuraEngineBackend.CuraEngineBackend.__init__ [96]: Found CuraEngine at: /tmp/.mount_UltiMaoYKRN8/CuraEngine
2023-06-27 14:31:51,218 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin CuraEngineBackend 1.0.1
2023-06-27 14:31:51,231 - DEBUG - [MainThread] UM.Backend.Backend._logSocketState [192]: Socket state changed to Listening
2023-06-27 14:31:51,238 - INFO - [MainThread] UM.Backend.Backend.startEngine [95]: Started engine process: /tmp/.mount_UltiMaoYKRN8/CuraEngine
2023-06-27 14:31:51,240 - DEBUG - [MainThread] UM.Backend.Backend._backendLog [115]: [Backend] Calling engine with: ['/tmp/.mount_UltiMaoYKRN8/CuraEngine', 'connect', '127.0.0.1:49674', '']
2023-06-27 14:31:51,275 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] 
2023-06-27 14:31:51,276 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] Cura_SteamEngine version 5.4.0-beta.1
2023-06-27 14:31:51,276 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] Copyright (C) 2022 Ultimaker
2023-06-27 14:31:51,277 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] 
2023-06-27 14:31:51,277 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin CuraProfileReader 1.0.1
2023-06-27 14:31:51,278 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] This program is free software: you can redistribute it and/or modify
2023-06-27 14:31:51,278 - DEBUG - [MainThread] UM.Backend.Backend._logSocketState [196]: Socket state changed to Connected
2023-06-27 14:31:51,278 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] it under the terms of the GNU Affero General Public License as published by
2023-06-27 14:31:51,279 - DEBUG - [MainThread] UM.Backend.Backend._onSocketStateChanged [185]: Backend connected on port 49674
2023-06-27 14:31:51,279 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] the Free Software Foundation, either version 3 of the License, or
2023-06-27 14:31:51,281 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] (at your option) any later version.
2023-06-27 14:31:51,282 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] 
2023-06-27 14:31:51,282 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] This program is distributed in the hope that it will be useful,
2023-06-27 14:31:51,283 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] but WITHOUT ANY WARRANTY; without even the implied warranty of
2023-06-27 14:31:51,283 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
2023-06-27 14:31:51,284 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] GNU Affero General Public License for more details.
2023-06-27 14:31:51,285 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] 
2023-06-27 14:31:51,286 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] You should have received a copy of the GNU Affero General Public License
2023-06-27 14:31:51,286 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] along with this program.  If not, see <http://www.gnu.org/licenses/>.
2023-06-27 14:31:51,287 - DEBUG - [EngineOutputThread] UM.Backend.Backend._backendLog [115]: [Backend] [2023-06-27 14:31:51.275] [info] Connecting to 127.0.0.1:49674
2023-06-27 14:31:51,290 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin CuraProfileWriter 1.0.1
2023-06-27 14:31:51,318 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin DigitalLibrary 1.1.0
2023-06-27 14:31:51,328 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin FirmwareUpdateChecker 1.0.1
2023-06-27 14:31:51,334 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin FirmwareUpdater 1.0.1
2023-06-27 14:31:51,342 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin GCodeGzReader 1.0.1
2023-06-27 14:31:51,351 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin GCodeGzWriter 1.0.1
2023-06-27 14:31:51,360 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin GCodeProfileReader 1.0.1
2023-06-27 14:31:51,384 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin GCodeReader 1.0.1
2023-06-27 14:31:51,395 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin GCodeWriter 1.0.1
2023-06-27 14:31:51,415 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin ImageReader 1.0.1
2023-06-27 14:31:51,426 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin LegacyProfileReader 1.0.1
2023-06-27 14:31:51,435 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin MachineSettingsAction 1.0.1
2023-06-27 14:31:51,465 - DEBUG - [MainThread] cura.OAuth2.AuthorizationService.getAccessToken [145]: No auth data to retrieve the access_token from
2023-06-27 14:31:51,466 - DEBUG - [MainThread] cura.UltimakerCloud.UltimakerCloudScope.requestHook [30]: User is not logged in for Cloud API request to https://api.ultimaker.com/cura-packages/v1/cura/v8.4.0/packages/package-updates?installed_packages=SupportEraser:1.0.1&installed_packages=LocalFileOutputDevice:1.0.1&installed_packages=STLReader:1.0.1&installed_packages=VersionUpgrade30to31:1.0.1&installed_packages=VersionUpgrade21to22:1.0.1&installed_packages=ConsoleLogger:1.0.1&installed_packages=XMLMaterialProfile:1.0.1&installed_packages=MachineSettingsAction:1.0.1&installed_packages=UFPWriter:1.0.1&installed_packages=VersionUpgrade42to43:1.0.0&installed_packages=SelectionTool:1.0.1&installed_packages=FirmwareUpdateChecker:1.0.1&installed_packages=SliceInfoPlugin:1.0.1&installed_packages=SentryLogger:1.0.0&installed_packages=X3DReader:1.0.1&installed_packages=UFPReader:1.0.0&installed_packages=VersionUpgrade40to41:1.0.1&installed_packages=VersionUpgrade43to44:1.0.0&installed_packages=Marketplace:1.0.0&installed_packages=OBJReader:1.0.1&installed_packages=SolidView:1.0.1&installed_packages=VersionUpgrade25to26:1.0.1&installed_packages=AMFReader:1.0.0&installed_packages=3MFWriter:1.0.1&installed_packages=UpdateChecker:1.0.1&installed_packages=VersionUpgrade48to49:1.0.0&installed_packages=VersionUpgrade34to35:1.0.1&installed_packages=TrimeshReader:1.0.0&installed_packages=VersionUpgrade462to47:1.0.0&installed_packages=MirrorTool:1.0.1&installed_packages=PrepareStage:1.0.1&installed_packages=VersionUpgrade44to45:1.0.0&installed_packages=3MFReader:1.0.1&installed_packages=VersionUpgrade35to40:1.0.0&installed_packages=VersionUpgrade27to30:1.0.1&installed_packages=VersionUpgrade49to410:1.0.0&installed_packages=CameraTool:1.0.1&installed_packages=RotateTool:1.0.1&installed_packages=TranslateTool:1.0.1&installed_packages=VersionUpgrade32to33:1.0.1&installed_packages=CuraProfileWriter:1.0.1&installed_packages=GCodeGzReader:1.0.1&installed_packages=GCodeWriter:1.0.1&installed_packages=VersionUpgrade460to462:1.0.0&installed_packages=GCodeProfileReader:1.0.1&installed_packages=GCodeGzWriter:1.0.1&installed_packages=LocalContainerProvider:1.0.1&installed_packages=LegacyProfileReader:1.0.1&installed_packages=FileLogger:1.0.1&installed_packages=VersionUpgrade22to24:1.0.1&installed_packages=ModelChecker:1.0.1&installed_packages=FirmwareUpdater:1.0.1&installed_packages=UM3NetworkPrinting:1.0.1&installed_packages=SimpleView:1.0.1&installed_packages=PerObjectSettingsTool:1.0.1&installed_packages=VersionUpgrade52to53:1.0.0&installed_packages=CuraProfileReader:1.0.1&installed_packages=RemovableDriveOutputDevice:1.0.1&installed_packages=VersionUpgrade41to42:1.0.0&installed_packages=VersionUpgrade33to34:1.0.1&installed_packages=OBJWriter:1.0.1&installed_packages=ImageReader:1.0.1&installed_packages=PostProcessingPlugin:2.2.1&installed_packages=VersionUpgrade26to27:1.0.1&installed_packages=GCodeReader:1.0.1&installed_packages=USBPrinting:1.0.2&installed_packages=VersionUpgrade47to48:1.0.0&installed_packages=DigitalLibrary:1.1.0&installed_packages=CuraDrive:1.2.0&installed_packages=VersionUpgrade411to412:1.0.0&installed_packages=SimulationView:1.0.1&installed_packages=STLWriter:1.0.1&installed_packages=MonitorStage:1.0.1&installed_packages=VersionUpgrade413to50:1.0.0&installed_packages=UltimakerMachineActions:1.0.1&installed_packages=XRayView:1.0.1&installed_packages=PreviewStage:1.0.1&installed_packages=ScaleTool:1.0.1&installed_packages=CuraEngineBackend:1.0.1&installed_packages=VersionUpgrade45to46:1.0.0&installed_packages=UltimakerNylon:1.4.0&installed_packages=GenericABS:1.4.0&installed_packages=FABtotumABS:1.4.0&installed_packages=UltimakerBAM:1.4.0&installed_packages=UltimakerCPEP:1.4.0&installed_packages=UltimakerPC:1.4.0&installed_packages=GenericPP:1.4.0&installed_packages=UltimakerPVA:1.4.0&installed_packages=UltimakerPP:1.4.0&installed_packages=GenericNylon:1.4.0&installed_packages=PolyWoodPLA:1.0.1&installed_packages=GenericPC:1.4.0&installed_packages=GenericCPE:1.4.0&installed_packages=UltimakerPLA:1.4.0&installed_packages=GenericPLA:1.4.0&installed_packages=GenericPETG:1.4.0&installed_packages=FABtotumPLA:1.4.0&installed_packages=PolyPlusPLA:1.0.1&installed_packages=FiberlogyHDPLA:1.0.1&installed_packages=GenericCFFPA:1.4.0&installed_packages=GenericGFFCPE:1.4.0&installed_packages=VertexDeltaPLA:1.4.0&installed_packages=DagomaChromatikPLA:1.0.1&installed_packages=OctofiberPLA:1.0.1&installed_packages=VertexDeltaPET:1.4.0&installed_packages=FABtotumTPU:1.4.0&installed_packages=GenericBAM:1.4.0&installed_packages=Filo3DPLA:1.0.1&installed_packages=IMADE3DJellyBOXPLA:1.0.1&installed_packages=GenericTPU:1.4.0&installed_packages=GenericPVA:1.4.0&installed_packages=VertexDeltaTPU:1.4.0&installed_packages=UltimakerABS:1.4.0&installed_packages=UltimakerCPE:1.4.0&installed_packages=FABtotumNylon:1.4.0&installed_packages=UltimakerTPLA:1.4.0&installed_packages=UltimakerTPU:1.4.0&installed_packages=PolyFlexPLA:1.0.1&installed_packages=GenericGFFPA:1.4.0&installed_packages=GenericCFFCPE:1.4.0&installed_packages=GenericToughPLA:1.4.0&installed_packages=GenericHIPS:1.4.0&installed_packages=IMADE3DJellyBOXPETG:1.0.1&installed_packages=VertexDeltaABS:1.4.0&installed_packages=PolyMaxPLA:1.0.1&installed_packages=GenericCPEPlus:1.4.0
2023-06-27 14:31:51,467 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin Marketplace 1.0.0
2023-06-27 14:31:51,475 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin ModelChecker 1.0.1
2023-06-27 14:31:51,480 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin MonitorStage 1.0.1
2023-06-27 14:31:51,492 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin PerObjectSettingsTool 1.0.1
2023-06-27 14:31:51,501 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin PostProcessingPlugin 2.2.1
2023-06-27 14:31:51,508 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin PrepareStage 1.0.1
2023-06-27 14:31:51,518 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin PreviewStage 1.0.1
2023-06-27 14:31:51,526 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin RemovableDriveOutputDevice 1.0.1
2023-06-27 14:31:51,552 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin SimulationView 1.0.1
2023-06-27 14:31:51,561 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin SliceInfoPlugin 1.0.1
2023-06-27 14:31:51,569 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin SolidView 1.0.1
2023-06-27 14:31:51,576 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin SupportEraser 1.0.1
2023-06-27 14:31:51,581 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin TrimeshReader 1.0.0
2023-06-27 14:31:51,592 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin UFPReader 1.0.0
2023-06-27 14:31:51,604 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin UFPWriter 1.0.1
/tmp/.mount_UltiMaoYKRN8/share/cura/plugins/UM3NetworkPrinting/src/ExportFileJob.py:31: DeprecationWarning: invalid escape sequence '\w'
  job_name = re.sub("[^\w\-. ()]", "-", job_name)
2023-06-27 14:31:51,728 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin UM3NetworkPrinting 2.0.0
/tmp/.mount_UltiMaoYKRN8/share/cura/plugins/USBPrinting/USBPrinterOutputDevice.py:280: DeprecationWarning: invalid escape sequence '\d'
  if re.search(b"[B|T\d*]: ?\d+\.?\d*", line):  # Temperature message. 'T:' for extruder and 'B:' for bed
2023-06-27 14:31:51,747 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin USBPrinting 1.0.2
2023-06-27 14:31:51,753 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin UltimakerMachineActions 1.0.1
2023-06-27 14:31:51,762 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade21to22 1.0.1
2023-06-27 14:31:51,767 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade22to24 1.0.1
2023-06-27 14:31:51,773 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade25to26 1.0.1
2023-06-27 14:31:51,777 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade26to27 1.0.1
2023-06-27 14:31:51,782 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade27to30 1.0.1
2023-06-27 14:31:51,788 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade30to31 1.0.1
2023-06-27 14:31:51,792 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade32to33 1.0.1
2023-06-27 14:31:51,797 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade33to34 1.0.1
2023-06-27 14:31:51,801 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade34to35 1.0.1
2023-06-27 14:31:51,806 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade35to40 1.0.0
2023-06-27 14:31:51,810 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade40to41 1.0.1
2023-06-27 14:31:51,814 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade411to412 1.0.0
2023-06-27 14:31:51,819 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade413to50 1.0.0
2023-06-27 14:31:51,824 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade41to42 1.0.0
2023-06-27 14:31:51,828 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade42to43 1.0.0
2023-06-27 14:31:51,833 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade43to44 1.0.0
2023-06-27 14:31:51,839 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade44to45 1.0.0
2023-06-27 14:31:51,843 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade45to46 1.0.0
2023-06-27 14:31:51,849 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade460to462 1.0.0
2023-06-27 14:31:51,854 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade462to47 1.0.0
2023-06-27 14:31:51,859 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade47to48 1.0.0
2023-06-27 14:31:51,863 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade48to49 1.0.0
2023-06-27 14:31:51,868 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade49to410 1.0.0
2023-06-27 14:31:51,874 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade52to53 1.0.0
2023-06-27 14:31:51,879 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin VersionUpgrade53to54 1.0.0
2023-06-27 14:31:51,889 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin X3DReader 1.0.1
2023-06-27 14:31:51,895 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin XRayView 1.0.1
2023-06-27 14:31:51,909 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin XmlMaterialProfile 1.0.1
2023-06-27 14:31:51,910 - DEBUG - [MainThread] UM.PluginRegistry.loadPlugins [416]: Loading all plugins took 1.1436610221862793 seconds
2023-06-27 14:31:51,914 - INFO - [MainThread] UM.VersionUpgradeManager.upgrade [163]: Looking for old configuration files to upgrade.
2023-06-27 14:31:51,918 - INFO - [MainThread] UM.VersionUpgradeManager.upgrade [177]: Checking and performing updates took 0.00553131103515625
2023-06-27 14:31:51,920 - INFO - [MainThread] UM.Qt.QtApplication.startSplashWindowPhase [256]: The preferences file cannot be opened or it is corrupted, so we will use default values
2023-06-27 14:31:51,920 - INFO - [MainThread] UM.Qt.QtApplication.startSplashWindowPhase [263]: The preferences file 'None' cannot be found, will use default values
2023-06-27 14:31:51,920 - INFO - [MainThread] UM.Qt.QtApplication.startSplashWindowPhase [266]: Completed loading preferences.
2023-06-27 14:31:51,942 - INFO - [MainThread] UM.Qt.QtApplication.startSplashWindowPhase [304]: Created system tray icon.
2023-06-27 14:31:53,354 - DEBUG - [MainThread] UM.Settings.ContainerRegistry.loadAllMetadata [548]: Loading metadata into container registry took 1.399137258529663 seconds
2023-06-27 14:31:53,370 - DEBUG - [MainThread] cura.Scene.CuraSceneController.setActiveBuildPlate [142]: Selected build plate: 0
2023-06-27 14:31:53,372 - DEBUG - [MainThread] cura.CuraApplication.run [832]: Using Conan managed dependencies: cura/5.4.0-beta.1, pyarcus/5.2.2, standardprojectsettings/0.1.0@ultimaker/stable, sipbuildtool/0.2.3@ultimaker/stable#5fe93e51cbb2a1cb25ee4358f844cbcd, protobuf/3.21.4, zlib/1.2.12, arcus/5.2.2, cpython/3.10.4, openssl/1.1.1l, expat/2.4.1, libffi/3.2.1, mpdecimal/2.5.0, libuuid/1.0.3, libxcrypt/4.4.25, bzip2/1.0.8, gdbm/1.19, sqlite3/3.36.0, tk/8.6.10, tcl/8.6.10, fontconfig/2.13.93, freetype/2.12.1, libpng/1.6.37, brotli/1.0.9, xorg/system, ncurses/6.2, xz_utils/5.2.5, curaengine/5.4.0-beta.1, clipper/6.4.2, boost/1.79.0, rapidjson/1.1.0, stb/20200203, spdlog/1.10.0, fmt/9.0.0, range-v3/0.12.0, scripta/0.1.0@ultimaker/testing, pysavitar/5.2.2, savitar/5.2.2, pugixml/1.12.1, pynest2d/5.2.2, nest2d/5.2.2, nlopt/2.7.0, uranium/5.4.0-beta.1, cura_binary_data/5.4.0-beta.1, fdm_materials/5.4.0-beta.1
2023-06-27 14:31:53,372 - INFO - [MainThread] cura.CuraApplication.run [837]: Initializing machine error checker
2023-06-27 14:31:53,373 - INFO - [MainThread] cura.CuraApplication.run [842]: Initializing machine manager
2023-06-27 14:31:53,374 - INFO - [MainThread] cura.CuraApplication.run [847]: Initializing container manager
2023-06-27 14:31:53,508 - DEBUG - [MainThread] cura.OAuth2.AuthorizationService.loadAuthDataFromPreferences [258]: Attempting to load the auth data from preferences.
2023-06-27 14:31:53,514 - WARNING - [MainThread] UM.OutputDevice.OutputDeviceManager.removeOutputDevice [235]: Could not find output device with id digital_factory to remove
2023-06-27 14:31:53,525 - DEBUG - [MainThread] UM.Scene.Camera._preferencesChanged [255]: Changing perspective mode to perspective.
2023-06-27 14:31:53,585 - DEBUG - [MainThread] UM.Qt.Bindings.Theme.load [188]: Loading theme file: /tmp/.mount_UltiMaoYKRN8/share/cura/resources/themes/cura-light/theme.json
2023-06-27 14:31:53,646 - DEBUG - [MainThread] UM.Qt.Bindings.Theme.load [323]: Loaded theme /tmp/.mount_UltiMaoYKRN8/share/cura/resources/themes/cura-light
2023-06-27 14:31:53,647 - INFO - [MainThread] UM.Qt.Bindings.Theme.load [324]: System's em size is 15px.
2023-06-27 14:31:54,299 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin._createView [350]: Creating post processing plugin view.
/tmp/.mount_UltiMaoYKRN8/share/cura/plugins/PostProcessingPlugin/Script.py:125: DeprecationWarning: invalid escape sequence '\.'
  m = re.search('^-?[0-9]+\.?[0-9]*', sub_part)
2023-06-27 14:31:54,318 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: ChangeAtZ
2023-06-27 14:31:54,321 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: ColorMix
2023-06-27 14:31:54,323 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: CreateThumbnail
2023-06-27 14:31:54,326 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: DisplayFilenameAndLayerOnLCD
2023-06-27 14:31:54,329 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: DisplayProgressOnLCD
2023-06-27 14:31:54,331 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: FilamentChange
2023-06-27 14:31:54,333 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: InsertAtLayerChange
2023-06-27 14:31:54,339 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: PauseAtHeight
2023-06-27 14:31:54,343 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: RetractContinue
2023-06-27 14:31:54,344 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: SearchAndReplace
2023-06-27 14:31:54,351 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: Stretch
2023-06-27 14:31:54,352 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: TimeLapse
2023-06-27 14:31:54,353 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin.loadScripts [212]: Begin loading of script: UsePreviousProbeMeasurements
2023-06-27 14:31:54,444 - DEBUG - [MainThread] PostProcessingPlugin.PostProcessingPlugin._createView [360]: Post processing view created.
2023-06-27 14:31:54,514 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/PyQt6/Qt6/qml/UM/MenuItem.qml:19:5: QML Shortcut: Shortcut: Only binding to one of multiple key bindings associated with 7. Use 'sequences: [ <key> ]' to bind to all of them.
2023-06-27 14:31:54,521 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Settings/SettingView.qml:40:9: QML TextField: Binding loop detected for property "implicitHeight"
2023-06-27 14:31:54,521 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Settings/SettingView.qml:40:9: QML TextField: Binding loop detected for property "implicitHeight"
2023-06-27 14:31:54,555 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/PyQt6/Qt6/qml/UM/MenuItem.qml:19:5: QML Shortcut: Shortcut: Only binding to one of multiple key bindings associated with 7. Use 'sequences: [ <key> ]' to bind to all of them.
2023-06-27 14:31:54,558 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/PyQt6/Qt6/qml/UM/MenuItem.qml:19:5: QML Shortcut: Shortcut: Only binding to one of multiple key bindings associated with 11. Use 'sequences: [ <key> ]' to bind to all of them.
2023-06-27 14:31:54,719 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/PrintSetupSelector/ProfileWarningReset.qml:77: TypeError: Cannot read property 'name' of null
2023-06-27 14:31:54,720 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/PrintSetupSelector/ProfileWarningReset.qml:77: TypeError: Cannot read property 'name' of null
2023-06-27 14:31:54,720 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingSlider.qml:36:9: Unable to assign [undefined] to QString
2023-06-27 14:31:54,720 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingComboBox.qml:69:9: Unable to assign [undefined] to QString
2023-06-27 14:31:54,720 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingTextField.qml:56:9: Unable to assign [undefined] to QString
2023-06-27 14:31:54,720 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingTextField.qml:56:9: Unable to assign [undefined] to QString
2023-06-27 14:31:54,720 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingComboBox.qml:69: TypeError: Cannot read property 'id' of null
2023-06-27 14:31:54,721 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingComboBox.qml:69: TypeError: Cannot read property 'id' of null
2023-06-27 14:31:54,721 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Cura.qml:631: TypeError: Cannot read property 'ExistingFile' of undefined
2023-06-27 14:31:54,729 - DEBUG - [MainThread] UM.Controller.setActiveStage [180]: Setting active stage to PrepareStage
2023-06-27 14:31:54,809 - DEBUG - [MainThread] cura.Machines.Models.NozzleModel._update [28]: Updating NozzleModel.
2023-06-27 14:31:54,811 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Menus/ConfigurationMenu/ConfigurationMenu.qml:278: TypeError: Cannot read property 'hasRemoteConnection' of null
2023-06-27 14:31:54,833 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Menus/ConfigurationMenu/CustomConfiguration.qml:188: TypeError: Cannot read property 'isEnabled' of null
2023-06-27 14:31:54,860 - DEBUG - [MainThread] UM.Controller.setActiveView [108]: Setting active view to SolidView
2023-06-27 14:31:54,880 - DEBUG - [MainThread] ModelChecker.ModelChecker._createView [118]: Creating model checker view.
2023-06-27 14:31:54,884 - DEBUG - [MainThread] ModelChecker.ModelChecker._createView [127]: Model checker view created.
2023-06-27 14:31:54,885 - DEBUG - [MainThread] SliceInfoPlugin.SliceInfo._createDialog [76]: Creating dialog [MoreInfoWindow.qml]
2023-06-27 14:31:54,942 - DEBUG - [MainThread] cura.CuraApplication.run [888]: Booting Cura took 4.765411138534546 seconds
2023-06-27 14:31:54,945 - DEBUG - [JobQueueWorker [0]] cura.Machines.ContainerTree.run [174]: Started background loading of MachineNodes
2023-06-27 14:31:54,945 - DEBUG - [JobQueueWorker [0]] cura.Machines.ContainerTree.run [185]: All MachineNode loading completed
2023-06-27 14:31:54,948 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:31:54,948 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [78]: No active GlobalStack, set quality profile model as empty.
2023-06-27 14:31:54,949 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:31:54,949 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [78]: No active GlobalStack, set quality profile model as empty.
2023-06-27 14:31:54,950 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:31:54,951 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [78]: No active GlobalStack, set quality profile model as empty.
2023-06-27 14:31:55,048 - DEBUG - [MainThread] cura.Machines.Models.CustomQualityProfilesDropDownMenuModel._update [33]: Updating CustomQualityProfilesDropDownMenuModel.
2023-06-27 14:31:55,049 - DEBUG - [MainThread] cura.Machines.Models.CustomQualityProfilesDropDownMenuModel._update [38]: No active GlobalStack, set CustomQualityProfilesDropDownMenuModel as empty.
2023-06-27 14:31:55,180 - DEBUG - [MainThread] UM.Qt.QtRenderer._initialize [211]: Support for Vertex Array Objects: True
2023-06-27 14:31:55,186 - DEBUG - [MainThread] UM.View.GL.OpenGL.__init__ [121]: Initialized OpenGL subsystems.
2023-06-27 14:31:55,186 - DEBUG - [MainThread] UM.View.GL.OpenGL.__init__ [122]: OpenGL Version:  4.6 (Core Profile) Mesa 23.0.4
2023-06-27 14:31:55,186 - DEBUG - [MainThread] UM.View.GL.OpenGL.__init__ [123]: OpenGL Vendor:   AMD
2023-06-27 14:31:55,187 - DEBUG - [MainThread] UM.View.GL.OpenGL.__init__ [124]: OpenGL Renderer: AMD Radeon Graphics (renoir, LLVM 15.0.7, DRM 3.49, 6.1.31-2-MANJARO)
2023-06-27 14:31:55,187 - DEBUG - [MainThread] UM.View.GL.OpenGL.__init__ [125]: GLSL Version:    4.60.0
2023-06-27 14:31:55,188 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/uranium/resources/shaders/default.shader]...
2023-06-27 14:31:55,191 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/uranium/resources/shaders/selection.shader]...
2023-06-27 14:31:55,193 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/uranium/resources/shaders/select_face.shader]...
2023-06-27 14:31:55,194 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/uranium/resources/shaders/default.shader]...
2023-06-27 14:31:55,195 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/uranium/resources/shaders/composite.shader]...
2023-06-27 14:31:55,196 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/overhang.shader]...
2023-06-27 14:31:55,198 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/striped.shader]...
2023-06-27 14:31:55,200 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/transparent_object.shader]...
2023-06-27 14:31:55,201 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/striped.shader]...
2023-06-27 14:31:55,203 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/xray.shader]...
2023-06-27 14:31:55,205 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/xray_composite.shader]...
2023-06-27 14:31:55,209 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/uranium/resources/shaders/platform.shader]...
2023-06-27 14:31:55,216 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/xray.shader]...
2023-06-27 14:31:59,633 - INFO - [MainThread] cura.CuraApplication.writeToLog [623]: User accepted the User-Agreement.
2023-06-27 14:32:02,400 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/WelcomePages/AddLocalPrinterScrollView.qml:248:25: Unable to assign QString to QRegularExpression
2023-06-27 14:32:09,684 - DEBUG - [MainThread] cura.AutoSave._onTimeout [64]: Autosaving preferences, instances and profiles took 0.034795522689819336 seconds
2023-06-27 14:32:16,383 - INFO - [MainThread] cura.Settings.MachineManager.addMachine [426]: Trying to add a machine with the definition id [creality_ender3]
2023-06-27 14:32:16,651 - WARNING - [MainThread] UM.Settings.SettingDefinition._deserialize_dict [653]: Unrecognised property comment in setting small_skin_width
2023-06-27 14:32:17,259 - DEBUG - [MainThread] cura.Machines.ContainerTree.__getitem__ [120]: Adding container tree for creality_ender3 took 0.4566164016723633 seconds.
2023-06-27 14:32:17,458 - WARNING - [MainThread] cura.Machines.VariantNode.preferredMaterial [99]: Could not find preferred material generic_pla, falling back to whatever works
2023-06-27 14:32:17,514 - INFO - [MainThread] cura.Settings.GlobalStack.addExtruder [190]: Extruder[creality_base_extruder_0 #2] added to [Creality Ender-3 / Ender-3 v2] at position [0]
2023-06-27 14:32:17,687 - WARNING - [MainThread] UM.Settings.SettingDefinition._deserialize_dict [653]: Unrecognised property comment in setting small_skin_width
2023-06-27 14:32:17,943 - INFO - [MainThread] cura.UI.MachineActionManager.addDefaultMachineActions [74]: Default machine actions added for machine definition [creality_ender3]
2023-06-27 14:32:17,950 - WARNING - [MainThread] cura.Settings.GlobalStack.addExtruder [185]: Extruder [creality_base_extruder_0 #2] has already been added to this stack [Creality Ender-3 / Ender-3 v2]
2023-06-27 14:32:17,951 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingTextField.qml:56:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,951 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingTextField.qml:56:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,951 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingComboBox.qml:69:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,951 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingSlider.qml:36:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,951 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:17,952 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [78]: No active GlobalStack, set quality profile model as empty.
2023-06-27 14:32:17,952 - INFO - [MainThread] cura.CuraApplication._setLoadingHint [824]: Initializing Active Machine...
2023-06-27 14:32:17,982 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingTextField.qml:56:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,982 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingTextField.qml:56:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,983 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingComboBox.qml:69:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,983 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Widgets/SingleSettingSlider.qml:36:9: Unable to assign [undefined] to QString
2023-06-27 14:32:17,983 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,058 - DEBUG - [MainThread] cura.Machines.Models.NozzleModel._update [28]: Updating NozzleModel.
2023-06-27 14:32:18,269 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Menus/SettingsMenu.qml:22:9: QML Menu: Binding loop detected for property "width"
2023-06-27 14:32:18,270 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,271 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,340 - WARNING - [MainThread] UM.Qt.QtApplication.__onQmlWarning [444]: file:///tmp/.mount_UltiMaoYKRN8/share/cura/resources/qml/Menus/ConfigurationMenu/CustomConfiguration.qml:188: TypeError: Cannot read property 'isEnabled' of null
2023-06-27 14:32:18,342 - DEBUG - [MainThread] cura.Machines.Models.NozzleModel._update [28]: Updating NozzleModel.
2023-06-27 14:32:18,350 - DEBUG - [MainThread] cura.Machines.Models.NozzleModel._update [28]: Updating NozzleModel.
2023-06-27 14:32:18,355 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,364 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,365 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
/tmp/.mount_UltiMaoYKRN8/share/cura/plugins/3MFReader/ThreeMFReader.py:126: DeprecationWarning: The binary mode of fromstring is deprecated, as it behaves surprisingly on unicode inputs. Use frombuffer instead
  data = numpy.fromstring(savitar_node.getMeshData().getFlatVerticesAsBytes(), dtype=numpy.float32)
2023-06-27 14:32:18,375 - DEBUG - [JobQueueWorker [1]] UM.Mesh.MeshData.calculateNormalsFromVertices [561]: Calculating normals took 0.0002963542938232422 seconds
2023-06-27 14:32:18,384 - DEBUG - [JobQueueWorker [1]] UM.Mesh.MeshData.approximateConvexHull [505]: approximateConvexHull(target_count=1024) Calculating 3D convex hull took 0.008204460144042969 seconds. 8 input vertices. 8 output vertices.
2023-06-27 14:32:18,482 - INFO - [MainThread] FirmwareUpdateChecker.FirmwareUpdateChecker.checkFirmwareVersion [79]: No machine with name Creality Ender-3 / Ender-3 v2 in list of firmware to check.
2023-06-27 14:32:18,592 - DEBUG - [MainThread] cura.Machines.Models.CustomQualityProfilesDropDownMenuModel._update [33]: Updating CustomQualityProfilesDropDownMenuModel.
2023-06-27 14:32:18,705 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/uranium/resources/shaders/default.shader]...
2023-06-27 14:32:18,706 - DEBUG - [MainThread] UM.View.GL.ShaderProgram.load [61]: Loading [/tmp/.mount_UltiMaoYKRN8/share/cura/resources/shaders/grid.shader]...
2023-06-27 14:32:18,741 - DEBUG - [MainThread] cura.TaskManagement.OnExitCallbackManager.addCallback [31]: on-app-exit callback [<bound method USBPrinterOutputDevice._checkActivePrintingUponAppExit of <USBPrinting.USBPrinterOutputDevice.USBPrinterOutputDevice object at 0x7fc2d41bf2e0>>] added.
2023-06-27 14:32:18,742 - DEBUG - [MainThread] cura.TaskManagement.OnExitCallbackManager.addCallback [31]: on-app-exit callback [<bound method USBPrinterOutputDevice._checkActivePrintingUponAppExit of <USBPrinting.USBPrinterOutputDevice.USBPrinterOutputDevice object at 0x7fc2ac39ee60>>] added.
2023-06-27 14:32:18,743 - DEBUG - [JobQueueWorker [2]] USBPrinting.AutoDetectBaudJob.run [24]: Auto detect baud rate started.
2023-06-27 14:32:18,743 - DEBUG - [JobQueueWorker [3]] USBPrinting.AutoDetectBaudJob.run [24]: Auto detect baud rate started.
2023-06-27 14:32:18,777 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,777 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,781 - DEBUG - [MainThread] cura.Machines.Models.IntentSelectionModel._update [73]: Updating IntentSelectionModel.
2023-06-27 14:32:18,957 - DEBUG - [MainThread] cura.Machines.Models.CustomQualityProfilesDropDownMenuModel._update [33]: Updating CustomQualityProfilesDropDownMenuModel.
2023-06-27 14:32:19,045 - DEBUG - [MainThread] cura.Machines.MachineErrorChecker._rescheduleCheck [164]: New error check scheduled.
2023-06-27 14:32:19,141 - INFO - [MainThread] cura.Machines.MachineErrorChecker._setResult [221]: Error check finished, result = False, time = 0.10s

@eloo
Copy link

eloo commented Jul 9, 2023

@MariMakes any updates here?

@nallath
Copy link
Member

nallath commented Jul 14, 2023

My best guess is that it is related to the USB printing plugin, since it only seems to trigger for machines that have the "supports_usb_connection" as far as I can tell.

To validate my suspicion, can people check if adding an Ultimaker 3, s3 or s5 also cause the issue? Since I don't have the issue myself, i can't check it myself :(

@eloo
Copy link

eloo commented Jul 14, 2023

@nallath you're the best!

it really looks like this is the issue!

i have added

        "supports_usb_connection": false

to my printers profile creality_ender3pro.def.json and now its working

so please guys... fix the usb printing plugin or at least give an option to disable the broken plugin!

@nallath
Copy link
Member

nallath commented Jul 14, 2023

@nallath you're the best!

it really looks like this is the issue!

i have added

        "supports_usb_connection": false

to my printers profile creality_ender3pro.def.json and now its working

so please guys... fix the usb printing plugin or at least give an option to disable the broken plugin!

Well, you can disable it in the marketplace. The problem is that I can't reproduce it (but I'm on Ubuntu, so maybe that's it?), which makes it very hard to figure out what is going on and how to fix it.

I've created a PR with some extra logging, i hope that will provide the info we need to fix it.

@jellespijker
Copy link
Member

The PR with the extra debugging statements are merged to main and I started a build for Linux such that you guys can run with this version. Sharing these logs would help @nallath out with figuring out what goes wrong.

You can download these artifacts here: https://github.com/Ultimaker/Cura/actions/runs/5552874115

@eloo
Copy link

eloo commented Jul 14, 2023

@jellespijker @nallath
here are some looks for usb

/tmp/.mount_UltiMapR0cxP/share/cura/plugins/USBPrinting/USBPrinterOutputDevice.py:280: DeprecationWarning: invalid escape sequence '\d'
2023-07-14 13:58:47,502 - INFO - [MainThread] UM.PluginRegistry.loadPlugin [493]: Loaded plugin USBPrinting 1.0.2
2023-07-14 13:58:52,825 - DEBUG - [MainThread] cura.TaskManagement.OnExitCallbackManager.addCallback [31]: on-app-exit callback [<bound method USBPrinterOutputDevice._checkActivePrintingUponAppExit of <USBPrinting.USBPrinterOutputDevice.USBPrinterOutputDevice object at 0x7f9326430700>>] added.
2023-07-14 13:58:52,827 - DEBUG - [MainThread] cura.TaskManagement.OnExitCallbackManager.addCallback [31]: on-app-exit callback [<bound method USBPrinterOutputDevice._checkActivePrintingUponAppExit of <USBPrinting.USBPrinterOutputDevice.USBPrinterOutputDevice object at 0x7f932674beb0>>] added.
2023-07-14 13:58:52,828 - DEBUG - [JobQueueWorker [1]] USBPrinting.AutoDetectBaudJob.run [24]: Auto detect baud rate started for /dev/ttyS5
2023-07-14 13:58:52,831 - DEBUG - [JobQueueWorker [2]] USBPrinting.AutoDetectBaudJob.run [24]: Auto detect baud rate started for /dev/ttyS4

and the screen is stuck at "initialize engine..."

@eloo
Copy link

eloo commented Jul 14, 2023

but so far

workaround: Disable "USB Printing" in marketplace

@nallath
Copy link
Member

nallath commented Jul 14, 2023

Can you run
sudo dmesg | grep ttyS

And share the output?

@eloo
Copy link

eloo commented Jul 14, 2023

[    0.441936] 0000:02:00.1: ttyS4 at I/O 0x3200 (irq = 33, base_baud = 115200) is a 16550A
[    0.442202] 0000:02:00.2: ttyS5 at I/O 0x3100 (irq = 34, base_baud = 115200) is a 16550A

FYI: i don't have my printer connected using USB... i use octoprint, so the printer was and will never be connected using usb

@nallath
Copy link
Member

nallath commented Jul 14, 2023

Yeah, i figured. But I'm trying to figure out why the auto detect is hanging itself up on some machines and not others.

@eloo
Copy link

eloo commented Jul 14, 2023

@nallath maybe it would be enough to set a timeout for the autodetect to just a few seconds

@piontec
Copy link

piontec commented Jul 14, 2023

I can confirm that adding ultimaker 3 worked without issues, only adding my networked ender 3 with octorpint seems to be an issue

@nallath
Copy link
Member

nallath commented Jul 17, 2023

@nallath maybe it would be enough to set a timeout for the autodetect to just a few seconds

It already has a timeout. The auto-detect also happens in a separate thread, so it shouldn't block the application itself. I'm at a bit of a loss what is exactly causing it to hang...

@nallath
Copy link
Member

nallath commented Jul 25, 2023

So, one more thing that people might be able to try. It does require changing a part of the code.

Can people check if removing these lines

        try:
            programmer.connect(self._serial_port)
            serial = programmer.leaveISP()
        except ispBase.IspError:
            programmer.close()

make the problem go away.

@MarcoCLA
Copy link

Yes it does work when commented.
cura.broken.log
cura.commented.log

@MarcoCLA
Copy link

MarcoCLA commented Aug 16, 2023

I narrowed it down to the flush statement here:

self.serial.flush()

If the flush is removed, cura does not hang.

cura.working.log
cura.broken.log

Maybe related?
python/cpython#99680
wjwwood/serial#184

@wawanbreton
Copy link
Contributor

Hi @MarcoCLA,
I tried to confirm your statement, but couldn't reproduce the bug either :(
My guess is that something on your system is messing with Cura trying to handle the usb port, either a service (like ModemManager) or a USB device (either external or internal) which would partially respond to our auto-detection calls.

Would you mind sharing the output of the following commands :
lsusb
lsmod
ps aux
ls -lh /sys/class/tty/*

For the record, we have added a ticket to the backlog with the intent to improve this.
For internal reference - CURA-10972
Thanks for the report! 👍

@MarcoCLA
Copy link

MarcoCLA commented Sep 1, 2023

Two devices cause it to hang on my system.

marco@MC-ThinkPad ~ % ls -lh /sys/class/tty/* | grep -E 'ttyS5|ttyS4'
lrwxrwxrwx 1 root root 0 Sep 1 07:54 /sys/class/tty/ttyS4 -> ../../devices/pci0000:00/0000:00:01.4/0000:03:00.1/tty/ttyS4/
lrwxrwxrwx 1 root root 0 Sep 1 07:54 /sys/class/tty/ttyS5 -> ../../devices/pci0000:00/0000:00:01.4/0000:03:00.2/tty/ttyS5/

marco@MC-ThinkPad ~ % lspci | grep -E '03:00.1|03:00.2'
03:00.1 Serial controller: Realtek Semiconductor Co., Ltd. RTL8111xP UART #1 (rev 0e)
03:00.2 Serial controller: Realtek Semiconductor Co., Ltd. RTL8111xP UART #2 (rev 0e)

Looks like some IPMI interface.

@wawanbreton
Copy link
Contributor

Hi @MarcoCLA,

Thanks for the report ! You do have some serial devices on your system, which may be linked to your problem, depending on how they react to what Cura is doing at startup.

I still have to find the best way to fix this without breaking the USB printing support. In the meantime, can you try starting cura with the following environment variable :

CURA_DEVICENAMES="$^" ./UltiMaker-Cura-5.4.0-linux.AppImage

That should completely stop opening the USB ports, and hopefully allow you to use Cura normally.

@wawanbreton
Copy link
Contributor

Well, from what I can tell, @MarcoCLA your theory really seems to make sense. The method Serial.flush calls tcdrainwhich can indeed block forever, and as it is a system call, it can block the whole Python interpreter.

Now there are many possibles ways for us to fix this. I'll discuss them with the team to find the most appropriate one.

@wawanbreton
Copy link
Contributor

Hey @MarcoCLA, could you please test this AppImage ? It should fix your issue without breaking USB support.

If you can't start it with your distribution, just tell me and I'll make a new one with different options.

@wawanbreton
Copy link
Contributor

Sorry, the link won't work for you.. You can download the file here

@MarcoCLA
Copy link

Do you also happen to have a patch file for me? Then I can apply it locally.

@wawanbreton
Copy link
Contributor

Oh sure, you may want to apply it manually, it is just somes lines of code removed : 8f4dec2

@MarcoCLA
Copy link

MarcoCLA commented Oct 7, 2023

This patch solves this issue.

@wawanbreton
Copy link
Contributor

Great, thanks for the feedback ! It will be included in the next Cura release.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Status: Under Investigation The issue has been confirmed or is assumed to be likely to be a real issue. It's pending discussion. Type: Bug The code does not produce the intended behavior.
Projects
None yet
Development

No branches or pull requests

9 participants