使用 wiredtiger 工具 wt 恢复数据

Recently at work, we experienced a series of events that could have proven to be catastrophic for one of our datasets. We have a daily process that does daily cleanup, but relies on the presence of control data that is ETL’d in from another process.

The secondary process failed, and as a result, everything was “cleaned” … aka, we purged an entire dataset.

This data happens to be on a 5 node replicaset (primary-secondary-secondary-arbiter-hidden), and the hidden node died over the holidays and I waited too long to recover it, so it was unable to ever catch up to the primary (always stuck in a RECOVERING state).

My incredible foresight (… laziness … ) resulted in us having a backup of the data ready to be extracted from the out of sync hidden node. All we had to do was start up mongod … right?

123456789101112131415161718

2016-01-29T21:06:05.180-0500 I CONTROL  ***** SERVER RESTARTED *****2016-01-29T21:06:05.241-0500 I CONTROL  [initandlisten] MongoDB starting : pid=1745 port=27021 dbpath=/data 64-bit host=xxx2016-01-29T21:06:05.241-0500 I CONTROL  [initandlisten] db version v3.0.82016-01-29T21:06:05.241-0500 I CONTROL  [initandlisten] git version: 83d8cc25e00e42856924d84e220fbe4a839e605d2016-01-29T21:06:05.241-0500 I CONTROL  [initandlisten] build info: Linux build3.ny.cbi.10gen.cc 2.6.32-431.3.1.el6.x86_64 #1 SMP Fri Jan 3 21:39:27 UTC 2014 x86_64 BOOST_LIB_VERSION=1_492016-01-29T21:06:05.241-0500 I CONTROL  [initandlisten] allocator: tcmalloc...2016-01-29T21:06:05.315-0500 W -        [initandlisten] Detected unclean shutdown - /data/mongod.lock is not empty.2016-01-29T21:06:05.315-0500 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.2016-01-29T21:06:05.324-0500 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=13G,session_max=20000,eviction=(threads_max=4),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),2016-01-29T21:06:05.725-0500 E STORAGE  [initandlisten] WiredTiger (0) [1454119565:724960][1745:0x7f2ac9534bc0], file:WiredTiger.wt, cursor.next: read checksum error for 4096B block at offset 6799360: block header checksum of 1769173605 doesn't match expected checksum of 41760847832016-01-29T21:06:05.725-0500 E STORAGE  [initandlisten] WiredTiger (0) [1454119565:725067][1745:0x7f2ac9534bc0], file:WiredTiger.wt, cursor.next: WiredTiger.wt: encountered an illegal file format or internal value2016-01-29T21:06:05.725-0500 E STORAGE  [initandlisten] WiredTiger (-31804) [1454119565:725088][1745:0x7f2ac9534bc0], file:WiredTiger.wt, cursor.next: the process must exit and restart: WT_PANIC: WiredTiger library panic2016-01-29T21:06:05.725-0500 I -        [initandlisten] Fatal Assertion 28558

Aw crap. I could not for the life of me get the node back up and running. Since this was a replica-set member, I thought maybe if I just copied the failing file from the (working) primary it would just work. Apparently that’s not the way MongoDB or WiredTiger works :P. Back to the drawing board.

I could see that my data directory contained a bunch of collection-*.wt and index-*.wtfiles, so I assumed these were the WiredTiger collection and index files. These are binary files so grep-ing didn’t help me identify the collection I needed.

I wanted to next see if I could just copy the collection’s backing file directly to a new (working) MongoDB installation, so I started up a new mongod, created a new collection with a document in it, then copied over any collection-*.wt file to see what would happen.

Guess what … didn’t work.

Identify the WiredTiger collection’s backing file

Since we had access to a working node, plus the collection hadn’t been dropped (just purged), I thought maybe the files on each node would be the same. I logged into the primary via the shell to get some info from my collection.

12345678910111213141516171819202122232425262728293031323334

db.getCollection('borkedCollection').stats(){    "ns" : "production.borkedCollection",    "count" : 0,    "size" : 0,    "storageSize" : 1138688,    "capped" : false,    "wiredTiger" : {        "metadata" : {            "formatVersion" : 1        },        "creationString" : "allocation_size=4KB,app_metadata=(formatVersion=1),block_allocation=best,block_compressor=snappy,cache_resident=0,checkpoint=(WiredTigerCheckpoint.5149=(addr=\"01808080808080c0b081e40ebe4855808080e3113fc0e401417fc0\",order=5149,time=1454966060,size=21078016,write_gen=119495)),checkpoint_lsn=(224134,44112768),checksum=on,collator=,columns=,dictionary=0,format=btree,huffman_key=,huffman_value=,id=178668,internal_item_max=0,internal_key_max=0,internal_key_truncate=,internal_page_max=4KB,key_format=q,key_gap=10,leaf_item_max=0,leaf_key_max=0,leaf_page_max=32KB,leaf_value_max=1MB,memory_page_max=10m,os_cache_dirty_max=0,os_cache_max=0,prefix_compression=0,prefix_compression_min=4,split_deepen_min_child=0,split_deepen_per_child=0,split_pct=90,value_format=u,version=(major=1,minor=1)",        "type" : "file",        "uri" : "statistics:table:collection-7895--1435676552983097781",        "LSM" : {            //...        },        "block-manager" : {            //...        },        "btree" : {            // ...        },        // ...    },    "nindexes" : 4,    "totalIndexSize" : 1437696,    "indexSizes" : {        "_id_" : 212992,        // ...    },    "ok" : 1}

That "uri" : "statistics:table:collection-7895--1435676552983097781" entry looked promising.

I started hunting for a way to extract the data from this file without having to “mount” the file in another MongoDB installation, as I assumed this was not possible. I stumbled across a command line utility for WiredTiger that happened to have a ‘salvage’ command.

Salvaging the WiredTiger collection

In order to use the wt utility, you have to build it from source. Being comfortable in Linux, this was not daunting ;)

wget http://source.wiredtiger.com/releases/wiredtiger-2.7.0.tar.bz2tar xvf wiredtiger-2.7.0.tar.bz2cd wiredtiger-2.7.0sudo apt-get install libsnappy-dev build-essential./configure --enable-snappymake

NOTE adding support for Google’s snappy compressor when building WiredTiger will save you some errors that I initially encountered when trying to salvage the data.

Now that I had a wt utility, I wanted to test it out on the collection file. It turns out that you need additional supporting files before you can do this. Once I’d copied over the necessary files, my working directory (called mongo-bak) looked like this:

-rw-r--r-- 1 root      root      4738772992 Feb  9 14:06 collection-2657--1723320556100349955.wt-rw-r--r-- 1 root      root         1155072 Feb  9 14:05 _mdb_catalog.wt-rw-r--r-- 1 root      root        26935296 Feb  9 14:05 sizeStorer.wt-rw-r--r-- 1 root      root              95 Feb  9 14:05 storage.bson-rw-r--r-- 1 root      root              46 Feb  9 14:04 WiredTiger-rw-r--r-- 1 root      root             495 Feb  9 14:04 WiredTiger.basecfg-rw-r--r-- 1 root      root              21 Feb  9 14:04 WiredTiger.lock-rw-r--r-- 1 root      root             916 Feb  9 14:04 WiredTiger.turtle-rw-r--r-- 1 root      root        10436608 Feb  9 14:04 WiredTiger.wt

Now, from the directory where we compiled WiredTiger, we started salvaging the collection:

./wt -v -h ../mongo-bak -C "extensions=[./ext/compressors/snappy/.libs/libwiredtiger_snappy.so]" -R salvage collection-2657--1723320556100349955.wt

You know it’s working if you see output along the lines of:

WT_SESSION.salvage 639400             

which I believe is just counting up the number of documents recovered. Once the operation has completed, it will have overwritten the source *.wt collection file with whatever it could salvage.

The only issue is that you still can’t load this into MongoDB yet.

Importing the WiredTiger collection via dump/load into MongoDB

In order to get the data into MongoDB, first we need to generate a dump file from the WiredTiger collection file. This is done using the wt utility:

./wt -v -h ../data -C "extensions=[./ext/compressors/snappy/.libs/libwiredtiger_snappy.so]" -R dump -f ../collection.dump collection-2657--1723320556100349955

This operation produces no output, so you’ll just have to sit tight and wait a while. You can always watch ls -l in another console if you want to make sure it’s working ;)

Once completed, you’ll have a collection.dump file, but this still can’t be loaded directly into MongoDB. You can however, using the wt utility one more time, load the dump back into a WiredTiger collection.

First, let’s startup a new mongod instance that we can try this out on.

mongod --dbpath tmp-mongo --storageEngine wiredTiger --nojournal                                  

Next, let’s connect to this instance via the mongo shell and create a new collection:

use Recoverydb.borkedCollection.insert({test: 1})db.borkedCollection.remove({})db.borkedCollection.stats()

I’ve created a new db called Recovery, and inserted/removed a document so the collection’s backing file would be generated. You can use the stats() method to get the collection name, but since we’re only using one collection, it’s easy enough to find just usingls.

Now we’re going to take the backing file name of the collection we just created and use that to load our WiredTiger dump file:

./wt -v -h ../data -C "extensions=[./ext/compressors/snappy/.libs/libwiredtiger_snappy.so]" -R load -f ../collection.dump -r collection-2-880383588247732034

Note that we drop the .wt extension from the collection file above. Also, the -h flag needs to point to the directory where our mongod has it’s dbPath. Finally, mongod should not be running.

This operation also provides a progress indicator showing how much data has been loaded:

table:collection-4--4286091263744514813: 1386220

Once completed, we can start mongod back up, shell in and have a look:

12345678910111213

$ mongoMongoDB shell version: 3.2.1connecting to: testMongo-Hacker 0.0.9laptop(mongod-3.2.1) test> show dbsRecovery → 0.087GBlocal    → 0.000GBlaptop(mongod-3.2.1) test> use Recoveryswitched to db Recoverylaptop(mongod-3.2.1) Recovery> show collectionsborkedCollection → 0.000MB / 88.801MBlaptop(mongod-3.2.1) Recovery> db.borkedCollection.count()0

WTF? The size looks right, but there are no documents???

123456789101112

laptop(mongod-3.2.1) Recovery> db.borkedCollection.find({}, {_id: 1}){  "_id": ObjectId("55e07f3b2e967329c888ac74")}{  "_id": ObjectId("55e07f3b2e967329c888ac76")}...{  "_id": ObjectId("55e07f402e967329c888ac85")}Fetched 20 record(s) in 29ms -- More[true]

Well that’s promising, but the collection still hasn’t been properly restored yet.

Restoring the MongoDB collection to a usable state

This final part is pretty straightforward, as we’re just going to do a mongodump, followed by amongorestore.

NOTE The mongodump will fail if you’re using a version of MongoDB < 3.2, as 3.2 is built against WiredTiger 2.7. I initially tested this using MongoDB 3.0.9 and the dump operation just returned 0 results.

12345678910111213141516171819202122232425262728293031323334353637

$ mongodump2016-02-10T22:04:00.580-0500    writing Recovery.borkedCollection to 2016-02-10T22:04:03.579-0500    Recovery.borkedCollection  2682192016-02-10T22:04:06.579-0500    Recovery.borkedCollection  3406552016-02-10T22:04:09.579-0500    Recovery.borkedCollection  4967872016-02-10T22:04:12.579-0500    Recovery.borkedCollection  6708942016-02-10T22:04:15.579-0500    Recovery.borkedCollection  7785392016-02-10T22:04:18.579-0500    Recovery.borkedCollection  8485252016-02-10T22:04:21.579-0500    Recovery.borkedCollection  9912772016-02-10T22:04:24.579-0500    Recovery.borkedCollection  11477182016-02-10T22:04:27.579-0500    Recovery.borkedCollection  11876002016-02-10T22:04:30.579-0500    Recovery.borkedCollection  13536652016-02-10T22:04:33.579-0500    Recovery.borkedCollection  13762552016-02-10T22:04:33.681-0500    Recovery.borkedCollection  13862202016-02-10T22:04:33.682-0500    done dumping Recovery.borkedCollection (1386220 documents)$ mongorestore --drop2016-02-10T22:05:51.959-0500    using default 'dump' directory2016-02-10T22:05:51.960-0500    building a list of dbs and collections to restore from dump dir2016-02-10T22:05:52.307-0500    reading metadata for Recovery.borkedCollection from dump/Recovery/borkedCollection.metadata.json2016-02-10T22:05:52.330-0500    restoring Recovery.borkedCollection from dump/Recovery/borkedCollection.bson2016-02-10T22:05:54.962-0500    [#.......................]  Recovery.borkedCollection  32.8 MB/569.8 MB  (5.8%)2016-02-10T22:05:57.962-0500    [###.....................]  Recovery.borkedCollection  80.5 MB/569.8 MB  (14.1%)2016-02-10T22:06:00.962-0500    [#####...................]  Recovery.borkedCollection  131.5 MB/569.8 MB  (23.1%)2016-02-10T22:06:03.962-0500    [#######.................]  Recovery.borkedCollection  178.5 MB/569.8 MB  (31.3%)2016-02-10T22:06:06.962-0500    [#########...............]  Recovery.borkedCollection  230.1 MB/569.8 MB  (40.4%)2016-02-10T22:06:09.962-0500    [###########.............]  Recovery.borkedCollection  271.6 MB/569.8 MB  (47.7%)2016-02-10T22:06:12.962-0500    [#############...........]  Recovery.borkedCollection  320.6 MB/569.8 MB  (56.3%)2016-02-10T22:06:15.962-0500    [###############.........]  Recovery.borkedCollection  366.3 MB/569.8 MB  (64.3%)2016-02-10T22:06:18.962-0500    [#################.......]  Recovery.borkedCollection  414.9 MB/569.8 MB  (72.8%)2016-02-10T22:06:21.962-0500    [###################.....]  Recovery.borkedCollection  464.8 MB/569.8 MB  (81.6%)2016-02-10T22:06:24.962-0500    [#####################...]  Recovery.borkedCollection  504.0 MB/569.8 MB  (88.4%)2016-02-10T22:06:27.962-0500    [#######################.]  Recovery.borkedCollection  554.5 MB/569.8 MB  (97.3%)2016-02-10T22:06:29.082-0500    [########################]  Recovery.borkedCollection  569.8 MB/569.8 MB  (100.0%)2016-02-10T22:06:29.082-0500    restoring indexes for collection Recovery.borkedCollection from metadata2016-02-10T22:06:29.104-0500    finished restoring Recovery.borkedCollection (1386220 documents)2016-02-10T22:06:29.104-0500    done

Now that we’ve dumped and reloaded the collection yet again, we can shell back in and validate that our recovery attempt has succeeded:

12345678910111213

$ mongoMongoDB shell version: 3.2.1connecting to: testMongo-Hacker 0.0.9laptop(mongod-3.2.1) test> show dbsRecovery → 0.099GBlocal    → 0.000GBlaptop(mongod-3.2.1) test> use Recoveryswitched to db Recoverylaptop(mongod-3.2.1) Recovery> show collectionsborkedCollection → 569.845MB / 88.594MBlaptop(mongod-3.2.1) Recovery> db.borkedCollection.count()1386220

BOOYA! Everything is back and properly accessible.

The mongorestore could actually have been done to the primary node in order to recover the data for production purposes. Once that’s done, just recreate the necessary indexes and you’re back in business.

转自：http://www.alexbevi.com/blog/2016/02/10/recovering-a-wiredtiger-collection-from-a-corrupt-mongodb-installation/