[SERVER-35733] Fassert on mongod 4.0 startup after a snapshot restore Created: 21/Jun/18  Updated: 27/Oct/23  Resolved: 22/Jun/18

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

Type: Bug Priority: Major - P3
Reporter: Lawrence Tan (Inactive) Assignee: Tess Avitabile (Inactive)
Resolution: Works as Designed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: Text File mongodb-4_dot_0_restore_failure.log    
Issue Links:
Depends
Related
Operating System: ALL
Participants:

 Description   

We're seeing this cloud provider snapshot restore problem only when using MongoDB 4.0.

2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] 
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] ** WARNING: mongod started without --replSet yet 1 documents are present in local.system.replset.
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] **          Database contents may appear inconsistent with the oplog and may appear to not contain
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] **          writes that were visible when this node was running as part of a replica set.
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] **          Restart with --replSet unless you are doing maintenance and no other clients are connected.
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] **          The TTL collection monitor will not start because of this.
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] **         
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten]  For more info see http://dochub.mongodb.org/core/ttlcollections
2018-06-19T22:30:05.354+0000 I STORAGE  [initandlisten] 
2018-06-19T22:30:05.354+0000 I NETWORK  [initandlisten] waiting for connections on port 37303
2018-06-19T22:30:05.356+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:53694 #1 (1 connection now open)
2018-06-19T22:30:05.363+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:53696 #2 (2 connections now open)
2018-06-19T22:30:05.365+0000 I COMMAND  [conn1] CMD: drop local.oplog.rs
2018-06-19T22:30:05.365+0000 I STORAGE  [conn1] Finishing collection drop for local.oplog.rs (24733bdc-79a3-4aed-b55b-a9631d878412).
2018-06-19T22:30:05.365+0000 I STORAGE  [WTOplogJournalThread] oplog journal thread loop shutting down
2018-06-19T22:30:05.370+0000 I STORAGE  [conn2] createCollection: local.oplog.rs with generated UUID: 80ce55c5-5ea3-4801-aebc-066682250d20
2018-06-19T22:30:05.394+0000 I STORAGE  [conn2] WiredTigerRecordStoreThread local.oplog.rs already started
2018-06-19T22:30:05.394+0000 I STORAGE  [conn2] The size storer reports that the oplog contains 0 records totaling to 0 bytes
2018-06-19T22:30:05.394+0000 I STORAGE  [conn2] Scanning the oplog to determine where to place markers for truncation
2018-06-19T22:30:05.395+0000 E STORAGE  [conn1] WiredTiger error (22) [1529447405:395315][11099:0x7fb2e89e6700], WT_SESSION.timestamp_transaction: commit timestamp 495C078000000001 older than oldest timestamp 5b297d9000000001: Invalid argument Raw: [1529447405:395315][11099:0x7fb2e89e6700], WT_SESSION.timestamp_transaction: commit timestamp 495C078000000001 older than oldest timestamp 5b297d9000000001: Invalid argument
2018-06-19T22:30:05.395+0000 F -        [conn1] Fatal assertion 39001 BadValue: timestamp_transaction 22: Invalid argument at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 1243
2018-06-19T22:30:05.395+0000 F -        [conn1] 
 
***aborting after fassert() failure

We first saw this issue on the following E2E tests:

However, we can reproduce the same problem when doing the cloud provider restore (w/ mongod 4.0) on cloud-qa env.


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