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
When Database is not accessible you have to make sure following 5 properties are correct.
Check the connectivity using SQL Developer for Oracle or PgAdmin for PostgresSQL.
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>
What are the Oracle alert, trace, and error logs telling you?
I have a doubt about following
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.
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
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.
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%';
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;
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.
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
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.
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.
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?
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
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.
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?
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
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.sql3/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.03/12/18 02:54:16.837 PM EDT [INFO] [main] [root] [UpgradeSchema] - Upgraded to the desired version - 10.5.2.03/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;
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;
SQL> select ts_db_versions from apmmgr.ts_domains;
So which index would I be dropping (if I follow that KB article)?
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.
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.
Can we either have a addendum to that KB or create a new KB reflecting the issue I am facing?
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.
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)
FORK NOT NULL NUMBER(19)
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.
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 ☺
Manish A. Parikh | (W): (703) 563-8141 | (C): (919) 449-7175 | firstname.lastname@example.org<mailto:email@example.com>
**Please consider the cost of paper and the environment before printing this email.**
Let us work this via the support case and once resolved we can publish the resolution here.
I have replied via the support case.
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?
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)
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?
...should be the updated one.