EM will not start - no apparent error in the log
Article ID: 187382
Updated On:
Products
CA Application Performance Management Agent (APM / Wily / Introscope)
CA Application Performance Management (APM / Wily / Introscope)
INTROSCOPE
DX Application Performance Management
Issue/Introduction
The Enterprise Manager will not start properly the process is running but it does not properly initialize and is not accessible.
There is no apparent error message in the em.log indicating any problem. The last entries before it seems to stop initializing are
3/25/20 09:45:46.180 AM GMT [INFO] [main] [Manager.AppMapSubsystem] AppMapEntity: fisAppMapEnabledtrue, fisAppMapLegacyEnabled=false
3/25/20 09:45:46.294 AM GMT [INFO] [main] [com.wily.apm.model.SpringAppContext] SpringAppContext initialization, logging configured with '/Introscope10.7.0.45/./config/log4j.properties'
3/25/20 09:45:49.379 AM GMT [INFO] [main] [com.ca.wily.jasypt.APMEncryptablePropertyPlaceholderConfigurer] Loading properties file from URL [file:/Introscope10.7.0.45/./config/APMEnterpriseManager.properties]
3/25/20 09:45:50.157 AM GMT [INFO] [main] [com.mchange.v2.log.MLog] MLog clients using log4j logging.
3/25/20 09:45:50.461 AM GMT [INFO] [main] [com.mchange.v2.c3p0.C3P0Registry] Initializing c3p0-0.9.2.1 [built 20-March-2013 11:16:28 +0000; debug? true; trace: 10]
3/25/20 09:45:51.481 AM GMT [INFO] [main] [com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource] Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 3, acquireRetryAttempts -> 3, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> apmDataSource, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> oracle.jdbc.OracleDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1br0i6ta94qn7u3ftlavz|47a4eee2, idleConnectionTestPeriod -> 120, initialPoolSize -> 2, jdbcUrl -> jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=myhost.com)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=PCAAPMDB))), maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 600, maxPoolSize -> 4, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 2, numHelperThreads -> 3, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, userOverrides -> {}, usesTraditionalReflectiveProxies -> false ]
3/25/20 09:54:15.097 AM GMT [INFO] [TimerBean] [Manager] Detected hot config change to /Introscope10.7.0.45/./config/IntroscopeEnterpriseManager.properties
3/25/20 09:54:30.001 AM GMT [DEBUG] [master clock] [Manager.Clock] Total Time for harvest: 0ms
3/25/20 09:54:30.002 AM GMT [DEBUG] [master clock] [Manager.Clock] Master harvest took 0ms
3/25/20 09:54:45.000 AM GMT [DEBUG] [master clock] [Manager.Clock] Total Time for harvest: 0ms
3/25/20 09:54:45.001 AM GMT [DEBUG] [master clock] [Manager.Clock] Master harvest took 0ms
There is no apparent error message in the em.log indicating any problem. The last entries before it seems to stop initializing are
3/25/20 09:45:46.180 AM GMT [INFO] [main] [Manager.AppMapSubsystem] AppMapEntity: fisAppMapEnabledtrue, fisAppMapLegacyEnabled=false
3/25/20 09:45:46.294 AM GMT [INFO] [main] [com.wily.apm.model.SpringAppContext] SpringAppContext initialization, logging configured with '/Introscope10.7.0.45/./config/log4j.properties'
3/25/20 09:45:49.379 AM GMT [INFO] [main] [com.ca.wily.jasypt.APMEncryptablePropertyPlaceholderConfigurer] Loading properties file from URL [file:/Introscope10.7.0.45/./config/APMEnterpriseManager.properties]
3/25/20 09:45:50.157 AM GMT [INFO] [main] [com.mchange.v2.log.MLog] MLog clients using log4j logging.
3/25/20 09:45:50.461 AM GMT [INFO] [main] [com.mchange.v2.c3p0.C3P0Registry] Initializing c3p0-0.9.2.1 [built 20-March-2013 11:16:28 +0000; debug? true; trace: 10]
3/25/20 09:45:51.481 AM GMT [INFO] [main] [com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource] Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 3, acquireRetryAttempts -> 3, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> apmDataSource, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> oracle.jdbc.OracleDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1br0i6ta94qn7u3ftlavz|47a4eee2, idleConnectionTestPeriod -> 120, initialPoolSize -> 2, jdbcUrl -> jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=myhost.com)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=PCAAPMDB))), maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 600, maxPoolSize -> 4, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 2, numHelperThreads -> 3, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, userOverrides -> {}, usesTraditionalReflectiveProxies -> false ]
3/25/20 09:54:15.097 AM GMT [INFO] [TimerBean] [Manager] Detected hot config change to /Introscope10.7.0.45/./config/IntroscopeEnterpriseManager.properties
3/25/20 09:54:30.001 AM GMT [DEBUG] [master clock] [Manager.Clock] Total Time for harvest: 0ms
3/25/20 09:54:30.002 AM GMT [DEBUG] [master clock] [Manager.Clock] Master harvest took 0ms
3/25/20 09:54:45.000 AM GMT [DEBUG] [master clock] [Manager.Clock] Total Time for harvest: 0ms
3/25/20 09:54:45.001 AM GMT [DEBUG] [master clock] [Manager.Clock] Master harvest took 0ms
Cause
After an hour the following error was reported in the log
3/25/20 10:45:56.379 AM GMT [WARN] [C3P0PooledConnectionPoolManager[identityToken->1br0i6ta94qn7u3ftlavz|47a4eee2, dataSourceName->apmDataSource]-HelperThread-#2] [com.mchange.v2.resourcepool.BasicResourcePool] com[email protected]73b922ae -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (3). Last acquisition attempt exception:
java.sql.SQLException: ORA-04021: timeout occurred while waiting to lock object
The ORA-04021 exception indicates an issue with the Oracle hosted APM database
3/25/20 10:45:56.379 AM GMT [WARN] [C3P0PooledConnectionPoolManager[identityToken->1br0i6ta94qn7u3ftlavz|47a4eee2, dataSourceName->apmDataSource]-HelperThread-#2] [com.mchange.v2.resourcepool.BasicResourcePool] com[email protected]73b922ae -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (3). Last acquisition attempt exception:
java.sql.SQLException: ORA-04021: timeout occurred while waiting to lock object
The ORA-04021 exception indicates an issue with the Oracle hosted APM database
Environment
Release : 10.7.0
Component : APM Agents
Resolution
Customer DBA addressed the space resource issue on the node where Oracle was hosted
Feedback
Yes
No
Powered by
