Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

postgres connection leak (maybe sqlite3 too?) #387

Closed
jpatters opened this issue Aug 21, 2021 · 7 comments
Closed

postgres connection leak (maybe sqlite3 too?) #387

jpatters opened this issue Aug 21, 2021 · 7 comments
Assignees
Labels
bug Something isn't working.

Comments

@jpatters
Copy link
Contributor

Describe the bug

After running maddy with the postgres module for 15 minutes, the number of connections to postgres has climbed to 13 open connections. I first observed this after running it over night and finding there were no more available connection in the morning. By the time i finished writing this report, the number of connections had grown to 22.
The query that is causing the issue is
UPDATE mboxes SET uidnext = uidnext + $1, msgsCount = msgsCount + $2, WHERE id = $3 RETURNING uidnext - 1

I originally switched to using postgres because I was having issues with sqlite3. Incoming mail was failing with reason: "the database is locked". I'd be curious to know if that was being caused by the same issue but am unfamiliar with sqlite3.

Steps to reproduce

Run maddy with the postgres module and watch the connections climb. (replace maddy with your database name in the following query).

select *
from pg_stat_activity
where datname = 'maddy';

Log files

truncated output from sql query
2021-08-21 10:18:54.699778+00 | 2021-08-21 10:18:54.699966+00 | 2021-08-21 10:18:54.700105+00 | Client          | ClientRead    | idle in trans
action |         614 |          614 |     UPDATE mboxes                              +| client backend
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     SET uidnext = uidnext + $1,+|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                 msgsCount = msgsCount + $2     +|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     WHERE id = $3              +|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     RETURNING uidnext - 1       |
 16385 | maddy   | 38914 |    16384 | maddy   |                  | ::1         |                 |       44842 | 2021-08-21 10:20:02.298881+00 |
 2021-08-21 10:20:02.687454+00 | 2021-08-21 10:20:02.687934+00 | 2021-08-21 10:20:02.687935+00 | Lock            | transactionid | active
       |         615 |          614 |     UPDATE mboxes                              +| client backend
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     SET uidnext = uidnext + $1,+|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                 msgsCount = msgsCount + $2     +|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     WHERE id = $3              +|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     RETURNING uidnext - 1       |
 16385 | maddy   | 38953 |    16384 | maddy   |                  | ::1         |                 |       44848 | 2021-08-21 10:21:07.46255+00  |
 2021-08-21 10:21:07.809999+00 | 2021-08-21 10:21:07.810432+00 | 2021-08-21 10:21:07.810432+00 | Lock            | tuple         | active
       |         616 |          614 |     UPDATE mboxes                              +| client backend
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     SET uidnext = uidnext + $1,+|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                 msgsCount = msgsCount + $2     +|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     WHERE id = $3              +|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              |                     RETURNING uidnext - 1       |
 16385 | maddy   | 38975 |    16384 | maddy   | psql             |             |                 |          -1 | 2021-08-21 10:21:41.633083+00 |
 2021-08-21 10:32:08.776246+00 | 2021-08-21 10:32:08.776246+00 | 2021-08-21 10:32:08.776249+00 |                 |               | active
       |             |          614 | select *                                       +| client backend
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              | from pg_stat_activity                          +|
       |         |       |          |         |                  |             |                 |             |                               |
                               |                               |                               |                 |               |
       |             |              | where datname = 'maddy';                        |

(it goes on)

Configuration file

maddy.conf
$(hostname) = mx1.example.com
$(primary_domain) = example.com
$(local_domains) = $(primary_domain)

debug true

tls {
    loader acme {
        hostname mx1.example.com
        email email@example.com
        agreed true
        challenge dns-01
        dns cloudflare {
            api_token "..."
        }
    }
}

auth.pass_table local_authdb {
    table sql_table {
        driver postgres
        dsn "user=maddy dbname=maddy"
        table_name passwords
    }
}

storage.imapsql local_mailboxes {
    driver postgres
    dsn "user=maddy dbname=maddy"

    msg_store s3 {
        endpoint s3compat.com
        access_key "..."
        secret_key "..."
        bucket bucket-name
        region a-valid-region
    }
}

hostname $(hostname)

table.chain local_rewrites {
    optional_step regexp "(.+)\+(.+)@(.+)" "$1@$3"
    optional_step file /etc/maddy/aliases
}

msgpipeline local_routing {
    destination postmaster $(local_domains) {
        modify {
            replace_rcpt &local_rewrites
        }

        deliver_to &local_mailboxes
    }

    default_destination {
        reject 550 5.1.1 "User doesn't exist"
    }
}

smtp tcp://0.0.0.0:25 {
    limits {
        # Up to 20 msgs/sec across max. 10 SMTP connections.
        all rate 20 1s
        all concurrency 10
    }

    auth &local_authdb

    dmarc yes
    check {
        require_mx_record
        dkim
        spf
    }

    source $(local_domains) {
        reject 501 5.1.8 "Use Submission for outgoing SMTP"
    }
    default_source {
        destination postmaster $(local_domains) {
            deliver_to &local_routing
        }
        default_destination {
            reject 550 5.1.1 "User doesn't exist"
        }
    }
}

submission tls://0.0.0.0:465 tcp://0.0.0.0:587 {
    limits {
        # Up to 50 msgs/sec across any amount of SMTP connections.
        all rate 50 1s
    }

    auth &local_authdb

    source $(local_domains) {
        check {
            authorize_sender {
                prepare_email &local_rewrites
                user_to_email identity
            }
        }

        destination postmaster $(local_domains) {
            deliver_to &local_routing
        }
        default_destination {
            modify {
                dkim $(primary_domain) $(local_domains) default
            }
            deliver_to &remote_queue
        }
    }
    default_source {
        reject 501 5.1.8 "Non-local sender domain"
    }
}

target.remote outbound_delivery {
    limits {
        # Up to 20 msgs/sec across max. 10 SMTP connections
        # for each recipient domain.
        destination rate 20 1s
        destination concurrency 10
    }
    mx_auth {
        dane
        mtasts {
            cache fs
            fs_dir mtasts_cache/
        }
        local_policy {
            min_tls_level encrypted
            min_mx_level none
        }
    }
}

target.queue remote_queue {
    target &outbound_delivery

    autogenerated_msg_domain $(primary_domain)
    bounce {
        destination postmaster $(local_domains) {
            deliver_to &local_routing
        }
        default_destination {
            reject 550 5.0.0 "Refusing to send DSNs to non-local addresses"
        }
    }
}

imap tls://0.0.0.0:993 tcp://0.0.0.0:143 {
    auth &local_authdb
    storage &local_mailboxes
}

Environment information

  • maddy version: 0.5.0
@jpatters jpatters added the bug Something isn't working. label Aug 21, 2021
@foxcpp foxcpp self-assigned this Aug 21, 2021
@foxcpp
Copy link
Owner

foxcpp commented Aug 21, 2021

The query output formatting seems to be messed up, can you upload it somewhere? (e.g. hastebin.com) I would like to see more connections and what state they are in.

@foxcpp
Copy link
Owner

foxcpp commented Aug 21, 2021

I run maddy 0.5.0 with PostgreSQL 13.4 and I do not have the same issue. The only difference seems to be you using S3 storage.

Could you also try killing the maddy process with SIGTRAP (killall -TRAP maddy) and uploading the output somewhere?

@jpatters
Copy link
Contributor Author

postgres connections: https://hastebin.com/awesebuday.rb

There was no output from running killall -TRAP maddy

I'll try without s3 as well to see if that helps. It could make sense as received messages don't seem to get stored anywhere. So maybe it's related.

@foxcpp
Copy link
Owner

foxcpp commented Aug 21, 2021

There was no output from running killall -TRAP maddy

It should be in maddy log (wherever it is, probably systemd journal).

@jpatters
Copy link
Contributor Author

I can confirm that switching to the fs module made both of these issues go away.

Here's the output of the TRAP: https://pastebin.com/v01dy38X (thanks for the tip on where to find it)

@jpatters
Copy link
Contributor Author

The issue turns out to be that my s3 connection settings were wrong (i'm actually using linode and their docs were a bit confusing). Now that the connection is working properly both issues have been resolved.
I think the take away might be that there was no error saying that it couldn't connect. Surfacing that error would have made this easier.
In any case, thanks for the help (and for making maddy).

@foxcpp foxcpp closed this as completed in 34094c1 Aug 21, 2021
@foxcpp
Copy link
Owner

foxcpp commented Aug 21, 2021

Thanks for helping me troubleshoot the issue!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working.
Projects
None yet
Development

No branches or pull requests

2 participants