search

danielflower / app-runner

Self-hosted platform as a service for Java, Node, Clojure, Scala, DotNet, Python and golang apps. Push to a git repo to deploy apps.
MIT License
70 stars 44 forks source link

Fail to startup in centOS with 'connection refuse' #8

Closed abigail830 closed 7 years ago

abigail830 commented 7 years ago

Tried to start it in a centOS7 but got below error, any idea? appRunner.txt

11:39:19.727 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @134008ms org.eclipse.jetty.io.ManagedSelector@38353cb4 id=0 keys=0 selected=0 11:39:19.727 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @134009ms org.eclipse.jetty.client.AbstractHttpClientTransport$ClientSelectorManager@272fd214 11:39:19.727 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @134009ms org.eclipse.jetty.client.http.HttpClientTransportOverHTTP@57471333 11:39:19.727 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @134009ms org.eclipse.jetty.client.HttpClient@524bd875 11:39:20.245 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.client.HttpClient@524bd875 added {HttpDestination[http://localhost:42557]@6606349c,queue=0,pool=null,MANAGED} 11:39:20.250 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting HttpDestination[http://localhost:42557]@6606349c,queue=0,pool=null 11:39:20.258 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - HttpDestination[http://localhost:42557]@6606349c,queue=0,pool=DuplexConnectionPool@3531ffd3[c=0/64,a=0,i=0] added {DuplexConnectionPool@3531ffd3[c=0/64,a=0,i=0],POJO} 11:39:20.260 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @134541ms HttpDestination[http://localhost:42557]@6606349c,queue=0,pool=DuplexConnectionPool@3531ffd3[c=0/64,a=0,i=0] 11:39:20.267 [pool-4-thread-1] DEBUG org.eclipse.jetty.client.HttpClient - Created HttpDestination[http://localhost:42557]@6606349c,queue=0,pool=DuplexConnectionPool@3531ffd3[c=0/64,a=0,i=0] 11:39:20.282 [pool-4-thread-1] DEBUG org.eclipse.jetty.client.HttpDestination - Queued HttpRequest[GET /app-runner-home/ HTTP/1.1]@640ae19a for HttpDestination[http://localhost:42557]@6606349c,queue=1,pool=DuplexConnectionPool@3531ffd3[c=0/64,a=0,i=0] 11:39:20.285 [pool-4-thread-1] DEBUG org.eclipse.jetty.client.AbstractConnectionPool - Connection 1/64 creation 11:39:20.311 [pool-4-thread-1] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue org.eclipse.jetty.util.SocketAddressResolver$Async$$Lambda$48/1724759036@7d72bf0e 11:39:20.323 [HttpClient@1380702325-68] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run org.eclipse.jetty.util.SocketAddressResolver$Async$$Lambda$48/1724759036@7d72bf0e 11:39:20.333 [HttpClient@1380702325-68] DEBUG org.eclipse.jetty.util.SocketAddressResolver - Resolved localhost in 0 ms 11:39:20.374 [HttpClient@1380702325-68] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change org.eclipse.jetty.io.ManagedSelector$Connect@39733ca5 on org.eclipse.jetty.io.ManagedSelector@38353cb4 id=0 keys=0 selected=0 11:39:20.378 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector loop woken up from select, 0/0 selected 11:39:20.378 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Running action org.eclipse.jetty.io.ManagedSelector$Connect@39733ca5 11:39:20.379 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector loop waiting on select 11:39:20.379 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector loop woken up from select, 1/1 selected 11:39:20.379 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - selected sun.nio.ch.SelectionKeyImpl@3b93f80f org.eclipse.jetty.io.ManagedSelector$Connect@39733ca5 11:39:20.381 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.client.HttpClientTransport - Could not connect to HttpDestination[http://localhost:42557]@6606349c,queue=1,pool=DuplexConnectionPool@3531ffd3[c=1/64,a=0,i=0] 11:39:20.381 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change org.eclipse.jetty.io.ManagedSelector$Connect@4f2579e7 on org.eclipse.jetty.io.ManagedSelector@38353cb4 id=0 keys=1 selected=1 11:39:20.381 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Running action org.eclipse.jetty.io.ManagedSelector$Connect@4f2579e7 11:39:20.381 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector loop waiting on select 11:39:20.381 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector loop woken up from select, 1/1 selected 11:39:20.382 [HttpClient@1380702325-68] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - ran org.eclipse.jetty.util.SocketAddressResolver$Async$$Lambda$48/1724759036@7d72bf0e 11:39:20.382 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - selected sun.nio.ch.SelectionKeyImpl@6b52a38c org.eclipse.jetty.io.ManagedSelector$Connect@4f2579e7 11:39:20.384 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.client.HttpClientTransport - Could not connect to HttpDestination[http://localhost:42557]@6606349c,queue=1,pool=DuplexConnectionPool@3531ffd3[c=1/64,a=0,i=0] 11:39:20.396 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.client.AbstractConnectionPool - Connection 1/64 creation failed java.net.ConnectException: 拒绝连接 at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717) at org.eclipse.jetty.io.SelectorManager.doFinishConnect(SelectorManager.java:320) at org.eclipse.jetty.io.ManagedSelector.processConnect(ManagedSelector.java:418) at org.eclipse.jetty.io.ManagedSelector.access$1000(ManagedSelector.java:60) at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.processSelected(ManagedSelector.java:350) at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:244) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:147) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produce(ExecuteProduceConsume.java:97) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:672) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:590) at java.lang.Thread.run(Thread.java:748) 11:39:20.412 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.client.HttpExchange - Failed HttpExchange@52c407a2 req=COMPLETED/java.net.ConnectException: 拒绝连接@4e42d053 res=COMPLETED/java.net.ConnectException: 拒绝连接@4e42d053: req=true/rsp=true {} 11:39:20.419 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.client.HttpExchange - Aborting while queued HttpExchange@52c407a2 req=COMPLETED/java.net.ConnectException: 拒绝连接@4e42d053 res=COMPLETED/java.net.ConnectException: 拒绝连接@4e42d053: {} 11:39:20.430 [pool-4-thread-1] INFO com.danielflower.apprunner.runners.Waiter - Waiting for start up of app-runner-home 11:39:20.430 [HttpClient@1380702325-67] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector loop waiting on select

danielflower commented 7 years ago

That's interesting. It's managed to start, and download App Runner Home, and build that. But then it can't seem to query that app.

Something to try:

cd /root/target/local/temp/app-runner-home/instances/1495362360654
/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-2.b11.el7_3.x86_64/jre/bin/java -Djava.io.tmpdir=/root/target/local/temp/app-runner-home -jar target/app-runner-home-1.0-SNAPSHOT.jar

That should just log to the console? Does it start successfully?

If it looks like it has started, then in another window...

curl http://localhost:8081/app-runner-home/

If that works, then it seems like java can't call a localhost URL. If you let me know the result of that test then maybe I can figure something out.

danielflower commented 7 years ago

Oh, actually it looks like it did start. The errors are just what's happening when it's checking itself to see if it's started. The last line in your log shows:

10:26:27.209 [pool-4-thread-1] INFO com.danielflower.apprunner.web.ProxyMap - app-runner-home maps to http://localhost:37899/app-runner-home

Which looks like it works. Which port is apprunner running on? If it's port 80, you should be able to curl http://localhost/api/v1/system to get info about what's happening. What actually happens when you try to load apprunner in a browser?

Note the logging is crazy if you don't specify INFO level logging with something like this.

abigail830 commented 7 years ago

image

abigail830 commented 7 years ago

[root@saraqian ~]# curl http://localhost:8080/app-runner-home curl: (7) Failed connect to localhost:8080; 拒绝连接

[root@saraqian ~]# curl http://localhost/api/v1/system <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">

404 Not Found

Not Found

The requested URL /api/v1/system was not found on this server.

[root@saraqian ~]# curl http://localhost:8080/api/v1/system curl: (7) Failed connect to localhost:8080; 拒绝连接

abigail830 commented 7 years ago

[root@saraqian 1495466379064]# /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-2.b11.el7_3.x86_64/jre/bin/java -Djava.io.tmpdir=/root/target/local/temp/app-runner-home -jar target/app-runner-home-1.0-SNAPSHOT.jar 15:43:40.248 [main] INFO org.eclipse.jetty.util.log - Logging initialized @445ms 15:43:40.677 [main] WARN com.danielflower.apprunner.App - No PHANTOMJS_BIN env var set, so no screenshots are available 15:43:40.776 [main] INFO org.eclipse.jetty.server.Server - jetty-9.3.z-SNAPSHOT 15:43:40.849 [main] INFO o.e.j.server.handler.ContextHandler - Started o.e.j.s.h.ContextHandler@612679d6{/app-runner-home,null,AVAILABLE} 15:43:40.850 [main] INFO o.e.j.server.handler.ContextHandler - Started o.e.j.s.h.ContextHandler@11758f2a{/app-runner-home,null,AVAILABLE} 15:43:40.850 [main] INFO o.e.j.server.handler.ContextHandler - Started o.e.j.s.h.ContextHandler@e720b71{/app-runner-home/docs,null,AVAILABLE} 15:43:40.856 [main] INFO o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@1b26f7b2{/,null,AVAILABLE} 15:43:40.867 [main] INFO o.e.jetty.server.AbstractConnector - Started ServerConnector@4e193d17{HTTP/1.1,[http/1.1]}{0.0.0.0:8081} 15:43:40.868 [main] INFO org.eclipse.jetty.server.Server - Started @1070ms 15:43:40.868 [main] INFO com.danielflower.apprunner.App - Started app-runner-home at http://localhost:8081/app-runner-home 15:44:16.035 [qtp1638215613-21] INFO c.d.apprunner.HomeController - GET http://172.104.74.214:8081/api/v1/apps 15:44:16.126 [qtp1638215613-21] ERROR c.d.apprunner.HomeController - Error while processing /app-runner-home/ java.lang.RuntimeException: 502 while loading http://172.104.74.214:8081/api/v1/apps. Content was: at com.danielflower.apprunner.HomeController.httpGet(HomeController.java:130) at com.danielflower.apprunner.HomeController.list(HomeController.java:81) at com.danielflower.apprunner.HomeController.handle(HomeController.java:51) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1182) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1116) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:534) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) at java.lang.Thread.run(Thread.java:748)

danielflower commented 7 years ago

Hmm... well it seems to be starting up. I can only think that there is a problem connecting from your browser to the server over HTTP. Hard to say more without trying it though. Maybe a little later I can get a CentOS image and try it out.

abigail830 commented 7 years ago

Or could send me ur key I add to my centOS so that you could try it directly?

abigail830 commented 7 years ago

seems my fault...forget that i updated below config.properties APPSERVER_PORT=8089

when move it back to appserver.port=8089 then its up now (even have same exception during startup..)