[SERVER-40556] Error: error doing query: failed: network error while attempting to run command 'buildinfo' Created: 10/Apr/19  Updated: 04/Sep/19  Resolved: 04/Sep/19

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

Type: Bug Priority: Major - P3
Reporter: donghua liu Assignee: Danny Hatcher (Inactive)
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File image-2019-06-11-16-24-26-876.png    
Issue Links:
Related
is related to SERVER-40583 Provide reason for why connections ar... Closed
Operating System: ALL
Steps To Reproduce:
  1. install the latest 4.0.8 on both Windows and ubuntu
  2. try to use the Windows client mongo to connect to the ubuntu server.
Participants:

 Description   

I installed both the latest version of mongodb 4.0.8 on my Windows and two ubuntu servers. If I tried to connect from Windows to ubuntu, I got the following errors.

C:\Users\Liu.D.H>mongo 113.55.14.114
MongoDB shell version v4.0.8
connecting to: mongodb://113.55.14.114:27017/test?gssapiServiceName=mongodb
Implicit session: session { "id" : UUID("b84061bf-e308-47f7-b59f-6c2940ba450d") }
2019-04-10T08:55:12.522+0800 E QUERY    [js] Error: error doing query: failed: network error while attempting to run command 'buildinfo' on host '113.55.14.114:27017'  :
DB.prototype.runCommand@src/mongo/shell/db.js:168:1
DB.prototype.adminCommand@src/mongo/shell/db.js:186:16
DB.prototype.serverBuildInfo@src/mongo/shell/db.js:1275:16
DB.prototype.version@src/mongo/shell/db.js:1327:16
connect@src/mongo/shell/mongo.js:363:29
@(connect):2:6
2019-04-10T08:55:12.526+0800 I NETWORK  [js] trying reconnect to 113.55.14.114:27017 failed
2019-04-10T08:55:12.529+0800 I NETWORK  [js] reconnect 113.55.14.114:27017 ok
exception: connect failed
 
C:\Users\Liu.D.H>

I tried to check the logs on server. `journalctl -u mongod` showed nothing erros. `sudo tail -f /var/log/mongodb/mongod.log` showed the following related errors.

2019-04-09T20:55:09.170-0400 I NETWORK  [listener] connection accepted from 113.55.127.140:3455 #3014 (1 connection now open)
2019-04-09T20:55:09.171-0400 I NETWORK  [conn3014] received client metadata from 113.55.127.140:3455 conn3014: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Windows", name: "Microsoft Windows 10", architecture: "x86_64", version: "10.0 (build 17763)" } }
2019-04-09T20:55:09.176-0400 I NETWORK  [conn3014] end connection 113.55.127.140:3455 (0 connections now open)
2019-04-09T20:55:09.182-0400 I NETWORK  [listener] connection accepted from 113.55.127.140:3456 #3015 (1 connection now open)
2019-04-09T20:55:09.182-0400 I NETWORK  [conn3015] received client metadata from 113.55.127.140:3456 conn3015: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Windows", name: "Microsoft Windows 10", architecture: "x86_64", version: "10.0 (build 17763)" } }
2019-04-09T20:55:09.184-0400 I NETWORK  [conn3015] end connection 113.55.127.140:3456 (0 connections now open)

The config file of the server was the following.

# mongod.conf
 
# for documentation of all options, see:
#   http://docs.mongodb.org/manual/reference/configuration-options/
 
# Where and how to store data.
storage:
  dbPath: /var/lib/mongodb
  journal:
    enabled: true
#  engine:
#  mmapv1:
#  wiredTiger:
 
# where to write logging data.
systemLog:
  destination: file
  logAppend: true
  path: /var/log/mongodb/mongod.log
 
# network interfaces
net:
  port: 27017
  bindIp: 0.0.0.0
 
 
# how the process runs
processManagement:
  timeZoneInfo: /usr/share/zoneinfo
 
security:
  authorization: enabled
 
#operationProfiling:
 
#replication:
 
#sharding:
 
## Enterprise-Only Options:
 
#auditLog:
 
#snmp:

I can confirm If I tried to connect between the two ubuntu or connect from ubuntu to Windows, it's worked as expected.

 



 Comments   
Comment by Danny Hatcher (Inactive) [ 29/Jul/19 ]

Have you had a chance to try this again?

Comment by Danny Hatcher (Inactive) [ 25/Jun/19 ]

Unfortunately, nothing in the logs indicate an issue so the only thing we have to go off of is a generic error message from the shell. In 4.0.10 we improved that error message to provide more detail. Would it be possible to upgrade to 4.0.10 and try connecting again to see if you get a different error?

Additionally, have you tried connecting with a simple application instead of the shell? The shell should work regardless but I want to identify if this is a shell issue or a general connection issue.

Comment by donghua liu [ 21/Jun/19 ]

@Daniel Hatcher, Hi, I cleared the log and then restart and reconnect. The same error like above. Here is the full contents of logging.

wlzx@ubuntu:/var/log/mongodb$ sudo cat mongod.log 
2019-06-20T22:01:58.114-0400 I CONTROL  [main] ***** SERVER RESTARTED *****
2019-06-20T22:01:58.117-0400 I CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] MongoDB starting : pid=48874 port=27017 dbpath=/var/lib/mongodb 64-bit host=ubuntu
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] db version v4.0.8
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] git version: 9b00696ed75f65e1ebc8d635593bed79b290cfbb
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] allocator: tcmalloc
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] modules: none
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] build environment:
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten]     distmod: ubuntu1604
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten]     distarch: x86_64
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten]     target_arch: x86_64
2019-06-20T22:01:58.126-0400 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "0.0.0.0", port: 27017 }, processManagement: { timeZoneInfo: "/usr/share/zoneinfo" }, security: { authorization: "enabled" }, storage: { dbPath: "/var/lib/mongodb", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2019-06-20T22:01:58.126-0400 I STORAGE  [initandlisten] Detected data files in /var/lib/mongodb created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2019-06-20T22:01:58.127-0400 I STORAGE  [initandlisten] 
2019-06-20T22:01:58.127-0400 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2019-06-20T22:01:58.127-0400 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2019-06-20T22:01:58.127-0400 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3471M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),
2019-06-20T22:01:58.896-0400 I STORAGE  [initandlisten] WiredTiger message [1561082518:896452][48874:0x7f54d39e2a40], txn-recover: Main recovery loop: starting at 6/6272 to 7/256
2019-06-20T22:01:58.988-0400 I STORAGE  [initandlisten] WiredTiger message [1561082518:988133][48874:0x7f54d39e2a40], txn-recover: Recovering log 6 through 7
2019-06-20T22:01:59.042-0400 I STORAGE  [initandlisten] WiredTiger message [1561082519:42151][48874:0x7f54d39e2a40], txn-recover: Recovering log 7 through 7
2019-06-20T22:01:59.090-0400 I STORAGE  [initandlisten] WiredTiger message [1561082519:90245][48874:0x7f54d39e2a40], txn-recover: Set global recovery timestamp: 0
2019-06-20T22:01:59.100-0400 I RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
2019-06-20T22:01:59.131-0400 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/mongodb/diagnostic.data'
2019-06-20T22:01:59.132-0400 I NETWORK  [initandlisten] waiting for connections on port 27017
2019-06-20T22:02:02.087-0400 I NETWORK  [listener] connection accepted from 113.55.13.114:55374 #1 (1 connection now open)
2019-06-20T22:02:02.087-0400 I NETWORK  [conn1] received client metadata from 113.55.13.114:55374 conn1: { driver: { name: "PyMongo", version: "3.7.2" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "4.15.0-51-generic" }, platform: "CPython 3.6.8.final.0" }
2019-06-20T22:02:02.088-0400 I NETWORK  [listener] connection accepted from 113.55.13.114:55376 #2 (2 connections now open)
2019-06-20T22:02:02.089-0400 I NETWORK  [conn2] received client metadata from 113.55.13.114:55376 conn2: { driver: { name: "PyMongo", version: "3.7.2" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "4.15.0-51-generic" }, platform: "CPython 3.6.8.final.0" }
2019-06-20T22:02:02.093-0400 I ACCESS   [conn2] Successfully authenticated as principal admin on admin
2019-06-20T22:02:16.191-0400 I NETWORK  [listener] connection accepted from 113.55.127.140:9983 #3 (3 connections now open)
2019-06-20T22:02:16.202-0400 I NETWORK  [conn3] received client metadata from 113.55.127.140:9983 conn3: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Windows", name: "Microsoft Windows 10", architecture: "x86_64", version: "10.0 (build 18362)" } }
2019-06-20T22:02:16.206-0400 I NETWORK  [conn3] end connection 113.55.127.140:9983 (2 connections now open)
2019-06-20T22:02:16.215-0400 I NETWORK  [listener] connection accepted from 113.55.127.140:9984 #4 (3 connections now open)
2019-06-20T22:02:16.225-0400 I NETWORK  [conn4] received client metadata from 113.55.127.140:9984 conn4: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Windows", name: "Microsoft Windows 10", architecture: "x86_64", version: "10.0 (build 18362)" } }
2019-06-20T22:02:16.228-0400 I NETWORK  [conn4] end connection 113.55.127.140:9984 (2 connections now open)
wlzx@ubuntu:/var/log/mongodb$

If I connect from My ubuntu client. The logs are.

wlzx@ubuntu:/var/log/mongodb$ sudo !!
sudo tail -f mongod.log 
2019-06-20T22:02:16.215-0400 I NETWORK  [listener] connection accepted from 113.55.127.140:9984 #4 (3 connections now open)
2019-06-20T22:02:16.225-0400 I NETWORK  [conn4] received client metadata from 113.55.127.140:9984 conn4: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Windows", name: "Microsoft Windows 10", architecture: "x86_64", version: "10.0 (build 18362)" } }
2019-06-20T22:02:16.228-0400 I NETWORK  [conn4] end connection 113.55.127.140:9984 (2 connections now open)
2019-06-20T23:54:59.713-0400 I NETWORK  [listener] connection accepted from 113.55.13.114:54292 #5 (3 connections now open)
2019-06-20T23:54:59.713-0400 I NETWORK  [conn5] received client metadata from 113.55.13.114:54292 conn5: { driver: { name: "PyMongo", version: "3.7.2" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "4.15.0-52-generic" }, platform: "CPython 3.6.8.final.0" }
2019-06-20T23:55:00.405-0400 I NETWORK  [listener] connection accepted from 113.55.13.114:54294 #6 (4 connections now open)
2019-06-20T23:55:00.406-0400 I NETWORK  [conn6] received client metadata from 113.55.13.114:54294 conn6: { driver: { name: "PyMongo", version: "3.7.2" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "4.15.0-52-generic" }, platform: "CPython 3.6.8.final.0" }
2019-06-20T23:55:00.602-0400 I ACCESS   [conn6] Successfully authenticated as principal admin on admin
2019-06-21T00:09:52.962-0400 I NETWORK  [conn2] end connection 113.55.13.114:55376 (3 connections now open)
2019-06-21T00:09:53.986-0400 I NETWORK  [conn1] end connection 113.55.13.114:55374 (2 connections now open)
2019-06-21T01:04:22.032-0400 I NETWORK  [listener] connection accepted from 113.55.12.52:44016 #7 (3 connections now open)
2019-06-21T01:04:22.032-0400 I NETWORK  [conn7] received client metadata from 113.55.12.52:44016 conn7: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.10" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "18.04" } }

Comment by Danny Hatcher (Inactive) [ 13/Jun/19 ]

Can you please provide the full error from the shell as well as the mongod logs from the server from that same timeframe?

Comment by Sameer [ 11/Jun/19 ]

Same error observed while running MongoDB 4.0.3 in Kubernetes. Intermittent timeouts and disconnections observed with error as below. 

Error: Error doing query: failed: network error while attempting to run command 'currentOp' on host 'MongoDB.server' 

Comment by Danny Hatcher (Inactive) [ 24/May/19 ]

Hello,

Sorry for the delay. Are you still experiencing the problem? If so, could you please attach the full logs from the server in question starting from the last restart until the connection attempt? It's possible something in the historical logs will reveal the problem that the point-in-time logs don't.

Thanks,

Danny

Comment by donghua liu [ 15/Apr/19 ]

Hi, Danny

Sorry for the late response. I run my server with `mongod -vvvvv --bind_ip_all --dbpath /tmp/db` and use the client to connect to it via `mongo 113.55.14.114`, the following are the logs related.

liudonghua@desktop-ldh:~$ mongo 113.55.14.114
MongoDB shell version v4.0.8
connecting to: mongodb://113.55.14.114:27017/test?gssapiServiceName=mongodb
Implicit session: session { "id" : UUID("4470c545-51f7-443d-a6c5-e5a33d82495c") }
2019-04-15T09:13:00.517+0800 E QUERY    [js] Error: error doing query: failed: network error while attempting to run command 'buildinfo' on host '113.55.14.114:27017'  :
DB.prototype.runCommand@src/mongo/shell/db.js:168:1
DB.prototype.adminCommand@src/mongo/shell/db.js:186:16
DB.prototype.serverBuildInfo@src/mongo/shell/db.js:1275:16
DB.prototype.version@src/mongo/shell/db.js:1327:16
connect@src/mongo/shell/mongo.js:363:29
@(connect):2:6
2019-04-15T09:13:00.526+0800 I NETWORK  [js] trying reconnect to 113.55.14.114:27017 failed
2019-04-15T09:13:00.529+0800 I NETWORK  [js] reconnect 113.55.14.114:27017 ok
exception: connect failed
liudonghua@desktop-ldh:~$

2019-04-14T21:12:59.000-0400 D STORAGE  [ftdc] setting timestamp read source: 1, provided timestamp: none
2019-04-14T21:12:59.034-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.134-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.235-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.335-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.435-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.471-0400 D STORAGE  [clientcursormon] NamespaceUUIDCache: registered namespace config.system.sessions with UUID 4cfc29fd-bec4-4bad-a815-50b4554271fe
2019-04-14T21:12:59.471-0400 D STORAGE  [clientcursormon] NamespaceUUIDCache: registered namespace local.startup_log with UUID 872093ce-fb11-4b82-a38a-bb4d27245c22
2019-04-14T21:12:59.471-0400 D STORAGE  [clientcursormon] NamespaceUUIDCache: registered namespace admin.system.version with UUID 810fba1d-9bb8-4ccc-969e-02c1ff7b0cfc
2019-04-14T21:12:59.535-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.622-0400 I NETWORK  [listener] connection accepted from 113.55.127.140:2486 #6 (2 connections now open)
2019-04-14T21:12:59.622-0400 D EXECUTOR [listener] Starting new executor thread in passthrough mode
2019-04-14T21:12:59.627-0400 D COMMAND  [conn6] run command admin.$cmd { isMaster: 1, client: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "18.04" } }, $db: "admin" }
2019-04-14T21:12:59.627-0400 I NETWORK  [conn6] received client metadata from 113.55.127.140:2486 conn6: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "18.04" } }
2019-04-14T21:12:59.627-0400 D NETWORK  [conn6] Starting server-side compression negotiation
2019-04-14T21:12:59.627-0400 D NETWORK  [conn6] Compression negotiation not requested by client
2019-04-14T21:12:59.628-0400 I COMMAND  [conn6] command admin.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1, client: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "18.04" } }, $db: "admin" } numYields:0 reslen:239 locks:{} protocol:op_query 0ms
2019-04-14T21:12:59.634-0400 D COMMAND  [conn6] run command admin.$cmd { whatsmyuri: 1, $db: "admin" }
2019-04-14T21:12:59.635-0400 I COMMAND  [conn6] command admin.$cmd appName: "MongoDB Shell" command: whatsmyuri { whatsmyuri: 1, $db: "admin" } numYields:0 reslen:67 locks:{} protocol:op_msg 0ms
2019-04-14T21:12:59.636-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.638-0400 D NETWORK  [conn6] Session from 113.55.127.140:2486 encountered a network error during SourceMessage
2019-04-14T21:12:59.638-0400 I NETWORK  [conn6] end connection 113.55.127.140:2486 (1 connection now open)
2019-04-14T21:12:59.638-0400 D NETWORK  [conn6] Cancelling outstanding I/O operations on connection to 113.55.127.140:2486
2019-04-14T21:12:59.688-0400 I NETWORK  [listener] connection accepted from 113.55.127.140:2487 #7 (2 connections now open)
2019-04-14T21:12:59.688-0400 D EXECUTOR [listener] Starting new executor thread in passthrough mode
2019-04-14T21:12:59.688-0400 D COMMAND  [conn7] run command admin.$cmd { isMaster: 1, client: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "18.04" } }, $db: "admin" }
2019-04-14T21:12:59.688-0400 I NETWORK  [conn7] received client metadata from 113.55.127.140:2487 conn7: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "18.04" } }
2019-04-14T21:12:59.688-0400 D NETWORK  [conn7] Starting server-side compression negotiation
2019-04-14T21:12:59.688-0400 D NETWORK  [conn7] Compression negotiation not requested by client
2019-04-14T21:12:59.688-0400 I COMMAND  [conn7] command admin.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1, client: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.8" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "18.04" } }, $db: "admin" } numYields:0 reslen:239 locks:{} protocol:op_query 0ms
2019-04-14T21:12:59.693-0400 D COMMAND  [conn7] run command admin.$cmd { endSessions: [ { id: UUID("4470c545-51f7-443d-a6c5-e5a33d82495c") } ], $db: "admin" }
2019-04-14T21:12:59.693-0400 I COMMAND  [conn7] command admin.$cmd appName: "MongoDB Shell" command: endSessions { endSessions: [ { id: UUID("4470c545-51f7-443d-a6c5-e5a33d82495c") } ], $db: "admin" } numYields:0 reslen:38 locks:{} protocol:op_msg 0ms
2019-04-14T21:12:59.694-0400 D NETWORK  [conn7] Session from 113.55.127.140:2487 encountered a network error during SourceMessage
2019-04-14T21:12:59.694-0400 I NETWORK  [conn7] end connection 113.55.127.140:2487 (1 connection now open)
2019-04-14T21:12:59.694-0400 D NETWORK  [conn7] Cancelling outstanding I/O operations on connection to 113.55.127.140:2487
2019-04-14T21:12:59.736-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.836-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:12:59.936-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.000-0400 D STORAGE  [ftdc] setting timestamp read source: 1, provided timestamp: none
2019-04-14T21:13:00.036-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.137-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.237-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.337-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.437-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.537-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.638-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.738-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.838-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:00.938-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.000-0400 D STORAGE  [ftdc] setting timestamp read source: 1, provided timestamp: none
2019-04-14T21:13:01.039-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.139-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.239-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.339-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.377-0400 D COMMAND  [conn5] run command admin.$cmd { ismaster: true, $readPreference: { mode: "secondaryPreferred" }, $db: "admin" }
2019-04-14T21:13:01.377-0400 D NETWORK  [conn5] Starting server-side compression negotiation
2019-04-14T21:13:01.377-0400 D NETWORK  [conn5] Compression negotiation not requested by client
2019-04-14T21:13:01.377-0400 I COMMAND  [conn5] command admin.$cmd command: isMaster { ismaster: true, $readPreference: { mode: "secondaryPreferred" }, $db: "admin" } numYields:0 reslen:239 locks:{} protocol:op_query 0ms
2019-04-14T21:13:01.439-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.540-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.640-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.740-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.840-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:01.940-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.000-0400 D STORAGE  [ftdc] setting timestamp read source: 1, provided timestamp: none
2019-04-14T21:13:02.040-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.141-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.241-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.341-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.441-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.542-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.642-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.742-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.842-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:02.942-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:03.000-0400 D STORAGE  [ftdc] setting timestamp read source: 1, provided timestamp: none
2019-04-14T21:13:03.043-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:03.143-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:03.243-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:03.343-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:03.444-0400 D STORAGE  [WTJournalFlusher] flushed journal
2019-04-14T21:13:03.471-0400 D STORAGE  [clientcursormon] NamespaceUUIDCache: registered namespace config.system.sessions with UUID 4cfc29fd-bec4-4bad-a815-50b4554271fe
2019-04-14T21:13:03.471-0400 D STORAGE  [clientcursormon] NamespaceUUIDCache: registered namespace local.startup_log with UUID 872093ce-fb11-4b82-a38a-bb4d27245c22
2019-04-14T21:13:03.472-0400 D STORAGE  [clientcursormon] NamespaceUUIDCache: registered namespace admin.system.version with UUID 810fba1d-9bb8-4ccc-969e-02c1ff7b0cfc
^C2019-04-14T21:13:03.524-0400 I CONTROL  [signalProcessingThread] got signal 2 (Interrupt), will terminate after current cmd ends
2019-04-14T21:13:03.524-0400 D -        [signalProcessingThread] User Assertion: NotMaster: not primary so can't step down src/mongo/db/db.cpp 893
2019-04-14T21:13:03.524-0400 I NETWORK  [signalProcessingThread] shutdown: going to close listening sockets...
2019-04-14T21:13:03.524-0400 I NETWORK  [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock
2019-04-14T21:13:03.525-0400 D WRITE    [signalProcessingThread] Beginning scanSessions. Scanning 0 sessions.
2019-04-14T21:13:03.525-0400 I CONTROL  [signalProcessingThread] Shutting down free monitoring
2019-04-14T21:13:03.525-0400 I FTDC     [signalProcessingThread] Shutting down full-time diagnostic data capture
2019-04-14T21:13:03.527-0400 D STORAGE  [signalProcessingThread] ~WiredTigerRecordStore for: admin.system.version
2019-04-14T21:13:03.528-0400 D STORAGE  [signalProcessingThread] ~WiredTigerRecordStore for: config.system.sessions
2019-04-14T21:13:03.528-0400 D STORAGE  [signalProcessingThread] ~WiredTigerRecordStore for: local.startup_log
2019-04-14T21:13:03.528-0400 D STORAGE  [signalProcessingThread] ~WiredTigerRecordStore for: _mdb_catalog
2019-04-14T21:13:03.528-0400 I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
2019-04-14T21:13:03.528-0400 I STORAGE  [signalProcessingThread] Shutting down session sweeper thread
2019-04-14T21:13:03.528-0400 D STORAGE  [WTIdleSessionSweeper] stopping WTIdleSessionSweeper thread
2019-04-14T21:13:03.528-0400 I STORAGE  [signalProcessingThread] Finished shutting down session sweeper thread
2019-04-14T21:13:03.544-0400 D STORAGE  [WTJournalFlusher] stopping WTJournalFlusher thread
2019-04-14T21:13:03.544-0400 D STORAGE  [WTCheckpointThread] stopping WTCheckpointThread thread
2019-04-14T21:13:03.544-0400 D RECOVERY [signalProcessingThread] Shutdown timestamps. StableTimestamp: 0 Initial data timestamp: 0
2019-04-14T21:13:03.550-0400 I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
2019-04-14T21:13:03.550-0400 I CONTROL  [signalProcessingThread] now exiting
2019-04-14T21:13:03.550-0400 I CONTROL  [signalProcessingThread] shutting down with code:0

Comment by Danny Hatcher (Inactive) [ 10/Apr/19 ]

Hello,

Can you please attach the full log file for the mongod process located at 113.55.14.114:27017 to this ticket?

Thanks,

Danny

Comment by donghua liu [ 10/Apr/19 ]

The issue was the same as https://jira.mongodb.org/browse/SERVER-39649, but that one was closed and some scenario was different, so I create a new one.

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