[SERVER-28488] WT Performance drops to zero during cache eviction with cache full Created: 24/Mar/17 Updated: 21/Jun/17 Resolved: 17/Apr/17 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | WiredTiger |
| Affects Version/s: | 3.2.11 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Wei Shan Ang | Assignee: | Kelsey Schubert |
| Resolution: | Done | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
MongoDB 3.2.11 with WiredTiger on FreeBSD 11. Sharded Cluster |
||
| Attachments: |
|
||||||||
| Issue Links: |
|
||||||||
| Backwards Compatibility: | Fully Compatible | ||||||||
| Participants: | |||||||||
| Description |
|
Hello, We are currently benchmarking our workload against the following test environment:
Our synthetic workload consists of:
We routinely see database operations drop from around 12000/s to 0 ops/s for several seconds at a time during what we believe to be WT cache eviction. After tuning the number of WT evictions threads to 8, eviction trigger(70), eviction target(68), eviction_dirty_trigger(20), eviction_dirty_target(18), we get a far more stable throughput of ~4000 ops/s with drops to 0 ops/s for only a second or so. During the drops to 0 ops/s, we see no disk IO (we're using ZFS with a 1GB L2 cache, no L2ARC, verified with iostat) and we become CPU bound. We are fully aware that we are pushing the system really hard but we didn't expect this behaviour during cache eviction. This issue does not occur when we are only running 200 worker threads against the system. |
| Comments |
| Comment by Wei Shan Ang [ 09/May/17 ] |
|
Hi @Ramon Fernandez, Please note that we are already running 3.2.12 and we are still seeing the same issue. Could you re-open the ticket please? Regards, |
| Comment by Dom Dwyer [ 21/Apr/17 ] |
|
Hi @Alexander Gorrod - I've been working with @Wei Shan Ang to test the throughput of mongodb for our usage scenario. We've been collecting various stats while running a workload generator that inserts a document, and then updates the document to add roughly 4k bytes of data after a small delay. We are currently testing against version 3.2.12. Our workload generator is the only application running on a 40 CPU core box, connected via a 1Gbps LAN to mongos - it performs no IO other than talking to mongo, it's sole purpose is to load test mongo. Monitoring the network interface, we never come remotely close to maxing the link, and we're nowhere near maxing the CPU of the host either. We've correlated the drops to 0 throughput with a declining TrackedDirtyBytesInTheCache delta (measured every second using db.serverStatus()) which is what led us to believe it was related to the cache eviction. During periods of 0 throughput, the mongod boxes become CPU bound (also 40 core boxes) - this is what led us to conclude mongo was stalling as opposed to anything on application side. See the attached graph which is a plot of throughput vs. mongod CPU usage. After resizing the wiredtiger cache from 19GB to 1GB (with wiredTiger.engineConfig.cacheSizeGB=1) the throughput drops are much shorter in duration but still noticable. We also tested setting eviction_dirty_trigger=10 and eviction_dirty_target=7 (with a 19GB cache) as you suggested we still see periods of 0 throughput. I have uploaded new diagnostic data from a mongod instance, and below are a couple of links to various stats we've recorded during various (different) testing runs in the hope they help. If you agree this is a mongo server issue, can we please re-open the ticket? I can run tests and provide any info needed over the next couple of weeks. CPU + disk IO stats: https://docs.google.com/a/itsallbroken.com/spreadsheets/d/1o6N23E_Nc1dBnFC_XXs6qWAXcdKAGjlgRuGHuVEXzn0/edit?usp=sharing |
| Comment by Ramon Fernandez Marina [ 19/Apr/17 ] |
|
vgalu, please note that the SERVER project is for reporting bugs or feature suggestions for the MongoDB server. For MongoDB-related support discussions the mongodb-user group or Stack Overflow with the mongodb tag are better forums. You can also see our Technical Support page for additional support resources. If you test with a newer version of MongoDB and you believe you've found a bug please post in this ticket and we'll reopen to investigate. Regards, |
| Comment by Vlad Galu [ 17/Apr/17 ] |
|
Hello [@alexander.gorrod@mongodb.com], thank you for looking into this. I would like to kindly ask that you keep the ticket open for now. Your interepretation of the uploaded data is opposite of what we see on the test platform. During the dips our I/O is 0, while the CPU of the replica set primary is completely hogged. We have since run further tests that suggest an issue in the WiredTiger cache, shrinking it to 1GB and using all of the available RAM for the ZFS ARC, which sees hit rates of ~90% and ensures consistent performance across lengthy runs. It is possible that the included diagnostic information is not accurate, we are going to repeat the test and update the ticket, if that is fine by you. |
| Comment by Alexander Gorrod [ 17/Apr/17 ] |
|
weishan.ang@gmail.com I have taken a look at the data you uploaded, and it appears as though your application is I/O bound. There are a number of times when all threads are waiting for either reads or writes. My experience is that often periods of slow/zero throughput correspond with I/O being overwhelmed. I can see in the diagnostic data that it is taking a long time for the storage engine to create a checkpoint (durable point in time snapshot on disk in the data files), which is another indication that I/O is overwhelmed. I would suggest trying with an even lower eviction_dirty_trigger=10 and eviction_dirty_target=7 since you have quite a large cache configured, and the cost of creating a checkpoint is proportional to the amount of "dirty" content in the cache. MongoDB has also been working hard to optimize for high-update throughput workloads, and so I would recommend upgrading to the latest version of MongoDB to see the benefit of those improvements. |
| Comment by Wei Shan Ang [ 27/Mar/17 ] |
|
Correction: We routinely see database operations drop from around 12000/s to 0 ops/s for several seconds at a time during what we believe to be WT cache eviction. After tuning the number of WT evictions threads to 8, eviction trigger(70), eviction target(68), eviction_dirty_trigger(20), eviction_dirty_target(18), we get a far more stable throughput of ~8000 ops/s with drops to 0 ops/s for only a second or so. |
| Comment by Wei Shan Ang [ 24/Mar/17 ] |
|
I have uploaded the logs to MongoDB portal at https://10gen-httpsupload.s3.amazonaws.com/upload_forms/6b355378-9cfe-4b04-a62f-84ccb64dd47b.html The uploaded file name is mongodb_upload_ |