Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-41783

File System Snapshot does not work with Encrypted SE

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Major - P3 Major - P3
    • 4.2.0-rc2, 4.3.1
    • Affects Version/s: 4.2.0-rc1
    • Component/s: Security, Storage
    • None
    • Fully Compatible
    • ALL
    • v4.2
    • Hide
      1. 4.2.0-rc1, enterprise module
      2. Start mongod with encryption on against an empty directory 
        mongod port 1111 --enableEncryption --encryptionKeyFile path-to-keyfile
      3. Open a backup cursor 
        db.runCommand({aggregate: 1, pipeline: [{$backupCursor: {}}], cursor: {batchSize: 100}})
      4. Keep the cursor open with getMore every several minutes just in case
      5. While the cursor is open, copy all files on disk mentioned in the backupCursor cmd response to a different directory. Snippet of such a response: 
              {
        "filename": "/tmp/testenc/key.store/local/WiredTiger"
      },
      {
        "filename": "/tmp/testenc/key.store/local/WiredTiger.backup"
      },
      {
        "filename": "/tmp/testenc/key.store/local/keystore.wt"
      },
      {
        "filename": "/tmp/testenc/sizeStorer.wt"
      },
      {
        "filename": "/tmp/testenc/index-6-5445053478482582191.wt"
      }

        Notice that there's this key.store/local/WiredTiger.backup file being returned

      6. Start mongod with encryption on against this target directory
      7. Expect the fassert 51166
      Show
      4.2.0-rc1, enterprise module Start mongod with encryption on against an empty directory mongod port 1111 --enableEncryption --encryptionKeyFile path-to-keyfile Open a backup cursor db.runCommand({aggregate: 1, pipeline: [{$backupCursor: {}}], cursor: {batchSize: 100}}) Keep the cursor open with getMore every several minutes just in case While the cursor is open, copy all files on disk mentioned in the backupCursor cmd response to a different directory. Snippet of such a response: { "filename" : "/tmp/testenc/key.store/local/WiredTiger" }, { "filename" : "/tmp/testenc/key.store/local/WiredTiger.backup" }, { "filename" : "/tmp/testenc/key.store/local/keystore.wt" }, { "filename" : "/tmp/testenc/sizeStorer.wt" }, { "filename" : "/tmp/testenc/index-6-5445053478482582191.wt" } Notice that there's this key.store/local/WiredTiger.backup file being returned Start mongod with encryption on against this target directory Expect the fassert 51166
    • Security 2019-07-01

      4.2.0-rc1 with enterprise module
      mongod log snippet:

      2019-06-13T22:26:12.547+0000 I  CONTROL  [main] ***** SERVER RESTARTED *****
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] MongoDB starting : pid=11153 port=46131 dbpath=/srv/mongodb/kms-sloth-shard-0-node-0 64-bit host=kms-sloth-shard-00-00-exmox.mmscloudteam.com
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] db version v4.2.0-rc1
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] git version: fdb56a92bfea1af0344044856df04af4d464a3b4
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] allocator: tcmalloc
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] modules: enterprise
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] build environment:
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten]     distmod: rhel70
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten]     distarch: x86_64
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten]     target_arch: x86_64
2019-06-13T22:26:12.558+0000 I  CONTROL  [initandlisten] options: { config: "/srv/mongodb/kms-sloth-shard-0-node-0/automation-mongod.conf", net: { bindIp: "0.0.0.0", compression: { compressors: "snappy,zlib" }, maxIncomingConnections: 350, maxIncomingConnectionsOverride: [ "192.168.248.0/21" ], port: 46131, tls: { CAFile: "/etc/pki/tls/certs/atlas-bundle.crt", allowConnectionsWithoutCertificates: true, certificateKeyFile: "/etc/pki/tls/private/mongod.pem", disabledProtocols: "TLS1_0", mode: "requireTLS" } }, processManagement: { fork: true }, security: { enableEncryption: true, javascriptEnabled: true, kmip: { clientCertificateFile: "/var/lib/mongodb-mms-automation/kmipClient.pem", port: 35696, serverCAFile: "/var/lib/mongodb-mms-automation/kmipCA.pem", serverName: "127.0.0.1" }, ldap: { authz: { queryTemplate: "{USER}?memberOf?base" }, bind: { queryPassword: "ILuv@DS4LDAP", queryUser: "CN=Administrator,CN=Users,DC=aws-atlas-ads-test-01,DC=mmscloudteam,DC=com" }, servers: "aws-atlas-ads-test-01.ldap.mmscloudteam.com:636", validateLDAPServerConfig: false } }, setParameter: { authenticationMechanisms: "SCRAM-SHA-1,PLAIN", disableLogicalSessionCacheRefresh: "true", failIndexKeyTooLong: "true", honorSystemUmask: "false", mongotHost: "localhost:28000", notablescan: "false", reportOpWriteConcernCountersInServerStatus: "true", suppressNoTLSPeerCertificateWarning: "true", ttlMonitorEnabled: "false", watchdogPeriodSeconds: "60" }, storage: { dbPath: "/srv/mongodb/kms-sloth-shard-0-node-0", engine: "wiredTiger", wiredTiger: { engineConfig: { configString: "cache_size=512MB" } } }, systemLog: { destination: "file", logAppend: true, path: "/srv/mongodb/kms-sloth-shard-0-node-0/mongodb.log" } }
2019-06-13T22:26:12.560+0000 W  STORAGE  [initandlisten] Detected unclean shutdown - /srv/mongodb/kms-sloth-shard-0-node-0/mongod.lock is not empty.
2019-06-13T22:26:12.560+0000 W  STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2019-06-13T22:26:12.560+0000 I  STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=388M,session_max=33000,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),verbose=(checkpoint_progress),encryption=(name=AES256-CBC,keyid=".system"),extensions=[local={entry=mongo_addWiredTigerEncryptors,early_load=true},,],cache_size=512MB
2019-06-13T22:26:13.122+0000 W  NETWORK  [initandlisten] You have an IP Address in the DNS Name field on your certificate. This formulation is deprecated.
2019-06-13T22:26:13.144+0000 I  STORAGE  [initandlisten] Opening WiredTiger keystore. Config: create,compatibility=(release=2.9),config_base=false,log=(enabled,file_max=3MB),transaction_sync=(enabled=true,method=fsync),extensions=[local={entry=mongo_addWiredTigerEncryptors,early_load=true},],encryption=(name=AES256-CBC,keyid=.master),
2019-06-13T22:26:13.145+0000 I  STORAGE  [initandlisten] WiredTiger keystore Both WiredTiger.turtle and WiredTiger.backup exist; recreating metadata from backup
2019-06-13T22:26:13.186+0000 I  STORAGE  [initandlisten] Detected keystore schema version 0 upgrading to schema version 1
2019-06-13T22:26:13.186+0000 F  -        [initandlisten] Fatal Assertion 51166 at src/mongo/db/modules/enterprise/src/encryptdb/encryption_key_manager.cpp 371
2019-06-13T22:26:13.186+0000 F  -        [initandlisten]

      The specific error is introduced in SERVER-40074

            Assignee:
            jonathan.reams@mongodb.com Jonathan Reams
            Reporter:
            chunming.li@mongodb.com Chunming Li (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            10 Start watching this issue

              Created:
              Updated:
              Resolved: