[NOT_REPRODUCIBLE] Squidex cli backup hang indefinitely

I have…

  • Checked the logs and have uploaded a log file and provided a link because I found something suspicious there. Please do not post the log file in the topic because very often something important is missing.

I’m submitting a…

  • Regression (a behavior that stopped working in a new release)
  • [ x] Bug report
  • Performance issue
  • Documentation issue or request

Current behavior

often backup with cli hang indefinitely with just
Processing app: site22

App added.
App selected.
Backup started, waiting for completion…

and not completed , just hanging so.

Expected behavior

Minimal reproduction of the problem

Environment

  • [x ] Self hosted with docker
  • Self hosted with IIS
  • Self hosted with other version
  • Cloud version

Version: [VERSION]

Browser:

  • Chrome (desktop)
  • Chrome (Android)
  • Chrome (iOS)
  • Firefox
  • Safari (desktop)
  • Safari (iOS)
  • IE
  • Edge

Others:
cli version - cli-v13.3 (latest)
squidex - 7.13.0

Some logs:
{
“logLevel”:“Error”,
“message”:“An unexpected exception has occurred.”,
“timestamp”:“2024-10-03T20:55:46Z”,
“app”:{
“name”:“Squidex”,
“version”:“7.13.0.0”,
“sessionId”:“62fbdefc-9c75-4a15-804b-592dc6cba238”
},
“web”:{
“requestId”:“00-a7c8de78865ce95af7eca3f75112dac2-cdb660fd77bb1849-01”,
“requestPath”:“/api/users/collaboration”,
“requestMethod”:“GET”
},
“category”:“Squidex.Web.Pipeline.RequestExceptionMiddleware”,
“exception”:{
“type”:“System.InvalidOperationException”,
“message”:“Socket is already closed.”,
“stackTrace”:" at YDotNet.Server.WebSockets.WebSocketDecoder.ReadIfEndOfBufferReachedAsync(CancellationToken ct)\n at YDotNet.Server.WebSockets.WebSocketDecoder.ReadByteAsync(CancellationToken ct)\n at YDotNet.Protocol.Decoder.ReadVarUintAsync(CancellationToken ct)\n at YDotNet.Server.WebSockets.YDotNetSocketMiddleware.InvokeAsync(HttpContext httpContext, String documentName)\n at YDotNet.Server.WebSockets.YDotNetSocketMiddleware.InvokeAsync(HttpContext httpContext, String documentName)\n at YDotNet.Server.WebSockets.YDotNetActionResult.ExecuteResultAsync(ActionContext context)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.\u003CInvokeResultAsync\u003Eg__Logged|22_0(ResourceInvoker invoker, IActionResult result)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.\u003CInvokeNextResultFilterAsync\u003Eg__Awaited|30_0[TFilter,TFilterAsync](ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResultExecutedContextSealed context)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.ResultNext[TFilter,TFilterAsync](State\u0026 next, Scope\u0026 scope, Object\u0026 state, Boolean\u0026 isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.\u003CInvokeResultFilters\u003Eg__Awaited|28_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.\u003CInvokeNextResourceFilter\u003Eg__Awaited|25_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State\u0026 next, Scope\u0026 scope, Object\u0026 state, Boolean\u0026 isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.\u003CInvokeFilterPipelineAsync\u003Eg__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.\u003CInvokeAsync\u003Eg__Logged|17_1(ResourceInvoker invoker)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.\u003CInvokeAsync\u003Eg__Logged|17_1(ResourceInvoker invoker)\n at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)\n at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)\n at Squidex.Web.Pipeline.UsageMiddleware.InvokeAsync(HttpContext context, RequestDelegate next) in /src/src/Squidex.Web/Pipeline/UsageMiddleware.cs:line 39\n at Squidex.Web.Pipeline.UsageMiddleware.InvokeAsync(HttpContext context, RequestDelegate next) in /src/src/Squidex.Web/Pipeline/UsageMiddleware.cs:line 87\n at Microsoft.AspNetCore.Builder.UseMiddlewareExtensions.InterfaceMiddlewareBinder.\u003C\u003Ec__DisplayClass2_0.\u003C\u003CCreateMiddleware\u003Eb__0\u003Ed.MoveNext()\n— End of stack trace from previous location —\n at Squidex.Web.Pipeline.RequestExceptionMiddleware.InvokeAsync(HttpContext context, IActionResultExecutor\u00601 writer, ILogger\u00601 log) in /src/src/Squidex.Web/Pipeline/RequestExceptionMiddleware.cs:line 42"
}
}

{“logLevel”:“Information”,“message”:“Handled JobStart { OwnerId = 1c845b9c-9681-4cce-a00f-7af369089c0a, Request = JobRequest { Actor = subject:654e09e42570846d6d87041f, TaskName = backup, Arguments = Squidex.Infrastructure.Collections.ReadonlyDictionary\u00602[System.String,System.String], AppId = 1c845b9c-9681-4cce-a00f-7af369089c0a,site122 } } for ChannelName { Name = backup.start, Type = Queue } with System.Func\u00603[System.Object,System.Threading.CancellationToken,System.Threading.Tasks.Task].”,“message”:“JobStart { OwnerId = 1c845b9c-9681-4cce-a00f-7af369089c0a, Request = JobRequest { Actor = subject:654e09e42570846d6d87041f, TaskName = backup, Arguments = Squidex.Infrastructure.Collections.ReadonlyDictionary\u00602[System.String,System.String], AppId = 1c845b9c-9681-4cce-a00f-7af369089c0a,site122 } }”,“channel”:“ChannelName { Name = backup.start, Type = Queue }”,“handler”:“System.Func\u00603[System.Object,System.Threading.CancellationToken,System.Threading.Tasks.Task]”,“timestamp”:“2024-10-03T20:28:31Z”,“app”:{“name”:“Squidex”,“version”:“7.13.0.0”,“sessionId”:“860b85cc-680b-463b-b0e3-550f8e4e0b12”},“category”:“Squidex.Messaging.Implementation.DelegatingConsumer”}
debian@minikube-de01:~$

Please format your logs properly with code blocks. They are hard to read. Do they sometimes work? Do you have a worker instance? By default the only node is marked as worker if not configured otherwise.

Some applications are successfully backing up while others are not, even though they follow the same backup logic. It seems to work inconsistently, sometimes succeeding and other times failing. We have a Squidex worker node. Squidex running inside minikube. Below are the latest backup logs, showing that one app was backed up successfully, while another failed.

Processing app: site91
> App added.
> App selected.
Backup started, waiting for completion...
ERROR: System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at System.Threading.Tasks.Task.GetExceptions(Boolean includeTaskCanceledExceptions)
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at CommandDotNet.AppRunner.Run(String[] args) in CommandDotNet/AppRunner.cs:line 95
   at Squidex.CLI.Program.Main(String[] args)
   --- End of stack trace from previous location ---
   at CommandDotNet.AppRunner.HandleException(Exception ex, CommandContext commandContext) in CommandDotNet/AppRunner.cs:line 191
   at CommandDotNet.AppRunner.Run(String[] args) in CommandDotNet/AppRunner.cs:line 101
   at Squidex.CLI.Program.Main(String[] args)
Error running Squidex CLI for site91: Command '['sq', 'backup', 'create', 'site91.zip', '--deleteAfterDownload', '--force']' returned non-zero exit status 255.
Processing app: sitetemplate
> App added.
> App selected.
Backup started, waiting for completion...
Backup completed. Downloading...
Removing backup from app
> Backup Download completed.
Backup created: sitetemplate.zip

Thats the CLI logs, only showing a timeout basically. Do you have logs from the backend that would help?