Skip to content
This repository has been archived by the owner on Aug 26, 2021. It is now read-only.

ERROR: for serviceapi Container "xxxx" is unhealthy. #149

Closed
mizbanpaytakht opened this issue Apr 23, 2018 · 13 comments
Closed

ERROR: for serviceapi Container "xxxx" is unhealthy. #149

mizbanpaytakht opened this issue Apr 23, 2018 · 13 comments

Comments

@mizbanpaytakht
Copy link

Hi,

I received this error while trying to start docker :
I think there is a problem with ElasticSearch service.
sudo docker-compose up -d root_db_1 is up-to-date root_es_1 is up-to-date root_rabbit_1 is up-to-date root_redis_1 is up-to-date ERROR: for serviceapi Container "b5182a16944e" is unhealthy. ERROR: Encountered errors while bringing up the project.

`version: "2.1"
networks:
internal_network:
services:
db:
restart: always
networks:
- internal_network
image: ambar/ambar-mongodb:2.0.1
environment:
- cacheSizeGB=2
volumes:
- /home/docker/db:/data/db
expose:
- "27017"
ports:
- "27017:27017"
es:
restart: always
networks:
- internal_network
image: ambar/ambar-es:2.0.1
expose:
- "9200"
ports:
- "9200:9200"
environment:
- cluster.name=ambar-es
- ES_JAVA_OPTS=-Xms2g -Xmx2g
ulimits:
memlock:
soft: -1
hard: -1
nofile:
soft: 65536
hard: 65536
cap_add:
- IPC_LOCK
volumes:
- /home/docker/es:/usr/share/elasticsearch/data
rabbit:
restart: always
networks:
- internal_network
image: ambar/ambar-rabbit:2.0.1
hostname: rabbit
expose:
- "15672"
- "5672"
ports:
- "15672:15672"
- "5672:5672"
volumes:
- /home/docker/rabbit:/var/lib/rabbitmq
redis:
restart: always
sysctls:
- net.core.somaxconn=1024
networks:
- internal_network
image: ambar/ambar-redis:2.0.1
expose:
- "6379"
ports:
- "6379:6379"
serviceapi:
depends_on:
redis:
condition: service_healthy
rabbit:
condition: service_healthy
es:
condition: service_healthy
db:
condition: service_healthy
restart: always
networks:
- internal_network
image: ambar/ambar-serviceapi:2.0.1
expose:
- "8081"
ports:
- "8081:8081"
environment:
- mongoDbUrl=mongodb://db:27017/ambar_data
- elasticSearchUrl=http://es:9200
- redisHost=redis
- redisPort=6379
- rabbitHost=amqp://rabbit
- langAnalyzer=ambar_en
volumes:
- /var/run/docker.sock:/var/run/docker.sock
webapi:
depends_on:
serviceapi:
condition: service_healthy
restart: always
networks:
restart: always
networks:
- internal_network
image: ambar/ambar-webapi:2.0.1
expose:
- "8080"
ports:
- "8080:8080"
environment:
- analyticsToken=cda4b0bb11a1f32aed7564b08c455992
- uiLang=en
- mongoDbUrl=mongodb://db:27017/ambar_data
- elasticSearchUrl=http://es:9200
- redisHost=redis
- redisPort=6379
- serviceApiUrl=http://serviceapi:8081
- rabbitHost=amqp://rabbit
volumes:
- /var/run/docker.sock:/var/run/docker.sock
frontend:
depends_on:
webapi:
condition: service_healthy
image: ambar/ambar-frontend:2.0.1
restart: always
networks:
- internal_network
ports:
- "80:80"
expose:
- "80"
environment:
- api=http://145.239.139.196:8080
pipeline0:
depends_on:
serviceapi:
condition: service_healthy
image: ambar/ambar-pipeline:2.0.1
restart: always
networks:
- internal_network
environment:
- id=0
- api_url=http://serviceapi:8081
- rabbit_host=amqp://rabbit
crawler0:
depends_on:
serviceapi:
condition: service_healthy
image: ambar/ambar-local-crawler
restart: always
image: ambar/ambar-local-crawler
restart: always
networks:
- internal_network
environment:
- apiUrl=http://serviceapi:8081
- crawlPath=/usr/data
- name=craw
volumes:
- /home/docker/2:/usr/data

@sochix
Copy link
Member

sochix commented Apr 23, 2018

@mizbanpaytakht check es logs

@mizbanpaytakht
Copy link
Author

How can I check es logs !?

sudo docker-compose up -d
Creating network "kamran_internal_network" with the default driver
Creating kamran_redis_1 ... done
Creating kamran_db_1 ... done
Creating kamran_rabbit_1 ... done
Creating kamran_es_1 ... done

ERROR: for serviceapi Container "5c66902c456c" is unhealthy.
ERROR: Encountered errors while bringing up the project.

sudo docker logs -f kamran_es_1 is empty !

@sochix
Copy link
Member

sochix commented Apr 23, 2018

@mizbanpaytakht if you are not familiar with docker, you can request our paid support. Check the pricing here

@mizbanpaytakht
Copy link
Author

Hi,

Im familiar with docker no logs shown for ES !

sudo docker-compose logs -f
Attaching to kamran_es_1, kamran_rabbit_1, kamran_db_1, kamran_redis_1
rabbit_1 | 2018-04-23 14:08:27.456 [info] <0.33.0> Application lager started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.362 [info] <0.33.0> Application mnesia started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.362 [info] <0.33.0> Application xmerl started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.363 [info] <0.33.0> Application recon started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.375 [info] <0.33.0> Application os_mon started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.376 [info] <0.33.0> Application crypto started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.376 [info] <0.33.0> Application cowlib started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.376 [info] <0.33.0> Application asn1 started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:28.376 [info] <0.33.0> Application public_key started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.384 [info] <0.33.0> Application ssl started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.394 [info] <0.33.0> Application ranch started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.397 [info] <0.33.0> Application cowboy started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.398 [info] <0.33.0> Application ranch_proxy_protocol started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.398 [info] <0.33.0> Application jsx started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.398 [info] <0.33.0> Application rabbit_common started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.411 [info] <0.33.0> Application amqp_client started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.493 [info] <0.33.0> Application inets started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:41.511 [info] <0.192.0>
rabbit_1 | Starting RabbitMQ 3.7.4 on Erlang 20.2.4
rabbit_1 | Copyright (C) 2007-2018 Pivotal Software, Inc.
rabbit_1 | Licensed under the MPL. See http://www.rabbitmq.com/
rabbit_1 |
rabbit_1 | ## ##
rabbit_1 | ## ## RabbitMQ 3.7.4. Copyright (C) 2007-2018 Pivotal Software, Inc.
rabbit_1 | ########## Licensed under the MPL. See http://www.rabbitmq.com/
rabbit_1 | ###### ##
rabbit_1 | ########## Logs:
rabbit_1 |
rabbit_1 | Starting broker...
rabbit_1 | 2018-04-23 14:08:41.533 [info] <0.192.0>
rabbit_1 | node : rabbit@rabbit
rabbit_1 | home dir : /var/lib/rabbitmq
rabbit_1 | config file(s) : /etc/rabbitmq/rabbitmq.config
rabbit_1 | cookie hash : 1s7BEuj8Wk3LI/JmHMHORw==
rabbit_1 | log(s) :
rabbit_1 | database dir : /var/lib/rabbitmq/mnesia/rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:44.839 [info] <0.200.0> Memory high watermark set to 799 MiB (838800179 bytes) of 1999 MiB (2097000448 bytes) total
rabbit_1 | 2018-04-23 14:08:44.866 [info] <0.202.0> Enabling free disk space monitoring
rabbit_1 | 2018-04-23 14:08:44.866 [info] <0.202.0> Disk free limit set to 50MB
rabbit_1 | 2018-04-23 14:08:44.879 [info] <0.204.0> Limiting to approx 1048476 file handles (943626 sockets)
rabbit_1 | 2018-04-23 14:08:44.880 [info] <0.205.0> FHC read buffering: OFF
rabbit_1 | 2018-04-23 14:08:44.880 [info] <0.205.0> FHC write buffering: ON
rabbit_1 | 2018-04-23 14:08:44.892 [info] <0.192.0> Node database directory at /var/lib/rabbitmq/mnesia/rabbit@rabbit is empty. Assuming we need to join an existing cluster or initialise from scratch...
rabbit_1 | 2018-04-23 14:08:44.892 [info] <0.192.0> Configured peer discovery backend: rabbit_peer_discovery_classic_config
rabbit_1 | 2018-04-23 14:08:44.893 [info] <0.192.0> Will try to lock with peer discovery backend rabbit_peer_discovery_classic_config
rabbit_1 | 2018-04-23 14:08:44.894 [info] <0.192.0> Peer discovery backend does not support locking, falling back to randomized delay
rabbit_1 | 2018-04-23 14:08:44.895 [info] <0.192.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping randomized startup delay.
rabbit_1 | 2018-04-23 14:08:44.895 [info] <0.192.0> All discovered existing cluster peers:
rabbit_1 | 2018-04-23 14:08:44.896 [info] <0.192.0> Discovered no peer nodes to cluster with
rabbit_1 | 2018-04-23 14:08:44.961 [info] <0.33.0> Application mnesia exited with reason: stopped
rabbit_1 | 2018-04-23 14:08:45.000 [info] <0.33.0> Application mnesia started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:45.101 [info] <0.192.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbit_1 | 2018-04-23 14:08:45.162 [info] <0.192.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbit_1 | 2018-04-23 14:08:45.186 [info] <0.192.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbit_1 | 2018-04-23 14:08:45.186 [info] <0.192.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
rabbit_1 | 2018-04-23 14:08:45.187 [info] <0.192.0> Priority queues enabled, real BQ is rabbit_variable_queue
rabbit_1 | 2018-04-23 14:08:45.232 [info] <0.374.0> Starting rabbit_node_monitor
rabbit_1 | 2018-04-23 14:08:45.258 [info] <0.192.0> message_store upgrades: 1 to apply
rabbit_1 | 2018-04-23 14:08:45.258 [info] <0.192.0> message_store upgrades: Applying rabbit_variable_queue:move_messages_to_vhost_store
rabbit_1 | 2018-04-23 14:08:45.259 [info] <0.192.0> message_store upgrades: No durable queues found. Skipping message store migration
rabbit_1 | 2018-04-23 14:08:45.259 [info] <0.192.0> message_store upgrades: Removing the old message store data
rabbit_1 | 2018-04-23 14:08:45.260 [info] <0.192.0> message_store upgrades: All upgrades applied successfully
rabbit_1 | 2018-04-23 14:08:45.289 [info] <0.192.0> Management plugin: using rates mode 'basic'
rabbit_1 | 2018-04-23 14:08:45.290 [info] <0.192.0> Adding vhost '/'
rabbit_1 | 2018-04-23 14:08:45.301 [info] <0.408.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@rabbit/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
rabbit_1 | 2018-04-23 14:08:45.304 [info] <0.408.0> Starting message stores for vhost '/'
rabbit_1 | 2018-04-23 14:08:45.304 [info] <0.412.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
rabbit_1 | 2018-04-23 14:08:45.306 [info] <0.408.0> Started message store of type transient for vhost '/'
rabbit_1 | 2018-04-23 14:08:45.306 [info] <0.415.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
rabbit_1 | 2018-04-23 14:08:45.307 [warning] <0.415.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
rabbit_1 | 2018-04-23 14:08:45.308 [info] <0.408.0> Started message store of type persistent for vhost '/'
rabbit_1 | 2018-04-23 14:08:45.309 [info] <0.192.0> Creating user 'guest'
rabbit_1 | 2018-04-23 14:08:45.314 [info] <0.192.0> Setting user tags for user 'guest' to [administrator]
rabbit_1 | 2018-04-23 14:08:45.315 [info] <0.192.0> Setting permissions for 'guest' in '/' to '.', '.', '.*'
rabbit_1 | 2018-04-23 14:08:45.319 [info] <0.453.0> started TCP Listener on [::]:5672
rabbit_1 | 2018-04-23 14:08:45.322 [info] <0.192.0> Setting up a table for connection tracking on this node: tracked_connection_on_node_rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:45.325 [info] <0.192.0> Setting up a table for per-vhost connection counting on this node: tracked_connection_per_vhost_on_node_rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:45.325 [info] <0.33.0> Application rabbit started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:45.332 [info] <0.33.0> Application rabbitmq_management_agent started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:45.332 [info] <0.33.0> Application rabbitmq_web_dispatch started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:45.376 [info] <0.510.0> Management plugin started. Port: 15672
rabbit_1 | 2018-04-23 14:08:45.376 [info] <0.616.0> Statistics database started.
rabbit_1 | 2018-04-23 14:08:45.378 [info] <0.33.0> Application rabbitmq_management started on node rabbit@rabbit
rabbit_1 | 2018-04-23 14:08:46.385 [info] <0.5.0> Server startup complete; 3 plugins started.
rabbit_1 | * rabbitmq_management
rabbit_1 | * rabbitmq_web_dispatch
rabbit_1 | * rabbitmq_management_agent
rabbit_1 | completed with 3 plugins.
db_1 | 2018-04-23T14:08:23.541+0000 I CONTROL [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db 64-bit host=9cc0adaaf0e9
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] db version v3.4.2
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] git version: 3f76e40c105fc223b3e5aac3e20dcd026b83b38b
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.0.1t 3 May 2016
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] allocator: tcmalloc
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] modules: none
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] build environment:
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] distmod: debian81
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] distarch: x86_64
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] target_arch: x86_64
db_1 | 2018-04-23T14:08:23.543+0000 I CONTROL [initandlisten] options: { config: "/etc/mongod.conf", storage: { wiredTiger: { engineConfig: { cacheSizeGB: 2.0 } } } }
db_1 | 2018-04-23T14:08:23.545+0000 I STORAGE [initandlisten]
db_1 | 2018-04-23T14:08:23.545+0000 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
db_1 | 2018-04-23T14:08:23.545+0000 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
db_1 | 2018-04-23T14:08:23.545+0000 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=2048M,session_max=20000,eviction=(threads_max=4),config_base=false,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),
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten]
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten]
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten]
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten] ** We suggest setting it to 'never'
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten]
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten] ** We suggest setting it to 'never'
db_1 | 2018-04-23T14:08:23.575+0000 I CONTROL [initandlisten]
db_1 | 2018-04-23T14:08:23.583+0000 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
db_1 | 2018-04-23T14:08:23.597+0000 I INDEX [initandlisten] build index on: admin.system.version properties: { v: 2, key: { version: 1 }, name: "incompatible_with_version_32", ns: "admin.system.version" }
db_1 | 2018-04-23T14:08:23.597+0000 I INDEX [initandlisten] building index using bulk method; build may temporarily use up to 500 megabytes of RAM
db_1 | 2018-04-23T14:08:23.600+0000 I INDEX [initandlisten] build index done. scanned 0 total records. 0 secs
db_1 | 2018-04-23T14:08:23.600+0000 I COMMAND [initandlisten] setting featureCompatibilityVersion to 3.4
db_1 | 2018-04-23T14:08:23.602+0000 I NETWORK [thread1] waiting for connections on port 27017
db_1 | 2018-04-23T14:08:41.133+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 578, after asserts: 1616, after backgroundFlushing: 2548, after connections: 3555, after dur: 3567, after extra_info: 4611, after globalLock: 5541, after locks: 5541, after network: 5541, after opLatencies: 5541, after opcounters: 5541, after opcountersRepl: 5541, after repl: 5554, after security: 5554, after storageEngine: 5554, after tcmalloc: 5568, after wiredTiger: 11323, at end: 11401 }
db_1 | 2018-04-23T14:08:41.259+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39238 #1 (1 connection now open)
db_1 | 2018-04-23T14:08:41.266+0000 I - [conn1] end connection 127.0.0.1:39238 (1 connection now open)
db_1 | 2018-04-23T14:09:04.700+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 0, after backgroundFlushing: 0, after connections: 0, after dur: 0, after extra_info: 0, after globalLock: 24, after locks: 48, after network: 48, after opLatencies: 48, after opcounters: 48, after opcountersRepl: 48, after repl: 48, after security: 48, after storageEngine: 48, after tcmalloc: 1001, after wiredTiger: 3061, at end: 15415 }
db_1 | 2018-04-23T14:09:04.819+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39244 #2 (1 connection now open)
db_1 | 2018-04-23T14:09:04.828+0000 I - [conn2] end connection 127.0.0.1:39244 (1 connection now open)
db_1 | 2018-04-23T14:09:10.629+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39248 #3 (1 connection now open)
db_1 | 2018-04-23T14:09:10.633+0000 I - [conn3] end connection 127.0.0.1:39248 (1 connection now open)
db_1 | 2018-04-23T14:09:22.610+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39254 #4 (1 connection now open)
db_1 | 2018-04-23T14:09:22.617+0000 I - [conn4] end connection 127.0.0.1:39254 (1 connection now open)
db_1 | 2018-04-23T14:09:27.771+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39258 #5 (1 connection now open)
db_1 | 2018-04-23T14:09:27.779+0000 I - [conn5] end connection 127.0.0.1:39258 (1 connection now open)
db_1 | 2018-04-23T14:09:43.404+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 2942, after asserts: 4076, after backgroundFlushing: 4967, after connections: 6032, after dur: 8033, after extra_info: 9996, after globalLock: 9996, after locks: 10011, after network: 10011, after opLatencies: 10011, after opcounters: 10011, after opcountersRepl: 10011, after repl: 10011, after security: 10011, after storageEngine: 10011, after tcmalloc: 10032, after wiredTiger: 10052, at end: 10104 }
db_1 | 2018-04-23T14:09:43.590+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39268 #6 (1 connection now open)
db_1 | 2018-04-23T14:09:43.593+0000 I - [conn6] end connection 127.0.0.1:39268 (1 connection now open)
db_1 | 2018-04-23T14:09:59.117+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 1737, after asserts: 1737, after backgroundFlushing: 1737, after connections: 1747, after dur: 1747, after extra_info: 1747, after globalLock: 1759, after locks: 1759, after network: 1759, after opLatencies: 1776, after opcounters: 1776, after opcountersRepl: 1776, after repl: 1776, after security: 1776, after storageEngine: 1776, after tcmalloc: 1776, after wiredTiger: 1786, at end: 1821 }
db_1 | 2018-04-23T14:09:59.378+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39274 #7 (1 connection now open)
db_1 | 2018-04-23T14:09:59.381+0000 I - [conn7] end connection 127.0.0.1:39274 (1 connection now open)
db_1 | 2018-04-23T14:10:11.702+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 2982, after asserts: 3007, after backgroundFlushing: 3054, after connections: 4079, after dur: 4079, after extra_info: 5259, after globalLock: 5259, after locks: 5269, after network: 5269, after opLatencies: 5269, after opcounters: 5269, after opcountersRepl: 5269, after repl: 5282, after security: 5282, after storageEngine: 5282, after tcmalloc: 5292, after wiredTiger: 5316, at end: 5380 }
db_1 | 2018-04-23T14:10:11.906+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39280 #8 (1 connection now open)
db_1 | 2018-04-23T14:10:11.909+0000 I - [conn8] end connection 127.0.0.1:39280 (1 connection now open)
db_1 | 2018-04-23T14:10:19.692+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39286 #9 (1 connection now open)
db_1 | 2018-04-23T14:10:19.696+0000 I - [conn9] end connection 127.0.0.1:39286 (1 connection now open)
db_1 | 2018-04-23T14:10:24.892+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39292 #10 (1 connection now open)
db_1 | 2018-04-23T14:10:24.911+0000 I - [conn10] end connection 127.0.0.1:39292 (1 connection now open)
db_1 | 2018-04-23T14:10:30.661+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39296 #11 (1 connection now open)
db_1 | 2018-04-23T14:10:30.666+0000 I - [conn11] end connection 127.0.0.1:39296 (1 connection now open)
db_1 | 2018-04-23T14:10:49.194+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 1987, after asserts: 2003, after backgroundFlushing: 4002, after connections: 9820, after dur: 9820, after extra_info: 9820, after globalLock: 9832, after locks: 9832, after network: 9832, after opLatencies: 9832, after opcounters: 9832, after opcountersRepl: 9832, after repl: 9832, after security: 9832, after storageEngine: 9832, after tcmalloc: 9855, after wiredTiger: 9881, at end: 9901 }
db_1 | 2018-04-23T14:10:49.367+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39302 #12 (1 connection now open)
db_1 | 2018-04-23T14:10:49.371+0000 I - [conn12] end connection 127.0.0.1:39302 (1 connection now open)
db_1 | 2018-04-23T14:10:57.618+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39308 #13 (1 connection now open)
db_1 | 2018-04-23T14:10:57.623+0000 I - [conn13] end connection 127.0.0.1:39308 (1 connection now open)
db_1 | 2018-04-23T14:11:02.794+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39312 #14 (1 connection now open)
db_1 | 2018-04-23T14:11:02.802+0000 I - [conn14] end connection 127.0.0.1:39312 (1 connection now open)
db_1 | 2018-04-23T14:11:18.292+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 11, after backgroundFlushing: 11, after connections: 23, after dur: 23, after extra_info: 23, after globalLock: 23, after locks: 33, after network: 33, after opLatencies: 33, after opcounters: 33, after opcountersRepl: 33, after repl: 33, after security: 33, after storageEngine: 33, after tcmalloc: 86, after wiredTiger: 1036, at end: 10005 }
db_1 | 2018-04-23T14:11:18.540+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39322 #15 (1 connection now open)
db_1 | 2018-04-23T14:11:18.544+0000 I - [conn15] end connection 127.0.0.1:39322 (1 connection now open)
db_1 | 2018-04-23T14:11:25.276+0000 I COMMAND [PeriodicTaskRunner] task: UnusedLockCleaner took: 923ms
db_1 | 2018-04-23T14:11:33.693+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 0, after backgroundFlushing: 0, after connections: 0, after dur: 0, after extra_info: 913, after globalLock: 929, after locks: 1845, after network: 1845, after opLatencies: 1856, after opcounters: 3862, after opcountersRepl: 3882, after repl: 6871, after security: 6898, after storageEngine: 9979, after tcmalloc: 10168, after wiredTiger: 10188, at end: 10268 }
db_1 | 2018-04-23T14:11:33.868+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39326 #16 (1 connection now open)
db_1 | 2018-04-23T14:11:33.870+0000 I - [conn16] end connection 127.0.0.1:39326 (1 connection now open)
db_1 | 2018-04-23T14:11:59.384+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 14, after asserts: 14, after backgroundFlushing: 14, after connections: 14, after dur: 14, after extra_info: 983, after globalLock: 1014, after locks: 1014, after network: 1014, after opLatencies: 1014, after opcounters: 1014, after opcountersRepl: 1014, after repl: 1014, after security: 1014, after storageEngine: 3023, after tcmalloc: 6022, after wiredTiger: 20054, at end: 20089 }
db_1 | 2018-04-23T14:11:59.654+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39334 #17 (1 connection now open)
db_1 | 2018-04-23T14:11:59.658+0000 I - [conn17] end connection 127.0.0.1:39334 (1 connection now open)
db_1 | 2018-04-23T14:12:07.842+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39338 #18 (1 connection now open)
db_1 | 2018-04-23T14:12:07.850+0000 I - [conn18] end connection 127.0.0.1:39338 (1 connection now open)
db_1 | 2018-04-23T14:12:12.966+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39344 #19 (1 connection now open)
db_1 | 2018-04-23T14:12:12.972+0000 I - [conn19] end connection 127.0.0.1:39344 (1 connection now open)
db_1 | 2018-04-23T14:12:18.195+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39350 #20 (1 connection now open)
db_1 | 2018-04-23T14:12:18.200+0000 I - [conn20] end connection 127.0.0.1:39350 (1 connection now open)
db_1 | 2018-04-23T14:12:31.290+0000 I COMMAND [PeriodicTaskRunner] task: UnusedLockCleaner took: 1000ms
db_1 | 2018-04-23T14:12:36.303+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 11, after backgroundFlushing: 11, after connections: 11, after dur: 11, after extra_info: 11, after globalLock: 11, after locks: 11, after network: 11, after opLatencies: 11, after opcounters: 11, after opcountersRepl: 11, after repl: 11, after security: 11, after storageEngine: 31, after tcmalloc: 82, after wiredTiger: 897, at end: 10953 }
db_1 | 2018-04-23T14:12:36.592+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39358 #21 (1 connection now open)
db_1 | 2018-04-23T14:12:36.596+0000 I - [conn21] end connection 127.0.0.1:39358 (1 connection now open)
db_1 | 2018-04-23T14:12:44.651+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 11, after backgroundFlushing: 26, after connections: 26, after dur: 26, after extra_info: 50, after globalLock: 2305, after locks: 2548, after network: 2548, after opLatencies: 2558, after opcounters: 2558, after opcountersRepl: 2558, after repl: 2558, after security: 2558, after storageEngine: 2568, after tcmalloc: 2579, after wiredTiger: 2602, at end: 2623 }
db_1 | 2018-04-23T14:12:44.834+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39362 #22 (1 connection now open)
db_1 | 2018-04-23T14:12:44.839+0000 I - [conn22] end connection 127.0.0.1:39362 (1 connection now open)
db_1 | 2018-04-23T14:12:50.240+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39368 #23 (1 connection now open)
db_1 | 2018-04-23T14:12:50.246+0000 I - [conn23] end connection 127.0.0.1:39368 (1 connection now open)
db_1 | 2018-04-23T14:13:03.859+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39376 #24 (1 connection now open)
db_1 | 2018-04-23T14:13:03.863+0000 I - [conn24] end connection 127.0.0.1:39376 (1 connection now open)
db_1 | 2018-04-23T14:13:10.592+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39382 #25 (1 connection now open)
db_1 | 2018-04-23T14:13:10.596+0000 I - [conn25] end connection 127.0.0.1:39382 (1 connection now open)
db_1 | 2018-04-23T14:13:23.276+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 959, after asserts: 959, after backgroundFlushing: 1983, after connections: 2993, after dur: 3005, after extra_info: 3015, after globalLock: 3015, after locks: 3015, after network: 3015, after opLatencies: 3026, after opcounters: 3026, after opcountersRepl: 3026, after repl: 3026, after security: 3026, after storageEngine: 3950, after tcmalloc: 3950, after wiredTiger: 3984, at end: 6969 }
db_1 | 2018-04-23T14:13:33.556+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39388 #26 (1 connection now open)
db_1 | 2018-04-23T14:13:33.564+0000 I - [conn26] end connection 127.0.0.1:39388 (1 connection now open)
db_1 | 2018-04-23T14:13:42.474+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 1047, after asserts: 1071, after backgroundFlushing: 1071, after connections: 1081, after dur: 1081, after extra_info: 1081, after globalLock: 1081, after locks: 1091, after network: 1091, after opLatencies: 1091, after opcounters: 1091, after opcountersRepl: 1091, after repl: 1101, after security: 1101, after storageEngine: 1101, after tcmalloc: 1155, after wiredTiger: 1167, at end: 1177 }
db_1 | 2018-04-23T14:13:42.643+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39392 #27 (1 connection now open)
db_1 | 2018-04-23T14:13:42.647+0000 I - [conn27] end connection 127.0.0.1:39392 (1 connection now open)
db_1 | 2018-04-23T14:13:49.649+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39400 #28 (1 connection now open)
db_1 | 2018-04-23T14:13:49.663+0000 I - [conn28] end connection 127.0.0.1:39400 (1 connection now open)
db_1 | 2018-04-23T14:14:14.555+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 12, after backgroundFlushing: 12, after connections: 12, after dur: 12, after extra_info: 978, after globalLock: 5038, after locks: 19155, after network: 19181, after opLatencies: 19191, after opcounters: 19191, after opcountersRepl: 19191, after repl: 19191, after security: 19191, after storageEngine: 19191, after tcmalloc: 19202, after wiredTiger: 19202, at end: 19270 }
db_1 | 2018-04-23T14:14:14.826+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39406 #29 (1 connection now open)
db_1 | 2018-04-23T14:14:14.829+0000 I - [conn29] end connection 127.0.0.1:39406 (1 connection now open)
db_1 | 2018-04-23T14:14:21.010+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39410 #30 (1 connection now open)
db_1 | 2018-04-23T14:14:21.015+0000 I - [conn30] end connection 127.0.0.1:39410 (1 connection now open)
db_1 | 2018-04-23T14:14:26.198+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39414 #31 (1 connection now open)
db_1 | 2018-04-23T14:14:26.202+0000 I - [conn31] end connection 127.0.0.1:39414 (1 connection now open)
db_1 | 2018-04-23T14:14:39.620+0000 I COMMAND [PeriodicTaskRunner] task: UnusedLockCleaner took: 305ms
db_1 | 2018-04-23T14:14:39.620+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39422 #32 (1 connection now open)
db_1 | 2018-04-23T14:14:39.624+0000 I - [conn32] end connection 127.0.0.1:39422 (1 connection now open)
db_1 | 2018-04-23T14:14:39.633+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 0, after backgroundFlushing: 0, after connections: 0, after dur: 0, after extra_info: 0, after globalLock: 0, after locks: 8386, after network: 8386, after opLatencies: 8386, after opcounters: 8386, after opcountersRepl: 8386, after repl: 8386, after security: 8386, after storageEngine: 8386, after tcmalloc: 8386, after wiredTiger: 8386, at end: 8396 }
db_1 | 2018-04-23T14:14:55.603+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 799, after backgroundFlushing: 799, after connections: 799, after dur: 799, after extra_info: 799, after globalLock: 799, after locks: 809, after network: 809, after opLatencies: 809, after opcounters: 809, after opcountersRepl: 809, after repl: 809, after security: 822, after storageEngine: 822, after tcmalloc: 833, after wiredTiger: 846, at end: 11131 }
db_1 | 2018-04-23T14:14:55.799+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39428 #33 (1 connection now open)
db_1 | 2018-04-23T14:14:55.802+0000 I - [conn33] end connection 127.0.0.1:39428 (1 connection now open)
db_1 | 2018-04-23T14:15:09.133+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 14, after asserts: 25, after backgroundFlushing: 25, after connections: 37, after dur: 37, after extra_info: 37, after globalLock: 58, after locks: 58, after network: 58, after opLatencies: 58, after opcounters: 58, after opcountersRepl: 58, after repl: 58, after security: 58, after storageEngine: 58, after tcmalloc: 106, after wiredTiger: 6020, at end: 7827 }
db_1 | 2018-04-23T14:15:09.321+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39436 #34 (1 connection now open)
db_1 | 2018-04-23T14:15:09.324+0000 I - [conn34] end connection 127.0.0.1:39436 (1 connection now open)
db_1 | 2018-04-23T14:15:15.386+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 1010, after backgroundFlushing: 1010, after connections: 1010, after dur: 1010, after extra_info: 1010, after globalLock: 1010, after locks: 1010, after network: 1010, after opLatencies: 1010, after opcounters: 1010, after opcountersRepl: 1010, after repl: 1010, after security: 1010, after storageEngine: 1010, after tcmalloc: 1010, after wiredTiger: 1036, at end: 1036 }
db_1 | 2018-04-23T14:15:15.610+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39442 #35 (1 connection now open)
db_1 | 2018-04-23T14:15:15.614+0000 I - [conn35] end connection 127.0.0.1:39442 (1 connection now open)
db_1 | 2018-04-23T14:15:25.645+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39446 #36 (1 connection now open)
db_1 | 2018-04-23T14:15:25.648+0000 I - [conn36] end connection 127.0.0.1:39446 (1 connection now open)
db_1 | 2018-04-23T14:15:32.378+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 0, after backgroundFlushing: 0, after connections: 0, after dur: 0, after extra_info: 24, after globalLock: 24, after locks: 24, after network: 24, after opLatencies: 24, after opcounters: 24, after opcountersRepl: 24, after repl: 24, after security: 24, after storageEngine: 24, after tcmalloc: 24, after wiredTiger: 51, at end: 1081 }
db_1 | 2018-04-23T14:15:44.366+0000 I COMMAND [PeriodicTaskRunner] task: DBConnectionPool-cleaner took: 3037ms
db_1 | 2018-04-23T14:15:45.537+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39452 #37 (1 connection now open)
db_1 | 2018-04-23T14:15:45.544+0000 I - [conn37] end connection 127.0.0.1:39452 (1 connection now open)
db_1 | 2018-04-23T14:15:51.670+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39458 #38 (1 connection now open)
db_1 | 2018-04-23T14:15:51.676+0000 I - [conn38] end connection 127.0.0.1:39458 (1 connection now open)
db_1 | 2018-04-23T14:16:01.560+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39466 #39 (1 connection now open)
db_1 | 2018-04-23T14:16:01.566+0000 I - [conn39] end connection 127.0.0.1:39466 (1 connection now open)
db_1 | 2018-04-23T14:16:10.711+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39470 #40 (1 connection now open)
db_1 | 2018-04-23T14:16:10.714+0000 I - [conn40] end connection 127.0.0.1:39470 (1 connection now open)
db_1 | 2018-04-23T14:16:16.715+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39476 #41 (1 connection now open)
db_1 | 2018-04-23T14:16:16.775+0000 I - [conn41] end connection 127.0.0.1:39476 (1 connection now open)
db_1 | 2018-04-23T14:16:30.794+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 1056, after asserts: 3267, after backgroundFlushing: 3282, after connections: 3305, after dur: 3305, after extra_info: 3513, after globalLock: 3513, after locks: 3513, after network: 3513, after opLatencies: 3513, after opcounters: 3513, after opcountersRepl: 3513, after repl: 3513, after security: 3513, after storageEngine: 3513, after tcmalloc: 3513, after wiredTiger: 3513, at end: 3523 }
db_1 | 2018-04-23T14:16:38.340+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 16, after asserts: 1025, after backgroundFlushing: 1025, after connections: 1025, after dur: 1025, after extra_info: 1025, after globalLock: 1036, after locks: 3002, after network: 3002, after opLatencies: 3002, after opcounters: 3002, after opcountersRepl: 3002, after repl: 3002, after security: 3002, after storageEngine: 3014, after tcmalloc: 3014, after wiredTiger: 3053, at end: 3099 }
db_1 | 2018-04-23T14:16:46.574+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39482 #42 (1 connection now open)
db_1 | 2018-04-23T14:16:46.578+0000 I - [conn42] end connection 127.0.0.1:39482 (1 connection now open)
db_1 | 2018-04-23T14:16:52.856+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39488 #43 (1 connection now open)
db_1 | 2018-04-23T14:16:52.859+0000 I - [conn43] end connection 127.0.0.1:39488 (1 connection now open)
db_1 | 2018-04-23T14:17:08.626+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 12, after asserts: 12, after backgroundFlushing: 22, after connections: 34, after dur: 34, after extra_info: 280, after globalLock: 292, after locks: 292, after network: 292, after opLatencies: 292, after opcounters: 292, after opcountersRepl: 292, after repl: 292, after security: 292, after storageEngine: 1250, after tcmalloc: 1262, after wiredTiger: 10589, at end: 10589 }
db_1 | 2018-04-23T14:17:08.724+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39492 #44 (1 connection now open)
db_1 | 2018-04-23T14:17:08.731+0000 I - [conn44] end connection 127.0.0.1:39492 (1 connection now open)
db_1 | 2018-04-23T14:17:22.385+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 10, after backgroundFlushing: 10, after connections: 21, after dur: 21, after extra_info: 21, after globalLock: 47, after locks: 47, after network: 952, after opLatencies: 3989, after opcounters: 3989, after opcountersRepl: 3989, after repl: 5025, after security: 7046, after storageEngine: 8005, after tcmalloc: 8042, after wiredTiger: 8052, at end: 8083 }
db_1 | 2018-04-23T14:17:22.667+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39500 #45 (1 connection now open)
db_1 | 2018-04-23T14:17:22.674+0000 I - [conn45] end connection 127.0.0.1:39500 (1 connection now open)
db_1 | 2018-04-23T14:17:30.555+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39504 #46 (1 connection now open)
db_1 | 2018-04-23T14:17:30.560+0000 I - [conn46] end connection 127.0.0.1:39504 (1 connection now open)
db_1 | 2018-04-23T14:17:36.623+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39512 #47 (1 connection now open)
db_1 | 2018-04-23T14:17:36.641+0000 I - [conn47] end connection 127.0.0.1:39512 (1 connection now open)
db_1 | 2018-04-23T14:17:56.379+0000 I COMMAND [PeriodicTaskRunner] task: UnusedLockCleaner took: 5053ms
db_1 | 2018-04-23T14:17:56.411+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 11, after backgroundFlushing: 11, after connections: 24, after dur: 24, after extra_info: 24, after globalLock: 35, after locks: 35, after network: 35, after opLatencies: 35, after opcounters: 35, after opcountersRepl: 35, after repl: 1022, after security: 3014, after storageEngine: 4021, after tcmalloc: 14119, after wiredTiger: 14129, at end: 14139 }
db_1 | 2018-04-23T14:17:56.625+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39518 #48 (1 connection now open)
db_1 | 2018-04-23T14:17:56.636+0000 I - [conn48] end connection 127.0.0.1:39518 (1 connection now open)
db_1 | 2018-04-23T14:18:09.400+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 2991, after asserts: 3001, after backgroundFlushing: 3001, after connections: 3001, after dur: 3001, after extra_info: 3001, after globalLock: 3001, after locks: 3001, after network: 3001, after opLatencies: 3001, after opcounters: 3013, after opcountersRepl: 3013, after repl: 3013, after security: 3013, after storageEngine: 3013, after tcmalloc: 3025, after wiredTiger: 3025, at end: 3048 }
db_1 | 2018-04-23T14:18:09.585+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39526 #49 (1 connection now open)
db_1 | 2018-04-23T14:18:09.587+0000 I - [conn49] end connection 127.0.0.1:39526 (1 connection now open)
db_1 | 2018-04-23T14:18:14.757+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39530 #50 (1 connection now open)
db_1 | 2018-04-23T14:18:14.768+0000 I - [conn50] end connection 127.0.0.1:39530 (1 connection now open)
db_1 | 2018-04-23T14:18:20.427+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39536 #51 (1 connection now open)
db_1 | 2018-04-23T14:18:20.431+0000 I - [conn51] end connection 127.0.0.1:39536 (1 connection now open)
db_1 | 2018-04-23T14:18:39.329+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 957, after asserts: 1977, after backgroundFlushing: 2027, after connections: 5035, after dur: 5048, after extra_info: 6983, after globalLock: 7993, after locks: 10009, after network: 11006, after opLatencies: 12050, after opcounters: 12050, after opcountersRepl: 12989, after repl: 12989, after security: 12989, after storageEngine: 12999, after tcmalloc: 12999, after wiredTiger: 13009, at end: 13023 }
db_1 | 2018-04-23T14:18:39.599+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39542 #52 (1 connection now open)
db_1 | 2018-04-23T14:18:39.604+0000 I - [conn52] end connection 127.0.0.1:39542 (1 connection now open)
db_1 | 2018-04-23T14:19:09.334+0000 I COMMAND [PeriodicTaskRunner] task: UnusedLockCleaner took: 8049ms
db_1 | 2018-04-23T14:19:09.366+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 534, after asserts: 534, after backgroundFlushing: 534, after connections: 534, after dur: 544, after extra_info: 567, after globalLock: 567, after locks: 578, after network: 578, after opLatencies: 591, after opcounters: 591, after opcountersRepl: 591, after repl: 601, after security: 601, after storageEngine: 613, after tcmalloc: 1013, after wiredTiger: 23076, at end: 23097 }
db_1 | 2018-04-23T14:19:09.610+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39550 #53 (1 connection now open)
db_1 | 2018-04-23T14:19:09.613+0000 I - [conn53] end connection 127.0.0.1:39550 (1 connection now open)
db_1 | 2018-04-23T14:19:25.396+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 1967, after asserts: 1992, after backgroundFlushing: 2013, after connections: 2013, after dur: 2026, after extra_info: 2988, after globalLock: 4988, after locks: 6010, after network: 6023, after opLatencies: 6988, after opcounters: 7083, after opcountersRepl: 7126, after repl: 9999, after security: 10014, after storageEngine: 10014, after tcmalloc: 10048, after wiredTiger: 10058, at end: 10068 }
db_1 | 2018-04-23T14:19:25.640+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39554 #54 (1 connection now open)
db_1 | 2018-04-23T14:19:25.650+0000 I - [conn54] end connection 127.0.0.1:39554 (1 connection now open)
db_1 | 2018-04-23T14:19:38.428+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 12, after asserts: 12, after backgroundFlushing: 12, after connections: 12, after dur: 24, after extra_info: 24, after globalLock: 24, after locks: 24, after network: 24, after opLatencies: 24, after opcounters: 24, after opcountersRepl: 24, after repl: 946, after security: 1927, after storageEngine: 1949, after tcmalloc: 1971, after wiredTiger: 4936, at end: 7052 }
db_1 | 2018-04-23T14:19:38.641+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39560 #55 (1 connection now open)
db_1 | 2018-04-23T14:19:38.644+0000 I - [conn55] end connection 127.0.0.1:39560 (1 connection now open)
db_1 | 2018-04-23T14:19:50.422+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 904, after asserts: 3090, after backgroundFlushing: 4931, after connections: 4941, after dur: 4941, after extra_info: 4955, after globalLock: 4955, after locks: 4955, after network: 4955, after opLatencies: 4955, after opcounters: 4955, after opcountersRepl: 4955, after repl: 4955, after security: 4955, after storageEngine: 4955, after tcmalloc: 4955, after wiredTiger: 4981, at end: 5056 }
db_1 | 2018-04-23T14:19:50.599+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39568 #56 (1 connection now open)
db_1 | 2018-04-23T14:19:50.602+0000 I - [conn56] end connection 127.0.0.1:39568 (1 connection now open)
db_1 | 2018-04-23T14:19:56.630+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39574 #57 (1 connection now open)
db_1 | 2018-04-23T14:19:56.633+0000 I - [conn57] end connection 127.0.0.1:39574 (1 connection now open)
db_1 | 2018-04-23T14:20:12.319+0000 I COMMAND [PeriodicTaskRunner] task: DBConnectionPool-cleaner took: 1029ms
db_1 | 2018-04-23T14:20:17.640+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39580 #58 (1 connection now open)
db_1 | 2018-04-23T14:20:17.647+0000 I - [conn58] end connection 127.0.0.1:39580 (1 connection now open)
db_1 | 2018-04-23T14:20:17.664+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 11, after asserts: 11, after backgroundFlushing: 11, after connections: 11, after dur: 11, after extra_info: 964, after globalLock: 975, after locks: 975, after network: 975, after opLatencies: 975, after opcounters: 975, after opcountersRepl: 975, after repl: 975, after security: 975, after storageEngine: 990, after tcmalloc: 1975, after wiredTiger: 9965, at end: 14298 }
db_1 | 2018-04-23T14:20:24.627+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39584 #59 (1 connection now open)
db_1 | 2018-04-23T14:20:24.632+0000 I - [conn59] end connection 127.0.0.1:39584 (1 connection now open)
db_1 | 2018-04-23T14:20:30.815+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39590 #60 (1 connection now open)
db_1 | 2018-04-23T14:20:30.820+0000 I - [conn60] end connection 127.0.0.1:39590 (1 connection now open)
redis_1 | 1:C 23 Apr 14:08:23.414 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis_1 | 1:C 23 Apr 14:08:23.414 # Redis version=4.0.2, bits=64, commit=00000000, modified=0, pid=1, just started
redis_1 | 1:C 23 Apr 14:08:23.414 # Configuration loaded
redis_1 | .
redis_1 | .-__ ''-._ redis_1 | _.- . . ''-._ Redis 4.0.2 (00000000/0) 64 bit
redis_1 | .- .-```. ```\/ _.,_ ''-._ redis_1 | ( ' , .-` | `, ) Running in standalone mode redis_1 | |`-._`-...-` __...-.-.|'_.-'| Port: 6379 redis_1 | | -. ._ / _.-' | PID: 1 redis_1 | -._ -._ -./ .-' .-'
redis_1 | |-._-.
-.__.-' _.-'_.-'| redis_1 | | -.
-._ _.-'_.-' | http://redis.io redis_1 | -._ -._-..-'.-' .-'
redis_1 | |-._-.
-.__.-' _.-'_.-'| redis_1 | | -.
-._ _.-'_.-' | redis_1 | -._ -._-.
.-'_.-' _.-'
redis_1 | -._ -..-' _.-'
redis_1 | -._ _.-' redis_1 | -.
.-'
redis_1 |
redis_1 | 1:M 23 Apr 14:08:23.415 # Server initialized
redis_1 | 1:M 23 Apr 14:08:23.415 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
redis_1 | 1:M 23 Apr 14:08:23.415 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
redis_1 | 1:M 23 Apr 14:08:23.415 * Ready to accept connections
redis_1 | 1:M 23 Apr 14:08:29.250 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:09:43.572 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:10:49.310 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:11:59.620 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:13:03.838 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:14:14.776 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:15:15.576 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:16:16.469 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:17:22.654 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:18:39.601 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
redis_1 | 1:M 23 Apr 14:19:50.592 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
db_1 | 2018-04-23T14:20:36.894+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39596 #61 (1 connection now open)
db_1 | 2018-04-23T14:20:36.941+0000 I - [conn61] end connection 127.0.0.1:39596 (1 connection now open)
db_1 | 2018-04-23T14:20:40.173+0000 I COMMAND [ftdc] serverStatus was very slow: { after basic: 13, after asserts: 27, after backgroundFlushing: 38, after connections: 38, after dur: 38, after extra_info: 50, after globalLock: 72, after locks: 87, after network: 87, after opLatencies: 112, after opcounters: 3028, after opcountersRepl: 3057, after repl: 3067, after security: 3079, after storageEngine: 3079, after tcmalloc: 3089, after wiredTiger: 3099, at end: 3109 }
db_1 | 2018-04-23T14:20:48.635+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39604 #62 (1 connection now open)
db_1 | 2018-04-23T14:20:48.637+0000 I - [conn62] end connection 127.0.0.1:39604 (1 connection now open)
kamran_es_1 exited with code 137
redis_1 | 1:M 23 Apr 14:20:53.976 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.
db_1 | 2018-04-23T14:20:54.046+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:39610 #63 (1 connection now open)
db_1 | 2018-04-23T14:20:54.086+0000 I - [conn63] end connection 127.0.0.1:39610 (1 connection now open)

@mizbanpaytakht
Copy link
Author

kamran_es_1 exited with code 137

@sochix
Copy link
Member

sochix commented Apr 23, 2018

@mizbanpaytakht
Copy link
Author

Hi,

Yes the problem was because of max_map_count value.

@sochix sochix closed this as completed Apr 24, 2018
@chintzs
Copy link

chintzs commented May 7, 2018

Hi @mizbanpaytakht , I am also receiving the same error. I have configured the max_map_count value as described. Please let me know how you managed to solve the same.

@andrea-ligios
Copy link

@mizbanpaytakht the problem was because of max_map_count, but what was the problem, and which setting did you use to fix it?
Thanks in advance

@zippanto
Copy link

zippanto commented May 9, 2018

I was having the same issue. At the end I figured out the docker machine (I was using a VM in vSphere) doesn't have enough RAM. After adding more RAM it goes further. Now I've got an issue with 9200 port already in use on the docker machine.. but that's another issue.

@fowlert
Copy link

fowlert commented May 11, 2018

I also got unhealthy serviceapi on Macbook.

I then ran
% docker run -it --rm --privileged --pid=host justincormack/nsenter1
Then set sysctl settings as listed in install instructions.
(see https://github.com/justincormack/nsenter1)

After this, still got unhealthy error. I then increased the amount of memory from 2GB to 8GB in Docker/Preferences/Advanced. Then it worked.

@sochix
Copy link
Member

sochix commented May 11, 2018

The minimal ES requirements is > 2GB of RAM

@7c
Copy link

7c commented Jan 11, 2019

Same here memory issues was the cause of my 2hours problem. 1GB is not enough

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants