[SERVER-31575] Unable to downgrade a newly created 3.6.0-rc0 node to 3.4.9 Created: 15/Oct/17  Updated: 27/Oct/23  Resolved: 16/Oct/17

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

Type: Bug Priority: Minor - P4
Reporter: Ramon Fernandez Marina Assignee: Alexander Gorrod
Resolution: Works as Designed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
related to DOCS-11711 Update 3.6 downgrade documentation to... Closed
Operating System: ALL
Steps To Reproduce:
  • Start a 3.6.0-rc0 node with a fresh dbpath
  • Shut it down
  • Try to start the node with 3.4.9
Participants:
Case:

 Description   

I created a 3.6.0-rc0 node, shut it down, and tried to bring it back up as 3.4.9. If this is not supported we need clear documentation around it:

2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten] MongoDB starting : pid=20923 port=27017 dbpath=/home/rf/tmp/SERVER-31574/data/db 64-bit host=tab
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten] db version v3.6.0-rc0
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten] git version: 96dfbfbb8cfc35640034b189ba58fef43751319e
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten] allocator: tcmalloc
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten] modules: none
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten] build environment:
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten]     distarch: x86_64
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten]     target_arch: x86_64
2017-10-15T11:14:30.203-0400 I CONTROL  [initandlisten] options: { net: { port: 27017 }, processManagement: { fork: true }, storage: { dbPath: "/home/rf/tmp/SERVER-31574/data/db" }, systemLog: { destination: "file", logAppend: true, path: "/home/rf/tmp/SERVER-31574/data/mongod.log" } }
2017-10-15T11:14:30.203-0400 I STORAGE  [initandlisten]
2017-10-15T11:14:30.203-0400 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2017-10-15T11:14:30.203-0400 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2017-10-15T11:14:30.203-0400 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=31684M,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),
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten]
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten]
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] ** WARNING: This server is bound to localhost.
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] **          Remote systems will be unable to connect to this server.
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] **          Start the server with --bind_ip <address> to specify which IP
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] **          addresses it should serve responses from, or with --bind_ip_all to
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] **          bind to all interfaces. If this behavior is desired, start the
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten] **          server with --bind_ip 127.0.0.1 to disable this warning.
2017-10-15T11:14:30.312-0400 I CONTROL  [initandlisten]
2017-10-15T11:14:30.313-0400 I STORAGE  [initandlisten] createCollection: admin.system.version with UUID: 4f8c77af-da87-4c93-8634-4647cb1876d9
2017-10-15T11:14:30.339-0400 I COMMAND  [initandlisten] setting featureCompatibilityVersion to 3.6
2017-10-15T11:14:30.346-0400 I STORAGE  [initandlisten] createCollection: local.startup_log with UUID: 60dbcb39-5fff-47f8-b057-4e371ff63901
2017-10-15T11:14:30.372-0400 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/home/rf/tmp/SERVER-31574/data/db/diagnostic.data'
2017-10-15T11:14:30.372-0400 I NETWORK  [initandlisten] waiting for connections on port 27017
2017-10-15T11:14:30.376-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59682 #1 (1 connection now open)
2017-10-15T11:14:30.376-0400 I NETWORK  [conn1] received client metadata from 127.0.0.1:59682 conn: { driver: { name: "PyMongo", version: "3.4.0" }, os: { type: "Linux", name: "Ubuntu 16.04 xenial", architecture: "x86_64", version: "4.4.0-93-generic" }, platform: "CPython 2.7.12.final.0" }
2017-10-15T11:14:30.377-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59684 #2 (2 connections now open)
2017-10-15T11:14:30.377-0400 I NETWORK  [conn2] received client metadata from 127.0.0.1:59684 conn: { driver: { name: "PyMongo", version: "3.4.0" }, os: { type: "Linux", name: "Ubuntu 16.04 xenial", architecture: "x86_64", version: "4.4.0-93-generic" }, platform: "CPython 2.7.12.final.0" }
2017-10-15T11:14:30.377-0400 I NETWORK  [conn2] end connection 127.0.0.1:59684 (1 connection now open)
2017-10-15T11:14:30.377-0400 I NETWORK  [conn1] end connection 127.0.0.1:59682 (0 connections now open)
2017-10-15T11:14:30.379-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59686 #3 (1 connection now open)
2017-10-15T11:14:30.379-0400 I NETWORK  [conn3] received client metadata from 127.0.0.1:59686 conn: { driver: { name: "PyMongo", version: "3.4.0" }, os: { type: "Linux", name: "Ubuntu 16.04 xenial", architecture: "x86_64", version: "4.4.0-93-generic" }, platform: "CPython 2.7.12.final.0" }
2017-10-15T11:14:30.380-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59688 #4 (2 connections now open)
2017-10-15T11:14:30.380-0400 I NETWORK  [conn4] received client metadata from 127.0.0.1:59688 conn: { driver: { name: "PyMongo", version: "3.4.0" }, os: { type: "Linux", name: "Ubuntu 16.04 xenial", architecture: "x86_64", version: "4.4.0-93-generic" }, platform: "CPython 2.7.12.final.0" }
2017-10-15T11:14:30.380-0400 I NETWORK  [conn4] end connection 127.0.0.1:59688 (1 connection now open)
2017-10-15T11:14:30.380-0400 I NETWORK  [conn3] end connection 127.0.0.1:59686 (0 connections now open)
2017-10-15T11:14:32.000-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59690 #5 (1 connection now open)
2017-10-15T11:14:32.000-0400 I NETWORK  [conn5] received client metadata from 127.0.0.1:59690 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.6.0-rc0" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
2017-10-15T11:14:37.305-0400 I NETWORK  [conn5] end connection 127.0.0.1:59690 (0 connections now open)
2017-10-15T11:14:39.458-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59692 #6 (1 connection now open)
2017-10-15T11:14:39.459-0400 I NETWORK  [conn6] received client metadata from 127.0.0.1:59692 conn: { driver: { name: "PyMongo", version: "3.4.0" }, os: { type: "Linux", name: "Ubuntu 16.04 xenial", architecture: "x86_64", version: "4.4.0-93-generic" }, platform: "CPython 2.7.12.final.0" }
2017-10-15T11:14:39.460-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59694 #7 (2 connections now open)
2017-10-15T11:14:39.460-0400 I NETWORK  [conn7] received client metadata from 127.0.0.1:59694 conn: { driver: { name: "PyMongo", version: "3.4.0" }, os: { type: "Linux", name: "Ubuntu 16.04 xenial", architecture: "x86_64", version: "4.4.0-93-generic" }, platform: "CPython 2.7.12.final.0" }
2017-10-15T11:14:39.460-0400 I NETWORK  [conn7] end connection 127.0.0.1:59694 (1 connection now open)
2017-10-15T11:14:39.461-0400 I NETWORK  [conn6] end connection 127.0.0.1:59692 (0 connections now open)
2017-10-15T11:14:39.488-0400 I CONTROL  [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
2017-10-15T11:14:39.488-0400 I NETWORK  [signalProcessingThread] shutdown: going to close listening sockets...
2017-10-15T11:14:39.488-0400 I FTDC     [signalProcessingThread] Shutting down full-time diagnostic data capture
2017-10-15T11:14:39.491-0400 I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
2017-10-15T11:14:39.589-0400 I NETWORK  [listener] connection accepted from 127.0.0.1:59696 #8 (1 connection now open)
2017-10-15T11:14:39.591-0400 I NETWORK  [conn8] end connection 127.0.0.1:59696 (0 connections now open)
2017-10-15T11:14:39.653-0400 I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
2017-10-15T11:14:39.653-0400 I CONTROL  [signalProcessingThread] now exiting
2017-10-15T11:14:39.653-0400 I CONTROL  [signalProcessingThread] shutting down with code:0
2017-10-15T11:14:43.951-0400 I CONTROL  [main] ***** SERVER RESTARTED *****
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten] MongoDB starting : pid=20997 port=27017 dbpath=/home/rf/tmp/SERVER-31574/data/db 64-bit host=tab
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten] db version v3.4.9
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten] git version: 876ebee8c7dd0e2d992f36a848ff4dc50ee6603e
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten] allocator: tcmalloc
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten] modules: none
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten] build environment:
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten]     distarch: x86_64
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten]     target_arch: x86_64
2017-10-15T11:14:43.955-0400 I CONTROL  [initandlisten] options: { net: { port: 27017 }, processManagement: { fork: true }, storage: { dbPath: "/home/rf/tmp/SERVER-31574/data/db" }, systemLog: { destination: "file", logAppend: true, path: "/home/rf/tmp/SERVER-31574/data/mongod.log" } }
2017-10-15T11:14:43.971-0400 I -        [initandlisten] Detected data files in /home/rf/tmp/SERVER-31574/data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2017-10-15T11:14:43.971-0400 I STORAGE  [initandlisten]
2017-10-15T11:14:43.971-0400 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2017-10-15T11:14:43.971-0400 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2017-10-15T11:14:43.971-0400 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=31684M,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),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
2017-10-15T11:14:43.988-0400 E STORAGE  [initandlisten] WiredTiger error (-31802) [1508080483:987995][20997:0x7ff723339d00], txn-recover: unsupported WiredTiger file version: this build  only supports major/minor versions up to 1/0,  and the file is version 2/0: WT_ERROR: non-specific WiredTiger error
2017-10-15T11:14:43.988-0400 E STORAGE  [initandlisten] WiredTiger error (0) [1508080483:988038][20997:0x7ff723339d00], txn-recover: WiredTiger is unable to read the recovery log.
2017-10-15T11:14:43.988-0400 E STORAGE  [initandlisten] WiredTiger error (0) [1508080483:988051][20997:0x7ff723339d00], txn-recover: This may be due to the log files being encrypted, being from an older version or due to corruption on disk
2017-10-15T11:14:43.988-0400 E STORAGE  [initandlisten] WiredTiger error (0) [1508080483:988063][20997:0x7ff723339d00], txn-recover: You should confirm that you have opened the database with the correct options including all encryption and compression options
2017-10-15T11:14:43.988-0400 E STORAGE  [initandlisten] WiredTiger error (-31802) [1508080483:988080][20997:0x7ff723339d00], txn-recover: Recovery failed: WT_ERROR: non-specific WiredTiger error
2017-10-15T11:14:43.992-0400 I -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 269
2017-10-15T11:14:43.993-0400 I STORAGE  [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
2017-10-15T11:14:43.993-0400 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2017-10-15T11:14:43.993-0400 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2017-10-15T11:14:43.993-0400 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
2017-10-15T11:14:43.993-0400 I CONTROL  [initandlisten] now exiting
2017-10-15T11:14:43.993-0400 I CONTROL  [initandlisten] shutting down with code:100



 Comments   
Comment by Ramon Fernandez Marina [ 15/Oct/17 ]

Thanks Max, pilot error – this is indeed documented (and I was running the command on the wrong server).

Comment by Max Hirschhorn [ 15/Oct/17 ]

ramon.fernandez, when you start a server with a fresh dbpath, the featureCompatibilityVersion will default to 3.6. You'd need to set the featureCompatibilityVersion to 3.4 in order to be able to downgrade. On shutdown, WiredTiger downgrade its files to a format compatibility with MongoDB 3.4.

2017-10-15T11:22:54.752-0400 I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
2017-10-15T11:22:54.843-0400 I STORAGE  [signalProcessingThread] Downgrading files to FCV 3.4
2017-10-15T11:22:55.352-0400 I STORAGE  [signalProcessingThread] WiredTiger message [1508080975:352661][12052:0x700000081000], txn-recover: Main recovery loop: starting at 1/14336
2017-10-15T11:22:55.469-0400 I STORAGE  [signalProcessingThread] WiredTiger message [1508080975:469750][12052:0x700000081000], txn-recover: Recovering log 1 through 2
2017-10-15T11:22:55.545-0400 I STORAGE  [signalProcessingThread] WiredTiger message [1508080975:545663][12052:0x700000081000], txn-recover: Recovering log 2 through 2

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