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

set read deadline for new conection to fix handshake stuck #861

Merged
merged 3 commits into from
May 7, 2024

Conversation

tangenta
Copy link
Contributor

We encountered a stuck issue caused by BinlogSyncer.close():

There is "syncer is closing" in log, but no "syncer is closed".

[info] binlogsyncer.go:206 syncer is closing...

Here are parts of the goroutines:

                                                 1   100% |   github.com/go-mysql-org/go-mysql/client.ConnectWithDialer github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/conn.go:109
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/client.(*Conn).handshake github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/conn.go:118
                                                 1   100% |   github.com/go-mysql-org/go-mysql/client.(*Conn).readInitialHandshake github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/auth.go:31
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/go-mysql-org/go-mysql/client.(*Conn).handshake github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/conn.go:118
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/client.(*Conn).readInitialHandshake github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/auth.go:31
                                                 1   100% |   github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacket github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:87 (inline)
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).newConnection github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:891
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/client.ConnectWithDialer github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/conn.go:109
                                                 1   100% |   github.com/go-mysql-org/go-mysql/client.(*Conn).handshake github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/conn.go:118
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/go-mysql-org/go-mysql/client.(*Conn).readInitialHandshake github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/auth.go:31 (inline)
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacket github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:87
                                                 1   100% |   github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacketReuseMem github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:97
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacket github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:87
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacketReuseMem github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:97
                                                 1   100% |   github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacketTo github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:149
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacketReuseMem github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:97
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacketTo github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/packet/conn.go:149
                                                 1   100% |   io.ReadFull io/io.go:351 (inline)
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/pingcap/tiflow/dm/syncer/binlogstream.(*StreamerController).resetReplicationSyncer github.com/pingcap/tiflow/dm/syncer/binlogstream/streamer_controller.go:259
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).Close github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:198
                                                 1   100% |   github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).close github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:223
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).Close github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:198
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).close github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:223
                                                 1   100% |   github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).newConnection github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:891
----------------------------------------------------------+-------------
                                                 1   100% |   github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).close github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:223
         0     0%   100%          1  0.89%                | github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).newConnection github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/replication/binlogsyncer.go:891
                                                 1   100% |   github.com/go-mysql-org/go-mysql/client.ConnectWithDialer github.com/go-mysql-org/go-mysql@v1.6.1-0.20221223014230-81966e15b9c5/client/conn.go:109

Because there is no deadline/timeout for readPacket, it may block forever.

This PR set timeout for all read operations of a connection.

@lance6716
Copy link
Collaborator

lance6716 commented Apr 30, 2024

We encountered a stuck issue caused by BinlogSyncer.close():

How long it has been stuck? I see that we set ReadTimeout to 1 minute, not sure it is too long for a cleanup logic in close

rest lgtm

@D3Hunter
Copy link
Contributor

D3Hunter commented May 7, 2024

We encountered a stuck issue caused by BinlogSyncer.close():

How long it has been stuck? I see that we set ReadTimeout to 1 minute, not sure it is too long for a cleanup logic in close

rest lgtm

met it again, blocks for 10 more hours, see pingcap/tiflow#11041

@lance6716 lance6716 merged commit 0ad0d03 into go-mysql-org:master May 7, 2024
13 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants