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

Benchmark performance against APFS

    XMLWordPrintable

    Details

    • Type: Task
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Duplicate
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: Performance
    • Labels:
      None

      Description

      Original Summary

      MongoDB is so slow with write operations on OSX High Sierra

      Original Description

      Hello!

      There is an issue that deserve some research on MongoDB running on OSX High Sierra. I was using Mongo DB 3.0.2 running in OSX Sierra and after the an updated required by Apple, where it installs the new OSX High Sierra, the write operations became so slow.

      No configuration was changed, I'm opened an issue at stack overflow where I've put my config there, you can check it at https://stackoverflow.com/questions/46828828/mongodb-running-in-macos-high-sierra-is-with-write-operations-very-slow

      This matter deserves some research because this is a new Operating System brought by Apple and I think there we have to observe the Mongo's behaviour running on it.

      Some log information can be checked bellow:

      2017-10-19T17:41:39.688-0200 I CONTROL  [initandlisten] MongoDB starting : pid=17344 port=27017 dbpath=/usr/local/var/mongodb 64-bit host=Macbook-Pro-Rogerio-Carrasqueira.local
      2017-10-19T17:41:39.688-0200 I CONTROL  [initandlisten] db version v3.0.15
      2017-10-19T17:41:39.688-0200 I CONTROL  [initandlisten] git version: b8ff507269c382bc100fc52f75f48d54cd42ec3b
      2017-10-19T17:41:39.688-0200 I CONTROL  [initandlisten] build info: Darwin mci-osx1010-9.build.10gen.cc 14.0.0 Darwin Kernel Version 14.0.0: Fri Sep 19 00:26:44 PDT 2014; root:xnu-2782.1.97~2/RELEASE_X86_64 x86_64 BOOST_LIB_VERSION=1_49
      2017-10-19T17:41:39.688-0200 I CONTROL  [initandlisten] allocator: system
      2017-10-19T17:41:39.688-0200 I CONTROL  [initandlisten] options: { config: "/usr/local/etc/mongod.conf", net: { bindIp: "127.0.0.1" }, storage: { dbPath: "/usr/local/var/mongodb", engine: "wiredTiger" }, systemLog: { destination: "file", logAppend: true, path: "/usr/local/var/log/mongodb/mongo.log" } }
      2017-10-19T17:41:39.689-0200 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=4G,session_max=20000,eviction=(threads_max=4),statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
      2017-10-19T17:41:39.982-0200 I CONTROL  [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
      2017-10-19T17:41:39.982-0200 I CONTROL  [initandlisten] 
      2017-10-19T17:41:39.982-0200 I CONTROL  [initandlisten] 
      2017-10-19T17:41:39.982-0200 I CONTROL  [initandlisten] ** WARNING: soft rlimits too low. Number of files is 256, should be at least 1000
      2017-10-19T17:41:40.126-0200 I NETWORK  [initandlisten] waiting for connections on port 27017
      2017-10-19T17:42:27.502-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:53741 #1 (1 connection now open)
      2017-10-19T17:42:38.335-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { customer_id: 1, opt_out: 1 }, name: "customer_id_1_opt_out_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.341-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.342-0200 I COMMAND  [conn1] command mailerweb_test.$cmd command: createIndexes { createIndexes: "contact", indexes: [ { background: true, name: "customer_id_1_opt_out_1", key: { customer_id: 1, opt_out: 1 }, dropDups: true } ] } keyUpdates:0 writeConflicts:0 numYields:0 reslen:113 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1, W: 2 } }, Collection: { acquireCount: { W: 1 } } } 215ms
      2017-10-19T17:42:38.404-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { customer_id: 1, status: 1 }, name: "customer_id_1_status_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.404-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.468-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { customer_id: 1, campaigns.id: 1, last_updated: -1 }, name: "customer_id_1_campaigns.id_1_last_updated_-1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.468-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.541-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { name: 1 }, name: "name_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.541-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.609-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { email: 1 }, name: "email_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.610-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.676-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { tag_list: 1 }, name: "tag_list_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.677-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.744-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { customer_id: 1 }, name: "customer_id_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.745-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.801-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { date_created: 1 }, name: "date_created_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.802-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.859-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, key: { campaigns.id: 1 }, name: "campaigns.id_1", ns: "mailerweb_test.contact", background: true }
      2017-10-19T17:42:38.859-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:42:38.923-0200 I INDEX    [conn1] build index on: mailerweb_test.contact properties: { v: 1, unique: true, key: { customer_id: 1, email: 1 }, name: "customer_id_1_email_1", ns: "mailerweb_test.contact", background: true, sparse: false }
      2017-10-19T17:42:38.924-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:23.772-0200 I INDEX    [conn1] build index on: mailerweb_test.opt_out_list properties: { v: 1, key: { customer_id: 1 }, name: "customer_id_1", ns: "mailerweb_test.opt_out_list", background: true }
      2017-10-19T17:43:23.773-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:23.774-0200 I COMMAND  [conn1] command mailerweb_test.$cmd command: createIndexes { createIndexes: "opt_out_list", indexes: [ { background: true, name: "customer_id_1", key: { customer_id: 1 }, dropDups: true } ] } keyUpdates:0 writeConflicts:0 numYields:0 reslen:113 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1, W: 2 } }, Collection: { acquireCount: { W: 1 } } } 178ms
      2017-10-19T17:43:23.836-0200 I INDEX    [conn1] build index on: mailerweb_test.opt_out_list properties: { v: 1, key: { email: 1 }, name: "email_1", ns: "mailerweb_test.opt_out_list", background: true }
      2017-10-19T17:43:23.836-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:23.900-0200 I INDEX    [conn1] build index on: mailerweb_test.opt_out_list properties: { v: 1, key: { reason: 1 }, name: "reason_1", ns: "mailerweb_test.opt_out_list", background: true }
      2017-10-19T17:43:23.901-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:23.962-0200 I INDEX    [conn1] build index on: mailerweb_test.opt_out_list properties: { v: 1, key: { date_created: 1 }, name: "date_created_1", ns: "mailerweb_test.opt_out_list", background: true }
      2017-10-19T17:43:23.962-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:24.027-0200 I INDEX    [conn1] build index on: mailerweb_test.opt_out_list properties: { v: 1, key: { customer_id: 1, email: 1 }, name: "customer_id_1_email_1", ns: "mailerweb_test.opt_out_list", background: true }
      2017-10-19T17:43:24.027-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:24.089-0200 I INDEX    [conn1] build index on: mailerweb_test.opt_out_list properties: { v: 1, key: { customer_id: 1, reason: 1 }, name: "customer_id_1_reason_1", ns: "mailerweb_test.opt_out_list", background: true }
      2017-10-19T17:43:24.090-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:24.154-0200 I INDEX    [conn1] build index on: mailerweb_test.opt_out_list properties: { v: 1, unique: true, key: { email: 1, customer_id: 1 }, name: "email_1_customer_id_1", ns: "mailerweb_test.opt_out_list", background: true, sparse: false }
      2017-10-19T17:43:24.154-0200 I INDEX    [conn1] build index done.  scanned 0 total records. 0 secs
      2017-10-19T17:43:24.161-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:53877 #2 (2 connections now open)
      2017-10-19T17:43:33.178-0200 I NETWORK  [conn2] end connection 127.0.0.1:53877 (1 connection now open)
      2017-10-19T17:43:39.817-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54065 #3 (2 connections now open)
      2017-10-19T17:43:48.830-0200 I NETWORK  [conn3] end connection 127.0.0.1:54065 (1 connection now open)
      2017-10-19T17:43:49.267-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54130 #4 (2 connections now open)
      2017-10-19T17:43:58.139-0200 I NETWORK  [conn4] end connection 127.0.0.1:54130 (1 connection now open)
      2017-10-19T17:44:25.786-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54213 #5 (2 connections now open)
      2017-10-19T17:44:34.573-0200 I NETWORK  [conn5] end connection 127.0.0.1:54213 (1 connection now open)
      2017-10-19T17:44:45.638-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54247 #6 (2 connections now open)
      2017-10-19T17:44:45.689-0200 I NETWORK  [conn6] end connection 127.0.0.1:54247 (1 connection now open)
      2017-10-19T17:44:46.176-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54251 #7 (2 connections now open)
      2017-10-19T17:44:46.176-0200 I NETWORK  [conn7] end connection 127.0.0.1:54251 (1 connection now open)
      2017-10-19T17:44:46.180-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54252 #8 (2 connections now open)
      2017-10-19T17:44:46.182-0200 I NETWORK  [conn8] end connection 127.0.0.1:54252 (1 connection now open)
      2017-10-19T17:44:46.185-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54253 #9 (2 connections now open)
      2017-10-19T17:44:46.187-0200 I NETWORK  [conn9] end connection 127.0.0.1:54253 (1 connection now open)
      2017-10-19T17:44:46.195-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54254 #10 (2 connections now open)
      2017-10-19T17:44:46.198-0200 I NETWORK  [conn10] end connection 127.0.0.1:54254 (1 connection now open)
      2017-10-19T17:44:46.203-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54255 #11 (2 connections now open)
      2017-10-19T17:44:46.205-0200 I NETWORK  [conn11] end connection 127.0.0.1:54255 (1 connection now open)
      2017-10-19T17:44:46.209-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54256 #12 (2 connections now open)
      2017-10-19T17:44:46.210-0200 I NETWORK  [conn12] end connection 127.0.0.1:54256 (1 connection now open)
      2017-10-19T17:44:46.215-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54257 #13 (2 connections now open)
      2017-10-19T17:44:46.221-0200 I NETWORK  [conn13] end connection 127.0.0.1:54257 (1 connection now open)
      2017-10-19T17:44:46.225-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54258 #14 (2 connections now open)
      2017-10-19T17:44:46.229-0200 I NETWORK  [conn14] end connection 127.0.0.1:54258 (1 connection now open)
      2017-10-19T17:44:47.474-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54268 #15 (2 connections now open)
      2017-10-19T17:44:47.662-0200 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:54270 #16 (3 connections now open)
      2017-10-19T17:44:56.508-0200 I NETWORK  [conn16] end connection 127.0.0.1:54270 (2 connections now open)
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              cristopher.stauffer Cristopher Stauffer
              Reporter:
              rogerio.carrasqueira Rogerio Carrasqueira
              Participants:
              Votes:
              0 Vote for this issue
              Watchers:
              16 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: