fuelen / ecto_dev_logger

An alternative logger for Ecto queries
Apache License 2.0
151 stars 16 forks source link

Allow logging for Ecto.ParameterizedType tuples #4

Closed emaiax closed 2 years ago

emaiax commented 2 years ago

First of all, thank you so much for this lib, it's so handy and awesome.

Context

I have multiple Ecto.ParameterizedType using Postgres types in the DB that can't be logged, raising the error below:

21:14:03.451 [error] Handler "ecto.dev_logger" has failed and has been detached. Class=:error
Reason=:function_clause
Stacktrace=[
  {Ecto.DevLogger, :stringify_ecto_params, [{"BRL", #Decimal<0>}, :root],
   [file: 'lib/ecto/dev_logger.ex', line: 137]},
  {Ecto.DevLogger, :"-telemetry_handler/4-fun-0-", 4,
   [file: 'lib/ecto/dev_logger.ex', line: 56]},
  {Enum, :"-reduce/3-lists^foldl/2-0-", 3, [file: 'lib/enum.ex', line: 2356]},
  {Ecto.DevLogger, :telemetry_handler, 4,
   [file: 'lib/ecto/dev_logger.ex', line: 52]},
  {:telemetry, :"-execute/3-fun-0-", 4,
   [
     file: '/Users/myuser/code/myapp/api/deps/telemetry/src/telemetry.erl',
     line: 135
   ]},
  {:lists, :foreach, 2, [file: 'lists.erl', line: 1342]},
  {Ecto.Adapters.SQL, :log, 4, [file: 'lib/ecto/adapters/sql.ex', line: 927]},
  {DBConnection, :log, 5, [file: 'lib/db_connection.ex', line: 1479]},
  {Postgrex, :query, 4, [file: 'lib/postgrex.ex', line: 312]},
  {Ecto.Adapters.SQL, :struct, 10,
   [file: 'lib/ecto/adapters/sql.ex', line: 802]},
  {Ecto.Repo.Schema, :apply, 4, [file: 'lib/ecto/repo/schema.ex', line: 744]},
  {Ecto.Repo.Schema, :"-do_insert/4-fun-1-", 15,
   [file: 'lib/ecto/repo/schema.ex', line: 367]},
  {Ecto.Repo.Schema, :"-wrap_in_transaction/6-fun-0-", 3,
   [file: 'lib/ecto/repo/schema.ex', line: 985]},
  {Ecto.Adapters.SQL, :"-checkout_or_transaction/4-fun-0-", 3,
   [file: 'lib/ecto/adapters/sql.ex', line: 1021]},
  {DBConnection, :run_transaction, 4,
   [file: 'lib/db_connection.ex', line: 1531]},
  {Ecto.Repo.Schema, :insert!, 4, [file: 'lib/ecto/repo/schema.ex', line: 269]},
  {MyApp.Transactions.SearchTest, :__ex_unit_setup_1, 1,
   [file: 'test/myapp/transactions/search_test.exs', line: 10]},
  {MyApp.Transactions.SearchTest, :__ex_unit__, 2,
   [file: 'test/myapp/transactions/search_test.exs', line: 1]},
  {ExUnit.Runner, :exec_test_setup, 2,
   [file: 'lib/ex_unit/runner.ex', line: 495]},
  {ExUnit.Runner, :"-spawn_test_monitor/4-fun-0-", 2,
   [file: 'lib/ex_unit/runner.ex', line: 454]}
]

Changes

Since ParameterizedTypes are dumped to the DB as tuples, this PR will allow more complex Ecto.ParameterizedType to be logged as well.

[debug] QUERY OK db=9.0ms
INSERT INTO "posts" ("array_of_strings","date","datetime","decimal","integer","map","money","multi_money","naive_datetime","string") VALUES ('{hello,world}','2022-04-15','2022-04-15T22:05:37.850495Z',0.12,0,'{"test":true}','(USD, 390)','{"(USD, 230)","(USD, 180)"}','2022-04-15T22:05:37.851978','Post 1') RETURNING "id"

Please note that after this change, I started to see the following debug log. Thoughts?

[debug] %Postgrex.Query{cache: :statement, columns: nil, name: "ecto_insert_posts_0", param_formats: nil, param_oids: nil, param_types: nil, ref: nil, result_formats: nil, result_oids: nil, result_types: nil, statement: "INSERT INTO \"posts\" (\"array_of_strings\",\"date\",\"datetime\",\"decimal\",\"integer\",\"map\",\"money\",\"multi_money\",\"naive_datetime\",\"string\") VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10) RETURNING \"id\"", types: nil} uses unknown oid(s) 563461, 563462forcing us to reload type information from the database. This is expected behaviour whenever you migrate your database.
fuelen commented 2 years ago

Hi Eduardo!

Good catch! Thank you for the contribution. Could you, please, also add a test for a list of parameterized types?

emaiax commented 2 years ago

@fuelen done! thanks for the tip! :)

fuelen commented 2 years ago

@emaiax Thank you!