akkadotnet/akka.net

Port of Akka actors for .NET

Bart de Boer

@boekabart

That's a Linqpad summary of the Journal.
Here's a Linqpad summary of the Snapshot:

The most relevant part of the log:

2019-08-13 12:27:54,032Z DEBUG [5  ] PostgreSqlSnapshotStore                  Started (Akka.Persistence.PostgreSql.Snapshot.PostgreSqlSnapshotStore)
2019-08-13 12:27:54,047Z DEBUG [8  ] PostgreSqlJournal                        Started (Akka.Persistence.PostgreSql.Journal.PostgreSqlJournal)
2019-08-13 12:27:54,625Z DEBUG [8  ] RuntimeActor                             Recovering an Snapshot 
snapshotOffer.ToString: SnapshotOffer<meta: SnapshotMetadata<pid: RuntimeActor, seqNr: 66298, timestamp: 2019/08/09>, snapshot: de7a22d1-bd93-4fef-81c3-00878a9f3517 en-queued at 2019-08-09T15:55:33.9508626+02:00>
snapshotOffer.SnapShot.GetType: Divv.IxIx.TitleCatalogizer.Actors.Runtime.RuntimeActor+EnqueuedWork
snapshotOffer.SnapShot.ToString de7a22d1-bd93-4fef-81c3-00878a9f3517 en-queued at 2019-08-09T15:55:33.9508626+02:00
2019-08-13 12:27:54,750Z DEBUG [5  ] ReplayFilter                             Started (Akka.Persistence.Journal.ReplayFilter)
2019-08-13 12:27:54,766Z DEBUG [5  ] PostgreSqlJournal                        now supervising akka://TitleCatalogizerPPTEST/system/akka.persistence.journal.postgresql/$a

As you can see, it seems to offer the last Journal entry as a snapshot.

This does not happen every time, about 50% of the times I start the completely stripped down application, it does start normal recovery of all the journal entries

Bart de Boer

@boekabart

full logging:

2019-08-13 12:27:53,766Z DEBUG [6  ] EventStream                              subscribing [akka://TitleCatalogizerPPTEST/system/log1-Log4NetLogger#1996803328] to channel Akka.Event.Debug
2019-08-13 12:27:53,766Z DEBUG [6  ] EventStream                              subscribing [akka://TitleCatalogizerPPTEST/system/log1-Log4NetLogger#1996803328] to channel Akka.Event.Info
2019-08-13 12:27:53,766Z DEBUG [6  ] EventStream                              subscribing [akka://TitleCatalogizerPPTEST/system/log1-Log4NetLogger#1996803328] to channel Akka.Event.Warning
2019-08-13 12:27:53,766Z DEBUG [6  ] EventStream                              subscribing [akka://TitleCatalogizerPPTEST/system/log1-Log4NetLogger#1996803328] to channel Akka.Event.Error
2019-08-13 12:27:53,766Z DEBUG [6  ] EventStream                              Logger log1-Log4NetLogger [Log4NetLogger] started
2019-08-13 12:27:53,766Z DEBUG [6  ] EventStream                              subscribing [akka://TitleCatalogizerPPTEST/system/UnhandledMessageForwarder#1371994935] to channel Akka.Event.UnhandledMessage
2019-08-13 12:27:53,766Z DEBUG [5  ] SystemGuardianActor                      now supervising akka://TitleCatalogizerPPTEST/system/UnhandledMessageForwarder
2019-08-13 12:27:53,766Z DEBUG [5  ] LoggingBus+UnhandledMessageForwarder     Started (Akka.Event.LoggingBus+UnhandledMessageForwarder)
2019-08-13 12:27:53,766Z DEBUG [6  ] EventStream                              Default Loggers started
2019-08-13 12:27:53,782Z DEBUG [5  ] SystemGuardianActor                      now supervising akka://TitleCatalogizerPPTEST/system/deadLetterListener
2019-08-13 12:27:53,782Z DEBUG [5  ] EventStream                              subscribing [akka://TitleCatalogizerPPTEST/system/deadLetterListener#1930670394] to channel Akka.Event.DeadLetter
2019-08-13 12:27:53,782Z DEBUG [5  ] DeadLetterListener                       Started (Akka.Event.DeadLetterListener)
2019-08-13 12:27:53,797Z DEBUG [5  ] EventStreamUnsubscriber                  registering unsubscriber with Akka.Event.EventStream
2019-08-13 12:27:53,797Z DEBUG [5  ] SystemGuardianActor                      now supervising akka://TitleCatalogizerPPTEST/system/EventStreamUnsubscriber-1
2019-08-13 12:27:53,797Z DEBUG [5  ] EventStreamUnsubscriber                  Started (Akka.Event.EventStreamUnsubscriber)
2019-08-13 12:27:53,829Z INFO  [1  ] TitleCatalogizerApp                      Started
2019-08-13 12:27:53,829Z INFO  [1  ] TitleCatalogizerApp                      The Divv.Comhem.Titlecatalogizer$PP-TEST service is now running, press Control+C to exit.
2019-08-13 12:27:53,829Z DEBUG [6  ] TitleCatalogizerAppActor                 Started (Divv.ComHem.TitleCatalogizer.Actors.TitleCatalogizerAppActor)
2019-08-13 12:27:53,829Z DEBUG [6  ] TitleCatalogizerAppActor                 now supervising akka://TitleCatalogizerPPTEST/user/TitleCatalogizer/Output
2019-08-13 12:27:53,829Z DEBUG [6  ] GuardianActor                            now supervising akka://TitleCatalogizerPPTEST/user/TitleCatalogizer
2019-08-13 12:27:53,829Z DEBUG [6  ] TitleCatalogizerAppActor                 now supervising akka://TitleCatalogizerPPTEST/user/TitleCatalogizer/Queue

2019-08-13 12:27:53,829Z DEBUG [6  ] BackoffSupervisor                        Started (Akka.Pattern.BackoffSupervisor)
2019-08-13 12:27:53,829Z DEBUG [6  ] BackoffSupervisor                        now supervising akka://TitleCatalogizerPPTEST/user/TitleCatalogizer/Queue/RuntimeActor
2019-08-13 12:27:53,829Z DEBUG [6  ] BaseCompositeActor+CompositeOutputActor  Started (Divv.Vlow.Akka.BaseActors.BaseCompositeActor+CompositeOutputActor)
2019-08-13 12:27:53,922Z DEBUG [5  ] SystemGuardianActor                      now supervising akka://TitleCatalogizerPPTEST/system/akka.persistence.journal.postgresql
2019-08-13 12:27:53,922Z DEBUG [5  ] RuntimeActor                             Started (Divv.ComHem.TitleCatalogizer.Actors.Runtime.RuntimeActor)
2019-08-13 12:27:53,922Z DEBUG [5  ] SystemGuardianActor                      now supervising akka://TitleCatalogizerPPTEST/system/akka.persistence.snapshot-store.postgresql
2019-08-13 12:27:53,922Z DEBUG [5  ] RuntimeActor                             now watched by [akka://TitleCatalogizerPPTEST/user/TitleCatalogizer/Queue#2002106618]
2019-08-13 12:27:53,938Z DEBUG [6  ] SystemGuardianActor                      now supervising akka://TitleCatalogizerPPTEST/system/recoveryPermitter
2019-08-13 12:27:53,938Z DEBUG [6  ] GuardianActor                            now supervising akka://TitleCatalogizerPPTEST/user/$a
2019-08-13 12:27:53,938Z DEBUG [6  ] RecoveryPermitter                        Started (Akka.Persistence.RecoveryPermitter)
2019-08-13 12:27:53,969Z DEBUG [6  ] AsyncWriteJournal+Resequencer            Started (Akka.Persistence.Journal.AsyncWriteJournal+Resequencer)
2019-08-13 12:27:53,969Z DEBUG [6  ] RuntimeActor                             now watched by [akka://TitleCatalogizerPPTEST/system/recoveryPermitter#906377815]
2019-08-13 12:27:54,032Z DEBUG [5  ] PostgreSqlSnapshotStore                  Started (Akka.Persistence.PostgreSql.Snapshot.PostgreSqlSnapshotStore)
2019-08-13 12:27:54,047Z DEBUG [8  ] PostgreSqlJournal                        Started (Akka.Persistence.PostgreSql.Journal.PostgreSqlJournal)
2019-08-13 12:27:54,625Z DEBUG [8  ] RuntimeActor                             Recovering an Snapshot SnapshotOffer<meta: SnapshotMetadata<pid: RuntimeActor, seqNr: 66298, timestamp: 2019/08/09>, snapshot: de7a22d1-bd93-4fef-81c3-00878a9f3517 en-queued at 2019-08-09T15:55:33.9508626+02:00> Divv.ComHem.TitleCatalogizer.Actors.Runtime.RuntimeActor+EnqueuedWork: de7a22d1-bd93-4fef-81c3-00878a9f3517 en-queued at 2019-08-09T15:55:33.9508626+02:00
2019-08-13 12:27:54,750Z DEBUG [5  ] ReplayFilter                             Started (Akka.Persistence.Journal.ReplayFilter)
2019-08-13 12:27:54,766Z DEBUG [5  ] PostgreSqlJournal                        now supervising akka://TitleCatalogizerPPTEST/system/akka.persistence.journal.postgresql/$a
2019-08-13 12:27:54,828Z INFO  [8  ] RuntimeActor                             Replay Success
2019-08-13 12:27:54,828Z DEBUG [8  ] ReplayFilter                             Stopped
2019-08-13 12:27:54,828Z INFO  [5  ] RuntimeActor                             Recovery completed
2019-08-13 12:27:54,844Z DEBUG [6  ] RuntimeActor                             no longer watched by [akka://TitleCatalogizerPPTEST/system/recoveryPermitter#906377815]

Bart de Boer

@boekabart

hocon:

akka : {
  log-config-on-start : on
  log-dead-letters : on
  stdout-loglevel : DEBUG
  loglevel : DEBUG
  loggers : ["Akka.Logger.log4net.Log4NetLogger, Akka.Logger.log4net","Akka.Event.StandardOutLogger, Akka"]
  suppress-json-serializer-warning : on
  actor : {
    debug : {
      receive : on
      autoreceive : on
      lifecycle : on
      event-stream : on
      unhandled : on
    }
  }
  persistence : {
    journal : {
      plugin : akka.persistence.journal.postgresql
      postgresql : {
        class : "Akka.Persistence.PostgreSql.Journal.PostgreSqlJournal, Akka.Persistence.PostgreSql"
        plugin-dispatcher : akka.actor.default-dispatcher
        connection-string : "Server=divv-1-pgsql-l.xixi.com;Port=5432;User Id=RtiTitleCatalogizer;Password=****;Database=RtiTitleCatalogizer;SslMode=Disable;"
        schema-name : public
        connection-timeout : 30s
        auto-initialize : on
        timestamp-provider : "Akka.Persistence.Sql.Common.Journal.DefaultTimestampProvider, Akka.Persistence.Sql.Common"
        metadata-table-name : metadata
        stored-as : BYTEA
      }
    }
    snapshot-store : {
      plugin : akka.persistence.snapshot-store.postgresql
      postgresql : {
        class : "Akka.Persistence.PostgreSql.Snapshot.PostgreSqlSnapshotStore, Akka.Persistence.PostgreSql"
        plugin-dispatcher : akka.actor.default-dispatcher
        connection-string : "Server=divv-1-pgsql-l.xixi.com;Port=5432;User Id=RtiTitleCatalogizer;Password=****;Database=RtiTitleCatalogizer;SslMode=Disable;"
        schema-name : public
        connection-timeout : 30s
        timestamp-provider : "Akka.Persistence.Sql.Common.Journal.DefaultTimestampProvider, Akka.Persistence.Sql.Common"
        auto-initialize : on
        stored-as : BYTEA
      }
    }
  }
}

Bart de Boer

@boekabart

another discovery: Seems that new Config( config, fallback); is slightly different than config.WithFallback(fallback). The former just keeps a reference, the latter performs an immediate merge.
Functionally, they seem to have the same effect. With one caveat: the ToString(true) of them are wildly different. Mostly in the sense that the former works, and the latter only dumps the original config... weirdly enough, because it seems that the entire config was merged!

Aaron Stannard

@Aaronontheweb

@boekabart I must have missed this - what's the LINQpad data for?

Bart de Boer

@boekabart

To show the contents on the actual journal and snapshot table

Aaron Stannard

@Aaronontheweb

on Postgres

and what is it that you're looking for?

I haven't followed the earlier thread

Bart de Boer

@boekabart

TLDR: snapshot table is empty, however, I get a snapshotOffer about 50% of startups, with the most recent Journal entry as the data source (time, seq Nr, type, data)

Aaron Stannard

@Aaronontheweb

LOL

oh man

Bart de Boer

@boekabart

well this is production code at a customer, so, less LOL than you'd imagine.

(when we get the snapshot offer, there are no journal recovery msgs)

Aaron Stannard

@Aaronontheweb

in terms of the Postgres HOCON

what are the table names being used?

Bart de Boer

@boekabart

default

snapshot_store and event_journal

Aaron Stannard

@Aaronontheweb

I wonder if the issue is the metadata table

but that's very odd

and also, a reason why we need akkadotnet/akka.net#3811 back

this crap would immediately power vomit an exception since the snapshot store couldn't deserialize those events

rather than YOLO serialization, which allows this type of error to silently fail in the background without any clear explanation

/ rant off

Bart de Boer

@boekabart

metadata table is empty btw

Aaron Stannard

@Aaronontheweb

can't be that then

first thing I'd look at is how the snapshot store is reading from the rows

because that's truly weird

can you file an issue on that project?

Bart de Boer

@boekabart

postgres project?

Aaron Stannard

@Aaronontheweb

correct

Bart de Boer

@boekabart

check

Aaron Stannard

@Aaronontheweb

since it seems to be specific to the Postgres driver

Bart de Boer

@boekabart

I see nothing weird in the postgres code though

Aaron Stannard

@Aaronontheweb

could be an issue with Akka.Persistence.Sql.Common

so maybe log an issue on the main Akka.NET project isntead

Bart de Boer

@boekabart

Except the postgres is on 1.3.9 but that shouldn't be an issue

Aaron Stannard

@Aaronontheweb

that will get more visibility at least

Bart de Boer

@boekabart

Will do

I tried to add some Console.Writeline to the postgres code but after building, I couldn't get that dll to work with the rest

dotnet version issues I guess

Aaron Stannard

@Aaronontheweb

well, we did make some important fixes to Akka.Persistence.Sql common in 1.3.12, 1.3.13, and 1.3.14

none for what you're describing really

serialization fixes and bug fixes for the CircuitBreaker

Where communities thrive

People

Repo info

Activity