The pool returned by pgxpool.Connect is nil or becomes nil quickly without error

Question

I have the following code for connecting to a Postgres database:

func connectToPostgres(ctx context.Context, url string) (*pgxpool.Pool, error) {
    var err error
    for i := 0; i < 5; i++ {
        p, err := pgxpool.Connect(ctx, url)
        if err != nil || p == nil {
            time.Sleep(3 * time.Second)
            continue
        }
        log.Printf("pool returned from connect: %s", p)
        return p, nil
    }
    return nil, errors.Wrap(err, "timed out waiting to connect postgres")
}

The use case is to wait for Postgres to become available when starting my server with docker-compose. Even though the code sleeps if p == nil, the log just before the first return prints out: pool returned from connect: %!s(*pgxpool.Pool=<nil>)

Is there some way that a background process in pgxpool could make p == nil?

Any thoughts on why this would happen?

EDIT: This appears to only happen while running my app and Postgres via docker-compose. I'm using the following compose file:

services:
    app:
        build: .
        ports:
            - "8080:8080"
        depends_on:
            - "db"

    db:
        image: postgres
        restart: always
        environment:
            - POSTGRES_DB=demo_db
            - POSTGRES_PASSWORD=${POSTGRES_PASSWORD}
        ports:
            - "8081:5432"

and the Dockerfile for my app:

FROM golang:1.17

WORKDIR /

COPY go.mod .
COPY go.sum .
COPY *.go .

RUN go mod download
RUN go build

EXPOSE 8080

CMD [ "./app" ]

And a minimally reproducible example go file:

package main

import (
    "context"
    "fmt"
    "log"
    "net/http"
    "time"

    "github.com/jackc/pgx/v4/pgxpool"
    "github.com/pkg/errors"
)

func main() {
    log.Printf("connecting to postgres...")
    pgpool, err := connectToPostgres(context.Background(), "postgresql://localhost:5432/demo_db")
    log.Printf("pool: %s", pgpool)
    if err != nil {
        log.Fatalln(err)
    }
    log.Printf("successfully connected to postgres")

    if err := http.ListenAndServe(":8080", nil); err != nil {
        log.Fatal(err)
    }
    log.Println("stopped")
}

func connectToPostgres(ctx context.Context, url string) (*pgxpool.Pool, error) {
    var err error
    for i := 0; i < 5; i++ {
        p, err := pgxpool.Connect(ctx, url)
        if err != nil || p == nil {
            time.Sleep(3 * time.Second)
            continue
        }
        log.Printf("pool returned from connect: %s", p)
        return p, nil
    }
    return nil, errors.Wrap(err, "timed out waiting to connect postgres")
}

That's so strange, I tried it locally and can't reproduce it. Can you provide a reproducible example: https://stackoverflow.com/help/minimal-reproducible-example ? — Wolfgang, Dec 21 '21 at 17:57
There's literally a check that if the p is nil it will get in the loop, are you sure you posted the same code? — Wolfgang, Dec 21 '21 at 18:07
I probably should have included that this only happens while running my app and postgres via docker-compose. Just updated the question with more information on how to reproduce the problem. — kingkupps, Dec 21 '21 at 18:08
RE: the nil check in the loop - yup I triple-checked. My hunch is that the log message is delayed by some degree and that something is happening in the background because otherwise the check would have prevented the nil value from slipping through. — kingkupps, Dec 21 '21 at 18:10
Looking through the `log.Printf` implementation, the string format happens immediately if the value of `p` changed it would have had to be directly after the branch which seems incredibly unlikely. The code in the question is exactly what I'm running (at this point I've checked a dozen times). I also made sure the docker container I'm seeing this issue on has this exact build. It's happening consistently for me but it should be impossible as you say. — kingkupps, Dec 21 '21 at 18:37
In your docker-compose you put the database as `db`, my connection string is: `"postgres://postgres:mysecretpassword@db:5432/postgres"` — Wolfgang, Dec 21 '21 at 18:47

Wolfgang · Accepted Answer · 2021-12-21T21:47:49.477

The issue is that when connecting in a docker-compose network, you have to connect to the hostname of the container, in this case db.

You could also use the other container's IP but would take additional amount of work, it's simpler to just use the hostname.

In other words, you have the wrong connection string, I got this as well when connecting to localhost

app_1  | 2021/12/21 18:53:28 pool: %!s(*pgxpool.Pool=<nil>)
app_1  | 2021/12/21 18:53:28 successfully connected to postgres

When connecting with the right connection string:

 "postgres://postgres:mysecretpassword@db:5432/postgres"

It works perfectly.

Rest of the logs

db_1   | 2021-12-21 18:56:04.122 UTC [1] LOG:  database system is ready to accept connections
app_1  | 2021/12/21 18:56:06 pool returned from connect: &{%!s(*puddle.Pool=&{0xc00007c040 0xc0000280b0 [0xc00007c0c0] [0xc00007c0c0] 0x65cb60 0x65dc80 16 1 9872796 1 0 false}) %!s(*pgxpool.Config=&{0xc0000a2000 <nil> <nil> <nil> <nil> 3600000000000 1800000000000 16 0 60000000000 false true}) %!s(func(context.Context, *pgx.ConnConfig) error=<nil>) %!s(func(context.Context, *pgx.Conn) error=<nil>) %!s(func(context.Context, *pgx.Conn) bool=<nil>) %!s(func(*pgx.Conn) bool=<nil>) %!s(int32=0) %!s(time.Duration=3600000000000) %!s(time.Duration=1800000000000) %!s(time.Duration=60000000000) {%!s(uint32=0) {%!s(int32=0) %!s(uint32=0)}} %!s(chan struct {}=0xc000024060)}
app_1  | 2021/12/21 18:56:06 pool: &{%!s(*puddle.Pool=&{0xc00007c040 0xc0000280b0 [0xc00007c0c0] [0xc00007c0c0] 0x65cb60 0x65dc80 16 1 9872796 1 0 false}) %!s(*pgxpool.Config=&{0xc0000a2000 <nil> <nil> <nil> <nil> 3600000000000 1800000000000 16 0 60000000000 false true}) %!s(func(context.Context, *pgx.ConnConfig) error=<nil>) %!s(func(context.Context, *pgx.Conn) error=<nil>) %!s(func(context.Context, *pgx.Conn) bool=<nil>) %!s(func(*pgx.Conn) bool=<nil>) %!s(int32=0) %!s(time.Duration=3600000000000) %!s(time.Duration=1800000000000) %!s(time.Duration=60000000000) {%!s(uint32=0) {%!s(int32=0) %!s(uint32=0)}} %!s(chan struct {}=0xc000024060)}
app_1  | 2021/12/21 18:56:06 successfully connected to postgres

Great find thank you so much! – kingkupps Dec 21 '21 at 18:57 — kingkupps, Dec 21 '21 at 18:57
No problem, it was interesting :) – Wolfgang Dec 21 '21 at 19:01 — Wolfgang, Dec 21 '21 at 19:01

The pool returned by pgxpool.Connect is nil or becomes nil quickly without error

1 Answers1