[SERVER-35399] MongoDB Server not received client metadata Created: 05/Jun/18  Updated: 23/Jul/18  Resolved: 15/Jun/18

Status: Closed
Project: Core Server
Component/s: Logging, WiredTiger
Affects Version/s: 3.4.0
Fix Version/s: None

Type: Question Priority: Major - P3
Reporter: Sandeep [X] Assignee: Nick Brewer
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File db.adminCommandOutput-10062018.json    
Issue Links:
Related
is related to SERVER-29109 Client metadata log message verbosity... Open
Participants:

 Description   

Dear Team,

A critical issues observed at our side.

MongoTimeoutException is occurring even when DB is running!!

we observed that MOngoServer didnt receive any metadata from the client-172.29.105.17.

Note: Both Client and MOngoServer are running on same Machine

Detailed Scenario is described below 

As observed from the  MongoDB  logs 

on 1st may 2018

2018-05-01T16:26:25.089-0400 I STORAGE [initandlisten] Service running
2018-05-01T16:26:25.089-0400 I NETWORK [thread1] waiting for connections on port 8090
{{2018-05-01T16:26:29.642-0400 I NETWORK [conn1] received client metadata from 172.29.105.17:64758 conn1: { driver:

Unknown macro: { name}

, os: { type: "Windows", name: "Windows Server 2012 R2", architecture: "x86", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_144-b01" }}}
{{2018-05-01T16:26:29.854-0400 I NETWORK [conn2] received client metadata from 172.29.105.17:64759 conn2: { driver:

Unknown macro: { name}

, os: { type: "Windows", name: "Windows Server 2012 R2", architecture: "x86", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_144-b01" }}}

on 12th may 2018

2018-05-12T17:24:33.148-0400 I CONTROL [main] Trying to start Windows service 'SRDMDbServer8090'
2018-05-12T17:24:33.224-0400 I CONTROL [initandlisten] MongoDB starting : pid=1404 port=8090 dbpath=C:\SRDM\SRDM2.5.0.11308.17\SRDM\Svr\DBService\bin64\..\data\db 64-bit host=WIN-OHPM52MOHG1
2018-05-12T17:24:45.446-0400 I STORAGE [initandlisten] Service running
2018-05-12T17:24:45.464-0400 I NETWORK [thread1] waiting for connections on port 8090

 

So, between  1st may 2018 & 12th may 2018 the difference we observed was server did'nt receive metadata from client .

hence when CLient initiate any DB Operations MOngoDB Timeout exceptions is occured with 

com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches ReadPreferenceServerSelector{readPreference=primary}. Client view of cluster state is {type=UNKNOWN, servers=[{address=172.29.105.17:8090, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by \{java.net.SocketException: Network is unreachable: connect}}]

Please let us know Why DB Operations is not successful in above said scenario??

Thanks & Regards

Sandeep KS

 

 



 Comments   
Comment by Nick Brewer [ 20/Jun/18 ]

Sandeep,

The error you're receiving indicates that the client is not able to reach the the mongod:

com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches ReadPreferenceServerSelector{readPreference=primary}. Client view of cluster state is {type=UNKNOWN, servers=[{address=172.29.105.17:8090, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by \{java.net.SocketException: Network is unreachable: connect}}]

It looks like you have both the client and the mongod running on the same Windows machine. One thing that sticks out here is that it appears that you were previously starting mongod on port 8090, however the getCmdLineOpts output you provided suggests that it is configured to listen on port 8099 - if you've changed the port that it's set to listen on, have you updated the command you're using to connect the client as well?

Before you attempt to connect the client, try using the following command to confirm that mongod is listening on the desired port:

netstat -aon |find /i "listening" |find "8099"

The use of readPreference=primary indicates that you're using a replica set - if this is the case, could you please attach the full output of rs.conf()? Also, what happens if you change your read preference to readPreference=primaryPreferred ?

Finally, it would be helpful to see the full command that you're using to attempt to connect to the mongod and perform CRUD operations, along with any logs from:

  • A time when you were able to connect successfully
  • More detailed logs from a time when you were unable to connect

You may need to remove the quiet: true setting for more verbose logging of failed connections.

Nick

Comment by Sandeep [X] [ 20/Jun/18 ]

Dear Nick,

Thank you for the support!

I agree with you that quiet: true option will suppress "Connection received" but this will not suppress "received client metadata".

This bug/ticket SERVER-35399 is not about include/not include in mongodb logs.

Rather this ticket is about why the Client is not able to perform any CURD Operations while MongoDB Server is running !!

Note: I have Posted the same ticket in mongodb-user-group as well https://groups.google.com/forum/#!topic/mongodb-user/vPCZcJT8toU

Hence Please let us know Why DB Operations is not successful in above said scenario??

Thanks & Regards

Sandeep KS

Comment by Nick Brewer [ 14/Jun/18 ]

Hi,

You're running mongod with the "quiet" : true option, which suppresses "connection received" and "end connection" messages, but does not currently suppress "received client metadata" messages. We're working on fixing this behavior to include those messages, and the relevant ticket for that change had been attached to this one.

In the instances where you're not seeing the "received client metadata" notifications, the cause is most likely that the client is failing to connect altogether - however this wouldn't be related to any inability on the part of the mongod server to accept client metadata.

If you are running into an issue connecting to your mongod install, I'd suggest making a post on the mongodb-user group or Stack Overflow with the mongodb tag.

Regards,
Nick

Comment by Sandeep [X] [ 14/Jun/18 ]

Dear Nick,

I have attached the request command output .<<db.adminCommandOutput-10062018.json>>

Let us any other information required if any to facilitate your support

db.adminCommandOutput-10062018.json

Thanks & Regards

Sandeep KS

Comment by Nick Brewer [ 13/Jun/18 ]

Hi,

We'd like to see the output of the following command:

db.adminCommand( { getCmdLineOpts: 1  } )

This will let us evaluate the settings that are being passed to mongod on startup. Since this is a public project, feel free to redact any hostnames or other sensitive information, but please leave the configuration options intact.

Thanks,
Nick

Comment by Jeffrey Yemin [ 12/Jun/18 ]

Yes, it was added in 3.4.0 in scope of JAVA-2266.  

Is there any evidence that the application was able to establish a connection the server at all, let alone include client metadata as part of the isMaster command that the driver sends after successfully connecting?

Comment by Mark Benvenuto [ 12/Jun/18 ]

jeff.yemin Does the Java Driver version 3.4.0 send client metadata to the server?

Comment by Sandeep [X] [ 12/Jun/18 ]

Dear Mark,

Please find details as below:

  •  ** MongoDB is running as window service .
  • targetMinOS: Windows 7/Windows Server 2008 R2
  • db version:: v3.4.0(*Affects Version/s:*3.4.0)
  • MongoDB Java driver version::3.4.0
    • *Name of driver:*mongo-java-driver-3.4.0.jar
  • target_arch:: 64 bit OS

Please let us know if you need any other information 

Thanks & Regards

Sandeep KS

 

Comment by Mark Benvenuto [ 11/Jun/18 ]

Dear Sandeep,

What driver and version are using to connect to MongoDB? Which version of MongoDB are you using?

Thanks

Mark

Comment by Sandeep [X] [ 11/Jun/18 ]

Dear Team,

Please let us know Why DB Operations is not successful When MongoDB Server  was unable to received client metadata message as observed from the MongoDB Logs.!!

Note: MongoDB Server is running in the above said case **

Also I have posted a query as below 

https://groups.google.com/forum/#!topic/mongodb-user/vPCZcJT8toU

 

Thanks & Regards

Sandeep KS

Comment by Sandeep [X] [ 06/Jun/18 ]

Dear Team,

May I request MongoDB Team  to provide us the support for the above said Issue please...?

Thanks & Regards

Sandeep KS

Generated at Thu Feb 08 04:39:42 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.