[GODRIVER-1695] heartbeats should always use connectTimeout as socket timeout Created: 16/Jul/20  Updated: 28/Oct/23  Resolved: 30/Jul/20

Status: Closed
Project: Go Driver
Component/s: None
Affects Version/s: None
Fix Version/s: 1.4.0, 1.3.6

Type: Bug Priority: Major - P3
Reporter: Suraj Narkhede Assignee: Isabella Siu (Inactive)
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
is related to GODRIVER-1708 Monitoring routine does not correctly... Closed
Backwards Compatibility: Minor Change

 Description   

When the socket timeout is set, the heartbeat loop uses that instead of using connect timeout as the timeout.



 Comments   
Comment by Divjot Arora (Inactive) [ 10/Aug/20 ]

bartle Just wanted to let you know that we've released 1.3.7 with the fix for GODRIVER-1708. Once again, thanks for reporting and debugging this!

Comment by David Bartley [ 07/Aug/20 ]

+1, looks good to me.

Comment by Divjot Arora (Inactive) [ 07/Aug/20 ]

bartle I've got a PR up for GODRIVER-1708 at https://github.com/mongodb/mongo-go-driver/pull/475/files. Feel free to take a look and comment. If all is fine in CI, we'll likely merge early next week.

Comment by David Bartley [ 07/Aug/20 ]

Thanks!

Comment by Divjot Arora (Inactive) [ 07/Aug/20 ]

bartle I filed GODRIVER-1708 for this. We're planning on expediting out a 1.3.7 release next week with the bugfix. Thanks for reporting!

Comment by Divjot Arora (Inactive) [ 07/Aug/20 ]

bartle Yeah, I think that's right. This is due to a difference in the 1.4.0 and 1.3.x branches because we made significant changes to the heartbeating code in 1.4.0.

Comment by David Bartley [ 07/Aug/20 ]

I think this broke averageRTT updating, at least on the 1.3 branch.  We used to set "now = time.Now()" on https://github.com/mongodb/mongo-go-driver/commit/61c371255d98bb1a9556ad0f5b38d48635a24bbf#diff-cc0b094d8ce69672d7e2ff6da8ff60f5L479, but when that block was moved into "createConnection" we lost that.  That means that when later call desc = desc.SetAverageRTT(s.updateAverageRTT(delay)), we'll compute delay as time.Since(time.Time{}).

Comment by Githook User [ 30/Jul/20 ]

Author:

{'name': 'Isabella Siu', 'email': 'isabella.siu@10gen.com', 'username': 'iwysiu'}

Message: GODRIVER-1695 always use heartbeatTimeout for heartbeat connection (#470)
Branch: release/1.3
https://github.com/mongodb/mongo-go-driver/commit/61c371255d98bb1a9556ad0f5b38d48635a24bbf

Comment by Githook User [ 30/Jul/20 ]

Author:

{'name': 'Isabella Siu', 'email': 'isabella.siu@10gen.com', 'username': 'iwysiu'}

Message: GODRIVER-1695 always use heartbeatTimeout for heartbeat connection (#470)
Branch: release/1.4
https://github.com/mongodb/mongo-go-driver/commit/d3ceaf30fad597f8bb0a08a3eb7a7310f159169f

Comment by Githook User [ 30/Jul/20 ]

Author:

{'name': 'Isabella Siu', 'email': 'isabella.siu@10gen.com', 'username': 'iwysiu'}

Message: GODRIVER-1695 always use heartbeatTimeout for heartbeat connection (#470)
Branch: master
https://github.com/mongodb/mongo-go-driver/commit/a8b8f62c130771f1d0edf3e5bbe73df71a3f4c56

Comment by Isabella Siu (Inactive) [ 28/Jul/20 ]

Hi surajn.vnit@gmail.com,

Thanks for the repro! The fix for this should be in the next release

Comment by Suraj Narkhede [ 27/Jul/20 ]

Hi Isabella Siu, Thank you for looking into this.

I think that timeout is not honored if SocketTimeout is set on client. Is that the expected behavior?

I can reproduce the issue with - https://play.golang.org/p/oAsNvIYASo2.

1) Start a replset with 3 nodes.

2) Start the script.

3) Add iptable rule to drop traffic to one of secondary port.

I added a log line in driver to determine the time it takes to execute IsMaster, and I see 

time for isMaster: addr=127.0.0.1:27017 time=1m0.000088482s 

Comment by Isabella Siu (Inactive) [ 23/Jul/20 ]

Hi surajn.vnit@gmail.com,

The heartbeatTimeout actually gets passed into the operation's connection directly, and thus doesn't need to be passed into the operation: https://github.com/mongodb/mongo-go-driver/blob/v1.3.5/x/mongo/driver/topology/server.go#L470-L474

I tested this earlier to double check, and confirmed that even if the server hangs for 20 seconds, op.Execute will return after 10 seconds.

Does this clarify the driver's behavior? If so, we can go ahead and close out this ticket.

Comment by Suraj Narkhede [ 22/Jul/20 ]

Hi – did you get a chance to look into this?

Comment by Suraj Narkhede [ 17/Jul/20 ]

https://github.com/mongodb/mongo-go-driver/pull/460

Comment by Suraj Narkhede [ 17/Jul/20 ]

I am referring to https://github.com/mongodb/mongo-go-driver/blob/v1.3.5/x/mongo/driver/topology/server.go#L500-L505.

Generated at Thu Feb 08 08:36:56 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.