Database issue after upgrade

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.

Do you have the full stack trace?

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 }

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.

Could you confirm this please?

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.

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

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.

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

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 )

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.

ok, thank you for your invetigation.

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.

Yes, the problem with latest ist stupid.

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 ?

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

1 Like

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

1 Like