MongoDB 3.4 fails on service restart

XMLWordPrintableJSON

    • Type: Bug
    • Resolution: Incomplete
    • Priority: Major - P3
    • None
    • Affects Version/s: 3.4.0-rc0, 3.4.0-rc1, 3.4.0-rc2, 3.4.0-rc3, 3.4.0-rc4, 3.4.0-rc5, 3.4.0
    • Component/s: WiredTiger
    • None
    • ALL
    • Hide

      1. setup a new instance
      2. start mongo
      3. stop mongo
      4. reboot host

      Installation receipt:
      ```
      run "sudo apt-key adv --keyserver hkp://keyserver.ubuntu.com:80 --recv 0C49F3730359A14518585931BC711F9BA15703C6"
      run "echo \"deb http://repo.mongodb.org/apt/ubuntu xenial/mongodb-org/3.4 multiverse\" | sudo tee /etc/apt/sources.list.d/mongodb-org-3.4.list"

      run "sudo apt-get update"
      run "sudo apt-get install -y --allow-unauthenticated mongodb-org"

      run "sudo service mongod stop || true"

      tmpfile = "/tmp/mongodb.conf"
      put IO.read("config/deploy/plugin/mongo/mongod.conf"), tmpfile
      run "sudo mv #

      {tmpfile} /etc/mongod.conf"

      tmpfile = "/tmp/mongodb.service"
      put IO.read("config/deploy/plugin/mongo/systemd/mongodb.service"), tmpfile
      run "sudo mv #{tmpfile}

      /etc/systemd/system/mongodb.service"

      run "sudo systemctl daemon-reload"
      run "sudo systemctl enable mongodb.service"

      run "sudo systemctl start mongodb || true"
      ```
      commands after install

      1. sudo systemctl stop mongodb
      2. sudo reboot
      Show
      1. setup a new instance 2. start mongo 3. stop mongo 4. reboot host Installation receipt: ``` run "sudo apt-key adv --keyserver hkp://keyserver.ubuntu.com:80 --recv 0C49F3730359A14518585931BC711F9BA15703C6" run "echo \"deb http://repo.mongodb.org/apt/ubuntu xenial/mongodb-org/3.4 multiverse\" | sudo tee /etc/apt/sources.list.d/mongodb-org-3.4.list" run "sudo apt-get update" run "sudo apt-get install -y --allow-unauthenticated mongodb-org" run "sudo service mongod stop || true" tmpfile = "/tmp/mongodb.conf" put IO.read("config/deploy/plugin/mongo/mongod.conf"), tmpfile run "sudo mv # {tmpfile} /etc/mongod.conf" tmpfile = "/tmp/mongodb.service" put IO.read("config/deploy/plugin/mongo/systemd/mongodb.service"), tmpfile run "sudo mv #{tmpfile} /etc/systemd/system/mongodb.service" run "sudo systemctl daemon-reload" run "sudo systemctl enable mongodb.service" run "sudo systemctl start mongodb || true" ``` commands after install sudo systemctl stop mongodb sudo reboot
    • None
    • None
    • None
    • None
    • None
    • None
    • None

      I've setup mongo 3.4 on m4.large instance but it fails even just after service stop and system reboot

      1. sudo systemctl stop mongodb
      2. sudo reboot

      Logs

      2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] MongoDB starting : pid=28930 port=27017 dbpath=/var/lib/mongodb 64-bit host=ip-172-30-1-203.us-west-2.compute.internal
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] db version v3.4.0
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] git version: f4240c60f005be757399042dc12f6addbc3170c1
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] modules: none
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] build environment:
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten]     distmod: ubuntu1604
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten]     distarch: x86_64
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2016-12-04T19:29:45.241+0000 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "0.0.0.0", port: 27017 }, replication: { replSetName: "tt" }, storage: { dbPath: "/var/lib/mongodb", engine: "wiredTiger", journal: { enabled: false } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log", quiet: true } }
2016-12-04T19:29:45.269+0000 I STORAGE  [initandlisten]
2016-12-04T19:29:45.269+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2016-12-04T19:29:45.269+0000 I STORAGE  [initandlisten] See http://dochub.mongodb.org/core/prodnotes-filesystem
2016-12-04T19:29:45.269+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3478M,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),,log=(enabled=false),
2016-12-04T19:29:45.341+0000 I CONTROL  [initandlisten]
2016-12-04T19:29:45.341+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2016-12-04T19:29:45.341+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2016-12-04T19:29:45.341+0000 I CONTROL  [initandlisten]
2016-12-04T19:29:45.360+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/mongodb/diagnostic.data'
2016-12-04T19:29:45.385+0000 I REPL     [initandlisten] Did not find local voted for document at startup;  NoMatchingDocument: Did not find replica set lastVote document in local.replset.election
2016-12-04T19:29:45.385+0000 I REPL     [initandlisten] Did not find local replica set configuration document at startup;  NoMatchingDocument: Did not find replica set configuration document in local.system.replset
2016-12-04T19:29:45.385+0000 I NETWORK  [thread1] waiting for connections on port 27017
2016-12-04T19:40:12.723+0000 I CONTROL  [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
2016-12-04T19:40:12.723+0000 I NETWORK  [signalProcessingThread] shutdown: going to close listening sockets...
2016-12-04T19:40:12.723+0000 I NETWORK  [signalProcessingThread] closing listening socket: 7
2016-12-04T19:40:12.723+0000 I NETWORK  [signalProcessingThread] closing listening socket: 8
2016-12-04T19:40:12.723+0000 I NETWORK  [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock
2016-12-04T19:40:12.723+0000 I NETWORK  [signalProcessingThread] shutdown: going to flush diaglog...
2016-12-04T19:40:12.723+0000 I REPL     [signalProcessingThread] shutting down replication subsystems
2016-12-04T19:40:12.723+0000 I FTDC     [signalProcessingThread] Shutting down full-time diagnostic data capture
2016-12-04T19:40:12.724+0000 I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
2016-12-04T19:40:12.734+0000 I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
2016-12-04T19:40:12.735+0000 I CONTROL  [signalProcessingThread] now exiting
2016-12-04T19:40:12.735+0000 I CONTROL  [signalProcessingThread] shutting down with code:0
2016-12-04T19:40:12.735+0000 I CONTROL  [initandlisten] shutting down with code:0
2016-12-04T19:41:21.025+0000 I CONTROL  [main] ***** SERVER RESTARTED *****
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] MongoDB starting : pid=1716 port=27017 dbpath=/var/lib/mongodb 64-bit host=ip-172-30-1-203.us-west-2.compute.internal
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] db version v3.4.0
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] git version: f4240c60f005be757399042dc12f6addbc3170c1
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] modules: none
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] build environment:
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten]     distmod: ubuntu1604
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten]     distarch: x86_64
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2016-12-04T19:41:21.099+0000 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "0.0.0.0", port: 27017 }, replication: { replSetName: "tt" }, storage: { dbPath: "/var/lib/mongodb", engine: "wiredTiger", journal: { enabled: false } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log", quiet: true } }
2016-12-04T19:41:21.108+0000 W -        [initandlisten] Detected unclean shutdown - /var/lib/mongodb/mongod.lock is not empty.
2016-12-04T19:41:21.196+0000 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2016-12-04T19:41:21.196+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3478M,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),,log=(enabled=false),
2016-12-04T19:41:21.365+0000 E STORAGE  [initandlisten] WiredTiger error (-31802) [1480880481:365973][1716:0x7fbab4eed100], file:WiredTiger.wt, connection: unable to read root page from file:WiredTiger.wt: WT_ERROR: non-specific WiredTiger error
2016-12-04T19:41:21.366+0000 E STORAGE  [initandlisten] WiredTiger error (0) [1480880481:366016][1716:0x7fbab4eed100], file:WiredTiger.wt, connection: WiredTiger has failed to open its metadata
2016-12-04T19:41:21.366+0000 E STORAGE  [initandlisten] WiredTiger error (0) [1480880481:366025][1716:0x7fbab4eed100], file:WiredTiger.wt, connection: This may be due to the database files being encrypted, being from an older version or due to corruption on disk
2016-12-04T19:41:21.366+0000 E STORAGE  [initandlisten] WiredTiger error (0) [1480880481:366032][1716:0x7fbab4eed100], file:WiredTiger.wt, connection: You should confirm that you have opened the database with the correct options including all encryption and compression options
2016-12-04T19:41:21.394+0000 I -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 267
2016-12-04T19:41:21.558+0000 I STORAGE  [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
2016-12-04T19:41:21.558+0000 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2016-12-04T19:41:21.558+0000 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2016-12-04T19:41:21.558+0000 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
2016-12-04T19:41:21.558+0000 I CONTROL  [initandlisten] now exiting
2016-12-04T19:41:21.558+0000 I CONTROL  [initandlisten] shutting down with code:100

      That's a really scary behavior, I've got the same issue with dta or without data, on clean aws instance. It fails and cant restore.
      MongoDb 3.2 with WiredTiger works well in the same environment.

            Assignee:
            Unassigned
            Reporter:
            Rostyslav Mykhajliw
            Votes:
            0 Vote for this issue
            Watchers:
            9 Start watching this issue

              Created:
              Updated:
              Resolved: