Skip to content

mix ecto.migrate --log-sql is broken #11

@wojtekmach

Description

@wojtekmach

Environment

  • Elixir version (elixir -v): master
  • Ecto version (mix deps): master
  • Database adapter and version (mix deps): postgrex master

Current behavior

Note, without --log-sql everything is fine.

hexpm[wm-ecto-3]% mix ecto.migrate --log-sql
[debug] QUERY OK source="schema_migrations" db=1.1ms
SELECT s0."version"::bigint FROM "schema_migrations" AS s0 FOR UPDATE []
[info] == Running Hexpm.Repo.Migrations.AddServiceToUsers.up/0 forward
[info] alter table users
[error] an exception was raised logging %DBConnection.LogEntry{call: :prepare_execute, connection_time: 12329000, decode_time: 14000, params: [], pool_time: nil, query: %Postgrex.Query{cache: :reference, columns: nil, name: "", param_formats: nil, param_oids: nil, param_types: nil, ref: nil, result_formats: nil, result_oids: nil, result_types: nil, statement: ["ALTER TABLE ", [34, "users", 34], 32, [[], "ADD COLUMN ", [34, "service", 34], 32, "boolean", [[" DEFAULT ", "false"], []]], []], types: nil}, result: {:ok, %Postgrex.Query{cache: :reference, columns: nil, name: "", param_formats: [], param_oids: [], param_types: [], ref: #Reference<0.2121130605.262930433.40304>, result_formats: [], result_oids: nil, result_types: nil, statement: ["ALTER TABLE ", [34, "users", 34], 32, [[], "ADD COLUMN ", [34, "service", 34], 32, "boolean", [[" DEFAULT ", "false"], []]], []], types: {Postgrex.DefaultTypes, #Reference<0.2121130605.263061505.39872>}}, %Postgrex.Result{columns: nil, command: :alter_table, connection_id: 80873, messages: [], num_rows: 0, rows: nil}}}: ** (FunctionClauseError) no function clause matching in Logger.__should_log__/1
    (logger) lib/logger.ex:663: Logger.__should_log__(true)
    (ecto) lib/ecto/log_entry.ex:57: Ecto.LogEntry.log/2
    (ecto_sql) lib/ecto/adapters/sql.ex:752: Ecto.Adapters.SQL.log/4
    (db_connection) lib/db_connection.ex:1303: DBConnection.log/5
    (postgrex) lib/postgrex.ex:168: Postgrex.query_prepare_execute/4
    (ecto_sql) lib/ecto/adapters/sql.ex:288: Ecto.Adapters.SQL.query!/4
    (elixir) lib/enum.ex:1326: Enum."-map/2-lists^map/1-0-"/2
    (ecto_sql) lib/ecto/adapters/sql.ex:671: Ecto.Adapters.SQL.execute_ddl/4
    (ecto_sql) lib/ecto/migration/runner.ex:272: Ecto.Migration.Runner.log_and_execute_ddl/3
    (ecto_sql) lib/ecto/migration/runner.ex:105: anonymous fn/2 in Ecto.Migration.Runner.flush/0
    (elixir) lib/enum.ex:1936: Enum."-reduce/3-lists^foldl/2-0-"/3
    (ecto_sql) lib/ecto/migration/runner.ex:103: Ecto.Migration.Runner.flush/0
    (stdlib) timer.erl:181: :timer.tc/2
    (ecto_sql) lib/ecto/migration/runner.ex:27: Ecto.Migration.Runner.run/6
    (ecto_sql) lib/ecto/migrator.ex:195: Ecto.Migrator.attempt/6
    (ecto_sql) lib/ecto/migrator.ex:112: anonymous fn/3 in Ecto.Migrator.do_up/4
    (ecto_sql) lib/ecto/adapters/sql.ex:774: anonymous fn/3 in Ecto.Adapters.SQL.checkout_or_transaction/4
    (db_connection) lib/db_connection.ex:1341: DBConnection.run_transaction/4
    (ecto_sql) lib/ecto/migrator.ex:183: Ecto.Migrator.do_run_maybe_in_transaction/3
    (elixir) lib/task/supervised.ex:88: Task.Supervised.do_apply/2

[info] execute "ALTER TABLE users ALTER password DROP NOT NULL"
[error] an exception was raised logging %DBConnection.LogEntry{call: :prepare_execute, connection_time: 496000, decode_time: 9000, params: [], pool_time: nil, query: %Postgrex.Query{cache: :reference, columns: nil, name: "", param_formats: nil, param_oids: nil, param_types: nil, ref: nil, result_formats: nil, result_oids: nil, result_types: nil, statement: "ALTER TABLE users ALTER password DROP NOT NULL", types: nil}, result: {:ok, %Postgrex.Query{cache: :reference, columns: nil, name: "", param_formats: [], param_oids: [], param_types: [], ref: #Reference<0.2121130605.262930433.40374>, result_formats: [], result_oids: nil, result_types: nil, statement: "ALTER TABLE users ALTER password DROP NOT NULL", types: {Postgrex.DefaultTypes, #Reference<0.2121130605.263061505.39872>}}, %Postgrex.Result{columns: nil, command: :alter_table, connection_id: 80873, messages: [], num_rows: 0, rows: nil}}}: ** (FunctionClauseError) no function clause matching in Logger.__should_log__/1
    (logger) lib/logger.ex:663: Logger.__should_log__(true)
    (ecto) lib/ecto/log_entry.ex:57: Ecto.LogEntry.log/2
    (ecto_sql) lib/ecto/adapters/sql.ex:752: Ecto.Adapters.SQL.log/4
    (db_connection) lib/db_connection.ex:1303: DBConnection.log/5
    (postgrex) lib/postgrex.ex:168: Postgrex.query_prepare_execute/4
    (ecto_sql) lib/ecto/adapters/sql.ex:288: Ecto.Adapters.SQL.query!/4
    (elixir) lib/enum.ex:1326: Enum."-map/2-lists^map/1-0-"/2
    (ecto_sql) lib/ecto/adapters/sql.ex:671: Ecto.Adapters.SQL.execute_ddl/4
    (ecto_sql) lib/ecto/migration/runner.ex:272: Ecto.Migration.Runner.log_and_execute_ddl/3
    (ecto_sql) lib/ecto/migration/runner.ex:105: anonymous fn/2 in Ecto.Migration.Runner.flush/0
    (elixir) lib/enum.ex:1936: Enum."-reduce/3-lists^foldl/2-0-"/3
    (ecto_sql) lib/ecto/migration/runner.ex:103: Ecto.Migration.Runner.flush/0
    (stdlib) timer.erl:181: :timer.tc/2
    (ecto_sql) lib/ecto/migration/runner.ex:27: Ecto.Migration.Runner.run/6
    (ecto_sql) lib/ecto/migrator.ex:195: Ecto.Migrator.attempt/6
    (ecto_sql) lib/ecto/migrator.ex:112: anonymous fn/3 in Ecto.Migrator.do_up/4
    (ecto_sql) lib/ecto/adapters/sql.ex:774: anonymous fn/3 in Ecto.Adapters.SQL.checkout_or_transaction/4
    (db_connection) lib/db_connection.ex:1341: DBConnection.run_transaction/4
    (ecto_sql) lib/ecto/migrator.ex:183: Ecto.Migrator.do_run_maybe_in_transaction/3
    (elixir) lib/task/supervised.ex:88: Task.Supervised.do_apply/2

[info] execute "INSERT INTO users (username, service, inserted_at, updated_at)\nVALUES ('hexdocs', true, now(), now())\n"
[error] an exception was raised logging %DBConnection.LogEntry{call: :prepare_execute, connection_time: 1963000, decode_time: 16000, params: [], pool_time: nil, query: %Postgrex.Query{cache: :reference, columns: nil, name: "", param_formats: nil, param_oids: nil, param_types: nil, ref: nil, result_formats: nil, result_oids: nil, result_types: nil, statement: "INSERT INTO users (username, service, inserted_at, updated_at)\nVALUES ('hexdocs', true, now(), now())\n", types: nil}, result: {:ok, %Postgrex.Query{cache: :reference, columns: nil, name: "", param_formats: [], param_oids: [], param_types: [], ref: #Reference<0.2121130605.262930433.40411>, result_formats: [], result_oids: nil, result_types: nil, statement: "INSERT INTO users (username, service, inserted_at, updated_at)\nVALUES ('hexdocs', true, now(), now())\n", types: {Postgrex.DefaultTypes, #Reference<0.2121130605.263061505.39872>}}, %Postgrex.Result{columns: nil, command: :insert, connection_id: 80873, messages: [], num_rows: 1, rows: nil}}}: ** (FunctionClauseError) no function clause matching in Logger.__should_log__/1
    (logger) lib/logger.ex:663: Logger.__should_log__(true)
    (ecto) lib/ecto/log_entry.ex:57: Ecto.LogEntry.log/2
    (ecto_sql) lib/ecto/adapters/sql.ex:752: Ecto.Adapters.SQL.log/4
    (db_connection) lib/db_connection.ex:1303: DBConnection.log/5
    (postgrex) lib/postgrex.ex:168: Postgrex.query_prepare_execute/4
    (ecto_sql) lib/ecto/adapters/sql.ex:288: Ecto.Adapters.SQL.query!/4
    (elixir) lib/enum.ex:1326: Enum."-map/2-lists^map/1-0-"/2
    (ecto_sql) lib/ecto/adapters/sql.ex:671: Ecto.Adapters.SQL.execute_ddl/4
    (ecto_sql) lib/ecto/migration/runner.ex:272: Ecto.Migration.Runner.log_and_execute_ddl/3
    (ecto_sql) lib/ecto/migration/runner.ex:105: anonymous fn/2 in Ecto.Migration.Runner.flush/0
    (elixir) lib/enum.ex:1936: Enum."-reduce/3-lists^foldl/2-0-"/3
    (ecto_sql) lib/ecto/migration/runner.ex:103: Ecto.Migration.Runner.flush/0
    (stdlib) timer.erl:181: :timer.tc/2
    (ecto_sql) lib/ecto/migration/runner.ex:27: Ecto.Migration.Runner.run/6
    (ecto_sql) lib/ecto/migrator.ex:195: Ecto.Migrator.attempt/6
    (ecto_sql) lib/ecto/migrator.ex:112: anonymous fn/3 in Ecto.Migrator.do_up/4
    (ecto_sql) lib/ecto/adapters/sql.ex:774: anonymous fn/3 in Ecto.Adapters.SQL.checkout_or_transaction/4
    (db_connection) lib/db_connection.ex:1341: DBConnection.run_transaction/4
    (ecto_sql) lib/ecto/migrator.ex:183: Ecto.Migrator.do_run_maybe_in_transaction/3
    (elixir) lib/task/supervised.ex:88: Task.Supervised.do_apply/2

[info] == Migrated in 0.0s
hexpm[wm-ecto-3]%

Expected behavior

No error

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions