Cloudsql-proxy: Multiple calls to refreshCfg leak goroutines

[lindlof]

Bug Description

There can be multiple Goroutines waiting on refreshCertAfter for the same database instance. If Dial fails tryConnect of cachedCfg it calls refreshCfg which creates another Goroutine waiting refreshCertAfter.

It seems that each refreshing Goroutine will keep refreshing itself every hour and they only die off if they get limited by refreshCfg throttling.

We had misconfigured routing to the SQL instance's IP address. Requests to SQL instance worked sometimes and sometimes failed on handshake.

Effectively this led to massive spam of ephemeral certificate for instance x will expire soon, refreshing now. in our logs after the service had run for an hour. There was no issue with ephemeral certificates but only with connection to the database.

In our case it was a configuration issue but a long-running cloudsql-proxy can ocassionally fail database connections and leak ephemeral certificate refreshes Goroutines. refreshCfg throttling gives some protection against this.

How to reproduce

1. Sometimes route Cloud SQL instance IP to wrong IP (or randomly fail tryConnect )
2. Make database queries
3. Wait for an hour to see multiple ephemeral certificate for instance x will expire soon, refreshing now log entries

Environment

1. OS type and version: golang:1.14-stretch image
2. Cloud SQL Proxy version (./cloud_sql_proxy -version): 1.17.0

[lindlof]

Thanks for looking into this @kurtisvg. I might have failed to elaborate this part but from what I have seen the new title is incorrect. Seems to me that ephemeral certificate refresh never failed. Connection to database failed and that caused ephemeral certificate to be refreshed. Can't see any reason for ephemeral certificate to be refreshed in this case but it did.

In our case there was a connection issue to the database IP address only. There was no issue with the Google APIs used to refresh ephemeral certificates.

From what I understand from the code is that Dial tries to connect to the database IP with the cached config. If database connection fails refreshCfg refreshes ephemeral certificate.

[kurtisvg]

@lindlof Apologies, I hadn't actually looked into it and was trying to update the title based on a quick scan of your original post (I wanted to avoid the phrase "leaking ephemeral certificate", which is what I thought I had read at first.)

I agree with your analysis that refreshCfg is leaking when called multiple times, and fixing it would involve making sure no more than one goroutine per instance coordinating refreshes.

[mo4islona]

Faced this issue in 1.19.1. Have master and 1 replica. Periodically it spams such logs

2021/02/04 18:08:06 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2-replica-0-XXXXX: will expire soon, refreshing now.
2021/02/04 18:08:08 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2: will expire soon, refreshing now.
2021/02/04 19:03:06 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2-replica-0-XXXXX: will expire soon, refreshing now.
2021/02/04 19:03:08 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2: will expire soon, refreshing now.
2021/02/04 19:58:06 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2-replica-0-XXXXX: will expire soon, refreshing now.
2021/02/04 19:58:08 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2: will expire soon, refreshing now.
2021/02/04 20:53:06 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2-replica-0-XXXXX: will expire soon, refreshing now.
2021/02/04 20:53:08 ephemeral certificate for instance XXXXX:europe-west2:db-instance-XXXXX-dev-2: will expire soon, refreshing now.

Connection fails by timeout. Restarted container works for some time
It is really annoying to do it manually for long running instances(