Derby not starting up in 1527 in AWS host (Coordinator)

Hi there,
I was able to successfully use the 0.9.1.1 version in standalone mode in my MAC as a single node setup - everything worked like charm. Now I’m creating a small cluster (t2.micro) in AWS using the same version (0.9.1.1).

1 node with Coordinator & Overlord - This same node hosts zookeeper & Derby

1 node with Broker

1 node with Historical & MiddleManager

Now when I start coordinator - ideally it should start the derby and have a successful creation of tables. But somehow this is not happening.

Coordinator Logs:

2016-12-01T01:46:45,102 INFO [main] org.apache.zookeeper.ZooKeeper - Client environment:user.name=ec2-user

2016-12-01T01:46:45,102 INFO [main] org.apache.zookeeper.ZooKeeper - Client environment:user.home=/home/ec2-user

2016-12-01T01:46:45,102 INFO [main] org.apache.zookeeper.ZooKeeper - Client environment:user.dir=/home/ec2-user/druid/druid-0.9.1.1

2016-12-01T01:46:45,103 INFO [main] org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=52.53.243.72 sessionTimeout=30000 watcher=org.apache.curator.ConnectionState@4613311f

2016-12-01T01:46:45,124 INFO [main] com.metamx.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking start method[public void io.druid.server.listener.announcer.ListenerDiscoverer.start()] on object[io.druid.server.listener.announcer.ListenerDiscoverer@1fb2d5e].

2016-12-01T01:46:45,124 INFO [main] io.druid.server.listener.announcer.ListenerDiscoverer - Started

2016-12-01T01:46:45,124 INFO [main] com.metamx.common.lifecycle.Lifecycle$AnnotationBasedHandler - Invoking start method[public void io.druid.metadata.storage.derby.DerbyMetadataStorage.start()] on object[io.druid.metadata.storage.derby.DerbyMetadataStorage@6573d2f7].

2016-12-01T01:46:45,124 INFO [main] io.druid.metadata.storage.derby.DerbyMetadataStorage - Starting Derby Metadata Storage

2016-12-01T01:46:45,133 INFO [main-SendThread(52.53.243.72:2181)] org.apache.zookeeper.ClientCnxn - Opening socket connection to server 52.53.243.72/52.53.243.72:2181. Will not attempt to authenticate using SASL (unknown error)

2016-12-01T01:47:15,317 WARN [main-SendThread(52.53.243.72:2181)] org.apache.zookeeper.ClientCnxn - Client session timed out, have not heard from server in 30195ms for sessionid 0x0

2016-12-01T01:47:15,318 INFO [main-SendThread(52.53.243.72:2181)] org.apache.zookeeper.ClientCnxn - Client session timed out, have not heard from server in 30195ms for sessionid 0x0, closing socket connection and attempting reconnect

2016-12-01T01:47:16,420 INFO [main-SendThread(52.53.243.72:2181)] org.apache.zookeeper.ClientCnxn - Opening socket connection to server 52.53.243.72/52.53.243.72:2181. Will not attempt to authenticate using SASL (unknown error)

:

:

2016-12-01T01:48:52,753 WARN [main] com.metamx.common.RetryUtils - Failed on try 1, retrying in 1,156ms.

org.skife.jdbi.v2.exceptions.UnableToObtainConnectionException: java.sql.SQLException: Cannot create PoolableConnectionFactory (java.net.ConnectException : Error connecting to server 52.53.243.72 on port 1,527 with message Connection timed out (Connection timed out).)

at org.skife.jdbi.v2.DBI.open(DBI.java:230) ~[jdbi-2.63.1.jar:2.63.1]

at org.skife.jdbi.v2.DBI.withHandle(DBI.java:279) ~[jdbi-2.63.1.jar:2.63.1]

at io.druid.metadata.SQLMetadataConnector$2.call(SQLMetadataConnector.java:123) ~[druid-server-0.9.1.1.jar:0.9.1.1]

at com.metamx.common.RetryUtils.retry(RetryUtils.java:60) [java-util-0.27.9.jar:?]

at com.metamx.common.RetryUtils.retry(RetryUtils.java:78) [java-util-0.27.9.jar:?]

at io.druid.metadata.SQLMetadataConnector.retryWithHandle(SQLMetadataConnector.java:127) [druid-server-0.9.1.1.jar:0.9.1.1]

at io.druid.metadata.SQLMetadataConnector.retryWithHandle(SQLMetadataConnector.java:136) [druid-server-0.9.1.1.jar:0.9.1.1]

at io.druid.metadata.SQLMetadataConnector.createTable(SQLMetadataConnector.java:176) [druid-server-0.9.1.1.jar:0.9.1.1]

at io.druid.metadata.SQLMetadataConnector.createConfigTable(SQLMetadataConnector.java:294) [druid-server-0.9.1.1.jar:0.9.1.1]

at io.druid.metadata.SQLMetadataConnector.createConfigTable(SQLMetadataConnector.java:475) [druid-server-0.9.1.1.jar:0.9.1.1]

at io.druid.guice.JacksonConfigManagerModule$1.start(JacksonConfigManagerModule.java:58) [druid-common-0.9.1.1.jar:0.9.1.1]

at com.metamx.common.lifecycle.Lifecycle.start(Lifecycle.java:259) [java-util-0.27.9.jar:?]

at io.druid.guice.LifecycleModule$2.start(LifecycleModule.java:155) [druid-api-0.9.1.1.jar:0.9.1.1]

at io.druid.cli.GuiceRunnable.initLifecycle(GuiceRunnable.java:91) [druid-services-0.9.1.1.jar:0.9.1.1]

at io.druid.cli.ServerRunnable.run(ServerRunnable.java:40) [druid-services-0.9.1.1.jar:0.9.1.1]

at io.druid.cli.Main.main(Main.java:105) [druid-services-0.9.1.1.jar:0.9.1.1]

Caused by: java.sql.SQLException: Cannot create PoolableConnectionFactory (java.net.ConnectException : Error connecting to server 52.53.243.72 on port 1,527 with message Connection timed out (Connection timed out).)

at org.apache.commons.dbcp2.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:2152) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.createDataSource(BasicDataSource.java:1903) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1413) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.skife.jdbi.v2.DataSourceConnectionFactory.openConnection(DataSourceConnectionFactory.java:36) ~[jdbi-2.63.1.jar:2.63.1]

at org.skife.jdbi.v2.DBI.open(DBI.java:212) ~[jdbi-2.63.1.jar:2.63.1]

… 15 more

Caused by: java.sql.SQLNonTransientConnectionException: java.net.ConnectException : Error connecting to server 52.53.243.72 on port 1,527 with message Connection timed out (Connection timed out).

at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.derby.client.am.SqlException.getSQLException(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.derby.jdbc.ClientDriver.connect(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.commons.dbcp2.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:39) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:205) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.validateConnectionFactory(BasicDataSource.java:2162) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:2148) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.createDataSource(BasicDataSource.java:1903) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1413) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.skife.jdbi.v2.DataSourceConnectionFactory.openConnection(DataSourceConnectionFactory.java:36) ~[jdbi-2.63.1.jar:2.63.1]

at org.skife.jdbi.v2.DBI.open(DBI.java:212) ~[jdbi-2.63.1.jar:2.63.1]

… 15 more

Caused by: org.apache.derby.client.am.DisconnectException: java.net.ConnectException : Error connecting to server 52.53.243.72 on port 1,527 with message Connection timed out (Connection timed out).

at org.apache.derby.client.net.NetAgent.(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.derby.client.net.NetConnection.newAgent_(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.derby.client.am.ClientConnection.(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.derby.client.net.NetConnection.(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.derby.client.net.ClientJDBCObjectFactoryImpl.newNetConnection(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.derby.jdbc.ClientDriver.connect(Unknown Source) ~[derbyclient-10.11.1.1.jar:?]

at org.apache.commons.dbcp2.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:39) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:205) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.validateConnectionFactory(BasicDataSource.java:2162) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:2148) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.createDataSource(BasicDataSource.java:1903) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1413) ~[commons-dbcp2-2.0.1.jar:2.0.1]

at org.skife.jdbi.v2.DataSourceConnectionFactory.openConnection(DataSourceConnectionFactory.java:36) ~[jdbi-2.63.1.jar:2.63.1]

at org.skife.jdbi.v2.DBI.open(DBI.java:212) ~[jdbi-2.63.1.jar:2.63.1]

… 15 more

Derby logs:

[ec2-user@ip-172-31-10-212 druid-0.9.1.1]$ cat var/druid/derby.log

Thu Dec 01 01:46:45 UTC 2016 : Could not listen on port 1527 on host 52.53.243.72:

java.net.BindException: Cannot assign requested address (Bind failed)

An exception was thrown during network server startup. DRDA_ListenPort.S:Could not listen on port 1527 on host 52.53.243.72:

java.net.BindException: Cannot assign requested address (Bind failed)

java.lang.reflect.InvocationTargetException

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:498)

at org.apache.derby.iapi.jdbc.DRDAServerStarter.run(Unknown Source)

at java.lang.Thread.run(Thread.java:745)

Caused by: java.lang.Exception: DRDA_ListenPort.S:Could not listen on port 1527 on host 52.53.243.72:

java.net.BindException: Cannot assign requested address (Bind failed)

at org.apache.derby.impl.drda.NetworkServerControlImpl.consolePropertyMessageWork(Unknown Source)

at org.apache.derby.impl.drda.NetworkServerControlImpl.consolePropertyMessage(Unknown Source)

at org.apache.derby.impl.drda.NetworkServerControlImpl.blockingStart(Unknown Source)

… 6 more

Here is the Coordinator runtime config & _common config

Common Config

druid.zk.service.host=52.53.243.72

druid.zk.paths.base=/druid

make sure that there is no firewall blocking or another service using that port

Hi Slim,
Thanks for response. I have checked that there is no firewall (I also enabled all the port and all the address in AWS ecurity groups for these hosts).

I also checked that there is no other daemons running on this port.

$ sudo netstat -nlp | grep :80

Nothing!

$ sudo lsof -i :80 | grep LISTEN

Nothing!

Is there a specific way to check why the Derby is not able to use that port or start in that port. Btw, I tried configuring other port numbers in the _common/common.runtime.properties file as well. That also does not seem to work. What are the options I’m left with?

Is there a different way to check if there is anything still blocking the port or to see the firewall rules.

I tried this as well (iptables -L)

[ec2-user@ip-172-31-10-212 druid-0.9.1.1]$ sudo iptables -L

Chain INPUT (policy ACCEPT)

target prot opt source destination

Chain FORWARD (policy ACCEPT)

target prot opt source destination

Chain OUTPUT (policy ACCEPT)

target prot opt source destination

Nothing fishy there as well!

Pls. help me out here :slight_smile:

Thanks,

Uday.

The port is 1527 not 80

Yeah - that was a cut n paste error .

I used 1527 indeed.

But i found the problem with this setup.

With AWS, we need to use the local IPs of the boxes for the cluster configs and not the public IPs. That was creating the issue.

Thanks,

Uday.

You might have better luck using the private IPs rather than the public IPs.