Loading...

XML

Word

Printable

JSON

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

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)

is related to

WT-3724 Log an error if flushing with F_FULLSYNC fails

Closed

Assignee:: Cristopher Stauffer

Reporter:: Rogerio Carrasqueira

Participants:: Cristopher Stauffer, Eric Milkie, Kelsey Schubert, Maxim Skripnik, Rogerio Carrasqueira

Votes:: 0 Vote for this issue

Watchers:: 16 Start watching this issue

Created:: Oct 19 2017 08:08:59 PM UTC

Updated:: Apr 02 2018 10:00:41 PM UTC

Resolved:: Mar 07 2018 02:38:53 PM UTC

Details

Description

Original Summary

Original Description

Attachments

Issue Links

Activity

People

Dates