PrusSlicer never finishes upload with PI4

PetrKroupa

Run comand and start upload.

pi@malej:~ $ journalctl -u duetwebserver -f
-- Logs begin at Tue 2022-02-15 05:47:02 CET. --
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.DeleteFileOrDirectory (DuetWebServer) in 29.9095ms
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.DeleteFileOrDirectory (DuetWebServer)'
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 DELETE http://192.168.1.50/machine/file/0:%2Fgcodes%2Ffixa_cidlo_0.2mm_PETG_malej_12h39m.gcode application/json - - 204 - - 32.2082ms
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 GET http://192.168.1.50/machine/directory/0:%2Fgcodes%2F application/json -
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[0] Executing endpoint 'DuetWebServer.Controllers.MachineController.GetFileList (DuetWebServer)'
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3] Route matched with {action = "GetFileList", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] GetFileList(System.String) on controller DuetWebServer.Controllers.MachineController (DuetWebServer).
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ContentResultExecutor[1] Executing ContentResult with HTTP Response ContentType of application/json
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.GetFileList (DuetWebServer) in 20.9218ms
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.GetFileList (DuetWebServer)'
Feb 16 16:53:30 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 GET http://192.168.1.50/machine/directory/0:%2Fgcodes%2F application/json - - 200 705 application/json 22.9608ms
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 GET http://192.168.1.50/rr_connect?password=reprap&time=2022-02-16T16:53:06 - -
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 GET http://192.168.1.50/rr_connect?password=reprap&time=2022-02-16T16:53:06 - - - 404 0 - 15.1087ms
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 GET http://192.168.1.50/machine/status - -
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[0] Executing endpoint 'DuetWebServer.Controllers.MachineController.Status (DuetWebServer)'
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3] Route matched with {action = "Status", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] Status() on controller DuetWebServer.Controllers.MachineController (DuetWebServer).
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ContentResultExecutor[1] Executing ContentResult with HTTP Response ContentType of application/json
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.Status (DuetWebServer) in 73.3141ms
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.Status (DuetWebServer)'
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 GET http://192.168.1.50/machine/status - - - 200 14110 application/json 90.5221ms
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 PUT http://192.168.1.50/machine/file/gcodes/fixa_cidlo_0.2mm_PETG_malej_12h39m.gcode - 13348749
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[0] Executing endpoint 'DuetWebServer.Controllers.MachineController.UploadFile (DuetWebServer)'
Feb 16 16:53:41 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3] Route matched with {action = "UploadFile", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] UploadFile(System.String, DuetWebServer.Singletons.ISessionStorage) on controller DuetWebServer.Controllers.MachineController (DuetWebServer).

and wait forewer.

after stop in prusa slicer:

journalctl -u duetwebserver -f
-- Logs begin at Tue 2022-02-15 05:47:02 CET. --
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.DeleteFileOrDirectory (DuetWebServer) in 40.363ms
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.DeleteFileOrDirectory (DuetWebServer)'
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 DELETE http://192.168.1.50/machine/file/0:%2Fgcodes%2Ffixa_cidlo_0.2mm_PETG_malej_12h39m.gcode application/json - - 204 - - 42.3188ms
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 GET http://192.168.1.50/machine/directory/0:%2Fgcodes%2F application/json -
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[0] Executing endpoint 'DuetWebServer.Controllers.MachineController.GetFileList (DuetWebServer)'
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3] Route matched with {action = "GetFileList", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] GetFileList(System.String) on controller DuetWebServer.Controllers.MachineController (DuetWebServer).
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ContentResultExecutor[1] Executing ContentResult with HTTP Response ContentType of application/json
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.GetFileList (DuetWebServer) in 19.3754ms
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.GetFileList (DuetWebServer)'
Feb 16 16:55:33 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 GET http://192.168.1.50/machine/directory/0:%2Fgcodes%2F application/json - - 200 705 application/json 22.5984ms
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 GET http://192.168.1.50/rr_connect?password=reprap&time=2022-02-16T16:55:09 - -
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 GET http://192.168.1.50/rr_connect?password=reprap&time=2022-02-16T16:55:09 - - - 404 0 - 10.9784ms
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 GET http://192.168.1.50/machine/status - -
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[0] Executing endpoint 'DuetWebServer.Controllers.MachineController.Status (DuetWebServer)'
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3] Route matched with {action = "Status", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] Status() on controller DuetWebServer.Controllers.MachineController (DuetWebServer).
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ContentResultExecutor[1] Executing ContentResult with HTTP Response ContentType of application/json
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.Status (DuetWebServer) in 67.8908ms
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.Status (DuetWebServer)'
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 GET http://192.168.1.50/machine/status - - - 200 14108 application/json 81.8717ms
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[1] Request starting HTTP/1.1 PUT http://192.168.1.50/machine/file/gcodes/fixa_cidlo_0.2mm_PETG_malej_12h39m.gcode - 13348749
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[0] Executing endpoint 'DuetWebServer.Controllers.MachineController.UploadFile (DuetWebServer)'
Feb 16 16:55:44 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3] Route matched with {action = "UploadFile", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] UploadFile(System.String, DuetWebServer.Singletons.ISessionStorage) on controller DuetWebServer.Controllers.MachineController (DuetWebServer).
Feb 16 16:57:23 malej DuetWebServer[596]: DuetWebServer.Controllers.MachineController[0] [UploadFile Failed upload file gcodes/fixa_cidlo_0.2mm_PETG_malej_12h39m.gcode (resolved to /opt/dsf/sd/gcodes/fixa_cidlo_0.2mm_PETG_malej_12h39m.gcode) Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)    at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)    at System.IO.Pipelines.PipeReader.CopyToAsyncCore[TStream](TStream destination, Func`4 writeAsync, CancellationToken cancellationToken)    at DuetWebServer.Controllers.MachineController.UploadFile(String filename, ISessionStorage sessionStorage) in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetWebServer/Controllers/MachineController.cs:line 410
Feb 16 16:57:23 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1] Executing ObjectResult, writing value of type 'System.String'.
Feb 16 16:57:23 malej DuetWebServer[596]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.UploadFile (DuetWebServer) in 98781.7749ms
Feb 16 16:57:23 malej DuetWebServer[596]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.UploadFile (DuetWebServer)'
Feb 16 16:57:23 malej DuetWebServer[596]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 PUT http://192.168.1.50/machine/file/gcodes/fixa_cidlo_0.2mm_PETG_malej_12h39m.gcode - 13348749 - 500 - text/plain;+charset=utf-8 98811.6824ms

If I can test something else, let me know.

chrishamm

@petrkroupa I cannot spot anything obvious there, it seems PS is getting stuck at some point during the transfer. I cannot reproduce this problem either, I just tried to upload a 20MB file and it worked as expected. Are you using Windows?

@bot It's just a PUT request (e.g. PUT http://duet3/machine/file/gcodes/myFile.gcode) with the plain G-code file as the body content. I just noticed one potential problem in PrusaSlicer 2.4.0: When you upload a file to a subdirectory, it doesn't use a slash but a backslash in the upload request as the directory separator (at least on Windows). Can you confirm this?

bot

@chrishamm I was just taking a look to see what might be going wrong. You could be correct. It encodes the filename directly to the url.

	if (connectionType == ConnectionType::dsf) {
		return (boost::format("%1%machine/file/gcodes/%2%")
				% get_base_url()
				% Http::url_encode(filename)).str();

Which is called like this (filename is the first argument):

auto upload_cmd = get_upload_url(upload_data.upload_path.string(), connectionType);

Which, digging into it, seems to directly set the upload path as the filesystem directory. So, yeah, on WIndows it might have \ instead of /.

In the logs above, I did notice:

Feb 16 16:57:23 malej DuetWebServer[596]: DuetWebServer.Controllers.MachineController[0] [UploadFile Failed upload file gcodes/fixa_cidlo_0.2mm_PETG_malej_12h39m.gcode (resolved to /opt/dsf/sd/gcodes/fixa_cidlo_0.2mm_PETG_malej_12h39m.gcode) Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)    at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)    at System.IO.Pipelines.PipeReader.CopyToAsyncCore[TStream](TStream destination, Func`4 writeAsync, CancellationToken cancellationToken)    at DuetWebServer.Controllers.MachineController.UploadFile(String filename, ISessionStorage sessionStorage) in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetWebServer/Controllers/MachineController.cs:line 410

But I do not understand what it means exactly.

chrishamm

@bot Thanks for looking into it. Unexpected end of request content means the request was too short which can be expected when the HTTP request is cancelled. So nothing unusual in there AFAICS.

bot

@chrishamm

I think the filename argument ends up being different depending on where the upload is initiated from. There seeems to be a background process that will upload files at times, or prepare the data for upload at least.

@Stephen6309 Do you have background slicing/processing enabled in prusaslicer? I forget what the exact feature name is called. It's in the app preferences.

Anyways. It seems to me that the path is set by the user input of the upload dialog.

Plater.cpp Line 6310

    PrintHostSendDialog dlg(default_output_file, upload_job.printhost->get_post_upload_actions(), groups);
    if (dlg.ShowModal() == wxID_OK) {
        upload_job.upload_data.upload_path = dlg.filename();
        upload_job.upload_data.post_action = dlg.post_action();
        upload_job.upload_data.group       = dlg.group();

        p->export_gcode(fs::path(), false, std::move(upload_job));
    }
}

There is a note on the dialog to use forward slashes a directory separators.

PetrKroupa

@chrishamm - Yes, on windows. Today I discovered an interesting thing. I use the arc welder plugin in post-processing scripts. If I do not use it, the upload will go smoothly.

@Stephen6309 - Do you use ARC Welder too?

chrishamm

@petrkroupa That's the reason why it doesn't work. Perhaps PrusaSlicer doesn't wait for ArcWelder to finish or it attempts to use file information of the old unprocessed file before it sends it over to the Duet.

Either way this is no problem in DSF or RRF.

PetrKroupa

@chrishamm - I agree. I assume that @Stephen6309 will confirm that he also uses this plugin. That's probably why no one has solved it yet and had no problem with it. This combination is probably not very common.

Thanks for help.

Stephen6309

@petrkroupa Yes I use arcwelder. But this problem only occurs with the PI4.

PetrKroupa

@stephen6309 - I can't test that because both printers I have with RPi4. However, if without SBC it works ok then it will be something in DSF or RRF. What do you think @chrishamm ?

chrishamm

@petrkroupa I am not convinced this is a problem in DSF. If you can upload files as usual using the web interface and if it works from PrusaSlicer without ArcWelder, it's obvious that ArcWelder interferes somehow with the upload process.

Stephen6309

@chrishamm Upload fine in standalone mode using arcwelder. My Duet 3 Mini 5+ is in standalone mode and everything uploaded fine. When I had a problem on my 6HC, I set it up in standalone mode for troubleshooting and the uploads worked fine.

The only difference between the two, is the PI4.

Stephen6309

@chrishamm PrusaSlicer 2.4.1beta4, SBC mode never finshes upload.

chrishamm

@stephen6309 I cannot confirm that (this is without ArcWelder on Windows x64):

I just checked 2.4.1-b3 on Linux x64 and there it works with ArcWelder too.

PetrKroupa

@chrishamm Without an arc welder, it works on both my printers. Both 6HC + SBC. But not with ARCwelder. It always gets stuck at 96-97% depending on the file size.
I don't have a Linux PC to test it.

Stephen6309

@chrishamm Without arcwelder or the PI, it works fine. Just not working in SBC mode.

Stephen6309

@stephen6309 Still doesn't work with 3.4.0 with the PI4.

STANDALONE mode works fine.

Superslicer 2.4.58.3 nightly from last week.

Phaedrux

@stephen6309 Do you have a different Pi and SD card to test with?

PetrKroupa

@phaedrux - I have two printers and same issue. Also have spare Pi and SD. If you have something to test, no problem.

Stephen6309

@phaedrux The 6HC with a PI4 and the Mini 5+ with a PI4, both running on a seperate meanwell power supply.

6HC's pi4 is running bullseye with current updates.
Mini's pi4 is running buster image from the duet3d doc site, with current updates.