Bad error message for postgres-level error message

[nickgartmann]

Ecto version: 1.1.0

Managed to get a not very helpful error message when inserting a string that was too long for the VARCHAR(255) column it was supposed to be inserted into:

** (exit) exited in: :gen_server.call(#PID<0.213.0>, {:query, #Reference<0.0.1.2581>, 15000}, 5000)
    ** (EXIT) no process
    (postgrex) lib/postgrex/connection.ex:97: Postgrex.Connection.query/4
    lib/ecto/adapters/postgres/connection.ex:31: Ecto.Adapters.Postgres.Connection.query/4
    (stdlib) timer.erl:197: :timer.tc/3
    lib/ecto/adapters/sql.ex:262: Ecto.Adapters.SQL.query/7
    lib/ecto/pool.ex:149: Ecto.Pool.run/4
    lib/ecto/adapters/sql.ex:247: Ecto.Adapters.SQL.query/6
    lib/ecto/adapters/sql.ex:625: Ecto.Adapters.SQL.rollback/7
    lib/ecto/pool.ex:244: Ecto.Pool.outer_transaction/6
    lib/ecto/adapters/sql.ex:551: Ecto.Adapters.SQL.transaction/3
    (elixir) lib/enum.ex:579: Enum."-each/2-lists^foreach/1-0-"/2
    (elixir) lib/enum.ex:579: Enum.each/2
    (mix) lib/mix/task.ex:291: Mix.Task.run_alias/3
    (mix) lib/mix/task.ex:243: Mix.Task.run/2
    (mix) lib/mix/cli.ex:55: Mix.CLI.run_task/2
    (elixir) lib/code.ex:363: Code.require_file/2

Code that generated it (content was coming from 3rd party web app):

defmodule Mix.Tasks.FetchAllVideos do
  use Mix.Task
  def run(_) do
    Day9tv.Repo.start_link
    {:ok, items, next_page_token} = Day9tv.YouTube.playlist_items("UUaxar6TBM-94_ezoS00fLkA")
    Enum.each items, fn(item) ->
      changeset = Day9tv.Video.create_from_youtube(item)
      Day9tv.Repo.insert!(changeset)
    end
  end
end

[nickgartmann]

Closing because I should have put this on posgrex. So now i did elixir-ecto/postgrex#129

[fishcakez]

There isn't anything postgrex can do about this error because ecto is giving you a postgrex pid that is no longer alive. Really this error is quite clear and we couldn't do better.

Is this the only error in your logs? Its likely an error has occurred before this that leads to checking out dying pid.

[nickgartmann]

This is the only error in the logs. I'd assume we'd want to pass that postgres error back up into the stack trace somehow. I had to dig out the posgres server logs to figure out what was going wrong.

[fishcakez]

If you see this line in the error:

lib/ecto/adapters/sql.ex:625: Ecto.Adapters.SQL.rollback/7

It looks like an error is being raised inside a transaction - and not rescued, which causes a rollback. When we try to rollback the transaction the postgrex connection is no longer alive. In these situation ecto should not try to rollback, as it should close the connection on error and remove the connection from the caller's pdict.

We should be able to see the error that is causing the rollback by wrapping the insert! call inside an explicit transaction and catching the exception from insert! inside the transaction.

defmodule Mix.Tasks.FetchAllVideos do
  use Mix.Task
  def run(_) do
    Day9tv.Repo.start_link
    {:ok, items, next_page_token} = Day9tv.YouTube.playlist_items("UUaxar6TBM-94_ezoS00fLkA")
    Enum.each items, fn(item) ->
      changeset = Day9tv.Video.create_from_youtube(item)
      Day9tv.Repo.transaction(fn ->
          try do
            Day9tv.Repo.insert!(changeset)
          catch
            kind, reason ->
               stack = System.stacktrace()
               IO.puts(Exception.format(kind, reason, stack))
               Day9tv.Repo.rollback(reason)
          end
       end)
    end
  end
end

[josevalim]

In these situation ecto should not try to rollback

@fishcakez is this solved in db_connection? Because if so, we could close this?

[fishcakez]

DBConnection should always log (more so than now) but would be good to know
the error as this situation shouldn't happen here, it could occur there
too. Too busy with holidays for now to try to reproduce without a full
example or the output from the snippet.

On Wednesday, 23 December 2015, José Valim notifications@github.com wrote:

In these situation ecto should not try to rollback

@fishcakez https://github.com/fishcakez is this solved in
db_connection? Because if so, we could close this?

—
Reply to this email directly or view it on GitHub
#1161 (comment).

[fishcakez]

The issue with rollback being attempted when the connection is closed will be fixed when using db_connection because the client process maintains control of the socket throughout a transaction. The issue this hides in postgrex has a fix in elixir-ecto/postgrex#132.