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

mongo startup by parameter --syslog: mongod 100% cpu usage under big data insert

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 3.4.2
    • Component/s: Logging
    • Labels:
      None
    • ALL
    • Hide

      1. MongoDB server version: 3.4.2

      2. startup mongo with parameter --syslog

          /usr/local/mongodb/bin/mongod --fork --dbpath=/data/db --syslog --port=27017 --bind_ip=127.0.0.1,136.227.20.70

      3. top -H -p

      PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
      29078 root 20 0 6586752 5.919g 6920 S 99.7 38.2 0:48.07 mongod
      30297 root 20 0 6586752 5.919g 6920 S 0.3 38.2 0:00.82 mongod
      30270 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.34 mongod
      30271 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30272 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.02 mongod
      30274 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.13 mongod
      30275 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.04 mongod
      30276 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.33 mongod
      30277 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.05 mongod
      30278 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30279 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.49 mongod
      30280 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.96 mongod
      30281 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30282 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:02.26 mongod
      30283 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.06 mongod
      30284 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30285 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.05 mongod
      30286 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30287 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.07 mongod
      30291 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.20 mongod
      30295 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.01 mongod
      30301 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.01 mongod
      30304 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.08 mongod
      30461 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod
      30494 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.95 mongod
      30879 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.23 mongod
      31477 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod
      31478 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.03 mongod
      31572 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod
      31917 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod

       

      4. thread of high cpu usage with common output by "pstack 29078"

      Thread 1 (process 29078):
      #0 0x00007f0e6bd2585d in write () from /lib64/libc.so.6
      #1 0x00007f0e6bcb1fb3 in _IO_new_file_write () from /lib64/libc.so.6
      #2 0x00007f0e6bcb274f in _GI_IO_file_xsputn () from /lib64/libc.so.6
      #3 0x00007f0e6bc8469d in vfprintf () from /lib64/libc.so.6
      #4 0x00007f0e6bcb0028 in vdprintf () from /lib64/libc.so.6
      #5 0x00007f0e6bc8db17 in dprintf () from /lib64/libc.so.6
      #6 0x00007f0e6bd2e47e in __vsyslog_chk () from /lib64/libc.so.6
      #7 0x00007f0e6bd2e622 in __syslog_chk () from /lib64/libc.so.6
      #8 0x000055bf16b15e9c in mongo::logger::SyslogAppender<mongo::logger::MessageEventEphemeral>::append(mongo::logger::MessageEventEphemeral const&) ()
      #9 0x000055bf171abca4 in mongo::logger::LogDomain<mongo::logger::MessageEventEphemeral>::append(mongo::logger::MessageEventEphemeral const&) ()
      #10 0x000055bf171aa849 in mongo::logger::LogstreamBuilder::~LogstreamBuilder() ()
      #11 0x000055bf16b1a1a1 in mongo::assembleResponse(mongo::OperationContext*, mongo::Message&, mongo::DbResponse&, mongo::HostAndPort const&) ()
      #12 0x000055bf1670a54d in mongo::ServiceEntryPointMongod::_sessionLoop(std::shared_ptr<mongo::transport::Session> const&) ()
      #13 0x000055bf1670ae8d in std::_Function_handler<void (std::shared_ptr<mongo::transport::Session> const&), mongo::ServiceEntryPointMongod::startSession(std::shared_ptr<mongo::transport::Session>)::{lambda(std::shared_ptr<mongo::transport::Session> const&)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<mongo::transport::Session> const&) ()
      #14 0x000055bf17379292 in mongo::(anonymous namespace)::runFunc(void*) ()
      #15 0x00007f0e6c006e25 in start_thread () from /lib64/libpthread.so.0
      #16 0x00007f0e6bd3434d in clone () from /lib64/libc.so.6

       

      5. strace -T -tt -e trace=all -s 10000 -fp 29078

      [pid 29078] 13:49:53.945831 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000017>
      [pid 29078] 13:49:53.945899 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56277, {1536126593, 955806828}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009955>
      [pid 29078] 13:49:53.955895 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000013>
      [pid 29078] 13:49:53.955940 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56279, {1536126593, 965887819}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009992>
      [pid 29078] 13:49:53.965976 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000015>
      [pid 29078] 13:49:53.966025 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56281, {1536126593, 975969073}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009991>
      [pid 29078] 13:49:53.976056 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000013>
      [pid 29078] 13:49:53.976101 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56283, {1536126593, 986048750}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009996>
      [pid 29078] 13:49:53.986135 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000018>
      [pid 29078] 13:49:53.986208 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56285, {1536126593, 996128238}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009960>
      [pid 29078] 13:49:53.996214 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000021>
      [pid 29078] 13:49:53.996263 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56287, {1536126594, 6205991}, ffffffff <unfinished ...>
      [pid 29089] 13:49:54.000072 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.997855>
      [pid 29089] 13:49:54.000103 futex(0x55e8587277e8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000013>
      [pid 29089] 13:49:54.000188 open("/proc/29076/stat", O_RDONLY) = 61 <0.000024>
      [pid 29089] 13:49:54.000258 fstat(61, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 <0.000013>
      [pid 29089] 13:49:54.000309 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f46eaba3000 <0.000020>
      [pid 29089] 13:49:54.000361 read(61, "29076 (mongod) S 1 29075 29075 0 -1 1077944384 218410 0 33 0 794 25000 0 0 20 0 27 0 303434491 2047733760 423496 18446744073709551615 94456257441792 94456302719232 140724326755424 140724326748608 139942541384005 0 8405507 4097 3308 18446744073709551615 0 0 17 5 0 0 43 0 0 94456302726464 94456304527088 94456334974976 140724326758539 140724326758636 140724326758636 140724326760410 0\n", 1024) = 384 <0.000032>
      [pid 29089] 13:49:54.000437 close(61) = 0 <0.000052>
      [pid 29089] 13:49:54.000538 munmap(0x7f46eaba3000, 4096) = 0 <0.000027>

       

      6. big size data insert mongodb: mongostat

      insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn time
      2 *0 *0 *0 0 2|0 1.2% 76.7% 0 6.30G 5.96G 0|0 0|0 2.66m 54.3k 10 Sep 5 14:37:09.504
      *0 *0 *0 *0 0 2|0 1.2% 76.7% 0 6.30G 5.96G 0|0 0|0 2.68m 54.2k 10 Sep 5 14:37:10.504
      4 *0 *0 *0 0 3|0 1.3% 76.8% 0 6.30G 5.96G 0|0 0|0 5.33m 54.4k 10 Sep 5 14:37:11.503
      1 *0 *0 *0 0 4|0 1.3% 76.8% 0 6.30G 5.96G 0|0 0|0 3.28m 54.6k 10 Sep 5 14:37:12.504
      4 *0 *0 *0 0 3|0 1.4% 76.9% 0 6.30G 5.96G 0|0 0|0 5.33m 54.4k 10 Sep 5 14:37:13.504
      *0 *0 *0 *0 0 2|0 1.4% 76.9% 0 6.30G 5.96G 0|0 0|0 2.63m 54.2k 10 Sep 5 14:37:14.505
      3 *0 *0 *0 0 5|0 1.5% 77.0% 0 6.30G 5.96G 0|0 0|0 2.71m 54.6k 10 Sep 5 14:37:15.504
      2 *0 *0 *0 0 3|0 1.5% 77.0% 0 6.30G 5.96G 0|0 0|0 5.35m 54.3k 10 Sep 5 14:37:16.503
      2 *0 *0 *0 0 7|0 1.6% 77.1% 0 6.30G 5.96G 0|0 0|0 2.66m 56.9k 10 Sep 5 14:37:17.504
      2 *0 *0 *0 0 3|0 1.6% 77.2% 0 6.30G 5.96G 0|0 0|0 5.35m 54.3k 10 Sep 5 14:37:18.504
      insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn time
      3 *0 *0 *0 0 4|0 1.7% 77.2% 0 6.30G 5.96G 0|0 0|0 2.69m 54.4k 10 Sep 5 14:37:19.504
      *0 *0 *0 *0 0 2|0 1.8% 77.2% 0 6.30G 5.96G 0|0 0|0 2.67m 54.2k 10 Sep 5 14:37:20.504
      3 *0 *0 *0 0 3|0 1.8% 77.3% 0 6.30G 5.96G 0|0 0|0 5.35m 54.5k 10 Sep 5 14:37:21.504
      2 *0 1 *0 0 5|0 1.9% 77.3% 0 6.30G 5.96G 0|0 0|0 3.26m 54.6k 10 Sep 5 14:37:22.504
      3 *0 *0 *0 0 2|0 1.9% 77.4% 0 6.30G 5.96G 0|0 0|0 5.32m 54.3k 10 Sep 5 14:37:23.505
      1 *0 *0 *0 0 3|0 2.0% 77.5% 0 6.30G 5.96G 0|0 0|0 2.71m 54.3k 10 Sep 5 14:37:24.503
      2 *0 *0 *0 0 3|0 2.0% 77.5% 0 6.30G 5.96G 0|0 0|0 2.63m 54.5k 10 Sep 5 14:37:25.504
      2 *0 *0 *0 0 4|0 2.1% 77.6% 0 6.30G 5.96G 0|0 0|0 5.33m 54.5k 10 Sep 5 14:37:26.504
      2 *0 *0 *0 0 2|0 2.1% 77.6% 0 6.30G 5.96G 0|0 0|0 2.69m 54.2k 10 Sep 5 14:37:27.505
      2 *0 *0 *0 0 3|0 2.2% 77.7% 0 6.30G 5.96G 0|0 0|0 5.34m 54.3k 10 Sep 5 14:37:28.504
      insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn time
      3 *0 *0 *0 0 3|0 2.2% 77.7% 0 6.30G 5.96G 0|0 0|0 2.67m 54.3k 10 Sep 5 14:37:29.503
      1 *0 *0 *0 0 3|0 2.3% 77.8% 0 6.30G 5.96G 0|0 0|0 5.35m 54.3k 10 Sep 5 14:37:30.503
      2 *0 *0 *0 0 2|0 2.3% 77.8% 0 6.30G 5.96G 0|0 0|0 2.66m 53.8k 10 Sep 5 14:37:31.512
      2 *0 1 *0 0 9|0 2.4% 77.9% 0 6.30G 5.96G 0|0 0|0 3.31m 57.6k 10 Sep 5 14:37:32.503
      4 *0 *0 *0 0 4|0 2.4% 78.0% 0 6.30G 5.96G 0|0 0|0 5.36m 54.6k 10 Sep 5 14:37:33.503
      *0 *0 *0 *0 0 3|0 2.5% 78.0% 0 6.30G 5.96G 0|0 0|0 2.64m 54.2k 10 Sep 5 14:37:34.504
      3 *0 *0 *0 0 3|0 2.5% 78.1% 0 6.30G 5.96G 0|0 0|0 5.32m 54.4k 10 Sep 5 14:37:35.506
      1 *0 *0 *0 0 3|0 2.6% 78.1% 0 6.30G 5.96G 0|0 0|0 2.71m 54.3k 10 Sep 5 14:37:36.504
      3 *0 *0 *0 0 3|0 2.7% 78.1% 0 6.30G 5.96G 0|0 0|0 2.63m 54.3k 10 Sep 5 14:37:37.503
      1 *0 *0 *0 0 2|0 2.7% 78.2% 0 6.30G 5.96G 0|0 0|0 5.33m 54.3k 10 Sep 5 14:37:38.504

      Show
      1. MongoDB server version: 3.4.2 2. startup mongo with parameter --syslog     /usr/local/mongodb/bin/mongod --fork --dbpath=/data/db --syslog --port=27017 --bind_ip=127.0.0.1,136.227.20.70 3. top -H -p PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 29078 root 20 0 6586752 5.919g 6920 S 99.7 38.2 0:48.07 mongod 30297 root 20 0 6586752 5.919g 6920 S 0.3 38.2 0:00.82 mongod 30270 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.34 mongod 30271 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod 30272 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.02 mongod 30274 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.13 mongod 30275 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.04 mongod 30276 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.33 mongod 30277 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.05 mongod 30278 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod 30279 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.49 mongod 30280 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.96 mongod 30281 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod 30282 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:02.26 mongod 30283 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.06 mongod 30284 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod 30285 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.05 mongod 30286 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod 30287 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.07 mongod 30291 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.20 mongod 30295 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.01 mongod 30301 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.01 mongod 30304 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.08 mongod 30461 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod 30494 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.95 mongod 30879 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.23 mongod 31477 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod 31478 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.03 mongod 31572 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod 31917 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod   4. thread of high cpu usage with common output by "pstack 29078" Thread 1 (process 29078): #0 0x00007f0e6bd2585d in write () from /lib64/libc.so.6 #1 0x00007f0e6bcb1fb3 in _IO_new_file_write () from /lib64/libc.so.6 #2 0x00007f0e6bcb274f in _ GI _IO_file_xsputn () from /lib64/libc.so.6 #3 0x00007f0e6bc8469d in vfprintf () from /lib64/libc.so.6 #4 0x00007f0e6bcb0028 in vdprintf () from /lib64/libc.so.6 #5 0x00007f0e6bc8db17 in dprintf () from /lib64/libc.so.6 #6 0x00007f0e6bd2e47e in __vsyslog_chk () from /lib64/libc.so.6 #7 0x00007f0e6bd2e622 in __syslog_chk () from /lib64/libc.so.6 #8 0x000055bf16b15e9c in mongo::logger::SyslogAppender<mongo::logger::MessageEventEphemeral>::append(mongo::logger::MessageEventEphemeral const&) () #9 0x000055bf171abca4 in mongo::logger::LogDomain<mongo::logger::MessageEventEphemeral>::append(mongo::logger::MessageEventEphemeral const&) () #10 0x000055bf171aa849 in mongo::logger::LogstreamBuilder::~LogstreamBuilder() () #11 0x000055bf16b1a1a1 in mongo::assembleResponse(mongo::OperationContext*, mongo::Message&, mongo::DbResponse&, mongo::HostAndPort const&) () #12 0x000055bf1670a54d in mongo::ServiceEntryPointMongod::_sessionLoop(std::shared_ptr<mongo::transport::Session> const&) () #13 0x000055bf1670ae8d in std::_Function_handler<void (std::shared_ptr<mongo::transport::Session> const&), mongo::ServiceEntryPointMongod::startSession(std::shared_ptr<mongo::transport::Session>)::{lambda(std::shared_ptr<mongo::transport::Session> const&)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<mongo::transport::Session> const&) () #14 0x000055bf17379292 in mongo::(anonymous namespace)::runFunc(void*) () #15 0x00007f0e6c006e25 in start_thread () from /lib64/libpthread.so.0 #16 0x00007f0e6bd3434d in clone () from /lib64/libc.so.6   5. strace -T -tt -e trace=all -s 10000 -fp 29078 [pid 29078] 13:49:53.945831 futex (0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000017> [pid 29078] 13:49:53.945899 futex (0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56277, {1536126593, 955806828}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009955> [pid 29078] 13:49:53.955895 futex (0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000013> [pid 29078] 13:49:53.955940 futex (0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56279, {1536126593, 965887819}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009992> [pid 29078] 13:49:53.965976 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000015> [pid 29078] 13:49:53.966025 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56281, {1536126593, 975969073}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009991> [pid 29078] 13:49:53.976056 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000013> [pid 29078] 13:49:53.976101 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56283, {1536126593, 986048750}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009996> [pid 29078] 13:49:53.986135 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000018> [pid 29078] 13:49:53.986208 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56285, {1536126593, 996128238}, ffffffff) = -1 ETIMEDOUT (Connection timed out) <0.009960> [pid 29078] 13:49:53.996214 futex(0x55e854e411a8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000021> [pid 29078] 13:49:53.996263 futex(0x55e854e411d4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 56287, {1536126594, 6205991}, ffffffff <unfinished ...> [pid 29089] 13:49:54.000072 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.997855> [pid 29089] 13:49:54.000103 futex(0x55e8587277e8, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000013> [pid 29089] 13:49:54.000188 open("/proc/29076/stat", O_RDONLY) = 61 <0.000024> [pid 29089] 13:49:54.000258 fstat(61, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 <0.000013> [pid 29089] 13:49:54.000309 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f46eaba3000 <0.000020> [pid 29089] 13:49:54.000361 read(61, "29076 (mongod) S 1 29075 29075 0 -1 1077944384 218410 0 33 0 794 25000 0 0 20 0 27 0 303434491 2047733760 423496 18446744073709551615 94456257441792 94456302719232 140724326755424 140724326748608 139942541384005 0 8405507 4097 3308 18446744073709551615 0 0 17 5 0 0 43 0 0 94456302726464 94456304527088 94456334974976 140724326758539 140724326758636 140724326758636 140724326760410 0\n", 1024) = 384 <0.000032> [pid 29089] 13:49:54.000437 close(61) = 0 <0.000052> [pid 29089] 13:49:54.000538 munmap(0x7f46eaba3000, 4096) = 0 <0.000027>   6. big size data insert mongodb: mongostat insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn time 2 *0 *0 *0 0 2|0 1.2% 76.7% 0 6.30G 5.96G 0|0 0|0 2.66m 54.3k 10 Sep 5 14:37:09.504 *0 *0 *0 *0 0 2|0 1.2% 76.7% 0 6.30G 5.96G 0|0 0|0 2.68m 54.2k 10 Sep 5 14:37:10.504 4 *0 *0 *0 0 3|0 1.3% 76.8% 0 6.30G 5.96G 0|0 0|0 5.33m 54.4k 10 Sep 5 14:37:11.503 1 *0 *0 *0 0 4|0 1.3% 76.8% 0 6.30G 5.96G 0|0 0|0 3.28m 54.6k 10 Sep 5 14:37:12.504 4 *0 *0 *0 0 3|0 1.4% 76.9% 0 6.30G 5.96G 0|0 0|0 5.33m 54.4k 10 Sep 5 14:37:13.504 *0 *0 *0 *0 0 2|0 1.4% 76.9% 0 6.30G 5.96G 0|0 0|0 2.63m 54.2k 10 Sep 5 14:37:14.505 3 *0 *0 *0 0 5|0 1.5% 77.0% 0 6.30G 5.96G 0|0 0|0 2.71m 54.6k 10 Sep 5 14:37:15.504 2 *0 *0 *0 0 3|0 1.5% 77.0% 0 6.30G 5.96G 0|0 0|0 5.35m 54.3k 10 Sep 5 14:37:16.503 2 *0 *0 *0 0 7|0 1.6% 77.1% 0 6.30G 5.96G 0|0 0|0 2.66m 56.9k 10 Sep 5 14:37:17.504 2 *0 *0 *0 0 3|0 1.6% 77.2% 0 6.30G 5.96G 0|0 0|0 5.35m 54.3k 10 Sep 5 14:37:18.504 insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn time 3 *0 *0 *0 0 4|0 1.7% 77.2% 0 6.30G 5.96G 0|0 0|0 2.69m 54.4k 10 Sep 5 14:37:19.504 *0 *0 *0 *0 0 2|0 1.8% 77.2% 0 6.30G 5.96G 0|0 0|0 2.67m 54.2k 10 Sep 5 14:37:20.504 3 *0 *0 *0 0 3|0 1.8% 77.3% 0 6.30G 5.96G 0|0 0|0 5.35m 54.5k 10 Sep 5 14:37:21.504 2 *0 1 *0 0 5|0 1.9% 77.3% 0 6.30G 5.96G 0|0 0|0 3.26m 54.6k 10 Sep 5 14:37:22.504 3 *0 *0 *0 0 2|0 1.9% 77.4% 0 6.30G 5.96G 0|0 0|0 5.32m 54.3k 10 Sep 5 14:37:23.505 1 *0 *0 *0 0 3|0 2.0% 77.5% 0 6.30G 5.96G 0|0 0|0 2.71m 54.3k 10 Sep 5 14:37:24.503 2 *0 *0 *0 0 3|0 2.0% 77.5% 0 6.30G 5.96G 0|0 0|0 2.63m 54.5k 10 Sep 5 14:37:25.504 2 *0 *0 *0 0 4|0 2.1% 77.6% 0 6.30G 5.96G 0|0 0|0 5.33m 54.5k 10 Sep 5 14:37:26.504 2 *0 *0 *0 0 2|0 2.1% 77.6% 0 6.30G 5.96G 0|0 0|0 2.69m 54.2k 10 Sep 5 14:37:27.505 2 *0 *0 *0 0 3|0 2.2% 77.7% 0 6.30G 5.96G 0|0 0|0 5.34m 54.3k 10 Sep 5 14:37:28.504 insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn time 3 *0 *0 *0 0 3|0 2.2% 77.7% 0 6.30G 5.96G 0|0 0|0 2.67m 54.3k 10 Sep 5 14:37:29.503 1 *0 *0 *0 0 3|0 2.3% 77.8% 0 6.30G 5.96G 0|0 0|0 5.35m 54.3k 10 Sep 5 14:37:30.503 2 *0 *0 *0 0 2|0 2.3% 77.8% 0 6.30G 5.96G 0|0 0|0 2.66m 53.8k 10 Sep 5 14:37:31.512 2 *0 1 *0 0 9|0 2.4% 77.9% 0 6.30G 5.96G 0|0 0|0 3.31m 57.6k 10 Sep 5 14:37:32.503 4 *0 *0 *0 0 4|0 2.4% 78.0% 0 6.30G 5.96G 0|0 0|0 5.36m 54.6k 10 Sep 5 14:37:33.503 *0 *0 *0 *0 0 3|0 2.5% 78.0% 0 6.30G 5.96G 0|0 0|0 2.64m 54.2k 10 Sep 5 14:37:34.504 3 *0 *0 *0 0 3|0 2.5% 78.1% 0 6.30G 5.96G 0|0 0|0 5.32m 54.4k 10 Sep 5 14:37:35.506 1 *0 *0 *0 0 3|0 2.6% 78.1% 0 6.30G 5.96G 0|0 0|0 2.71m 54.3k 10 Sep 5 14:37:36.504 3 *0 *0 *0 0 3|0 2.7% 78.1% 0 6.30G 5.96G 0|0 0|0 2.63m 54.3k 10 Sep 5 14:37:37.503 1 *0 *0 *0 0 2|0 2.7% 78.2% 0 6.30G 5.96G 0|0 0|0 5.33m 54.3k 10 Sep 5 14:37:38.504

      PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
      29078 root 20 0 6586752 5.919g 6920 S 99.7 38.2 0:48.07 mongod
      30297 root 20 0 6586752 5.919g 6920 S 0.3 38.2 0:00.82 mongod
      30270 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.34 mongod
      30271 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30272 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.02 mongod
      30274 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.13 mongod
      30275 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.04 mongod
      30276 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.33 mongod
      30277 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.05 mongod
      30278 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30279 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.49 mongod
      30280 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.96 mongod
      30281 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30282 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:02.26 mongod
      30283 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.06 mongod
      30284 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30285 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.05 mongod
      30286 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod
      30287 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.07 mongod
      30291 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.20 mongod
      30295 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.01 mongod
      30301 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.01 mongod
      30304 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.08 mongod
      30461 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod
      30494 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:01.95 mongod
      30879 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.23 mongod
      31477 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod
      31478 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.03 mongod
      31572 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.02 mongod
      31917 root 20 0 6586752 5.919g 6920 S 0.0 38.2 0:00.00 mongod

        1. db.getLogComponents
          4 kB
        2. diagnostic-data.tar.gz
          38.64 MB
        3. diagnostic-data.tar.gz
          13.89 MB
        4. Screen Shot 2018-09-06 at 10.10.58 AM.png
          Screen Shot 2018-09-06 at 10.10.58 AM.png
          56 kB
        5. server1-rsyslog.conf
          3 kB
        6. server2-rsyslog.conf
          3 kB
        7. server2-rsyslog.conf
          3 kB

            Assignee:
            nick.brewer Nick Brewer
            Reporter:
            wynn wynn zhao
            Votes:
            0 Vote for this issue
            Watchers:
            9 Start watching this issue

              Created:
              Updated:
              Resolved: