[SERVER-18583] Errors validating newly created WiredTiger replica member during upgrade to 3.0 Created: 20/May/15  Updated: 04/Aug/15  Resolved: 20/Jun/15

Status: Closed
Project: Core Server
Component/s: Replication, Storage, WiredTiger
Affects Version/s: 3.0.2, 3.0.3
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Oleksiy Kovyrin Assignee: Ramon Fernandez Marina
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File replica303.log.gz    
Issue Links:
Related
is related to WT-1959 Change block leak to be a verify warn... Closed
Operating System: ALL
Steps To Reproduce:

We have tried to re-create this replica on a few different servers, the issue happened 3 times out of 4. Though on the replica that wasn't corrupted initially, we have noticed the issue a few days later. So that makes it 4 out of 4.

I'm not sure if it is reproducible on other clusters since we didn't have a chance to try it there.

Participants:

 Description   

We are trying to migrate from Mongo 2.6 to the latest 3.0 and as a part of the process we have decided to switch one of our backup replicas (that we use for lvm-snapshot-based backups) to 3.0 and see how it behaves.

The initial sync of the new replica succeeds, but when we try to validate the data on it, we hit a really weird issue: the data seems to be corrupted. Our validation script runs validate on all collections on the server and the first one it hits is local.oplog.rs. Here is the result:

bulk:SECONDARY> use local
switched to db local
bulk:SECONDARY> db.oplog.rs.validate()
{
	"ns" : "local.oplog.rs",
	"nIndexes" : 0,
	"keysPerIndex" : {
 
	},
	"valid" : false,
	"errors" : [
		"[1432129022:325598][14023:0x7f00ae4d3700], file:collection-6--2540725476965076228.wt, session.verify: checkpoint ranges never verified: 668",
		"[1432129022:521082][14023:0x7f00ae4d3700], file:collection-6--2540725476965076228.wt, session.verify: file ranges never verified: 668",
		"verify() returned WT_ERROR: non-specific WiredTiger error. This indicates structural damage. Not examining individual documents."
	],
	"warning" : "Some checks omitted for speed. use {full:true} option to do more thorough scan.",
	"advice" : "ns corrupt. See http://dochub.mongodb.org/core/data-recovery",
	"ok" : 1
}

Configuration file for the server looks like this:

# Where to log
systemLog:
  destination: file
  path: /var/log/mongo/mongod-bulk.log
  logAppend: true
  logRotate: reopen
 
#-------------------------------------------------------------------------------
# Where to listen for connections
net:
  # TCP port for connections
  port: 27018
 
  # Disable IPv6
  ipv6: false
 
  # Disable unix socket
  unixDomainSocket:
    enabled: false
 
#-------------------------------------------------------------------------------
# How to deal with the processes
processManagement:
  # Fork and run in background
  fork: true
 
  # Location of pidfile
  pidFilePath: /var/run/mongodb/mongod-bulk.pid
 
#-------------------------------------------------------------------------------
# Where and how to store data
storage:
  # Database path
  dbPath: /db/mongo/bulk
 
  # Enable journaling
  journal:
    enabled: true
 
  # Use WiredTiger storage engine by default
  engine: wiredTiger
 
  # Tuning for wired tiger
  wiredTiger:
    engineConfig:
      # Use up to 2G of RAM for caching
      cacheSizeGB: 2
 
#-------------------------------------------------------------------------------
# Replication Options
replication:
  # Limit the size of oplog
  oplogSizeMB: 65536
 
  # Set replica name
  replSetName: bulk



 Comments   
Comment by Ramon Fernandez Marina [ 20/Jun/15 ]

kovyrin, we haven't heard from you for a while so I'm going to close this ticket for now. You may be interested in looking at WT-1959, which will turn this error into a warning as the situation is not fatal. If this is still an issue for you feel free to reopen the ticket and provide the information requested in my comments above for further investigation.

Regards,
Ramón.

Comment by Ramon Fernandez Marina [ 09/Jun/15 ]

Hi kovyrin, have you had a chance to validate collections other than the oplog? Are you able to provide any of the information requested above that may help us understand the root cause of your issue?

Thanks,
Ramón.

Comment by Ramon Fernandez Marina [ 03/Jun/15 ]

kovyrin, have you tried validating other collections? I'm wondering whether the LVM snapshot is the source of the issue here, so it would be interesting to know if other collections also fail to validate or only the oplog. Can you please run validate() on the rest of your collections?

Thanks,
Ramón.

Comment by Ramon Fernandez Marina [ 28/May/15 ]

kovyrin, we've been discussing options internally, and without a way to reproduce this behavior it may be very hard to track down what's happening.

You mention you were able to reproduce this multiple times on different servers; was the storage used for MongoDB local to the server or were you using a SAN or NFS volume? The error you're seeing indicates that a block is missing and I want to make sure the storage layer you're using is not the culprit here.

As for your question about replication and the local database, it seems there could be a bug in the handling of the oplog that's being triggered in your secondaries by your particular workload. If that was the case it may help to send us the oplog, but if you say your secondary has been working well since last week we may have lost that window.

I'll try to reproduce on our end. Are there any other information about your setup you can provide, like sample (redacted) documents, a list of databases, collections and indexes, and details about your typical workload? You can put any information you're able to share in text files and upload them privately as above, so no details about your system are made public.

Thanks,
Ramón.

Comment by Oleksiy Kovyrin [ 26/May/15 ]

And another question while we're at it: how comes mongo does not see any issues in using the corrupted oplog while handling the replication stream on this replica? The replica has been alive and well since last week and nothing in the logs seems to indicate that the oplog is corrupted...

Comment by Oleksiy Kovyrin [ 26/May/15 ]

One more thing I'm still not sure about is how could the local database corruption be related to the data being replicated (the contents of the primary) when local database itself is not being replicated and all the issues with it are the sole responsibility of the replica mongo process? Am I missing something?

Thanks in advance for any clarifications you could provide.

Comment by Oleksiy Kovyrin [ 26/May/15 ]

Unfortunately I can't upload the database both because it is more than a terabyte in size and because it contains all of our customers data in it.
Regrading running repair: AFAIR your own documentation said that repair should never be used on members of a replicaset and instead a replica should be recreated. Though in this case replica is getting created in a broken state :-/

What other options for further debugging do we have in this case that would not involve us uploading a terabyte of sensitive customer data to your servers?

Thanks,
Oleksiy

Comment by Ramon Fernandez Marina [ 26/May/15 ]

kovyrin, to fix the error you're seeing it should be sufficient to run repair, but we'd like to understand how the problem appeared in the first place. If I understand correctly you've been able to reproduce this multiple times, so I was hoping we could do the same locally. Would it be possible to upload the contents of your 2.6.9 primary and the exact process you followed to reproduce the problem? You can use scp as above for a private and secure upload.

Thanks,
Ramón.

Comment by Ramon Fernandez Marina [ 22/May/15 ]

Thanks for the files kovyrin, we're investigating them and we'll let you know what we find and/or if we need more data.

Comment by Oleksiy Kovyrin [ 21/May/15 ]

Done, uploaded it as SERVER-18583.tgz

Comment by Oleksiy Kovyrin [ 20/May/15 ]

I'm looking into uploading the data now.

Regarding the oplog, here is what happened. We have created the replica, created a snapshot of it (which we then use for backup purposes) and to validate the snapshot we have started a separate mongo instance from it, found all collections and started performing validate() call on each of them. Oplog was simply the first collection our backups validation script found and tried to validate. I haven't tried others simply because those are 1Tb+ in size and when oplog is corrupted, I could not trust the backup to be valid anyways.

Comment by Ramon Fernandez Marina [ 20/May/15 ]

Thanks for the additional information kovyrin. Can you please upload the file that shows the errors so we can investigate why validate() is complaining? You can upload files securely and privately (only accessible to MongoDB staff) via scp:

tar czf upload.tgz collection-6--2540725476965076228.wt WiredTiger.turtle WiredTiger.wt
scp -P upload.tgz SERVER-18583@www.mongodb.com:

When prompted for a password just press enter.

Also, what prompted you to validate the oplog? Have you validated other collections successfully?

Thanks,
Ramón.

Comment by Oleksiy Kovyrin [ 20/May/15 ]

Just attached the log file.

Comment by Oleksiy Kovyrin [ 20/May/15 ]

1. Versions:

  • we're upgrading from: 2.6.9, though the data has been in this cluster for a very long time (since 2.2).
  • we're upgrading to: we have started the upgrade when the latest one was 3.0.2, the last attempt was on 3.0.3.

2. Just tried to validate the same collection on another box - worked with no issues. What actually makes this situation really weird, is that the collection in question is oplog, which is not replicated between servers. This, as far as I understand, means that is is either got created incorrectly, got corrupted along the way, or there is some underlying issue with validating this particular collection (or this type of collection, which is a capped one).

3. Logs (redacted in both cases to remove any customer data and other sensitive information):

Comment by Ramon Fernandez Marina [ 20/May/15 ]

kovyrin, we'll need more information to determine if there's a bug in the server:

  1. Can you post the specific versions of MongoDB you're upgrading from and to? I see you selected 3.0.2 and 3.0.3 in the affectVersions field; I'd suggest you use 3.0.3 – but what 2.6 version you're using?
  2. Have you tried to validate your data in one of the 2.6 members before the upgrade? We should determine if the upgrade cause the error or it merely detected a pre-existing error
  3. Can you please upload full logs for the primary and the member you upgrade to 3.0.3?

Thanks,
Ramón.

Generated at Thu Feb 08 03:48:09 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.