DBConnection.Connection.start_link logs credentials

[Aqualon]

Hello, in one of our applications we have a release task to run DB migrations

  def migrate do
    start_apps = [:logger, :ecto, :ecto_sql, :myxql, :telemetry]
    Enum.each(start_apps, &Application.ensure_all_started/1)

    Repo.start_link()

    IO.puts("Running migrations")
    path = Application.app_dir(:social, "priv/repo/migrations")

    if File.exists?(path) do
      IO.puts("Migration: Running from #{path}")
    else
      IO.puts("Migration: WARNING: Migration folder does not exist: #{path}")
    end

    Migrator.run(Repo, path, :up, all: true, log: :debug)

    :init.stop()
  end

Since we also had handle_otp_reports: true set, we get credentials for the DB logged as part of start_link (replaced with ###):

Start Call: DBConnection.Connection.start_link(MyXQL.Connection, [pool_index: 7, disconnect_on_error_codes: [1461], repo: Social.Repo, telemetry_prefix: [:social, :repo], otp_app: :social, timeout: 15000, username: "###", password: "###", database: "###", hostname: "###", pool_size: 10, charset: "utf8mb4", socket_options: [nodelay: true], pool: DBConnection.ConnectionPool], #PID<0.150.0>, #Reference<0.3579042925.1829634049.98198>)

Is this expected behavior and setting handle_otp_reports: false is the right fix or did we set something else wrong?

Currently the app is on elixir 1.12.2, erlang 24.0.5-1, db_connection version is 2.5.0.

[josevalim]

Can you provide a couple lines before and after the logging?

[Aqualon]

Here's the complete output of the migration, we run it with docker on kubernetes:

Deploying Pod/social-backend-migration-1685002834 (timeout: 600s)
Streaming logs from Pod/social-backend-migration-1685002834 container 'social-backend-migration':
Pid: #PID<0.158.0>
Start Call: DBConnection.Connection.start_link(MyXQL.Connection, [pool_index: 7, disconnect_on_error_codes: [1461], repo: Social.Repo, telemetry_prefix: [:social, :repo], otp_app: :social, timeout: 15000, username: "USERNAME", password: "PASSWORD", database: "DATABASE", hostname: "HOST", pool_size: 10, charset: "utf8mb4", socket_options: [nodelay: true], pool: DBConnection.ConnectionPool], #PID<0.150.0>, #Reference<0.3579042925.1829634049.98198>)
10:24:33.557 [info] Child {MyXQL.Connection, #PID<0.150.0>, 8} of Supervisor #PID<0.151.0> (DBConnection.ConnectionPool.Pool) started
Pid: #PID<0.159.0>
Start Call: DBConnection.Connection.start_link(MyXQL.Connection, [pool_index: 8, disconnect_on_error_codes: [1461], repo: Social.Repo, telemetry_prefix: [:social, :repo], otp_app: :social, timeout: 15000, username: "USERNAME", password: "PASSWORD", database: "DATABASE", hostname: "HOST", pool_size: 10, charset: "utf8mb4", socket_options: [nodelay: true], pool: DBConnection.ConnectionPool], #PID<0.150.0>, #Reference<0.3579042925.1829634049.98198>)
10:24:33.557 [info] Child {MyXQL.Connection, #PID<0.150.0>, 9} of Supervisor #PID<0.151.0> (DBConnection.ConnectionPool.Pool) started
Pid: #PID<0.160.0>
Start Call: DBConnection.Connection.start_link(MyXQL.Connection, [pool_index: 9, disconnect_on_error_codes: [1461], repo: Social.Repo, telemetry_prefix: [:social, :repo], otp_app: :social, timeout: 15000, username: "USERNAME", password: "PASSWORD", database: "DATABASE", hostname: "HOST", pool_size: 10, charset: "utf8mb4", socket_options: [nodelay: true], pool: DBConnection.ConnectionPool], #PID<0.150.0>, #Reference<0.3579042925.1829634049.98198>)
10:24:33.558 [info] Child {MyXQL.Connection, #PID<0.150.0>, 10} of Supervisor #PID<0.151.0> (DBConnection.ConnectionPool.Pool) started
Pid: #PID<0.161.0>
Start Call: DBConnection.Connection.start_link(MyXQL.Connection, [pool_index: 10, disconnect_on_error_codes: [1461], repo: Social.Repo, telemetry_prefix: [:social, :repo], otp_app: :social, timeout: 15000, username: "USERNAME", password: "PASSWORD", database: "DATABASE", hostname: "HOST", pool_size: 10, charset: "utf8mb4", socket_options: [nodelay: true], pool: DBConnection.ConnectionPool], #PID<0.150.0>, #Reference<0.3579042925.1829634049.98198>)
Running migrations
10:24:33.558 [info] Child DBConnection.ConnectionPool of Supervisor Social.Repo started
Pid: #PID<0.150.0>
Start Call: Ecto.Repo.Supervisor.start_child({DBConnection.ConnectionPool, :start_link, [{MyXQL.Connection, [disconnect_on_error_codes: [1461], repo: Social.Repo, telemetry_prefix: [:social, :repo], otp_app: :social, timeout: 15000, username: "USERNAME", password: "PASSWORD", database: "DATABASE", hostname: "HOST", pool_size: 10, charset: "utf8mb4", socket_options: [nodelay: true], pool: DBConnection.ConnectionPool]}]}, Social.Repo, Ecto.Adapters.MyXQL, %{cache: #Reference<0.3579042925.1829634049.98197>, opts: [repo: Social.Repo, timeout: 15000, pool_size: 10, pool: DBConnection.ConnectionPool], repo: Social.Repo, sql: Ecto.Adapters.MyXQL.Connection, stacktrace: nil, telemetry: {Social.Repo, :debug, [:social, :repo, :query]}})
Migration: Running from /app/rel/social/lib/social-1.0.0/priv/repo/migrations
10:24:33.567 [info] Child of Supervisor :inet_gethost_native_sup started
Pid: #PID<0.163.0>
Start Call: :inet_gethost_native.init([])
10:24:33.567 [info] Child :inet_gethost_native_sup of Supervisor :kernel_safe_sup started
Pid: #PID<0.162.0>
Start Call: :inet_gethost_native.start_link()
10:24:33.589 [info] Child :timer_server of Supervisor :kernel_safe_sup started
Pid: #PID<0.164.0>
Start Call: :timer.start_link()
Successfully deployed in 18.6s: Pod/social-backend-migration-1685002834

The task itself is called via

exec rel/$APP_NAME/bin/$APP_NAME eval Elixir.Release.Tasks.migrate

[josevalim]

It seems you have enabled handle_sasl_reports instead. Those are verbose debug logs, you should disable them, yeah. :)

[Aqualon]

We had it enabled. With handle_sasl_reports to disabled and handle_otp_reports enabled, it's not logged anymore.