Adding start_from: :current made the problem more reproducible but I could not find a solution.
I built a short repository that reproduces the issue when running mix test. On my side, error messages show up more than 50% of the time I run mix test.
The repo is available at: GitHub - datafoo/elixir-1.15-registry-issue · GitHub
Thank you for your help so far.
Extra advice: include a .tool-versions file in the repo, and put some little README.md file to describe what is this repository reproducing as a problem. A screenshot or copied logging output should orient any visitor.
I have managed to drastically improve the reproducibility of the issue by creating tests that execute very fast:
defmodule MyApp.Facility.EventStoreRegistryTest do
use MyApp.CqrsCase
describe "fast test" do
@tag :integration
test "1" do
assert true
end
@tag :integration
test "2" do
assert true
end
@tag :integration
test "3" do
assert true
end
end
end
Here are the results:
# mix test
.15:57:48.962 [error] GenServer {MyApp.EventStore.EventStore.Subscriptions.Registry, {"$all", "CascadeSelectorMarkedAsNonexistent"}} terminating
** (ArgumentError) unknown registry: MyApp.EventStore.EventStore.PubSub
(elixir 1.15.7) lib/registry.ex:1391: Registry.info!/1
(elixir 1.15.7) lib/registry.ex:1007: Registry.register/3
(eventstore 1.4.7) lib/event_store/pubsub.ex:38: EventStore.PubSub.subscribe/3
(eventstore 1.4.7) lib/event_store/subscriptions/subscription_fsm.ex:70: EventStore.Subscriptions.SubscriptionFsm.transition/3
(eventstore 1.4.7) lib/event_store/subscriptions/subscription.ex:221: EventStore.Subscriptions.Subscription.handle_call/3
(stdlib 4.3.1.6) gen_server.erl:1149: :gen_server.try_handle_call/4
(stdlib 4.3.1.6) gen_server.erl:1178: :gen_server.handle_msg/6
(stdlib 4.3.1.6) proc_lib.erl:240: :proc_lib.init_p_do_apply/3
Last message (from #PID<0.367.0>): {:connect, #PID<0.367.0>, [retry_interval: 60000, hibernate_after: 15000, partition_by: nil, concurrency_limit: 1, name: MyApp.EventStore, mapper: &Commanded.EventStore.Adapters.EventStore.Mapper.from_recorded_event/1, conn: MyApp.EventStore.Postgrex, event_store: MyApp.EventStore, query_timeout: 15000, schema: "public", serializer: Commanded.Serialization.JsonSerializer, stream_uuid: "$all", subscription_name: "CascadeSelectorMarkedAsNonexistent", start_from: 0]}
domain=otp file=gen_server.erl line=1402 mfa=:gen_server.error_info/8 pid=<0.368.0>
.15:57:49.090 [error] GenServer {MyApp.EventStore.EventStore.Subscriptions.Registry, {"$all", "CascadeSelectorMarkedAsNonexistent"}} terminating
** (ArgumentError) unknown registry: MyApp.EventStore.EventStore.PubSub
(elixir 1.15.7) lib/registry.ex:1391: Registry.info!/1
(elixir 1.15.7) lib/registry.ex:1007: Registry.register/3
(eventstore 1.4.7) lib/event_store/pubsub.ex:38: EventStore.PubSub.subscribe/3
(eventstore 1.4.7) lib/event_store/subscriptions/subscription_fsm.ex:70: EventStore.Subscriptions.SubscriptionFsm.transition/3
(eventstore 1.4.7) lib/event_store/subscriptions/subscription.ex:221: EventStore.Subscriptions.Subscription.handle_call/3
(stdlib 4.3.1.6) gen_server.erl:1149: :gen_server.try_handle_call/4
(stdlib 4.3.1.6) gen_server.erl:1178: :gen_server.handle_msg/6
(stdlib 4.3.1.6) proc_lib.erl:240: :proc_lib.init_p_do_apply/3
Last message (from #PID<0.428.0>): {:connect, #PID<0.428.0>, [retry_interval: 60000, hibernate_after: 15000, partition_by: nil, concurrency_limit: 1, name: MyApp.EventStore, mapper: &Commanded.EventStore.Adapters.EventStore.Mapper.from_recorded_event/1, conn: MyApp.EventStore.Postgrex, event_store: MyApp.EventStore, query_timeout: 15000, schema: "public", serializer: Commanded.Serialization.JsonSerializer, stream_uuid: "$all", subscription_name: "CascadeSelectorMarkedAsNonexistent", start_from: 0]}
domain=otp file=gen_server.erl line=1402 mfa=:gen_server.error_info/8 pid=<0.430.0>
.
Finished in 0.4 seconds (0.00s async, 0.4s sync)
3 tests, 0 failures
Randomized with seed 521679
What is relevant is in MyApp.CqrsCase which follows the documentation:
defmodule MyApp.CqrsCase do
@moduledoc false
use ExUnit.CaseTemplate
using do
quote do
import Ecto
import Ecto.Changeset
import Ecto.Query
end
end
setup do
{:ok, _} = Application.ensure_all_started(:myapp)
on_exit(fn ->
# Uncomment to prevent `unknown registry: MyApp.EventStore.EventStore.PubSub` error messages
# :timer.sleep(100)
:ok = Application.stop(:myapp)
MyApp.Storage.reset!()
end)
:ok
end
end
Somehow, since Elixir 1.15, things are going too fast and slowing down the test cleanup by adding :timer.sleep(100) right before :ok = Application.stop(:myapp) make the error messages disappear.
The test results are predictable. There is exactly a total of N-1 error messages with N being the amount of tests. And it is the first test which does not trigger an error message.
Interesting,
Elixir v1.15 is a smaller release with focused improvements on compilation and boot times.
I also see commanded uses elixir 1.12
This appears to resolve the issue, can you run against that branch and let me know how it goes?
