Attribute validation escalates to "something went wrong" instead of "invalid attribute"

[smt116]

There is a potential regression between Ash 04707aafd74fe3c5439d642578bce0817fda5ced and 81842a319aa18e974c9e87905c2a30b42e5084f10bf2931a6709e26398eeb5a6 or Ash Graphql between 8d612a08bc8956e350d0cc579a8be476d1b0ba74 and 5d784606582c0bcf36570bc9245a9db8524415d2a48a92c075e306475f2eba7f.

I have an action that suppose to validate the state of a record:

update :update_interval do
  accept []

  # ...

  validate attribute_equals(:state, :active)

  change after_action(fn changeset, resource, _context ->
            # ...
          end)
end

That action is exposed via GQL API. After upgrading those two packages, I see that a test is faling now because relevant GQL mutation returns "something went wrong" instead of "invalid attribute".

Note that I have other actions that rely on Ash State Machine and these validates the state correctly - it returns a correct error if the state validation fails.

Here are logs from the action execution:

08:33:37.025 function=log/4 module=Ecto.Adapters.SQL user_id=3196e23e-931f-4005-897f-ef95a27b85f9 [debug] QUERY OK db=0.6ms idle=145.5ms
begin []
↳ Ash.Actions.Update.Bulk.run/6, at: lib/ash/actions/update/bulk.ex:243

08:33:37.035 function=log/4 module=Ecto.Adapters.SQL user_id=3196e23e-931f-4005-897f-ef95a27b85f9 [debug] QUERY ERROR source="subscriptions" db=5.3ms
UPDATE "subscriptions" AS s0 SET "updated_at" = s1."__new_updated_at", "id" = s1."__new_id" FROM (SELECT $1::timestamp::timestamp AS "__new_updated_at", (CASE WHEN ss0."state"::varchar != $2::varchar THEN ash_raise_error((jsonb_build_object('exception', $3::text, 'input', jsonb_build_object($4::text, $5::jsonb, $6::text, ss0."state"::varchar, $7::text, (jsonb_build_object($8::varchar::varchar,($9::varchar::varchar),$10::varchar::varchar,($11::varchar::varchar)))::jsonb, $12::text, $13::jsonb)))::jsonb, ss0."id"::uuid) ELSE ss0."id"::uuid END) AS "__new_id", ss0."id" AS "id", ss0."effective_at" AS "effective_at", ss0."expires_at" AS "expires_at", ss0."inserted_at" AS "inserted_at", ss0."updated_at" AS "updated_at", ss0."user_id" AS "user_id", ss0."subscription_plan_id" AS "subscription_plan_id", ss0."state" AS "state" FROM "subscriptions" AS ss0 INNER JOIN "public"."users" AS su1 ON ss0."user_id" = su1."id" WHERE (ss0."id"::uuid = $14::uuid) AND (su1."id"::text = $15::text) LIMIT $16) AS s1 WHERE (s0."id" = s1."id") RETURNING s0."id", s0."effective_at", s0."expires_at", s0."inserted_at", s0."updated_at", s0."user_id", s0."subscription_plan_id", s0."state" [~U[2024-07-19 06:33:37.026736Z], :active, "Ash.Error.Changes.InvalidAttribute", "message", "must equal %{value}", "value", "vars", :value, :active, :field, :state, "field", "state", "ac279681-c7bf-4d98-8146-66ca0ba5c321", "3196e23e-931f-4005-897f-ef95a27b85f9", 1]
↳ AshPostgres.DataLayer.update_query/4, at: lib/data_layer.ex:1405

08:33:37.036 function=log/4 module=Ecto.Adapters.SQL user_id=3196e23e-931f-4005-897f-ef95a27b85f9 [debug] QUERY OK db=0.3ms
rollback []
↳ Ash.Actions.Update.Bulk.run/6, at: lib/ash/actions/update/bulk.ex:243

08:33:37.038 function=to_errors/3 module=AshGraphql.Errors user_id=3196e23e-931f-4005-897f-ef95a27b85f9 [warning] `4e8e6f16-5637-437d-926d-89d662cf6c3c`: AshGraphql.Error not implemented for error:

** (Ash.Error.Unknown.UnknownError) unknown error: :rollback
    (ash 3.2.4) [filtered]/elixir/deps/splode/lib/splode.ex:291: Ash.Error.to_error/2
    (ash 3.2.4) lib/ash/actions/update/bulk.ex:298: Ash.Actions.Update.Bulk.run/6
    (ash_graphql 1.2.1) lib/graphql/resolver.ex:1236: AshGraphql.Graphql.Resolver.mutate/2
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:234: Absinthe.Phase.Document.Execution.Resolution.reduce_resolution/1
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:189: Absinthe.Phase.Document.Execution.Resolution.do_resolve_field/3
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:174: Absinthe.Phase.Document.Execution.Resolution.do_resolve_fields/6
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:145: Absinthe.Phase.Document.Execution.Resolution.resolve_fields/4
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:88: Absinthe.Phase.Document.Execution.Resolution.walk_result/5
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:67: Absinthe.Phase.Document.Execution.Resolution.perform_resolution/3
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:24: Absinthe.Phase.Document.Execution.Resolution.resolve_current/3
    (absinthe 1.7.6) lib/absinthe/pipeline.ex:408: Absinthe.Pipeline.run_phase/3
    (absinthe_plug 1.5.8) lib/absinthe/plug.ex:536: Absinthe.Plug.run_query/4
    (absinthe_plug 1.5.8) lib/absinthe/plug.ex:290: Absinthe.Plug.call/2
    (phoenix 1.7.14) lib/phoenix/router/route.ex:42: Phoenix.Router.Route.call/2
    (phoenix 1.7.14) lib/phoenix/router.ex:484: Phoenix.Router.__call__/5
    (coinbits 2.0.0) lib/coinbits_web/endpoint.ex:1: CoinbitsWeb.Endpoint.plug_builder_call/2
    (coinbits 2.0.0) [filtered]/elixir/deps/plug/lib/plug/debugger.ex:136: CoinbitsWeb.Endpoint."call (overridable 3)"/2
    (coinbits 2.0.0) lib/coinbits_web/endpoint.ex:1: CoinbitsWeb.Endpoint.call/2
    (phoenix 1.7.14) lib/phoenix/endpoint/sync_code_reload_plug.ex:22: Phoenix.Endpoint.SyncCodeReloadPlug.do_call/4
    (bandit 1.5.5) lib/bandit/pipeline.ex:124: Bandit.Pipeline.call_plug!/2
    (bandit 1.5.5) lib/bandit/pipeline.ex:36: Bandit.Pipeline.run/4
    (bandit 1.5.5) lib/bandit/http1/handler.ex:12: Bandit.HTTP1.Handler.handle_data/3
    (bandit 1.5.5) lib/bandit/delegating_handler.ex:18: Bandit.DelegatingHandler.handle_data/3
    (bandit 1.5.5) [filtered]/elixir/deps/thousand_island/lib/thousand_island/handler.ex:411: Bandit.DelegatingHandler.handle_continue/2
    (stdlib 5.0.2) gen_server.erl:1067: :gen_server.try_handle_continue/3
    (stdlib 5.0.2) gen_server.erl:977: :gen_server.loop/7
    (stdlib 5.0.2) proc_lib.erl:241: :proc_lib.init_p_do_apply/3

08:33:37.040 function=to_errors/3 module=AshGraphql.Errors user_id=3196e23e-931f-4005-897f-ef95a27b85f9 [warning] `7f6a56d2-e310-47d5-b06f-60717a2472ef`: AshGraphql.Error not implemented for error:

** (Ash.Error.Unknown.UnknownError) unknown error: :rollback
    (ash 3.2.4) [filtered]/elixir/deps/splode/lib/splode.ex:291: Ash.Error.to_error/2
    (ash 3.2.4) lib/ash/actions/update/bulk.ex:298: Ash.Actions.Update.Bulk.run/6
    (ash_graphql 1.2.1) lib/graphql/resolver.ex:1236: AshGraphql.Graphql.Resolver.mutate/2
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:234: Absinthe.Phase.Document.Execution.Resolution.reduce_resolution/1
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:189: Absinthe.Phase.Document.Execution.Resolution.do_resolve_field/3
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:174: Absinthe.Phase.Document.Execution.Resolution.do_resolve_fields/6
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:145: Absinthe.Phase.Document.Execution.Resolution.resolve_fields/4
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:88: Absinthe.Phase.Document.Execution.Resolution.walk_result/5
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:67: Absinthe.Phase.Document.Execution.Resolution.perform_resolution/3
    (absinthe 1.7.6) lib/absinthe/phase/document/execution/resolution.ex:24: Absinthe.Phase.Document.Execution.Resolution.resolve_current/3
    (absinthe 1.7.6) lib/absinthe/pipeline.ex:408: Absinthe.Pipeline.run_phase/3
    (absinthe_plug 1.5.8) lib/absinthe/plug.ex:536: Absinthe.Plug.run_query/4
    (absinthe_plug 1.5.8) lib/absinthe/plug.ex:290: Absinthe.Plug.call/2
    (phoenix 1.7.14) lib/phoenix/router/route.ex:42: Phoenix.Router.Route.call/2
    (phoenix 1.7.14) lib/phoenix/router.ex:484: Phoenix.Router.__call__/5
    (coinbits 2.0.0) lib/coinbits_web/endpoint.ex:1: CoinbitsWeb.Endpoint.plug_builder_call/2
    (coinbits 2.0.0) [filtered]/elixir/deps/plug/lib/plug/debugger.ex:136: CoinbitsWeb.Endpoint."call (overridable 3)"/2
    (coinbits 2.0.0) lib/coinbits_web/endpoint.ex:1: CoinbitsWeb.Endpoint.call/2
    (phoenix 1.7.14) lib/phoenix/endpoint/sync_code_reload_plug.ex:22: Phoenix.Endpoint.SyncCodeReloadPlug.do_call/4
    (bandit 1.5.5) lib/bandit/pipeline.ex:124: Bandit.Pipeline.call_plug!/2
    (bandit 1.5.5) lib/bandit/pipeline.ex:36: Bandit.Pipeline.run/4
    (bandit 1.5.5) lib/bandit/http1/handler.ex:12: Bandit.HTTP1.Handler.handle_data/3
    (bandit 1.5.5) lib/bandit/delegating_handler.ex:18: Bandit.DelegatingHandler.handle_data/3
    (bandit 1.5.5) [filtered]/elixir/deps/thousand_island/lib/thousand_island/handler.ex:411: Bandit.DelegatingHandler.handle_continue/2
    (stdlib 5.0.2) gen_server.erl:1067: :gen_server.try_handle_continue/3
    (stdlib 5.0.2) gen_server.erl:977: :gen_server.loop/7
    (stdlib 5.0.2) proc_lib.erl:241: :proc_lib.init_p_do_apply/3

08:33:37.041 function=phoenix_endpoint_stop/4 module=Phoenix.Logger user_id=3196e23e-931f-4005-897f-ef95a27b85f9 [info] Sent 200 in 235ms

[zachdaniel]

I fixed a bug remarkably similar to this in ash core recently. Just want to double check that latest of ash, ash_graphql, and ash_state_machine don't resolve the issue.

[smt116]

The issue exists on the latest branches of these packages. Tested via:

      # Ash Framework and its dependencies
      {:ash,
       github: "ash-project/ash", sha: "3c2f51224a767b6487decd538af1e0299096dcac", override: true},
      {:ash_appsignal, "~> 0.1.3"},
      {:ash_authentication_phoenix, "~> 2.0.0"},
      {:ash_authentication, "~> 4.0.0"},
      {:ash_graphql,
       github: "ash-project/ash_graphql", sha: "3e5cf20023f3990aff2d66c7307e3479d2a357ad"},
      {:ash_oban, "0.2.3"},
      {:ash_phoenix, "~> 2.0.2"},
      {:ash_postgres, "~> 2.0.8"},
      {:ash_state_machine,
       github: "ash-project/ash_state_machine", sha: "4549fb277d992134fc7f6de4bac359b88476e667"},
      {:picosat_elixir, "~> 0.2"},

[zachdaniel]

I'll have to get a reproduction set up. Hopefully within the next few days. Is something that is being called in the after_action hook raising an error or rolling back the transaction? Will need to narrow down the likely causes to reproduce it.

[smt116]

I've removed everything and tried again with 3.2.6 and latest branches and seems to be working now. I have no idea what get changed but seems to be resolved now.