Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issues Connecting to MongoBD from Node Guestbook #8

Closed
seanmcbreen opened this issue Mar 29, 2019 · 3 comments
Closed

Issues Connecting to MongoBD from Node Guestbook #8

seanmcbreen opened this issue Mar 29, 2019 · 3 comments

Comments

@seanmcbreen
Copy link
Contributor

seanmcbreen commented Mar 29, 2019

I have some issues connecting to the Mongo DB. I see the following in the frontend log...

connection err: { MongoNetworkError: failed to connect to server [localhost:27017] on first connect [MongoNetworkError: connect ECONNREFUSED 127.0.0.1:27017]
    at Pool.<anonymous> (/backend/node_modules/mongodb-core/lib/topologies/server.js:564:11)
    at emitOne (events.js:116:13)
    at Pool.emit (events.js:211:7)
    at Connection.<anonymous> (/backend/node_modules/mongodb-core/lib/connection/pool.js:317:12)
    at Object.onceWrapper (events.js:317:30)
    at emitTwo (events.js:126:13)
    at Connection.emit (events.js:214:7)
    at Socket.<anonymous> (/backend/node_modules/mongodb-core/lib/connection/connection.js:246:50)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:116:13)
    at Socket.emit (events.js:211:7)
    at emitErrorNT (internal/streams/destroy.js:66:8)
    at _combinedTickCallback (internal/process/next_tick.js:139:11)
    at process._tickCallback (internal/process/next_tick.js:181:9)
  name: 'MongoNetworkError',
  errorLabels: [ 'TransientTransactionError' ],
  [Symbol(mongoErrorContextSymbol)]: {} }
connection err: { MongoNetworkError: failed to connect to server [mongo-service:27017] on first connect [MongoNetworkError: connection 1 to mongo-service:27017 timed out]
    at Pool.<anonymous> (/backend/node_modules/mongodb-core/lib/topologies/server.js:564:11)
    at emitOne (events.js:116:13)
    at Pool.emit (events.js:211:7)
    at Connection.<anonymous> (/backend/node_modules/mongodb-core/lib/connection/pool.js:317:12)
    at Object.onceWrapper (events.js:317:30)
    at emitTwo (events.js:126:13)
    at Connection.emit (events.js:214:7)
    at Socket.<anonymous> (/backend/node_modules/mongodb-core/lib/connection/connection.js:257:10)
    at Object.onceWrapper (events.js:313:30)
    at emitNone (events.js:106:13)
    at Socket.emit (events.js:208:7)
    at Socket._onTimeout (net.js:422:8)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'MongoNetworkError',
  errorLabels: [ 'TransientTransactionError' ],
  [Symbol(mongoErrorContextSymbol)]: {} }

The full Mongo log is

2019-03-29T23:42:42.005+0000 W CONTROL  [main] Option: sslMode is deprecated. Please use tlsMode instead.
about to fork child process, waiting until server is ready for connections.
forked process: 22
2019-03-29T23:42:42.008+0000 I CONTROL  [main] ***** SERVER RESTARTED *****
2019-03-29T23:42:42.014+0000 I CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
2019-03-29T23:42:42.018+0000 I CONTROL  [initandlisten] MongoDB starting : pid=22 port=27017 dbpath=/data/db 64-bit host=mongo-65f7945978-jvknl
2019-03-29T23:42:42.018+0000 I CONTROL  [initandlisten] db version v4.1.9
2019-03-29T23:42:42.018+0000 I CONTROL  [initandlisten] git version: a5fa363117062a20d6056c76e01edb3a08f71b7c
2019-03-29T23:42:42.018+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2019-03-29T23:42:42.018+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2019-03-29T23:42:42.019+0000 I CONTROL  [initandlisten] modules: none
2019-03-29T23:42:42.019+0000 I CONTROL  [initandlisten] build environment:
2019-03-29T23:42:42.019+0000 I CONTROL  [initandlisten]     distmod: ubuntu1604
2019-03-29T23:42:42.019+0000 I CONTROL  [initandlisten]     distarch: x86_64
2019-03-29T23:42:42.019+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2019-03-29T23:42:42.019+0000 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1", port: 27017, tls: { mode: "disabled" } }, processManagement: { fork: true, pidFilePath: "/tmp/docker-entrypoint-temp-mongod.pid" }, systemLog: { destination: "file", logAppend: true, path: "/proc/1/fd/1" } }
2019-03-29T23:42:42.019+0000 I STORAGE  [initandlisten] 
2019-03-29T23:42:42.019+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2019-03-29T23:42:42.019+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2019-03-29T23:42:42.020+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1340M,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-03-29T23:42:42.740+0000 I STORAGE  [initandlisten] WiredTiger message [1553902962:740854][22:0x7f2af7345a80], txn-recover: Set global recovery timestamp: (0,0)
2019-03-29T23:42:42.748+0000 I RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
2019-03-29T23:42:42.758+0000 I STORAGE  [initandlisten] Timestamp monitor starting
2019-03-29T23:42:42.762+0000 I CONTROL  [initandlisten] 
2019-03-29T23:42:42.762+0000 I CONTROL  [initandlisten] ** NOTE: This is a development version (4.1.9) of MongoDB.
2019-03-29T23:42:42.762+0000 I CONTROL  [initandlisten] **       Not recommended for production.
2019-03-29T23:42:42.762+0000 I CONTROL  [initandlisten] 
2019-03-29T23:42:42.762+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2019-03-29T23:42:42.763+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2019-03-29T23:42:42.763+0000 I CONTROL  [initandlisten] 
2019-03-29T23:42:42.764+0000 I STORAGE  [initandlisten] createCollection: admin.system.version with provided UUID: 81be457c-b812-47ce-bdb0-f4b44a362523
2019-03-29T23:42:42.775+0000 I INDEX    [initandlisten] index build: done building index _id_ on ns admin.system.version
2019-03-29T23:42:42.775+0000 I SHARDING [initandlisten] Marking collection admin.system.version as collection version: <unsharded>
2019-03-29T23:42:42.775+0000 I COMMAND  [initandlisten] setting featureCompatibilityVersion to 4.2
2019-03-29T23:42:42.778+0000 I SHARDING [initandlisten] Marking collection local.system.replset as collection version: <unsharded>
2019-03-29T23:42:42.779+0000 I SHARDING [initandlisten] Marking collection admin.system.roles as collection version: <unsharded>
2019-03-29T23:42:42.779+0000 I STORAGE  [initandlisten] createCollection: local.startup_log with generated UUID: 189d06a2-9540-4813-946a-bd010d09fb83
2019-03-29T23:42:42.791+0000 I INDEX    [initandlisten] index build: done building index _id_ on ns local.startup_log
2019-03-29T23:42:42.792+0000 I SHARDING [initandlisten] Marking collection local.startup_log as collection version: <unsharded>
2019-03-29T23:42:42.792+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
2019-03-29T23:42:42.793+0000 I NETWORK  [initandlisten] Listening on /tmp/mongodb-27017.sock
2019-03-29T23:42:42.793+0000 I NETWORK  [initandlisten] Listening on 127.0.0.1
2019-03-29T23:42:42.793+0000 I NETWORK  [initandlisten] waiting for connections on port 27017
child process started successfully, parent exiting
2019-03-29T23:42:42.796+0000 I SHARDING [LogicalSessionCacheRefresh] Marking collection config.system.sessions as collection version: <unsharded>
2019-03-29T23:42:42.796+0000 I STORAGE  [LogicalSessionCacheRefresh] createCollection: config.system.sessions with generated UUID: a3483914-ec35-4856-bb56-f9f76bb38f26
2019-03-29T23:42:42.813+0000 I INDEX    [LogicalSessionCacheRefresh] index build: done building index _id_ on ns config.system.sessions
2019-03-29T23:42:42.830+0000 I INDEX    [LogicalSessionCacheRefresh] index build: starting on config.system.sessions properties: { v: 2, key: { lastUse: 1 }, name: "lsidTTLIndex", ns: "config.system.sessions", expireAfterSeconds: 1800 } using method: Hybrid
2019-03-29T23:42:42.830+0000 I INDEX    [LogicalSessionCacheRefresh] build may temporarily use up to 500 megabytes of RAM
2019-03-29T23:42:42.830+0000 I INDEX    [LogicalSessionCacheRefresh] index build: collection scan done. scanned 0 total records in 0 seconds
2019-03-29T23:42:42.830+0000 I INDEX    [LogicalSessionCacheRefresh] index build: inserted 0 keys from external sorter into index in 0 seconds
2019-03-29T23:42:42.831+0000 I INDEX    [LogicalSessionCacheRefresh] index build: done building index lsidTTLIndex on ns config.system.sessions
2019-03-29T23:42:42.930+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:48134 #1 (1 connection now open)
2019-03-29T23:42:42.930+0000 I NETWORK  [conn1] received client metadata from 127.0.0.1:48134 conn1: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.1.9" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
2019-03-29T23:42:42.941+0000 I NETWORK  [conn1] end connection 127.0.0.1:48134 (0 connections now open)
2019-03-29T23:42:43.090+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:48136 #2 (1 connection now open)
2019-03-29T23:42:43.090+0000 I NETWORK  [conn2] received client metadata from 127.0.0.1:48136 conn2: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.1.9" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
2019-03-29T23:42:43.180+0000 I SHARDING [conn2] Marking collection admin.system.users as collection version: <unsharded>
2019-03-29T23:42:43.180+0000 I STORAGE  [conn2] createCollection: admin.system.users with generated UUID: 8a5ebc66-d352-4176-a112-f12a852391fd
2019-03-29T23:42:43.194+0000 I INDEX    [conn2] index build: done building index _id_ on ns admin.system.users
2019-03-29T23:42:43.200+0000 I INDEX    [conn2] index build: done building index user_1_db_1 on ns admin.system.users
Successfully added user: {
	"user" : "root",
	"roles" : [
		{
			"role" : "root",
			"db" : "admin"
		}
	]
}
2019-03-29T23:42:43.202+0000 E -        [main] Error saving history file: FileOpenFailed: Unable to open() file /home/mongodb/.dbshell: Unknown error 2

/usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/*

2019-03-29T23:42:43.218+0000 I NETWORK  [conn2] end connection 127.0.0.1:48136 (0 connections now open)
2019-03-29T23:42:43.259+0000 W CONTROL  [main] Option: sslMode is deprecated. Please use tlsMode instead.
2019-03-29T23:42:43.261+0000 I CONTROL  [main] ***** SERVER RESTARTED *****
2019-03-29T23:42:43.264+0000 I CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
killing process with pid: 22
2019-03-29T23:42:43.276+0000 I CONTROL  [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
2019-03-29T23:42:43.276+0000 I NETWORK  [signalProcessingThread] shutdown: going to close listening sockets...
2019-03-29T23:42:43.276+0000 I NETWORK  [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock
2019-03-29T23:42:43.276+0000 I CONTROL  [signalProcessingThread] Shutting down free monitoring
2019-03-29T23:42:43.276+0000 I FTDC     [signalProcessingThread] Shutting down full-time diagnostic data capture
2019-03-29T23:42:43.280+0000 I STORAGE  [signalProcessingThread] Timestamp monitor shutting down
2019-03-29T23:42:43.280+0000 I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
2019-03-29T23:42:43.281+0000 I STORAGE  [signalProcessingThread] Shutting down session sweeper thread
2019-03-29T23:42:43.281+0000 I STORAGE  [signalProcessingThread] Finished shutting down session sweeper thread
2019-03-29T23:42:43.281+0000 I STORAGE  [signalProcessingThread] Shutting down journal flusher thread
2019-03-29T23:42:43.356+0000 I STORAGE  [signalProcessingThread] Finished shutting down journal flusher thread
2019-03-29T23:42:43.356+0000 I STORAGE  [signalProcessingThread] Shutting down checkpoint thread
2019-03-29T23:42:43.388+0000 I STORAGE  [signalProcessingThread] Finished shutting down checkpoint thread
2019-03-29T23:42:43.413+0000 I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
2019-03-29T23:42:43.413+0000 I CONTROL  [signalProcessingThread] now exiting
2019-03-29T23:42:43.413+0000 I CONTROL  [signalProcessingThread] shutting down with code:0

MongoDB init process complete; ready for start up.

2019-03-29T23:42:44.381+0000 I CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db 64-bit host=mongo-65f7945978-jvknl
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] db version v4.1.9
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] git version: a5fa363117062a20d6056c76e01edb3a08f71b7c
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] modules: none
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] build environment:
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten]     distmod: ubuntu1604
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten]     distarch: x86_64
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2019-03-29T23:42:44.386+0000 I CONTROL  [initandlisten] options: { net: { bindIp: "*" }, security: { authorization: "enabled" } }
2019-03-29T23:42:44.387+0000 I STORAGE  [initandlisten] Detected data files in /data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2019-03-29T23:42:44.387+0000 I STORAGE  [initandlisten] 
2019-03-29T23:42:44.387+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2019-03-29T23:42:44.387+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2019-03-29T23:42:44.387+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1340M,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-03-29T23:42:46.444+0000 I STORAGE  [initandlisten] WiredTiger message [1553902966:444038][1:0x7fe71c889a80], txn-recover: Main recovery loop: starting at 1/30080 to 2/256
2019-03-29T23:42:46.700+0000 I STORAGE  [initandlisten] WiredTiger message [1553902966:700115][1:0x7fe71c889a80], txn-recover: Recovering log 1 through 2
2019-03-29T23:42:46.782+0000 I STORAGE  [initandlisten] WiredTiger message [1553902966:782875][1:0x7fe71c889a80], txn-recover: Recovering log 2 through 2
2019-03-29T23:42:46.911+0000 I STORAGE  [initandlisten] WiredTiger message [1553902966:911275][1:0x7fe71c889a80], txn-recover: Set global recovery timestamp: (0,0)
2019-03-29T23:42:46.953+0000 I RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
2019-03-29T23:42:46.963+0000 I STORAGE  [initandlisten] Timestamp monitor starting
2019-03-29T23:42:46.965+0000 I CONTROL  [initandlisten] 
2019-03-29T23:42:46.965+0000 I CONTROL  [initandlisten] ** NOTE: This is a development version (4.1.9) of MongoDB.
2019-03-29T23:42:46.965+0000 I CONTROL  [initandlisten] **       Not recommended for production.
2019-03-29T23:42:46.965+0000 I CONTROL  [initandlisten] 
2019-03-29T23:42:46.980+0000 I SHARDING [initandlisten] Marking collection local.system.replset as collection version: <unsharded>
2019-03-29T23:42:46.982+0000 I SHARDING [initandlisten] Marking collection admin.system.roles as collection version: <unsharded>
2019-03-29T23:42:46.982+0000 I SHARDING [initandlisten] Marking collection admin.system.version as collection version: <unsharded>
2019-03-29T23:42:46.983+0000 I SHARDING [initandlisten] Marking collection local.startup_log as collection version: <unsharded>
2019-03-29T23:42:46.983+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
2019-03-29T23:42:46.984+0000 I NETWORK  [initandlisten] Listening on /tmp/mongodb-27017.sock
2019-03-29T23:42:46.984+0000 I NETWORK  [initandlisten] Listening on 0.0.0.0
2019-03-29T23:42:46.984+0000 I NETWORK  [initandlisten] waiting for connections on port 27017
2019-03-29T23:42:46.985+0000 I SHARDING [LogicalSessionCacheRefresh] Marking collection config.system.sessions as collection version: <unsharded>

Any ideas?

@seanmcbreen
Copy link
Contributor Author

This was an issue w/ my cluster closing.

@seanmcbreen
Copy link
Contributor Author

This i still happening esp. on fresh deployments.

We were able to use the terminal on the pod and see that the service was not running e.g.

# service mongod status
mongod: unrecognized service

We deleted the pod and at least 1 time this worked (i.e. the pod came back up and worked). however this was not consitant.

Most fresh deployment fail with this error. Once the database is running it works every time.

Sean

@seanmcbreen
Copy link
Contributor Author

Closing as the commit fixes this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant