Cloudbreak autoscaling doesn't work

[#1]

I launched a Cloudbreak Deployer v2.7.0 (latest) on AWS following the instruction: https://docs.hortonworks.com/HDPDocuments/Cloudbreak/Cloudbreak-2.4.1/content/aws-launch/index.html

I created a cluster and tested the autoscaling functionality, however, it always failed with the following error found by `cbd logs-tail periscope` command:

periscope_1    | 2018-06-26 03:02:30,040 [getThreadPoolExecutorFactoryBean-36] createAmbariClient:44 INFO  c.s.p.s.AmbariClientProvider - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] Create Ambari client to connect to 172.31.47.29:9443
periscope_1    | 2018-06-26 03:02:30,050 [getThreadPoolExecutorFactoryBean-36] run:60 INFO  c.s.p.m.e.MetricEvaluator - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] Checking metric based alert: 'disk-usage'
periscope_1    | 2018-06-26 03:02:30,051 [getThreadPoolExecutorFactoryBean-36] getRawResource:84 INFO  c.s.a.c.AmbariClientUtils - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] AmbariClient getRawResource, resourceRequestMap: {path=https://172.31.47.29:9443/api/v1/clusters, query={fields=Clusters}}
periscope_1    | 2018-06-26 03:02:30,069 [getThreadPoolExecutorFactoryBean-36] getRawResource:84 INFO  c.s.a.c.AmbariClientUtils - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] AmbariClient getRawResource, resourceRequestMap: {path=https://172.31.47.29:9443/api/v1/clusters/aisin-storm/alert_history, query={AlertHistory/definition_name=ambari_agent_disk_usage}}
periscope_1    | 2018-06-26 03:02:30,084 [getThreadPoolExecutorFactoryBean-36] getRawResource:84 INFO  c.s.a.c.AmbariClientUtils - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] AmbariClient getRawResource, resourceRequestMap: {path=https://172.31.47.29:9443/api/v1/clusters/aisin-storm/alert_history/28}
periscope_1    | 2018-06-26 03:02:30,097 [getThreadPoolExecutorFactoryBean-36] run:72 INFO  c.s.p.m.e.MetricEvaluator - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] Alert: disk-usage is in 'CRITICAL' state since 5.22 min(s)
periscope_1    | 2018-06-26 03:02:30,103 [getThreadPoolExecutorFactoryBean-36] createAmbariClient:44 INFO  c.s.p.s.AmbariClientProvider - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] Create Ambari client to connect to 172.31.47.29:9443
periscope_1    | 2018-06-26 03:02:30,107 [getThreadPoolExecutorFactoryBean-36] getRawResource:84 INFO  c.s.a.c.AmbariClientUtils - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] AmbariClient getRawResource, resourceRequestMap: {path=https://172.31.47.29:9443/api/v1/clusters, query={fields=Clusters}}
periscope_1    | 2018-06-26 03:02:30,130 [getThreadPoolExecutorFactoryBean-36] getRawResource:84 INFO  c.s.a.c.AmbariClientUtils - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] AmbariClient getRawResource, resourceRequestMap: {path=https://172.31.47.29:9443/api/v1/clusters/aisin-storm}
periscope_1    | 2018-06-26 03:02:30,249 [getThreadPoolExecutorFactoryBean-43] scaleUp:76 INFO  c.s.p.m.h.ScalingRequest - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] Sending request to add 1 instance(s) into host group 'supervisor', triggered policy 'scale-out'
periscope_1    | 2018-06-26 03:02:30,313 [getThreadPoolExecutorFactoryBean-43] logExceptions:127 WARN  o.h.e.j.s.SqlExceptionHelper - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] SQL Error: 0, SQLState: 22001
periscope_1    | 2018-06-26 03:02:30,313 [getThreadPoolExecutorFactoryBean-43] logExceptions:127 WARN  o.h.e.j.s.SqlExceptionHelper - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] SQL Error: 0, SQLState: 22001
periscope_1    | 2018-06-26 03:02:30,314 [getThreadPoolExecutorFactoryBean-43] logExceptions:129 ERROR o.h.e.j.s.SqlExceptionHelper - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] ERROR: value too long for type character varying(255)
periscope_1    | 2018-06-26 03:02:30,314 [getThreadPoolExecutorFactoryBean-43] logExceptions:129 ERROR o.h.e.j.s.SqlExceptionHelper - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] ERROR: value too long for type character varying(255)
periscope_1    | 2018-06-26 03:02:30,314 [getThreadPoolExecutorFactoryBean-43] release:193 INFO  o.h.e.j.b.i.AbstractBatchImpl - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] HHH000010: On release of batch it still contained JDBC statements
periscope_1    | 2018-06-26 03:02:30,314 [getThreadPoolExecutorFactoryBean-43] release:193 INFO  o.h.e.j.b.i.AbstractBatchImpl - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] HHH000010: On release of batch it still contained JDBC statements
periscope_1    | 2018-06-26 03:02:30,315 [getThreadPoolExecutorFactoryBean-43] run:65 ERROR c.s.p.m.h.ScalingRequest - [owner:11d6ae4f-8de0-446e-83d9-1b3492185d6b] [id:3] [cb-stack-id:3] Cannot retrieve an oauth token from the identity server
periscope_1    | org.springframework.dao.DataIntegrityViolationException: could not execute statement; SQL [n/a]; nested exception is org.hibernate.exception.DataException: could not execute statement
periscope_1    | 	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:282)
periscope_1    | 	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:244)
periscope_1    | 	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:521)
periscope_1    | 	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
periscope_1    | 	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
periscope_1    | 	at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:504)
periscope_1    | 	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:292)
periscope_1    | 	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
periscope_1    | 	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
periscope_1    | 	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136)
periscope_1    | 	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
periscope_1    | 	at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:133)
periscope_1    | 	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
periscope_1    | 	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
periscope_1    | 	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
periscope_1    | 	at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:57)
periscope_1    | 	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
periscope_1    | 	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
periscope_1    | 	at com.sun.proxy.$Proxy188.save(Unknown Source)
periscope_1    | 	at sun.reflect.GeneratedMethodAccessor92.invoke(Unknown Source)
periscope_1    | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
periscope_1    | 	at java.lang.reflect.Method.invoke(Method.java:498)
periscope_1    | 	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
periscope_1    | 	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
periscope_1    | 	at com.sun.proxy.$Proxy189.save(Unknown Source)
periscope_1    | 	at com.sequenceiq.periscope.service.HistoryService.createEntry(HistoryService.java:28)
periscope_1    | 	at com.sequenceiq.periscope.monitor.handler.ScalingRequest.scaleUp(ScalingRequest.java:88)
periscope_1    | 	at com.sequenceiq.periscope.monitor.handler.ScalingRequest.run(ScalingRequest.java:60)
periscope_1    | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
periscope_1    | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
periscope_1    | 	at java.lang.Thread.run(Thread.java:748)
periscope_1    | Caused by: org.hibernate.exception.DataException: could not execute statement
periscope_1    | 	at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:118)
periscope_1    | 	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
periscope_1    | 	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109)
periscope_1    | 	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:95)
periscope_1    | 	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207)
periscope_1    | 	at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45)
periscope_1    | 	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2949)
periscope_1    | 	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3449)
periscope_1    | 	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:89)
periscope_1    | 	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:582)
periscope_1    | 	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:456)
periscope_1    | 	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
periscope_1    | 	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
periscope_1    | 	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1282)
periscope_1    | 	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:465)
periscope_1    | 	at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2963)
periscope_1    | 	at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2339)
periscope_1    | 	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:485)
periscope_1    | 	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:147)
periscope_1    | 	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38)
periscope_1    | 	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231)
periscope_1    | 	at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:65)
periscope_1    | 	at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:61)
periscope_1    | 	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:517)
periscope_1    | 	... 28 common frames omitted
periscope_1    | Caused by: org.postgresql.util.PSQLException: ERROR: value too long for type character varying(255)
periscope_1    | 	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2455)
periscope_1    | 	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2155)
periscope_1    | 	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:288)
periscope_1    | 	at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:430)
periscope_1    | 	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:356)
periscope_1    | 	at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:168)
periscope_1    | 	at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:135)
periscope_1    | 	at com.zaxxer.hikari.proxy.PreparedStatementProxy.executeUpdate(PreparedStatementProxy.java:61)
periscope_1    | 	at com.zaxxer.hikari.proxy.HikariPreparedStatementProxy.executeUpdate(HikariPreparedStatementProxy.java)
periscope_1    | 	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204)
periscope_1    | 	... 47 common frames omitted
periscope_1    | 2018-06-26 03:02:31,236 [Timer-1] collectStackDetails:49 INFO  c.s.p.s.StackCollectorService - [owner:spring] [id:] [cb-stack-id:] Evaluate cluster management for stack: aisin-storm (ID:3)
periscope_1    | 2018-06-26 03:02:31,260 [getThreadPoolExecutorFactoryBean-35] createAmbariClient:44 INFO  c.s.p.s.AmbariClientProvider - [owner:periscope] [id:] [cb-stack-id:] Create Ambari client to connect to 172.31.47.29:9443<br>

Looks like Cloudbreak Deployer failed to add or update a record in PostgreSQL because a value to add is too long for the type character varying(255), according to the error log above. However, I have no idea what value it is and how to make it shorter.

Could you please help me how to resolve the problem? Thank you in advance.

[#2 · Accepted solution]

Hi @Mai Nakagawa,

It looks like we have some logging issue here, so I can't see the real reason. Could you attach please the Cloudbreak log file from the same time? You can find the file under your deployment directory in the logs subfolder.

In the meanwhile we will work on fixing the logging issue.

Thanks

[#3]

Hi @mmolnar,

Thank you for your quick response. Attached please find the files in the logs subfolder of my deployment directory.

Please note that logs-1.tar.gz contains files under logs/autoscale and logs/cloudbreak directories and that logs-2.tar.gz contains the other files under logs directory. Also, please be noted that the both files are actually .tar.bz2 - this is in order to make the size smaller than the limitation (512 kB). I used .tar.gz extension just because the website doesn't allow .tar.bz2 extension for attachments.

Cheers,

Mai Nakagawa

[#4]

Hi @Mai Nakagawa,

I could not find the cause of you issue in the logs, but I have a build which have the logging issue solved hopefully. If it is a test environment you have, you can check out the new periscope to see the real error.

To have the new version please add the following line to you Profile under deployment directory:

export DOCKER_TAG_PERISCOPE=2.7.1-rc.11

And after it you have to issue the

cbd restart

command. This will terminate cloudbreak, regenerate the docker-compose.yml with the new version of periscope, then start cloudbreak again.

[#5]

Hi @mmolnar,

The error message changed as attached. It indicates the error is because of the unrecognized field "type", however, I have no idea how to fix it unfortunately.

I'm wondering if it's a bug of v2.7.0 because the error doesn't occur when I do the same thing on v2.4.0

Thank you,

Mai Nakagawa

[#6]

Hi @Mai Nakagawa,

yes, it's a bug in 2.7.0 but we managed to create the fix, but we are not ready yet to release 2.7.1
If you would like to use the fix, please update the DOCKER_TAG_PERISCOPE variable to 2.7.1-rc.13