[SERVER-8889] Missing 'connection accepted' entry in mongos log Created: 07/Mar/13  Updated: 08/Mar/13  Resolved: 08/Mar/13

Status: Closed
Project: Core Server
Component/s: Diagnostics, Logging, Sharding
Affects Version/s: 2.2.1
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: James Blackburn Assignee: sam.helman@10gen.com
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: Linux
Participants:

 Description   

Trying to get to the bottom of PYTHON-482 where sockets block forever in read from a mongos on a sharded cluster. We came across an instance where the mongos log appears to be missing events.

The mongos log we have contains these entries (no events have been chopped):

Wed Mar  6 16:47:56 [conn4706]  authenticate db: admin { authenticate: 1, nonce: "616360f77e999eb6", user: "ahldev", key: "ca1a6a071af25060bae233a30e9c8e6d" }
Wed Mar  6 16:48:00 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' acquired, ts : 5137733f7bb46eb6d5eed4f5
Wed Mar  6 16:48:00 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' unlocked. 
Wed Mar  6 16:48:18 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' acquired, ts : 513773527bb46eb6d5eed4f6
Wed Mar  6 16:48:18 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' unlocked. 
Wed Mar  6 16:48:24 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' acquired, ts : 513773587bb46eb6d5eed4f7
Wed Mar  6 16:48:24 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' unlocked. 
Wed Mar  6 16:48:41 [conn4706] end connection 127.0.0.1:54309 (2 connections now open)
Wed Mar  6 16:48:54 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' acquired, ts : 513773767bb46eb6d5eed4f8
Wed Mar  6 16:48:54 [Balancer] distributed lock 'balancer/dlonapahls200.maninvestments.com:27119:1362572650:1804289383' unlocked. 
Wed Mar  6 16:49:08 [mongosMain] connection accepted from 127.0.0.1:54624 #4707 (3 connections now open)
Wed Mar  6 16:49:08 [conn4707] end connection 127.0.0.1:54624 (2 connections now open)
Wed Mar  6 16:49:08 [mongosMain] connection accepted from 127.0.0.1:54625 #4708 (3 connections now open)
Wed Mar  6 16:49:08 [conn4708]  authenticate db: admin { authenticate: 1, nonce: "c9a6ca2e71b590a7", user: "ahldev", key: "2f864d0041a557ff0dfdae6a472d22d0" }

Note there is no line: [mongosMain] connection accepted from x.x.x.x:y #4707



 Comments   
Comment by James Blackburn [ 08/Mar/13 ]

We're upgrading to 2.2.3 today.

Looks like I was being blind in that logfile - the connection is created immediately before it is closed. Sorry for the noise, please close this issue.

Comment by sam.helman@10gen.com [ 08/Mar/13 ]

Hello,

To make sure we understand correctly, is that the very beginning of the mongos log (from when it came up)? This is where the log starts in PYTHON-482 as well.

Can you provide any sort of script to reproduce this? I also notice that you are running server version 2.2.3 - the most recent build of 2.2.x is 2.2.3, and we recommend upgrading and seeing if the issue (as well as PYTHON-482) persists.

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