Multisource - Duplicate Table when adding metadata

[wirnse]

Hello!

I am facing troubles with mutlisource configuration.

Some background:

We use several databases which have the same schema/tables/etc.

These are oracle databases which run on the same server with different servicenames.

Teiid Version is 8.9.1.

Here is our vdb configuration which works fine:

<vdb name="rgkk-vdb" version="1">

<description>VDB for RGKK Databases</description>

<property name="UseConnectorMetadata" value="true" />

<model name="Traeger">

<property name="importer.useQualifiedName" value="false" />

<property name="importer.schemaPattern" value="ELF_SYSADMIN" />

<property name="multisource" value="true" />

<property name="multisource.columnName" value="TRAEGER_ID" />

<property name="multisource.addColumn" value="true" />

<source name="14" translator-name="oracle"

connection-jndi-name="java:/rgkk-14" />

<source name="18" translator-name="oracle"

connection-jndi-name="java:/rgkk-18" />

<metadata type="NATIVE,DDL"><![CDATA[

]]>

</metadata>

</model>

<translator name="translator-oracle" type="oracle">

<property name="SupportsNativeQueries" value="true" />

</translator>

</vdb>

With that configuration we can query the databases with  "Select * from termine where TRAEGER_ID=14" and it works just fine.

Now when we add something to metadata like:

<metadata type="NATIVE,DDL"><![CDATA[

     CREATE FOREIGN PROCEDURE PROC (arg1 IN STRING NOT NULL, arg2 IN STRING, TRAEGER_ID IN STRING)

]]>

</metadata>

We get the following exception:

13.02.2015 12:33:58,115 +0100 WARN [org.teiid.RUNTIME] (teiid-async-threads - 4) TEIID50036 VDB rgkk-vdb.1 model "Traeger" metadata failed to load. Reason:TEIID60013 Duplicate Table AHK_QUARTALSAETZE:

org.teiid.metadata.DuplicateRecordException: TEIID60013 Duplicate Table AHK_QUARTALSAETZE

at org.teiid.metadata.Schema.addTable(Schema.java:49) [teiid-api-8.9.1.jar:8.9.1]

at org.teiid.metadata.MetadataFactory.addTable(MetadataFactory.java:197) [teiid-api-8.9.1.jar:8.9.1]

at org.teiid.translator.jdbc.JDBCMetdataProcessor.addTable(JDBCMetdataProcessor.java:325)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.addTable(JDBCMetdataProcessor.java:308)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.getTables(JDBCMetdataProcessor.java:281)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.getConnectorMetadata(JDBCMetdataProcessor.java:144)

at org.teiid.translator.jdbc.JDBCExecutionFactory.getMetadata(JDBCExecutionFactory.java:309)

at org.teiid.translator.jdbc.JDBCExecutionFactory.getMetadata(JDBCExecutionFactory.java:57)

at org.teiid.query.metadata.NativeMetadataRepository.getMetadata(NativeMetadataRepository.java:83) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.NativeMetadataRepository.loadMetadata(NativeMetadataRepository.java:60) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.ChainingMetadataRepository.loadMetadata(ChainingMetadataRepository.java:55) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.ChainingMetadataRepository.loadMetadata(ChainingMetadataRepository.java:55) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.jboss.VDBService$6.run(VDBService.java:396) [teiid-jboss-integration-8.9.1.jar:8.9.1]

at org.teiid.jboss.VDBService$7.run(VDBService.java:444) [teiid-jboss-integration-8.9.1.jar:8.9.1]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]

at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]

at org.jboss.threads.JBossThread.run(JBossThread.java:122)

Any advise?

Thanks in advance!

[shawkins]

I'll have a look.  There's nothing that I know of off the top of my head that would cause something that looks like an unrelated interaction.   Would it be possible to provide the DDL for the good state of the Traeger schema?

[shawkins]

With a similar dummy setup I don't see any issues.  Are you sure it's not related for example to not using the qualified name for the Teiid name?

[wirnse]

Hello! Thanks for the answer.

When we set <property name="importer.useQualifiedName" value="true" /> then we get the same exception but with Schema name:

16.02.2015 08:22:39,340 +0100 WARN [org.teiid.RUNTIME] (teiid-async-threads - 2) TEIID50036 VDB rgkk-vdb.1 model "Traeger" metadata failed to load. Reason:TEIID60013 Duplicate Table ELF_SYSADMIN.AHK_QUARTALSAETZE:

org.teiid.metadata.DuplicateRecordException: TEIID60013 Duplicate Table ELF_SYSADMIN.AHK_QUARTALSAETZE

at org.teiid.metadata.Schema.addTable(Schema.java:49) [teiid-api-8.9.1.jar:8.9.1]

at org.teiid.metadata.MetadataFactory.addTable(MetadataFactory.java:197) [teiid-api-8.9.1.jar:8.9.1]

at org.teiid.translator.jdbc.JDBCMetdataProcessor.addTable(JDBCMetdataProcessor.java:325)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.addTable(JDBCMetdataProcessor.java:308)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.getTables(JDBCMetdataProcessor.java:281)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.getConnectorMetadata(JDBCMetdataProcessor.java:144)

at org.teiid.translator.jdbc.JDBCExecutionFactory.getMetadata(JDBCExecutionFactory.java:309)

at org.teiid.translator.jdbc.JDBCExecutionFactory.getMetadata(JDBCExecutionFactory.java:57)

at org.teiid.query.metadata.NativeMetadataRepository.getMetadata(NativeMetadataRepository.java:83) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.NativeMetadataRepository.loadMetadata(NativeMetadataRepository.java:60) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.ChainingMetadataRepository.loadMetadata(ChainingMetadataRepository.java:55) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.ChainingMetadataRepository.loadMetadata(ChainingMetadataRepository.java:55) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.jboss.VDBService$6.run(VDBService.java:396) [teiid-jboss-integration-8.9.1.jar:8.9.1]

at org.teiid.jboss.VDBService$7.run(VDBService.java:444) [teiid-jboss-integration-8.9.1.jar:8.9.1]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]

at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]

at org.jboss.threads.JBossThread.run(JBossThread.java:122)

Also when we try to define <property name="importer.importProcedures" value="true" /> then we also get the same exception.

[shawkins]

Do you have any other related logs?  Such as "Failed to get metadata, trying next source."?

I'm still not able to reproduce.  Is this the exact vdb.xml you are using?  Does the import work when you remove one of the sources?

[wirnse]

Yes it is the exact vdb.xml. And no there are no other logs. All i get after i deploy the vdb is:

17.02.2015 10:38:49,626 +0100 INFO [org.jboss.as.server.deployment] (MSC service thread 1-3) JBAS015876: Starte Deployment von "rgkk-vdb.xml" (runtime-name: "rgkk-vdb.xml")

17.02.2015 10:38:49,656 +0100 INFO [org.teiid.RUNTIME.VDBLifeCycleListener] (MSC service thread 1-1) TEIID40118 VDB rgkk-vdb.1 added to the repository - is reloading false

17.02.2015 10:38:49,657 +0100 INFO [org.teiid.RUNTIME] (MSC service thread 1-1) TEIID50029 VDB rgkk-vdb.1 model "Traeger" metadata is currently being loaded. Start Time: 17.02.15 10:38

17.02.2015 10:38:49,658 +0100 INFO [org.teiid.CONNECTOR] (teiid-async-threads - 2) OracleExecutionFactory Commit=true;DatabaseProductName=Oracle;DatabaseProductVersion=Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options;DriverMajorVersion=11;DriverMajorVersion=2;DriverName=Oracle JDBC driver;DriverVersion=11.2.0.3.0;IsolationLevel=2

17.02.2015 10:38:49,694 +0100 INFO [org.jboss.as.server] (management-handler-thread - 1) JBAS018559: "rgkk-vdb.xml" deployed (runtime-name: "rgkk-vdb.xml")

17.02.2015 10:39:01,952 +0100 WARN [org.teiid.RUNTIME] (teiid-async-threads - 2) TEIID50036 VDB rgkk-vdb.1 model "Traeger" metadata failed to load. Reason:TEIID60013 Duplicate Table AHK_QUARTALSAETZE:

org.teiid.metadata.DuplicateRecordException: TEIID60013 Duplicate Table AHK_QUARTALSAETZE

at org.teiid.metadata.Schema.addTable(Schema.java:49) [teiid-api-8.9.1.jar:8.9.1]

at org.teiid.metadata.MetadataFactory.addTable(MetadataFactory.java:197) [teiid-api-8.9.1.jar:8.9.1]

at org.teiid.translator.jdbc.JDBCMetdataProcessor.addTable(JDBCMetdataProcessor.java:325)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.addTable(JDBCMetdataProcessor.java:308)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.getTables(JDBCMetdataProcessor.java:281)

at org.teiid.translator.jdbc.JDBCMetdataProcessor.getConnectorMetadata(JDBCMetdataProcessor.java:144)

at org.teiid.translator.jdbc.JDBCExecutionFactory.getMetadata(JDBCExecutionFactory.java:309)

at org.teiid.translator.jdbc.JDBCExecutionFactory.getMetadata(JDBCExecutionFactory.java:57)

at org.teiid.query.metadata.NativeMetadataRepository.getMetadata(NativeMetadataRepository.java:83) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.NativeMetadataRepository.loadMetadata(NativeMetadataRepository.java:60) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.ChainingMetadataRepository.loadMetadata(ChainingMetadataRepository.java:55) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.query.metadata.ChainingMetadataRepository.loadMetadata(ChainingMetadataRepository.java:55) [teiid-engine-8.9.1.jar:8.9.1]

at org.teiid.jboss.VDBService$6.run(VDBService.java:396) [teiid-jboss-integration-8.9.1.jar:8.9.1]

at org.teiid.jboss.VDBService$7.run(VDBService.java:444) [teiid-jboss-integration-8.9.1.jar:8.9.1]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]

at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]

at org.jboss.threads.JBossThread.run(JBossThread.java:122)

Here is our datasource configuration in jboss eap 6.2:

<datasource jndi-name="java:/rgkk-14" pool-name="rgkk-14" enabled="true">

<connection-url>jdbc:oracle:thin:@url:port:1541:rgkket14</connection-url>

<driver>oracle</driver>

<security>

<user-name>ELF_SYSADMIN</user-name>

<password>secret</password>

</security>

</datasource>

<datasource jndi-name="java:/rgkk-18" pool-name="rgkk-18" enabled="true">

<connection-url>jdbc:oracle:thin:@url:port:rgkket18</connection-url>

<driver>oracle</driver>

<security>

<user-name>ELF_SYSADMIN</user-name>

<password>secret</password>

</security>    

</datasource>

Both databases have the user/schema ELF_SYSADMIN with the extact same tables/procedures/functions etc.

It is working when we remove one source.

Thanks!

[rareddy]

Steve: I could not find code where we are only loading from the first source in the multi-source model, the code reads like it reads from source after source. I know there were changes in dealing with multiple sources, forgot what were?

Herbert: can you run the server in DEBUG, there were couple other log statements we can capture to see more detail?

[shawkins]

> Steve: I could not find code where we are only loading from the first source in the multi-source model, the code reads like it reads from source after source. I know there were changes in dealing with multiple sources, forgot what were?

The code will attempt to load from each source until one is successful.  There is an issue however that the metadatafactory is not being reset, so the next load attempt will be against existing metadata.  Hence the question about "Failed to get metadata, trying next source." But yes that will be at a debug level.

> Yes it is the exact vdb.xml.

The root cause of the problem is that the DDL is not correct.  That means the series of events here is that we load from the first source, then hit an error with the DDL, then we attempt to load from the second source, but are still using the partial metadata from the first load.  The result is an inaccurate error that is masking the true problem.

Can you log an issue for this?  I have a fix ready that we'll get into 8.10 CR2.

[rareddy]

Logged [TEIID-3341] Metadata load failure between retries of multi-source models - JBoss Issue Tracker

[wirnse]

Sorry. Yes it is logged at DEBUG level.

7.02.2015 15:13:11,645 +0100 INFO [org.teiid.RUNTIME.VDBLifeCycleListener] (MSC service thread 1-12) TEIID40118 VDB rgkk-vdb.1 added to the repository - is reloading false

17.02.2015 15:13:11,646 +0100 INFO [org.teiid.RUNTIME] (MSC service thread 1-12) TEIID50029 VDB rgkk-vdb.1 model "Traeger" metadata is currently being loaded. Start Time: 17.02.15 15:13

17.02.2015 15:13:11,646 +0100 INFO [org.teiid.CONNECTOR] (teiid-async-threads - 3) OracleExecutionFactory Commit=true;DatabaseProductName=Oracle;DatabaseProductVersion=Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options;DriverMajorVersion=11;DriverMajorVersion=2;DriverName=Oracle JDBC driver;DriverVersion=11.2.0.3.0;IsolationLevel=2

17.02.2015 15:13:11,652 +0100 DEBUG [org.teiid.CONNECTOR] (teiid-async-threads - 3) JDBCMetadataProcessor - Importing tables

17.02.2015 15:13:11,671 +0100 INFO [org.jboss.as.server] (DeploymentScanner-threads - 1) JBAS018565: Deployment "rgkk-vdb.xml" durch Deployment "rgkk-vdb.xml" ersetzt

17.02.2015 15:13:11,692 +0100 DEBUG [org.teiid.CONNECTOR] (teiid-async-threads - 3) JDBCMetadataProcessor - Importing columns

17.02.2015 15:13:19,251 +0100 DEBUG [org.teiid.CONNECTOR] (teiid-async-threads - 3) JDBCMetadataProcessor - Importing primary keys

17.02.2015 15:13:20,007 +0100 DEBUG [org.teiid.CONNECTOR] (teiid-async-threads - 3) JDBCMetadataProcessor - Importing index info

17.02.2015 15:13:21,276 +0100 DEBUG [org.teiid.CONNECTOR] (teiid-async-threads - 3) JDBCMetadataProcessor - Importing foreign keys

17.02.2015 15:13:23,354 +0100 DEBUG [org.teiid.RUNTIME] (teiid-async-threads - 3)

org.teiid.metadata.ParseException: TEIID30386 org.teiid.api.exception.query.QueryParserException: TEIID31100 Parsing error: Encountered "DP_D_LOG( TRAEGER_ID [*]IN[*] STRING )" at line 2, column 71.

Was expecting: "string" | "varbinary" | "varchar" | "boolean" | "byte" | "tinyint" | "short" | "smallint" | "char" | "integer" ... Failed to get metadata, trying next source.

17.02.2015 15:13:23,359 +0100 DEBUG [org.teiid.CONNECTOR] (teiid-async-threads - 3) JDBCMetadataProcessor - Importing tables

17.02.2015 15:13:23,373 +0100 WARN [org.teiid.RUNTIME] (teiid-async-threads - 3) TEIID50036 VDB rgkk-vdb.1 model "Traeger" metadata failed to load. Reason:TEIID60013 Duplicate Table AHK_QUARTALSAETZE:

org.teiid.metadata.DuplicateRecordException: TEIID60013 Duplicate Table AHK_QUARTALSAETZE

...

But it acutally should work we used the example from:

Multisource Models - Teiid 8.9 - Project Documentation Editor

We defined:

CREATE FOREIGN PROCEDURE DP_D_LOG( TRAEGER_ID IN STRING );

Also could you please give us an example how to define a sequence? we tried it like described here: JDBC Translator - Teiid 8.9 - Project Documentation Editor

thanks

[shawkins]

> But it acutally should work we used the example from:

Yes, the in keyword is not where it should be.  That has been corrected now.  Instead of:

CREATE FOREIGN PROCEDURE DP_D_LOG( TRAEGER_ID IN STRING );

Use

CREATE FOREIGN PROCEDURE DP_D_LOG(IN TRAEGER_ID STRING );

> Also could you please give us an example how to define a sequence? we tried it like described here: JDBC Translator - Teiid 8.9 - Project Documentation Editor

There is a table representation and a function representation, both with example DDL.  Which did you try and what issues did you see?

[rareddy]

DDL Metadata - Teiid 8.10 (draft) - Project Documentation Editor

Should we turn the DEBUG message about parsing error into INFO or ERROR?

[shawkins]

> Should we turn the DEBUG message about parsing error into INFO or ERROR?

Could be raised to info.  Effectively we are only showing the last error to the user - which could be changed if desired.  Once this is resolved you'd see the expected error.

[wirnse]

we tried the following:

CREATE FOREIGN TABLE SEQ_TAB_TERMINE (nextval integer OPTIONS (NAMEINSOURCE 'SEQ_TAB_TERMINE.nextval'), currval (NAMEINSOURCE 'SEQ_TAB_TERMINE.currval') ) OPTIONS (NAMEINSOURCE 'DUAL')

and we get:

7.02.2015 15:58:31,077 +0100 DEBUG [org.teiid.RUNTIME] (teiid-async-threads - 4)

org.teiid.metadata.ParseException: TEIID30386 org.teiid.api.exception.query.QueryParserException: TEIID31100 Parsing error: Encountered "), currval [*]([*]NAMEINSOURCE 'SEQ_TAB_TERMINE.currval'" at line 2, column 137. Was expecting: "string" | "varbinary" | "varchar" | "boolean" | "byte" | "tinyint" | "short" | "smallint" | "char" | "integer" ... Failed to get metadata, trying next source.

[shawkins]

The OPTIONS keyword / type was missing from the example, which is now corrected:

currval (NAMEINSOURCE 'SEQ_TAB_TERMINE.currval') )

should be

currval integer OPTIONS (NAMEINSOURCE 'SEQ_TAB_TERMINE.currval') )