Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Too many open files with codenvy/che:nightly #143

Closed
freewind opened this issue Dec 29, 2015 · 21 comments
Closed

Too many open files with codenvy/che:nightly #143

freewind opened this issue Dec 29, 2015 · 21 comments
Labels
kind/question Questions that haven't been identified as being feature requests or bugs.

Comments

@freewind
Copy link

I have the same problem with this issue #140.

I run the image codenvy/che:nightly in a virtual box, which is running ubuntu 14.04, and the "open files" settings is increased as following:

scaleworks@ubuntu:~$ ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 31375
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 100000
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 200000
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

and append the following to /etc/security/limits.conf:

*                hard    nofile          100000
*                hard    nproc           200000
*                soft    nofile          100000
*                soft    nproc           200000

Then I start codenvy/che:nightly:

$ docker run -it -p 8080:8080 codenvy/che:nightly

It seems started correctly:

$ docker run -it -p 8080:8080 codenvy/che:nightly
 * Starting Docker: docker                                               [ OK ]
Using CATALINA_BASE:   /home/user/che/tomcat
Using CATALINA_HOME:   /home/user/che/tomcat
Using CATALINA_TMPDIR: /home/user/che/tomcat/temp
Using JRE_HOME:        /opt/jre1.8.0_65
Using CLASSPATH:       /home/user/che/tomcat/conf/:/opt/jre1.8.0_65/lib/tools.jar:/home/user/che/tomcat/bin/bootstrap.jar:/home/user/che/tomcat/bin/tomcat-juli.jar
2015-12-29 06:10:51,681[main]             [INFO ] [o.a.c.s.VersionLoggerListener 89]    - Server version:        Apache Tomcat/8.0.28
2015-12-29 06:10:51,683[main]             [INFO ] [o.a.c.s.VersionLoggerListener 91]    - Server built:          Oct 7 2015 18:25:21 UTC
2015-12-29 06:10:51,683[main]             [INFO ] [o.a.c.s.VersionLoggerListener 93]    - Server number:         8.0.28.0
2015-12-29 06:10:51,683[main]             [INFO ] [o.a.c.s.VersionLoggerListener 95]    - OS Name:               Linux
2015-12-29 06:10:51,684[main]             [INFO ] [o.a.c.s.VersionLoggerListener 97]    - OS Version:            3.13.0-32-generic
2015-12-29 06:10:51,684[main]             [INFO ] [o.a.c.s.VersionLoggerListener 99]    - Architecture:          amd64
2015-12-29 06:10:51,684[main]             [INFO ] [o.a.c.s.VersionLoggerListener 101]   - Java Home:             /opt/jre1.8.0_65
2015-12-29 06:10:51,684[main]             [INFO ] [o.a.c.s.VersionLoggerListener 103]   - JVM Version:           1.8.0_65-b17
2015-12-29 06:10:51,685[main]             [INFO ] [o.a.c.s.VersionLoggerListener 105]   - JVM Vendor:            Oracle Corporation
2015-12-29 06:10:51,685[main]             [INFO ] [o.a.c.s.VersionLoggerListener 107]   - CATALINA_BASE:         /home/user/che/tomcat
2015-12-29 06:10:51,685[main]             [INFO ] [o.a.c.s.VersionLoggerListener 109]   - CATALINA_HOME:         /home/user/che/tomcat
2015-12-29 06:10:51,685[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.config.file=/home/user/che/tomcat/conf/logging.properties
2015-12-29 06:10:51,686[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2015-12-29 06:10:51,687[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xms256m
2015-12-29 06:10:51,688[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xmx1024m
2015-12-29 06:10:51,688[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.logs.dir=/home/user/che/tomcat/logs/
2015-12-29 06:10:51,688[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote
2015-12-29 06:10:51,689[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.ssl=false
2015-12-29 06:10:51,689[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
2015-12-29 06:10:51,690[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.local.conf.dir=/home/user/.che
2015-12-29 06:10:51,690[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.home=/home/user/che
2015-12-29 06:10:51,690[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.endorsed.dirs=/home/user/che/tomcat/endorsed
2015-12-29 06:10:51,690[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.base=/home/user/che/tomcat
2015-12-29 06:10:51,690[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.home=/home/user/che/tomcat
2015-12-29 06:10:51,691[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.io.tmpdir=/home/user/che/tomcat/temp
2015-12-29 06:10:51,826[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 424]  - Initializing ProtocolHandler ["http-nio-8080"]
2015-12-29 06:10:51,835[main]             [INFO ] [o.a.t.util.net.NioSelectorPool 72]   - Using a shared selector for servlet write/read
2015-12-29 06:10:51,837[main]             [INFO ] [o.a.catalina.startup.Catalina 587]   - Initialization processed in 416 ms
2015-12-29 06:10:51,854[main]             [INFO ] [c.m.JmxRemoteLifecycleListener 332]  - The JMX Remote Listener has configured the registry on port 32001 and the server on port 32101 for the Platform server
2015-12-29 06:10:51,854[main]             [INFO ] [o.a.c.core.StandardService 433]      - Starting service Catalina
2015-12-29 06:10:51,854[main]             [INFO ] [o.a.c.core.StandardEngine 259]       - Starting Servlet Engine: Apache Tomcat/8.0.28
2015-12-29 06:10:51,910[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/che.war
2015-12-29 06:10:56,477[ost-startStop-1]  [INFO ] [.c.p.d.c.DockerRegistryChecker 43]   - Probing registry 'http://localhost:5000'
2015-12-29 06:10:56,487[ost-startStop-1]  [WARN ] [.c.p.d.c.DockerRegistryChecker 50]   - Docker registry http://localhost:5000 is not available, which means that you won't be able to save snapshots of your workspaces.
How to configure registry?
    Local registry  -> https://docs.docker.com/registry/
    Remote registry -> set up 'docker.registry.auth.*' properties
2015-12-29 06:10:58,125[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/che.war has finished in 6,215 ms
2015-12-29 06:10:58,131[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/dashboard.war
2015-12-29 06:10:58,305[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/dashboard.war has finished in 174 ms
2015-12-29 06:10:58,307[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1036]       - Deploying web application directory /home/user/che/tomcat/webapps/ROOT
2015-12-29 06:10:58,386[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1152]       - Deployment of web application directory /home/user/che/tomcat/webapps/ROOT has finished in 79 ms
2015-12-29 06:10:58,394[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 469]  - Starting ProtocolHandler ["http-nio-8080"]
2015-12-29 06:10:58,401[main]             [INFO ] [o.a.catalina.startup.Catalina 638]   - Server startup in 6562 ms

But now I can't run any commands, even the simplest ls:

$ ls
-bash: start_pipeline: pgrp pipe: Too many open files in system
-bash: /bin/ls: Too many open files in system

Then I visit the che from browser:

http://10.202.128.49:8080/

It doesn't show anything, instead, I can see many "Too many open files in system" showing on the log:

2015-12-29 06:10:58,401[main]             [INFO ] [o.a.catalina.startup.Catalina 638]   - Server startup in 6562 ms

2015-12-29 06:11:26,236[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2015-12-29 06:11:26,289[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2015-12-29 06:11:26,392[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]

I tried to docker ps but failed:

-bash: start_pipeline: pgrp pipe: Too many open files in system
-bash: /usr/bin/docker: Too many open files in system
@freewind freewind changed the title Too many open files Too many open files with codenvy/che;nightly Dec 29, 2015
@freewind freewind changed the title Too many open files with codenvy/che;nightly Too many open files with codenvy/che:nightly Dec 29, 2015
@wu560130911
Copy link

2015-12-29 06:10:56,487[ost-startStop-1] [WARN ] [.c.p.d.c.DockerRegistryChecker 50] - Docker registry http://localhost:5000 is not available, which means that you won't be able to save snapshots of your workspaces.
How to configure registry?
Local registry -> https://docs.docker.com/registry/
Remote registry -> set up 'docker.registry.auth.*' properties

@freewind
Copy link
Author

@wu560130911 Not understand why you quote this warning? It should not related to the "too many open files" issue

@TylerJewell
Copy link

I periodically run into this issue, but have been unable to cause it to happen reliably. In doing research on it, there are some additional fixes. On the host system:

  1. update the /etc/security/limits.conf to include :* - nofile 64000
  2. add to your /etc/sysctl.conf : fs.file-max = 64000
  3. restart sysctl : sudo sysctl -p
  4. restart the docker daemon

Also, though I believe it is unrelated, you will need to start Che with --privileged mode.

I am going to spend some time this afternoon attempting to reliably recreate the too many open files circumstances so that we can put some tests around it and also explore different solutions.

@freewind
Copy link
Author

@TylerJewell Thanks very much, I will try it tomorrow ~

@TylerJewell
Copy link

Sure thing. It should be noted that running Che inside of a Docker
container is provided for experimentation. When running Che in production,
we only run the server natively. Docker is awesome for quick start, but it
does pose interesting issues:

  1. All state is inside the container, so you need to snapshot to retain
    state. Initial snapshots take forever.
  2. You need to mount your projects outside the container, so that is more
    configuration.
  3. Lots of port mapping to be managed
  4. And since Che launches docker itself, you need --privileged mode.

But we wnat to make this work, so I also think it's a great test case &
exercise.

Tyler Jewell | CEO | tyler@​codenvy.​com | 9​78​.8​84​.53​55

On Tue, Dec 29, 2015 at 1:02 PM, freewind notifications@github.com wrote:

@TylerJewell https://github.com/TylerJewell Thanks very much, I will
try it tomorrow ~


Reply to this email directly or view it on GitHub
#143 (comment).

@ghost
Copy link

ghost commented Dec 30, 2015

You do not run the image in the right way. --privileged flag is Mandatory for Docker to start inside a Docker container.

Please, check docs - https://eclipse-che.readme.io/v4.0/docs/install-using-docker

@freewind
Copy link
Author

@eivantsov Yes, you right right!! Sorry for my stupid mistake. But the error is too misleading 😭

@TylerJewell
Copy link

We have been working on a new set of che startup scripts that will start
Che either in native mode or as a Docker image.

This will prevent these sorts of startup mistakes from happening.

If you want to test it, you can check out branch IDEX-3975. The che.bat
and che.sh scripts should have self-explanatory help at that point.

These scripts also take care to start virtualbox, docker-machine, and
docker if it's not started, too along with all environmental setup.

Tyler Jewell | CEO | tyler@​codenvy.​com | 9​78​.8​84​.53​55

On Wed, Dec 30, 2015 at 6:56 PM, freewind notifications@github.com wrote:

@eivantsov https://github.com/eivantsov Yes, you right right!! Sorry
for my stupid mistake. But the error is too misleading [image: 👎]


Reply to this email directly or view it on GitHub
#143 (comment).

@freewind
Copy link
Author

@TylerJewell Thanks, that's great! I will try it later, these scripts are really helpful for docker newbies

@freewind
Copy link
Author

@eivantsov Sometimes the "too many open files" error still appear even if I set --privileged

@ghost
Copy link

ghost commented Jan 1, 2016

Sometimes? Under what conditions?

@freewind
Copy link
Author

freewind commented Jan 1, 2016

@eivantsov It didn't happen today. "Sometimes" means I didn't change anything, only restart the container with the same command, it reported that error, but I can't remember the details.

I will reopen this next time I see it

@freewind freewind closed this as completed Jan 1, 2016
@freewind
Copy link
Author

freewind commented Jan 1, 2016

It is suddenly report "too many open files". I didn't do anything special, just kill previous container and run it again (it was OK last time).

The command is:

docker run -it --privileged -e DOCKER_MACHINE_HOST=159.203.222.119 -p 8080:8080 -p 32768-32788:32768-32788 codenvy/che:nightly

The log is:

twer@ubuntu-4gb-sfo1-01:~$ docker run -it --privileged -e DOCKER_MACHINE_HOST=159.203.222.119 -p 8080:8080 -p 32768-32788:32768-32788 codenvy/che:nightly
 * Starting Docker: docker                                                        [ OK ]
Using CATALINA_BASE:   /home/user/che/tomcat
Using CATALINA_HOME:   /home/user/che/tomcat
Using CATALINA_TMPDIR: /home/user/che/tomcat/temp
Using JRE_HOME:        /opt/jre1.8.0_65
Using CLASSPATH:       /home/user/che/tomcat/conf/:/opt/jre1.8.0_65/lib/tools.jar:/home/user/che/tomcat/bin/bootstrap.jar:/home/user/che/tomcat/bin/tomcat-juli.jar
2016-01-01 16:39:47,343[main]             [INFO ] [o.a.c.s.VersionLoggerListener 89]    - Server version:        Apache Tomcat/8.0.28
2016-01-01 16:39:47,347[main]             [INFO ] [o.a.c.s.VersionLoggerListener 91]    - Server built:          Oct 7 2015 18:25:21 UTC
2016-01-01 16:39:47,347[main]             [INFO ] [o.a.c.s.VersionLoggerListener 93]    - Server number:         8.0.28.0
2016-01-01 16:39:47,348[main]             [INFO ] [o.a.c.s.VersionLoggerListener 95]    - OS Name:               Linux
2016-01-01 16:39:47,348[main]             [INFO ] [o.a.c.s.VersionLoggerListener 97]    - OS Version:            3.13.0-71-generic
2016-01-01 16:39:47,349[main]             [INFO ] [o.a.c.s.VersionLoggerListener 99]    - Architecture:          amd64
2016-01-01 16:39:47,362[main]             [INFO ] [o.a.c.s.VersionLoggerListener 101]   - Java Home:             /opt/jre1.8.0_65
2016-01-01 16:39:47,363[main]             [INFO ] [o.a.c.s.VersionLoggerListener 103]   - JVM Version:           1.8.0_65-b17
2016-01-01 16:39:47,363[main]             [INFO ] [o.a.c.s.VersionLoggerListener 105]   - JVM Vendor:            Oracle Corporation
2016-01-01 16:39:47,364[main]             [INFO ] [o.a.c.s.VersionLoggerListener 107]   - CATALINA_BASE:         /home/user/che/tomcat
2016-01-01 16:39:47,364[main]             [INFO ] [o.a.c.s.VersionLoggerListener 109]   - CATALINA_HOME:         /home/user/che/tomcat
2016-01-01 16:39:47,365[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.config.file=/home/user/che/tomcat/conf/logging.properties
2016-01-01 16:39:47,366[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2016-01-01 16:39:47,369[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xms256m
2016-01-01 16:39:47,369[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xmx1024m
2016-01-01 16:39:47,370[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.logs.dir=/home/user/che/tomcat/logs/
2016-01-01 16:39:47,371[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote
2016-01-01 16:39:47,372[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.ssl=false
2016-01-01 16:39:47,373[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
2016-01-01 16:39:47,374[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.local.conf.dir=/home/user/.che
2016-01-01 16:39:47,374[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.home=/home/user/che
2016-01-01 16:39:47,375[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.endorsed.dirs=/home/user/che/tomcat/endorsed
2016-01-01 16:39:47,384[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.base=/home/user/che/tomcat
2016-01-01 16:39:47,384[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.home=/home/user/che/tomcat
2016-01-01 16:39:47,385[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.io.tmpdir=/home/user/che/tomcat/temp
2016-01-01 16:39:47,654[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 424]  - Initializing ProtocolHandler ["http-nio-8080"]
2016-01-01 16:39:47,676[main]             [INFO ] [o.a.t.util.net.NioSelectorPool 72]   - Using a shared selector for servlet write/read
2016-01-01 16:39:47,679[main]             [INFO ] [o.a.catalina.startup.Catalina 587]   - Initialization processed in 829 ms
2016-01-01 16:39:47,712[main]             [INFO ] [c.m.JmxRemoteLifecycleListener 332]  - The JMX Remote Listener has configured the registry on port 32001 and the server on port 32101 for the Platform server
2016-01-01 16:39:47,713[main]             [INFO ] [o.a.c.core.StandardService 433]      - Starting service Catalina
2016-01-01 16:39:47,799[main]             [INFO ] [o.a.c.core.StandardEngine 259]       - Starting Servlet Engine: Apache Tomcat/8.0.28
2016-01-01 16:39:47,893[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/dashboard.war
2016-01-01 16:45:54,178[ost-startStop-1]  [INFO ] [o.a.c.u.SessionIdGeneratorBase 241]  - Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [365,790] milliseconds.
2016-01-01 16:45:54,202[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/dashboard.war has finished in 366,309 ms
2016-01-01 16:45:54,206[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/che.war
2016-01-01 16:46:02,314[ost-startStop-1]  [INFO ] [.c.p.d.c.DockerRegistryChecker 43]   - Probing registry 'http://localhost:5000'
2016-01-01 16:46:02,350[ost-startStop-1]  [WARN ] [.c.p.d.c.DockerRegistryChecker 50]   - Docker registry http://localhost:5000 is not available, which means that you won't be able to save snapshots of your workspaces.
How to configure registry?
    Local registry  -> https://docs.docker.com/registry/
    Remote registry -> set up 'docker.registry.auth.*' properties
2016-01-01 16:46:04,129[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/che.war has finished in 9,923 ms
2016-01-01 16:46:04,140[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1036]       - Deploying web application directory /home/user/che/tomcat/webapps/ROOT
2016-01-01 16:46:04,237[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1152]       - Deployment of web application directory /home/user/che/tomcat/webapps/ROOT has finished in 97 ms
2016-01-01 16:46:04,244[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 469]  - Starting ProtocolHandler ["http-nio-8080"]
2016-01-01 16:46:04,264[main]             [INFO ] [o.a.catalina.startup.Catalina 638]   - Server startup in 376584 ms
2016-01-01 16:46:05,167[nio-8080-exec-6]  [WARN ] [i.ContainerResponse$BodyWriter 90]   - Client has aborted connection. Response writing omitted.
2016-01-01 16:47:26,642[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-01 16:47:26,701[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-01 16:47:26,804[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-01 16:47:27,008[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-01 16:47:27,412[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-01 16:47:28,216[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]

I can't see if is the memory run up, because no matter I input any command, it show the same error:

twer@ubuntu-4gb-sfo1-01:~$ top
-bash: start_pipeline: pgrp pipe: Too many open files in system
-bash: /usr/bin/top: Too many open files in system

@freewind freewind reopened this Jan 1, 2016
@ghost
Copy link

ghost commented Jan 1, 2016

I just tried it on freshly created machines on Digital Ocean and Azure, and failed to reproduce it.

-bash: start_pipeline: pgrp pipe: Too many open files in system - is this on your host or in a container?

Can you exec into a container after it has been started and run docker info there?

@freewind
Copy link
Author

freewind commented Jan 2, 2016

It's from the log of the docker container which runs the che.

Can you exec into a container after it has been started and run docker info there?

Sorry, when I see that errors, I can't do anything on the host. Even a simple ls command will fail and also reports "too many open files" error, so I can't exec into the container.

I have to kill the container by press "ctrl + c", and then I can execute other linux commands

Maybe I can record it next time and share to you

@ghost
Copy link

ghost commented Jan 2, 2016

It is a host problem then. I have tried to reproduce it on different environments - no luck. It is possible that when a container starts it consumes hosts resources that may be insufficient.

@freewind
Copy link
Author

freewind commented Jan 5, 2016

Just now, it happens one time again. But if I ctrl+c to cancel it and run it again, it works well:

twer@ubuntu-4gb-sfo1-01:/media$ docker run -it --privileged -e DOCKER_MACHINE_HOST=159.203.222.119 -p 8080:8080 -p 32768-32788:32768-32788 codenvy/che:nightly
 * Starting Docker: docker                                               [ OK ]
Using CATALINA_BASE:   /home/user/che/tomcat
Using CATALINA_HOME:   /home/user/che/tomcat
Using CATALINA_TMPDIR: /home/user/che/tomcat/temp
Using JRE_HOME:        /opt/jre1.8.0_65
Using CLASSPATH:       /home/user/che/tomcat/conf/:/opt/jre1.8.0_65/lib/tools.jar:/home/user/che/tomcat/bin/bootstrap.jar:/home/user/che/tomcat/bin/tomcat-juli.jar
2016-01-05 03:34:21,469[main]             [INFO ] [o.a.c.s.VersionLoggerListener 89]    - Server version:        Apache Tomcat/8.0.28
2016-01-05 03:34:21,474[main]             [INFO ] [o.a.c.s.VersionLoggerListener 91]    - Server built:          Oct 7 2015 18:25:21 UTC
2016-01-05 03:34:21,475[main]             [INFO ] [o.a.c.s.VersionLoggerListener 93]    - Server number:         8.0.28.0
2016-01-05 03:34:21,476[main]             [INFO ] [o.a.c.s.VersionLoggerListener 95]    - OS Name:               Linux
2016-01-05 03:34:21,477[main]             [INFO ] [o.a.c.s.VersionLoggerListener 97]    - OS Version:            3.13.0-71-generic
2016-01-05 03:34:21,478[main]             [INFO ] [o.a.c.s.VersionLoggerListener 99]    - Architecture:          amd64
2016-01-05 03:34:21,479[main]             [INFO ] [o.a.c.s.VersionLoggerListener 101]   - Java Home:             /opt/jre1.8.0_65
2016-01-05 03:34:21,480[main]             [INFO ] [o.a.c.s.VersionLoggerListener 103]   - JVM Version:           1.8.0_65-b17
2016-01-05 03:34:21,481[main]             [INFO ] [o.a.c.s.VersionLoggerListener 105]   - JVM Vendor:            Oracle Corporation
2016-01-05 03:34:21,482[main]             [INFO ] [o.a.c.s.VersionLoggerListener 107]   - CATALINA_BASE:         /home/user/che/tomcat
2016-01-05 03:34:21,482[main]             [INFO ] [o.a.c.s.VersionLoggerListener 109]   - CATALINA_HOME:         /home/user/che/tomcat
2016-01-05 03:34:21,483[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.config.file=/home/user/che/tomcat/conf/logging.properties
2016-01-05 03:34:21,485[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2016-01-05 03:34:21,488[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xms256m
2016-01-05 03:34:21,490[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xmx1024m
2016-01-05 03:34:21,491[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.logs.dir=/home/user/che/tomcat/logs/
2016-01-05 03:34:21,492[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote
2016-01-05 03:34:21,499[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.ssl=false
2016-01-05 03:34:21,502[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
2016-01-05 03:34:21,503[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.local.conf.dir=/home/user/.che
2016-01-05 03:34:21,503[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.home=/home/user/che
2016-01-05 03:34:21,504[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.endorsed.dirs=/home/user/che/tomcat/endorsed
2016-01-05 03:34:21,505[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.base=/home/user/che/tomcat
2016-01-05 03:34:21,506[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.home=/home/user/che/tomcat
2016-01-05 03:34:21,508[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.io.tmpdir=/home/user/che/tomcat/temp
2016-01-05 03:34:21,826[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 424]  - Initializing ProtocolHandler ["http-nio-8080"]
2016-01-05 03:34:21,867[main]             [INFO ] [o.a.t.util.net.NioSelectorPool 72]   - Using a shared selector for servlet write/read
2016-01-05 03:34:21,883[main]             [INFO ] [o.a.catalina.startup.Catalina 587]   - Initialization processed in 916 ms
2016-01-05 03:34:34,442[main]             [INFO ] [c.m.JmxRemoteLifecycleListener 332]  - The JMX Remote Listener has configured the registry on port 32001 and the server on port 32101 for the Platform server
2016-01-05 03:34:34,444[main]             [INFO ] [o.a.c.core.StandardService 433]      - Starting service Catalina
2016-01-05 03:34:34,445[main]             [INFO ] [o.a.c.core.StandardEngine 259]       - Starting Servlet Engine: Apache Tomcat/8.0.28
2016-01-05 03:34:34,538[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/dashboard.war
2016-01-05 03:37:25,187[ost-startStop-1]  [INFO ] [o.a.c.u.SessionIdGeneratorBase 241]  - Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [170,108] milliseconds.
2016-01-05 03:37:25,223[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/dashboard.war has finished in 170,684 ms
2016-01-05 03:37:25,229[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/che.war
2016-01-05 03:37:34,188[ost-startStop-1]  [INFO ] [.c.p.d.c.DockerRegistryChecker 43]   - Probing registry 'http://localhost:5000'
2016-01-05 03:37:34,222[ost-startStop-1]  [WARN ] [.c.p.d.c.DockerRegistryChecker 50]   - Docker registry http://localhost:5000 is not available, which means that you won't be able to save snapshots of your workspaces.
How to configure registry?
    Local registry  -> https://docs.docker.com/registry/
    Remote registry -> set up 'docker.registry.auth.*' properties
2016-01-05 03:37:36,017[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/che.war has finished in 10,788 ms
2016-01-05 03:37:36,026[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1036]       - Deploying web application directory /home/user/che/tomcat/webapps/ROOT
2016-01-05 03:37:36,116[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1152]       - Deployment of web application directory /home/user/che/tomcat/webapps/ROOT has finished in 89 ms
2016-01-05 03:37:36,143[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 469]  - Starting ProtocolHandler ["http-nio-8080"]
2016-01-05 03:37:36,167[main]             [INFO ] [o.a.catalina.startup.Catalina 638]   - Server startup in 194282 ms
2016-01-05 04:01:22,846[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:22,902[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:23,009[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:23,210[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:23,611[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:24,416[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:26,024[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:27,632[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:29,236[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:30,841[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
2016-01-05 04:01:32,446[8080-Acceptor-0]  [ERROR] [o.a.t.util.net.NioEndpoint 709]      - Socket accept failed
java.io.IOException: Too many open files in system
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[na:1.8.0_65]
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[na:1.8.0_65]
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) ~[tomcat-coyote.jar:8.0.28]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
^C2016-01-05 04:01:33,757[Thread-3]         [INFO ] [o.a.c.http11.Http11NioProtocol 484]  - Pausing ProtocolHandler ["http-nio-8080"]
2016-01-05 04:01:33,762[Thread-3]         [INFO ] [o.a.c.core.StandardService 495]      - Stopping service Catalina
2016-01-05 04:01:33,869[ost-startStop-2]  [ERROR] [o.a.c.c.C.[.[localhost].[/che] 4791] - Exception sending context destroyed event to listener instance of class org.eclipse.che.inject.CodenvyBootstrap
java.lang.NoClassDefFoundError: org/everrest/core/impl/FileCollectorDestroyer
    at org.everrest.guice.servlet.EverrestGuiceContextListener.makeFileCollectorDestroyer(EverrestGuiceContextListener.java:131) ~[everrest-integration-guice-1.10.0.jar:na]
    at org.everrest.guice.servlet.EverrestGuiceContextListener.contextDestroyed(EverrestGuiceContextListener.java:122) ~[everrest-integration-guice-1.10.0.jar:na]
    at org.eclipse.che.inject.CheBootstrap.contextDestroyed(CheBootstrap.java:112) ~[che-core-commons-inject-4.0.0-beta-3-SNAPSHOT.jar:4.0.0-beta-3-SNAPSHOT]
    at org.apache.catalina.core.StandardContext.listenerStop(StandardContext.java:4785) [catalina.jar:8.0.28]
    at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5404) [catalina.jar:8.0.28]
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:232) [catalina.jar:8.0.28]
    at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1424) [catalina.jar:8.0.28]
    at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1413) [catalina.jar:8.0.28]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_65]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_65]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_65]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
Caused by: java.lang.ClassNotFoundException: org.everrest.core.impl.FileCollectorDestroyer
    at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1333) ~[catalina.jar:8.0.28]
    at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1167) ~[catalina.jar:8.0.28]
    ... 12 common frames omitted
2016-01-05 04:01:33,890[Thread-3]         [INFO ] [o.a.c.http11.Http11NioProtocol 513]  - Stopping ProtocolHandler ["http-nio-8080"]
^C2016-01-05 04:01:33,958[Thread-3]         [INFO ] [o.a.c.http11.Http11NioProtocol 528]  - Destroying ProtocolHandler ["http-nio-8080"]
twer@ubuntu-4gb-sfo1-01:/media$ docker run -it --privileged -e DOCKER_MACHINE_HOST=159.203.222.119 -p 8080:8080 -p 32768-32788:32768-32788 codenvy/che:nightly
 * Starting Docker: docker                                                        [ OK ]
Using CATALINA_BASE:   /home/user/che/tomcat
Using CATALINA_HOME:   /home/user/che/tomcat
Using CATALINA_TMPDIR: /home/user/che/tomcat/temp
Using JRE_HOME:        /opt/jre1.8.0_65
Using CLASSPATH:       /home/user/che/tomcat/conf/:/opt/jre1.8.0_65/lib/tools.jar:/home/user/che/tomcat/bin/bootstrap.jar:/home/user/che/tomcat/bin/tomcat-juli.jar
2016-01-05 04:03:21,054[main]             [INFO ] [o.a.c.s.VersionLoggerListener 89]    - Server version:        Apache Tomcat/8.0.28
2016-01-05 04:03:21,069[main]             [INFO ] [o.a.c.s.VersionLoggerListener 91]    - Server built:          Oct 7 2015 18:25:21 UTC
2016-01-05 04:03:21,072[main]             [INFO ] [o.a.c.s.VersionLoggerListener 93]    - Server number:         8.0.28.0
2016-01-05 04:03:21,075[main]             [INFO ] [o.a.c.s.VersionLoggerListener 95]    - OS Name:               Linux
2016-01-05 04:03:21,078[main]             [INFO ] [o.a.c.s.VersionLoggerListener 97]    - OS Version:            3.13.0-71-generic
2016-01-05 04:03:21,080[main]             [INFO ] [o.a.c.s.VersionLoggerListener 99]    - Architecture:          amd64
2016-01-05 04:03:21,083[main]             [INFO ] [o.a.c.s.VersionLoggerListener 101]   - Java Home:             /opt/jre1.8.0_65
2016-01-05 04:03:21,086[main]             [INFO ] [o.a.c.s.VersionLoggerListener 103]   - JVM Version:           1.8.0_65-b17
2016-01-05 04:03:21,088[main]             [INFO ] [o.a.c.s.VersionLoggerListener 105]   - JVM Vendor:            Oracle Corporation
2016-01-05 04:03:21,091[main]             [INFO ] [o.a.c.s.VersionLoggerListener 107]   - CATALINA_BASE:         /home/user/che/tomcat
2016-01-05 04:03:21,093[main]             [INFO ] [o.a.c.s.VersionLoggerListener 109]   - CATALINA_HOME:         /home/user/che/tomcat
2016-01-05 04:03:21,098[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.config.file=/home/user/che/tomcat/conf/logging.properties
2016-01-05 04:03:21,101[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2016-01-05 04:03:21,104[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xms256m
2016-01-05 04:03:21,106[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xmx1024m
2016-01-05 04:03:21,109[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.logs.dir=/home/user/che/tomcat/logs/
2016-01-05 04:03:21,112[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote
2016-01-05 04:03:21,114[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.ssl=false
2016-01-05 04:03:21,117[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
2016-01-05 04:03:21,119[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.local.conf.dir=/home/user/.che
2016-01-05 04:03:21,122[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.home=/home/user/che
2016-01-05 04:03:21,133[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.endorsed.dirs=/home/user/che/tomcat/endorsed
2016-01-05 04:03:21,140[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.base=/home/user/che/tomcat
2016-01-05 04:03:21,145[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.home=/home/user/che/tomcat
2016-01-05 04:03:21,149[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.io.tmpdir=/home/user/che/tomcat/temp
2016-01-05 04:03:22,286[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 424]  - Initializing ProtocolHandler ["http-nio-8080"]
2016-01-05 04:03:22,879[main]             [INFO ] [o.a.t.util.net.NioSelectorPool 72]   - Using a shared selector for servlet write/read
2016-01-05 04:03:22,914[main]             [INFO ] [o.a.catalina.startup.Catalina 587]   - Initialization processed in 4236 ms
2016-01-05 04:03:23,197[main]             [INFO ] [c.m.JmxRemoteLifecycleListener 332]  - The JMX Remote Listener has configured the registry on port 32001 and the server on port 32101 for the Platform server
2016-01-05 04:03:23,204[main]             [INFO ] [o.a.c.core.StandardService 433]      - Starting service Catalina
2016-01-05 04:03:23,206[main]             [INFO ] [o.a.c.core.StandardEngine 259]       - Starting Servlet Engine: Apache Tomcat/8.0.28
2016-01-05 04:03:24,041[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/dashboard.war
2016-01-05 04:07:30,407[ost-startStop-1]  [INFO ] [o.a.c.u.SessionIdGeneratorBase 241]  - Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [243,128] milliseconds.
2016-01-05 04:07:30,446[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/dashboard.war has finished in 246,405 ms
2016-01-05 04:07:30,451[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 916]        - Deploying web application archive /home/user/che/tomcat/webapps/che.war
2016-01-05 04:07:38,559[ost-startStop-1]  [INFO ] [.c.p.d.c.DockerRegistryChecker 43]   - Probing registry 'http://localhost:5000'
2016-01-05 04:07:38,588[ost-startStop-1]  [WARN ] [.c.p.d.c.DockerRegistryChecker 50]   - Docker registry http://localhost:5000 is not available, which means that you won't be able to save snapshots of your workspaces.
How to configure registry?
    Local registry  -> https://docs.docker.com/registry/
    Remote registry -> set up 'docker.registry.auth.*' properties
2016-01-05 04:07:39,802[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 980]        - Deployment of web application archive /home/user/che/tomcat/webapps/che.war has finished in 9,351 ms
2016-01-05 04:07:39,803[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1036]       - Deploying web application directory /home/user/che/tomcat/webapps/ROOT
2016-01-05 04:07:39,883[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1152]       - Deployment of web application directory /home/user/che/tomcat/webapps/ROOT has finished in 80 ms
2016-01-05 04:07:39,895[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 469]  - Starting ProtocolHandler ["http-nio-8080"]
2016-01-05 04:07:39,916[main]             [INFO ] [o.a.catalina.startup.Catalina 638]   - Server startup in 256999 ms

And we have enough resources this time:

top - 00:42:00 up 3 days, 23:49,  3 users,  load average: 0.00, 0.01, 0.05
Tasks: 150 total,   1 running, 149 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.2 us,  0.0 sy,  0.0 ni, 99.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:   4048268 total,  3528552 used,   519716 free,     8244 buffers
KiB Swap: 10485756 total,        0 used, 10485756 free.  2500076 cached Mem
twer@ubuntu-4gb-sfo1-01:~$ ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 31559
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 100000
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 200000
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

Seems it happens quite randomly.

It has never happened in my mac + virtual box, but happened in digital-ocean and another could host managed by our company.

@ghost
Copy link

ghost commented Jan 6, 2016

Just checked it with Digital Ocean - Che started just fine. The issue is with starting Docker in Docker - it looks like this does not work well in all environments.

@ghost
Copy link

ghost commented Jan 25, 2016

@freewind can you still repeatedly reproduce this issue? Only with Digital Ocean or locally as well?

@ddementieva ddementieva added the kind/question Questions that haven't been identified as being feature requests or bugs. label Jan 26, 2016
@TylerJewell
Copy link

@freewind See the pull request #257 as a way that will help eliminate this issue.

@ghost
Copy link

ghost commented Feb 21, 2016

@freewind I think after switching to a a no-docker-in-docker image the problem fixed itself.

Closing the issue since we do not start Docker in Docker anymore.

@ghost ghost closed this as completed Feb 21, 2016
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/question Questions that haven't been identified as being feature requests or bugs.
Projects
None yet
Development

No branches or pull requests

4 participants