在我的环境中,有套Cloudera CDH 5 在启动CM服务【cloudera-scm-server】的时候,遇到如题所示的错误;
具体如下:

[root@cloudera1 ~]# service cloudera-scm-server start
Starting cloudera-scm-server:                              [  OK  ]
[root@cloudera1 ~]# 
[root@cloudera1 ~]# service cloudera-scm-server status
cloudera-scm-server dead but pid file exists
[root@cloudera1 ~]# 

可以看到,发起启动服务的命令虽然执行成功,但是在稍后的服务状态查看的结果中,其实,该服务并没有正确的被启动。

来看看具体的报错信息,看看cloudera的错误日志:【/var/log/cloudera-scm-server/cloudera-scm-server.log】

下面是在该错误发生时候的服务启动的后台日志的全文:

2019-10-22 09:07:09,307 INFO main:com.cloudera.server.cmf.Main: Starting SCM Server. JVM Args: [-Dlog4j.configuration=file:/etc/cloudera-scm-server/log4j.properties, -Dfile.encoding=UTF-8, -Dcmf.root.logger=INFO,LOGFILE, -Dcmf.log.dir=/var/log/cloudera-scm-server, -Dcmf.log.file=cloudera-scm-server.log, -Dcmf.jetty.threshhold=WARN, -Dcmf.schema.dir=/usr/share/cmf/schema, -Djava.awt.headless=true, -Djava.net.preferIPv4Stack=true, -Dpython.home=/usr/share/cmf/python, -XX:+UseConcMarkSweepGC, -XX:+UseParNewGC, -XX:+HeapDumpOnOutOfMemoryError, -Xmx2G, -XX:MaxPermSize=256m, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=/tmp, -XX:OnOutOfMemoryError=kill -9 %p], Args: [], Version: 5.13.3 (#6 built by jenkins on 20180328-1830 git: f90c58536c252d70a23bde6d94514d92a1f111d4)
2019-10-22 09:07:09,419 INFO main:org.mortbay.log: Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
2019-10-22 09:07:09,598 INFO main:org.springframework.context.support.ClassPathXmlApplicationContext: Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@4426a725: startup date [Tue Oct 22 09:07:09 EDT 2019]; root of context hierarchy
2019-10-22 09:07:09,664 INFO main:org.springframework.beans.factory.xml.XmlBeanDefinitionReader: Loading XML bean definitions from class path resource [webapp/WEB-INF/spring/beanRefFactory.xml]
2019-10-22 09:07:10,197 INFO main:org.springframework.beans.factory.support.DefaultListableBeanFactory: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3e372b61: defining beans [bootstrapContext,rootContext]; root of factory hierarchy
2019-10-22 09:07:10,232 INFO main:org.springframework.context.support.GenericApplicationContext: Refreshing org.springframework.context.support.GenericApplicationContext@3bd660e5: startup date [Tue Oct 22 09:07:10 EDT 2019]; root of context hierarchy
2019-10-22 09:07:10,235 INFO main:org.springframework.beans.factory.support.DefaultListableBeanFactory: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@141aa8d4: defining beans [commandLineConfigurationBean,entityManagerFactoryBean,com.cloudera.server.cmf.TrialState,com.cloudera.server.cmf.TrialManager,com.cloudera.cmf.crypto.LicenseLoader]; root of factory hierarchy
2019-10-22 09:07:10,323 INFO main:com.cloudera.enterprise.CommonMain: Reading database properties from /etc/cloudera-scm-server/db.properties
2019-10-22 09:07:10,329 INFO main:com.cloudera.enterprise.CommonMain: Statistics not enabled, c3p0 JMX disabled
2019-10-22 09:07:10,539 INFO main:org.hibernate.annotations.common.Version: HCANN000001: Hibernate Commons Annotations {4.0.2.Final}
2019-10-22 09:07:10,548 INFO main:org.hibernate.Version: HHH000412: Hibernate Core {4.2.2.Final}
2019-10-22 09:07:10,551 INFO main:org.hibernate.cfg.Environment: HHH000206: hibernate.properties not found
2019-10-22 09:07:10,553 INFO main:org.hibernate.cfg.Environment: HHH000021: Bytecode provider name : javassist
2019-10-22 09:07:11,275 INFO main:org.hibernate.cfg.Configuration: HHH000221: Reading mappings from resource: cmf.hbm.xml
2019-10-22 09:07:11,674 INFO main:org.hibernate.service.jdbc.connections.internal.ConnectionProviderInitiator: HHH000130: Instantiating explicit connection provider: org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider
2019-10-22 09:07:11,675 INFO main:org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider: HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://mysql02/cmf?useUnicode=true&characterEncoding=UTF-8
2019-10-22 09:07:11,675 INFO main:org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider: HHH000046: Connection properties: {user=cmf, password=****, autocommit=true, release_mode=auto}
2019-10-22 09:07:11,675 INFO main:org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider: HHH000006: Autocommit mode: true
2019-10-22 09:07:11,723 INFO main:com.mchange.v2.log.MLog: MLog clients using log4j logging.
2019-10-22 09:07:11,876 INFO main:com.mchange.v2.c3p0.C3P0Registry: Initializing c3p0-0.9.1.1 [built 15-March-2007 01:32:31; debug? true; trace: 10]
2019-10-22 09:07:11,947 INFO main:org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider: HHH000149: JDBC isolation level: READ_COMMITTED
2019-10-22 09:07:12,016 INFO main:com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource: Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@9a931106 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@e57c2743 [ acquireIncrement -> 3, acquireRetryAttempts -> 5, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 20000, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1hgef7na51vl1cm2mve4r6|250382ca, idleConnectionTestPeriod -> 300, initialPoolSize -> 3, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 50, maxStatements -> 2500, maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@17730025 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 1hgef7na51vl1cm2mve4r6|6119d27b, jdbcUrl -> jdbc:mysql://mysql02/cmf?useUnicode=true&characterEncoding=UTF-8, properties -> {user=******, password=******, autocommit=true, release_mode=auto} ], preferredTestQuery -> null, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 1hgef7na51vl1cm2mve4r6|767bdf2a, numHelperThreads -> 3 ]
2019-10-22 09:07:12,438 INFO main:org.hibernate.dialect.Dialect: HHH000400: Using dialect: org.hibernate.dialect.MySQL5InnoDBDialect
2019-10-22 09:07:12,453 INFO main:org.hibernate.engine.jdbc.internal.LobCreatorBuilder: HHH000424: Disabling contextual LOB creation as createClob() method threw error : java.lang.reflect.InvocationTargetException
2019-10-22 09:07:12,711 INFO main:org.hibernate.engine.transaction.internal.TransactionFactoryInitiator: HHH000268: Transaction strategy: org.hibernate.engine.transaction.internal.jdbc.JdbcTransactionFactory
2019-10-22 09:07:12,719 INFO main:org.hibernate.hql.internal.ast.ASTQueryTranslatorFactory: HHH000397: Using ASTQueryTranslatorFactory
2019-10-22 09:07:12,896 INFO main:org.hibernate.cache.spi.UpdateTimestampsCache: HHH000250: Starting update timestamps cache at region: org.hibernate.cache.spi.UpdateTimestampsCache
2019-10-22 09:07:12,899 WARN main:org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory: HHH020003: Could not find a specific ehcache configuration for cache named [org.hibernate.cache.spi.UpdateTimestampsCache]; using defaults.
2019-10-22 09:07:12,903 INFO main:org.hibernate.cache.internal.StandardQueryCache: HHH000248: Starting query cache at region: org.hibernate.cache.internal.StandardQueryCache
2019-10-22 09:07:12,904 WARN main:org.hibernate.cache.ehcache.AbstractEhcacheRegionFactory: HHH020003: Could not find a specific ehcache configuration for cache named [org.hibernate.cache.internal.StandardQueryCache]; using defaults.
2019-10-22 09:07:12,949 INFO main:org.hibernate.validator.internal.util.Version: HV000001: Hibernate Validator 5.0.1.Final
2019-10-22 09:07:15,435 INFO main:com.cloudera.enterprise.CommonMain: Statistics not enabled, JMX will not be registered
2019-10-22 09:07:15,612 INFO main:com.cloudera.server.cmf.bootstrap.EntityManagerFactoryBean: MYSQL database engine and table mapping: {InnoDB=[CM_VERSION, ROLE_CONFIG_GROUPS, PARCELS, DIAGNOSTICS_EVENTS, REVISIONS, CLUSTERS_AUD, RELEASES_AUD, PARCEL_COMPONENTS, CONFIGS_AUD, CLUSTER_MANAGED_RELEASES, ROLES_AUD, CLUSTERS, SNAPSHOT_POLICIES, USERS, CONFIG_CONTAINERS, CM_PEERS, ROLE_STALENESS_STATUS, PROCESS_ACTIVE_RELEASES, CLIENT_CONFIGS_TO_HOSTS, METRICS, HOST_TEMPLATES, CLUSTER_UNDISTRIBUTED_RELEASES, USER_ROLES, GLOBAL_SETTINGS, CLUSTER_ACTIVATED_RELEASES_AUD, HOSTS_AUD, ROLES, PROCESSES_DETAIL, ROLE_CONFIG_GROUPS_AUD, AUDITS, SERVICES_AUD, PROCESSES, USER_SETTINGS, COMMANDS, CONFIGS, EXTERNAL_ACCOUNTS, COMMAND_SCHEDULES, CREDENTIALS, CLUSTER_ACTIVATED_RELEASES, SCHEMA_VERSION, SERVICES, RELEASES, EXTERNAL_ACCOUNTS_AUD, CLIENT_CONFIGS, HOST_TEMPLATE_TO_ROLE_CONF_GRP, COMMANDS_DETAIL, HOSTS]}
2019-10-22 09:07:15,635 INFO main:com.cloudera.enterprise.dbutil.DbUtil: Schema version table already exists.
2019-10-22 09:07:15,636 INFO main:com.cloudera.enterprise.dbutil.DbUtil: DB Schema version 51300.
2019-10-22 09:07:15,649 INFO main:com.cloudera.enterprise.dbutil.DbUtil: Schema version table already exists.
2019-10-22 09:07:15,650 INFO main:com.cloudera.enterprise.dbutil.DbUtil: DB Schema version 51300.
2019-10-22 09:07:15,650 INFO main:com.cloudera.enterprise.dbutil.DbUtil: Current database schema version: 51300
2019-10-22 09:07:15,719 WARN main:org.hibernate.engine.jdbc.spi.SqlExceptionHelper: SQL Error: 1881, SQLState: HY000
2019-10-22 09:07:15,719 ERROR main:org.hibernate.engine.jdbc.spi.SqlExceptionHelper: Operation not allowed when innodb_forced_recovery > 0.
2019-10-22 09:07:15,722 ERROR main:com.cloudera.server.cmf.components.ScmActive: ScmActive: 
javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute statement
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387)
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1310)
	at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1397)
	at org.hibernate.ejb.AbstractQueryImpl.executeUpdate(AbstractQueryImpl.java:108)
	at com.cloudera.cmf.persist.DbVersionDao.markCmActive(DbVersionDao.java:112)
	at com.cloudera.server.cmf.components.ScmActive.markScmActive(ScmActive.java:194)
	at com.cloudera.server.cmf.bootstrap.EntityManagerFactoryBean.runScmActiveAtBootup(EntityManagerFactoryBean.java:412)
	at com.cloudera.server.cmf.bootstrap.EntityManagerFactoryBean.getObject(EntityManagerFactoryBean.java:129)
	at com.cloudera.server.cmf.bootstrap.EntityManagerFactoryBean.getObject(EntityManagerFactoryBean.java:65)
	at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:142)
	at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.getObjectFromFactoryBean(FactoryBeanRegistrySupport.java:102)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getObjectForBeanInstance(AbstractBeanFactory.java:1440)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:247)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:192)
	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:322)
	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:106)
	at org.springframework.beans.factory.support.ConstructorResolver.resolveConstructorArguments(ConstructorResolver.java:616)
	at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:148)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1003)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:907)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:485)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
	at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:293)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:290)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:192)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:585)
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:895)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:425)
	at com.cloudera.server.cmf.Main.bootstrapSpringContext(Main.java:392)
	at com.cloudera.server.cmf.Main.<init>(Main.java:242)
	at com.cloudera.server.cmf.Main.main(Main.java:216)
Caused by: org.hibernate.exception.GenericJDBCException: could not execute statement
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:136)
	at org.hibernate.engine.query.spi.NativeSQLQueryPlan.performExecuteUpdate(NativeSQLQueryPlan.java:204)
	at org.hibernate.internal.SessionImpl.executeNativeUpdate(SessionImpl.java:1313)
	at org.hibernate.internal.SQLQueryImpl.executeUpdate(SQLQueryImpl.java:401)
	at org.hibernate.ejb.QueryImpl.internalExecuteUpdate(QueryImpl.java:194)
	at org.hibernate.ejb.AbstractQueryImpl.executeUpdate(AbstractQueryImpl.java:99)
	... 28 more
Caused by: java.sql.SQLException: Operation not allowed when innodb_forced_recovery > 0.
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3597)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3529)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1990)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2151)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2625)
	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2119)
	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2415)
	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2333)
	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2318)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:133)
	... 33 more
2019-10-22 09:07:15,726 ERROR main:com.cloudera.server.cmf.components.ScmActive: ScmActive failed. Bootup = true
2019-10-22 09:07:15,726 ERROR main:com.cloudera.server.cmf.components.ScmActive: ScmActive was not able to access CM identity to validate it.
2019-10-22 09:07:15,726 ERROR main:com.cloudera.server.cmf.components.ScmActive: ScmActive is deferring the validation to the next run in 15 seconds.
2019-10-22 09:07:15,729 INFO main:com.cloudera.server.cmf.bootstrap.EntityManagerFactoryBean: ScmActive at bootup: Completed successfully.
2019-10-22 09:07:16,424 INFO main:org.springframework.context.support.ClassPathXmlApplicationContext: Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@ff1ea2d: startup date [Tue Oct 22 09:07:16 EDT 2019]; parent: org.springframework.context.support.GenericApplicationContext@3bd660e5
2019-10-22 09:07:16,425 INFO main:org.springframework.beans.factory.xml.XmlBeanDefinitionReader: Loading XML bean definitions from class path resource [webapp/WEB-INF/spring/cmf-root-config.xml]
2019-10-22 09:07:16,485 INFO JmxPeriodicLogging-0:com.cloudera.enterprise.PeriodicJmx: JMX: {"beans":[{"name":"java.lang:type=MemoryPool,name=CMS Old Gen","modelerType":"sun.management.MemoryPoolImpl","CollectionUsage":
(过多的输出,...)

其中,错误的原因是:

2019-10-22 09:07:15,719 WARN main:org.hibernate.engine.jdbc.spi.SqlExceptionHelper: SQL Error: 1881, SQLState: HY000
2019-10-22 09:07:15,719 ERROR main:org.hibernate.engine.jdbc.spi.SqlExceptionHelper: Operation not allowed when innodb_forced_recovery > 0.
2019-10-22 09:07:15,722 ERROR main:com.cloudera.server.cmf.components.ScmActive: ScmActive: 
javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute statement
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387)

(过多的输出,...)

可以看到,Cloudera Manager的服务【cloudera-scm-server】在启动服务的时候,是会检测MySQL的状态的;
如果innodb_forced_recovery的值大于0,也就是不是以正常的方式启动的,那么Cloudera会认为后端数据库的状态不正常,将阻止服务端进程的进一步启动。

在我的场景中,前面是因为我因为一些原因强行关机后,导致MySQL数据库crash,因此我设置了【innodb_forced_recovery】参数去修复数据库。

所以,到这里,我们知道了,文首cloudera不能启动的原因,其实是因为MySQL的一个参数状态不正常导致的(PS:不正常与不正确是有差别的)。

下面,修复本文的Cloudera的这个问题。


MySQL服务器:

[root@mysql02 log]# mysql -u root -p
Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 17
Server version: 5.7.27-log MySQL Community Server (GPL)

Copyright (c) 2000, 2019, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show variables like 'innodb_force%';
+-----------------------------+-------+
| Variable_name               | Value |
+-----------------------------+-------+
| innodb_force_load_corrupted | OFF   |
| innodb_force_recovery       | 0     |
+-----------------------------+-------+
2 rows in set (0.00 sec)

mysql> 

然后,Cloudera的服务就可以正常启动了:

[root@cloudera1 ~]# service cloudera-scm-server start
Starting cloudera-scm-server:                              [  OK  ]
[root@cloudera1 ~]# service cloudera-scm-server status
cloudera-scm-server (pid  103492) is running...
[root@cloudera1 ~]# 
[root@cloudera1 ~]# netstat -tupln | grep 7180
tcp        0      0 0.0.0.0:7180                0.0.0.0:*                   LISTEN      103494/java         
[root@cloudera1 ~]# 

Finished。

说点什么

avatar

此站点使用Akismet来减少垃圾评论。了解我们如何处理您的评论数据

  Subscribe  
提醒
隐藏
变装