elixir-ecto / db_connection

Database connection behaviour
http://hexdocs.pm/db_connection/DBConnection.html
309 stars 112 forks source link

2.0.4 Causes test failures, not sure why #183

Closed juulSme closed 5 years ago

juulSme commented 5 years ago

Our CI started to fail after updating db_connection to 2.04. It is not set as an explicit dependency, but is pulled in with (I think?) Phoenix / Ecto. Adding {:db_connection, "2.0.3"} to our mix.exs fixed the issue.

This is a project that has recently been upgraded from Elixir 1.6.2 and Phoenix 1.3.x to Elixir 1.8 and Phoenix 1.4, so perhaps there is some old config somewhere that causes the issue, but during a build there are no obvious deprecation warnings or stuff like that.

Environment

OS: Ubuntu 18.04 Docker: 18.09.1 build 4c52b90 Elixir 1.8 Phoenix 1.4.0 Ecto 3.0.6 Postgres 9.6

Our CI builds in-Docker with the Elixir 1.8-alpine image.

Failing build output

Test script executing...
Installing dependency managers...
* creating /root/.mix/archives/hex-0.19.0
* creating /root/.mix/rebar
* creating /root/.mix/rebar3
Updating dependencies when required...
Resolving Hex dependencies...
Dependency resolution completed:
New:
  arc 0.11.0
  arc_ecto 0.11.1
  argon2_elixir 1.3.3
  base64url 0.0.1
  certifi 2.4.2
  combine 0.10.0
  comeonin 4.1.2
  connection 1.0.4
  cors_plug 1.5.2
  cowboy 2.6.1
  cowlib 2.7.0
  crontab 1.1.5
  csv 2.1.1
  db_connection 2.0.4
  decimal 1.6.0
  ecto 3.0.6
  ecto_sql 3.0.4
  elixir_make 0.4.2
  ex_aws 2.1.0
  ex_aws_s3 2.0.1
  ex_aws_ses 2.0.2
  ex_aws_sns 2.0.1
  ex_phone_number 0.1.1
  file_system 0.2.6
  gen_stage 0.14.1
  gen_state_machine 2.0.5
  gettext 0.16.1
  guardian 1.2.1
  guardian_db 2.0.0
  hackney 1.15.0
  hashids 2.0.4
  idna 6.0.0
  jason 1.1.2
  jose 1.9.0
  libring 1.4.0
  metrics 1.0.1
  mime 1.3.1
  mimerl 1.0.2
  parallel_stream 1.0.6
  parse_trans 3.3.0
  phoenix 1.4.0
  phoenix_ecto 4.0.0
  phoenix_html 2.13.1
  phoenix_live_reload 1.2.0
  phoenix_pubsub 1.1.1
  plug 1.7.1
  plug_cowboy 2.0.1
  plug_crypto 1.0.0
  postgrex 0.14.1
  quantum 2.3.4
  ranch 1.7.1
  ssl_verify_fun 1.1.4
  swarm 3.4.0
  sweet_xml 0.6.5
  telemetry 0.3.0
  timex 3.5.0
  trans 2.1.0
  tzdata 0.5.19
  ueberauth 0.5.0
  ueberauth_identity 0.2.3
  unicode_util_compat 0.4.1
  word_smith 0.1.2
* Getting ex_phone_number (Hex package)
* Getting quantum (Hex package)
* Getting crontab (Hex package)
* Getting gen_stage (Hex package)
* Getting swarm (Hex package)
* Getting gen_state_machine (Hex package)
* Getting libring (Hex package)
* Updating db_connection (Hex package)
Waiting for Postgres and creating test database...
wait_for_it.sh: waiting 60 seconds for postgres_my_app:5432
wait_for_it.sh: postgres_my_app:5432 is available after 0 seconds
==> gen_state_machine
Compiling 3 files (.ex)
Generated gen_state_machine app
==> gen_stage
Compiling 10 files (.ex)
Generated gen_stage app
warning: found quoted keyword "coveralls" but the quotes are not required. Note that keywords are always atoms, even when quoted. Similar to atoms, keywords made exclusively of Unicode letters, numbers, underscore, and @ do not require quotes
  /application/my_app_umbrella/deps/ex_phone_number/mix.exs:13

==> ex_phone_number
Compiling 21 files (.ex)
Generated ex_phone_number app
==> db_connection
Compiling 16 files (.ex)
Generated db_connection app
==> crontab
Compiling 7 files (.ex)
Generated crontab app
==> libring
Compiling 5 files (.ex)
Generated libring app
==> swarm
Compiling 1 file (.erl)
Compiling 10 files (.ex)
Generated swarm app
==> quantum
Compiling 37 files (.ex)
Generated quantum app
==> postgrex
Compiling 61 files (.ex)
Generated postgrex app
==> ecto_sql
Compiling 23 files (.ex)
Generated ecto_sql app
==> trans
Compiling 3 files (.ex)
Generated trans app
==> guardian_db
Compiling 5 files (.ex)
Generated guardian_db app
==> my_app_notifier
Compiling 3 files (.ex)
Generated my_app_notifier app
==> my_app
Compiling 57 files (.ex)
warning: clauses with the same name and arity (number of arguments) should be grouped together, "defp generate_aws_body/2" was previously defined (lib/my_app/aws/aws_sns.ex:116)
  lib/my_app/aws/aws_sns.ex:165

warning: unused alias Healthcheck
  lib/my_app/system/healthcheck.ex:2

warning: variable "module" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/my_app/accounts/guardian.ex:47

warning: variable "value" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/my_app/utilities/filter_validator.ex:61

warning: module attribute @since was set but never used
  lib/my_app/events/events.ex:605

Generated my_app app
==> my_app_api
Compiling 35 files (.ex)
warning: unused import Supervisor.Spec
  lib/my_app_api/application.ex:5

warning: key "limited" will be overridden in map
  lib/my_app_api/controllers/limited_controller.ex:127

warning: MyApp.Events.invite_users_to_event_deprecated/2 is deprecated. Use the new invite_users_to_event instead
  lib/my_app_api/controllers/event_controller.ex:277

Generated my_app_api app
==> my_app_cms
Compiling 30 files (.ex)
warning: unused import Supervisor.Spec
  lib/my_app_cms/application.ex:5

Generated my_app_cms app
==> my_app_endpoint
Compiling 11 files (.ex)
warning: redefining @doc attribute previously set at line 37
  lib/mix/tasks/my_app_endpoint.digest.ex:41: Mix.Tasks.MyAppEndpoint.Digest (module)

warning: redefining @doc attribute previously set at line 41
  lib/mix/tasks/my_app_endpoint.digest.ex:43: Mix.Tasks.MyAppEndpoint.Digest (module)

Generated my_app_endpoint app
The database for MyApp.Repo has been created
** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 894ms. You can configure how long requests wait in the queue using :queue_target and :queue_interval. See DBConnection.start_link/2 for more information
    (db_connection) lib/db_connection.ex:784: DBConnection.transaction/3
    (ecto_sql) lib/ecto/migrator.ex:192: Ecto.Migrator.run_maybe_in_transaction/5
    (elixir) lib/task/supervised.ex:90: Task.Supervised.invoke_mfa/2
    (elixir) lib/task/supervised.ex:35: Task.Supervised.reply/5
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Running tests...
==> my_app_notifier
no tests to run --no-color
** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 906ms. You can configure how long requests wait in the queue using :queue_target and :queue_interval. See DBConnection.start_link/2 for more information
    (db_connection) lib/db_connection.ex:784: DBConnection.transaction/3
    (ecto_sql) lib/ecto/migrator.ex:192: Ecto.Migrator.run_maybe_in_transaction/5
    (elixir) lib/task/supervised.ex:90: Task.Supervised.invoke_mfa/2
    (elixir) lib/task/supervised.ex:35: Task.Supervised.reply/5
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3

Expected behaviour

After adding db_connection 2.0.3 to our mix.exs file the expected output is shown:

Test script executing...
Installing dependency managers...
* creating /root/.mix/archives/hex-0.19.0
* creating /root/.mix/rebar
* creating /root/.mix/rebar3
Updating dependencies when required...
Resolving Hex dependencies...
Dependency resolution completed:
New:
  arc 0.11.0
  arc_ecto 0.11.1
  argon2_elixir 1.3.3
  base64url 0.0.1
  certifi 2.4.2
  combine 0.10.0
  comeonin 4.1.2
  connection 1.0.4
  cors_plug 1.5.2
  cowboy 2.6.1
  cowlib 2.7.0
  crontab 1.1.5
  csv 2.1.1
  db_connection 2.0.3
  decimal 1.6.0
  ecto 3.0.6
  ecto_sql 3.0.4
  elixir_make 0.4.2
  ex_aws 2.1.0
  ex_aws_s3 2.0.1
  ex_aws_ses 2.0.2
  ex_aws_sns 2.0.1
  ex_phone_number 0.1.1
  file_system 0.2.6
  gen_stage 0.14.1
  gen_state_machine 2.0.5
  gettext 0.16.1
  guardian 1.2.1
  guardian_db 2.0.0
  hackney 1.15.0
  hashids 2.0.4
  idna 6.0.0
  jason 1.1.2
  jose 1.9.0
  libring 1.4.0
  metrics 1.0.1
  mime 1.3.1
  mimerl 1.0.2
  parallel_stream 1.0.6
  parse_trans 3.3.0
  phoenix 1.4.0
  phoenix_ecto 4.0.0
  phoenix_html 2.13.1
  phoenix_live_reload 1.2.0
  phoenix_pubsub 1.1.1
  plug 1.7.1
  plug_cowboy 2.0.1
  plug_crypto 1.0.0
  postgrex 0.14.1
  quantum 2.3.4
  ranch 1.7.1
  ssl_verify_fun 1.1.4
  swarm 3.4.0
  sweet_xml 0.6.5
  telemetry 0.3.0
  timex 3.5.0
  trans 2.1.0
  tzdata 0.5.19
  ueberauth 0.5.0
  ueberauth_identity 0.2.3
  unicode_util_compat 0.4.1
  word_smith 0.1.2
* Updating db_connection (Hex package)
Waiting for Postgres and creating test database...
wait_for_it.sh: waiting 60 seconds for postgres_my_app:5432
wait_for_it.sh: postgres_my_app:5432 is available after 0 seconds
==> db_connection
Compiling 16 files (.ex)
Generated db_connection app
==> postgrex
Compiling 61 files (.ex)
Generated postgrex app
==> ecto_sql
Compiling 23 files (.ex)
Generated ecto_sql app
==> trans
Compiling 3 files (.ex)
Generated trans app
==> guardian_db
Compiling 5 files (.ex)
Generated guardian_db app
==> my_app_notifier
Compiling 3 files (.ex)
Generated my_app_notifier app
==> my_app
Compiling 57 files (.ex)
warning: clauses with the same name and arity (number of arguments) should be grouped together, "defp generate_aws_body/2" was previously defined (lib/my_app/aws/aws_sns.ex:116)
  lib/my_app/aws/aws_sns.ex:165

warning: unused alias Healthcheck
  lib/my_app/system/healthcheck.ex:2

warning: variable "module" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/my_app/accounts/guardian.ex:47

warning: variable "value" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/my_app/utilities/filter_validator.ex:61

warning: module attribute @since was set but never used
  lib/my_app/events/events.ex:605

Generated my_app app
==> my_app_api
Compiling 35 files (.ex)
warning: unused import Supervisor.Spec
  lib/my_app_api/application.ex:5

warning: key "limited" will be overridden in map
  lib/my_app_api/controllers/limited_controller.ex:127

warning: MyApp.Events.invite_users_to_event_deprecated/2 is deprecated. Use the new invite_users_to_event instead
  lib/my_app_api/controllers/event_controller.ex:277

Generated my_app_api app
==> my_app_cms
Compiling 30 files (.ex)
warning: unused import Supervisor.Spec
  lib/my_app_cms/application.ex:5

Generated my_app_cms app
==> my_app_endpoint
Compiling 11 files (.ex)
warning: redefining @doc attribute previously set at line 37
  lib/mix/tasks/my_app_endpoint.digest.ex:41: Mix.Tasks.MyAppEndpoint.Digest (module)

warning: redefining @doc attribute previously set at line 41
  lib/mix/tasks/my_app_endpoint.digest.ex:43: Mix.Tasks.MyAppEndpoint.Digest (module)

Generated my_app_endpoint app
The database for MyApp.Repo has been created
Running tests...
==> my_app_notifier
no tests to run --no-color
==> my_app
......................................................

Finished in 6.4 seconds
54 tests, 0 failures

Randomized with seed 836174
==> my_app_api
no tests to run --no-color
==> my_app_cms
no tests to run --no-color
==> my_app_endpoint
no tests to run --no-color
josevalim commented 5 years ago

I cannot reproduce it. Can you please provide a minimal app that reproduces it? Thanks!

juulSme commented 5 years ago

That's not going to be simple :p It's quite a large umbrella app that I've only started to work on recently and mostly do the ops for. Isolating the problem might be a bit of a pain. I'm willing to give it a try but it's going to be sometime next week I'm afraid, perhaps Tuesday if that's ok

josevalim commented 5 years ago

Totally fine!

josevalim commented 5 years ago

Oh, I know what it is. I will push something in 5 min.

josevalim commented 5 years ago

Can you please try master?

supersimple commented 5 years ago

@josevalim I had the same issue. Loading the dependency from master fixes it.

josevalim commented 5 years ago

v2.0.5 is out!