[SERVER-32544] Corrupt DB after Hard Crash (repeated 3 times) Created: 04/Jan/18 Updated: 29/Jan/18 Resolved: 05/Jan/18 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Stability, Storage |
| Affects Version/s: | 3.6.1 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Critical - P2 |
| Reporter: | John Page | Assignee: | Daniel Gottlieb (Inactive) |
| Resolution: | Cannot Reproduce | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Backwards Compatibility: | Fully Compatible |
| Operating System: | ALL |
| Steps To Reproduce: | This won't be easy. Centos 7 VM - VirtualBox 5.1.30 on OSX, 2 cores, 8GB RAM Crashes - sometimes leaving DB corrupted. Database files are available. |
| Participants: |
| Description |
|
MongoDB 3.6 - Centos 7 Running in VM (Virtualbox on OSX) - several times Virtualbox has crashed with memory error. Not this is NOT the bug. After this crash - WT databases being written to at the time corrupted and cannot start.
|
| Comments |
| Comment by Daniel Gottlieb (Inactive) [ 05/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Thanks John. Feel free to let us know if some new data pops up. | |||||||||||||||||||||||||||||||||||
| Comment by John Page [ 05/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
I cannot reproduce this short of having a physical box to pull the plug on, not reproducible with a kill -9 of mongod on AWS. I'm happy to go with bruce.lucas view it's a (virtual) hardware fault in the disk system and all data was on the same drive. | |||||||||||||||||||||||||||||||||||
| Comment by John Page [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Go clarify, when it broke I was running mongorestore on the included dump to an undsharded collection | |||||||||||||||||||||||||||||||||||
| Comment by Susan LoVerso [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
The content of configRepl/rs3/db/WiredTiger.wt is clearer VM/OS level corruption. Trying to list the metadata gives this error:
Offset 192515 is 0x2f000. The content at that address is garbage (mostly 0's) and the following block contains data from what appears to be the mongodb informational log file. Again I include a bit of the previous, uncorrupted block with actual WiredTiger metadata content:
| |||||||||||||||||||||||||||||||||||
| Comment by Daniel Gottlieb (Inactive) [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Same for configRepl/rs3. All members of the shards started up fine. john.page can you clarify what you mean when you say the crash can happen when "restoring BSON"? The FTDC data for the shards isn't as complete as I would expect, but from what I can see, would it be correct that no application was running against the system? The only operations being performed were internal sharded cluster procedures? | |||||||||||||||||||||||||||||||||||
| Comment by Susan LoVerso [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
That file definitely shows on-disk corruption. Offset 196608 is 0x30000. Here's what is in the file (from hexdump -C. I include some of the correct and typical content right before it too:
| |||||||||||||||||||||||||||||||||||
| Comment by Daniel Gottlieb (Inactive) [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Trying to start configRepl/rs2 (with the intention of comparing the oplog to rs1), WT gets checksum failures reading WiredTiger.wt:
| |||||||||||||||||||||||||||||||||||
| Comment by Bruce Lucas (Inactive) [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
The kernel backtrace above comes from OSX, and has been reported (based the "Kernel Extensions in backtrace" section) by other users. The listed kernel extensions in backtrace include "com.apple.iokit.IOStorageFamily". This makes me suspect that the root cause could be an OSX bug that can cause storage corruption, but that's purely based on thin circumstantial evidence. I think a repro on AWS would be useful. | |||||||||||||||||||||||||||||||||||
| Comment by Susan LoVerso [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Particularly if you think there is corruption, saving a copy of the pre-restart files would be helpful as well as the post corruption files. | |||||||||||||||||||||||||||||||||||
| Comment by John Page [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Would you like me to fuzz test it on AWS tomorrow and see if I can cause any issues once I take Virtualbox out of the picture? | |||||||||||||||||||||||||||||||||||
| Comment by John Page [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
pasette - it's not consistent , I can try to reproduce but I don't like doing so as It involved a Kernel panic on my laptop caused by the VM. In broad terms it's Small sharded cluster on VM, VM Causes Host OS Kernel Panic, After that a WT files corrupted. Kernel panic happens when WT (a) restoring BSON or (b) Balancing a bunch of chunks. Not sure how I can give you reproducible case but have given you the files post corruption. | |||||||||||||||||||||||||||||||||||
| Comment by Daniel Pasette (Inactive) [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
John, can you give more detailed repro steps? | |||||||||||||||||||||||||||||||||||
| Comment by John Page [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Virtual Box caused a Kernel Panic on my Mac
So yes, a virtual hardware error causing a pysical OS panic. The first time I saw this I think it was WT corruption - but Given the VM crash I ignored it , this time it looks like a replication issue. | |||||||||||||||||||||||||||||||||||
| Comment by Bruce Lucas (Inactive) [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Can you clarify what you mean by "memory error"? What were the specific messages and where and when did you see them? If there are (virtual) hardware errors, i.e. the VM is not operating properly, then data integrity can't be guaranteed. Having said that this doesn't appear to be data corruption per se, i.e. the data is well-formed at the storage engine level. It appears rather that (as you mention) to be a replication issue - the oplog appears to be in an unexpected state. This could be a replication bug related to a crash and unrelated to the reason for the crash ("memory errors"). | |||||||||||||||||||||||||||||||||||
| Comment by John Page [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
Files available at https://s3-eu-west-1.amazonaws.com/johnpage2016/SERVER32544.tgz | |||||||||||||||||||||||||||||||||||
| Comment by John Page [ 04/Jan/18 ] | |||||||||||||||||||||||||||||||||||
|
This message looks subtly different to last which I didnt keep - perhaps replication related. |