Database issue after upgrade

Greg · September 3, 2020, 1:45pm

I have…

[X ] Checked the logs and have provided the logs if I found something suspicious there

I’m submitting a…

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

Current behavior

After container reboot, the Squidex docker image has been update from 4.5.1 to 5.0.0.
After that there are errors in mongo DB access.
For instance MongoDB.Driver.MongoConnectionException
“An exception occurred while receiving a message from the server.”
at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync()
Moreover many links between content and assets are broken.
Change history is not available anymore in content. Still there is schemas.

Expected behavior

I expected that mongo database created in a previous version of Squidex would be compatible with future major versions.
Changlog for 4.6.0 mentions a bugfix which requires mongodb 4.2 , ours is 4.4.
Apart from that, I see nothing saying that v5.0.0 is incompatible with old mongo DB created with 4.5.1

Minimal reproduction of the problem

Install Squidex V4.5.1.
Add schemas, content and assets.
Have content linked to assets.
Upgrade to 5.0.0

Environment

[ ] Self hosted with docker
[ ] Self hosted with IIS
[X ] Self hosted with other version (azure app service)
[ ] Cloud version

Version: [5.0.0]

Browser:

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

Others:

Is this the expected behavior or should Squidex v5.0.0 work fine with a mongo database created with Squidex 4.5.1? Thank you.

Sebastian · September 3, 2020, 1:57pm

Do you have the full stack trace?

Greg · September 3, 2020, 2:07pm

2020-09-02T13:26:43.782954727Z {
2020-09-02T13:26:43.782982127Z “logLevel”: “Error”,
2020-09-02T13:26:43.790968040Z “action”: “TrackUsage”,
2020-09-02T13:26:43.790974140Z “status”: “Failed”,
2020-09-02T13:26:43.790977640Z “app”: {
2020-09-02T13:26:43.790980840Z “name”: “Squidex”,
2020-09-02T13:26:43.790984140Z “version”: “4.5.1.0”,
2020-09-02T13:26:43.790987340Z “sessionId”: “4f47b7d4-5980-4dac-a8ba-f92598346db3”
2020-09-02T13:26:43.790990740Z },
2020-09-02T13:26:43.790993740Z “timestamp”: “2020-09-02T13:26:42Z”,
2020-09-02T13:26:43.790996840Z “exception”: {
2020-09-02T13:26:43.790999841Z “type”: “MongoDB.Driver.MongoConnectionException”,
2020-09-02T13:26:43.791003141Z “message”: “An exception occurred while receiving a message from the server.”,
2020-09-02T13:26:43.791009241Z “stackTrace”: " at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync()\n at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(Int32 responseTo, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveMessageAsync(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.WireProtocol.CommandUsingCommandMessageWireProtocol\u00601.ExecuteAsync(IConnection connection, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Servers.Server.ServerChannel.ExecuteProtocolAsync[TResult](IWireProtocol\u00601 protocol, ICoreSession session, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.RetryableWriteOperationExecutor.ExecuteAsync[TResult](IRetryableWriteOperation\u00601 operation, RetryableWriteContext context, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.BulkUnmixedWriteOperationBase\u00601.ExecuteBatchAsync(RetryableWriteContext context, Batch batch, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.BulkUnmixedWriteOperationBase\u00601.ExecuteBatchesAsync(RetryableWriteContext context, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.BulkMixedWriteOperation.ExecuteBatchAsync(RetryableWriteContext context, Batch batch, CancellationToken cancellationToken)\n at MongoDB.Driver.Core.Operations.BulkMixedWriteOperation.ExecuteAsync(IWriteBinding binding, CancellationToken cancellationToken)\n at MongoDB.Driver.OperationExecutor.ExecuteWriteOperationAsync[TResult](IWriteBinding binding, IWriteOperation\u00601 operation, CancellationToken cancellationToken)\n at MongoDB.Driver.MongoCollectionImpl\u00601.ExecuteWriteOperationAsync[TResult](IClientSessionHandle session, IWriteOperation\u00601 operation, CancellationToken cancellationToken)\n at MongoDB.Driver.MongoCollectionImpl\u00601.BulkWriteAsync(IClientSessionHandle session, IEnumerable\u00601 requests, BulkWriteOptions options, CancellationToken cancellationToken)\n at MongoDB.Driver.MongoCollectionImpl\u00601.UsingImplicitSessionAsync[TResult](Func\u00602 funcAsync, CancellationToken cancellationToken)\n at Squidex.Infrastructure.Log.Store.BackgroundRequestLogStore.TrackAsync() in /src/src/Squidex.Infrastructure/Log/Store/BackgroundRequestLogStore.cs:line 63"
2020-09-02T13:26:43.791034541Z }
2020-09-02T13:26:43.791038041Z }

Greg · September 3, 2020, 2:14pm

What I did is that I reconfigured my squidex container to force the docker image version to 4.5.1; then I restarted it: then I restored my last backup before the issue to a new app.
On this restored app, everything is working fine : images are back in place, content history is shown again.
So I presume there is a hitch between Squidex 5.0.0 db schema and 4.5.1 db schema.

Greg · September 3, 2020, 2:15pm

Could you confirm this please?

Sebastian · September 3, 2020, 2:21pm

I am not sure, what goes wrong. But 5.0.0 is still in beta, so I don’t know what is wrong. But the Beta does not make any changes to the mongodb connection itself.

Greg · September 3, 2020, 2:29pm

here is complete log archive
https://mega.nz/file/1RdCHY5Q#SDpf1ygNoPgPKIUgHDwoZ-Qj6NEssldGURDXTnxRVos

Sebastian · September 3, 2020, 2:31pm

Thanks, do you one or multiple nodes? I do not see any error after the migration was running that was introduced with 5.0

Edit: I do not see any error at all in the logs.

Greg · September 3, 2020, 2:35pm

only one node is running
there are MongoDB.Driver.MongoConnectionException in the xxx.23…log file

Greg · September 3, 2020, 2:40pm

the upgrade occured on 2020-09-02 03:18:32 (see 2020_09_02_RD0050F2817953_docker.log )
first exception occured on 2020-09-02 10:20:44 (see 2020_09_02_RD0050F2817953_default_docker.42.log) : Microsoft.Azure.Storage.StorageException
then on 2020-09-02 10h37 there is Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException
then on 2020-09-02 13:26 there is MongoDB.Driver.MongoConnectionException (see 2020_09_02_RD0050F2817953_default_docker.23.log )

Sebastian · September 3, 2020, 2:41pm

Thank you. The stack trace has nothing to do with the changes I did. Not sure, why it happened.

But as I said: The 5.0.0 is still in beta, but the problem with references might be interesting, I will have a look to that.

Greg · September 3, 2020, 2:42pm

ok, thank you for your invetigation.

Jiri · September 3, 2020, 2:55pm

I have the same issue after the upgrade it was used the last beta (because beta is published as “latest” in docker hub). And I will break all reference to assets. And same as Greg after downgrade to 4.6 (using specific version in docker-compose file) I cannot access most of the part my app. I think it will be better to replace the latest version in dockerhub with 4.6 and use a different tag for beta version. Because I do not expect this and as I found here I am not only one.

But something positive restore with build-in backup is pretty nice.

Sebastian · September 3, 2020, 3:00pm

Yes, the problem with latest ist stupid.

Thomas · September 8, 2020, 1:54pm

Hi

I’m experiencing the same issue - and I try to figure out how to fix this. My backup is too old, and creating a new backup on the version 5 beta (which has content there, but broken references) fails. I cannot reference assets to fix it manually either. Both just assigning assets or creating a new app and assigning assets doesn’t work.

Do I have any other options than to build the app manually on version 4.6 by copy pasting, @Sebastian ?

Sebastian · September 8, 2020, 1:56pm

You can try dev-4827 and see if it fixes the problem for you.

Thomas · September 8, 2020, 2:22pm

Thanks, it works!

I also needed to troubleshoot a “HPE_HEADER_OVERFLOW” I got for my big graphql query, but found the solution: 502 Bad Gateway on some graphql queries

Thomas · October 26, 2020, 10:36am

@Sebastian do you have any tips in how to upgrade to the latest version? I backed up our MongoDB file share just in case, and tried to upgrade from dev-4827 to 5.2.1 - but that resulted in assets not showing and all but 2 schemas not showing. When reverting to dev-4827, it seems both assets and schemas still works as expected.

E.g. if there is a version in between the two that could work out as a transition version?

Sebastian · October 26, 2020, 10:49am

There is no version in between. You can send me your backup and I can have a look, but it should just work. Perhaps the migration was not running in your case?

Thomas · October 26, 2020, 11:29am

Sure, I can send a backup for one of the apps. However, we have 4 apps and one of the apps started to fail creating backups after the miss upgrade when we went for the dev beta 5 latest version:

But I guess that is another issue.