Rocketchat not starting returning exited code 1

Community Support
1

Description:

Hello all,

After a reboot, rocketchat is not starting correctly :

rocketchatdevelop_rocketchat_1 exited with code 1

I stopped all mongo process and start mongo, same result.

Server Setup Information:

Operating System: Debian 7.11
Deployment Method(snap/docker/tar/etc): docker
Number of Running Instances: 1
mongoDB Version: db version v2.0.6, pdfile version 4.5

Steps to Reproduce:

kill mongod process
To be sure : ps aux | grep mongod
service mongod start
docker-compose up rocketchat

Expected behavior:

rocketchat up and running
Actual behavior:

        /usr/src/Rocket.Chat-develop# docker-compose up rocketchat
        Starting rocketchatdevelop_mongo_1
        Starting rocketchatdevelop_rocketchat_1
        Attaching to rocketchatdevelop_rocketchat_1
        rocketchat_1 |
        rocketchat_1 | /app/bundle/programs/server/node_modules/fibers/future.js:313
        rocketchat_1 | throw(ex);
        rocketchat_1 | ^
        rocketchat_1 | MongoError: failed to connect to server [mongo:27017] on first connect [MongoError: connect ECONNREFUSED 172.17.0.2:27017]
        rocketchat_1 | at Pool. (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/topologies/server.js:336:35)
        rocketchat_1 | at emitOne (events.js:116:13)
        rocketchat_1 | at Pool.emit (events.js:211:7)
        rocketchat_1 | at Connection. (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:280:12)
        rocketchat_1 | at Object.onceWrapper (events.js:317:30)
        rocketchat_1 | at emitTwo (events.js:126:13)
        rocketchat_1 | at Connection.emit (events.js:214:7)
        rocketchat_1 | at Socket. (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:189:49)
        rocketchat_1 | at Object.onceWrapper (events.js:315:30)
        rocketchat_1 | at emitOne (events.js:116:13)
        rocketchat_1 | at Socket.emit (events.js:211:7)
        rocketchat_1 | at emitErrorNT (internal/streams/destroy.js:64:8)
        rocketchat_1 | at _combinedTickCallback (internal/process/next_tick.js:138:11)
        rocketchat_1 | at process._tickCallback (internal/process/next_tick.js:180:9)
        rocketchatdevelop_rocketchat_1 exited with code 1

Relevant logs:

/var/log/mongodb/mongodb.log :

***** SERVER RESTARTED *****


Wed Mar 21 16:59:22 [initandlisten] MongoDB starting : pid=3037 port=27017 dbpath=/home/sites/chat.symbiose.fr/mongodb 64-bit host=atlantis
Wed Mar 21 16:59:22 [initandlisten] db version v2.0.6, pdfile version 4.5
Wed Mar 21 16:59:22 [initandlisten] git version: nogitversion
Wed Mar 21 16:59:22 [initandlisten] build info: Linux tigereye 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u3 (2016-01-17) x86_64 BOOST_LIB_VERSION=1_49
Wed Mar 21 16:59:22 [initandlisten] options: { bind_ip: "127.0.0.1", command: [ "run" ], config: "/etc/mongodb.conf", dbpath: "/home/sites/chat.symbiose.fr/mongodb", journal: "true", logappend: "true", logpath: "/var/log/mongodb/mongodb.log", unixSocketPrefix: "/var/run/mongodb" }
Wed Mar 21 16:59:22 [initandlisten] journal dir=/home/sites/chat.symbiose.fr/mongodb/journal
Wed Mar 21 16:59:22 [initandlisten] recover : no journal files present, no recovery needed
Wed Mar 21 16:59:22 [websvr] admin web console waiting for connections on port 28017
Wed Mar 21 16:59:22 [initandlisten] waiting for connections on port 27017
Wed Mar 21 16:59:40 [initandlisten] connection accepted from 127.0.0.1:38811 #1
Wed Mar 21 17:00:12 [conn1] end connection 127.0.0.1:38811
Wed Mar 21 17:00:22 [clientcursormon] mem (MB) res:18 virt:170 mapped:0
Wed Mar 21 17:02:00 [initandlisten] connection accepted from 127.0.0.1:39064 #2
Wed Mar 21 17:02:10 [conn2] end connection 127.0.0.1:39064
Wed Mar 21 17:02:10 [initandlisten] connection accepted from 127.0.0.1:39074 #3
Wed Mar 21 17:02:31 [conn3] end connection 127.0.0.1:39074
Wed Mar 21 17:05:22 [clientcursormon] mem (MB) res:18 virt:171 mapped:0
Wed Mar 21 17:10:22 [clientcursormon] mem (MB) res:18 virt:171 mapped:0
Wed Mar 21 17:15:22 [clientcursormon] mem (MB) res:18 virt:171 mapped:0
Wed Mar 21 17:20:22 [clientcursormon] mem (MB) res:18 virt:171 mapped:0
Wed Mar 21 17:24:02 got kill or ctrl c or hup signal 15 (Terminated), will terminate after current cmd ends
Wed Mar 21 17:24:02 [interruptThread] now exiting
Wed Mar 21 17:24:02 dbexit:
Wed Mar 21 17:24:02 [interruptThread] shutdown: going to close listening sockets...
Wed Mar 21 17:24:02 [interruptThread] closing listening socket: 6
Wed Mar 21 17:24:02 [interruptThread] closing listening socket: 7
Wed Mar 21 17:24:02 [interruptThread] closing listening socket: 8
Wed Mar 21 17:24:02 [interruptThread] removing socket file: /var/run/mongodb/mongodb-27017.sock
Wed Mar 21 17:24:02 [interruptThread] shutdown: going to flush diaglog...
Wed Mar 21 17:24:02 [interruptThread] shutdown: going to close sockets...
Wed Mar 21 17:24:02 [interruptThread] shutdown: waiting for fs preallocator...
Wed Mar 21 17:24:02 [interruptThread] shutdown: lock for final commit...
Wed Mar 21 17:24:02 [interruptThread] shutdown: final commit...
Wed Mar 21 17:24:02 [interruptThread] shutdown: closing all files...
Wed Mar 21 17:24:02 [interruptThread] closeAllFiles() finished
Wed Mar 21 17:24:02 [interruptThread] journalCleanup...
Wed Mar 21 17:24:02 [interruptThread] removeJournalFiles
Wed Mar 21 17:24:02 [interruptThread] shutdown: removing fs lock...
Wed Mar 21 17:24:02 dbexit: really exiting now

Thanks in advance!

2

Continuing the discussion from Rocketchat not starting returning exited code 1:

I changed the 172.17.0.2:27017 to localhost:27017 in docker-compose.yml : not better

3

As you can see from your mongo logs mongo isn’t starting up. Its actually getting killed it looks like before its finished according to this line:

4

Where can i find the reason why mongo is killed ? Increase verbosity log?

5

Last night i tried : docker-compose up -d rocketchat
and now its stuck at : Wed Mar 28 09:36:23 [clientcursormon] mem (MB) res:18 virt:169 mapped:0

mongodb.log :

***** SERVER RESTARTED *****

Tue Mar 27 22:45:22 [initandlisten] MongoDB starting : pid=12556 port=27017 dbpath=/home/sites/chat.symbiose.fr/mongodb 64-bit host=atlantis
Tue Mar 27 22:45:22 [initandlisten] db version v2.0.6, pdfile version 4.5
Tue Mar 27 22:45:22 [initandlisten] git version: nogitversion
Tue Mar 27 22:45:22 [initandlisten] build info: Linux tigereye 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u3 (2016-01-17) x86_64 BOOST_LIB_VERSION=1_49
Tue Mar 27 22:45:22 [initandlisten] options: { bind_ip: “127.0.0.1”, command: [ “run” ], config: “/etc/mongodb.conf”, dbpath: “/home/sites/chat.symbiose.fr/mongodb”, journal: “true”, logappend: “true”, logpath: “/var/log/mongodb/mongodb.log”, unixSocketPrefix: “/var/run/mongodb” }
Tue Mar 27 22:45:22 [initandlisten] journal dir=/home/sites/chat.symbiose.fr/mongodb/journal
Tue Mar 27 22:45:22 [initandlisten] recover : no journal files present, no recovery needed
Tue Mar 27 22:45:22 [websvr] admin web console waiting for connections on port 28017
Tue Mar 27 22:45:22 [initandlisten] waiting for connections on port 27017
Tue Mar 27 22:46:22 [clientcursormon] mem (MB) res:18 virt:169 mapped:0
Tue Mar 27 22:51:22 [clientcursormon] mem (MB) res:18 virt:169 mapped:0
…
Wed Mar 28 09:41:23 [clientcursormon] mem (MB) res:18 virt:169 mapped:0

6

Those aren’t errors. Looks to me like it’s up and waiting for connections. See the line about listening. If it werent it would have exited

7

It looks like my rocketchat database is gone :frowning:

PRIMARY> show dbs

local 4.201171875GB
rocketchat (empty)
test (empty)

How my db can be empty?

8

What’s your docker-compose file look like? If you don’t mount your db volume… if you do any sort of remove on the containers data goes away.

Running: docker ps -a should give you a bit more info about how old containers are, to explain if maybe new container was created. Also let us see if old container happens to be around.

9 
docker ps -a
CONTAINER ID        IMAGE                           COMMAND                  CREATED             STATUS                    PORTS                    NAMES
b16a617e7f93        rocketchat/rocket.chat:latest   "node main.js"           6 hours ago         Exited (1) 6 hours ago                             rocketchatdevelop_rocketchat_1
65f7920d2bf5        rocketchat/hubot-rocketchat     "/bin/sh -c 'node ..."   7 days ago          Exited (255) 7 days ago   0.0.0.0:3001->8080/tcp   rocketchatdevelop_hubot_1
98aadc581430        mongo                           "docker-entrypoint..."   7 days ago          Exited (62) 6 hours ago                            rocketchatdevelop_mongo_1
a5c7adc392c5        87bfde2fb77e                    "node main.js"           2 years ago         Exited (8) 2 years ago                             ecstatic_ardinghelli
10

Here is my docker-compose.yml :

mongo:
  image: mongo
  volumes:
    - /home/sites/chat.symbiose.fr/web/runtime/db:/data/db
    - /home/sites/chat.symbiose.fr/web/dump:/dump
  command: mongod --smallfiles --oplogSize 128

rocketchat:
  image: rocketchat/rocket.chat:latest
  volumes:
    - /home/sites/chat.symbiose.fr/web/uploads:/app/uploads
  environment:
    - PORT=3000
    - ROOT_URL=https://chat.symbiose.fr
    - MONGO_URL=mongodb://mongo:27017/rocketchat
  links:
    - mongo:mongo
  ports:
    - 3000:3000

# hubot, the popular chatbot (add the bot user first and change the password before starting this image)
hubot:
  image: rocketchat/hubot-rocketchat
  environment:
    - ROCKETCHAT_URL=rocketchat:3000
    - ROCKETCHAT_ROOM=GENERAL
    - ROCKETCHAT_USER=bot
    - ROCKETCHAT_PASSWORD=botpassword
    - BOT_NAME=bot
# you can add more scripts as you'd like here, they need to be installable by npm
    - EXTERNAL_SCRIPTS=hubot-help,hubot-seen,hubot-links,hubot-diagnostics
  links:
    - rocketchat:rocketchat
# this is used to expose the hubot port for notifications on the host on port 3000, e.g. for hubot-jenkins-notifier
  ports:
    - 3000:8080
11

Someone have an idea?