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

Add --wait-interval and $DBMATE_WAIT_INTERVAL to make wait interval configurable at runtime #516

Open
jessebye opened this issue Jan 24, 2024 · 7 comments

Comments

@jessebye
Copy link

Description

When using the --wait flag and dbmate up is run before the DB is ready, the logs are flooded with this message:

[mysql] 2024/01/24 19:58:12 packets.go:37: unexpected EOF

Eventually it stops when the DB is ready and it can run migrations:

[mysql] 2024/01/24 19:58:12 packets.go:37: unexpected EOF
[mysql] 2024/01/24 19:58:12 packets.go:37: unexpected EOF
Waiting for database.....................................................................................................................
Migrations complete.
Connecting to 127.0.0.1:15020 (127.0.0.1:15020)
  • Version: 2.11
  • Database: mysql
  • Operating System: Linux (official Docker container)

Steps To Reproduce
Set up a K8S job that will run the dbmate container against a K8S mysql pod. Restart the mysql pod then kick off the dbmate job with --wait flag. Observe the log messages.

Expected Behavior
I would expect to see the message Waiting for database and a . for each time it attempts connection until it succeeds.

@jessebye jessebye added the bug label Jan 24, 2024
@dossy
Copy link
Collaborator

dossy commented Jan 25, 2024

So, the error is being logged by the go-sql-driver/mysql driver, not by dbmate itself.

I suspect the issue is caused by how k8s implements cluster networking, specifically in the case where there's a Service that registers the port for the service but has no Pods available to forward that traffic to, yet. In this case, K8s is accepting the connection on its ingress, but then drops the connection as there's no Pod to forward it to, which the MySQL client treats as an unexpected EOF (end of file, or in this case, server-closed network connection) and the driver is implemented to log that occurrence.

We have no direct control over the MySQL driver's behavior itself, so the best we could do from the dbmate end would be to expose the DB.WaitInterval as a command-line argument, as it's currently defaulted to 1 second which could be quite noisy if it takes a few minutes for the Pod to become available.

I think adding --wait-interval and $DBMATE_WAIT_INTERVAL as ways of setting the interval could be a useful addition, but ultimately I suspect just ignoring the noisy logging from the go-sql-driver/mysql driver is the path of least resistance ... 😄

@jessebye, what do you think?

@jessebye
Copy link
Author

@dossy seems like a reasonable approach, given the context 👍

@dossy dossy changed the title packets.go unexpected EOF when using --wait and database is not ready Add --wait-interval and $DBMATE_WAIT_INTERVAL to make wait interval configurable at runtime Jan 25, 2024
@Mizaro
Copy link

Mizaro commented May 12, 2024

I would like to contribute code to this issue if we decide that it should be implemented @dossy .

@dossy
Copy link
Collaborator

dossy commented May 13, 2024

I would like to contribute code to this issue if we decide that it should be implemented @dossy .

I think that as long as the implementation preserves the current behavior by default, I think a contribution implementing this configurability would be useful to those who need it.

While there don't appear to be too many people who have come forward look for or needing this functionality, it is certainly a quality-of-life improvement that some folks may appreciate.

@amacneil
Copy link
Owner

I think we should silence any errors from mysql driver while we are in the "wait" operation. If there are any real error messages people need to uncover for debugging, they can run any other dbmate command.

Adding --wait-interval cli flag seems reasonable (it is already exposed to API users), but it's not going to prevent this spam going to the console. So let's fix that first.

@dossy
Copy link
Collaborator

dossy commented May 19, 2024

I think we should silence any errors from mysql driver while we are in the "wait" operation. If there are any real error messages people need to uncover for debugging, they can run any other dbmate command.

Adding --wait-interval cli flag seems reasonable (it is already exposed to API users), but it's not going to prevent this spam going to the console. So let's fix that first.

How do you feel about emitting the errors if and when --verbose is also specified?

@amacneil
Copy link
Owner

How do you feel about emitting the errors if and when --verbose is also specified?

Do we need it?

The wait command expects an error. Encountering an error is a normal part of its operation - that is the whole point of the command, to attempt a connection, and if there is an error to catch it and retry. For all other database drivers today we handle and suppress the error details.

In this case, the mysql driver is taking matters into its own hands and spewing some console output about an error in addition to returning an error. I think that is bad behavior of the driver and we should suppress it (along with the error which we already suppress).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants