App backup restore fails

abhilash-hm · January 19, 2023, 1:40pm

I have…

[x] Read the following guideline: https://docs.squidex.io/01-getting-started/installation/troubleshooting-and-support. I understand that my support request might get deleted if I do not follow the guideline.

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

The restore of a backup fails with an internal error

Expected behavior

The restore should work.

Minimal reproduction of the problem

Environment

App Name:

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

Version: 6.14.0.0

Browser:

[x] Chrome (desktop)
[ ] Chrome (Android)
[ ] Chrome (iOS)
[x] Firefox
[ ] Safari (desktop)
[ ] Safari (iOS)
[ ] IE
[ ] Edge

Others:
The app backup URL: https://squidex-dev.testrps.click/api/apps/backups/c8b67664-31b1-4c62-ae82-21bf49e619a5?app=svw-app-content&appId=f89b673e-08ee-4aa8-9eee-af2e68453ff2
App URL: cms-test.app.werder.de
Logs from the pods:

{"logLevel":"Error","message":"Backup with job id 9be973a9-c604-4d1b-b3d1-1bf7542667b1 from URL \u0027https://squidex-dev.testrps.click/api/apps/backups/c8b67664-31b1-4c62-ae82-21bf49e619a5?app=svw-app-content\u0026appId=f89b673e-08ee-4aa8-9eee-af2e68453ff2\u0027 failed.","backupId":"9be973a9-c604-4d1b-b3d1-1bf7542667b1","url":"https://squidex-dev.testrps.click/api/apps/backups/c8b67664-31b1-4c62-ae82-21bf49e619a5?app=svw-app-content\u0026appId=f89b673e-08ee-4aa8-9eee-af2e68453ff2","timestamp":"2023-01-19T13:23:06Z","app":{"name":"Squidex","version":"6.14.0.0","sessionId":"83cc9c7c-6e24-4af2-a280-a2bea92a1a0e"},"category":"Squidex.Domain.Apps.Entities.Backup.RestoreGrain","exception":{"type":"System.FormatException","message":"An error occurred while deserializing the Events property of class Squidex.Infrastructure.EventSourcing.MongoEventCommit: An error occurred while deserializing the Payload property of class Squidex.Infrastructure.EventSourcing.MongoEvent: Exception of type \u0027System.OutOfMemoryException\u0027 was thrown.","stackTrace":" at MongoDB.Bson.Serialization.BsonClassMapSerializer\u00601.DeserializeMemberValue(BsonDeserializationContext context, BsonMemberMap memberMap)\n at MongoDB.Bson.Serialization.BsonClassMapSerializer\u00601.DeserializeClass(BsonDeserializationContext context)\n at MongoDB.Bson.Serialization.BsonClassMapSerializer\u00601.Deserialize(BsonDeserializationContext context, BsonDeserializationArgs args)\n at MongoDB.Bson.Serialization.IBsonSerializerExtensions.Deserialize[TValue](IBsonSerializer\u00601 serializer, BsonDeserializationContext context)\n at MongoDB.Driver.Core.Operations.CursorBatchDeserializationHelper.DeserializeBatch[TDocument](RawBsonArray batch, IBsonSerializer\u00601 documentSerializer, MessageEncoderSettings messageEncoderSettings)\n at MongoDB.Driver.Core.Operations.AsyncCursor\u00601.CreateCursorBatch(BsonDocument result)\n at MongoDB.Driver.Core.Operations.AsyncCursor\u00601.ExecuteGetMoreCommandAsync(IChannelHandle channel, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.AsyncCursor\u00601.GetNextBatchAsync(CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.AsyncCursor\u00601.MoveNextAsync(CancellationToken cancellationToken)\n at MongoDB.Driver.IAsyncCursorExtensions.ToListAsync[TDocument](IAsyncCursor\u00601 source, CancellationToken cancellationToken)\n at MongoDB.Driver.IAsyncCursorSourceExtensions.ToListAsync[TDocument](IAsyncCursorSource\u00601 source, CancellationToken cancellationToken)\n at Squidex.Infrastructure.EventSourcing.MongoEventStore.QueryManyAsync(IEnumerable\u00601 streamNames, CancellationToken ct) in /src/src/Squidex.Infrastructure.MongoDb/EventSourcing/MongoEventStore_Reader.cs:line 109\n at Squidex.Infrastructure.States.BatchContext\u00601.LoadAsync(IEnumerable\u00601 ids) in /src/src/Squidex.Infrastructure/States/BatchContext.cs:line 58\n at Squidex.Infrastructure.Commands.Rebuilder.\u003C\u003Ec__DisplayClass10_0\u00602.\u003C\u003CInsertManyAsync\u003Eb__0\u003Ed.MoveNext() in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 95\n--- End of stack trace from previous location ---\n at Squidex.Infrastructure.Commands.Rebuilder.\u003C\u003Ec__DisplayClass10_0\u00602.\u003C\u003CInsertManyAsync\u003Eb__0\u003Ed.MoveNext() in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 97\n--- End of stack trace from previous location ---\n at Squidex.Infrastructure.Commands.Rebuilder.InsertManyAsync[T,TState](IAsyncEnumerable\u00601 source, Int32 batchSize, Double errorThreshold, CancellationToken ct) in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 150\n at Squidex.Infrastructure.Commands.Rebuilder.InsertManyAsync[T,TState](IEnumerable\u00601 source, Int32 batchSize, Double errorThreshold, CancellationToken ct) in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 73\n at Squidex.Domain.Apps.Entities.Contents.BackupContents.RestoreAsync(RestoreContext context, CancellationToken ct) in /src/src/Squidex.Domain.Apps.Entities/Contents/BackupContents.cs:line 196\n at Squidex.Domain.Apps.Entities.Backup.RestoreGrain.ProcessAsync() in /src/src/Squidex.Domain.Apps.Entities/Backup/RestoreGrain.cs:line 163"}}

{"logLevel":"Warning","message":".NET Thread Pool is exhibiting delays of 2.8751408s. This can indicate .NET Thread Pool starvation, very long .NET GC pauses, or other runtime or machine pauses.","threadPoolQueueDelaySeconds":"2.8751408","timestamp":"2023-01-19T13:23:11Z","app":{"name":"Squidex","version":"6.14.0.0","sessionId":"83cc9c7c-6e24-4af2-a280-a2bea92a1a0e"},"category":"Orleans.Runtime.MembershipService.LocalSiloHealthMonitor"}

{"logLevel":"Warning","message":"Self-monitoring determined that local health is degraded. Degradation score is 2/8 (lower is better). Complaints: .NET Thread Pool is exhibiting delays of 2.8751408s. This can indicate .NET Thread Pool starvation, very long .NET GC pauses, or other runtime or machine pauses.","score":"2","maxScore":"8","complaints":".NET Thread Pool is exhibiting delays of 2.8751408s. This can indicate .NET Thread Pool starvation, very long .NET GC pauses, or other runtime or machine pauses.","timestamp":"2023-01-19T13:23:11Z","app":{"name":"Squidex","version":"6.14.0.0","sessionId":"83cc9c7c-6e24-4af2-a280-a2bea92a1a0e"},"category":"Orleans.Runtime.MembershipService.LocalSiloHealthMonitor"}

Sebastian · January 19, 2023, 2:46pm

Please format the logs properly (with indentation and code blocks)

abhilash-hm · January 19, 2023, 3:26pm

Apologies. I have tried to fix it below, hope this is fine.

Log 1: Error

{
   "logLevel": "Error",
   "message": "Backup with job id 9be973a9-c604-4d1b-b3d1-1bf7542667b1 from URL 'https://squidex-dev.testrps.click/api/apps/backups/c8b67664-31b1-4c62-ae82-21bf49e619a5?app=svw-app-content&appId=f89b673e-08ee-4aa8-9eee-af2e68453ff2' failed.",
   "backupId": "9be973a9-c604-4d1b-b3d1-1bf7542667b1",
   "url": "https://squidex-dev.testrps.click/api/apps/backups/c8b67664-31b1-4c62-ae82-21bf49e619a5?app=svw-app-content&appId=f89b673e-08ee-4aa8-9eee-af2e68453ff2",
   "timestamp": "2023-01-19T13:23:06Z",
   "app": {
     "name": "Squidex",
     "version": "6.14.0.0",
     "sessionId": "83cc9c7c-6e24-4af2-a280-a2bea92a1a0e"
   },
   "category": "Squidex.Domain.Apps.Entities.Backup.RestoreGrain",
   "exception": {
     "type": "System.FormatException",
     "message": "An error occurred while deserializing the Events property of class Squidex.Infrastructure.EventSourcing.MongoEventCommit: An error occurred while deserializing the Payload property of class Squidex.Infrastructure.EventSourcing.MongoEvent: Exception of type 'System.OutOfMemoryException' was thrown.",
     "stackTrace": " at MongoDB.Bson.Serialization.BsonClassMapSerializer`1.DeserializeMemberValue(BsonDeserializationContext context, BsonMemberMap memberMap)\n at MongoDB.Bson.Serialization.BsonClassMapSerializer`1.DeserializeClass(BsonDeserializationContext context)\n at MongoDB.Bson.Serialization.BsonClassMapSerializer`1.Deserialize(BsonDeserializationContext context, BsonDeserializationArgs args)\n at MongoDB.Bson.Serialization.IBsonSerializerExtensions.Deserialize[TValue](IBsonSerializer`1 serializer, BsonDeserializationContext context)\n at MongoDB.Driver.Core.Operations.CursorBatchDeserializationHelper.DeserializeBatch[TDocument](RawBsonArray batch, IBsonSerializer`1 documentSerializer, MessageEncoderSettings messageEncoderSettings)\n at MongoDB.Driver.Core.Operations.AsyncCursor`1.CreateCursorBatch(BsonDocument result)\n at MongoDB.Driver.Core.Operations.AsyncCursor`1.ExecuteGetMoreCommandAsync(IChannelHandle channel, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.AsyncCursor`1.GetNextBatchAsync(CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.AsyncCursor`1.MoveNextAsync(CancellationToken cancellationToken)\n at MongoDB.Driver.IAsyncCursorExtensions.ToListAsync[TDocument](IAsyncCursor`1 source, CancellationToken cancellationToken)\n at MongoDB.Driver.IAsyncCursorSourceExtensions.ToListAsync[TDocument](IAsyncCursorSource`1 source, CancellationToken cancellationToken)\n at Squidex.Infrastructure.EventSourcing.MongoEventStore.QueryManyAsync(IEnumerable`1 streamNames, CancellationToken ct) in /src/src/Squidex.Infrastructure.MongoDb/EventSourcing/MongoEventStore_Reader.cs:line 109\n at Squidex.Infrastructure.States.BatchContext`1.LoadAsync(IEnumerable`1 ids) in /src/src/Squidex.Infrastructure/States/BatchContext.cs:line 58\n at Squidex.Infrastructure.Commands.Rebuilder.<>c__DisplayClass10_0`2.<<InsertManyAsync>b__0>d.MoveNext() in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 95\n--- End of stack trace from previous location ---\n at Squidex.Infrastructure.Commands.Rebuilder.<>c__DisplayClass10_0`2.<<InsertManyAsync>b__0>d.MoveNext() in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 97\n--- End of stack trace from previous location ---\n at Squidex.Infrastructure.Commands.Rebuilder.InsertManyAsync[T,TState](IAsyncEnumerable`1 source, Int32 batchSize, Double errorThreshold, CancellationToken ct) in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 150\n at Squidex.Infrastructure.Commands.Rebuilder.InsertManyAsync[T,TState](IEnumerable`1 source, Int32 batchSize, Double errorThreshold, CancellationToken ct) in /src/src/Squidex.Infrastructure/Commands/Rebuilder.cs:line 73\n at Squidex.Domain.Apps.Entities.Contents.BackupContents.RestoreAsync(RestoreContext context, CancellationToken ct) in /src/src/Squidex.Domain.Apps.Entities/Contents/BackupContents.cs:line 196\n at Squidex.Domain.Apps.Entities.Backup.RestoreGrain.ProcessAsync() in /src/src/Squidex.Domain.Apps.Entities/Backup/RestoreGrain.cs:line 163"
   }
}

Log 2: Warning

{
   "logLevel": "Warning",
   "message": ".NET Thread Pool is exhibiting delays of 2.8751408s. This can indicate .NET Thread Pool starvation, very long .NET GC pauses, or other runtime or machine pauses.",
   "threadPoolQueueDelaySeconds": "2.8751408",
   "timestamp": "2023-01-19T13:23:11Z",
   "app": {
     "name": "Squidex",
     "version": "6.14.0.0",
     "sessionId": "83cc9c7c-6e24-4af2-a280-a2bea92a1a0e"
   },
   "category": "Orleans.Runtime.MembershipService.LocalSiloHealthMonitor"
}

Log 3: Warning

{
   "logLevel": "Warning",
   "message": "Self-monitoring determined that local health is degraded. Degradation score is 2/8 (lower is better). Complaints: .NET Thread Pool is exhibiting delays of 2.8751408s. This can indicate .NET Thread Pool starvation, very long .NET GC pauses, or other runtime or machine pauses.",
   "score": "2",
   "maxScore": "8",
   "complaints": ".NET Thread Pool is exhibiting delays of 2.8751408s. This can indicate .NET Thread Pool starvation, very long .NET GC pauses, or other runtime or machine pauses.",
   "timestamp": "2023-01-19T13:23:11Z",
   "app": {
     "name": "Squidex",
     "version": "6.14.0.0",
     "sessionId": "83cc9c7c-6e24-4af2-a280-a2bea92a1a0e"
   },
   "category": "Orleans.Runtime.MembershipService.LocalSiloHealthMonitor"
}

abhilash-hm · January 19, 2023, 4:33pm

Also, one more question. This is deployed using helm chart version: 1.3.0:

repository      = "https://squidex.github.io/squidex/helm/"
chart           = "squidex"
version         = "1.3.0"

Is there a newer, more stable version?

abhilash-hm · January 20, 2023, 6:09am

Hi @Sebastian, a sincere request. Kindly have a look at the responses, please. Thanks in advance.

Sebastian · January 20, 2023, 8:47am

In the first log you see an OutOfMemoryException. This could be the source problem. I would have a look at your resources.

About Helm: Squidex 7 has a new architecture and therefore there is a new HELM: https://github.com/Squidex/squidex/tree/master/helm/squidex7

The main difference: This helm has 2 deployments:

API Service (N instances)
Worker Service (1 Instance)

abhilash-hm · January 20, 2023, 9:03am

Thanks for your response. I have increased the node capacity and also increased the memory limits of the pods. Testing it.

And when you say Worker service (1 instance), does that mean that we can only run one replica of Squidex?

abhilash-hm · January 20, 2023, 9:22am

Also, we are unable to restore this one app through the regular backup and restore method. How do we do this through the mongodb backup restore?

Sebastian · January 20, 2023, 10:05am

If you have another problem, just post it.

It is all described in the docs: https://docs.squidex.io/02-documentation/concepts/backups#when-not-to-use-the-backup-system

No. The worker handles background jobs and you should not replicate that. But you can have as many API nodes as you want.

abhilash-hm · January 21, 2023, 5:26am

Hi @Sebastian, thanks for your responses. I have ditched the backup and restore method from the Squidex cms and am trying the MongoDB backup and restore method.

Should I back up all the collections?
I mean every collection under the following:

And should we also backup and restore the System?

Thanks in advance.

Sebastian · January 21, 2023, 10:15am

No, only the 2 Squidex databases.

abhilash-hm · January 24, 2023, 10:00am

Hi @Sebastian, unable to export Events2 collection. It says it’s about 3.9GBs and the connection fails after exporting about 20+%.

Kindly, let us know if there is any other way to do this. This is very critical for us. I really appreciate any help you can provide.

Sebastian · January 24, 2023, 11:06am

This is a mongodb problem and I cannot give you support for this.