Silo keeps starting / stopping

Support
1

We are running Squidix within an Azure Web App which worked just fine (built from commit: 08e9ac30d989).

I’ve tried updating to the latest version. Building works fine but the starting of the application has some very strange behaviour. The application loads but is extremely slow. When i look at the orleans dashboard is see that a Silo is started, then runs for 20 seconds and get’s killed again.

Seems like the application is cycling in startup. I’ve enabled logging and see an error popping up right after the migration steps:

{
“logLevel”: “Fatal”,
“message”: “An error occurred starting the application”,
“eventId”: {
“id”: 9
},
“exception”: {
“type”: “System.AggregateException”,
“message”: “One or more errors occurred. (Unable to cast object of type ‘MongoDB.Bson.BsonDocument’ to type ‘MongoDB.Bson.BsonString’.)”,
“stackTrace”: " at Microsoft.AspNetCore.Hosting.Internal.HostedServiceExecutor.ExecuteAsync(Func`2 callback)\r\n at Microsoft.AspNetCore.Hosting.Internal.HostedServiceExecutor.StartAsync(CancellationToken token)"
},
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:12.4222375Z”,
“category”: “Microsoft.AspNetCore.Hosting.Internal.HostedServiceExecutor”
}

With you’re latest changes on https://github.com/Squidex/squidex/commit/e97d38148df93a2a3cdb76957c8771253259a777 this causes the application to stop the silo.

I’ve no clue where to look for the cause of this exception. Any ideas on this?

2

Before my change some problems were just swallowed and it was starting but made a lot of problems later.

Do you have the full stack trace?

3

I think that it could be a problem with migrations, but I am not sure, what exactly happens. Can you show me the entry in the Migration collection, it should show

{ 
    "_id" : "Default", 
    "IsLocked" : false, 
    "Version" : NumberInt(13)
}

Furthermore it would be great to see an entry from the RuleEvents collection. I would like to know whether the Job.actionData is a document or string. Should be a string.

4

Below is the full log perhaps that helps. I’m not able to find the complete stacktrace of the exception because it runs in Azure. Remote debugging doesn’t work because the application already restarted once the remote debugger is connected.
`

Log

— Started Logging 1/8/2019 10:50:54 AM —
{
“logLevel”: “Information”,
“message”: “Application started”,
“environment”: {
<> },
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:50:54.4495562Z”
}

{
“logLevel”: “Information”,
“message”: “Starting IdentityServer4 version 2.3.2.0”,
“version”: “2.3.2.0”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:04.2751339Z”,
“category”: “IdentityServer4.Startup”
}

{
“logLevel”: “Information”,
“message”: “Using the default authentication scheme Identity.Application for IdentityServer”,
“scheme”: “Identity.Application”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:04.3732238Z”,
“category”: “IdentityServer4.Startup”
}

{
“logLevel”: “Information”,
“elapsedRequestMs”: 48,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“web”: {
“requestId”: “76b798e5-aab0-42a5-adbd-376bce54a0cf”,
“requestPath”: “/”,
“requestMethod”: “GET”
},
“timestamp”: “2019-01-08T10:51:06.0972581Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “AzureBlobAssetStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:09.4104834Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoEventStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:09.6783633Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoEventStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:09.7181013Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoMigrationStatus”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:09.7257467Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoUsageRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:09.8543202Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoRuleEventRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:09.9429774Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoHistoryEventRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:10.0288361Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoPersistedGrantStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:10.2519942Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoRoleStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:11.6022502Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoUserStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:11.6907866Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoAssetRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:11.7598591Z”
}

{
“logLevel”: “Information”,
“siloInitializedSystem”: “MongoContentRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:11.8229123Z”
}

{
“logLevel”: “Information”,
“message”: “Silo started”,
“elapsedMs”: 7228,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.8253789Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “AzureBlobAssetStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9377974Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoEventStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9460175Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoEventStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9494506Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoMigrationStatus”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9495736Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoUsageRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9539847Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoRuleEventRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9577311Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoHistoryEventRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9616631Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoPersistedGrantStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9670648Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoRoleStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9715538Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoUserStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9868546Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoAssetRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:11.9967638Z”
}

{
“logLevel”: “Information”,
“initializedSystem”: “MongoContentRepository”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:12.0059624Z”
}

{
“logLevel”: “Information”,
“action”: “Migration”,
“status”: “Started”,
“migrator”: “Migrate_01.Migrations.StopEventConsumers”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:12.1716446Z”
}

{
“logLevel”: “Information”,
“action”: “Migration”,
“status”: “Completed”,
“migrator”: “Migrate_01.Migrations.StopEventConsumers”,
“elapsedMs”: 10,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:12.1886946Z”
}

{
“logLevel”: “Information”,
“action”: “Migration”,
“status”: “Started”,
“migrator”: “Migrate_01.Migrations.ConvertEventStore”,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:12.1888024Z”
}

{
“logLevel”: “Information”,
“action”: “Migration”,
“status”: “Completed”,
“migrator”: “Migrate_01.Migrations.ConvertEventStore”,
“elapsedMs”: 204,
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”
},
“timestamp”: “2019-01-08T10:51:12.3932506Z”
}

{
** “logLevel”: “Fatal”,**
** “message”: “An error occurred starting the application”,**
** “eventId”: {**
** “id”: 9**
** },**
** “exception”: {**
** “type”: “System.AggregateException”,**
** “message”: “One or more errors occurred. (Unable to cast object of type ‘MongoDB.Bson.BsonDocument’ to type ‘MongoDB.Bson.BsonString’.)”,**
** “stackTrace”: " at Microsoft.AspNetCore.Hosting.Internal.HostedServiceExecutor.ExecuteAsync(Func`2 callback)\r\n at Microsoft.AspNetCore.Hosting.Internal.HostedServiceExecutor.StartAsync(CancellationToken token)"**
** },**
** “app”: {**
** “name”: “Squidex”,**
** “version”: “1.0.0.0”,**
** “sessionId”: “b3bb9cdc-4f15-47a6-a862-21a2d89a32f1”**
** },**
** “timestamp”: “2019-01-08T10:51:12.4222375Z”,**
** “category”: “Microsoft.AspNetCore.Hosting.Internal.HostedServiceExecutor”**
}

{
“logLevel”: “Warning”,
“message”: “UnregisterManyAsync 1 failed.”,
“eventId”: {
“id”: 100502
},
“exception”: {
“type”: “System.InvalidOperationException”,
“message”: “Grain directory is stopping”,
“stackTrace”: " at Orleans.Runtime.GrainDirectory.LocalGrainDirectory.CheckIfShouldForward(GrainId grainId, Int32 hopCount, String operationDescription)\r\n at Orleans.Runtime.GrainDirectory.LocalGrainDirectory.UnregisterOrPutInForwardList(IEnumerable1 addresses, UnregistrationCause cause, Int32 hopCount, Dictionary2& forward, List1 tasks, String context)\r\n at Orleans.Runtime.GrainDirectory.LocalGrainDirectory.UnregisterManyAsync(List1 addresses, UnregistrationCause cause, Int32 hopCount)\r\n at Orleans.Runtime.Scheduler.AsyncClosureWorkItem.Execute()\r\n at Orleans.Runtime.Catalog.FinishDestroyActivations(List`1 list, Int32 number, MultiTaskCompletionSource tcs)"
},
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:13.0846159Z”,
“category”: “Orleans.Runtime.Catalog”
}

{
“logLevel”: “Warning”,
“message”: “Failed to un-register NonExistentActivation S10.68.20.7:11111:284640663*grn/7483D9D2/00000000@5173d8b1”,
“eventId”: {
“id”: 101535
},
“exception”: {
“type”: “System.InvalidOperationException”,
“message”: “Grain directory is stopping”,
“stackTrace”: " at Orleans.Runtime.GrainDirectory.LocalGrainDirectory.CheckIfShouldForward(GrainId grainId, Int32 hopCount, String operationDescription)\r\n at Orleans.Runtime.GrainDirectory.LocalGrainDirectory.UnregisterAsync(ActivationAddress address, UnregistrationCause cause, Int32 hopCount)\r\n at Orleans.Runtime.Dispatcher.<>c__DisplayClass18_1.<b__0>d.MoveNext()"
},
“app”: {
“name”: “Squidex”,
“version”: “1.0.0.0”,
“sessionId”: “304299c5-f0ee-43df-bb6b-ef256bb8ea4d”
},
“timestamp”: “2019-01-08T10:51:13.1563658Z”,
“category”: “Orleans.Runtime.Dispatcher”
}

`

5

This is the entry in the Migration collection:
{
“_id”:“Default”,
“IsLocked”:false,
“Version”:0:
}

My RuleEvents collection is empty

6

Would you export the database for me and send me the export?

7

No problem. Do you have a safe upload location?

8

No, sorry, just upload it to dropbox or so and send me the link via private message.

9

Do you remember which version you had before the update?

10

Before the update we had a version that was built from commit: https://github.com/Squidex/squidex/commit/08e9ac30d98969be272de4260f424ab7cac3fa80

11

What I do not understand is why your “Migration” collection has an very old status. It tries to run migrations which are very old (< 1 year) and therefore it fails. You can try to set the version to 13

12

I’ve set the version to 13 manually. Now it starts just fine (seemed to take a while for Orleans to recover).

The version based on https://github.com/Squidex/squidex/commit/08e9ac30d98969be272de4260f424ab7cac3fa80 was the first version we used. This version also filled the initial database.

Perhaps there is an issue with initializing a fresh database and setting the migrations field?

13

I don’t think so. I think it was due a previous error that was swallowed in your case. I use a new database regularly.