[SERVER-20125] ReplicaSet Cluster log lots of "9001 SocketException" Created: 26/Aug/15  Updated: 27/Apr/18  Resolved: 03/Sep/15

Status: Closed
Project: Core Server
Component/s: Replication
Affects Version/s: 3.0.4
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: YANG Chenghu Assignee: Sam Kleinman (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Linux Redhat6


Issue Links:
Backports
backports NODE-1439 SocketException on mongo nodes Closed
Participants:

 Description   

Deployed a ReplicaSet Cluster, watch mongod.log, log "9001 socket exception [CLOSED]" every 30 seconds

log content:

2015-08-26T14:22:35.844+0800 I -        [conn447]
 0xfe6e9e 0xf7e2bf 0xfacc5b 0xfb06d2 0xfb099c 0xfb09a9 0xfb09f5 0xfa7123 0xfa97f7 0x3001c07851 0x30018e767d
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"400000","o":"BE6E9E"},{"b":"400000","o":"B7E2BF"},{"b":"400000","o":"BACC5B"},{"b":"400000","o":"BB06D2"},{"b":"400000","o":"BB099C"},{"b":"400000","o":"BB09A9"},{"b":"400000","o":"BB09F5"},{"b":"400000","o":"BA7123"},{"b":"400000","o":"BA97F7"},{"b":"3001C00000","o":"7851"},{"b":"3001800000","o":"E767D"}],"processInfo":{ "mongodbVersion" : "3.0.4", "gitVersion" : "66de49a84c1d09c03b1c637cee13635bcaacd04b", "uname" : { "sysname" : "Linux", "release" : "2.6.32-220.23.2.ali878.el6.x86_64", "version" : "#1 SMP Mon Jan 28 17:12:52 CST 2013", "machine" : "x86_64" }, "somap" : [ { "elfType" : 2, "b" : "400000", "buildId" : "C3D8239ECDF3B80FA9611686D39384ADF8B47787" }, { "b" : "7FFF04AFF000", "elfType" : 3, "buildId" : "505D1DB16903CBB2ECAC8DD8137C641A63080C97" }, { "path" : "/lib64/libpthread.so.0", "elfType" : 3, "buildId" : "48A9F8600F0A15F6418EDE25846C324EC8891DD4" }, { "path" : "/lib64/librt.so.1", "elfType" : 3, "buildId" : "1574F9C2DDAECEE537C45143BB79E8D61BED98FE" }, { "path" : "/lib64/libdl.so.2", "elfType" : 3, "buildId" : "0B4FE52FE93C0B9894775AFDD53E2DF9D3C2839A" }, { "path" : "/usr/lib64/libstdc++.so.6", "elfType" : 3, "buildId" : "B8350DC16926B2780F2D65E4411BD945594F630F" }, { "path" : "/lib64/libm.so.6", "elfType" : 3, "buildId" : "BF14593D7915402AA62C2573FCCDB252AEEBF754" }, { "path" : "/lib64/libgcc_s.so.1", "elfType" : 3, "buildId" : "D8405BCE908D0284AC52BAEAB32CE3F7911B8C27" }, { "path" : "/lib64/libc.so.6", "elfType" : 3, "buildId" : "3AC348A69F62BFC2280DA1A8188173961BB2E9BE" }, { "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "42AEFAFC23375DC250C49C420C37EDC4515B9C02" }, { "b" : "7FA717A30000", "path" : "/usr/lib64/gconv/ISO8859-1.so", "elfType" : 3, "buildId" : "5EA241EDDC9B76C60052AC759F76C3C23974522A" } ] }}
 mongod(_ZN5mongo15printStackTraceERSo+0x2E) [0xfe6e9e]
 mongod(_ZN5mongo11DBException13traceIfNeededERKS0_+0x16F) [0xf7e2bf]
 mongod(+0xBACC5B) [0xfacc5b]
 mongod(_ZN5mongo6Socket15handleRecvErrorEii+0x4B2) [0xfb06d2]
 mongod(_ZN5mongo6Socket5_recvEPci+0x4C) [0xfb099c]
 mongod(_ZN5mongo6Socket11unsafe_recvEPci+0x9) [0xfb09a9]
 mongod(_ZN5mongo6Socket4recvEPci+0x35) [0xfb09f5]
 mongod(_ZN5mongo13MessagingPort4recvERNS_7MessageE+0xA3) [0xfa7123]
 mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x3C7) [0xfa97f7]
 libpthread.so.0(+0x7851) [0x3001c07851]
 libc.so.6(clone+0x6D) [0x30018e767d]
-----  END BACKTRACE  -----
2015-08-26T14:22:35.844+0800 D NETWORK  [conn447] SocketException: remote: 10.189.195.0:40411 error: 9001 socket exception [CLOSED] server [10.189.195.0:40411]

Check source code, about cleanUpOlderThan_inlock.

MongoDB ConnectionPool will close the connection that before 30 seconds creating, but, it's not pretty.

it should be it not used in 30 seconds



 Comments   
Comment by YANG Chenghu [ 25/Sep/15 ]

thanks for you reply, I think mongod closed the socket connection every 30 seconds is not sensible.
closing socket may avoid socket exception state, cause mistake judgement. but in the high load, create socket may spend a lot of time.
i think the better logic is, just closing the 30 second never used socket.

cleanUpOlderThan_inlock {
     if (socket.last_usedtime > 30 second) {
         socket.close();
     }
}

onRpcFinished {
   socket.last_usedtime = now();
}

Comment by Sam Kleinman (Inactive) [ 03/Sep/15 ]

It looks like you have set systemLog.traceAllExceptions to true. You can change the presence of the backtrace data at runtime using the traceExceptions parameter.

You may also want to consider configuring or modifying your own logrotation system to control how you persist and store log data.

The SERVER project is for tracking bugs and issue requests related to the core MongoDB server product. Questions like this are probably best addressed to one of our support channels.

Regards,
sam

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