[SERVER-13972] connections_opened.js failure Created: 04/Apr/14  Updated: 11/Mar/15  Resolved: 30/Apr/14

Status: Closed
Project: Core Server
Component/s: Testing Infrastructure
Affects Version/s: None
Fix Version/s: 2.6.2, 2.7.0

Type: Bug Priority: Minor - P4
Reporter: Randolph Tan Assignee: Spencer Brody (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File connections_opened.log    
Issue Links:
Depends
depends on SERVER-13745 Provide way to override the default 5... Closed
Related
is related to SERVER-13700 Improve logging of socket connect tim... Closed
is related to SERVER-13771 Increase connect timeout in shell fro... Closed
Operating System: ALL
Backport Completed:
Participants:
Linked BF Score: 0

 Description   

http://buildlogs.mongodb.org/mci_0.9_windows_64_2k8_debug/builds/43780/test/noPassthroughWithMongod_2/connections_opened.js
https://mci.10gen.com/ui/task/mongodb_mongo_v2.6_windows_64_2k8_debug_8a71a071e54d96361fcabb992cd82f60ce413eb8_14_04_02_22_09_07_noPassthroughWithMongod_windows_64_test

 EDT	
assert.soon failed: function () {
                    currentConnInfo = db.serverStatus().connections;
                    return (expectedCurrentConnections == currentConnInfo.current) &&
                        (expectedTotalConnections, currentConnInfo.totalCreated);
                }, msg:Incorrect connection numbers. Expected 201 current connections and 201 total connections. Connection info from serverStatus: { "current" : 200, "available" : 999800, "totalCreated" : NumberLong(201) }
Error: assert.soon failed: function () {
                    currentConnInfo = db.serverStatus().connections;
                    return (expectedCurrentConnections == currentConnInfo.current) &&
                        (expectedTotalConnections, currentConnInfo.totalCreated);
                }, msg:Incorrect connection numbers. Expected 201 current connections and 201 total connections. Connection info from serverStatus: { "current" : 200, "available" : 999800, "totalCreated" : NumberLong(201) }
    at Error (<anonymous>)
    at doassert (src/mongo/shell/assert.js:11:14)
    at Function.assert.soon (src/mongo/shell/assert.js:180:60)
    at waitForConnections (D:\data\mci\git@github.commongodb\mongo.git\mongodb-mongo-v2.6\jstests\noPassthroughWithMongod\connections_opened.js:34:12)
    at D:\data\mci\git@github.commongodb\mongo.git\mongodb-mongo-v2.6\jstests\noPassthroughWithMongod\connections_opened.js:73:1

http://buildlogs.mongodb.org/mci_0.9_windows_64_debug/builds/42074/test/noPassthroughWithMongod_0/connections_opened.js
https://mci.10gen.com/ui/task/mongodb_mongo_master_windows_64_debug_789097cb1823b849e6598ac8e4a3ecff9befd682_14_04_03_18_03_07_noPassthroughWithMongod_windows_64_test

T	
assert.soon failed: function () {
                    currentConnInfo = db.serverStatus().connections;
                    return (expectedCurrentConnections == currentConnInfo.current) &&
                        (expectedTotalConnections, currentConnInfo.totalCreated);
                }, msg:Incorrect connection numbers. Expected 201 current connections and 201 total connections. Connection info from serverStatus: { "current" : 194, "available" : 999806, "totalCreated" : NumberLong(195) }
Error: assert.soon failed: function () {
                    currentConnInfo = db.serverStatus().connections;
                    return (expectedCurrentConnections == currentConnInfo.current) &&
                        (expectedTotalConnections, currentConnInfo.totalCreated);
                }, msg:Incorrect connection numbers. Expected 201 current connections and 201 total connections. Connection info from serverStatus: { "current" : 194, "available" : 999806, "totalCreated" : NumberLong(195) }
    at Error (<anonymous>)
    at doassert (src/mongo/shell/assert.js:11:14)
    at Function.assert.soon (src/mongo/shell/assert.js:180:60)
    at waitForConnections (D:\data\mci\git@github.commongodb\mongo.git\mongodb-mongo-master\jstests\noPassthroughWithMongod\connections_opened.js:34:12)
    at D:\data\mci\git@github.commongodb\mongo.git\mongodb-mongo-master\jstests\noPassthroughWithMongod\connections_opened.js:73:1



 Comments   
Comment by Githook User [ 16/May/14 ]

Author:

{u'username': u'stbrody', u'name': u'Spencer T Brody', u'email': u'spencer@mongodb.com'}

Message: SERVER-13972 Make connections_opened.js test retry any connections that fail to connect
(cherry picked from commit b64939f3ac16843525adf6f0e893a78409ddaf16)
Branch: v2.6
https://github.com/mongodb/mongo/commit/0366e4a86262a89e329fabbadde06e14bd4a33cb

Comment by Eric Milkie [ 16/May/14 ]

It is okay to backport. Unfortunately, that commit has no associated server ticket so it will be hard to track the backport process.

Comment by Siyuan Zhou [ 16/May/14 ]

It seems this issue happened on v2.6 branch. https://mci.10gen.com/ui/task/mongodb_mongo_v2.6_windows_64_2k8_debug_f076d57d427e7fde945303aaec32ba594de5872c_14_05_16_00_22_40_noPassthroughWithMongod_windows_64_2k8_debug

spencer - is it appropriate to backport this change to 2.6?

Comment by Spencer Brody (Inactive) [ 30/Apr/14 ]

That last commit should have fixed this. I'm going to resolve this issue until/unless this happens again.

Comment by Spencer Brody (Inactive) [ 29/Apr/14 ]

https://github.com/mongodb/mongo/commit/b64939f3ac16843525adf6f0e893a78409ddaf16

Comment by Eric Milkie [ 28/Apr/14 ]

If a server is overloaded and you'd like to be able to log in with the shell to save it, you probably would like to have a connect timeout longer than 5 seconds. I think it should be raised regardless of pending refactoring, as long as it is easy to change in the shell code itself.

Comment by Spencer Brody (Inactive) [ 28/Apr/14 ]

https://mci.10gen.com/ui/task/mongodb_mongo_master_windows_64_2k8_debug_381a35be63129419516c77825c2a27e7fc447e63_14_04_27_15_15_06_noPassthroughWithMongod_windows_64_2k8_debug

Comment by J Rassi [ 26/Apr/14 ]

this test is spawning hundreds of mongo shell processes on the same machine as the server, and in five seconds expects all of them to complete their connect() calls (and then release the socket mutex to the respective connectbg threads). this seems reasonable to expect for the release builds, but not (at all!) for the debug builds.

after reflecting, i think this test should be disabled on the debug buildvariants. i don't think we should shoehorn connect timeout logic into the network subsystem right now, and that we should just wait to address the underlying issue until we give that subsystem a proper refactor.

Comment by Eric Milkie [ 25/Apr/14 ]

Yes.

Comment by Spencer Brody (Inactive) [ 25/Apr/14 ]

https://mci.10gen.com/ui/task/mongodb_mongo_master_windows_64_2k8_debug_e02aec12a1af456223482fa0e968440700f2e7cc_14_04_24_15_49_06_noPassthroughWithMongod_windows_64_2k8_debug

sh3192| 2014-04-24T19:02:45.928+0000 warning: Failed to connect to 127.0.0.1:27000 after 5000 milliseconds, giving up.
sh3192| 2014-04-24T19:02:45.930+0000 Error: couldn't connect to server localhost:27000 (127.0.0.1), connection attempt failed at src/mongo/shell/mongo.js:148
sh3192| exception: connect failed

This verifies that the failure is a connection timeout. Not clear why the connection attempt is taking so long though...

milkie - do you think we should increase the default connection timeout from 5 seconds?

Comment by Spencer Brody (Inactive) [ 23/Apr/14 ]

Hopefully https://github.com/mongodb/mongo/commit/bd1f40ab79656b14874bf3c496ad93fcffa89413 should reveal if this is a simple timeout.

Comment by Randolph Tan [ 07/Apr/14 ]

Another failure:
https://mci.10gen.com/ui/task/mongodb_mongo_v2.6_windows_64_2k8_debug_1c1c76aeca21c5983dc178920f5052c298db616c_14_04_07_00_44_06_noPassthroughWithMongod_windows_64_test

Generated at Thu Feb 08 03:33:27 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.