]
Steven Hawkins updated TEIID-5436:
----------------------------------
Fix Version/s: 12.3
(was: 8.12.16.6_4)
(was: 12.2)
Materialization translator infinispan-hotrod inconsistent state
---------------------------------------------------------------
Key: TEIID-5436
URL:
https://issues.jboss.org/browse/TEIID-5436
Project: Teiid
Issue Type: Bug
Components: JDG Connector, Misc. Connectors
Affects Versions: 8.12.12.6_4
Reporter: Jan Stastny
Assignee: Van Halbert
Priority: Critical
Fix For: 12.3
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}