cpursley / walex

Postgres change events (CDC) in Elixir
MIT License
276 stars 14 forks source link

Fix config tests #54

Closed oortlieb closed 4 months ago

oortlieb commented 4 months ago

Oops, I still managed to break the tests! This should fix it -- I have it passing locally (though I thought I had the previous PR passing tests locally, as well).

Probably a good idea to send it through the workflow on GH as well just to be sure, but it's up to you 😄

oortlieb commented 4 months ago

The tests in the worker are failing differently than what I'm seeing locally. This is the result of running MIX_ENV=test mix test on my machine:

15:27:34.550 [error] GenServer {:walex_registry, {WalEx.Destinations.EventModules, :test_app}} terminating
** (RuntimeError) Process error
    test/walex/event/event_test.exs:144: TestApp.TestModule.process_all/1
    (elixir 1.15.7) lib/enum.ex:984: Enum."-each/2-lists^foreach/1-0-"/2
    (walex 3.8.0) lib/walex/destinations/event_modules.ex:37: WalEx.Destinations.EventModules.handle_call/3
    (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
    (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
    (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
Last message (from #PID<0.557.0>): {:process, %WalEx.Changes.Transaction{changes: [%WalEx.Changes.UpdatedRecord{type: "UPDATE", old_record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.535414-07:00 -07 Etc/UTC-7>}, record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.546409-07:00 -07 Etc/UTC-7>}, schema: "public", table: "user", columns: [%WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "id", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "email", type: "citext", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "name", type: "varchar", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "age", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "created_at", type: "timestamptz", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "updated_at", type: "timestamptz", type_modifier: 4294967295}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}, :test_app}
State: %{}
Client #PID<0.557.0> is alive

    (stdlib 5.1.1) gen.erl:240: :gen.do_call/4
    (elixir 1.15.7) lib/gen_server.ex:1071: GenServer.call/3
    (walex 3.8.0) lib/walex/destinations/destinations.ex:51: WalEx.Destinations.process_destinations/2
    (walex 3.8.0) lib/walex/destinations/destinations.ex:38: WalEx.Destinations.handle_call/3
    (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
    (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
    (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3

15:27:34.553 [error] GenServer {:walex_registry, {WalEx.Destinations, :test_app}} terminating
** (stop) exited in: GenServer.call({:via, Registry, {:walex_registry, {WalEx.Destinations.EventModules, :test_app}}}, {:process, %WalEx.Changes.Transaction{changes: [%WalEx.Changes.UpdatedRecord{type: "UPDATE", old_record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.535414-07:00 -07 Etc/UTC-7>}, record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.546409-07:00 -07 Etc/UTC-7>}, schema: "public", table: "user", columns: [%WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "id", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "email", type: "citext", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "name", type: "varchar", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "age", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "created_at", type: "timestamptz", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "updated_at", type: "timestamptz", type_modifier: 4294967295}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}, :test_app}, :infinity)
    ** (EXIT) an exception was raised:
        ** (RuntimeError) Process error
            test/walex/event/event_test.exs:144: TestApp.TestModule.process_all/1
            (elixir 1.15.7) lib/enum.ex:984: Enum."-each/2-lists^foreach/1-0-"/2
            (walex 3.8.0) lib/walex/destinations/event_modules.ex:37: WalEx.Destinations.EventModules.handle_call/3
            (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
            (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
            (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
    (elixir 1.15.7) lib/gen_server.ex:1074: GenServer.call/3
    (walex 3.8.0) lib/walex/destinations/destinations.ex:51: WalEx.Destinations.process_destinations/2
    (walex 3.8.0) lib/walex/destinations/destinations.ex:38: WalEx.Destinations.handle_call/3
    (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
    (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
    (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
Last message (from #PID<0.554.0>): {:process, %WalEx.Changes.Transaction{changes: [%WalEx.Changes.UpdatedRecord{type: "UPDATE", old_record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.535414-07:00 -07 Etc/UTC-7>}, record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.546409-07:00 -07 Etc/UTC-7>}, schema: "public", table: "user", columns: [%WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "id", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "email", type: "citext", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "name", type: "varchar", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "age", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "created_at", type: "timestamptz", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "updated_at", type: "timestamptz", type_modifier: 4294967295}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}, :test_app}
State: %{}
Client #PID<0.554.0> is alive

    (stdlib 5.1.1) gen.erl:240: :gen.do_call/4
    (elixir 1.15.7) lib/gen_server.ex:1071: GenServer.call/3
    (walex 3.8.0) lib/walex/replication/publisher.ex:69: WalEx.Replication.Publisher.handle_cast/2
    (stdlib 5.1.1) gen_server.erl:1103: :gen_server.try_handle_cast/3
    (stdlib 5.1.1) gen_server.erl:1165: :gen_server.handle_msg/6
    (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3

15:27:34.556 [error] GenServer {:walex_registry, {WalEx.Replication.Publisher, :test_app}} terminating
** (stop) exited in: GenServer.call({:via, Registry, {:walex_registry, {WalEx.Destinations, :test_app}}}, {:process, %WalEx.Changes.Transaction{changes: [%WalEx.Changes.UpdatedRecord{type: "UPDATE", old_record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.535414-07:00 -07 Etc/UTC-7>}, record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.546409-07:00 -07 Etc/UTC-7>}, schema: "public", table: "user", columns: [%WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "id", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "email", type: "citext", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "name", type: "varchar", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "age", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "created_at", type: "timestamptz", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "updated_at", type: "timestamptz", type_modifier: 4294967295}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}, :test_app}, :infinity)
    ** (EXIT) exited in: GenServer.call({:via, Registry, {:walex_registry, {WalEx.Destinations.EventModules, :test_app}}}, {:process, %WalEx.Changes.Transaction{changes: [%WalEx.Changes.UpdatedRecord{type: "UPDATE", old_record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.535414-07:00 -07 Etc/UTC-7>}, record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.546409-07:00 -07 Etc/UTC-7>}, schema: "public", table: "user", columns: [%WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "id", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "email", type: "citext", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "name", type: "varchar", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "age", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "created_at", type: "timestamptz", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "updated_at", type: "timestamptz", type_modifier: 4294967295}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}, :test_app}, :infinity)
        ** (EXIT) an exception was raised:
            ** (RuntimeError) Process error
                test/walex/event/event_test.exs:144: TestApp.TestModule.process_all/1
                (elixir 1.15.7) lib/enum.ex:984: Enum."-each/2-lists^foreach/1-0-"/2
                (walex 3.8.0) lib/walex/destinations/event_modules.ex:37: WalEx.Destinations.EventModules.handle_call/3
                (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
                (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
                (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
    (elixir 1.15.7) lib/gen_server.ex:1074: GenServer.call/3
    (walex 3.8.0) lib/walex/replication/publisher.ex:69: WalEx.Replication.Publisher.handle_cast/2
    (stdlib 5.1.1) gen_server.erl:1103: :gen_server.try_handle_cast/3
    (stdlib 5.1.1) gen_server.erl:1165: :gen_server.handle_msg/6
    (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
Last message: {:"$gen_cast", %{message: %WalEx.Decoder.Messages.Commit{flags: [], lsn: {0, 179231608}, end_lsn: {0, 179231656}, commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}, app_name: :test_app}}
State: %WalEx.Replication.Publisher.State{relations: %{87111 => %WalEx.Decoder.Messages.Relation{id: 87111, namespace: "public", name: "user", replica_identity: :all_columns, columns: [%WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "id", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "email", type: "citext", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "name", type: "varchar", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "age", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "created_at", type: "timestamptz", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "updated_at", type: "timestamptz", type_modifier: 4294967295}]}}, transaction: {{0, 179231608}, %WalEx.Changes.Transaction{changes: [%WalEx.Changes.UpdatedRecord{type: "UPDATE", old_record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.535414-07:00 -07 Etc/UTC-7>}, record: %{id: 1, name: "John Doe", age: 30, created_at: #DateTime<2024-04-09 10:31:26.282598-07:00 -07 Etc/UTC-7>, email: "john.doe@example.com", updated_at: #DateTime<2024-04-09 12:27:34.546409-07:00 -07 Etc/UTC-7>}, schema: "public", table: "user", columns: [%WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "id", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "email", type: "citext", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "name", type: "varchar", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "age", type: "int4", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "created_at", type: "timestamptz", type_modifier: 4294967295}, %WalEx.Decoder.Messages.Relation.Column{flags: [:key], name: "updated_at", type: "timestamptz", type_modifier: 4294967295}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}], commit_timestamp: ~U[2024-04-09 19:27:34.548213Z]}}, types: %{86994 => "citext"}}
.........................
15:27:36.649 [info] Database is running.
.
15:27:37.668 [info] Database is running.
.
Finished in 15.6 seconds (0.00s async, 15.6s sync)
1 doctest, 50 tests, 0 failures

Randomized with seed 19559

Could you provide any guidance around why the test results might be different, or how what needs to be fixed here? I'm seeing the output above when I run tests on bc06febe (the commit before the socket_options merge) or on this branch.

cpursley commented 4 months ago

I see this sometimes and think it's related to Registry not get set fast enough. I need to fix the test running at some point but not time at the moment, so I'll go ahead and merge.

DaemonSnake commented 4 months ago

@oortlieb @cpursley any idea how to fix the tests ? It's been 3 weeks. I can help maybe if you don't have the time.