DX Application Performance Management

after installing EM (MoM) v10.5.2_SP2, I started up (after copying all the necessary config from v10.1.0.15 MoM EM), I get the following ERRORs constantly in the logs

3/05/18 09:53:49.358 AM EST [INFO] [Thread-47] [Manager.AppMap] DB is not available. Next attempt to retry to connect in 15 seconds.
3/05/18 09:54:04.360 AM EST [INFO] [Thread-47] [Manager.AppMap] Starting ATC Initialization, DB version is 10.5.2.0, Application version is version 10.5.2.
3/05/18 09:54:04.364 AM EST [INFO] [Thread-47] [Manager.AppMap] Inserted 0 Initial records.
3/05/18 09:54:04.606 AM EST [ERROR] [Thread-47] [Manager.AppMap]

org.springframework.jdbc.BadSqlGrammarException: PreparedStatementCallback; bad SQL grammar [SELECT s.vertex_id, s.alert_id, s.metric_id, s.state FROM appmap_states_20180228 s WHERE s.end_time = ?]; nested exception is java.sql.SQLSyntaxErrorException: ORA-00904: "S"."METRIC_ID": invalid identifier

at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:231)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:660)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:695)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:722)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:772)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.query(NamedParameterJdbcTemplate.java:192)
at com.wily.introscope.appmap.em.model.dao.impl.gmt.GMTNamedParameterJdbcTemplate.query(GMTNamedParameterJdbcTemplate.java:131)
at com.wily.introscope.appmap.em.model.dao.impl.CollectorOperationsDaoImpl.getLastVertexStatuses(CollectorOperationsDaoImpl.java:1075)
at sun.reflect.GeneratedMethodAccessor455.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
at com.sun.proxy.$Proxy133.getLastVertexStatuses(Unknown Source)
at sun.reflect.GeneratedMethodAccessor455.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at com.wily.introscope.appmap.em.model.dao.interceptor.ProfilingMethodInterceptor.invoke(ProfilingMethodInterceptor.java:54)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
at com.sun.proxy.$Proxy134.getLastVertexStatuses(Unknown Source)
at com.wily.introscope.appmap.em.ontology.OntologyModelBean.postConstruct(OntologyModelBean.java:138)
at com.wily.introscope.appmap.config.AppMapPostConstructExecutor.initializeAll(AppMapPostConstructExecutor.java:160)
at com.wily.introscope.appmap.config.AppMapPostConstructExecutor.access$1(AppMapPostConstructExecutor.java:147)
at com.wily.introscope.appmap.config.AppMapPostConstructExecutor$1.run(AppMapPostConstructExecutor.java:248)
Caused by: java.sql.SQLSyntaxErrorException: ORA-00904: "S"."METRIC_ID": invalid identifier

at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:439)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:395)
at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:802)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:436)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:186)
at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:521)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:205)
at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:861)
at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1145)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1259)
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3449)
at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3493)
at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:703)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:644)
... 32 more

Appreciate any and all assistance on this issue. I also have a case open - #00977324

Thanks in advance

Manish

When Database is not accessible you have to make sure following 5 properties are correct.

1. DB Hostname
2. DB Port
3. service Name
4. DB User ID
5. DB Password

Check the connectivity using SQL Developer for Oracle or PgAdmin for PostgresSQL.

junaidwily

I am using Oracle for APM DB and all the properties are correct and I matched it with v10.1 properties to make sure also.

Here is my tess-db-cfg.xml file:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-configuration PUBLIC
"-//Hibernate/Hibernate Configuration DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd">
<hibernate-configuration>
<session-factory>
<property name="em.dbtype">Oracle</property>
<property name="hibernate.connection.username">apmmgr</property>
<property name="hibernate.connection.password">******</property>
<property name="plainTextPasswords">true</property>
<property name="hibernate.dialect">org.hibernate.dialect.OracleDialect</property>
<property name="hibernate.connection.driver_class">oracle.jdbc.driver.OracleDriver</property>
<property name="hibernate.connection.url">jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=xx.xx.***.xx)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=cemdev)))</property>
<property name="hibernate.connection.tcpKeepAlive">true</property>
</session-factory>
</hibernate-configuration>

Manish:

What are the Oracle alert, trace, and error logs telling you?

mparikh72

I have a  doubt about following

<property name="hibernate.connection.password">******</property>

<property name="plainTextPasswords">true</property>

can you put plain text password and make plainTextPasswords property true and restart you EM.

when EM is up make sure the property is showing false and password is encrypted.

I  hope  it will solve the problem.

Can you  also try SQL developer to connect to DB.

Thanks

junaidwily

I intentionally put the asterisk (*) to cover the password so I don't show it to the community. The password is actually plaintext 

Yes I believe this to be key - when the EM starts it should encyrpt the password and set plain text password to false. If it is not doing it I suspect that the is some error in the tess-db-cfg.xml file, this could have been introduced if the manually editted the file at some point. If you say 10.1 file is working ok then try taking a copy of that file in the 10.5.2 environment and the carefully set the userid password and connect string (set plain text back to true) without making any changes outside the fields. I had a similar problem myself and I could not see where the corruption was and following the above worked for me

thanks

Mike

Also if you get no errors on the collectors you could just copy the file from there - that should also work

So looks like, according to CA Support...

-----------

"I reviewed the information you sent and the error occurring indicates that a column name, we are attempting to run a select statement on, is missing (the integer METRIC_ID). When you get a chance, can you please ask your DBA to send the results of the following:
SELECT ts_db_versions FROM ts_domains;    --> to check if the db schema was fully upgraded. 
SELECT * FROM appmap_states_20180228;  --> to check what information is contained in the table the select statement is being run.

Here is an example of the table from my environment (Postgres):

For clarification purposes, please also let me know if there is any information of importance stored yet in this database (as it might be simplest to drop and recreate the schema)."

------------------------------

So, I am going to have DBA do this and see what happens.

Hi Manish,

I have a new 10.5.2 Oracle EM install and I just forced creation of an APPMAP_STATES_* table with a new app.

Describing the new table APPMAP_STATES_20180305 shows the METRIC_ID in the definition i.e.

===

SQL> select object_name,object_type from user_objects where object_name like 'APPMAP_STATES%';

OBJECT_NAME
--------------------------------------------------------------------------------
OBJECT_TYPE
-----------------------
APPMAP_STATES_20180305
TABLE

APPMAP_STATES_201803051_IDX
INDEX

APPMAP_STATES_201803052_IDX
INDEX

SQL> desc APPMAP_STATES_20180305
Name Null? Type
----------------------------------------- -------- ----------------------------
VERTEX_ID NOT NULL NUMBER(19)
METRIC_ID NOT NULL NUMBER(19)
ALERT_ID NOT NULL NUMBER(19)
START_TIME NOT NULL TIMESTAMP(6)
END_TIME NOT NULL TIMESTAMP(6)
FORK NOT NULL NUMBER(19)
STATE NUMBER(19)

SQL> select ts_db_versions from ts_domains;

TS_DB_VERSIONS
--------------------------------------------------------------------------------
10.5.2.0

===

So some problem with the schema upgrade during the 10.1-10.5.2 upgrade step is definitely a possible root cause.

I also found a few occurrences of this being reported before, but it seems the true root cause could not be found.

Regards,

Lynn

Lynn_Williams

Probably a good idea for the product group to look into this and possibly have them write up a KB article or re-develop the installer or issue a patch

Tom_Wyszomierski

Looks like I had to drop the entire schema (apmmgr) of my database (cemdev) and start from scratch. I am currently working with our DBA and CA Support on dropping "apmmgr" and then recreating it. After.........run the EM installer.

Manish:

I have marked this as correct since you are working a case AND a number of good next steps have been provided. However, I encourage you to continue posting to this thread.

Thanks 

Hal German

So I restored the db from a back-up v10.1.0.0 and then ran the installer with option #3 (Databse Only). The upgrade failed with the following ERROR:

3/13/18 03:21:40.747 PM EDT [ERROR] [main] [root] [UpgradeSchema] - Error creating schema

I don't see anything else in any other logs indicating anything else. Any idea?

Thanks

Manish

mparikh72

Make sure the folder you are running installer + installer.bin file and the folder where you installing you database schema has sufficient permission. I had the same problem and I found that the permission was the issue. try to make it 755 or 777

junaidwily

The EM is on one server (physical) and the DB is on a separate server (VM). 18 months ago when I upgraded from v9.5.3 to v10.1.0.15, I didn't have any issues and no one has made any changes to the permissions on the DB server.

Hi Manish,

So you are running the 10.5.2 EM installer on the DB server?

Regarding "[ERROR] [main] [root] [UpgradeSchema] - Error creating schema" is that from main install log or the schematools.log? Or maybe schematools.log did not get created?

Also is this a root or non-root install of Postgres?

Thanks

Lynn

Lynn_Williams

No, I am running v10.5.2 EM installer on EM server where it connects to the DB server on port 1521 and should upgrades the DB from v10.1.0.0 to v10.5.2

The ERROR is from "schematools.log". I've uploaded all the necessary install logs on the case notes if anyone is interested in reviewing them. 

This is a non-root install of Oracle DB.

I am in a bit of a time crunch so would like to resolve this asap.

again, any/all assistance is greatly appreciated

Manish

Hi Manish,

I had a look at the schematools.log from your case 00977324:

The seems to have been 1 error during the schema upgrade  and I think that has result in the final error "Error creating schema" i.e.

===

3/12/18 02:46:19.826 PM EDT [INFO] [main] [com.wily.apm.dbutil.SqlExecutor] Running sql statement: ALTER TABLE appmap_vertices DROP (search_attrib1, search_attrib2, search_attrib3, search_attrib4, search_attrib5, application_id)
3/12/18 02:46:29.620 PM EDT [ERROR] [main] [com.wily.apm.dbutil.SqlExecutor] Sql error in file: dbupgrade-apm-oracle-10.1.0.0.sql
3/12/18 02:46:29.620 PM EDT [ERROR] [main] [com.wily.apm.dbutil.SqlExecutor] java.sql.SQLException: ORA-02429: cannot drop index used for enforcement of unique/primary key

...

3/12/18 02:54:16.837 PM EDT [INFO] [main] [root] [UpgradeSchema] - Current release after running an upgrade is: 10.5.2.0
3/12/18 02:54:16.837 PM EDT [INFO] [main] [root] [UpgradeSchema] - Upgraded to the desired version - 10.5.2.0
3/12/18 02:54:16.845 PM EDT [ERROR] [main] [root] [UpgradeSchema] - Error creating schema

===

That ORA-02429 error may not be anything to be concerned about but we will need to check.

I suspect the overall upgrade has been successful. Does this SQL return "10.5.2.0"?

select ts_db_versions from ts_domains;

Thanks

Lynn

Looks like known problem 

APM 10.5.1 Oracle database upgrade gives the error - CA Knowledge 

yes, the SQL does return 10.5.2.0

SQL> select name from v$database;

NAME

---------

CEMDEV

SQL> select ts_db_versions from apmmgr.ts_domains;

TS_DB_VERSIONS

--------------------------------------------------------------------------------

10.5.2.0

SQL>

Lynn_Williams

So which index would I be dropping (if I follow that KB article)?

Hi Manish,

From looking at the case that spawned the KB, the KB seems to have incomplete details.

There appears to have been an extra index in 10.1 version of the APPMAP_VERTICES table (maybe APPMAP_VERTICES_ATTRIB_LOOKUP?) that is not dropped by dbupgrade-apm-oracle-10.1.0.0.sql before it runs the ALTER TABLE on the table to drop the 5 columns search_attrib1, search_attrib2, search_attrib3, search_attrib4, search_attrib5, application_id.

I think it best if Tom_Wyszomierski works with you on the case tomorrow because it will need some further research to get the 100% details for you. If I have time in the meantime I will try to setup a 10.1 environment and compare.

Regards,

Lynn

Lynn,

Tom_Wyszomierski is out all this week. I'd be more than happy to set up a WebEx for tomorrow if I can get a definite resource to assist me and my DBA to see this through to resolution. I am kind of running close to deadline for this.

Cheers,

Manish

Lynn,

Can we either have a addendum to that KB or create a new KB reflecting the issue I am facing?

Hi Manish,

Looks like Tom sent you an email earlier today and I think he is in. If not we will try to arrange another resource for tomorrow.

Yes we will review/update the KB as required or we may create a new one if the root cause is different for 10.1->10.5.2 upgrade.

Thanks

Lynn

Lynn_Williams - any updates? I haven't heard anything thus far

My DBA tried the following and wasn't successful

SQL> desc APMMGR.appmap_vertices

 Name                                      Null?    Type

 ----------------------------------------- -------- ----------------------------

 VERTEX_ID                                 NOT NULL NUMBER(19)

 START_TIME                                NOT NULL TIMESTAMP(6)

 END_TIME                                  NOT NULL TIMESTAMP(6)

 VERTEX_NAME                                        VARCHAR2(2048)

 BUSINESS_SERVICE                                   VARCHAR2(2048)

 APPLICATION_ID                                     VARCHAR2(256)

 SEARCH_ATTRIB1                                     VARCHAR2(256)

 SEARCH_ATTRIB2                                     VARCHAR2(256)

 SEARCH_ATTRIB3                                     VARCHAR2(256)

 SEARCH_ATTRIB4                                     VARCHAR2(256)

 SEARCH_ATTRIB5                                     VARCHAR2(256)

 GATHERED_ATTRIBS                                   CLOB

 OTHER_ATTRIBS                                      CLOB

 FORK                                      NOT NULL NUMBER(19)

SQL>

Hi Manish,

Yesterday I was not able to recreate the problem in-house for a 10.1->10.5.2 Oracle APM DB upgrade and I am not sure why. I just started my shift in Australia so will start to have another look now and review the latest files you uploaded to the case.

Regards,

Lynn

If you want to do reach out to me via phone then feel free to call me on my mobile +1 (919) 449-7175. I am happy to do a WebEx today your time if you want. Don’t worry about how late it is here ☺

Thank You,

V/r,

Manish A. Parikh | (W): (703) 563-8141 | (C): (919) 449-7175 | manish.a.parikh@baesystems.com<mailto:manish.a.parikh@baesystems.com>

**Please consider the cost of paper and the environment before printing this email.**

Hi Manish,

Let us work this via the support case and once resolved we can publish the resolution here.

I have replied via the support case.

Thanks

Lynn

ok, sounds good.

For the benefit of the community we resolved this problem as follows:

Subsequently I was able to recreate the upgrade error in-house after I used my 10.1 system for team Center attribute activity.

The root cause was the APPMAP_VERTICES index APPMAP_VERTICES_ATTRIB_LOOKUP which after restoring the DB backup needed to be dropped prior to running the upgrade again. To be able to drop it required primary key constraint to be temporarily disabled as follows:
ALTER TABLE APPMAP_VERTICES DISABLE CONSTRAINT <PRIMARY_KEY_CONSTRAINT>;
DROP INDEX APPMAP_VERTICES_ATTRIB_LOOKUP;
ALTER TABLE APPMAP_VERTICES ENABLE CONSTRAINT <PRIMARY_KEY_CONSTRAINT>;
(NOTE: <PRIMARY_KEY_CONSTRAINT> name is system generated so will be specific to the Oracle instance.)

So the question now is...

When I plan my prod env upgrade, will I come across this same scenario?

Hi Manish,

Yes with any Oracle APM DB upgrade from 10.1 to 10.5.x, I think this same problem could potentially occur (the APPMAP_VERTICES table only had index APPMAP_VERTICES_ATTRIB_LOOKUP in 9.7, 10.0 & 10.1, so it should only impact upgrades from that release)

Regards,

Lynn

that sucks. gotta do it all over again

btw, did a new KB article get published for this issue or are we going to stick with other one?

APM 10.5.1 Oracle database upgrade gives the error - CA Knowledge 

...should be the updated one.