Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-17254

WT: drop collection while concurrent oplog tailing may greatly reduce throughput

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical - P2
    • Resolution: Fixed
    • Affects Version/s: 3.0.0-rc8
    • Fix Version/s: 3.0.5, 3.1.5
    • Component/s: WiredTiger
    • Labels:
    • Backwards Compatibility:
      Fully Compatible
    • Operating System:
      ALL
    • Backport Completed:
    • Sprint:
      Quint Iteration 5

      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"
        

        Attachments

        1. hammer.test.linux.gz
          1.66 MB
        2. locks.png
          locks.png
          130 kB
        3. summary.png
          summary.png
          98 kB

          Activity

            People

            • Votes:
              0 Vote for this issue
              Watchers:
              15 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: