You are viewing a plain text version of this content. The canonical link for it is here.

Posted to commits@airflow.apache.org by "andrii-korotkov-verkada (via GitHub)" <gi...@apache.org> on 2025/01/07 01:42:36 UTC

[D] Db migrations getting stuck for a while with no logs until failure. What can be wrong? [airflow]

GitHub user andrii-korotkov-verkada created a discussion: Db migrations getting stuck for a while with no logs until failure. What can be wrong?

My setup is ArgoCD for deployment, Terraform for secrets, db, permissions etc. configuration, AWS for hosting EKS and Aurora Postgres database, Airflow image based on version 2.10.3 and Python 3.10. I'm using PgBouncer, which I've configured to sync before the db migrations job. I see some logs for pgbouncer which show what seems like some successful connections, probably from the metrics exporter:
```
2025-01-07 01:21:25.340 UTC [1] DEBUG C-0x7fc222b94930: (nodb)/(nouser)@127.0.0.1:57012 ignoring startup parameter: extra_float_digits=2
2025-01-07 01:21:25.340 UTC [1] DEBUG C-0x7fc222b94930: (nodb)/(nouser)@127.0.0.1:57012 got var: user=postgres
2025-01-07 01:21:25.340 UTC [1] DEBUG C-0x7fc222b94930: (nodb)/(nouser)@127.0.0.1:57012 got var: datestyle=ISO, MDY
2025-01-07 01:21:25.340 UTC [1] DEBUG C-0x7fc222b94930: (nodb)/(nouser)@127.0.0.1:57012 got var: database=pgbouncer
2025-01-07 01:21:25.340 UTC [1] DEBUG C-0x7fc222b94930: (nodb)/(nouser)@127.0.0.1:57012 got var: client_encoding=UTF8
2025-01-07 01:21:25.340 UTC [1] LOG C-0x7fc222b94930: pgbouncer/postgres@127.0.0.1:57012 login attempt: db=pgbouncer user=postgres tls=no
2025-01-07 01:21:25.340 UTC [1] DEBUG C-0x7fc222b94930: pgbouncer/postgres@127.0.0.1:57012 P: got connection: 127.0.0.1:57012 -> 127.0.0.1:6543
2025-01-07 01:21:25.340 UTC [1] DEBUG C-0x7fc222b94930: pgbouncer/postgres@127.0.0.1:57012 C: selected SASL mechanism: SCRAM-SHA-256
```
My metadata connection string is configured as (some variables replaced with values)
```
postgresql://postgres:<password-placeholder>@airflow-pgbouncer.vairflow:6543/airflow-metadata?sslmode=disable
```
For metadata connection there are presumable crashes among PgBouncer logs
```
2025-01-07 01:25:30.407 UTC [1] LOG S-0x7fc222b42040: airflow-metadata/postgres@<ip-address-placeholder>:5432 new connection to server (from 10.34.119.135:41096)
2025-01-07 01:25:40.408 UTC [1] LOG S-0x7fc222b42040: airflow-metadata/postgres@<ip-address-placeholder>:5432 closing because: server conn crashed? (age=10s)
```
Here's pgbouncer.ini config setup (replaced some variables with values)
```
  secret_string = join("\n", [
    "[databases]",
    "airflow-metadata = host=<rds-cluster-endpoint-placeholder> dbname=vairflow port=5432 pool_size=10 ",
    "airflow-result-backend = host=<rds-cluster-endpoint-placeholder> dbname=vairflow port=5432 pool_size=5 ",
    "",
    "[pgbouncer]",
    "pool_mode = transaction",
    "listen_port = 6543",
    "listen_addr = *",
    "auth_type = scram-sha-256",
    "auth_file = /etc/pgbouncer/users.txt",
    "stats_users = postgres",
    "ignore_startup_parameters = extra_float_digits",
    "max_client_conn = 100",
    "verbose = 1",
    "log_disconnections = 1",
    "log_connections = 1",
    "",
    "server_tls_sslmode = disable",
    "server_tls_ciphers = normal",
  ])
```
Here's users.txt setup (not sure duplication is needed, but it was there in helm templates)
```
  secret_string = join("\n", [
    "\"postgres\" \"<password-placeholder>\"",
    "\"postgres\" \"<password-placeholder>\""
  ])
```
I've also found these logs in PgBouncer
```
2025-01-07 01:31:02.733 UTC [1] LOG C-0x7fc222b94680: airflow-metadata/postgres@<ip-address-placeholder>:51429 closing because: client_login_timeout (server down) (age=60s)
2025-01-07 01:31:02.733 UTC [1] WARNING C-0x7fc222b94680: airflow-metadata/postgres@<ip-address-placeholder>:51429 pooler error: client_login_timeout (server down)
```
Similar client login timeout eventually appears when the db migrations job pod fails and is recreated/restarted:
```
....................
ERROR! Maximum number of retries (20) reached.

Last check result:
$ airflow db check
/home/airflow/.local/lib/python3.10/site-packages/airflow/configuration.py:859 FutureWarning: section/key [core/sql_alchemy_conn] has been deprecated, you should use[database/sql_alchemy_conn] instead. Please update your `conf.get*` call to use the new name
/home/airflow/.local/lib/python3.10/site-packages/airflow/metrics/statsd_logger.py:184 RemovedInAirflow3Warning: The basic metric validator will be deprecated in the future in favor of pattern-matching.  You can try this now by setting config option metrics_use_pattern_match to True.
[2025-01-07T00:24:07.482+0000] {cli_action_loggers.py:177} WARNING - Failed to log action (psycopg2.OperationalError) connection to server at "airflow-pgbouncer.vairflow" (<ip-address-placeholder>), port 6543 failed: FATAL:  client_login_timeout (server down)
<stacktrace-placeholder>
psycopg2.OperationalError: connection to server at "airflow-pgbouncer.vairflow" (<ip-address-placeholder>), port 6543 failed: FATAL:  client_login_timeout (server down)
```
When checking on the DB side, metrics show some activity but 0 db connections.
I'd be grateful for some hints about what can be wrong, in particular whether it's DB issue, pgbouncer issues, migrations issue or something else. Thanks.

GitHub link: https://github.com/apache/airflow/discussions/45446

----
This is an automatically sent email for commits@airflow.apache.org.
To unsubscribe, please send an email to: commits-unsubscribe@airflow.apache.org