[bitnami/postgresql-ha] Timeout while connecting to primary - No way to specify a connect_timeout - Githubissues

bitnami / charts

Bitnami Helm Charts

https://bitnami.com

Other

8.84k stars 9.13k forks source link

[bitnami/postgresql-ha] Timeout while connecting to primary - No way to specify a connect_timeout #15390

Closed sonawaneshivraj closed 10 months ago

sonawaneshivraj commented 1 year ago

Name and Version

postgresql-ha 6.5.5

What architecture are you using?

None

What steps will reproduce the bug?

We have a 3 replica deployment (Primary + 2 Secondaries), the statefulset deployment details are below. In some of the setups the secondaries go into a crashloopbackoff state with the following error.

ERROR: connection to database failed
DETAIL: 
timeout expired

On some of our setups, this is hit consistently. No specific steps to reproduce, and normal deployment fails. Easy to see on env with slightly higher latencies

Complete debug log

[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.23 [0m
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.24 [0m[1mWelcome to the Postgresql-repmgr container[0m
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.24 [0m
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.25 [0m[38;5;2mINFO [0m ==> ** Starting PostgreSQL with Replication Manager setup **
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.31 [0m[38;5;2mINFO [0m ==> Validating settings in REPMGR_* env vars...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.31 [0m[38;5;2mINFO [0m ==> Validating settings in POSTGRESQL_* env vars..
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.32 [0m[38;5;3mWARN [0m ==> A CA X.509 certificate was not provided. Client verification will not be performed in TLS connections
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.33 [0m[38;5;2mINFO [0m ==> Querying all partner nodes for common upstream node...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:10.34 [0m[38;5;5mDEBUG[0m ==> Checking node 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.44 [0m[38;5;5mDEBUG[0m ==> Pretending primary role node - 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.44 [0m[38;5;5mDEBUG[0m ==> Pretending primary set to 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'!
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.45 [0m[38;5;5mDEBUG[0m ==> Checking node 'metrics-postgresql-ha-postgresql-1.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'...
psql: error: could not connect to server: Connection refused
    Is the server running on host "metrics-postgresql-ha-postgresql-1.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local" (192.168.2.77) and accepting
    TCP/IP connections on port 5432?
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.47 [0m[38;5;5mDEBUG[0m ==> Skipping: failed to get primary from the node 'metrics-postgresql-ha-postgresql-1.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'!
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.48 [0m[38;5;5mDEBUG[0m ==> Checking node 'metrics-postgresql-ha-postgresql-2.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'...
psql: error: could not translate host name "metrics-postgresql-ha-postgresql-2.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local" to address: Name or service not known
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.51 [0m[38;5;5mDEBUG[0m ==> Skipping: failed to get primary from the node 'metrics-postgresql-ha-postgresql-2.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'!
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.52 [0m[38;5;2mINFO [0m ==> Auto-detected primary node: 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.52 [0m[38;5;5mDEBUG[0m ==> Primary node: 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.54 [0m[38;5;2mINFO [0m ==> Preparing PostgreSQL configuration...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.54 [0m[38;5;5mDEBUG[0m ==> Injecting a new postgresql.conf file...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.55 [0m[38;5;2mINFO [0m ==> postgresql.conf file not detected. Generating it...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.69 [0m[38;5;2mINFO [0m ==> Configuring TLS
chmod: changing permissions of '/certs/tls.key': Read-only file system
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.70 [0m[38;5;3mWARN [0m ==> Could not set compulsory permissions (600) on file /certs/tls.key
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.73 [0m[38;5;5mDEBUG[0m ==> Injecting a new pg_hba.conf file...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.74 [0m[38;5;2mINFO [0m ==> Preparing repmgr configuration...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.75 [0m[38;5;5mDEBUG[0m ==> Node ID: '1001', Rol: 'standby', Primary Node: 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432'
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.75 [0m[38;5;2mINFO [0m ==> Initializing Repmgr...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.76 [0m[38;5;2mINFO [0m ==> Waiting for primary node...
[38;5;6mpostgresql-repmgr [38;5;5m14:46:14.76 [0m[38;5;5mDEBUG[0m ==> Wait for schema repmgr.repmgr on 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432', will try 6 times with 10 delay seconds (TIMEOUT=60)
[38;5;6mpostgresql-repmgr [38;5;5m14:46:18.83 [0m[38;5;5mDEBUG[0m ==> Schema repmgr.repmgr exists!
[38;5;6mpostgresql-repmgr [38;5;5m14:46:18.83 [0m[38;5;2mINFO [0m ==> Cloning data from primary node...
WARNING: following problems with command line parameters detected:
  -D/--pgdata will be ignored if a repmgr configuration file is provided
NOTICE: destination directory "/bitnami/postgresql/data" provided
INFO: connecting to source node
DETAIL: connection string is: host=metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local port=5432 user=repmgr dbname=repmgr
ERROR: connection to database failed
DETAIL: 
timeout expired

Are you using any custom parameters or values?

Deployment details as below

apiVersion: apps/v1
kind: StatefulSet
metadata:
  annotations:
    meta.helm.sh/release-name: metrics
    meta.helm.sh/release-namespace: nsxi-platform
  creationTimestamp: "2023-01-30T14:18:02Z"
  generation: 5
  labels:
    app.kubernetes.io/component: postgresql
    app.kubernetes.io/instance: metrics
    app.kubernetes.io/managed-by: Helm
    app.kubernetes.io/name: postgresql-ha
    helm.sh/chart: postgresql-ha-6.5.5
    vmware/version: 3.2.1-1.0-20138956
  name: metrics-postgresql-ha-postgresql
  namespace: nsxi-platform
  resourceVersion: "24087629"
  uid: e8765f93-6615-4f2b-b43c-54bdd698b543
spec:
  podManagementPolicy: Parallel
  replicas: 3
  revisionHistoryLimit: 10
  selector:
    matchLabels:
      app.kubernetes.io/component: postgresql
      app.kubernetes.io/instance: metrics
      app.kubernetes.io/name: postgresql-ha
  serviceName: metrics-postgresql-ha-postgresql-headless
  template:
    metadata:
      creationTimestamp: null
      labels:
        allow-traffic-to-dns: "true"
        app.kubernetes.io/component: postgresql
        app.kubernetes.io/instance: metrics
        app.kubernetes.io/managed-by: Helm
        app.kubernetes.io/name: postgresql-ha
        helm.sh/chart: postgresql-ha-6.5.5
        vmware/version: 3.2.1-1.0-20138956
    spec:
      affinity:
        podAntiAffinity:
          preferredDuringSchedulingIgnoredDuringExecution:
          - podAffinityTerm:
              labelSelector:
                matchLabels:
                  app.kubernetes.io/component: postgresql
                  app.kubernetes.io/instance: metrics
                  app.kubernetes.io/name: postgresql-ha
              namespaces:
              - nsxi-platform
              topologyKey: kubernetes.io/hostname
            weight: 1
      containers:
      - env:
        - name: BITNAMI_DEBUG
          value: "true"
        - name: POSTGRESQL_VOLUME_DIR
          value: /bitnami/postgresql
        - name: PGDATA
          value: /bitnami/postgresql/data
        - name: POSTGRES_USER
          value: postgres
        - name: POSTGRES_PASSWORD
          valueFrom:
            secretKeyRef:
              key: postgresql-password
              name: metrics-postgresql-password
        - name: POSTGRES_DB
          value: postgres
        - name: POSTGRESQL_LOG_HOSTNAME
          value: "true"
        - name: POSTGRESQL_LOG_CONNECTIONS
          value: "false"
        - name: POSTGRESQL_LOG_DISCONNECTIONS
          value: "false"
        - name: POSTGRESQL_PGAUDIT_LOG_CATALOG
          value: "off"
        - name: POSTGRESQL_CLIENT_MIN_MESSAGES
          value: error
        - name: POSTGRESQL_SHARED_PRELOAD_LIBRARIES
          value: pgaudit, repmgr
        - name: POSTGRESQL_MAX_CONNECTIONS
          value: "256"
        - name: MY_POD_NAME
          valueFrom:
            fieldRef:
              apiVersion: v1
              fieldPath: metadata.name
        - name: REPMGR_UPGRADE_EXTENSION
          value: "no"
        - name: REPMGR_PGHBA_TRUST_ALL
          value: "no"
        - name: REPMGR_MOUNTED_CONF_DIR
          value: /build/repmgr/conf
        - name: REPMGR_NAMESPACE
          valueFrom:
            fieldRef:
              apiVersion: v1
              fieldPath: metadata.namespace
        - name: REPMGR_PARTNER_NODES
          value: metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.$(REPMGR_NAMESPACE).svc.cluster.local,metrics-postgresql-ha-postgresql-1.metrics-postgresql-ha-postgresql-headless.$(REPMGR_NAMESPACE).svc.cluster.local,metrics-postgresql-ha-postgresql-2.metrics-postgresql-ha-postgresql-headless.$(REPMGR_NAMESPACE).svc.cluster.local,
        - name: REPMGR_PRIMARY_HOST
          value: metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.$(REPMGR_NAMESPACE).svc.cluster.local
        - name: REPMGR_NODE_NAME
          value: $(MY_POD_NAME)
        - name: REPMGR_NODE_NETWORK_NAME
          value: $(MY_POD_NAME).metrics-postgresql-ha-postgresql-headless.$(REPMGR_NAMESPACE).svc.cluster.local
        - name: REPMGR_LOG_LEVEL
          value: NOTICE
        - name: REPMGR_CONNECT_TIMEOUT
          value: "30"
        - name: REPMGR_RECONNECT_ATTEMPTS
          value: "5"
        - name: REPMGR_RECONNECT_INTERVAL
          value: "5"
        - name: REPMGR_USERNAME
          value: repmgr
        - name: REPMGR_PASSWORD
          valueFrom:
            secretKeyRef:
              key: repmgr-password
              name: metrics-postgresql-password
        - name: REPMGR_DATABASE
          value: repmgr
        - name: POSTGRESQL_NUM_SYNCHRONOUS_REPLICAS
          value: "2"
        - name: POSTGRESQL_ENABLE_TLS
          value: "yes"
        - name: POSTGRESQL_TLS_KEY_FILE
          value: /certs/tls.key
        - name: POSTGRESQL_TLS_CERT_FILE
          value: /certs/tls.crt
        image: harbor.cmp.be.atos.net/napp-3-2/clustering/third-party/postgresql-repmgr:20138956
        imagePullPolicy: IfNotPresent
        lifecycle:
          preStop:
            exec:
              command:
              - /pre-stop.sh
        livenessProbe:
          exec:
            command:
            - bash
            - -ec
            - PGPASSWORD=$POSTGRES_PASSWORD psql -w -U "postgres" -d "postgres"  -h
              127.0.0.1 -c "SELECT 1"
          failureThreshold: 6
          initialDelaySeconds: 60
          periodSeconds: 10
          successThreshold: 1
          timeoutSeconds: 5
        name: postgresql
        ports:
        - containerPort: 5432
          name: postgresql
          protocol: TCP
        readinessProbe:
          exec:
            command:
            - bash
            - -ec
            - PGPASSWORD=$POSTGRES_PASSWORD psql -w -U "postgres" -d "postgres"  -h
              127.0.0.1 -c "SELECT 1"
          failureThreshold: 6
          initialDelaySeconds: 30
          periodSeconds: 20
          successThreshold: 1
          timeoutSeconds: 5
        resources: {}
        securityContext:
          runAsUser: 1001
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
        volumeMounts:
        - mountPath: /build/repmgr/conf
          name: postgresql-config
        - mountPath: /docker-entrypoint-initdb.d/
          name: custom-init-scripts
        - mountPath: /bitnami/postgresql
          name: data
        - mountPath: /pre-stop.sh
          name: hooks-scripts
          subPath: pre-stop.sh
        - mountPath: /certs
          name: postgres-certs
      dnsPolicy: ClusterFirst
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext:
        fsGroup: 1001
      serviceAccount: metrics-postgresql-ha-postgresql
      serviceAccountName: metrics-postgresql-ha-postgresql
      terminationGracePeriodSeconds: 30
      volumes:
      - name: postgres-certs
        projected:
          defaultMode: 420
          sources:
          - secret:
              items:
              - key: tls.key
                mode: 384
                path: tls.key
              - key: tls.crt
                mode: 384
                path: tls.crt
              name: metrics-postgresql-ha-postgresql-tls-cert
      - configMap:
          defaultMode: 493
          name: metrics-postgresql-ha-postgresql-hooks-scripts
        name: hooks-scripts
      - configMap:
          defaultMode: 420
          name: metrics-postgresql-ha-postgresql-configuration
        name: postgresql-config
      - configMap:
          defaultMode: 420
          name: metrics-create-db-script-configmap
        name: custom-init-scripts
  updateStrategy:
    type: RollingUpdate
  volumeClaimTemplates:
  - apiVersion: v1
    kind: PersistentVolumeClaim
    metadata:
      creationTimestamp: null
      name: data
    spec:
      accessModes:
      - ReadWriteOnce
      resources:
        requests:
          storage: 10Gi
      storageClassName: nsx-t-napp-datastores
      volumeMode: Filesystem
    status:
      phase: Pending
status:
  collisionCount: 0
  currentReplicas: 1
  currentRevision: metrics-postgresql-ha-postgresql-6fd848694b
  observedGeneration: 5
  readyReplicas: 1
  replicas: 3
  updateRevision: metrics-postgresql-ha-postgresql-5d9f579c76
  updatedReplicas: 1

What is the expected behavior?

We understand that the timeout is possibly due to some latencies in the failing environments. What we need is a way to specify the timeout value, currently, there seems to be no way to achieve this and it is getting defaulted to 2 secs.

What do you see instead?

When the standby node comes up, before proceeding with cloning the data from the primary, it does some checks on the primary, (more details here) https://github.com/EnterpriseDB/repmgr/blob/a90d1cf3dd8da7eb036a86c42dca99bf46741784/repmgr-action-standby.c#L5751,

during this check, it tries to connect to repmgr db on the primary, this connection attempt times out with the said error.

In absence of an externally specified timeout, this defaults to 2 secs, more details here https://github.com/EnterpriseDB/repmgr/blob/a90d1cf3dd8da7eb036a86c42dca99bf46741784/dbutils.c#L302.

Additional information

Based on the debugging done on our side, the following piece of code in the bitnami scripts controls this workflow

repmgr_initialize() {
    debug "Node ID: '$(repmgr_get_node_id)', Rol: '$REPMGR_ROLE', Primary Node: '${REPMGR_CURRENT_PRIMARY_HOST}:${REPMGR_CURRENT_PRIMARY_PORT}'"
    info "Initializing Repmgr..."
     ensure_dir_exists "$REPMGR_LOCK_DIR"
    am_i_root && chown "$POSTGRESQL_DAEMON_USER:$POSTGRESQL_DAEMON_GROUP" "$REPMGR_LOCK_DIR"
    if [[ "$REPMGR_ROLE" = "standby" ]]; then
        repmgr_wait_primary_node || exit 1
        # TODO: better way to detect it's a 1st boot
        if [[ ! -f "$POSTGRESQL_CONF_FILE" ]] || ! is_boolean_yes "$REPMGR_SWITCH_ROLE"; then
            repmgr_clone_primary
        else
            repmgr_rewind
        fi
    fi

and

repmgr_clone_primary() {
    info "Cloning data from primary node..."
    local -r flags=("-f" "$REPMGR_CONF_FILE" "-h" "$REPMGR_CURRENT_PRIMARY_HOST" "-p" "$REPMGR_CURRENT_PRIMARY_PORT" "-U" "$REPMGR_USERNAME" "-d" "$REPMGR_DATABASE" "-D" "$POSTGRESQL_DATA_DIR" "standby" "clone" "--fast-checkpoint" "--force")
    PGPASSWORD="$REPMGR_PASSWORD" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
}

The repmgr_clone_primary is the one triggering the workflow. And as described above with the absence of a connect_timeout, its getting defaulted to 2 secs, https://github.com/EnterpriseDB/repmgr/blob/a90d1cf3dd8da7eb036a86c42dca99bf46741784/dbutils.c#L302

javsalgar commented 1 year ago

Hi,

Looking at the container code, I see the following in the repmgr_generate_repmgr_config function

conninfo='user=${REPMGR_USERNAME} $(repmgr_get_conninfo_password) host=${REPMGR_NODE_NETWORK_NAME} dbname=${REPMGR_DATABASE} port=${REPMGR_PORT_NUMBER} connect_timeout=${REPMGR_CONNECT_TIMEOUT}'

This is being consumed by the statefulset

        - name: REPMGR_CONNECT_TIMEOUT
          value: "30"
        - name: REPMGR_RECONNECT_ATTEMPTS
          value: "5"
        - name: REPMGR_RECONNECT_INTERVAL
          value: "5"

And this is set in the postgresql.repmgrConnectTimeout timeout.

In the case of the repmgr_clone_primary function, we may need to check if we explicitly need to set the connection info (including the timeout) as the parameter in order to be consumed. Could you confirm that indeed it took two seconds before crashing?

sonawaneshivraj commented 1 year ago

We tested with REPMGR_CONNECT_TIMEOUT, REPMGR_RECONNECT_ATTEMPTS, and REPMGR_RECONNECT_INTERVAL, once set, they do reflect successfully in the repmgr.conf.

But for the connection attempt in question, these are not the configurations picked up.

In the debug logs it prints the connection info detail, no connect_timeout here.

INFO: connecting to source node
DETAIL: connection string is: host=metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local port=5432 user=repmgr dbname=repmgr
ERROR: connection to database failed

The log entry above comes from https://github.com/EnterpriseDB/repmgr/blob/a90d1cf3dd8da7eb036a86c42dca99bf46741784/repmgr-action-standby.c#L5766, this prints the complete connection string, no connect_timeout here.

javsalgar commented 1 year ago

Hi,

So, if instead of using the -h, -p flags in the clone command, we used the following:

  -d, --dbname=conninfo               conninfo of the upstream node to use for cloning.

This should be enough for including the timeout, is that correct? Could you try launching the chart with diagnosticMode.enabled=true and try manually running the clone command with the --dbname flag, does the configuration get consumed?

sonawaneshivraj commented 1 year ago

From the repmgr_clone_primary code, it seems -d is already being used to set the dbname

repmgr_clone_primary() {
    info "Cloning data from primary node..."
    local -r flags=("-f" "$REPMGR_CONF_FILE" "-h" "$REPMGR_CURRENT_PRIMARY_HOST" "-p" "$REPMGR_CURRENT_PRIMARY_PORT" "-U" "$REPMGR_USERNAME" "-d" "$REPMGR_DATABASE" "-D" "$POSTGRESQL_DATA_DIR" "standby" "clone" "--fast-checkpoint" "--force")

    PGPASSWORD="$REPMGR_PASSWORD" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
}

But as you point out it does seem like -d can be utilized for providing the complete conninfo and not just the dbname, https://repmgr.org/docs/4.2/repmgr-standby-clone.html

Will check further on this, try it out, and get back.

Also, https://repmgr.org/docs/4.2/cloning-cascading.html demonstrates the -f option to specify the conf file to use, but I do not see it documented anywhere, may be worth a try as well.

sonawaneshivraj commented 1 year ago

I tried using conninfo in the -d param, it seems to work and picks up the connect_timeout

$ repmgr -h metrics-pg-postgresql-0.metrics-pg-postgresql-headless.nsxdev-dgsinstances-hhi4a0zb.svc.cluster.local -U repmgr -d "dbname=repmgr connect_timeout=30 password=$REPMGR_PASSWORD" -D /data --force standby clone --dry-run
NOTICE: destination directory "/data" provided
INFO: connecting to source node
DETAIL: connection string is: host=metrics-pg-postgresql-0.metrics-pg-postgresql-headless.nsxdev-dgsinstances-hhi4a0zb.svc.cluster.local user=repmgr password=Kts65So3TQQxkNapa2jQPwK1w9uF3PJt connect_timeout=30 dbname=repmgr
DETAIL: current installation size is 198 MB
INFO: "repmgr" extension is installed in database "repmgr"

aoterolorenzo commented 1 year ago

Hi @sonawaneshivraj,

As I've understood, implementing the conninfo string in the repmgr_clone_primary() function could solve the issue:

repmgr_clone_primary() {
    # Clears WAL directory if existing (pg_basebackup requires the WAL dir to be empty)
    local -r waldir=$(postgresql_get_waldir)
    if [[ -d "$waldir" ]]; then
        info "Deleting existing WAL directory $waldir..."
        rm -rf "$waldir" && ensure_dir_exists "$waldir"
    fi

    info "Cloning data from primary node..."
    local -r flags=("-f" "$REPMGR_CONF_FILE" "-h" "$REPMGR_CURRENT_PRIMARY_HOST" "-p" "$REPMGR_CURRENT_PRIMARY_PORT" "-U" "$REPMGR_USERNAME" "-d" "user=${REPMGR_USERNAME} $(repmgr_get_conninfo_password) host=${REPMGR_NODE_NETWORK_NAME} dbname=${REPMGR_DATABASE} port=${REPMGR_PORT_NUMBER} connect_timeout=${REPMGR_CONNECT_TIMEOUT}" "-D" "$POSTGRESQL_DATA_DIR" "standby" "clone" "--fast-checkpoint" "--force")
    if [[ "$REPMGR_USE_PASSFILE" = "true" ]]; then
        PGPASSFILE="$REPMGR_PASSFILE_PATH" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    else
        PGPASSWORD="$REPMGR_PASSWORD" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    fi

}

Could you give it a try?

sonawaneshivraj commented 1 year ago

Hi @sonawaneshivraj,

As I've understood, implementing the conninfo string in the repmgr_clone_primary() function could solve the issue:

repmgr_clone_primary() {
    # Clears WAL directory if existing (pg_basebackup requires the WAL dir to be empty)
    local -r waldir=$(postgresql_get_waldir)
    if [[ -d "$waldir" ]]; then
        info "Deleting existing WAL directory $waldir..."
        rm -rf "$waldir" && ensure_dir_exists "$waldir"
    fi

    info "Cloning data from primary node..."
    local -r flags=("-f" "$REPMGR_CONF_FILE" "-h" "$REPMGR_CURRENT_PRIMARY_HOST" "-p" "$REPMGR_CURRENT_PRIMARY_PORT" "-U" "$REPMGR_USERNAME" "-d" "user=${REPMGR_USERNAME} $(repmgr_get_conninfo_password) host=${REPMGR_NODE_NETWORK_NAME} dbname=${REPMGR_DATABASE} port=${REPMGR_PORT_NUMBER} connect_timeout=${REPMGR_CONNECT_TIMEOUT}" "-D" "$POSTGRESQL_DATA_DIR" "standby" "clone" "--fast-checkpoint" "--force")
    if [[ "$REPMGR_USE_PASSFILE" = "true" ]]; then
        PGPASSFILE="$REPMGR_PASSFILE_PATH" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    else
        PGPASSWORD="$REPMGR_PASSWORD" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    fi

}

Could you give it a try?

Sure, will give this a try.

Can you please help me understand why the user value is "${REPMGR_USERNAME} $(repmgr_get_conninfo_password)" ? What does the repmgr_get_conninfo_password signify?

aoterolorenzo commented 1 year ago

@sonawaneshivraj my approach is just send in the -d flag of the repmgr_clone_primary() function, all the conninfo string. In the repmgr library scripts, this equals to user=${REPMGR_USERNAME} $(repmgr_get_conninfo_password) host=${REPMGR_NODE_NETWORK_NAME} dbname=${REPMGR_DATABASE} port=${REPMGR_PORT_NUMBER} connect_timeout=${REPMGR_CONNECT_TIMEOUT}

librepmgr.sh:499

conninfo='user=${REPMGR_USERNAME} $(repmgr_get_conninfo_password) host=${REPMGR_NODE_NETWORK_NAME} dbname=${REPMGR_DATABASE} port=${REPMGR_PORT_NUMBER} connect_timeout=${REPMGR_CONNECT_TIMEOUT}'

So my intend is to just replicate that string, as a base point to develop the fix. If you feel a parameter not needed you just can try to omit them.

aoterolorenzo commented 1 year ago

This could also work (just passing conninfo to the -d flag). I just wanted to be sure using directly the env vars.

repmgr_clone_primary() {
    # Clears WAL directory if existing (pg_basebackup requires the WAL dir to be empty)
    local -r waldir=$(postgresql_get_waldir)
    if [[ -d "$waldir" ]]; then
        info "Deleting existing WAL directory $waldir..."
        rm -rf "$waldir" && ensure_dir_exists "$waldir"
    fi

    info "Cloning data from primary node..."
    local -r flags=("-f" "$REPMGR_CONF_FILE" "-h" "$REPMGR_CURRENT_PRIMARY_HOST" "-p" "$REPMGR_CURRENT_PRIMARY_PORT" "-U" "$REPMGR_USERNAME" "-d" "$conninfo" "-D" "$POSTGRESQL_DATA_DIR" "standby" "clone" "--fast-checkpoint" "--force")
    if [[ "$REPMGR_USE_PASSFILE" = "true" ]]; then
        PGPASSFILE="$REPMGR_PASSFILE_PATH" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    else
        PGPASSWORD="$REPMGR_PASSWORD" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    fi

}

Even just narrowing the logic for this case adding just the connect_timeout parameter to the -d flag.

repmgr_clone_primary() {
    # Clears WAL directory if existing (pg_basebackup requires the WAL dir to be empty)
    local -r waldir=$(postgresql_get_waldir)
    if [[ -d "$waldir" ]]; then
        info "Deleting existing WAL directory $waldir..."
        rm -rf "$waldir" && ensure_dir_exists "$waldir"
    fi

    info "Cloning data from primary node..."
       local -r flags=("-f" "$REPMGR_CONF_FILE" "-h" "$REPMGR_CURRENT_PRIMARY_HOST" "-p" "$REPMGR_CURRENT_PRIMARY_PORT" "-U" "$REPMGR_USERNAME" "-d" "$REPMGR_DATABASE connect_timeout=${REPMGR_CONNECT_TIMEOUT}" "-D" "$POSTGRESQL_DATA_DIR" "standby" "clone" "--fast-checkpoint" "--force")
    if [[ "$REPMGR_USE_PASSFILE" = "true" ]]; then
        PGPASSFILE="$REPMGR_PASSFILE_PATH" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    else
        PGPASSWORD="$REPMGR_PASSWORD" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    fi

}

sonawaneshivraj commented 1 year ago

The latter is what I am thinking. I am dealing with an older version 6.5.5 (appVersion: 11.11.0), I need to figure out how do I add this change to an existing image or build a new one with this change. Any pointers will be helpful

aoterolorenzo commented 1 year ago

Could you provide the exact Chart values you are using? I can only see the result StatefulSet specification.

sonawaneshivraj commented 1 year ago

annotations:
  category: Database
apiVersion: v2
appVersion: 11.11.0
dependencies:
  - name: common
    repository: file://../kubernetes-infra/bitnami-common
    version: 1.x.x
  - name: commonlib
    version: 0.1.0
    repository: file://../commonlib
description: Chart for PostgreSQL with HA architecture (using Replication Manager (repmgr) and Pgpool).
engine: gotpl
home: https://github.com/bitnami/charts/tree/master/bitnami/postgresql-ha
icon: https://bitnami.com/assets/stacks/postgresql/img/postgresql-stack-220x234.png
keywords:
  - postgresql
  - repmgr
  - pgpool
  - postgres
  - database
  - sql
  - replication
  - cluster
  - high availability
maintainers:
  - email: containers@bitnami.com
    name: Bitnami
name: postgresql-ha
sources:
  - https://github.com/bitnami/bitnami-docker-postgresql
  - https://www.postgresql.org/
version: 6.5.5

agomezmoron commented 1 year ago

Hi @sonawaneshivraj ,

as we talked privately, please try the fix Alberto provided with the latest image, you're using a very old one (older than 2 years ago) and let us know if that fix works for you. Then we will create a new container image with the patch.

Thanks

vyom-soft commented 1 year ago

Hello, I am seeing the same error timeout. Any pointer.

➜  postgresql git:(main) ✗     kubectl run postgresdb-postgresql-client --rm --tty -i --restart='Never' --namespace test-dev --image docker.io/bitnami/postgresql:15.2.0-debian-11-r5 --env="PGPASSWORD=$POSTGRES_ADMIN_PASSWORD" \
      --command -- psql --host postgresdb-postgresql -U testme -d testdb -p 5432
If you don't see a command prompt, try pressing enter.

psql: error: connection to server at "postgresdb-postgresql" (10.233.19.75), port 5432 failed: Connection timed out
    Is the server running on that host and accepting TCP/IP connections?
pod "postgresdb-postgresql-client" deleted
pod test-dev/postgresdb-postgresql-client terminated (Error)

➜  k -n test-dev exec -ti postgresdb-postgresql-client -- bash
I have no name!@postgresdb-postgresql-client:/$ psql -d testdb -U testme
psql: error: connection to server on socket "/tmp/.s.PGSQL.5432" failed: No such file or directory
    Is the server running locally and accepting connections on that socket?
I have no name!@postgresdb-postgresql-client:/$ command terminated with exit code 137

➜  tmp k logs -f postgresdb-postgresql-0 -n test-dev
postgresql 16:58:28.26
postgresql 16:58:28.26 Welcome to the Bitnami postgresql container
postgresql 16:58:28.26 Subscribe to project updates by watching https://github.com/bitnami/containers
postgresql 16:58:28.26 Submit issues and feature requests at https://github.com/bitnami/containers/issues
postgresql 16:58:28.27
postgresql 16:58:28.27 DEBUG ==> Configuring libnss_wrapper...
postgresql 16:58:28.29 INFO  ==> ** Starting PostgreSQL setup **
postgresql 16:58:28.32 INFO  ==> Validating settings in POSTGRESQL_* env vars..
postgresql 16:58:28.33 INFO  ==> Loading custom pre-init scripts...
postgresql 16:58:28.34 INFO  ==> Initializing PostgreSQL database...
postgresql 16:58:28.34 DEBUG ==> Ensuring expected directories/files exist...
postgresql 16:58:28.37 INFO  ==> pg_hba.conf file not detected. Generating it...
postgresql 16:58:28.37 INFO  ==> Generating local authentication configuration
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with locale "en_US.UTF-8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /bitnami/postgresql/data ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Etc/UTC
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok

Success. You can now start the database server using:

    /opt/bitnami/postgresql/bin/pg_ctl -D /bitnami/postgresql/data -l logfile start

initdb: warning: enabling "trust" authentication for local connections
initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.
postgresql 16:58:29.46 INFO  ==> Starting PostgreSQL in background...
waiting for server to start....2023-03-13 16:58:29.528 GMT [68] LOG:  starting PostgreSQL 15.2 on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2023-03-13 16:58:29.529 GMT [68] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2023-03-13 16:58:29.539 GMT [68] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2023-03-13 16:58:29.575 GMT [71] LOG:  database system was shut down at 2023-03-13 16:58:29 GMT
2023-03-13 16:58:29.620 GMT [68] LOG:  database system is ready to accept connections
 done
server started
CREATE DATABASE
postgresql 16:58:29.79 INFO  ==> Changing password of postgres
ALTER ROLE
postgresql 16:58:29.82 INFO  ==> Creating user testme
CREATE ROLE
postgresql 16:58:29.84 INFO  ==> Granting access to "testme" to the database "testdb"
GRANT
ALTER DATABASE
postgresql 16:58:29.89 INFO  ==> Setting ownership for the 'public' schema database "testdb" to "testdb"
ALTER SCHEMA
postgresql 16:58:29.92 INFO  ==> Configuring replication parameters
postgresql 16:58:29.96 INFO  ==> Configuring synchronous_replication
postgresql 16:58:29.97 INFO  ==> Configuring fsync
postgresql 16:58:30.03 INFO  ==> Stopping PostgreSQL...
waiting for server to shut down....2023-03-13 16:58:30.041 GMT [68] LOG:  received fast shutdown request
2023-03-13 16:58:30.053 GMT [68] LOG:  aborting any active transactions
2023-03-13 16:58:30.055 GMT [68] LOG:  background worker "logical replication launcher" (PID 74) exited with exit code 1
2023-03-13 16:58:30.056 GMT [69] LOG:  shutting down
2023-03-13 16:58:30.064 GMT [69] LOG:  checkpoint starting: shutdown immediate
2023-03-13 16:58:30.201 GMT [69] LOG:  checkpoint complete: wrote 927 buffers (5.7%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.089 s, sync=0.021 s, total=0.146 s; sync files=257, longest=0.013 s, average=0.001 s; distance=4222 kB, estimate=4222 kB
2023-03-13 16:58:30.208 GMT [68] LOG:  database system is shut down
 done
server stopped
postgresql 16:58:30.24 INFO  ==> Loading custom scripts...
postgresql 16:58:30.25 INFO  ==> Loading user's custom files from /docker-entrypoint-initdb.d ...
postgresql 16:58:30.25 INFO  ==> Starting PostgreSQL in background...
waiting for server to start....2023-03-13 16:58:30.290 GMT [152] LOG:  pgaudit extension initialized
2023-03-13 16:58:30.306 GMT [152] LOG:  starting PostgreSQL 15.2 on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2023-03-13 16:58:30.306 GMT [152] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2023-03-13 16:58:30.320 GMT [152] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2023-03-13 16:58:30.340 GMT [155] LOG:  database system was shut down at 2023-03-13 16:58:30 GMT
2023-03-13 16:58:30.369 GMT [152] LOG:  database system is ready to accept connections
 done
server started
2023-03-13 16:58:30.386 GMT [160] LOG:  connection received: host=[local]
postgresql 16:58:30.39 DEBUG ==> Executing /docker-entrypoint-initdb.d/..2023_03_13_16_58_19.4294736326/init_script.sql
2023-03-13 16:58:30.407 GMT [166] LOG:  connection received: host=[local]
2023-03-13 16:58:30.415 GMT [166] LOG:  connection authenticated: identity="postgres" method=md5 (/opt/bitnami/postgresql/conf/pg_hba.conf:3)
2023-03-13 16:58:30.415 GMT [166] LOG:  connection authorized: user=postgres database=testdb application_name=psql
CREATE EXTENSION
CREATE EXTENSION
GRANT
CREATE DATABASE
CREATE ROLE
GRANT
CREATE SCHEMA
CREATE SCHEMA
CREATE SCHEMA
CREATE SCHEMA
GRANT
GRANT
GRANT
GRANT
2023-03-13 16:58:31.151 GMT [166] LOG:  disconnection: session time: 0:00:00.744 user=postgres database=testdb host=[local]
postgresql 16:58:31.15 INFO  ==> Enabling remote connections
postgresql 16:58:31.16 INFO  ==> Stopping PostgreSQL...
waiting for server to shut down....2023-03-13 16:58:31.173 GMT [152] LOG:  received fast shutdown request
2023-03-13 16:58:31.183 GMT [152] LOG:  aborting any active transactions
2023-03-13 16:58:31.185 GMT [152] LOG:  background worker "logical replication launcher" (PID 158) exited with exit code 1
2023-03-13 16:58:31.185 GMT [153] LOG:  shutting down
2023-03-13 16:58:31.192 GMT [153] LOG:  checkpoint starting: shutdown immediate
2023-03-13 16:58:31.395 GMT [153] LOG:  checkpoint complete: wrote 2144 buffers (13.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.121 s, sync=0.057 s, total=0.211 s; sync files=363, longest=0.037 s, average=0.001 s; distance=14579 kB, estimate=14579 kB
2023-03-13 16:58:31.404 GMT [152] LOG:  database system is shut down
 done
server stopped

postgresql 16:58:31.47 INFO  ==> ** PostgreSQL setup finished! **
postgresql 16:58:31.49 INFO  ==> ** Starting PostgreSQL **
2023-03-13 16:58:31.520 GMT [1] LOG:  pgaudit extension initialized
2023-03-13 16:58:31.538 GMT [1] LOG:  starting PostgreSQL 15.2 on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2023-03-13 16:58:31.539 GMT [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2023-03-13 16:58:31.539 GMT [1] LOG:  listening on IPv6 address "::", port 5432
2023-03-13 16:58:31.549 GMT [1] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2023-03-13 16:58:31.571 GMT [183] LOG:  database system was shut down at 2023-03-13 16:58:31 GMT
2023-03-13 16:58:31.583 GMT [1] LOG:  database system is ready to accept connections
2023-03-13 16:58:37.918 GMT [193] LOG:  connection received: host=localhost port=54264
2023-03-13 16:58:47.934 GMT [199] LOG:  connection received: host=localhost port=54108
2023-03

aoterolorenzo commented 1 year ago

Hi,

I will just create an internal task for addressing the issue. We will reach you back here as soon as this gets into an outcome.

andricDu commented 1 year ago

I am experiencing the exact same issue as described in the original post.

postgresql-repmgr 21:16:49.07 DEBUG ==> Schema repmgr.repmgr exists!
postgresql-repmgr 21:16:49.07 INFO  ==> Rejoining node...
postgresql-repmgr 21:16:49.08 INFO  ==> Cloning data from primary node...
WARNING: following problems with command line parameters detected:
  -D/--pgdata will be ignored if a repmgr configuration file is provided
NOTICE: destination directory "/bitnami/postgresql/data" provided
ERROR: connection to database failed
DETAIL:
connection to server at "keycloak-postgresql-ha-postgresql-0.keycloak-postgresql-ha-postgresql-headless.keycloak.svc.cluster.local" (15.0.4.112), port 5432 failed: timeout expired

Out of the 3 nodes, only 1 that happens to be scheduled on a different node pool runs into the timeout, though manually scheduling debugging pods to that node and nodepool I have confirmed no packet loss or networking issues exist.

ssjsk commented 11 months ago

hello, @andricDu and rest who have faced this issue, did you guys manage to find the workaround/solution for this issue? I've been firefighting this since many days. Appreciate if anyone can share the solution, I've also posted question on SO

github-actions[bot] commented 11 months ago

This Issue has been automatically marked as "stale" because it has not had recent activity (for 15 days). It will be closed if no further activity occurs. Thanks for the feedback.

github-actions[bot] commented 10 months ago

Due to the lack of activity in the last 5 days since it was marked as "stale", we proceed to close this Issue. Do not hesitate to reopen it later if necessary.

ryuseongryong commented 9 months ago

@ssjsk I also faced the same thing. If I run the image entry point and command in diagnostic mode, it works as you said. So I compared diagnostic mode and non-diagnostic mode, and the biggest difference is whether Kubernetes uses readiness or not. It works if you set readiness to false, but when you look at the chart, there is a headlessWithNotReadyAddresses value set. Setting this will cause the readiness.sh script to work, replacing the existing readiness (psql query "SELECT 1"). We are currently checking the exact reason.

ssjsk commented 9 months ago

hi @ryuseongryong you've found pain point, disabling liveness/readiness probes for this postgres-ha cluster, makes it work smoothly, definitely not ideal to disable probes though. I tried editing kubernetes statefulset for this helm, mainly to change readiness/liveness script but didn't succeed. I hope bitnami team or someone else can find the solution.

aniket20 commented 9 months ago

Hi Team, we are also facing the same issue. Interestingly, whenever we enable readiness probes, the connection b/w 2 postgres pods is taking ~4 seconds causing the timeout at 2 seconds in establish_db_connection_by_params function.

From logs in this ticket also, I can see that here it's taking ~4 seconds:

14:46:14.76  ==> Wait for schema repmgr.repmgr on 'metrics-postgresql-ha-postgresql-0.metrics-postgresql-ha-postgresql-headless.nsxi-platform.svc.cluster.local:5432', will try 6 times with 10 delay seconds (TIMEOUT=60)
14:46:18.83 ==> Schema repmgr.repmgr exists!

Do we know the root cause for this (why would readiness probe make the communication slower)? Or do we have any other solution apart from disabling readiness probe?

carrodher commented 9 months ago

Thank you for reaching out and for your interest in our project. We'd be happy to assist you, but to do so effectively, we'll need some more details. Could you please create a separate issue filling the Issue template?

Providing this information will help us better understand your situation and assist you in a more targeted manner.

andricDu commented 8 months ago

necroing this thread to point out that the work around @aniket20 proposed does indeed work. While I now must live in dishonour for disabling liveness and readiness probes, at least it runs 😆

kwenzh commented 1 month ago

host=${REPMGR_NODE_NETWORK_NAME}

why flags host=${REPMGR_NODE_NETWORK_NAME} not host=$REPMGR_CURRENT_PRIMARY_HOST ? may be primary is other nodes, in repmgr clone primary stage

kwenzh commented 1 month ago

Hi @sonawaneshivraj, As I've understood, implementing the conninfo string in the repmgr_clone_primary() function could solve the issue:

repmgr_clone_primary() {
    # Clears WAL directory if existing (pg_basebackup requires the WAL dir to be empty)
    local -r waldir=$(postgresql_get_waldir)
    if [[ -d "$waldir" ]]; then
        info "Deleting existing WAL directory $waldir..."
        rm -rf "$waldir" && ensure_dir_exists "$waldir"
    fi

    info "Cloning data from primary node..."
    local -r flags=("-f" "$REPMGR_CONF_FILE" "-h" "$REPMGR_CURRENT_PRIMARY_HOST" "-p" "$REPMGR_CURRENT_PRIMARY_PORT" "-U" "$REPMGR_USERNAME" "-d" "user=${REPMGR_USERNAME} $(repmgr_get_conninfo_password) host=${REPMGR_NODE_NETWORK_NAME} dbname=${REPMGR_DATABASE} port=${REPMGR_PORT_NUMBER} connect_timeout=${REPMGR_CONNECT_TIMEOUT}" "-D" "$POSTGRESQL_DATA_DIR" "standby" "clone" "--fast-checkpoint" "--force")
    if [[ "$REPMGR_USE_PASSFILE" = "true" ]]; then
        PGPASSFILE="$REPMGR_PASSFILE_PATH" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    else
        PGPASSWORD="$REPMGR_PASSWORD" debug_execute "${REPMGR_BIN_DIR}/repmgr" "${flags[@]}"
    fi

}

Could you give it a try?

Sure, will give this a try.

Can you please help me understand why the user value is "${REPMGR_USERNAME} $(repmgr_get_conninfo_password)" ? What does the repmgr_get_conninfo_password signify?

Why not consider incorporating this change?