question Re: Cannot start Ambari-metrics-collector in Support Questions

Cannot start Ambari-metrics-collector

akafazov — Wed, 06 Jul 2016 22:33:10 GMT

Hi,

I am having difficulties getting the ambari-metrics-collector to start. I have HBase running in distributed mode.

ambari-metrics-collectorlog.txtI have attached the ambari-metrics-collector.log

I already tried the suggestions from this thread: https://community.hortonworks.com/questions/15818/ambari-metrics-collector-now-starting.html as well as the workaround for issue 6 here https://cwiki.apache.org/confluence/display/AMBARI/Known+Issues

Any tips will be very appreciated.

Re: Cannot start Ambari-metrics-collector

orenault — Wed, 06 Jul 2016 23:08:48 GMT

Which version of Ambari are you using?

Re: Cannot start Ambari-metrics-collector

akafazov — Thu, 07 Jul 2016 00:11:10 GMT

Hi Orivier,

It is Version2.1.2.1

Re: Cannot start Ambari-metrics-collector

tyu — Thu, 07 Jul 2016 00:22:55 GMT

2016-07-06 14:59:14,466 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=m2.domain:2181 sessionTimeout=120000 watcher=hconnection- 0x7bc9e6ab0x0, quorum=m2.domain:2181, baseZNode=/hbase-secure

Looks like AMS tried to connect to hbase cluster's znode.

AMS should use /ams-hbase-secure as base znode.

Can you check your configuration ?

Re: Cannot start Ambari-metrics-collector

akafazov — Thu, 07 Jul 2016 00:56:46 GMT

Hi, I changed it, but now I am getting

2016-07-06 17:55:20,187 ERROR org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation: The node /ams-hbase-secure is not in ZooKeeper. It should have been written by the master. Check the value configured in 'zookeeper.znode.parent'. There could be a mismatch with the one configured in the master.

Re: Cannot start Ambari-metrics-collector

avijayan — Thu, 07 Jul 2016 01:20:08 GMT

Hi Angel,

From your error, it looks like AMS is talking to cluster zookeeper (port 2181) . AMS in Version 2.1.2.1 uses it's own zookeeper in all modes of operation (port 61181).

Can you share your hbase-site.xml in /etc/ams-hbase/conf ? That will help us figure out the issue.

Thanks!

Re: Cannot start Ambari-metrics-collector

sidwagle — Thu, 07 Jul 2016 01:21:54 GMT

Please revert back the znode setting to default, if cluster is not kerberized:

/ams-hbase-unsecure

Also, make sure the quorum value in ams-hbase-site is:

hbase.zookeeper.quorum

Re: Cannot start Ambari-metrics-collector

akafazov — Thu, 07 Jul 2016 01:41:24 GMT

Hi swagle,

the cluster is kerberized. hbase.zookeeper.quorum looks ok

Re: Cannot start Ambari-metrics-collector

Shelton — Thu, 07 Jul 2016 04:37:19 GMT

@Angel Kafazov

See the attached doc should help.

Re: Cannot start Ambari-metrics-collector

sidwagle — Thu, 07 Jul 2016 11:19:57 GMT

@Angel Kafazov We need to look at the Master, RS and ZK logs to identify the issue. Can you upload them from /var/log/ambari-metrics-collector/ ?

Re: Cannot start Ambari-metrics-collector

Shelton — Thu, 07 Jul 2016 11:36:03 GMT

@Angel Kafazov

Did you take note of no.9 "zookeeper.znode.parent" and restart all the components

Re: Cannot start Ambari-metrics-collector

sidwagle — Thu, 07 Jul 2016 13:02:17 GMT

@Geoffrey Shelton Okot The document suggests setting the zookeeper.znode.parent to the same value as HBase service which is somewhat incorrect for versions > 2.1.2.1. Prior to 2.2, the value was not set so it defaulted to /hbase, this was ok because AMS started its own ZK. Post 2.2, AMS talks to cluster ZK and thereby the znode is set to /ams-hbase-(unsecure/secure).

Logs would indicate whether TGT was acquired correctly and if the problem is something totally different.

Re: Cannot start Ambari-metrics-collector

akafazov — Thu, 07 Jul 2016 14:08:39 GMT

Hi Geoffrey,

In HBase config I have:

zookeeper.znode.parent=/hbase-secure

In Ambari metrics:

zookeeper.znode.parent=/ams-hbase-secure

I am not sure if those must be the same.

Re: Cannot start Ambari-metrics-collector

akafazov — Thu, 07 Jul 2016 21:38:42 GMT

hbase-ams-master-m2-trunkatedlog.txt

hbase-ams-zookeeper-m2log.txt

hbase-ams-regionserver-m2log.txt

sorry for the delay

Re: Cannot start Ambari-metrics-collector

sidwagle — Fri, 08 Jul 2016 02:03:29 GMT

Both Master and Regions server logs indicate unable to login to Kerberos.

Login failure for amshbasemaster/m2.DOMAIN@DOMAIN from keytab /etc/security/keytabs/ams-hbase.regionserver.keytab: javax.security.auth.login.LoginException: Unable to obtain password from user

Can you check if you can manually login with the ams keytabs under /etc/security/keytabs/ams*.keytab

Example: kinit -kt /etc/security/keytabs/ams-hbase.regionserver.keytab amshbasemaster/m2.DOMAIN@DOMAIN

Re: Cannot start Ambari-metrics-collector

akafazov — Fri, 08 Jul 2016 02:50:34 GMT

I have attached the master, zk and rs logs.

hbase-ams-master-m2-trunkatedlog.txt

hbase-ams-zookeeper-m2log.txt

hbase-ams-regionserver-m2log.txt

There seems to be authentication issue in the RS:

2016-07-06 11:42:43,688 ERROR [main] regionserver.HRegionServerCommandLine: Region server exiting
java.lang.RuntimeException: Failed construction of Regionserver: class org.apache.hadoop.hbase.regionserver.HRegionServer
at org.apache.hadoop.hbase.regionserver.HRegionServer.constructRegionServer(HRegionServer.java:2636)
at org.apache.hadoop.hbase.regionserver.HRegionServerCommandLine.start(HRegionServerCommandLine.java:64)
at org.apache.hadoop.hbase.regionserver.HRegionServerCommandLine.run(HRegionServerCommandLine.java:87)
at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)
at org.apache.hadoop.hbase.util.ServerCommandLine.doMain(ServerCommandLine.java:126)
at org.apache.hadoop.hbase.regionserver.HRegionServer.main(HRegionServer.java:2651)
Caused by: java.lang.reflect.InvocationTargetException
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
at org.apache.hadoop.hbase.regionserver.HRegionServer.constructRegionServer(HRegionServer.java:2634)
... 5 more
Caused by: java.io.IOException: Login failure for amshbasemaster/m2.DOMAIN@DOMAIN from keytab /etc/security/keytabs/ams-hbase.regionserver.keytab: javax.security.auth.login.LoginException: Unable to obtain password from user
at org.apache.hadoop.security.UserGroupInformation.loginUserFromKeytab(UserGroupInformation.java:962)
at org.apache.hadoop.security.SecurityUtil.login(SecurityUtil.java:246)
at org.apache.hadoop.hbase.security.User$SecureHadoopUser.login(User.java:386)
at org.apache.hadoop.hbase.security.User.login(User.java:253)
at org.apache.hadoop.hbase.security.UserProvider.login(UserProvider.java:115)
at org.apache.hadoop.hbase.regionserver.HRegionServer.login(HRegionServer.java:612)
at org.apache.hadoop.hbase.regionserver.HRegionServer.<init>(HRegionServer.java:550)
... 10 more
Caused by: javax.security.auth.login.LoginException: Unable to obtain password from user
at com.sun.security.auth.module.Krb5LoginModule.promptForPass(Krb5LoginModule.java:897)
at com.sun.security.auth.module.Krb5LoginModule.attemptAuthentication(Krb5LoginModule.java:760)
at com.sun.security.auth.module.Krb5LoginModule.login(Krb5LoginModule.java:617)
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:497)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
at javax.security.auth.login.LoginContext.login(LoginContext.java:587)
at org.apache.hadoop.security.UserGroupInformation.loginUserFromKeytab(UserGroupInformation.java:953)
... 16 more

ZOOKEEPER:

ERROR [main] quorum.QuorumPeerConfig: Invalid configuration, only one server specified (ignoring)

MASTER:

2016-07-06 10:48:18,075 WARN  [main-SendThread(localhost:61181)] zookeeper.ClientCnxn: Session 0x155bfd1eb150003 for server null, unexpected error, closing socket connection and attempting reconnect
java.net.ConnectException: Connection refused
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
2016-07-06 10:48:20,103 INFO  [main-SendThread(localhost:61181)] zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:61181. Will not attempt to authenticate using SASL (unknown error)
2016-07-06 10:48:20,104 WARN  [main-SendThread(localhost:61181)] zookeeper.ClientCnxn: Session 0x155bfd1eb150003 for server null, unexpected error, closing socket connection and attempting reconnect
java.net.ConnectException: Connection refused
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
2016-07-06 10:48:21,724 INFO  [main-SendThread(localhost:61181)] zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:61181. Will not attempt to authenticate using SASL (unknown error)
2016-07-06 10:48:21,725 WARN  [main-SendThread(localhost:61181)] zookeeper.ClientCnxn: Session 0x155bfd1eb150003 for server null, unexpected error, closing socket connection and attempting reconnect
java.net.ConnectException: Connection refused
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
2016-07-06 10:48:21,825 WARN  [RS:0;m2:49385] zookeeper.RecoverableZooKeeper: Possibly transient ZooKeeper, quorum=localhost:61181, exception=org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/rs/m2.tmaut.tlabsdata.com,49385,1467802057410
2016-07-06 10:48:21,826 ERROR [RS:0;m2:49385] zookeeper.RecoverableZooKeeper: ZooKeeper delete failed after 4 attempts
2016-07-06 10:48:21,826 WARN  [RS:0;m2:49385] regionserver.HRegionServer: Failed deleting my ephemeral node
org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/rs/m2.tmaut.tlabsdata.com,49385,1467802057410
at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.delete(RecoverableZooKeeper.java:178)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.deleteNode(ZKUtil.java:1345)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.deleteNode(ZKUtil.java:1334)
at org.apache.hadoop.hbase.regionserver.HRegionServer.deleteMyEphemeralNode(HRegionServer.java:1403)
at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:1079)
at java.lang.Thread.run(Thread.java:745)

Re: Cannot start Ambari-metrics-collector

akafazov — Fri, 08 Jul 2016 18:59:50 GMT

So I removed the ambari-metrics service and added it again (moving to another node didn't work). I also made some changes:

- switch to distributed mode

- modified zookeeper.znode.parent=/hbase-secure

- manually recreated ams.collector.keytab and zk.service.keytab due to authentication errors in the log

- changed hbase. zookeeper.property.clientPort to 2181 from 61181

- changed rootdir from local to HDFS

I think I am getting cluse as AMS can connect to zookeeper:

INFO org.apache.phoenix.query.ConnectionQueryServicesImpl: Successfull login to secure cluster!!

However I am getting error connecting to HBase

WARN org.apache.hadoop.yarn.server.applicationhistoryservice.metrics.timeline.query.DefaultPhoenixDataSource: Unable to connect to HBase store using Phoenix.
java.sql.SQLException: ERROR 103 (08004): Unable to establish connection.

I'll attached the logs in a comment

Re: Cannot start Ambari-metrics-collector

akafazov — Fri, 08 Jul 2016 19:06:49 GMT

logs

ambari-metrics-collectorlog.txt

Re: Cannot start Ambari-metrics-collector

akafazov — Fri, 08 Jul 2016 19:51:35 GMT

Found wrong rootdir hostname, after that I am getting

2016-07-08 12:44:39,320 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server m2.domain/172.16.164.131:2181. Will not attempt to authenticate using SASL (unknown error)
2016-07-08 12:44:39,321 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to m2.domain/172.16.164.131:2181, initiating session
2016-07-08 12:44:39,328 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server m2.domain/172.16.164.131:2181, sessionid = 0x255ca408b8d0063, negotiated timeout = 40000
2016-07-08 12:44:50,376 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:45:07,243 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:45:16,166 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:45:32,517 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:45:54,803 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:46:10,720 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:46:37,467 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:47:01,600 WARN org.apache.hadoop.hbase.ipc.AbstractRpcClient: Couldn't setup connection for amshbase/m2.domain@domain to amshbasemaster/m1.domain@domain
2016-07-08 12:47:01,600 INFO org.apache.hadoop.hbase.client.RpcRetryingCaller: Call exception, tries=10, retries=35, started=142264 ms ago, cancelled=false, msg=

Re: Cannot start Ambari-metrics-collector

akafazov — Fri, 08 Jul 2016 22:42:40 GMT

Also moving ambari-metrics-collector to another host fails in the wizard with the following error:

stderr: 
Traceback (most recent call last):
  File "/var/lib/ambari-agent/cache/common-services/AMBARI_METRICS/0.1.0/package/scripts/service_check.py", line 165, in <module>
    AMSServiceCheck().execute()
  File "/usr/lib/python2.6/site-packages/resource_management/libraries/script/script.py", line 216, in execute
    method(env)
  File "/usr/lib/python2.6/site-packages/ambari_commons/os_family_impl.py", line 89, in thunk
    return fn(*args, **kwargs)
  File "/var/lib/ambari-agent/cache/common-services/AMBARI_METRICS/0.1.0/package/scripts/service_check.py", line 92, in service_check
    raise Fail("Metrics were not saved. Service check has failed. "
resource_management.core.exceptions.Fail: Metrics were not saved. Service check has failed. 
Connection failed.
 stdout:
2016-07-08 15:41:07,832 - Ambari Metrics service check was started.
2016-07-08 15:41:07,844 - Generated metrics:
{
  "metrics": [
    {
      "metricname": "AMBARI_METRICS.SmokeTest.FakeMetric",
      "appid": "amssmoketestfake",
      "hostname": "w1.domain",
      "timestamp": 1467992467000,
      "starttime": 1467992467000,
      "metrics": {
        "1467992467000": 0.113469705131,
        "1467992468000": 1467992467000
      }
    }
  ]
}
2016-07-08 15:41:07,844 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:41:17,856 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:41:17,857 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:41:27,867 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:41:27,867 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:41:37,878 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:41:37,878 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:41:47,891 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:41:47,892 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:41:57,904 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:41:57,905 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:42:07,919 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:42:07,919 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:42:17,929 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:42:17,930 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:42:27,941 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:42:27,942 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/
2016-07-08 15:42:37,956 - Connection failed. Next retry in 10 seconds.
2016-07-08 15:42:37,956 - Connecting (POST) to w3.domain:6188/ws/v1/timeline/metrics/