Cura: After print I can't send another job unless I restart Cura.

[partsoven]

If I print a job successfully (Ultimaker 3 Extended) and remove it from the build, then I click through the menu on the printer to make sure its ready to go again. However in Cura 2.3.0 it says:

"Unable to start a new print job because the printer is busy. Please check the printer."

If I close Cura and reopen it and reload my files I can then print. Wish I didn't have to close Cura and reopen every time I want to send a job to the printer.

[thopiekar]

@partsoven Thank you for your report and sorry for the inconvenience.

[thopiekar]

Now tracked on JIRA..

[nallath]

Could you add your logs? Without them we can't help you (It seems to work just fine on my setup)

[partsoven]

curalog.txt

[partsoven]

This help?

[sedwards2009]

@partsoven I saw something in the log which suggested that you are using an old beta version of Cura or maybe you did use one and then later upgraded it. Is that possible?

I saw this:

2016-11-05 10:23:04,677 - DEBUG - D:\2.3\build\inst\lib\python3.4\site-packages\UM\Backend\Backend.py (_backendLog [88]): [Backend] [WARNING] Couldn't load extruder.def.json file for extruder 1. Index out of bounds.

The reference to extruder.def.json looks like the name for an old file which we renamed during development.

[Ghostkeeper]

Actually, that file name is hardcoded in the warning message in the engine. We also get that error message at every slice in normal operation.

[partsoven]

Yep. Much of the log is stuff that is preloaded.

[nallath]

Could you check if this is still the case in cura 2.3.1? I can't find anything in the log to indicate a reason why this is happening.

[partsoven]

Will do as soon as my UM3 is back up and running. The head shroud filled with material and is all jammed up.

[partsoven]

Got my UM3 working (kinda)... but still having this issue with the 2.3.1 version

[fieldOfView]

Just to get something obvious out of the way: do you confirm on the UM3 display that you have cleared the buildplate after printing?

[partsoven]

Yes.

[fieldOfView]

I don't have a UM3, so I cannot test or reproduce your issues.

In your logs I see a number of unexpected disconnects and bonjour service interruptions. Directly after uploading the gcode the printer seems to actively say goodbye, which is weird. I hope someone at UM can figure out what is going on.

Wifi or wired? Anything special about your network?

[partsoven]

thanks. Wired network. Nothing special about my network.

[fieldOfView]

What happens if after printing you reset the UM3? Does it "return" in Cura? I'm not suggesting this would be a solution, but at least we would know if Cura is still responsive to network events.

Another thing to try is adding another printer to Cura (without connecting it to your UM3), and switching to that and back. This forces a reconnection if Cura can find the printer.

[partsoven]

If I reboot the machine it returns in Cura yes. Switching machines does not.

[partsoven]

Deleted the printer and re-added it and reauthorized with Cura 2.3.1 and it seems to be working now...

[partsoven]

Nevermind this bug is back again...

[thopiekar]

I'm sorry to hear about this :disappointed:

Which firmware version are you using, @partsoven ?
Our testers tried to reproduce it approx one week ago and they couldn't reproduce it. So any hint or further info about your setup would be useful , so we could find the reason for this behavior.

Thanks!

[partsoven]

Cura 2.3.1
Latest stable firmware. I'm printing now but I will followup after the print completes. Thanks for looking into this.

[thopiekar]

Thanks!

[partsoven]

Firmware on printer says:
3.4.16.20161104

[partsoven]

Noticed I'm not the only one who is having this issue. I haven't connected my printer to Wifi and only hardwired it. Could this be causing the issue. I will try after my print finishes to see if Wifi connection cures this.

[partsoven]

I just realized I hardwired the machine but had not selected "Wired connection" on the UM3. So this may only effect wireless connectivity. Once I did this I am now able (so far) to start another job. I will update again on Monday if this bug persists.

[Ghostkeeper]

Did this bug persist on the wired connection?

[SunnyJames]

As far as I can tell this bug still exists in the newest version of Cura v2.5.0. It doesn't matter for me if it is wired or wireless and I generally cannot predict whether or not Cura will let me print after clearing the print bed. Switching printers and then switching back clears it up. Restarting Cura also clears it.

I'm running Mac OS Sierra 10.12.4

[MFHFozzy]

Im having this bug. Every. Single. Print.
Wired connections. Cura 2.6.2.
Windows 10 x64.
Looking at the logs, i see this:
2017-08-01 14:14:17,575 - DEBUG - CuraEngineBackend.CuraEngineBackend._onSlicingFinishedMessage [474]: Slicing took 1.7409298419952393 seconds
2017-08-01 14:14:17,577 - DEBUG - UM.Backend.Backend._logSocketState [176]: Socket state changed to Closing
2017-08-01 14:14:17,578 - DEBUG - UM.Backend.Backend._onSocketError [198]: Socket debug: Arcus Error (13): Closing socket because other side requested close.
2017-08-01 14:14:17,579 - DEBUG - UM.Backend.Backend._logSocketState [178]: Socket state changed to Closed
2017-08-01 14:14:17,589 - DEBUG - CuraEngineBackend.CuraEngineBackend._onBackendQuit [585]: Backend quit with return code 0. Resetting process and socket.

[tylerecouture]

I'm using Cura 2.6.2 AppImage on Mint 17.3 with a U3 Extended printing over Wifi. After a print is done I click the button on the U3 to confirm print removal, then when I try to "print over network" again I get this: "Unable to start a new print job, printer is busy. Current printer status is printing". Printer display is on the "Print/Material.../System" menu.

I have to restart Cura to be able to print again. Not sure where the log file is to show.

[Ghostkeeper]

I don't think there would be anything in the log, but nevertheless you can find the log with these instructions: https://github.com/Ultimaker/Cura#logging-issues

So far this issue doesn't reproduce here. I'm afraid that for an issue like this we really have to be able to reproduce it locally in order to begin debugging the problem.

[MFHFozzy]

Are the socket errors that i posted not related?

[MFHFozzy]

Ive just finished a print, and again, cannot start another one. I have not shut Cura down yet, but will be installing a beta version in a sec to see if this goes away and to test if the disappearing custom materials goes away.

So heres a full bug report for the network issue on 2.6 release as of 2017-08-15
Log file, CFG file and DX Diag attached.
2017-08015-DxDiag.txt
cura.cfg.txt
cura.zip

Application Version: 2.6

Platform: Win10 X64 Pro
Qt: QT5 from help about. No clue how to get more detailed on this for windows.
PyQt: No idea.
Display Driver: Nvidia game ready driver 384.76

Steps to Reproduce:
Connect to printer over wired Ethernet (Gigabit). Load STL file, slice, print. Do not abort.
Prints im using take ~1hour.

Actual Results:
Print finished successfully. Remove print from tray. Press button on front of Ultimaker3.
Load new STL file. Slice. Attempt to print over network. Get error that printer is busy printing.
Check that printer is NOT busy.

Expected results:
Printer should print.

Additional Information:
Restart Cura and you can print again.

[MFHFozzy]

Just successfully printed a 2nd print with beta 2.7 without having to close/re-open.
Also noticed that 2.7 actually had a notice for me to remove the print from the bed when it was done, and when i pushed the button the printer, the notice went away.

So is seems there was/is a bug in 2.6 and its related to recognizing that the "print has been removed" button the ultimaker is pressed.

[MFHFozzy]

False hope. Problem went away for exactly 1 print. Its back now, on every print.

[partsoven]

Same here. This problem is such a pain.

[nallath]

In the beta it should say "Unable to start a new print job, printer is busy. Current printer status is [STATUS]"
What is the status that it gives you?

[Ghostkeeper]

Are the socket errors that i posted not related?

No, those are about the connection to CuraEngine, not to the printer.

I'm fearing that this bug only occurs on certain LANs, which could be why it's not reproducing for us at work. Ultimaker's LAN is a bit... unconventional.

[MFHFozzy]

Im pretty knowledgeable in networks, can i offer some assistance?
Or is there some extra logging i can enable for you?

[nallath]

As far as logging goes; All logging that we have is enabled by default. But like i said, the message if this happens should give me some more info.

[MFHFozzy]

Ill get you the exact message next time it happens.

[MFHFozzy]

Ill get you the exact message next time it happens. Currently Cura is using soo much memory, Windows is killing it before the print is finished.

[MFHFozzy]

Now on 2.7 release.
Issue text has changed. It is now:
"No access to print with this printer.
Unable to send print job."

Note, that going to printer management and requesting access (again) does not actually request access at the printer.

Logs attached
cura.zip

[nallath]

I've fixed the memory leak for the next release. So there is that.

I really can't explain why the authentication is going wrong. The logging indicates that the authentication succeeded, that the internal state is correctly set to authenticated, but the first moment you actually try to send a print, it tells you it's not authenticated :S

[MFHFozzy]

Looking forward to it too :)

[mfrank28]

I've been having the same problem for several releases. I have a hardwired connection & one UM3. The workaround for me was to re-select the UM3 in the printer drop-down menu. Cura would take a few seconds to seemingly reconnect, then I would re-slice and be able to print. With Cura 2.7 & the latest firmware, that workaround no longer works. A fix would be great. It's inconvenient to have to restart Cura after every print. Definitely not the the user experience I'd expect from a polished UM3 / Cura combo.

[partsoven]

Yeah still having the same issue. I confirm with latest release it is worse. I now can't just select another printer and reselect I also have to either restart cura or restart the printer. Please help this problem is very bad and makes the ultimaker not a worthwhile investment in a production environment.

[bckline]

I just got an Ultimaker3 and after successfully printing a single item via hardwired network connection I am unable to print anything else. I receive the error "No access to print with this printer. Unable to send print job." every time I press "Print over network". I have restarted Cura and the printer itself multiple times to no avail. I definitely cannot (will not) rely solely on USB, so this issue may be a dealbreaker.

[partsoven]

I agree bckline. Luckily for me I have several other printers which use Octoprint via Raspberry Pi's that live on the network and are able to print flawlessly. This bug is extremely frustrating especially since the problem is even worse now.

[SunnyJames]

Agree with others. This problem has been outstanding for well over a year and counting. The current release made things significantly worse.

[nallath]

The issue here is that I'm unable to reproduce this on my system. This might seem like a weak defence, but i need to have the problem in order to fix it (or well, it makes it a whole lot easier!).
Did you guys have the problem with 2.7? If this happens, could you please provide log files (please delete the log files before hand, so it's not cluttered with a gazillion entries)?
I totally agree that this is a major issue. So if you guys can help me, i can return the favour.

[fieldOfView]

[nallath]

I've added a ton of extra logging for the next release in hopes that it might shed some light onto the issue.

[partsoven]

Thank you nallath. I will do whatever you need. Can you break down a step by step of what you want me to do?
I am on Windows 10.

[partsoven]

Cleared my Cura log and printing some jobs now to recreate. Thanks again nallath.

[nallath]

When you have the Cura 3.0; delete your log files, use cura as you would normally. If it breaks, send me the log file.

[partsoven]

cura.txt.log

Ok here is my log. I cleared it, ran a job, clicked "Print Removed" on the printer, and tried to run another job and this is what the log says.

[nallath]

@partsoven; Next time this happens, could you then also look at http://192.168.1.28/api/v1/printer and http://192.168.1.28/api/v1/print_job and share the results with me?

[fieldOfView]

Why does NetworkPrinterOutputDevice use self._printer_state instead of self._job_state? self._printer_state is only ever used by NetworkPrinterOutputDevice, and self._job_state seems to have the correct information judging from the screenshot (whereas self._printer_state apparently has the tendency to fluke out). In the screenshot we see both the save button and the monitor button in the topbar having the right info, and that is based on self._job_state.

Note that when switching to self._job_state, check for "ready" instead of "idle".

[partsoven]

http://192.168.1.28/api/v1/printer:

{"bed": {"pre_heat": {"active": false}, "temperature": {"current": 22.8, "target": 0.0}}, "beep": {}, "diagnostics": {}, "heads": [{"acceleration": 3000.0, "extruders": [{"active_material": {"GUID": "e256615d-a04e-4f53-b311-114b90560af9", "guid": "e256615d-a04e-4f53-b311-114b90560af9", "length_remaining": -1.0}, "feeder": {"acceleration": 3000.0, "jerk": 5.0, "max_speed": 45.0}, "hotend": {"id": "AA 0.4", "offset": {"state": "valid", "x": 0.0, "y": 0.0, "z": 0.0}, "serial": "422a7d130000", "statistics": {"last_material_guid": "e256615d-a04e-4f53-b311-114b90560af9", "material_extruded": 1236940, "max_temperature_exposed": 261, "time_spent_hot": 9273360}, "temperature": {"current": 27.7, "target": 0.0}}}, {"active_material": {"GUID": "86a89ceb-4159-47f6-ab97-e9953803d70f", "guid": "86a89ceb-4159-47f6-ab97-e9953803d70f", "length_remaining": -1.0}, "feeder": {"acceleration": 3000.0, "jerk": 5.0, "max_speed": 45.0}, "hotend": {"id": "BB 0.4", "offset": {"state": "valid", "x": 0.0, "y": 0.0, "z": 1.6300000000000003}, "serial": "035473140000", "statistics": {"last_material_guid": "86a89ceb-4159-47f6-ab97-e9953803d70f", "material_extruded": 232870, "max_temperature_exposed": 232, "time_spent_hot": 6629280}, "temperature": {"current": 27.6, "target": 0.0}}}], "fan": 0.0, "jerk": {"x": 20.0, "y": 20.0, "z": 0.4}, "max_speed": {"x": 300.0, "y": 300.0, "z": 40.0}, "position": {"x": 0.0, "y": 0.0, "z": 0.0}}], "led": {"blink": {}, "brightness": 100.0, "hue": 0.0, "saturation": 0.0}, "network": {"ethernet": {"connected": true, "enabled": true}, "wifi": {"connected": false, "enabled": false, "ssid": "UM-NO-HOTSPOT-NAME-SET"}, "wifi_networks": []}, "status": "printing"}

http://192.168.1.28/api/v1/print_job:

{"datetime_cleaned": "", "datetime_finished": "2017-09-28T02:47:45", "datetime_started": "2017-09-28T00:08:41", "name": "Visor_Socket_Rev_Y_Left", "progress": 1.0, "result": "", "source": "WEB_API", "source_application": "Cura-2.7.0", "source_user": "Chris", "state": "wait_cleanup", "time_elapsed": 9249, "time_total": 9248, "uuid": "a8b09266-d047-49e0-83e9-ea0c777d7625"}

[nallath]

Is this after you pressed the "print removed"? It seems like that the printer didn't register this.

[partsoven]

Now after pressing print removed and trying to send another job:

http://192.168.1.28/api/v1/print_job:

{"message": "Not found"}

http://192.168.1.28/api/v1/printer:

{"bed": {"pre_heat": {"active": false}, "temperature": {"current": 22.9, "target": 0.0}}, "beep": {}, "diagnostics": {}, "heads": [{"acceleration": 3000.0, "extruders": [{"active_material": {"GUID": "e256615d-a04e-4f53-b311-114b90560af9", "guid": "e256615d-a04e-4f53-b311-114b90560af9", "length_remaining": -1.0}, "feeder": {"acceleration": 3000.0, "jerk": 5.0, "max_speed": 45.0}, "hotend": {"id": "AA 0.4", "offset": {"state": "valid", "x": 0.0, "y": 0.0, "z": 0.0}, "serial": "422a7d130000", "statistics": {"last_material_guid": "e256615d-a04e-4f53-b311-114b90560af9", "material_extruded": 1236940, "max_temperature_exposed": 261, "time_spent_hot": 9273360}, "temperature": {"current": 27.7, "target": 0.0}}}, {"active_material": {"GUID": "86a89ceb-4159-47f6-ab97-e9953803d70f", "guid": "86a89ceb-4159-47f6-ab97-e9953803d70f", "length_remaining": -1.0}, "feeder": {"acceleration": 3000.0, "jerk": 5.0, "max_speed": 45.0}, "hotend": {"id": "BB 0.4", "offset": {"state": "valid", "x": 0.0, "y": 0.0, "z": 1.6300000000000003}, "serial": "035473140000", "statistics": {"last_material_guid": "86a89ceb-4159-47f6-ab97-e9953803d70f", "material_extruded": 232870, "max_temperature_exposed": 232, "time_spent_hot": 6629280}, "temperature": {"current": 27.6, "target": 0.0}}}], "fan": 0.0, "jerk": {"x": 20.0, "y": 20.0, "z": 0.4}, "max_speed": {"x": 300.0, "y": 300.0, "z": 40.0}, "position": {"x": 0.0, "y": 0.0, "z": 0.0}}], "led": {"blink": {}, "brightness": 100.0, "hue": 0.0, "saturation": 0.0}, "network": {"ethernet": {"connected": true, "enabled": true}, "wifi": {"connected": false, "enabled": false, "ssid": "UM-NO-HOTSPOT-NAME-SET"}, "wifi_networks": []}, "status": "idle"}

[fieldOfView]

Could you try hacking a file?
C:\Program Files\Cura 2.7\plugins\UM3NetworkPrinting\NetworkPrinterOutputDevice.py, line 628
https://github.com/Ultimaker/Cura/blob/2.7/plugins/UM3NetworkPrinting/NetworkPrinterOutputDevice.py#L628

Change
if self._printer_state not in ["idle", ""]:
to
if self._job_state not in ["ready", ""]:

Take care that you do not change the indentation. I would be quite surprised if that does not fix the issue.

[partsoven]

No problem, I hacked the file while Cura I will reboot Cura and try and run a few jobs now to see if it is fixed. Thanks for your attention on this.

[partsoven]

That didn't work. Now after a job is complete and I go to print again I get the "No access to print with this printer. Unable to send print job."

http://192.168.1.28/api/v1/printer:
{"bed": {"pre_heat": {"active": false}, "temperature": {"current": 48.1, "target": 0.0}}, "beep": {}, "diagnostics": {}, "heads": [{"acceleration": 3000.0, "extruders": [{"active_material": {"GUID": "e256615d-a04e-4f53-b311-114b90560af9", "guid": "e256615d-a04e-4f53-b311-114b90560af9", "length_remaining": -1.0}, "feeder": {"acceleration": 3000.0, "jerk": 5.0, "max_speed": 45.0}, "hotend": {"id": "AA 0.4", "offset": {"state": "valid", "x": 0.0, "y": 0.0, "z": 0.0}, "serial": "422a7d130000", "statistics": {"last_material_guid": "e256615d-a04e-4f53-b311-114b90560af9", "material_extruded": 1239220, "max_temperature_exposed": 261, "time_spent_hot": 9282960}, "temperature": {"current": 55.9, "target": 0.0}}}, {"active_material": {"GUID": "86a89ceb-4159-47f6-ab97-e9953803d70f", "guid": "86a89ceb-4159-47f6-ab97-e9953803d70f", "length_remaining": -1.0}, "feeder": {"acceleration": 3000.0, "jerk": 5.0, "max_speed": 45.0}, "hotend": {"id": "BB 0.4", "offset": {"state": "valid", "x": 0.0, "y": 0.0, "z": 1.6300000000000003}, "serial": "035473140000", "statistics": {"last_material_guid": "86a89ceb-4159-47f6-ab97-e9953803d70f", "material_extruded": 232870, "max_temperature_exposed": 232, "time_spent_hot": 6629280}, "temperature": {"current": 38.9, "target": 0.0}}}], "fan": 0.0, "jerk": {"x": 20.0, "y": 20.0, "z": 0.4}, "max_speed": {"x": 300.0, "y": 300.0, "z": 40.0}, "position": {"x": 0.0, "y": 0.0, "z": 0.0}}], "led": {"blink": {}, "brightness": 100.0, "hue": 0.0, "saturation": 0.0}, "network": {"ethernet": {"connected": true, "enabled": true}, "wifi": {"connected": false, "enabled": false, "ssid": "UM-NO-HOTSPOT-NAME-SET"}, "wifi_networks": []}, "status": "idle"}

http://192.168.1.28/api/v1/print_job
{"message": "Not found"}

[fieldOfView]

Interesting. Got logs for that?

[partsoven]

cura.log

[nallath]

It seems like the local json in Cura was never updated. I'll poke around a bit to see how that can happen.

edit
Could you replace the line:
self._updatePrinterState(self._json_printer_state["status"])
with

Logger.log("d", "printer state is %s", self._json_printer_state["status"])
self._updatePrinterState(self._json_printer_state["status"])

That should help a bit figuring out what's going on.

[partsoven]

Now I can't connect even after a machine and Cura restart.

[nallath]

okay, could you share the logs?

[partsoven]

After I made that change I click Cura to open and it won't open at all now. I changed the python back to what it was and it still won't open. Yikes!!! Now I am dead in the water with Cura 2.7. I am deleting all traces of Cura and reinstalling now to see if I can get it to open.

[partsoven]

Got it to reopen after completely wiping all traces of Cura from my system including the Roaming and Local AppData folders. I will run a few tests to see if this resolves my issue too.

[partsoven]

No dice
cura.log

[partsoven]

[nallath]

I fear you will have to wait until the next version. That will have a number of extra debug statements that I need.

[partsoven]

Yikes. How far out is that?

[fieldOfView]

oktober 17th

[MFHFozzy]

Finally more to add. Just updated to 3.0, and printed overnight. Cura did not crash/use all available memory, so i finally got the network error again. The exact message is:
"Unable to start a new print job, printer is busy.
Current printer status is printing." Pic attached.

Log attached
cura - Copy.zip

[SunnyJames]

Problem still occurs with 3.0.4. I had a good run of several prints without issues, but woke this morning to the issue occurring on new prints unless Cura is restarted. I am currently trying the change suggested by @nallath

cura.log

[Ghostkeeper]

This seems to be a new iteration with the same symptoms.

2017-11-05 08:02:41,863 - DEBUG - UM3NetworkPrinting.NetworkPrinterOutputDevicePlugin._onNetworkRequestFinished [169]: This url is not from a cluster printer: [PyQt5.QtCore.QUrl('http://10.0.1.230/cluster-api/v1/printers/?origin=check_cluster')]

@nallath Is it trying to use a call to cluster API with a printer whose firmware doesn't support cluster yet?

[nallath]

It's calling the cluster api to figure out if it's a cluster printer. In this case it noticed that it isn't

[Ghostkeeper]

I'm thinking this is more of a bug in the Ultimaker 3 firmware, but the Ultimaker 3 firmware isn't open source so I'm hoping that some of those developers are still reading this...

[nallath]

If it's an issue with the networking plugin it might be fixed for 3.2 as I'm re-writing that now.

[ChrisTerBeke]

Not having any issues anymore in 3.1. Also not in the network rewrite (scheduled for 3.3).