Closed aleksei-burlakov closed 7 years ago
@aleksei-burakov does it happen to every stack that you start? Does it happen immediately after workspace agent starts or you do smth in a workspace, e.g. run commands and only then it happens? How much RAM have you allocated for a workspace?
I have tried it with blank, Java, Java-Mysql, C++ and custom stacks. I did not change the default settings for the blank, Java, Java-Mysql, C++ stacks and I have allocated 4 gigs for the custom stack which bases on codenvy/ubuntu_jdk8 image with some minor changes. It happens when a workspace starts. It runs for some time ok and interrupts immediately after the last line of output you see on the screenshot occures.
@aleksei-burakov can you provide server logs?
@aleksei-burakov can you try launching che this way:
docker run -ti -v /var/run/docker.sock:/var/run/docker.sock -v $(pwd):/data eclipse/che-cli:nightly start
You may replace $(pwd)
with a path to any local directory where you want to store Che config and data.
docker run -ti -v /var/run/docker.sock:/var/run/docker.sock -v ~/che/config:/data eclipse/che-cli:nightly start
has written into ~/che/config/cli.log
the following
Wed Jan 4 14:43:37 UTC 2017
INFO: (che cli): Checking network... (hint: '--fast' skips version and network checks)
/usr/bin/curl --noproxy 10.44.108.110 "-I -k dockerhub.com -s -o /dev/null --write-out %{http_code}"
INFO: (che cli): Loading cli...
DEBUG: docker_run
DEBUG: is_boot2docker
DEBUG: is_initialized
/usr/bin/curl --noproxy 10.44.108.110 "-s https://hub.docker.com/v2/repositories/eclipse/che-cli/tags/nightly/"
Wed Jan 4 14:44:09 UTC 2017
INFO: (che cli): Checking network... (hint: '--fast' skips version and network checks)
/usr/bin/curl --noproxy 10.44.108.110 "-I -k dockerhub.com -s -o /dev/null --write-out %{http_code}"
INFO: (che cli): Loading cli...
DEBUG: docker_run
DEBUG: is_boot2docker
DEBUG: is_initialized
/usr/bin/curl --noproxy 10.44.108.110 "-s https://hub.docker.com/v2/repositories/eclipse/che-cli/tags/nightly/"
I started che
$ docker run -it --rm -e CHE_HOST=10.44.108.110 -v /var/run/docker.sock:/var/run/docker.sock -v ~/che:/che eclipse/che-cli start
then started the BLANK workspace and I got the following output
[DOCKER] latest: Pulling from codenvy/ubuntu_jdk8
[DOCKER] Digest: sha256:018f74a9a6f407f10c2815c39fb965f9dea8a1acb0f5cd2de7ef1ec32f133ed5
[DOCKER] Status: Image is up to date for codenvy/ubuntu_jdk8:latest
Listening for transport dt_socket at address: 4403
2017-01-04 14:48:20,879[main] [INFO ] [o.a.c.s.VersionLoggerListener 89] - Server version: Apache Tomcat/8.0.38
2017-01-04 14:48:20,884[main] [INFO ] [o.a.c.s.VersionLoggerListener 91] - Server built: Oct 6 2016 20:51:55 UTC
2017-01-04 14:48:20,885[main] [INFO ] [o.a.c.s.VersionLoggerListener 93] - Server number: 8.0.38.0
2017-01-04 14:48:20,885[main] [INFO ] [o.a.c.s.VersionLoggerListener 95] - OS Name: Linux
2017-01-04 14:48:20,886[main] [INFO ] [o.a.c.s.VersionLoggerListener 97] - OS Version: 4.4.0-57-generic
2017-01-04 14:48:20,887[main] [INFO ] [o.a.c.s.VersionLoggerListener 99] - Architecture: amd64
2017-01-04 14:48:20,888[main] [INFO ] [o.a.c.s.VersionLoggerListener 101] - Java Home: /opt/jdk1.8.0_45/jre
2017-01-04 14:48:20,888[main] [INFO ] [o.a.c.s.VersionLoggerListener 103] - JVM Version: 1.8.0_45-b14
2017-01-04 14:48:20,889[main] [INFO ] [o.a.c.s.VersionLoggerListener 105] - JVM Vendor: Oracle Corporation
2017-01-04 14:48:20,889[main] [INFO ] [o.a.c.s.VersionLoggerListener 107] - CATALINA_BASE: /home/user/che/ws-agent
2017-01-04 14:48:20,890[main] [INFO ] [o.a.c.s.VersionLoggerListener 109] - CATALINA_HOME: /home/user/che/ws-agent
2017-01-04 14:48:20,892[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.util.logging.config.file=/home/user/che/ws-agent/conf/logging.properties
2017-01-04 14:48:20,893[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2017-01-04 14:48:20,893[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Xms256m
2017-01-04 14:48:20,894[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Xmx2048m
2017-01-04 14:48:20,895[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.security.egd=file:/dev/./urandom
2017-01-04 14:48:20,895[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dche.logs.dir=/home/user/che/ws-agent/logs
2017-01-04 14:48:20,896[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
2017-01-04 14:48:20,896[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
2017-01-04 14:48:20,897[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -agentlib:jdwp=transport=dt_socket,address=4403,server=y,suspend=n
2017-01-04 14:48:20,898[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcom.sun.management.jmxremote
2017-01-04 14:48:20,898[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcom.sun.management.jmxremote.ssl=false
2017-01-04 14:48:20,899[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
2017-01-04 14:48:20,900[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dche.local.conf.dir=/mnt/che/conf
2017-01-04 14:48:20,901[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.endorsed.dirs=/home/user/che/ws-agent/endorsed
2017-01-04 14:48:20,901[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcatalina.base=/home/user/che/ws-agent
2017-01-04 14:48:20,902[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcatalina.home=/home/user/che/ws-agent
2017-01-04 14:48:20,902[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.io.tmpdir=/home/user/che/ws-agent/temp
2017-01-04 14:48:21,505[main] [INFO ] [o.a.c.http11.Http11NioProtocol 443] - Initializing ProtocolHandler ["http-nio-4401"]
2017-01-04 14:48:21,566[main] [INFO ] [o.a.t.util.net.NioSelectorPool 72] - Using a shared selector for servlet write/read
2017-01-04 14:48:21,572[main] [INFO ] [o.a.catalina.startup.Catalina 591] - Initialization processed in 1228 ms
2017-01-04 14:48:21,719[main] [INFO ] [c.m.JmxRemoteLifecycleListener 332] - The JMX Remote Listener has configured the registry on port 32002 and the server on port 32102 for the Platform server
2017-01-04 14:48:21,720[main] [INFO ] [o.a.c.core.StandardService 435] - Starting service Catalina
2017-01-04 14:48:21,721[main] [INFO ] [o.a.c.core.StandardEngine 259] - Starting Servlet Engine: Apache Tomcat/8.0.38
2017-01-04 14:48:21,849[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 911] - Deploying web application archive /home/user/che/ws-agent/webapps/ROOT.war
Wed Jan 04 14:48:41 UTC 2017 - [localhost-startStop-1] Product-specified preferences called before plugin is started
2017-01-04 14:48:41,853[ost-startStop-1] [INFO ] [.e.c.a.v.i.f.e.LoEventListener 48] - Subscribing to event service: class org.eclipse.che.api.vfs.impl.file.event.LoEventListener
2017-01-04 14:48:41,878[ost-startStop-1] [INFO ] [.e.c.a.v.i.f.e.VfsEventService 58] - Starting virtual file system event service: LoEventService
2017-01-04 14:48:41,883[ost-startStop-1] [INFO ] [.e.c.a.v.i.f.e.VfsEventService 58] - Starting virtual file system event service: HiEventService
2017-01-04 14:48:42,238[rest.WSClient-0] [INFO ] [.c.a.c.n.WSocketEventBusClient 227] - Open connection to ws://che-host:8080/wsmaster/api/eventbus/?token=dummy_token.
2017-01-04 14:48:43,637[s polled Thread] [INFO ] [o.e.c.p.m.server.rmi.RmiClient 130] - Port/Name:11919/MavenRemoteServerImplb56e2302
2017-01-04 14:48:48,245[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 975] - Deployment of web application archive /home/user/che/ws-agent/webapps/ROOT.war has finished in 26,390 ms
2017-01-04 14:48:48,272[main] [INFO ] [o.a.c.http11.Http11NioProtocol 488] - Starting ProtocolHandler ["http-nio-4401"]
2017-01-04 14:48:48,285[main] [INFO ] [o.a.catalina.startup.Catalina 642] - Server startup in 26712 ms
2017-01-04 14:48:49,706[nio-4401-exec-7] [WARN ] [o.e.c.impl.ContainerResponse 93] - Client has aborted connection. Response writing omitted.
2017-01-04 14:48:49,706[nio-4401-exec-3] [WARN ] [o.e.c.impl.ContainerResponse 93] - Client has aborted connection. Response writing omitted.
2017-01-04 14:48:49,706[nio-4401-exec-4] [WARN ] [o.e.c.impl.ContainerResponse 93] - Client has aborted connection. Response writing omitted.
2017-01-04 14:48:49,706[nio-4401-exec-6] [WARN ] [o.e.c.impl.ContainerResponse 93] - Client has aborted connection. Response writing omitted.
2017-01-04 14:48:49,706[nio-4401-exec-5] [WARN ] [o.e.c.impl.ContainerResponse 93] - Client has aborted connection. Response writing omitted.
2017-01-04 14:48:49,706[nio-4401-exec-1] [WARN ] [o.e.c.impl.ContainerResponse 93] - Client has aborted connection. Response writing omitted.
2017-01-04 14:48:49,706[nio-4401-exec-2] [WARN ] [o.e.c.impl.ContainerResponse 93] - Client has aborted connection. Response writing omitted
then there was a pop-up Getting projects...
and the error occured.
$ docker logs -f a8fdec57ef91
has returned
Using embedded assembly...
Using embedded che.properties... Copying template to /home/d067440/che/instance/data/conf.
2017-01-04 14:47:28,389[main] [INFO ] [o.a.c.s.VersionLoggerListener 89] - Server version: Apache Tomcat/8.0.38
2017-01-04 14:47:28,394[main] [INFO ] [o.a.c.s.VersionLoggerListener 91] - Server built: Oct 6 2016 20:51:55 UTC
2017-01-04 14:47:28,395[main] [INFO ] [o.a.c.s.VersionLoggerListener 93] - Server number: 8.0.38.0
2017-01-04 14:47:28,395[main] [INFO ] [o.a.c.s.VersionLoggerListener 95] - OS Name: Linux
2017-01-04 14:47:28,396[main] [INFO ] [o.a.c.s.VersionLoggerListener 97] - OS Version: 4.4.0-57-generic
2017-01-04 14:47:28,397[main] [INFO ] [o.a.c.s.VersionLoggerListener 99] - Architecture: amd64
2017-01-04 14:47:28,397[main] [INFO ] [o.a.c.s.VersionLoggerListener 101] - Java Home: /usr/lib/jvm/java-1.8-openjdk/jre
2017-01-04 14:47:28,398[main] [INFO ] [o.a.c.s.VersionLoggerListener 103] - JVM Version: 1.8.0_111-b14
2017-01-04 14:47:28,398[main] [INFO ] [o.a.c.s.VersionLoggerListener 105] - JVM Vendor: Oracle Corporation
2017-01-04 14:47:28,399[main] [INFO ] [o.a.c.s.VersionLoggerListener 107] - CATALINA_BASE: /home/user/che/tomcat
2017-01-04 14:47:28,399[main] [INFO ] [o.a.c.s.VersionLoggerListener 109] - CATALINA_HOME: /home/user/che/tomcat
2017-01-04 14:47:28,400[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.util.logging.config.file=/home/user/che/tomcat/conf/logging.properties
2017-01-04 14:47:28,401[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2017-01-04 14:47:28,401[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dche.docker.network=bridge
2017-01-04 14:47:28,401[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dport.http=8080
2017-01-04 14:47:28,402[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dche.home=/home/user/che
2017-01-04 14:47:28,403[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dche.logs.dir=/home/user/che/tomcat/logs/
2017-01-04 14:47:28,403[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dche.logs.level=INFO
2017-01-04 14:47:28,404[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
2017-01-04 14:47:28,405[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
2017-01-04 14:47:28,406[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcom.sun.management.jmxremote
2017-01-04 14:47:28,406[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcom.sun.management.jmxremote.ssl=false
2017-01-04 14:47:28,407[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
2017-01-04 14:47:28,407[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dche.local.conf.dir=/data/conf
2017-01-04 14:47:28,408[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.endorsed.dirs=/home/user/che/tomcat/endorsed
2017-01-04 14:47:28,408[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcatalina.base=/home/user/che/tomcat
2017-01-04 14:47:28,408[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Dcatalina.home=/home/user/che/tomcat
2017-01-04 14:47:28,409[main] [INFO ] [o.a.c.s.VersionLoggerListener 115] - Command line argument: -Djava.io.tmpdir=/home/user/che/tomcat/temp
2017-01-04 14:47:28,809[main] [INFO ] [o.a.c.http11.Http11NioProtocol 443] - Initializing ProtocolHandler ["http-nio-8080"]
2017-01-04 14:47:28,887[main] [INFO ] [o.a.t.util.net.NioSelectorPool 72] - Using a shared selector for servlet write/read
2017-01-04 14:47:28,894[main] [INFO ] [o.a.catalina.startup.Catalina 591] - Initialization processed in 1338 ms
2017-01-04 14:47:29,078[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
2017-01-04 14:47:29,079[main] [INFO ] [o.a.c.core.StandardService 435] - Starting service Catalina
2017-01-04 14:47:29,080[main] [INFO ] [o.a.c.core.StandardEngine 259] - Starting Servlet Engine: Apache Tomcat/8.0.38
2017-01-04 14:47:30,281[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 911] - Deploying web application archive /home/user/che/tomcat/webapps/dashboard.war
2017-01-04 14:47:30,669[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 975] - Deployment of web application archive /home/user/che/tomcat/webapps/dashboard.war has finished in 386 ms
2017-01-04 14:47:30,705[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 911] - Deploying web application archive /home/user/che/tomcat/webapps/ROOT.war
2017-01-04 14:47:32,163[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 975] - Deployment of web application archive /home/user/che/tomcat/webapps/ROOT.war has finished in 1,458 ms
2017-01-04 14:47:32,175[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 911] - Deploying web application archive /home/user/che/tomcat/webapps/swagger.war
2017-01-04 14:47:32,318[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 975] - Deployment of web application archive /home/user/che/tomcat/webapps/swagger.war has finished in 143 ms
2017-01-04 14:47:32,364[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 911] - Deploying web application archive /home/user/che/tomcat/webapps/wsmaster.war
2017-01-04 14:47:46,456[ost-startStop-1] [INFO ] [o.f.c.i.d.DbSupportFactory 44] - Database: jdbc:h2:che (H2 1.4)
2017-01-04 14:47:46,497[ost-startStop-1] [INFO ] [o.f.c.i.util.VersionPrinter 44] - Flyway 4.0.3 by Boxfuse
2017-01-04 14:47:46,500[ost-startStop-1] [INFO ] [o.f.c.i.d.DbSupportFactory 44] - Database: jdbc:h2:che (H2 1.4)
2017-01-04 14:47:46,558[ost-startStop-1] [INFO ] [i.f.CustomSqlMigrationResolver 153] - Searching for sql scripts in locations [classpath:che-schema]
2017-01-04 14:47:46,597[ost-startStop-1] [INFO ] [o.f.c.i.command.DbValidate 44] - Successfully validated 2 migrations (execution time 00:00.040s)
2017-01-04 14:47:46,627[ost-startStop-1] [INFO ] [o.f.c.i.command.DbMigrate 44] - Current version of schema "PUBLIC": 5.0.0.9.1
2017-01-04 14:47:46,629[ost-startStop-1] [INFO ] [o.f.c.i.command.DbMigrate 44] - Schema "PUBLIC" is up to date. No migration necessary.
2017-01-04 14:47:50,397[ost-startStop-1] [INFO ] [o.a.c.startup.HostConfig 975] - Deployment of web application archive /home/user/che/tomcat/webapps/wsmaster.war has finished in 18,032 ms
2017-01-04 14:47:50,404[main] [INFO ] [o.a.c.http11.Http11NioProtocol 488] - Starting ProtocolHandler ["http-nio-8080"]
2017-01-04 14:47:50,421[main] [INFO ] [o.a.catalina.startup.Catalina 642] - Server startup in 21526 ms
2017-01-04 14:48:06,998[nio-8080-exec-5] [INFO ] [o.e.c.a.w.s.WorkspaceManager 884] - Workspace 'che:wksp-0gor' with id 'workspacetck02tbvcgphdeha' created by user 'che'
2017-01-04 14:48:14,042[spaceRuntimes-0] [INFO ] [o.e.c.a.w.s.WorkspaceRuntimes 600] - Launching 'org.eclipse.che.terminal' agent at workspace workspacetck02tbvcgphdeha
2017-01-04 14:48:16,348[spaceRuntimes-0] [INFO ] [o.e.c.a.w.s.WorkspaceRuntimes 600] - Launching 'org.eclipse.che.ws-agent' agent at workspace workspacetck02tbvcgphdeha
2017-01-04 14:48:50,518[spaceRuntimes-0] [INFO ] [o.e.c.a.w.s.WorkspaceRuntimes 600] - Launching 'org.eclipse.che.ssh' agent at workspace workspacetck02tbvcgphdeha
2017-01-04 14:48:51,401[kspaceManager-0] [INFO ] [o.e.c.a.w.s.WorkspaceManager 640] - Workspace 'che:wksp-0gor' with id 'workspacetck02tbvcgphdeha' started by user 'che'
2017-01-04 14:49:15,309[kspaceManager-0] [INFO ] [o.e.c.a.w.s.WorkspaceManager 686] - Workspace 'che:wksp-0gor' with id 'workspacetck02tbvcgphdeha' is being stopped by user 'che'
2017-01-04 14:49:15,312[kspaceManager-0] [INFO ] [o.e.c.a.w.s.WorkspaceManager 761] - Creating snapshot of workspace 'workspacetck02tbvcgphdeha', machines to snapshot: '1'
2017-01-04 14:49:22,996[kspaceManager-0] [INFO ] [o.e.c.a.w.s.WorkspaceManager 782] - Saving new snapshots metadata, workspace id 'workspacetck02tbvcgphdeha'
2017-01-04 14:49:24,947[kspaceManager-0] [INFO ] [o.e.c.a.w.s.WorkspaceManager 705] - Workspace 'che:wksp-0gor' with id 'workspacetck02tbvcgphdeha' stopped by user 'che'
Looks like a client side problem - browser is unable to connect to a workspace agent. Can you open Chrome dev console to check to failed or pending requests?
Btw, when I did
$ docker run -ti -v /var/run/docker.sock:/var/run/docker.sock -v ~/che/config:/data eclipse/che-cli:nightly start
it did not start che. It has only shown some info.
WARNING: No swap limit support
INFO: Proxy: HTTP_PROXY=http://proxy.wdf.sap.corp:8080/, HTTPS_PROXY=https://proxy.wdf.sap.corp:8080/, NO_PROXY='192.168.174.148,.sap.corp,10.*,localhost,127.0.0.1,0.0.0.0,github.wdf.sap.corp,nexus.wdf.sap.corp:8443,nexus.wdf.sap.corp:8081,*.sap.corp,*.local,169.254/16,*.corp.sap,10.17.81.88:8081'
INFO: (che cli): Checking network... (hint: '--fast' skips version and network checks)
INFO: (che cli): Loading cli...
However, I could start che without nightly, i.e. $ docker run -ti -v /var/run/docker.sock:/var/run/docker.sock -v ~/che/config:/data eclipse/che-cli start
Btw again, I tried it in Chrome and Firefox. They both complained "Unable to initialize IDE" and then the che popup "Workspace Agent not responding" occured.
Chrome dev console to check to failed or pending requests?
When you started Che with the new sequence, there would be a cli.log
in the folder that you mounted. You can also paste the tail of that as it contains traces of what the CLI is doing and any errors.
This is the full log file.
Mon Jan 9 13:00:31 UTC 2017
INFO: (che cli): Checking network... (hint: '--fast' skips version and network checks)
/usr/bin/curl "-I -k dockerhub.com -s -o /dev/null --write-out %{http_code}"
INFO: (che cli): Pulling image alpine:3.4
docker pull alpine:3.4 >> "/data/cli.log" 2>&1
INFO: (che cli): Pulling image eclipse/che-ip:nightly
docker pull eclipse/che-ip:nightly >> "/data/cli.log" 2>&1
INFO: (che cli): Loading cli...
DEBUG: docker_run
DEBUG: is_boot2docker
DEBUG: is_initialized
DEBUG: cli_parse
DEBUG: cmd_start
DEBUG: is_docker_for_mac
DEBUG: is_initialized
DEBUG: is_initialized
INFO: (che cli): Checking registry for version '5.0.0' images
eval IMAGE_PUPPET=puppet/puppet-agent-alpine:4.6.2
eval IMAGE_REGISTRY=registry:2.5.0
eval IMAGE_INIT=eclipse/che-init:5.0.0
eval IMAGE_CHE=eclipse/che-server:5.0.0
DEBUG: update_image_if_not_found
INFO: (che download): Checking for image 'puppet/puppet-agent-alpine:4.6.2'...
not found
DEBUG: update_image
INFO: (che download): Pulling image puppet/puppet-agent-alpine:4.6.2
docker pull puppet/puppet-agent-alpine:4.6.2 >> "/data/cli.log" 2>&1
DEBUG: update_image_if_not_found
INFO: (che download): Checking for image 'registry:2.5.0'...
not found
DEBUG: update_image
INFO: (che download): Pulling image registry:2.5.0
docker pull registry:2.5.0 >> "/data/cli.log" 2>&1
DEBUG: update_image_if_not_found
INFO: (che download): Checking for image 'eclipse/che-init:5.0.0'...
not found
DEBUG: update_image
INFO: (che download): Pulling image eclipse/che-init:5.0.0
docker pull eclipse/che-init:5.0.0 >> "/data/cli.log" 2>&1
DEBUG: update_image_if_not_found
INFO: (che download): Checking for image 'eclipse/che-server:5.0.0'...
not found
DEBUG: update_image
INFO: (che download): Pulling image eclipse/che-server:5.0.0
docker pull eclipse/che-server:5.0.0 >> "/data/cli.log" 2>&1
INFO: (che init): Installing configuration and bootstrap variables:
mkdir -p "/data"
mkdir -p "/data/instance"
DEBUG: docker_run
INFO: (che init): CHE_HOST=172.17.0.1
INFO: (che init): CHE_VERSION=5.0.0
INFO: (che init): CHE_CONFIG=/home/alex/che
INFO: (che init): CHE_INSTANCE=/home/alex/che/instance
INFO: (che init): CHE_DEVELOPMENT_REPO=/home/alex/che
INFO: (che init): CHE_ASSEMBLY=/home/alex/che/instance/dev/che-tomcat
DEBUG: docker_run
INFO: (che config): Generating che configuration...
DEBUG: generate_configuration_with_puppet
DEBUG: is_docker_for_windows
docker_run --env-file="/data/che.env" --env-file=/version/5.0.0/images -v "/home/alex/che/instance":/opt/che:rw -v "/home/alex/che/dockerfiles/init/manifests":/etc/puppet/manifests:ro -v "/home/alex/che/dockerfiles/init/modules":/etc/puppet/modules:ro -e "CHE_ASSEMBLY=/home/alex/che/instance/dev/che-tomcat" -e "CHE_ENV_FILE=/home/alex/che/instance/config/che.env" -e "CHE_CONTAINER_ROOT=/data" -e "CHE_ENVIRONMENT=development" -e "CHE_CONFIG=/home/alex/che/instance" -e "CHE_INSTANCE=/home/alex/che/instance" -e "CHE_REPO=on" --entrypoint=/usr/bin/puppet eclipse/che-init:5.0.0 apply --modulepath /etc/puppet/modules/ /etc/puppet/manifests/che.pp --show_diff
DEBUG: docker_run
INFO: (che config): Customizing docker-compose for running in a container
INFO: (che config): Copying local binaries to /home/alex/che/instance/dev...
INFO: (che start): Preflight checks
DEBUG: docker_run
DEBUG: port_open
port 8080 (http): [AVAILABLE]
DEBUG: port_open
port 8000 (debug): [AVAILABLE]
DEBUG: port_open
DEBUG: port_open
INFO: (che start): Starting containers...
docker_compose --file="/data/instance/docker-compose-container.yml" -p="che" up -d
DEBUG: docker_compose
DEBUG: docker_run
docker inspect -f '{{.Id}}' che
INFO: (che start): Services booting...
/usr/bin/curl "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
200
INFO:
/usr/bin/curl "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
200
DEBUG: is_docker_for_mac
INFO: (che start): Booted and reachable
DEBUG: is_initialized
INFO: (che start): Ver: 5.0.0
INFO: (che start): Use: http://172.17.0.1:8080
INFO: (che start): API: http://172.17.0.1:8080/swagger
DEBUG: is_docker_for_mac
INFO: (che start): Debug: http://172.17.0.1:8000
Mon Jan 9 13:40:59 UTC 2017
INFO: (che cli): Checking network... (hint: '--fast' skips version and network checks)
/usr/bin/curl "-I -k dockerhub.com -s -o /dev/null --write-out %{http_code}"
INFO: (che cli): Pulling image alpine:3.4
docker pull alpine:3.4 >> "/data/cli.log" 2>&1
INFO: (che cli): Pulling image eclipse/che-ip:nightly
docker pull eclipse/che-ip:nightly >> "/data/cli.log" 2>&1
INFO: (che cli): Loading cli...
DEBUG: docker_run
DEBUG: is_boot2docker
DEBUG: is_initialized
DEBUG: is_initialized
DEBUG: is_initialized
DEBUG: cli_parse
DEBUG: cmd_start
DEBUG: is_docker_for_mac
DEBUG: is_initialized
INFO: (che cli): Checking registry for version '5.0.0' images
eval IMAGE_PUPPET=puppet/puppet-agent-alpine:4.6.2
eval IMAGE_REGISTRY=registry:2.5.0
eval IMAGE_INIT=eclipse/che-init:5.0.0
eval IMAGE_CHE=eclipse/che-server:5.0.0
DEBUG: docker_run
INFO: (che config): Generating che configuration...
DEBUG: generate_configuration_with_puppet
DEBUG: is_docker_for_windows
docker_run --env-file="/data/che.env" --env-file=/version/5.0.0/images -v "/home/d067440/che/instance":/opt/che:rw -v "/home/d067440/che/dockerfiles/init/manifests":/etc/puppet/manifests:ro -v "/home/d067440/che/dockerfiles/init/modules":/etc/puppet/modules:ro -e "CHE_ASSEMBLY=/home/d067440/che/instance/dev/che-tomcat" -e "CHE_ENV_FILE=/home/d067440/che/instance/config/che.env" -e "CHE_CONTAINER_ROOT=/data" -e "CHE_ENVIRONMENT=development" -e "CHE_CONFIG=/home/d067440/che/instance" -e "CHE_INSTANCE=/home/d067440/che/instance" -e "CHE_REPO=on" --entrypoint=/usr/bin/puppet eclipse/che-init:5.0.0 apply --modulepath /etc/puppet/modules/ /etc/puppet/manifests/che.pp --show_diff
DEBUG: docker_run
INFO: (che config): Customizing docker-compose for running in a container
docker_run -v "/home/d067440/che/instance/dev":/root/dev alpine:3.4 sh -c "rm -rf /root/dev/*"
DEBUG: docker_run
rm -rf "/home/d067440/che/instance/dev" >> "/data/cli.log"
INFO: (che config): Copying local binaries to /home/d067440/che/instance/dev...
INFO: (che start): Preflight checks
DEBUG: docker_run
DEBUG: port_open
port 8080 (http): [AVAILABLE]
DEBUG: port_open
port 8000 (debug): [AVAILABLE]
DEBUG: port_open
DEBUG: port_open
INFO: (che start): Starting containers...
docker_compose --file="/data/instance/docker-compose-container.yml" -p="che" up -d
DEBUG: docker_compose
DEBUG: docker_run
docker inspect -f '{{.Id}}' che
INFO: (che start): Services booting...
/usr/bin/curl --noproxy 172.17.0.1 "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 172.17.0.1 "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 172.17.0.1 "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 172.17.0.1 "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 172.17.0.1 "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 172.17.0.1 "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
200
INFO:
/usr/bin/curl --noproxy 172.17.0.1 "-I -k 172.17.0.1:8080/api/ -s -o /dev/null --write-out %{http_code}"
200
DEBUG: is_docker_for_mac
INFO: (che start): Booted and reachable
DEBUG: is_initialized
INFO: (che start): Ver: 5.0.0
INFO: (che start): Use: http://172.17.0.1:8080
INFO: (che start): API: http://172.17.0.1:8080/swagger
DEBUG: is_docker_for_mac
INFO: (che start): Debug: http://172.17.0.1:8000
Mon Jan 9 13:43:49 UTC 2017
INFO: (che cli): Checking network... (hint: '--fast' skips version and network checks)
/usr/bin/curl --noproxy 10.44.108.110 "-I -k dockerhub.com -s -o /dev/null --write-out %{http_code}"
INFO: (che cli): Loading cli...
DEBUG: docker_run
DEBUG: is_boot2docker
DEBUG: is_initialized
DEBUG: is_initialized
DEBUG: is_initialized
DEBUG: cli_parse
DEBUG: cmd_start
DEBUG: is_docker_for_mac
DEBUG: is_initialized
INFO: (che cli): Checking registry for version '5.0.0' images
eval IMAGE_PUPPET=puppet/puppet-agent-alpine:4.6.2
eval IMAGE_REGISTRY=registry:2.5.0
eval IMAGE_INIT=eclipse/che-init:5.0.0
eval IMAGE_CHE=eclipse/che-server:5.0.0
DEBUG: docker_run
INFO: (che config): Generating che configuration...
DEBUG: generate_configuration_with_puppet
DEBUG: is_docker_for_windows
docker_run --env-file="/data/che.env" --env-file=/version/5.0.0/images -v "/home/d067440/che/instance":/opt/che:rw -v "/home/d067440/che/dockerfiles/init/manifests":/etc/puppet/manifests:ro -v "/home/d067440/che/dockerfiles/init/modules":/etc/puppet/modules:ro -e "CHE_ASSEMBLY=/home/d067440/che/instance/dev/che-tomcat" -e "CHE_ENV_FILE=/home/d067440/che/instance/config/che.env" -e "CHE_CONTAINER_ROOT=/data" -e "CHE_ENVIRONMENT=development" -e "CHE_CONFIG=/home/d067440/che/instance" -e "CHE_INSTANCE=/home/d067440/che/instance" -e "CHE_REPO=on" --entrypoint=/usr/bin/puppet eclipse/che-init:5.0.0 apply --modulepath /etc/puppet/modules/ /etc/puppet/manifests/che.pp --show_diff
DEBUG: docker_run
INFO: (che config): Customizing docker-compose for running in a container
docker_run -v "/home/d067440/che/instance/dev":/root/dev alpine:3.4 sh -c "rm -rf /root/dev/*"
DEBUG: docker_run
rm -rf "/home/d067440/che/instance/dev" >> "/data/cli.log"
INFO: (che config): Copying local binaries to /home/d067440/che/instance/dev...
INFO: (che start): Preflight checks
DEBUG: docker_run
DEBUG: port_open
port 8080 (http): [AVAILABLE]
DEBUG: port_open
port 8000 (debug): [AVAILABLE]
DEBUG: port_open
DEBUG: port_open
INFO: (che start): Starting containers...
docker_compose --file="/data/instance/docker-compose-container.yml" -p="che" up -d
DEBUG: docker_compose
DEBUG: docker_run
docker inspect -f '{{.Id}}' che
INFO: (che start): Services booting...
/usr/bin/curl --noproxy 10.44.108.110 "-I -k 10.44.108.110:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 10.44.108.110 "-I -k 10.44.108.110:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 10.44.108.110 "-I -k 10.44.108.110:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 10.44.108.110 "-I -k 10.44.108.110:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 10.44.108.110 "-I -k 10.44.108.110:8080/api/ -s -o /dev/null --write-out %{http_code}"
000
sleep 2
/usr/bin/curl --noproxy 10.44.108.110 "-I -k 10.44.108.110:8080/api/ -s -o /dev/null --write-out %{http_code}"
200
INFO:
/usr/bin/curl --noproxy 10.44.108.110 "-I -k 10.44.108.110:8080/api/ -s -o /dev/null --write-out %{http_code}"
200
DEBUG: is_docker_for_mac
INFO: (che start): Booted and reachable
DEBUG: is_initialized
INFO: (che start): Ver: 5.0.0
INFO: (che start): Use: http://10.44.108.110:8080
INFO: (che start): API: http://10.44.108.110:8080/swagger
DEBUG: is_docker_for_mac
INFO: (che start): Debug: http://10.44.108.110:8000
@aleksei-burakov - that output log seems to indicate that Che has started successfully without any errors. Just to confirm if you are still having the same issues, please do the following:
I am not seeing anything wrong iwth your configuration - it looks good.
I failed to start a nightly version.
$ docker run -it --rm -e CHE_HOST=10.44.108.110 -v /var/run/docker.sock:/var/run/docker.sock -v ~/che:/repo -v ~/che:/data eclipse/che-cli:nightly start --debug
WARNING: No swap limit support
INFO: Proxy: HTTP_PROXY=http://proxy.wdf.sap.corp:8080/, HTTPS_PROXY=https://proxy.wdf.sap.corp:8080/, NO_PROXY=
INFO: (che cli): :/repo mounted - using binaries from your local repository
INFO: (che cli): Checking network... (hint: '--fast' skips version and network checks)
INFO: (che cli): Loading cli...
$
and thats it. No server was started. Insead I started the non nightly che
docker run -it --rm -e CHE_HOST=10.44.108.110 -v /var/run/docker.sock:/var/run/docker.sock -v ~/che:/repo -v ~/che:/data eclipse/che-cli start --debug
and then started a BLANK workspace. When starting the workspace I had the following log in the workspace console
[DOCKER] latest: Pulling from eclipse/ubuntu_jdk8
[DOCKER] Digest: sha256:58505295083a0e4be0d73cc8027d43c08e13f71cda89b1903903459ba7e3dcd4
[DOCKER] Status: Image is up to date for eclipse/ubuntu_jdk8:latest
[STDOUT] Exec-agent configuration
[STDOUT] Server
[STDOUT] - Address: :4411
[STDOUT] - Static content: /home/user/che/terminal/
[STDOUT] - Base path: ''
[STDOUT] Terminal
[STDOUT] - Slave command: '/bin/bash'
[STDOUT] - Activity tracking enabled: false
[STDOUT] Process executor
[STDOUT] - Logs dir: /home/user/che/exec-agent/logs
[STDOUT]
[STDOUT] ⇩ Registered HttpRoutes:
[STDOUT]
[STDOUT] Process Routes:
[STDOUT] ✓ Start Process ........................... POST /process
[STDOUT] ✓ Get Process ............................. GET /process/:pid
[STDOUT] ✓ Kill Process ............................ DELETE /process/:pid
[STDOUT] ✓ Get Process Logs ........................ GET /process/:pid/logs
[STDOUT] ✓ Get Processes ........................... GET /process
[STDOUT]
[STDOUT] Channel Routes:
[STDOUT] ✓ Connect to Exec-Agent(webscoket) ........ GET /connect
[STDOUT]
[STDOUT] Terminal routes:
[STDOUT] ✓ Connect to pty(webscoket) ............... GET /pty
[STDOUT]
[STDOUT]
[STDOUT] ⇩ Registered RpcRoutes:
[STDOUT]
[STDOUT] Process Routes:
[STDOUT] ✓ process.start
[STDOUT] ✓ process.kill
[STDOUT] ✓ process.subscribe
[STDOUT] ✓ process.unsubscribe
[STDOUT] ✓ process.updateSubscriber
[STDOUT] ✓ process.getLogs
[STDOUT] ✓ process.getProcess
[STDOUT] ✓ process.getProcesses
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: .sap.corp: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: localhost: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: 10.*: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: 0.0.0.0: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: *.local: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: 10.17.81.88:8081|10.44.108.110|: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: 127.0.0.1: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: github.wdf.sap.corp: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: nexus.wdf.sap.corp:8443: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: nexus.wdf.sap.corp:8081: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: *.sap.corp: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: 169.254/16: not found
/home/user/che/ws-agent/bin/catalina.sh: 1: eval: *.corp.sap: not found
Usage: java [-options] class [args...]
(to execute a class)
or java [-options] -jar jarfile [args...]
(to execute a jar file)
where options include:
-d32 use a 32-bit data model if available
-d64 use a 64-bit data model if available
-server to select the "server" VM
The default VM is server,
because you are running on a server-class machine.
-cp
-classpath
A : separated list of directories, JAR archives,
and ZIP archives to search for class files.
-D=
set a system property
-verbose:[class|gc|jni]
enable verbose output
-version print product version and exit
-version:
Warning: this feature is deprecated and will be removed
in a future release.
require the specified version to run
-showversion print product version and continue
-jre-restrict-search | -no-jre-restrict-search
Warning: this feature is deprecated and will be removed
in a future release.
include/exclude user private JREs in the version search
-? -help print this help message
-X print help on non-standard options
-ea[:...|:]
-enableassertions[:...|:]
enable assertions with specified granularity
-da[:...|:]
-disableassertions[:...|:]
disable assertions with specified granularity
-esa | -enablesystemassertions
enable system assertions
-dsa | -disablesystemassertions
disable system assertions
-agentlib:[=]
load native agent library , e.g. -agentlib:hprof
see also, -agentlib:jdwp=help and -agentlib:hprof=help
-agentpath:[=]
load native agent library by full pathname
-javaagent:[=]
load Java programming language agent, see java.lang.instrument
-splash:
show splash screen with specified image
it seems that one of the enviroment variables (namely NO_PROXY) was not properly parsed. I unset NO_PROXY and the workspace has started. I think the issue can be closed.
@aleksei-burakov - when you said "you unset NO_PROXY", can you elaborate on how you do that? We are having the CLI inherit proxy parameters set within your Docker Daemon. If you think that our inheritance is causing a problem, we should investigate.
I have removed a line from /etc/systemd/system/docker.service.d/http-proxy.conf
I think it was something like
Environment="NO_PROXY='192.168.174.148,.sap.corp,10.*,localhost,127.0.0.1,0.0.0.0,github.wdf.sap.corp,nexus.wdf.sap.corp:8443,nexus.wdf.sap.corp:8081,*.sap.corp,*.local,169.254/16,*.corp.sap,10.17.81.88:8081'"
Then I restarted docker and unset the enviroment variable NO_PROXY
$ systemctl daemon-reload
$ unset NO_PROXY
After that the problem has gone. Its also likely be that the NO_PROXY variable is written with mistakes.
The enviromental variable itself was set before as
local _NOPROXY="192.168.174.148,.sap.corp,10.*,localhost,127.0.0.1,0.0.0.0,github.wdf.sap.corp,nexus.wdf.sap.corp:8443,nexus.wdf.sap.corp:8081,*.sap.corp,*.local,169.254/16,*.corp.sap,10.17.81.88:8081"
export NO_PROXY=${_NOPROXY}
Ok, thanks. We may need to think about additional tests that we can do within the CLI to verify that NO_PROXY inheritance from the Docker daemon is setup properly.
@benoitf - will you take 30 minutes and study this backlog to think if there is any sort of additional HTTP_PROXY, NO_PROXY tests that we can do within the CLI to have detected this isssue in advance?
I think I am hitting this issue while trying eclipse/che in play-with-docker. Steps to reproduce:
docker run -v $(pwd)/eclipse_che:/data -v /var/run/docker.sock:/var/run/docker.sock eclipse/che start
It will hang with "Starting workspace agent..." until 'Unable to initialize IDE' is shown in a dialog. Below, the dialog reported by @aleksei-burakov is shown. These are the errors shown in the console:
link #6535
@1138-4EB can you switch to network tab in the console and hit F5?
@eivantsov, sure. Do you mean to do it after reproducing all the steps above?
@eivantsov I 'recorded' an animated gif:
When I start a workspace I have an error
Reproduction Steps:
Expected behavior:
It starts the workspace.
Observed behavior:
It throws an error.
Che version: latest OS and version: Ubuntu 14.04 Docker version: 1.12.15
Additional information: