[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Jan Stastny (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Jan Stastny edited comment on TEIID-5270 at 3/1/18 10:06 AM:
-------------------------------------------------------------
[~van.halbert] Well, I can reliably. You have to try hard to pick the right moment probably.
was (Author: jstastny):
[~vhalbert] Well, I can reliably. You have to try hard to pick the right moment probably.
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Components: JDG Connector, Misc. Connectors
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Jan Stastny (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Jan Stastny commented on TEIID-5270:
------------------------------------
[~vhalbert] Well, I can reliably. You have to try hard to pick the right moment probably.
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Components: JDG Connector, Misc. Connectors
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5265) AssertionError: Batch not found in storage
by Steven Hawkins (JIRA)
[ https://issues.jboss.org/browse/TEIID-5265?page=com.atlassian.jira.plugin... ]
Steven Hawkins updated TEIID-5265:
----------------------------------
Component/s: Query Engine
> AssertionError: Batch not found in storage
> ------------------------------------------
>
> Key: TEIID-5265
> URL: https://issues.jboss.org/browse/TEIID-5265
> Project: Teiid
> Issue Type: Bug
> Components: Query Engine
> Affects Versions: 10.1
> Reporter: Bram Gadeyne
> Assignee: Steven Hawkins
>
> While executing the following query:
> {code:sql}
> insert into rep149_cci(PatientID,age,Orig,Upd,agepointsO,agepointsU,AMI,CHF,PVD,CVD,DEM,CPD,PUD,MLD,SLD,DNC,DWC,HEM,RED,MAL,MST,HIV)
> select cci.patientid as patientid,cci.age as age,cci.orig as orig,cci.upd as upd,cci.agepointso as agepointso,cci.agepointsu as agepointsu,
> cci.charlson_ami as ami,cci.charlson_chf as chf,cci.charlson_pvd as pvd,cci.charlson_cvd as cvd,cci.charlson_dem as dem,cci.charlson_cpd as cpd,cci.charlson_pud as pud,
> cci.charlson_mld as mld,cci.charlson_sld as sld,cci.charlson_dnc as dnc,cci.charlson_dwc as dwc,cci.charlson_hem as hem,cci.charlson_red as red,cci.charlson_mal as mal,
> cci.charlson_mst as mst,cci.charlson_hiv as hiv
> from rep149_cohort gd
> join izisviews.pr_calculate_cci cci on
> cci.patientid_in = gd.patientid;
> {code}
> rep149_cci is defined as
> {code:sql}
> create foreign temporary table rep149_cci(
> PatientID integer not null,
> age bigdecimal,
> Orig long,
> Upd long,
> agepointsO integer,
> agepointsU integer,
> AMI integer,
> CHF integer,
> PVD integer,
> CVD integer,
> DEM integer,
> CPD integer,
> PUD integer,
> MLD integer,
> SLD integer,
> DNC integer,
> DWC integer,
> HEM integer,
> RED integer,
> MAL integer,
> MST integer,
> HIV integer,
> primary key(patientid)
> )OPTIONS (UPDATABLE true) on tmptables;
> {code}
> pr_calculate_cci is a virtual procedure. (I can't however share this code for confidentiality reasons).
> {code:sql}
> CREATE VIRTUAL PROCEDURE pr_calculate_cci(patientid_in integer)
> RETURNS (
> PatientID integer,
> age bigdecimal,
> Orig long,
> Upd long,
> agepointsO integer,
> agepointsU integer,
> AMI integer,
> CHF integer,
> PherVascDis integer,
> CerebVascDis integer,
> Dement integer,
> ChrPulmDis integer,
> PeptUlcer integer,
> MildLivDis integer,
> SevLivDis integer,
> DiabetesNoCompl integer,
> DiabetesWithCompl integer,
> HemiPara integer,
> RenalDis integer,
> Malign integer,
> Metastase integer,
> HIV_AIDS integer
> )
> AS
> BEGIN
> ...
> END
> {code}
> There are a few error reports like this one:
> 2018-02-23 08:33:05,478 ERROR [org.teiid.BUFFER_MGR] (Worker291_QueryProcessorQueue571476) mh0bsTIbs7qY TEIID30001 Max block number exceeded by object 1,366,497 from group 5,068,016. It is a Batch of 1797 rows of [Ljava.lang.String;@10953478. The estimated size was 172,528, but the actual size was 14,410. Increase the maxStorageObjectSize to support larger storage objects. Alternatively you could make the processor batch size smaller.
> The final stack trace is:
> 2018-02-23 08:33:05,539 ERROR [org.teiid.PROCESSOR] (Worker291_QueryProcessorQueue571476) mh0bsTIbs7qY TEIID30019 Unexpected exception for request mh0bsTIbs7qY.90: java.lang.AssertionError: Batch not found in storage 5067771
> at org.teiid.common.buffer.impl.BufferManagerImpl$BatchManagerImpl.getBatch(BufferManagerImpl.java:382)
> at org.teiid.common.buffer.SPage.getValues(SPage.java:234)
> at org.teiid.common.buffer.SPage.search(SPage.java:135)
> at org.teiid.common.buffer.STree.find(STree.java:247)
> at org.teiid.common.buffer.STree.insert(STree.java:295)
> at org.teiid.query.processor.relational.WindowFunctionProjectNode.saveValues(WindowFunctionProjectNode.java:419)
> at org.teiid.query.processor.relational.WindowFunctionProjectNode.buildResults(WindowFunctionProjectNode.java:380)
> at org.teiid.query.processor.relational.WindowFunctionProjectNode.nextBatchDirect(WindowFunctionProjectNode.java:229)
> at org.teiid.query.processor.relational.RelationalNode.nextBatch(RelationalNode.java:277)
> at org.teiid.query.processor.relational.ProjectNode.nextBatchDirect(ProjectNode.java:146)
> at org.teiid.query.processor.relational.RelationalNode.nextBatch(RelationalNode.java:277)
> at org.teiid.query.processor.relational.UnionAllNode.nextBatchDirectInternal(UnionAllNode.java:165)
> at org.teiid.query.processor.relational.UnionAllNode.nextBatchDirect(UnionAllNode.java:138)
> at org.teiid.query.processor.relational.RelationalNode.nextBatch(RelationalNode.java:277)
> at org.teiid.query.processor.relational.SelectNode.nextBatchDirect(SelectNode.java:100)
> at org.teiid.query.processor.relational.RelationalNode.nextBatch(RelationalNode.java:277)
> at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:160)
> at org.teiid.query.processor.relational.SourceState.prefetch(SourceState.java:207)
> at org.teiid.query.processor.relational.SourceState.rowCountLE(SourceState.java:154)
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5268) Anonymous bind login doesn't work for ldap connector
by Steven Hawkins (JIRA)
[ https://issues.jboss.org/browse/TEIID-5268?page=com.atlassian.jira.plugin... ]
Steven Hawkins resolved TEIID-5268.
-----------------------------------
Fix Version/s: 10.0.4
10.2
10.1.2
Resolution: Done
There isn't a good way to rely on setting an empty property. Instead there is now an explicit LdapAuthType property that can be set to none instead of the default of simple.
> Anonymous bind login doesn't work for ldap connector
> ----------------------------------------------------
>
> Key: TEIID-5268
> URL: https://issues.jboss.org/browse/TEIID-5268
> Project: Teiid
> Issue Type: Bug
> Components: LDAP Connector
> Affects Versions: 8.8, 8.12.5
> Reporter: Yuming Zhu
> Assignee: Steven Hawkins
> Fix For: 10.0.4, 10.2, 10.1.2
>
>
> I configured an anonymous to connect to LDAP server via ldaps://... according to https://docs.jboss.org/author/display/teiid812final/LDAP+Data+Sources
> like:
> {code:xml}
> <resource-adapter id="ldap">
> <module slot="main" id="org.jboss.teiid.resource-adapter.ldap"/>
> <connection-definitions>
> <connection-definition class-name="org.teiid.resource.adapter.ldap.LDAPManagedConnectionFactory" jndi-name="java:/ldapDS" enabled="true" use-java-context="true" pool-name="ldapDS">
> <config-property name="LdapUrl">
> ldaps://ldap.corp.redhat.com:636
> </config-property>
> <config-property name="LdapAdminUserDN">
> </config-property>
> <config-property name="LdapAdminUserPassword">
> </config-property>
> <config-property name="LdapTxnTimeoutInMillis">
> -1
> </config-property>
> </connection-definition>
> </connection-definitions>
> </resource-adapter>
> {code}
> when I test the connection by jboss-cli, error occurs:
> command:
> {code}
> [standalone@localhost:9999 /] /subsystem=resource-adapters/resource-adapter=ldap/connection-definitions=ldapDS:test-connection-in-pool
> {code}
> error:
> {code}
> 13:02:17,263 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (management-handler-thread - 3) ldapDS running as FIFO
> 13:02:17,263 DEBUG [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (management-handler-thread - 3) Register pool: SemaphoreArrayListManagedConnectionPool@13f30b23[pool=ldapDS] (interval=1800000)
> 13:02:17,264 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (management-handler-thread - 3) ldapDS: getConnection(null, null) [0/20]
> 13:02:17,802 WARN [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (management-handler-thread - 3) IJ000604: Throwable while attempting to get a new connection: null: javax.resource.ResourceException: Initializing LDAP directory context failed. Please check LDAP connection properties, including username and password: [LDAP: error code 49 - Invalid Credentials]
> at org.teiid.resource.adapter.ldap.LDAPConnectionImpl.initializeLDAPContext(LDAPConnectionImpl.java:151)
> at org.teiid.resource.adapter.ldap.LDAPConnectionImpl.<init>(LDAPConnectionImpl.java:75)
> at org.teiid.resource.adapter.ldap.LDAPManagedConnectionFactory$1.getConnection(LDAPManagedConnectionFactory.java:49)
> at org.teiid.resource.adapter.ldap.LDAPManagedConnectionFactory$1.getConnection(LDAPManagedConnectionFactory.java:43)
> at org.teiid.resource.spi.BasicManagedConnectionFactory.createManagedConnection(BasicManagedConnectionFactory.java:71)
> at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.createConnectionEventListener(SemaphoreArrayListManagedConnectionPool.java:858) [ironjacamar-core-impl-1.0.37.Final-redhat-1.jar:1.0.37.Final-redhat-1]
> at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.getConnection(SemaphoreArrayListManagedConnectionPool.java:413) [ironjacamar-core-impl-1.0.37.Final-redhat-1.jar:1.0.37.Final-redhat-1]
> at org.jboss.jca.core.connectionmanager.pool.AbstractPool.internalTestConnection(AbstractPool.java:725) [ironjacamar-core-impl-1.0.37.Final-redhat-1.jar:1.0.37.Final-redhat-1]
> at org.jboss.jca.core.connectionmanager.pool.strategy.OnePool.testConnection(OnePool.java:89) [ironjacamar-core-impl-1.0.37.Final-redhat-1.jar:1.0.37.Final-redhat-1]
> at org.jboss.as.connector.subsystems.common.pool.PoolOperations$TestConnectionInPool.invokeCommandOn(PoolOperations.java:143) [jboss-as-connector-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.connector.subsystems.common.pool.PoolOperations$1.execute(PoolOperations.java:82) [jboss-as-connector-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:702) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.AbstractOperationContext.doCompleteStep(AbstractOperationContext.java:537) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.AbstractOperationContext.completeStepInternal(AbstractOperationContext.java:338) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:314) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1144) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:331) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:201) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler.doExecute(ModelControllerClientOperationHandler.java:208) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler.access$300(ModelControllerClientOperationHandler.java:135) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler$1$1.run(ModelControllerClientOperationHandler.java:157) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler$1$1.run(ModelControllerClientOperationHandler.java:153) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.8.0_112]
> at javax.security.auth.Subject.doAs(Subject.java:422) [rt.jar:1.8.0_112]
> at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:94) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler$1.execute(ModelControllerClientOperationHandler.java:153) [jboss-as-controller-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.protocol.mgmt.AbstractMessageHandler$2$1.doExecute(AbstractMessageHandler.java:298)
> at org.jboss.as.protocol.mgmt.AbstractMessageHandler$AsyncTaskRunner.run(AbstractMessageHandler.java:537)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_112]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_112]
> at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_112]
> at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.2.Final-redhat-1.jar:2.1.2.Final-redhat-1]
> Caused by: javax.naming.AuthenticationException: [LDAP: error code 49 - Invalid Credentials]
> at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3136) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3082) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2883) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2797) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:319) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:192) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:210) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:153) [rt.jar:1.8.0_112]
> at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:83) [rt.jar:1.8.0_112]
> at org.jboss.as.naming.InitialContext.getDefaultInitCtx(InitialContext.java:122) [jboss-as-naming-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.naming.InitialContext.init(InitialContext.java:107) [jboss-as-naming-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:154) [rt.jar:1.8.0_112]
> at org.jboss.as.naming.InitialContext.<init>(InitialContext.java:98) [jboss-as-naming-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.jboss.as.naming.InitialContextFactory.getInitialContext(InitialContextFactory.java:44) [jboss-as-naming-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) [rt.jar:1.8.0_112]
> at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:313) [rt.jar:1.8.0_112]
> at javax.naming.InitialContext.init(InitialContext.java:244) [rt.jar:1.8.0_112]
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:154) [rt.jar:1.8.0_112]
> at org.teiid.resource.adapter.ldap.LDAPConnectionImpl.initializeLDAPContext(LDAPConnectionImpl.java:148)
> ... 31 more
> 13:02:17,808 DEBUG [org.jboss.as.controller.management-operation] (management-handler-thread - 3) JBAS014616: Operation ("test-connection-in-pool") failed - address: ([
> ("subsystem" => "resource-adapters"),
> ("resource-adapter" => "ldap"),
> ("connection-definitions" => "ldapDS")
> ]) - failure description: "JBAS010440: failed to invoke operation: JBAS010447: Connection is not valid"
> {code}
> It looks username isn't set as expected
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Van Halbert (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Van Halbert edited comment on TEIID-5270 at 3/1/18 9:41 AM:
------------------------------------------------------------
I can't duplicate it. Using squirrel to access the VDB and watching the log, I don't see an issue.
I've used this VDB as my usecase.
And yes, JDG controls the writes, and can be slower in some cases.
was (Author: van.halbert):
I can't duplicate it. Using squirrel to access the VDB and watching the log, I don't see an issue.
I've used this VDB as my usecase.
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Components: JDG Connector, Misc. Connectors
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Van Halbert (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Van Halbert commented on TEIID-5270:
------------------------------------
I can't duplicate it. Using squirrel to access the VDB and watching the log, I don't see an issue.
I've used this VDB as my usecase.
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Components: JDG Connector, Misc. Connectors
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Jan Stastny (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Jan Stastny commented on TEIID-5270:
------------------------------------
[~rareddy]
Yes, I have. The materialization process wouldn't work at all, if I didn't have any.
This is not always reproducible, my test fails once in 2-5 runs. The reason seems to be that hotrod client takes longer to write into cache than it claims (or is it even async operation).
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Components: JDG Connector, Misc. Connectors
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Jan Stastny (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Jan Stastny updated TEIID-5270:
-------------------------------
Component/s: JDG Connector
Misc. Connectors
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Components: JDG Connector, Misc. Connectors
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Ramesh Reddy (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Ramesh Reddy commented on TEIID-5270:
-------------------------------------
There is a third alias cache you need for renaming stuff to work, have you done that?
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0
[JBoss JIRA] (TEIID-5270) Materialization translator infinispan-hotrod inconsistent state
by Jan Stastny (JIRA)
[ https://issues.jboss.org/browse/TEIID-5270?page=com.atlassian.jira.plugin... ]
Jan Stastny commented on TEIID-5270:
------------------------------------
Reproducible also when using xa data-source.
> Materialization translator infinispan-hotrod inconsistent state
> ---------------------------------------------------------------
>
> Key: TEIID-5270
> URL: https://issues.jboss.org/browse/TEIID-5270
> Project: Teiid
> Issue Type: Bug
> Affects Versions: 8.12.12.6_4
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Priority: Critical
>
> There is an inconsistency between contents of status table and jdg cache when using infinispan-hotrod translator for materialization.
> For a vdb:
> {code:xml}
> <vdb name="teiid5259" version="1">
> <model name="source">
> <source connection-jndi-name="java:/jdg71HotrodDS" name="source"
> translator-name="tr-override" />
> <metadata type="DDL">
> <![CDATA[
> CREATE FOREIGN TABLE a(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${primary.cache.name}');
> CREATE FOREIGN TABLE a_stage(id integer NOT NULL PRIMARY KEY) OPTIONS (UPDATABLE TRUE, "teiid_ispn:cache" '${staging.cache.name}');
> ]]>
> </metadata>
> <metadata type="NATIVE" />
> </model>
> <model name="h2Source">
> <source name="h2Source" translator-name="h2" connection-jndi-name="java:/h2-localhost-9292-ds" />
> </model>
> <model name="View" type="VIRTUAL">
> <metadata type="DDL"><![CDATA[
> CREATE VIEW mat_a(
> id integer NOT NULL
> ) OPTIONS (MATERIALIZED 'TRUE',
> MATERIALIZED_TABLE 'source.a',
> "teiid_rel:MATERIALIZED_STAGE_TABLE" 'source.a_stage',
> "teiid_rel:ALLOW_MATVIEW_MANAGEMENT" 'true',
> "teiid_rel:MATVIEW_STATUS_TABLE" 'h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE',
> "teiid_rel:MATVIEW_AFTER_LOAD_SCRIPT" 'execute source.native(''rename source.a_stage source.a'');',
> "teiid_rel:MATVIEW_BEFORE_LOAD_SCRIPT" 'execute source.native(''truncate source.a_stage'');',
> "teiid_rel:MATVIEW_ONERROR_ACTION" 'THROW_EXCEPTION',
> "teiid_rel:MATVIEW_TTL" 10000
> )
> AS SELECT 1 UNION ALL SELECT 2;
> ]]>
> </metadata>
> </model>
> <translator name="tr-override" type="infinispan-hotrod">
> <property name="SupportsDirectQueryProcedure" value="true"/>
> </translator>
> </vdb>
> {code}
> I can reach a state when:
> # The status table states LOADED for the view
> # The DATA SRC commands inserting into JDG ended (according to teiid-command log)
> # But consecutive query against the view returns lower count (even though having THROW_EXCEPTION in ONERROR_ACTION property)
> See the attached command log:
> {code}
> 13:59:31,679 INFO [org.teiid.COMMAND_LOG] (Teiid Timer0) L8MeUp92Tess START USER COMMAND: startTime=2018-03-01 13:59:31.679 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess applicationName=internal principal=embedded-async vdbName=teiid5259 vdbVersion=1 sql=execute SYSADMIN.loadMatView('View','mat_a')
> 13:59:31,680 INFO [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue14) SBqGYWW07OB5 END USER COMMAND: endTime=2018-03-01 13:59:31.68 requestID=SBqGYWW07OB5.0 txID=null sessionID=SBqGYWW07OB5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=SELECT g_0.NAME, g_0.TARGETSCHEMANAME, g_0.TARGETNAME, g_0.VALID, g_0.LOADSTATE, g_0.UPDATED, g_0.CARDINALITY, g_0.LOADNUMBER FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:31,715 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue16) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.715 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[SELECT g_0."NAME", g_0."TARGETSCHEMANAME", g_0."TARGETNAME", g_0."VALID", g_0."LOADSTATE", g_0."UPDATED", g_0."CARDINALITY", g_0."LOADNUMBER" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:31,716 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue17) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.716 requestID=L8MeUp92Tess.0 sourceCommandID=70 executionID=8 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1071137
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADING', valid = FALSE, Updated = {ts'2018-03-01 13:59:31.719'}, Cardinality = -1 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:31,725 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue18) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:31.725 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADING', "VALID" = 0, "UPDATED" = TIMESTAMP '2018-03-01 13:59:31.719', "CARDINALITY" = -1 WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:31,728 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:31.728 requestID=L8MeUp92Tess.0 sourceCommandID=71 executionID=9 txID=null modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=1169356
> 13:59:31,731 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.731 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('truncate source.a_stage')
> 13:59:31,845 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:31.845 requestID=uaySHcXyc0o5.0 sourceCommandID=74 executionID=6 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=3558736
> 13:59:31,847 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:31.847 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:32,040 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.04 requestID=L8MeUp92Tess.0 sourceCommandID=73 executionID=10 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=1493046
> 13:59:32,047 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.047 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (1)
> 13:59:32,460 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:32.46 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=12 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4783162
> 13:59:32,462 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.462 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=INSERT INTO source.a_stage (id) VALUES (2)
> 13:59:32,753 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.753 requestID=uaySHcXyc0o5.0 sourceCommandID=79 executionID=11 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=0 cpuTime(ns)=5021072
> 13:59:32,800 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 START DATA SRC COMMAND: startTime=2018-03-01 13:59:32.8 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 1, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:32.756'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 1)
> 13:59:32,801 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 SOURCE SRC COMMAND: endTime=2018-03-01 13:59:32.801 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 1, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:32.756', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 1]
> 13:59:32,804 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END SRC COMMAND: endTime=2018-03-01 13:59:32.804 requestID=uaySHcXyc0o5.0 sourceCommandID=80 executionID=14 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:e status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=uaySHcXyc0o5 principal=embedded-async finalRowCount=1 cpuTime(ns)=31050942
> 13:59:32,806 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue11) uaySHcXyc0o5 END USER COMMAND: endTime=2018-03-01 13:59:32.806 requestID=uaySHcXyc0o5.0 txID=null sessionID=uaySHcXyc0o5 principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:33,005 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.005 requestID=L8MeUp92Tess.0 sourceCommandID=74 executionID=13 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=4943881
> 13:59:33,014 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.014 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async sql=EXEC source.native('rename source.a_stage source.a')
> 13:59:33,723 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue19) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.723 requestID=L8MeUp92Tess.0 sourceCommandID=79 executionID=15 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=source translatorName=tr-override sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=0 cpuTime(ns)=4426814
> 13:59:33,731 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess START DATA SRC COMMAND: startTime=2018-03-01 13:59:33.731 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sql=UPDATE h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE SET LoadNumber = 2, LoadState = 'LOADED', valid = TRUE, Updated = {ts'2018-03-01 13:59:33.725'}, Cardinality = 2 WHERE (VDBName = 'teiid5259') AND (VDBVersion = 1) AND (schemaName = 'View') AND (Name = 'mat_a') AND (loadNumber = 2)
> 13:59:33,732 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess SOURCE SRC COMMAND: endTime=2018-03-01 13:59:33.732 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async sourceCommand=[UPDATE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" SET "LOADNUMBER" = 2, "LOADSTATE" = 'LOADED', "VALID" = 1, "UPDATED" = TIMESTAMP '2018-03-01 13:59:33.725', "CARDINALITY" = ? WHERE "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBNAME" = 'teiid5259' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."VDBVERSION" = 1 AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."SCHEMANAME" = 'View' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."NAME" = 'mat_a' AND "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE"."LOADNUMBER" = 2]
> 13:59:33,737 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END SRC COMMAND: endTime=2018-03-01 13:59:33.737 requestID=L8MeUp92Tess.0 sourceCommandID=80 executionID=16 txID=TransactionImple < ac, BasicAction: 0:ffff0a2804e2:b3ef2e2:5a97f919:f status: ActionStatus.RUNNING > modelName=h2Source translatorName=h2 sessionID=L8MeUp92Tess principal=embedded-async finalRowCount=1 cpuTime(ns)=3747146
> 13:59:33,740 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue20) L8MeUp92Tess END USER COMMAND: endTime=2018-03-01 13:59:33.74 requestID=L8MeUp92Tess.0 txID=null sessionID=L8MeUp92Tess principal=embedded-async vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> 13:59:35,871 INFO [org.teiid.COMMAND_LOG] (New I/O worker #2) eP8bDNkHEpSG START USER COMMAND: startTime=2018-03-01 13:59:35.871 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG applicationName=JDBC principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 sql=SELECT COUNT(*) FROM mat_a
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.VALID, g_0.LOADSTATE FROM h2Source.DB.PUBLIC.DV_MATVIEWS_STATUSTABLE AS g_0 WHERE (g_0.VDBNAME = 'teiid5259') AND (g_0.VDBVERSION = 1) AND (g_0.SCHEMANAME = 'View') AND (g_0.NAME = 'mat_a')
> 13:59:35,877 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue22) eP8bDNkHEpSG SOURCE SRC COMMAND: endTime=2018-03-01 13:59:35.877 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security sourceCommand=[SELECT g_0."VALID", g_0."LOADSTATE" FROM "DB"."PUBLIC"."DV_MATVIEWS_STATUSTABLE" AS g_0 WHERE g_0."VDBNAME" = 'teiid5259' AND g_0."VDBVERSION" = 1 AND g_0."SCHEMANAME" = 'View' AND g_0."NAME" = 'mat_a']
> 13:59:35,878 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue23) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:35.878 requestID=eP8bDNkHEpSG.0 sourceCommandID=6 executionID=17 txID=null modelName=h2Source translatorName=h2 sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=904441
> 13:59:35,879 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue24) eP8bDNkHEpSG START DATA SRC COMMAND: startTime=2018-03-01 13:59:35.879 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security sql=SELECT g_0.id FROM source.a AS g_0
> 13:59:36,326 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue25) eP8bDNkHEpSG END SRC COMMAND: endTime=2018-03-01 13:59:36.326 requestID=eP8bDNkHEpSG.0 sourceCommandID=9 executionID=18 txID=null modelName=source translatorName=tr-override sessionID=eP8bDNkHEpSG principal=user@teiid-security finalRowCount=1 cpuTime(ns)=32679662
> 13:59:36,384 INFO [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) eP8bDNkHEpSG END USER COMMAND: endTime=2018-03-01 13:59:36.384 requestID=eP8bDNkHEpSG.0 txID=null sessionID=eP8bDNkHEpSG principal=user@teiid-security vdbName=teiid5259 vdbVersion=1 finalRowCount=1
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 10 months
- 1
- 0