InvalidDatabaseSchema error on RailsEventStoreActiveRecord::EventRepository

[jasonjho]

We recently upgraded to the latest version of RES (0.40.1) running on Rails 6.0.0.rc1. Things generally work OK, but very intermittently, we will see the following 500 Internal Server Error from client API requests:

RailsEventStoreActiveRecord::EventRepository::InvalidDatabaseSchema: Oh no!\n\nIt seems you're using RailsEventStoreActiveRecord::EventRepository\nwith incompatible database schema.\n\nSee release notes how to migrate to current database schema.

which seems to be stemming from

lib/rails_event_store_active_record/correct_schema_verifier.rb:45:in `raise_invalid_db_schema'"

Note: we've so far only seen this in development -- so not sure if there's some development specific setting that could trigger this, but it's unclear at the moment.

Has anyone seen this before? Strange how it would complain about DB schema integrity.

[mostlyobvious]

Can you tell me the output of following in rails console?

ActiveRecord::Base.connection.columns(:event_store_events).map(&:name)
ActiveRecord::Base.connection.columns(:event_store_events_in_streams).map(&:name)

[mostlyobvious]

Btw. schema verification only runs when EventRepository is initialized:
https://github.com/RailsEventStore/rails_event_store/blob/master/rails_event_store_active_record/lib/rails_event_store_active_record/event_repository.rb#L11

[mostlyobvious]

We've added Rails 6.0.0.rc1 to test matrix.

Without further knowledge on columns or how the involved components (client, repository) are initialized and possibly reloaded (as this is a problem in development env so far) I cannot help more.

Please reopen in case of new information.

[jasonjho]

@pawelpacana It seems to happen on app/* changes in development mode. Could there be some reloading issues here?

[jasonjho]

When the error occurs on app reload (dev mode), I checked the following:

ActiveRecord::Base.connection.columns(:event_store_events).map(&:name)
=> ["event_type", "id", "metadata", "data", "created_at"]

ActiveRecord::Base.connection.columns(:event_store_events_in_streams).map(&:name)
=> ["id", "stream", "position", "event_id", "created_at"]

The DB schemas definitely don't change in between code reloads, so something must be off here.

[jasonjho]

Hi @pawelpacana

Based on the column checks here:

https://github.com/RailsEventStore/rails_event_store/blob/v0.40.1/rails_event_store_active_record/lib/rails_event_store_active_record/correct_schema_verifier.rb#L37

https://github.com/RailsEventStore/rails_event_store/blob/v0.40.1/rails_event_store_active_record/lib/rails_event_store_active_record/correct_schema_verifier.rb#L32

I noticed that eql? is being used here. Could it be the case that the following could cause that condition to fail? Though beyond this, I'm not sure why it would fail and then work again on the 2nd try.

%w(id event_type metadata data created_at).eql?(["id", "event_type", "metadata", "data", "created_at"])
=> true

%w(id event_type metadata data created_at).eql?(["event_type", "id", "metadata", "data", "created_at"])
=> false

The column checks seem to be tripping up here based on the index order. Thoughts?

[mostlyobvious]

I forgot that we recommend to define RES client as:

Rails.configuration.to_prepare do
  Rails.configuration.event_store = RailsEventStore::Client.new
  ...
end

This to_prepare block gets executed on code reloads in development mode, that would explain re-initializing event repository.

Why would the columns be returned in a different order remains a question.

Btw. what database do you use in development, Postgres?

[jasonjho]

@pawelpacana We are using Postgres 9.6.

There seems to be 2 issues.

First, correct schema verification relies on order-dependent column comparison, and for whatever reason, ActiveRecord/PG column metadata doesn't seem to have predictable ordering.

Second, ActiveRecord::Base.connected? seems to be set once actual requests to the DB are made. This means on rails server start (prod or development), this value is false. Since EventRepository uses the following logic to check for schema integrity:

     # connected? is not "true" here
     with_connection do
        return if no_tables_yet? || correct_schema?
        raise_invalid_db_schema
      end

it will simply pass and no exception is raised.

On production, this codepath is never re-executed so there is no further schema checks made.
On development, subsequent reloads will trigger EventRepository initialization and if any DB queries have been made, ActiveRecord::Base.connected? is now true and the schema is attempted to be validated. This will now return false due to the column comparison issue described above.

To fix the column check, how about using something like:

%w(id event_type metadata data created_at).sort == ["event_type", "id", "metadata", "data", "created_at"].sort

Let me know what you think. And thanks again for being super helpful on this.

[mostlyobvious]

I tried to reproduce the case with different column order. I did not manage to observe it in my timebox on Rails 6 + Postgres 11, on a new app. I do however agree we should not depend on order here.

To add some background — schema verifier was quite important when we were changing database schema around v0.18.2. Nowadays not much and I'm leaning towards removing it completely.

Second, ActiveRecord::Base.connected? seems to be set once actual requests to the DB are made.

That could have changed across Rails versions. We've had an issue in the past (#464) where ActiveRecord::Base.connected? was evaluated to true in initialization and just before migrations.

[mostlyobvious]

I've just released https://github.com/RailsEventStore/rails_event_store/releases/tag/v0.41.0 that lacks this schema verification mechanism. I hope that helps in 🙂