[SERVER-17254] WT: drop collection while concurrent oplog tailing may greatly reduce throughput Created: 11/Feb/15  Updated: 19/Sep/15  Resolved: 24/Jun/15

Status: Closed
Project: Core Server
Component/s: WiredTiger
Affects Version/s: 3.0.0-rc8
Fix Version/s: 3.0.5, 3.1.5

Type: Bug Priority: Critical - P2
Reporter: Rui Zhang (Inactive) Assignee: Martin Bligh
Resolution: Done Votes: 0
Labels: 28qa, WTcc
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File hammer.test.linux.gz     PNG File locks.png     PNG File summary.png    
Issue Links:
Depends
Related
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Completed:
Sprint: Quint Iteration 5
Participants:

 Description   

Description:

Found out that a special sequence of event may reduce server throughput by 90% for around 10min. So far, the trigger seems drop a collection while there is concurrent oplog tailing going on.

Test setup

  • single node replica set with wiredTiger
  • use a special written tool to tail oplog with 32 or 64 thread (run from a separate server)
  • use bench run run simple insert into multi collection, step of the test
    • drop all collection
    • use benchRun do simple insert
  • check throughput with mongostat

Observation:

The throughput will drop from 70k to 600, and this will last for up to 10min (after stop tailing oplog)

MongoDB shell version: 3.0.0-rc8
connecting to: test
{ "name" : "wiredTiger" }
0: 79966.63852879952      <-- every test last 10 second
1: 73956.35971517103
2: 70263.89507592177
3: 76272.46177347556
4: 76179.7331941972
5: 76071.29258252526
6: 76504.322290524
7: 77133.12436735495
8: 76096.40869079733
9: 600.3870288152949        <--- the drop
10: 585.1938886069264      <-- stop tailing oplog
11: 587.1715686099094
 
.....
 
67: 569.518186223205
68: 550.9203010903097
69: 401.6865724762767
70: 74848.28307466969      <--- recover, drop last for 600sec
71: 76152.44327463405

  • this also happen with smaller thread number, much easier to repro with higher thread count (tailing oplog)
  • could not reproduce this with mmapv1
  • tested with RC8

perf topN

-  12.37%  mongod  mongod               [.] __rec_row_leaf_insert
   - __rec_row_leaf_insert 
   - __rec_row_leaf        
   - __wt_reconcile        
      - 99.30% __wt_cache_op 
         - 98.54% __wt_checkpoint 
            - 98.58% __wt_txn_checkpoint  
                 __session_checkpoint     
                 __ckpt_server    
                 start_thread
            + 1.42% __checkpoint_apply    
         + 1.46% __wt_txn_checkpoint      
      + 0.70% __evict_review 
-  10.84%  mongod  mongod               [.] __config_getraw.isra.
   - __config_getraw.isra.0
      - 54.82% __wt_config_getones
         - 63.83% __wt_schema_open_table  
              __wt_schema_get_table       
              __wt_schema_drop    
              __session_drop 
              mongo::WiredTigerKVEngine::dropAllQueued()
              mongo::WiredTigerSessionCache::releaseSession(mongo::WiredTigerSession*)
              mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
            + mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
         - 27.61% __wt_schema_open_colgroups 
              __wt_schema_open_table      
              __wt_schema_get_table       
              __wt_schema_drop    
              __session_drop 
              mongo::WiredTigerKVEngine::dropAllQueued()
              mongo::WiredTigerSessionCache::releaseSession(mongo::WiredTigerSession*)
              mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
            + mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
         + 8.47% __wt_config_gets_def     
      - 44.87% __wt_config_get    
         - 98.94% __wt_config_gets
            - 71.56% __wt_cursor_init     
                 __wt_curfile_create      
                 __wt_metadata_cursor     
                 __wt_metadata_update     
                 __wt_meta_track_off      
                 __wt_schema_drop 
                 __session_drop   
                 mongo::WiredTigerKVEngine::dropAllQueued()
                 mongo::WiredTigerSessionCache::releaseSession(mongo::WiredTigerSession*)
                 mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
               + mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
            - 15.69% __wt_curfile_create  
                 __wt_metadata_cursor     
                 __wt_metadata_update     
                 __wt_meta_track_off      
                 __wt_schema_drop 
                 __session_drop   
                 mongo::WiredTigerKVEngine::dropAllQueued()
                 mongo::WiredTigerSessionCache::releaseSession(mongo::WiredTigerSession*)
                 mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
               + mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit()
            + 12.62% __wt_schema_drop     
         + 1.06% __wt_config_collapse     

Setup

  • rc8

            "version" : "3.0.0-rc8",
            "gitVersion" : "9d0714cdcffadb203ff68730acedbc40875403da",
    

  • parameters

                    "--dbpath=/data/ssd-sdc/dbs-wt",
                    "--logpath=/data/ssd-sdc/logs/mongod.log",
                    "--fork",
                    "--replSet",
                    "r",
                    "--storageEngine=wiredTiger"
    



 Comments   
Comment by Githook User [ 20/Jul/15 ]

Author:

{u'username': u'martinbligh', u'name': u'Martin Bligh', u'email': u'mbligh@mongodb.com'}

Message: SERVER-17254: Throttle retry of failed drop attempts
Branch: v3.0
https://github.com/mongodb/mongo/commit/750bc4a89e8f9a40cd641d03cbd8e05cec74933e

Comment by Githook User [ 24/Jun/15 ]

Author:

{u'username': u'martinbligh', u'name': u'Martin Bligh', u'email': u'mbligh@mongodb.com'}

Message: SERVER-17254 Throttle retry of failed drop attempts
Branch: master
https://github.com/mongodb/mongo/commit/ea31b15b2bf6499cfadec4581fed668e4ef14f16

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