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

RC9/wiredTiger batched insert performance regression

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical - P2
    • Resolution: Fixed
    • Affects Version/s: 3.0.0-rc9
    • Fix Version/s: 3.0.0-rc10, 3.1.0
    • Component/s: WiredTiger
    • Labels:
    • Backwards Compatibility:
      Fully Compatible
    • Operating System:
      ALL
    • Backport Completed:

      Description

      run latest rc9, which show a clear performance regression with batched insert

      preliminary results

      SHA Comment Insert rate after 60sec
      e6577bc37a2edba81b99146934cf7bad00c6e1b2 rc9 46,505.43
      ea5f871b550c1c3a8a5f0cd749fb47570557a067 rc9 previous 96,237.72
      9d0714cdcffadb203ff68730acedbc40875403da rc8 98,139.40
      • rc9 tested is the "legacy" build from download page
      • rc9 previous is the "old" and reverted rc9 build
      • test is sysbench insert traffic, will try to come up with a simpler tool for repro
      1. batch_insert.js
        0.7 kB
        Dan Pasette

        Activity

        Hide
        rui.zhang Rui Zhang added a comment - - edited

        raw capture for server build information and cmd line option as well as sysbench output
        for sysbench results, please check the cumulated number, as show as "cum ips=XXXX.XX"

         
         
         
        rc9.legacy build
        -----------------
         
        >>> sysbench output as 60 seconds mark
        Thread[Thread-2,5,main]2,794,000 inserts : 60 seconds : cum ips=46,505.43 : int ips=70,622.32
         
         
        connecting to: test
        {
                "version" : "3.0.0-rc9",
                "gitVersion" : "e6577bc37a2edba81b99146934cf7bad00c6e1b2",
                "OpenSSLVersion" : "",
                "sysInfo" : "Linux build3.nj1.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_49",
                "loaderFlags" : "-fPIC -pthread -Wl,-z,now -rdynamic",
                "compilerFlags" : "-Wnon-virtual-dtor -Woverloaded-virtual -std=c++11 -fPIC -fno-strict-aliasing -ggdb -pthread -Wall -Wsign-compare -Wno-unknown-pragmas -Winvalid-pch -pipe -Werror -O3 -Wno-unused-local-typedefs -Wno-unused-function -Wno-deprecated-declarations -Wno-unused-but-set-variable -Wno-missing-braces -fno-builtin-memcmp -std=c99",
                "allocator" : "tcmalloc",
                "versionArray" : [
                        3,
                        0,
                        0,
                        -1
                ],
                "javascriptEngine" : "V8",
                "bits" : 64,
                "debug" : false,
                "maxBsonObjectSize" : 16777216,
                "ok" : 1
        }
        {
                "argv" : [
                        "/home/rzhang/wt/bin/rc9.legacy/mongod",
                        "--dbpath=/data/ssd-sdc/dbs-wt",
                        "--storageEngine=wiredTiger",
                        "--logpath=/data/ssd-sdc/logs/mongod.log",
                        "--fork"
                ],
                "parsed" : {
                        "processManagement" : {
                                "fork" : true
                        },
                        "storage" : {
                                "dbPath" : "/data/ssd-sdc/dbs-wt",
                                "engine" : "wiredTiger"
                        },
                        "systemLog" : {
                                "destination" : "file",
                                "path" : "/data/ssd-sdc/logs/mongod.log"
                        }
                },
                "ok" : 1
        }
         
         
         
         
         
        rc9.old
        -------
         
        >>> sysbench output as 60 seconds mark
        Thread[Thread-2,5,main]5,781,000 inserts : 60 seconds : cum ips=96,237.72 : int ips=97,524.46
         
        connecting to: test
        {
                "version" : "3.0.0-rc9",
                "gitVersion" : "ea5f871b550c1c3a8a5f0cd749fb47570557a067",
                "OpenSSLVersion" : "",
                "sysInfo" : "Linux build12.nj1.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_49",
                "loaderFlags" : "-fPIC -pthread -Wl,-z,now -rdynamic",
                "compilerFlags" : "-Wnon-virtual-dtor -Woverloaded-virtual -std=c++11 -fPIC -fno-strict-aliasing -ggdb -pthread -Wall -Wsign-compare -Wno-unknown-pragmas -Winvalid-pch -pipe -Werror -O3 -Wno-unused-local-typedefs -Wno-unused-function -Wno-deprecated-declarations -Wno-unused-but-set-variable -Wno-missing-braces -fno-builtin-memcmp -std=c99",
                "allocator" : "tcmalloc",
                "versionArray" : [
                        3,
                        0,
                        0,
                        -1
                ],
                "javascriptEngine" : "V8",
                "bits" : 64,
                "debug" : false,
                "maxBsonObjectSize" : 16777216,
                "ok" : 1
        }
        {
                "argv" : [
                        "/home/rzhang/wt/bin/rc9.old/mongod",
                        "--dbpath=/data/ssd-sdc/dbs-wt",
                        "--storageEngine=wiredTiger",
                        "--logpath=/data/ssd-sdc/logs/mongod.log",
                        "--fork"
                ],
                "parsed" : {
                        "processManagement" : {
                                "fork" : true
                        },
                        "storage" : {
                                "dbPath" : "/data/ssd-sdc/dbs-wt",
                                "engine" : "wiredTiger"
                        },
                        "systemLog" : {
                                "destination" : "file",
                                "path" : "/data/ssd-sdc/logs/mongod.log"
                        }
                },
                "ok" : 1
        }
         
         
        rc8:
        ----
         
        >>> sysbench output as 60 seconds mark
        Thread[Thread-2,5,main]5,897,000 inserts : 60 seconds : cum ips=98,139.40 : int ips=90,109.89
         
         
        connecting to: test
        {
                "version" : "3.0.0-rc8",
                "gitVersion" : "9d0714cdcffadb203ff68730acedbc40875403da",
                "OpenSSLVersion" : "",
                "sysInfo" : "Linux build15.nj1.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_49",
                "loaderFlags" : "-fPIC -pthread -Wl,-z,now -rdynamic",
                "compilerFlags" : "-Wnon-virtual-dtor -Woverloaded-virtual -std=c++11 -fPIC -fno-strict-aliasing -ggdb -pthread -Wall -Wsign-compare -Wno-unknown-pragmas -Winvalid-pch -pipe -Werror -O3 -Wno-unused-local-typedefs -Wno-unused-function -Wno-deprecated-declarations -Wno-unused-but-set-variable -Wno-missing-braces -fno-builtin-memcmp -std=c99",
                "allocator" : "tcmalloc",
                "versionArray" : [
                        3,
                        0,
                        0,
                        -2
                ],
                "javascriptEngine" : "V8",
                "bits" : 64,
                "debug" : false,
                "maxBsonObjectSize" : 16777216,
                "ok" : 1
        }
        {
                "argv" : [
                        "/home/rzhang/wt/bin/rc8/mongod",
                        "--dbpath=/data/ssd-sdc/dbs-wt",
                        "--storageEngine=wiredTiger",
                        "--logpath=/data/ssd-sdc/logs/mongod.log",
                        "--fork"
                ],
                "parsed" : {
                        "processManagement" : {
                                "fork" : true
                        },
                        "storage" : {
                                "dbPath" : "/data/ssd-sdc/dbs-wt",
                                "engine" : "wiredTiger"
                        },
                        "systemLog" : {
                                "destination" : "file",
                                "path" : "/data/ssd-sdc/logs/mongod.log"
                        }
                },
                "ok" : 1
        }
         

        Show
        rui.zhang Rui Zhang added a comment - - edited raw capture for server build information and cmd line option as well as sysbench output for sysbench results, please check the cumulated number, as show as "cum ips=XXXX.XX"       rc9.legacy build -----------------   >>> sysbench output as 60 seconds mark Thread[Thread-2,5,main]2,794,000 inserts : 60 seconds : cum ips=46,505.43 : int ips=70,622.32     connecting to: test { "version" : "3.0.0-rc9", "gitVersion" : "e6577bc37a2edba81b99146934cf7bad00c6e1b2", "OpenSSLVersion" : "", "sysInfo" : "Linux build3.nj1.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_49", "loaderFlags" : "-fPIC -pthread -Wl,-z,now -rdynamic", "compilerFlags" : "-Wnon-virtual-dtor -Woverloaded-virtual -std=c++11 -fPIC -fno-strict-aliasing -ggdb -pthread -Wall -Wsign-compare -Wno-unknown-pragmas -Winvalid-pch -pipe -Werror -O3 -Wno-unused-local-typedefs -Wno-unused-function -Wno-deprecated-declarations -Wno-unused-but-set-variable -Wno-missing-braces -fno-builtin-memcmp -std=c99", "allocator" : "tcmalloc", "versionArray" : [ 3, 0, 0, -1 ], "javascriptEngine" : "V8", "bits" : 64, "debug" : false, "maxBsonObjectSize" : 16777216, "ok" : 1 } { "argv" : [ "/home/rzhang/wt/bin/rc9.legacy/mongod", "--dbpath=/data/ssd-sdc/dbs-wt", "--storageEngine=wiredTiger", "--logpath=/data/ssd-sdc/logs/mongod.log", "--fork" ], "parsed" : { "processManagement" : { "fork" : true }, "storage" : { "dbPath" : "/data/ssd-sdc/dbs-wt", "engine" : "wiredTiger" }, "systemLog" : { "destination" : "file", "path" : "/data/ssd-sdc/logs/mongod.log" } }, "ok" : 1 }           rc9.old -------   >>> sysbench output as 60 seconds mark Thread[Thread-2,5,main]5,781,000 inserts : 60 seconds : cum ips=96,237.72 : int ips=97,524.46   connecting to: test { "version" : "3.0.0-rc9", "gitVersion" : "ea5f871b550c1c3a8a5f0cd749fb47570557a067", "OpenSSLVersion" : "", "sysInfo" : "Linux build12.nj1.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_49", "loaderFlags" : "-fPIC -pthread -Wl,-z,now -rdynamic", "compilerFlags" : "-Wnon-virtual-dtor -Woverloaded-virtual -std=c++11 -fPIC -fno-strict-aliasing -ggdb -pthread -Wall -Wsign-compare -Wno-unknown-pragmas -Winvalid-pch -pipe -Werror -O3 -Wno-unused-local-typedefs -Wno-unused-function -Wno-deprecated-declarations -Wno-unused-but-set-variable -Wno-missing-braces -fno-builtin-memcmp -std=c99", "allocator" : "tcmalloc", "versionArray" : [ 3, 0, 0, -1 ], "javascriptEngine" : "V8", "bits" : 64, "debug" : false, "maxBsonObjectSize" : 16777216, "ok" : 1 } { "argv" : [ "/home/rzhang/wt/bin/rc9.old/mongod", "--dbpath=/data/ssd-sdc/dbs-wt", "--storageEngine=wiredTiger", "--logpath=/data/ssd-sdc/logs/mongod.log", "--fork" ], "parsed" : { "processManagement" : { "fork" : true }, "storage" : { "dbPath" : "/data/ssd-sdc/dbs-wt", "engine" : "wiredTiger" }, "systemLog" : { "destination" : "file", "path" : "/data/ssd-sdc/logs/mongod.log" } }, "ok" : 1 }     rc8: ----   >>> sysbench output as 60 seconds mark Thread[Thread-2,5,main]5,897,000 inserts : 60 seconds : cum ips=98,139.40 : int ips=90,109.89     connecting to: test { "version" : "3.0.0-rc8", "gitVersion" : "9d0714cdcffadb203ff68730acedbc40875403da", "OpenSSLVersion" : "", "sysInfo" : "Linux build15.nj1.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_49", "loaderFlags" : "-fPIC -pthread -Wl,-z,now -rdynamic", "compilerFlags" : "-Wnon-virtual-dtor -Woverloaded-virtual -std=c++11 -fPIC -fno-strict-aliasing -ggdb -pthread -Wall -Wsign-compare -Wno-unknown-pragmas -Winvalid-pch -pipe -Werror -O3 -Wno-unused-local-typedefs -Wno-unused-function -Wno-deprecated-declarations -Wno-unused-but-set-variable -Wno-missing-braces -fno-builtin-memcmp -std=c99", "allocator" : "tcmalloc", "versionArray" : [ 3, 0, 0, -2 ], "javascriptEngine" : "V8", "bits" : 64, "debug" : false, "maxBsonObjectSize" : 16777216, "ok" : 1 } { "argv" : [ "/home/rzhang/wt/bin/rc8/mongod", "--dbpath=/data/ssd-sdc/dbs-wt", "--storageEngine=wiredTiger", "--logpath=/data/ssd-sdc/logs/mongod.log", "--fork" ], "parsed" : { "processManagement" : { "fork" : true }, "storage" : { "dbPath" : "/data/ssd-sdc/dbs-wt", "engine" : "wiredTiger" }, "systemLog" : { "destination" : "file", "path" : "/data/ssd-sdc/logs/mongod.log" } }, "ok" : 1 }  
        Hide
        pasette Dan Pasette added a comment -

        I'm seeing ~2x perf drop in batch inserts b/w rc8 and rc9 with a simple batch insert js test.

        • single thread
        • batch insert of 100 docs
        • all default mongod settings, no oplog

        Attached repro. It's more complicated than it has to be, but allows you to easily adjust run time, batch size, doc size/shape, num worker threads.

        Show
        pasette Dan Pasette added a comment - I'm seeing ~2x perf drop in batch inserts b/w rc8 and rc9 with a simple batch insert js test. single thread batch insert of 100 docs all default mongod settings, no oplog Attached repro. It's more complicated than it has to be, but allows you to easily adjust run time, batch size, doc size/shape, num worker threads.

          People

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

            Dates

            • Created:
              Updated:
              Resolved: