search

commanded / commanded-extreme-adapter

Extreme event store adapter for Commanded
MIT License
12 stars 18 forks source link

[Subscription] Event handlers receive no events #3

Closed sascha-wolf closed 7 years ago

sascha-wolf commented 7 years ago

As it stands commanded event handlers do not seem to receive any events.

Test event handler

I've implemented a test handler which listens for any event and logs it to the console:

defmodule TestEventHandler do
  @behaviour Commanded.Event.Handler

  require Logger

  def start_link do
    Commanded.Event.Handler.start_link("test_handler", __MODULE__)
  end

  def handle(any_event, _metadata) do
    Logger.info "EVENT: #{inspect any_event}"

    :ok
  end
end

This test handler is being started by a simple Supervisor which in turn is being started by the application. I've verified that the event handler is indeed running using :observer.start() and checking the Persistent Subscriptions tab from the EventStore web UI.

EventStore configuration

Furthermore I've verified that the EventStore is indeed running with the necessary configuration options; see the output from the EventStore start:

[00001,01,14:25:30.844] 
ES VERSION:               4.0.1.0 (HEAD/5f53330a4cc31fc6eb8b337cc630038b40a4f47a, Wed, 12 Apr 2017 15:28:32 +0200)
[00001,01,14:25:30.881] OS:                       Linux (Unix 4.9.36.0)
[00001,01,14:25:30.889] RUNTIME:                  4.6.2 (Stable 4.6.2.16/ac9e222) (64-bit)
[00001,01,14:25:30.889] GC:                       2 GENERATIONS
[00001,01,14:25:30.889] LOGS:                     /var/log/eventstore
[00001,01,14:25:30.903] MODIFIED OPTIONS:

        START STANDARD PROJECTIONS: true (Environment Variable)
        CLUSTER GOSSIP PORT:      2112 (Environment Variable)
        RUN PROJECTIONS:          All (Environment Variable)
        INT IP:                   0.0.0.0 (Config File)
        EXT IP:                   0.0.0.0 (Config File)
        INT HTTP PREFIXES:        http://*:2112/ (Config File)
        EXT HTTP PREFIXES:        http://*:2113/ (Config File)
        ADD INTERFACE PREFIXES:   false (Config File)

Testing

After dispatching a few test commands to commanded I've verified that the events are being written to EventStore (checked the web UI).

It seems that the subscription of the event handler never receives any kind of events.

While trying to boil down the problem, I've run the tests from the adapter which resulted in some failed tests (Output in a comment below).

How to proceed?

Can you give some input on the issue? We tried to track down the culprit in our team but as it stands we are not sure where to start. We would be happy to fix any problems and submit a pull request, as soon as we know what needs to be done.

sascha-wolf commented 7 years ago

Test Output

warning: variable "desc" does not exist and is being expanded to "desc()", please use parentheses to remove the ambiguity or change the variable name
  /Users/swolf/dev/libs/elixir/commanded-extreme-adapter/deps/docker/mix.exs:8

warning: variable "package" does not exist and is being expanded to "package()", please use parentheses to remove the ambiguity or change the variable name
  /Users/swolf/dev/libs/elixir/commanded-extreme-adapter/deps/docker/mix.exs:9

warning: variable "deps" does not exist and is being expanded to "deps()", please use parentheses to remove the ambiguity or change the variable name
  /Users/swolf/dev/libs/elixir/commanded-extreme-adapter/deps/docker/mix.exs:10

16:32:37.126 [info]  Connecting Extreme to localhost:1113

16:32:37.147 [info]  Successfully connected to EventStore @ localhost:1113
warning: default arguments in assert_receive_events/3 are never used
  deps/commanded/test/event_store_adapter/subscription_test.exs:177

.
16:33:20.322 [info]  Stopping persistent subscription "$ce-commandedtest::subscriber" as subscriber is down due to: {:shutdown, :subscriber_shutdown}

  1) test subscribe to all streams should receive events appended to any stream (Commanded.EventStore.Adapter.SubscriptionTest)
     deps/commanded/test/event_store_adapter/subscription_test.exs:57
     ** (MatchError) no match of right hand side value: {:error, :wrong_expected_version}
     stacktrace:
       deps/commanded/test/event_store_adapter/subscription_test.exs:62: (test)

     The following output was logged:

     16:33:08.942 [info]  Application commanded exited: :stopped

     16:33:08.942 [info]  Application commanded_extreme_adapter exited: :stopped

     16:33:08.942 [info]  Application extreme exited: :stopped

     16:33:08.943 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/kill [] "" [async: true, stream_to: #PID<0.272.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:08.948 [debug] delete http://localhost:2375/containers/commanded-tests-eventstore [] "" [async: true, stream_to: #PID<0.272.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:08.956 [debug] post http://localhost:2375/containers/create?name=commanded-tests-eventstore [{"Content-Type", "application/json"}] "{\"Env\":[\"EVENTSTORE_DB=/tmp/db\",\"EVENTSTORE_RUN_PROJECTIONS=All\",\"EVENTSTORE_START_STANDARD_PROJECTIONS=True\"],\"ExposedPorts\":{\"1113/tcp\":{},\"2113/tcp\":{}},\"Image\":\"eventstore/eventstore\",\"PortBindings\":{\"1113/tcp\":[{\"HostPort\":\"1113\"}],\"2113/tcp\":[{\"HostPort\":\"2113\"}]}}" [async: true, stream_to: #PID<0.272.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:09.113 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/start [] "" [async: true, stream_to: #PID<0.272.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:10.308 [info]  Connecting Extreme to localhost:1113

     16:33:10.309 [debug] Extreme event store subscribe to stream: "$ce-commandedtest", start from: :origin

     16:33:10.309 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:10.313 [info]  Connecting Extreme to localhost:1113

     16:33:10.314 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:10.317 [debug] Successfully connected to persistent subscription id: "$ce-commandedtest::subscriber"

     16:33:20.313 [debug] Extreme event store attempting to append to stream "commandedtest-stream1" 1 event(s)

     16:33:20.320 [info]  Extreme eventstore wrong expected version "0" due to: %Extreme.Msg.WriteEventsCompleted{commit_position: 0, first_event_number: -2147483648, last_event_number: -2147483648, message: "Wrong expected version.", prepare_position: -2147483648, result: :WrongExpectedVersion}

     16:33:20.322 [debug] Extreme event store subscription down due to: :shutdown

     16:33:20.322 [info]  Stopping persistent subscription "$ce-commandedtest::subscriber" as subscriber is down due to: {:shutdown, :subscriber_shutdown}

  2) test unsubscribe from all streams should not receive further events appended to any stream (Commanded.EventStore.Adapter.SubscriptionTest)
     deps/commanded/test/event_store_adapter/subscription_test.exs:121
     ** (MatchError) no match of right hand side value: {:error, :wrong_expected_version}
     stacktrace:
       deps/commanded/test/event_store_adapter/subscription_test.exs:124: (test)

     The following output was logged:

     16:33:20.325 [info]  Application commanded exited: :stopped

     16:33:20.327 [info]  Application commanded_extreme_adapter exited: :stopped

     16:33:20.327 [info]  Application extreme exited: :stopped

     16:33:20.327 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/kill [] "" [async: true, stream_to: #PID<0.303.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:20.329 [debug] delete http://localhost:2375/containers/commanded-tests-eventstore [] "" [async: true, stream_to: #PID<0.303.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:20.337 [debug] post http://localhost:2375/containers/create?name=commanded-tests-eventstore [{"Content-Type", "application/json"}] "{\"Env\":[\"EVENTSTORE_DB=/tmp/db\",\"EVENTSTORE_RUN_PROJECTIONS=All\",\"EVENTSTORE_START_STANDARD_PROJECTIONS=True\"],\"ExposedPorts\":{\"1113/tcp\":{},\"2113/tcp\":{}},\"Image\":\"eventstore/eventstore\",\"PortBindings\":{\"1113/tcp\":[{\"HostPort\":\"1113\"}],\"2113/tcp\":[{\"HostPort\":\"2113\"}]}}" [async: true, stream_to: #PID<0.303.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:20.437 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/start [] "" [async: true, stream_to: #PID<0.303.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:21.615 [info]  Connecting Extreme to localhost:1113

     16:33:21.616 [debug] Extreme event store subscribe to stream: "$ce-commandedtest", start from: :origin

     16:33:21.617 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:21.620 [info]  Connecting Extreme to localhost:1113

     16:33:21.620 [debug] Extreme event store attempting to append to stream "commandedtest-stream1" 1 event(s)

     16:33:21.621 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:21.624 [info]  Extreme eventstore wrong expected version "0" due to: %Extreme.Msg.WriteEventsCompleted{commit_position: 0, first_event_number: -2147483648, last_event_number: -2147483648, message: "Wrong expected version.", prepare_position: -2147483648, result: :WrongExpectedVersion}

     16:33:21.624 [debug] Extreme event store subscription down due to: :shutdown

.

  3) test resume subscription should remember last seen event number when subscription resumes (Commanded.EventStore.Adapter.SubscriptionTest)
     deps/commanded/test/event_store_adapter/subscription_test.exs:142
     ** (MatchError) no match of right hand side value: {:error, :wrong_expected_version}
     stacktrace:
       deps/commanded/test/event_store_adapter/subscription_test.exs:143: (test)

     The following output was logged:

     16:33:22.962 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:22.963 [info]  Application commanded exited: :stopped

     16:33:22.963 [info]  Application commanded_extreme_adapter exited: :stopped

     16:33:22.963 [info]  Application extreme exited: :stopped

     16:33:22.963 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/kill [] "" [async: true, stream_to: #PID<0.365.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:22.966 [debug] delete http://localhost:2375/containers/commanded-tests-eventstore [] "" [async: true, stream_to: #PID<0.365.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:22.974 [debug] post http://localhost:2375/containers/create?name=commanded-tests-eventstore [{"Content-Type", "application/json"}] "{\"Env\":[\"EVENTSTORE_DB=/tmp/db\",\"EVENTSTORE_RUN_PROJECTIONS=All\",\"EVENTSTORE_START_STANDARD_PROJECTIONS=True\"],\"ExposedPorts\":{\"1113/tcp\":{},\"2113/tcp\":{}},\"Image\":\"eventstore/eventstore\",\"PortBindings\":{\"1113/tcp\":[{\"HostPort\":\"1113\"}],\"2113/tcp\":[{\"HostPort\":\"2113\"}]}}" [async: true, stream_to: #PID<0.365.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:23.088 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/start [] "" [async: true, stream_to: #PID<0.365.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:24.764 [info]  Connecting Extreme to localhost:1113

     16:33:24.764 [debug] Extreme event store attempting to append to stream "commandedtest-stream1" 1 event(s)

     16:33:24.765 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:24.768 [info]  Extreme eventstore wrong expected version "0" due to: %Extreme.Msg.WriteEventsCompleted{commit_position: 0, first_event_number: -2147483648, last_event_number: -2147483648, message: "Wrong expected version.", prepare_position: -2147483648, result: :WrongExpectedVersion}

  4) test catch-up subscription should receive any existing events (Commanded.EventStore.Adapter.SubscriptionTest)
     deps/commanded/test/event_store_adapter/subscription_test.exs:101
     ** (MatchError) no match of right hand side value: {:error, :wrong_expected_version}
     stacktrace:
       deps/commanded/test/event_store_adapter/subscription_test.exs:102: (test)

     The following output was logged:

     16:33:24.768 [info]  Application commanded exited: :stopped

     16:33:24.769 [info]  Application commanded_extreme_adapter exited: :stopped

     16:33:24.769 [info]  Application extreme exited: :stopped

     16:33:24.769 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/kill [] "" [async: true, stream_to: #PID<0.391.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:24.771 [debug] delete http://localhost:2375/containers/commanded-tests-eventstore [] "" [async: true, stream_to: #PID<0.391.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:24.780 [debug] post http://localhost:2375/containers/create?name=commanded-tests-eventstore [{"Content-Type", "application/json"}] "{\"Env\":[\"EVENTSTORE_DB=/tmp/db\",\"EVENTSTORE_RUN_PROJECTIONS=All\",\"EVENTSTORE_START_STANDARD_PROJECTIONS=True\"],\"ExposedPorts\":{\"1113/tcp\":{},\"2113/tcp\":{}},\"Image\":\"eventstore/eventstore\",\"PortBindings\":{\"1113/tcp\":[{\"HostPort\":\"1113\"}],\"2113/tcp\":[{\"HostPort\":\"2113\"}]}}" [async: true, stream_to: #PID<0.391.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:24.946 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/start [] "" [async: true, stream_to: #PID<0.391.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:26.095 [info]  Connecting Extreme to localhost:1113

     16:33:26.095 [debug] Extreme event store attempting to append to stream "commandedtest-stream1" 1 event(s)

     16:33:26.096 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:26.099 [info]  Extreme eventstore wrong expected version "0" due to: %Extreme.Msg.WriteEventsCompleted{commit_position: 0, first_event_number: -2147483648, last_event_number: -2147483648, message: "Wrong expected version.", prepare_position: -2147483648, result: :WrongExpectedVersion}

.....

  5) test stream events from a stream should read events (Commanded.EventStore.Adapter.AppendEventsTest)
     deps/commanded/test/event_store_adapter/append_events_test.exs:32
     Assertion with == failed
     code:  {:ok, 4} == @event_store.append_to_stream("stream", 0, events)
     left:  {:ok, 4}
     right: {:error, :wrong_expected_version}
     stacktrace:
       deps/commanded/test/event_store_adapter/append_events_test.exs:35: (test)

     The following output was logged:

     16:33:32.958 [info]  Application commanded exited: :stopped

     16:33:32.958 [info]  Application commanded_extreme_adapter exited: :stopped

     16:33:32.958 [info]  Application extreme exited: :stopped

     16:33:32.958 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/kill [] "" [async: true, stream_to: #PID<0.551.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:32.961 [debug] delete http://localhost:2375/containers/commanded-tests-eventstore [] "" [async: true, stream_to: #PID<0.551.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:32.967 [debug] post http://localhost:2375/containers/create?name=commanded-tests-eventstore [{"Content-Type", "application/json"}] "{\"Env\":[\"EVENTSTORE_DB=/tmp/db\",\"EVENTSTORE_RUN_PROJECTIONS=All\",\"EVENTSTORE_START_STANDARD_PROJECTIONS=True\"],\"ExposedPorts\":{\"1113/tcp\":{},\"2113/tcp\":{}},\"Image\":\"eventstore/eventstore\",\"PortBindings\":{\"1113/tcp\":[{\"HostPort\":\"1113\"}],\"2113/tcp\":[{\"HostPort\":\"2113\"}]}}" [async: true, stream_to: #PID<0.551.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:33.087 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/start [] "" [async: true, stream_to: #PID<0.551.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:34.304 [info]  Connecting Extreme to localhost:1113

     16:33:34.304 [debug] Extreme event store attempting to append to stream "commandedtest-stream" 4 event(s)

     16:33:34.305 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:34.308 [info]  Extreme eventstore wrong expected version "0" due to: %Extreme.Msg.WriteEventsCompleted{commit_position: 0, first_event_number: -2147483648, last_event_number: -2147483648, message: "Wrong expected version.", prepare_position: -2147483648, result: :WrongExpectedVersion}

.

  6) test stream events from a stream should read from single stream (Commanded.EventStore.Adapter.AppendEventsTest)
     deps/commanded/test/event_store_adapter/append_events_test.exs:48
     Assertion with == failed
     code:  {:ok, 2} == @event_store.append_to_stream("stream", 0, events1)
     left:  {:ok, 2}
     right: {:error, :wrong_expected_version}
     stacktrace:
       deps/commanded/test/event_store_adapter/append_events_test.exs:52: (test)

     The following output was logged:

     16:33:35.682 [info]  Application commanded exited: :stopped

     16:33:35.683 [info]  Application commanded_extreme_adapter exited: :stopped

     16:33:35.683 [info]  Application extreme exited: :stopped

     16:33:35.683 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/kill [] "" [async: true, stream_to: #PID<0.604.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:35.686 [debug] delete http://localhost:2375/containers/commanded-tests-eventstore [] "" [async: true, stream_to: #PID<0.604.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:35.695 [debug] post http://localhost:2375/containers/create?name=commanded-tests-eventstore [{"Content-Type", "application/json"}] "{\"Env\":[\"EVENTSTORE_DB=/tmp/db\",\"EVENTSTORE_RUN_PROJECTIONS=All\",\"EVENTSTORE_START_STANDARD_PROJECTIONS=True\"],\"ExposedPorts\":{\"1113/tcp\":{},\"2113/tcp\":{}},\"Image\":\"eventstore/eventstore\",\"PortBindings\":{\"1113/tcp\":[{\"HostPort\":\"1113\"}],\"2113/tcp\":[{\"HostPort\":\"2113\"}]}}" [async: true, stream_to: #PID<0.604.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:35.836 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/start [] "" [async: true, stream_to: #PID<0.604.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:37.056 [info]  Connecting Extreme to localhost:1113

     16:33:37.056 [debug] Extreme event store attempting to append to stream "commandedtest-stream" 2 event(s)

     16:33:37.057 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:37.060 [info]  Extreme eventstore wrong expected version "0" due to: %Extreme.Msg.WriteEventsCompleted{commit_position: 0, first_event_number: -2147483648, last_event_number: -2147483648, message: "Wrong expected version.", prepare_position: -2147483648, result: :WrongExpectedVersion}

  7) test append events to a stream should fail to append to a stream because of wrong expected version (Commanded.EventStore.Adapter.AppendEventsTest)
     deps/commanded/test/event_store_adapter/append_events_test.exs:24
     Assertion with == failed
     code:  {:ok, 2} == @event_store.append_to_stream("stream", 0, build_events(2))
     left:  {:ok, 2}
     right: {:error, :wrong_expected_version}
     stacktrace:
       deps/commanded/test/event_store_adapter/append_events_test.exs:25: (test)

     The following output was logged:

     16:33:37.062 [info]  Application commanded exited: :stopped

     16:33:37.063 [info]  Application commanded_extreme_adapter exited: :stopped

     16:33:37.063 [info]  Application extreme exited: :stopped

     16:33:37.063 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/kill [] "" [async: true, stream_to: #PID<0.631.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:37.065 [debug] delete http://localhost:2375/containers/commanded-tests-eventstore [] "" [async: true, stream_to: #PID<0.631.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:37.074 [debug] post http://localhost:2375/containers/create?name=commanded-tests-eventstore [{"Content-Type", "application/json"}] "{\"Env\":[\"EVENTSTORE_DB=/tmp/db\",\"EVENTSTORE_RUN_PROJECTIONS=All\",\"EVENTSTORE_START_STANDARD_PROJECTIONS=True\"],\"ExposedPorts\":{\"1113/tcp\":{},\"2113/tcp\":{}},\"Image\":\"eventstore/eventstore\",\"PortBindings\":{\"1113/tcp\":[{\"HostPort\":\"1113\"}],\"2113/tcp\":[{\"HostPort\":\"2113\"}]}}" [async: true, stream_to: #PID<0.631.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:37.218 [debug] post http://localhost:2375/containers/commanded-tests-eventstore/start [] "" [async: true, stream_to: #PID<0.631.0>, ssl_options: [certfile: 'docker.crt', keyfile: 'docker.key']]

     16:33:38.415 [info]  Connecting Extreme to localhost:1113

     16:33:38.415 [debug] Extreme event store attempting to append to stream "commandedtest-stream" 2 event(s)

     16:33:38.416 [info]  Successfully connected to EventStore @ localhost:1113

     16:33:38.419 [info]  Extreme eventstore wrong expected version "0" due to: %Extreme.Msg.WriteEventsCompleted{commit_position: 0, first_event_number: -2147483648, last_event_number: -2147483648, message: "Wrong expected version.", prepare_position: -2147483648, result: :WrongExpectedVersion}

Finished in 60.7 seconds
15 tests, 7 failures

Randomized with seed 162103
slashdotdash commented 7 years ago

The latest release of Commanded (v0.12) contains a new event handler macro that you could try using:

defmodule TestEventHandler do
  use Commanded.Event.Handler, name: "test_event_handler"

  require Logger

  def handle(any_event, _metadata) do
    Logger.info "EVENT: #{inspect any_event}"
    IO.puts "Received event: #{inspect any_event}"
    :ok
  end
end

Start the handler (or include in a supervisor):

TestEventHandler.start_link()

Ensure you've configured the log level to :info in the environment config:

config :logger, :console, level: :info, format: "[$level] $message\n"

Are you running the Event Store with all projections enabled and standard projections started?

Use the --run-projections=all --start-standard-projections=true flags when running the Event Store executable.

sascha-wolf commented 7 years ago

Thank you for the blazing fast response. We will definitely try the new version.

Regarding your questions: I've verified that the logging is set to the correct level. And in the issue I've mentioned that EventStore is configured correctly, as you can also see in the startup output which I've provided.

slashdotdash commented 7 years ago

Did you configure a stream prefix for the library in your environment config, as below?

config :commanded_extreme_adapter,
  serializer: Commanded.Serialization.JsonSerializer,
  stream_prefix: "commandeddev"

Have you tried running the commanded-extreme-example app? It includes the bare minimum required to host Commanded with Event Store. I'll have a check that it works with event handlers.

sascha-wolf commented 7 years ago

It seems I have found the issue, we had configured the commanded_extreme_adapter like this:

config :commanded_extreme_adapter,
  serializer: Commanded.Serialization.JsonSerializer,
  stream_prefix: "commanded-dev-"

Removing the dashes (-) in the stream_prefix solved the problem. Our now working configuration looks like this:

config :commanded_extreme_adapter,
  serializer: Commanded.Serialization.JsonSerializer,
  stream_prefix: "commandeddev"

Any idea why that happens?

slashdotdash commented 7 years ago

Good catch!

We're using Event Store's category projections for subscriptions. A category is whatever is included in the stream name, up to the first "-" character. This allows multiple instances of Commanded, or other applications, to use the same Event Store (e.g. different environments) and filters the events that are received to only those of interest.

We use the stream prefix to define the category ("prefix-stream"). So including a dash in this settting will affect the prefix.

I'll add a compile time warning to prevent this issue as it's currently undocumented and an easy trap to fall into.

slashdotdash commented 7 years ago

Take a look at the Event Store documentation for projections for more detail (by category).

slashdotdash commented 7 years ago

@Zeeker I've published commanded_extreme_adapter v0.2.0 to Hex which includes a check to prevent :stream_prefix from containing a dash character.

Thanks for identifying the cause of this issue. Hopefully this change will prevent anyone falling into this trap again.