5 Replies Latest reply on Feb 4, 2016 3:05 PM by shawkins

    TEIID Requests Getting Cancelled - TEIID30160

    walla2sl

      We're seeing requests getting cancelled with the following error stack:

       

      20:01:56,692 DEBUG [org.teiid.PROCESSOR] (Worker5_QueryProcessorQueue52) Request Thread mk+VLTDPDwgZ.52 - error occurred after cancel: org.teiid.core.TeiidProcessingException: TEIID30160 The request mk+VLTDPDwgZ.52 has been cancelled.

        at org.teiid.query.processor.QueryProcessor.nextBatchDirect(QueryProcessor.java:146) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.query.processor.QueryProcessor.nextBatch(QueryProcessor.java:114) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:164) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:146) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.dqp.internal.process.RequestWorkItem.processMore(RequestWorkItem.java:462) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.dqp.internal.process.RequestWorkItem.process(RequestWorkItem.java:344) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.dqp.internal.process.AbstractWorkItem.run(AbstractWorkItem.java:51) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.dqp.internal.process.RequestWorkItem.run(RequestWorkItem.java:271) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:276) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:119) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:210) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_66]

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_66]

        at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_66]

       

      Any hints on how I can debug this further?

        • 1. Re: TEIID Requests Getting Cancelled - TEIID30160
          shawkins

          Note that it's logged at a debug level, so this may not be meaningful to you.  Are seeing any problems with your clients?

          • 2. Re: TEIID Requests Getting Cancelled - TEIID30160
            walla2sl

            Yes, client connection fails during the query. Fails after about 90 seconds or so.

             

            We have one client coming into Teiid via ODBC and that's where the issue was reported.

             

            I'm testing with Teiid Designer and I'm able to reproduce.

             

            The query on the database side continues and eventually succeeds, but since the request was cancelled on the Teiid side, the results never reach the client.

            • 3. Re: TEIID Requests Getting Cancelled - TEIID30160
              shawkins

              Are there any other logs related to that query in the log and do you have any query timeouts set?

              • 4. Re: TEIID Requests Getting Cancelled - TEIID30160
                walla2sl

                Full log is pasted below as well as connection and timeout settings from standalone-teiid.xml. Query runs fine in the database and rows are ready to return to client but Teiid cancels at that point.

                 

                                    <pool>

                                        <min-pool-size>0</min-pool-size>

                                        <max-pool-size>100</max-pool-size>

                                        <prefill>false</prefill>

                                        <use-strict-min>false</use-strict-min>

                                        <flush-strategy>FailingConnectionOnly</flush-strategy>

                                    </pool>

                 

                 

                                     <timeout>

                                        <set-tx-query-timeout>true</set-tx-query-timeout>

                                        <blocking-timeout-millis>5000</blocking-timeout-millis>

                                        <idle-timeout-minutes>10</idle-timeout-minutes>

                                        <query-timeout>600</query-timeout>

                                        <allocation-retry>3</allocation-retry>

                                        <allocation-retry-wait-millis>1000</allocation-retry-wait-millis>

                                    </timeout>

                 

                 

                21:50:08,169 INFO  [org.teiid.COMMAND_LOG] (New I/O worker #2)START USER COMMAND:startTime=2016-02-03 21:50:08.169requestID=oWyjQD36adh3.0txID=nullsessionID=oWyjQD36adh3applicationName=JDBCprincipal=appuser@teiid-securityvdbName=WarehousevdbVersion=1sql=select sum(T172081."num_items") as c1,

                     sum(T172081."pub_comm_base") as c2,

                     T139712."month_year_name" as c3,

                     case  when T172081."sku_number" is null then 'Unmeasured' else T172081."sku_number" end  as c4,

                     T139818."publisher_key" as c5,

                     T139818."publisher_name" as c6,

                     T139712."date_key" as c7,

                     T172081."u1" as c8,

                     T172081."orderid" as c9,

                     T139712."year_month" as c10

                from

                     "Warehouse"."warehouse"."dim_publisher" T139818,

                     "Warehouse"."warehouse"."dim_date" T139712,

                     "Warehouse"."warehouse"."dim_network" T139705,

                     "Warehouse"."warehouse"."fact_transaction_consumer_trans_date_detail" T172081

                where  ( T139705."network_key" = T172081."network_key" and T139705."network_name" = 'US Network' and T139712."date_key" = T172081."process_date_key" and T139818."publisher_key" = T172081."publisher_key" and T172081."advertiser_key" = 2291 and T139818."publisher_key" <> -1 and case  when T172081."sku_number" is null then 'Unmeasured' else T172081."sku_number" end  <> 'Unmeasured' and T139712."date_key" between {d '2015-12-01'} and {d '2016-12-31'} and T172081."process_date_key" between {d '2015-12-01'} and {d '2016-12-31'} )

                group by T139712."date_key", T139712."month_year_name", T139712."year_month", T139818."publisher_key", T139818."publisher_name", T172081."orderid", T172081."u1", case  when T172081."sku_number" is null then 'Unmeasured' else T172081."sku_number" end

                 

                 

                21:50:08,169 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156124) Request Thread oWyjQD36adh3.0 with state NEW

                21:50:08,169 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156124) oWyjQD36adh3.0 Command has no cache hint and result set cache mode is not on.

                21:50:08,169 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156124) oWyjQD36adh3.0 executing  select sum(T172081."num_items") as c1,

                     sum(T172081."pub_comm_base") as c2,

                     T139712."month_year_name" as c3,

                     case  when T172081."sku_number" is null then 'Unmeasured' else T172081."sku_number" end  as c4,

                     T139818."publisher_key" as c5,

                     T139818."publisher_name" as c6,

                     T139712."date_key" as c7,

                     T172081."u1" as c8,

                     T172081."orderid" as c9,

                     T139712."year_month" as c10

                from

                     "Warehouse"."warehouse"."dim_publisher" T139818,

                     "Warehouse"."warehouse"."dim_date" T139712,

                     "Warehouse"."warehouse"."dim_network" T139705,

                     "Warehouse"."warehouse"."fact_transaction_consumer_trans_date_detail" T172081

                where  ( T139705."network_key" = T172081."network_key" and T139705."network_name" = 'US Network' and T139712."date_key" = T172081."process_date_key" and T139818."publisher_key" = T172081."publisher_key" and T172081."advertiser_key" = 2291 and T139818."publisher_key" <> -1 and case  when T172081."sku_number" is null then 'Unmeasured' else T172081."sku_number" end  <> 'Unmeasured' and T139712."date_key" between {d '2015-12-01'} and {d '2016-12-31'} and T172081."process_date_key" between {d '2015-12-01'} and {d '2016-12-31'} )

                group by T139712."date_key", T139712."month_year_name", T139712."year_month", T139818."publisher_key", T139818."publisher_name", T172081."orderid", T172081."u1", case  when T172081."sku_number" is null then 'Unmeasured' else T172081."sku_number" end

                 

                 

                21:50:08,182 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156124) ProcessTree for oWyjQD36adh3.0 AccessNode(1) output=[anon_grp0.agg0 AS c1, anon_grp0.agg1 AS c2, anon_grp0.gcol1 AS c3, anon_grp0.gcol7 AS c4, anon_grp0.gcol3 AS c5, anon_grp0.gcol4 AS c6, anon_grp0.gcol0 AS c7, anon_grp0.gcol6 AS c8, anon_grp0.gcol5 AS c9, anon_grp0.gcol2 AS c10] SELECT SUM(v_0.c_8), SUM(v_0.c_9), v_0.c_1, v_0.c_7, v_0.c_3, v_0.c_4, v_0.c_0, v_0.c_6, v_0.c_5, v_0.c_2 FROM (SELECT g_1.date_key AS c_0, g_1.month_year_name AS c_1, g_1.year_month AS c_2, g_0.publisher_key AS c_3, g_0.publisher_name AS c_4, g_3.orderid AS c_5, g_3.u1 AS c_6, CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END AS c_7, g_3.num_items AS c_8, g_3.pub_comm_base AS c_9 FROM warehouse.dim_publisher AS g_0 INNER JOIN (warehouse.dim_date AS g_1 INNER JOIN (warehouse.dim_network AS g_2 INNER JOIN warehouse.fact_transaction_consumer_trans_date_detail AS g_3 ON g_2.network_key = convert(g_3.network_key, long)) ON g_1.date_key = g_3.process_date_key) ON g_0.publisher_key = g_3.publisher_key WHERE (g_0.publisher_key <> -1) AND (g_1.date_key >= '2015-12-01') AND (g_1.date_key <= '2016-12-31') AND (g_2.network_name = 'US Network') AND (g_3.advertiser_key = 2291) AND (CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END <> 'Unmeasured') AND (g_3.process_date_key >= '2015-12-01') AND (g_3.process_date_key <= '2016-12-31') AND (g_3.publisher_key <> -1)) AS v_0 GROUP BY v_0.c_0, v_0.c_1, v_0.c_2, v_0.c_3, v_0.c_4, v_0.c_5, v_0.c_6, v_0.c_7

                 

                 

                21:50:08,183 DEBUG [org.teiid.CONNECTOR] (Worker648_QueryProcessorQueue156124) oWyjQD36adh3.0.1.577 Create State

                21:50:08,183 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156124) Request Thread oWyjQD36adh3.0 - processor blocked

                21:50:08,183 DEBUG [org.teiid.PROCESSOR] (Worker649_QueryProcessorQueue156125) Running task for parent thread Worker648_QueryProcessorQueue156124

                21:50:08,183 DEBUG [org.teiid.CONNECTOR] (Worker649_QueryProcessorQueue156125) oWyjQD36adh3.0.1.577 Processing NEW request: SELECT SUM(v_0.c_8), SUM(v_0.c_9), v_0.c_1, v_0.c_7, v_0.c_3, v_0.c_4, v_0.c_0, v_0.c_6, v_0.c_5, v_0.c_2 FROM (SELECT g_1.date_key AS c_0, g_1.month_year_name AS c_1, g_1.year_month AS c_2, g_0.publisher_key AS c_3, g_0.publisher_name AS c_4, g_3.orderid AS c_5, g_3.u1 AS c_6, CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END AS c_7, g_3.num_items AS c_8, g_3.pub_comm_base AS c_9 FROM warehouse.dim_publisher AS g_0 INNER JOIN (warehouse.dim_date AS g_1 INNER JOIN (warehouse.dim_network AS g_2 INNER JOIN warehouse.fact_transaction_consumer_trans_date_detail AS g_3 ON g_2.network_key = convert(g_3.network_key, long)) ON g_1.date_key = g_3.process_date_key) ON g_0.publisher_key = g_3.publisher_key WHERE (g_0.publisher_key <> -1) AND (g_1.date_key >= '2015-12-01') AND (g_1.date_key <= '2016-12-31') AND (g_2.network_name = 'US Network') AND (g_3.advertiser_key = 2291) AND (CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END <> 'Unmeasured') AND (g_3.process_date_key >= '2015-12-01') AND (g_3.process_date_key <= '2016-12-31') AND (g_3.publisher_key <> -1)) AS v_0 GROUP BY v_0.c_0, v_0.c_1, v_0.c_2, v_0.c_3, v_0.c_4, v_0.c_5, v_0.c_6, v_0.c_7

                21:50:09,194 DEBUG [org.teiid.CONNECTOR] (Worker649_QueryProcessorQueue156125) oWyjQD36adh3.0.1.577 Obtained execution

                21:50:09,194 DEBUG [org.teiid.COMMAND_LOG] (Worker649_QueryProcessorQueue156125)START DATA SRC COMMAND:startTime=2016-02-03 21:50:09.194requestID=oWyjQD36adh3.0sourceCommandID=1executionID=577txID=nullmodelName=warehousetranslatorName=impalasessionID=oWyjQD36adh3principal=appuser@teiid-securitysql=SELECT SUM(v_0.c_8), SUM(v_0.c_9), v_0.c_1, v_0.c_7, v_0.c_3, v_0.c_4, v_0.c_0, v_0.c_6, v_0.c_5, v_0.c_2 FROM (SELECT g_1.date_key AS c_0, g_1.month_year_name AS c_1, g_1.year_month AS c_2, g_0.publisher_key AS c_3, g_0.publisher_name AS c_4, g_3.orderid AS c_5, g_3.u1 AS c_6, CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END AS c_7, g_3.num_items AS c_8, g_3.pub_comm_base AS c_9 FROM warehouse.dim_publisher AS g_0 INNER JOIN (warehouse.dim_date AS g_1 INNER JOIN (warehouse.dim_network AS g_2 INNER JOIN warehouse.fact_transaction_consumer_trans_date_detail AS g_3 ON g_2.network_key = convert(g_3.network_key, long)) ON g_1.date_key = g_3.process_date_key) ON g_0.publisher_key = g_3.publisher_key WHERE (g_0.publisher_key <> -1) AND (g_1.date_key >= '2015-12-01') AND (g_1.date_key <= '2016-12-31') AND (g_2.network_name = 'US Network') AND (g_3.advertiser_key = 2291) AND (CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END <> 'Unmeasured') AND (g_3.process_date_key >= '2015-12-01') AND (g_3.process_date_key <= '2016-12-31') AND (g_3.publisher_key <> -1)) AS v_0 GROUP BY v_0.c_0, v_0.c_1, v_0.c_2, v_0.c_3, v_0.c_4, v_0.c_5, v_0.c_6, v_0.c_7

                21:50:09,194 DEBUG [org.teiid.CONNECTOR] (Worker649_QueryProcessorQueue156125) Source-specific command: SELECT SUM(v_0.c_8), SUM(v_0.c_9), v_0.c_1, v_0.c_7, v_0.c_3, v_0.c_4, v_0.c_0, v_0.c_6, v_0.c_5, v_0.c_2 FROM (SELECT g_1.`date_key` AS c_0, g_1.`month_year_name` AS c_1, g_1.`year_month` AS c_2, g_0.`publisher_key` AS c_3, g_0.`publisher_name` AS c_4, g_3.`orderid` AS c_5, g_3.`u1` AS c_6, CASE WHEN g_3.`sku_number` IS NULL THEN 'Unmeasured' ELSE g_3.`sku_number` END AS c_7, g_3.`num_items` AS c_8, g_3.`pub_comm_base` AS c_9 FROM warehouse.dim_network g_2  JOIN warehouse.fact_transaction_consumer_trans_date_detail g_3 ON g_2.`network_key` = cast(g_3.`network_key` AS bigint)  JOIN warehouse.dim_date g_1 ON g_1.`date_key` = g_3.`process_date_key`  JOIN warehouse.dim_publisher g_0 ON g_0.`publisher_key` = g_3.`publisher_key` WHERE g_0.`publisher_key` <> -1 AND g_1.`date_key` >= '2015-12-01' AND g_1.`date_key` <= '2016-12-31' AND g_2.`network_name` = 'US Network' AND g_3.`advertiser_key` = 2291 AND CASE WHEN g_3.`sku_number` IS NULL THEN 'Unmeasured' ELSE g_3.`sku_number` END <> 'Unmeasured' AND g_3.`process_date_key` >= '2015-12-01' AND g_3.`process_date_key` <= '2016-12-31' AND g_3.`publisher_key` <> -1) v_0 GROUP BY v_0.c_0, v_0.c_1, v_0.c_2, v_0.c_3, v_0.c_4, v_0.c_5, v_0.c_6, v_0.c_7

                21:50:18,774 DEBUG [org.teiid.PROCESSOR] (SessionMonitor) cancelQuery for requestID=oWyjQD36adh3.0

                21:50:18,775 DEBUG [org.teiid.CONNECTOR] (SessionMonitor) oWyjQD36adh3.0.1.577 Processing CANCEL request

                21:50:18,775 DEBUG [org.teiid.COMMAND_LOG] (SessionMonitor)CANCEL SRC COMMAND:endTime=2016-02-03 21:50:18.775requestID=oWyjQD36adh3.0sourceCommandID=1executionID=577txID=nullmodelName=warehousetranslatorName=impalasessionID=oWyjQD36adh3principal=appuser@teiid-securityfinalRowCount=-1

                21:50:20,103 DEBUG [org.teiid.CONNECTOR] (Worker649_QueryProcessorQueue156125) oWyjQD36adh3.0.1.577 Executed command

                21:50:20,103 DEBUG [org.teiid.CONNECTOR] (Worker649_QueryProcessorQueue156125) oWyjQD36adh3.0.1.577 Processing MORE request

                21:50:20,103 DEBUG [org.teiid.CONNECTOR] (Worker649_QueryProcessorQueue156125) oWyjQD36adh3.0.1.577 Getting results from connector

                21:50:20,104 DEBUG [org.teiid.COMMAND_LOG] (Worker649_QueryProcessorQueue156125)ERROR SRC COMMAND:endTime=2016-02-03 21:50:20.104requestID=oWyjQD36adh3.0sourceCommandID=1executionID=577txID=nullmodelName=warehousetranslatorName=impalasessionID=oWyjQD36adh3principal=appuser@teiid-securityfinalRowCount=null

                21:50:20,104 DEBUG [org.teiid.CONNECTOR] (Worker649_QueryProcessorQueue156125) Connector worker process failed for atomic-request=oWyjQD36adh3.0.1.577

                21:50:20,104 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156126) Request Thread oWyjQD36adh3.0 with state PROCESSING

                21:50:20,105 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156126) QueryProcessor: closing processor

                21:50:20,105 DEBUG [org.teiid.CONNECTOR] (Worker648_QueryProcessorQueue156126) oWyjQD36adh3.0.1.577 Processing CANCEL request

                21:50:20,105 DEBUG [org.teiid.CONNECTOR] (Worker648_QueryProcessorQueue156126) oWyjQD36adh3.0.1.577 Remove State

                21:50:20,105 DEBUG [org.teiid.CONNECTOR] (Worker648_QueryProcessorQueue156126) oWyjQD36adh3.0.1.577 Processing Close : SELECT SUM(v_0.c_8), SUM(v_0.c_9), v_0.c_1, v_0.c_7, v_0.c_3, v_0.c_4, v_0.c_0, v_0.c_6, v_0.c_5, v_0.c_2 FROM (SELECT g_1.date_key AS c_0, g_1.month_year_name AS c_1, g_1.year_month AS c_2, g_0.publisher_key AS c_3, g_0.publisher_name AS c_4, g_3.orderid AS c_5, g_3.u1 AS c_6, CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END AS c_7, g_3.num_items AS c_8, g_3.pub_comm_base AS c_9 FROM warehouse.dim_publisher AS g_0 INNER JOIN (warehouse.dim_date AS g_1 INNER JOIN (warehouse.dim_network AS g_2 INNER JOIN warehouse.fact_transaction_consumer_trans_date_detail AS g_3 ON g_2.network_key = convert(g_3.network_key, long)) ON g_1.date_key = g_3.process_date_key) ON g_0.publisher_key = g_3.publisher_key WHERE (g_0.publisher_key <> -1) AND (g_1.date_key >= '2015-12-01') AND (g_1.date_key <= '2016-12-31') AND (g_2.network_name = 'US Network') AND (g_3.advertiser_key = 2291) AND (CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END <> 'Unmeasured') AND (g_3.process_date_key >= '2015-12-01') AND (g_3.process_date_key <= '2016-12-31') AND (g_3.publisher_key <> -1)) AS v_0 GROUP BY v_0.c_0, v_0.c_1, v_0.c_2, v_0.c_3, v_0.c_4, v_0.c_5, v_0.c_6, v_0.c_7

                21:50:20,106 DEBUG [org.teiid.CONNECTOR] (Worker648_QueryProcessorQueue156126) oWyjQD36adh3.0.1.577 Closed execution

                21:50:20,107 DEBUG [org.teiid.CONNECTOR] (Worker648_QueryProcessorQueue156126) oWyjQD36adh3.0.1.577 Closed connection

                21:50:20,107 DEBUG [org.teiid.COMMAND_LOG] (Worker648_QueryProcessorQueue156126)END SRC COMMAND:endTime=2016-02-03 21:50:20.107requestID=oWyjQD36adh3.0sourceCommandID=1executionID=577txID=nullmodelName=warehousetranslatorName=impalasessionID=oWyjQD36adh3principal=appuser@teiid-securityfinalRowCount=0cpuTime(ns)=37122973

                21:50:20,107 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156126) Request Thread oWyjQD36adh3.0 - error occurred after cancel: org.teiid.core.TeiidProcessingException: TEIID30160 The request oWyjQD36adh3.0 has been cancelled.

                at org.teiid.query.processor.QueryProcessor.nextBatchDirect(QueryProcessor.java:146) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.query.processor.QueryProcessor.nextBatch(QueryProcessor.java:114) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:164) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:146) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.dqp.internal.process.RequestWorkItem.processMore(RequestWorkItem.java:462) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.dqp.internal.process.RequestWorkItem.process(RequestWorkItem.java:344) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.dqp.internal.process.AbstractWorkItem.run(AbstractWorkItem.java:51) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.dqp.internal.process.RequestWorkItem.run(RequestWorkItem.java:271) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:276) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:119) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:210) [teiid-engine-8.12.0.CR1.jar:8.12.0.CR1]
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_66]
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_66]
                at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_66]

                 

                 

                21:50:20,107 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156126) Removing tuplesource for the request oWyjQD36adh3.0

                21:50:20,108 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156126) oWyjQD36adh3.0 Finished Processing

                21:50:20,108 DEBUG [org.teiid.PROCESSOR] (Worker648_QueryProcessorQueue156126) org.teiid.core.TeiidProcessingException: TEIID30160 The request oWyjQD36adh3.0 has been cancelled. Sending error to client oWyjQD36adh3.0

                21:50:20,109 INFO  [org.teiid.COMMAND_LOG] (Worker648_QueryProcessorQueue156126)END USER COMMAND:endTime=2016-02-03 21:50:20.108requestID=oWyjQD36adh3.0txID=nullsessionID=oWyjQD36adh3principal=appuser@teiid-securityvdbName=WarehousevdbVersion=1finalRowCount=0plan=AccessNode

                  + Relational Node ID:1

                  + Output Columns:

                    0: c1 (long)

                    1: c2 (bigdecimal)

                    2: c3 (string)

                    3: c4 (string)

                    4: c5 (long)

                    5: c6 (string)

                    6: c7 (string)

                    7: c8 (string)

                    8: c9 (string)

                    9: c10 (long)

                  + Statistics:

                    0: Node Output Rows: 0

                    1: Node Next Batch Process Time: 0

                    2: Node Cumulative Next Batch Process Time: 0

                    3: Node Cumulative Process Time: 0

                    4: Node Next Batch Calls: 1

                    5: Node Blocks: 1

                  + Cost Estimates:Estimated Node Cardinality: -1.0

                  + Query:SELECT SUM(v_0.c_8), SUM(v_0.c_9), v_0.c_1, v_0.c_7, v_0.c_3, v_0.c_4, v_0.c_0, v_0.c_6, v_0.c_5, v_0.c_2 FROM (SELECT g_1.date_key AS c_0, g_1.month_year_name AS c_1, g_1.year_month AS c_2, g_0.publisher_key AS c_3, g_0.publisher_name AS c_4, g_3.orderid AS c_5, g_3.u1 AS c_6, CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END AS c_7, g_3.num_items AS c_8, g_3.pub_comm_base AS c_9 FROM warehouse.dim_publisher AS g_0 INNER JOIN (warehouse.dim_date AS g_1 INNER JOIN (warehouse.dim_network AS g_2 INNER JOIN warehouse.fact_transaction_consumer_trans_date_detail AS g_3 ON g_2.network_key = convert(g_3.network_key, long)) ON g_1.date_key = g_3.process_date_key) ON g_0.publisher_key = g_3.publisher_key WHERE (g_0.publisher_key <> -1) AND (g_1.date_key >= '2015-12-01') AND (g_1.date_key <= '2016-12-31') AND (g_2.network_name = 'US Network') AND (g_3.advertiser_key = 2291) AND (CASE WHEN g_3.sku_number IS NULL THEN 'Unmeasured' ELSE g_3.sku_number END <> 'Unmeasured') AND (g_3.process_date_key >= '2015-12-01') AND (g_3.process_date_key <= '2016-12-31') AND (g_3.publisher_key <> -1)) AS v_0 GROUP BY v_0.c_0, v_0.c_1, v_0.c_2, v_0.c_3, v_0.c_4, v_0.c_5, v_0.c_6, v_0.c_7

                  + Model Name:warehouse

                • 5. Re: TEIID Requests Getting Cancelled - TEIID30160
                  shawkins

                  The important line from above is:


                  21:50:18,774 DEBUG [org.teiid.PROCESSOR] (SessionMonitor) cancelQuery for requestID=oWyjQD36adh3.0


                  That indicates it's the server that is killing the session based upon the client not sending successful pings for that session.  What Teiid client version are you using, how long ago was the Teiid session created, and if you turn up logging on the client do you see messages about not being able to ping the server?