firethorn

changeset 4199:7cb76899479d 2.1.28-tap-issues

Completing vs Non Completing (Same query) logs
author Stelios <stv@roe.ac.uk>
date Wed Apr 17 16:45:12 2019 +0300 (2019-04-17)
parents f14ed718d705
children c8b3054c8e83
files doc/notes/stv/20190417-Non-propagated-Fail.txt doc/notes/stv/20190417-Propagated-Fail.txt
line diff
     1.1 --- /dev/null	Thu Jan 01 00:00:00 1970 +0000
     1.2 +++ b/doc/notes/stv/20190417-Non-propagated-Fail.txt	Wed Apr 17 16:45:12 2019 +0300
     1.3 @@ -0,0 +1,214 @@
     1.4 +#
     1.5 +# <meta:header>
     1.6 +#   <meta:licence>
     1.7 +#     Copyright (c) 2018, ROE (http://www.roe.ac.uk/)
     1.8 +#
     1.9 +#     This information is free software: you can redistribute it and/or modify
    1.10 +#     it under the terms of the GNU General Public License as published by
    1.11 +#     the Free Software Foundation, either version 3 of the License, or
    1.12 +#     (at your option) any later version.
    1.13 +#
    1.14 +#     This information is distributed in the hope that it will be useful,
    1.15 +#     but WITHOUT ANY WARRANTY; without even the implied warranty of
    1.16 +#     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
    1.17 +#     GNU General Public License for more details.
    1.18 +#  
    1.19 +#     You should have received a copy of the GNU General Public License
    1.20 +#     along with this program.  If not, see <http://www.gnu.org/licenses/>.
    1.21 +#   </meta:licence>
    1.22 +# </meta:header>
    1.23 +#
    1.24 +#
    1.25 +
    1.26 +## The following runs a query on a Table that was deleted.
    1.27 +## In this particular case, the fail was not properly propagated to Firethorn
    1.28 +## This eventually returned a 502 Proxy Error
    1.29 +
    1.30 +... query_str = "SELECT TOP 10 * from temp.XX_V3XRF4TOX22AGAAAAFVCOLMUXE"
    1.31 +>>> query_obj = workspace.create_query(
    1.32 +...     query_str,
    1.33 +...     "COMPLETED",
    1.34 +...     None,
    1.35 +...     3000000
    1.36 +...     )
    1.37 +
    1.38 +ERROR:root:HTTP Error 502: Proxy Error
    1.39 +Traceback (most recent call last):
    1.40 +  File "/usr/local/lib/python3.4/dist-packages/firethorn-0.1.0-py3.4.egg/firethorn/core/query_engine.py", line 124, in create_query
    1.41 +    with urllib.request.urlopen(request, data) as response:
    1.42 +  File "/usr/lib/python3.4/urllib/request.py", line 161, in urlopen
    1.43 +    return opener.open(url, data, timeout)
    1.44 +  File "/usr/lib/python3.4/urllib/request.py", line 469, in open
    1.45 +    response = meth(req, response)
    1.46 +  File "/usr/lib/python3.4/urllib/request.py", line 579, in http_response
    1.47 +    'http', request, response, code, msg, hdrs)
    1.48 +  File "/usr/lib/python3.4/urllib/request.py", line 507, in error
    1.49 +    return self._call_chain(*args)
    1.50 +  File "/usr/lib/python3.4/urllib/request.py", line 441, in _call_chain
    1.51 +    result = func(*args)
    1.52 +  File "/usr/lib/python3.4/urllib/request.py", line 587, in http_error_default
    1.53 +    raise HTTPError(req.full_url, code, msg, hdrs, fp)
    1.54 +urllib.error.HTTPError: HTTP Error 502: Proxy Error
    1.55 +
    1.56 +## If we check the blue query status we see it as:
    1.57 +## "status": "RUNNING",
    1.58 +
    1.59 +
    1.60 +2019-04-17 13:36:16,853 DEBUG event.LoggingActivityListener [pool-1-thread-43,debug:84] PENDING: Activity uk.org.ogsadai.DeliverToRequestStatus (instance name = uk.org.ogsadai.DeliverToRequestStatus-ogsadai-15df7c00-a340-4e47-a7e7-ea8cb3c059c3)
    1.61 +2019-04-17 13:36:16,853 DEBUG event.LoggingActivityListener [pool-1-thread-43,debug:84] PENDING: Activity uk.ac.roe.wfau.firethorn.Delays (instance name = uk.ac.roe.wfau.firethorn.Delays-ogsadai-1d1af8cd-2e4d-438c-8699-2dd8df45a2e5)
    1.62 +2019-04-17 13:36:16,854 DEBUG event.LoggingActivityListener [pool-1-thread-43,debug:84] PENDING: Activity uk.ac.roe.wfau.firethorn.Context (instance name = uk.ac.roe.wfau.firethorn.Context-ogsadai-0ef2e6b9-f063-49a9-860f-9f9ea2d481ad)
    1.63 +2019-04-17 13:36:16,854 DEBUG event.LoggingActivityListener [pool-1-thread-43,debug:84] PENDING: Activity uk.org.ogsadai.SQLQuery (instance name = uk.org.ogsadai.SQLQuery-ogsadai-4c660365-75de-4e62-b96e-aff634cd2ede)
    1.64 +2019-04-17 13:36:16,854 DEBUG event.LoggingActivityListener [pool-1-thread-43,debug:84] PENDING: Activity uk.ac.roe.wfau.firethorn.JdbcInsertData (instance name = uk.ac.roe.wfau.firethorn.JdbcInsertData-ogsadai-47cc78c5-bfe7-49ab-91b9-2394abe5c3f7)
    1.65 +2019-04-17 13:36:16,854 DEBUG event.LoggingActivityListener [pool-1-thread-43,debug:84] PENDING: Activity uk.ac.roe.wfau.firethorn.Limits (instance name = uk.ac.roe.wfau.firethorn.Limits-ogsadai-6cf18e79-eb0c-448b-87c9-8466a2505f48)
    1.66 +2019-04-17 13:36:16,875 DEBUG event.LoggingActivityListener [pool-1-thread-44,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.JdbcInsertData (instance name = uk.ac.roe.wfau.firethorn.JdbcInsertData-ogsadai-47cc78c5-bfe7-49ab-91b9-2394abe5c3f7)
    1.67 +2019-04-17 13:36:16,875 DEBUG activity.MatchedIterativeActivity [pool-1-thread-44,debug:84] performing first stage of processing
    1.68 +2019-04-17 13:36:16,875 DEBUG event.LoggingActivityListener [pool-1-thread-45,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.Context (instance name = uk.ac.roe.wfau.firethorn.Context-ogsadai-0ef2e6b9-f063-49a9-860f-9f9ea2d481ad)
    1.69 +2019-04-17 13:36:16,875 DEBUG file.SimpleFileLoginProvider [pool-1-thread-44,debug:84] In SimpleFileLogin:getLogin
    1.70 +2019-04-17 13:36:16,876 DEBUG activity.MatchedIterativeActivity [pool-1-thread-45,debug:84] performing first stage of processing
    1.71 +2019-04-17 13:36:16,876 DEBUG file.SimpleFileLoginProvider [pool-1-thread-44,debug:84] In getLogin: ResourceID:  User ID: null
    1.72 +2019-04-17 13:36:16,876 DEBUG blue.ContextActivity [pool-1-thread-45,preprocess:126] preprocess()
    1.73 +2019-04-17 13:36:16,876 DEBUG file.SimpleFileLoginProvider [pool-1-thread-44,debug:84] Found 4 lines that match
    1.74 +2019-04-17 13:36:16,877 DEBUG file.SimpleFileLoginProvider [pool-1-thread-44,debug:84] Found a login for null
    1.75 +2019-04-17 13:36:16,876 DEBUG activity.MatchedIterativeActivity [pool-1-thread-45,debug:84] performing iterative stage of processing
    1.76 +2019-04-17 13:36:16,877 DEBUG jdbc.JDBCDataResource [pool-1-thread-44,debug:84] Using JDBC URL : jdbc:apache:commons:dbcp:ogsadai-jdbcpool-ogsadai-e276da99-d894-4732-88d3-9ab631334756
    1.77 +2019-04-17 13:36:16,877 DEBUG blue.ContextActivity [pool-1-thread-45,processIteration:150] processIteration(Object[])
    1.78 +2019-04-17 13:36:16,877 DEBUG blue.ContextActivity [pool-1-thread-45,processIteration:194]  value [SELECT TOP 10 [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_OICNN6LA7ZGE4AAAAFVCOLMU64] AS "filterID",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GA3L6QBDMJJBGAAAAFVCOLMU7I] AS "shortName",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_LKH44AVWZ57A6AAAAFVCOLMU7Q] AS "name",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GANXWEZOASLXSAAAAFVCOLMU7Y] AS "description",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_S4RM57SQGFNFIAAAAFVCOLMVAA] AS "cutOn",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_TV6YY3AG4TXQGAAAAFVCOLMVAI] AS "cutOff",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_WWBAXSUCWPDSEAAAAFVCOLMVAQ] AS "aebv",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_YCSK2LNXTXZZEAAAAFVCOLMVAY] AS "vegaToAB",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_P2BAI4NRHRD5MAAAAFVCOLMVBE] AS "oneSecMLVg",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_AUOSHIQIJPPJ2AAAAFVCOLMVBM] AS "isSectioned"
    1.79 +FROM [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE]]
    1.80 +2019-04-17 13:36:16,878 DEBUG activity.MatchedIterativeActivity [pool-1-thread-45,debug:84] performing last stage of processing
    1.81 +2019-04-17 13:36:16,878 DEBUG blue.ContextActivity [pool-1-thread-45,postprocess:227] postprocess()
    1.82 +2019-04-17 13:36:16,878 DEBUG activity.MatchedIterativeActivity [pool-1-thread-45,debug:84] performing clean-up
    1.83 +2019-04-17 13:36:16,878 DEBUG activity.MatchedIterativeActivity [pool-1-thread-44,debug:84] performing iterative stage of processing
    1.84 +2019-04-17 13:36:16,878 DEBUG event.LoggingActivityListener [pool-1-thread-45,debug:84] COMPLETED: Activity uk.ac.roe.wfau.firethorn.Context (instance name = uk.ac.roe.wfau.firethorn.Context-ogsadai-0ef2e6b9-f063-49a9-860f-9f9ea2d481ad)
    1.85 +2019-04-17 13:36:16,886 DEBUG event.LoggingActivityListener [pool-1-thread-45,debug:84] PROCESSING: Activity uk.org.ogsadai.DeliverToRequestStatus (instance name = uk.org.ogsadai.DeliverToRequestStatus-ogsadai-15df7c00-a340-4e47-a7e7-ea8cb3c059c3)
    1.86 +2019-04-17 13:36:16,887 DEBUG event.LoggingActivityListener [pool-1-thread-46,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.Delays (instance name = uk.ac.roe.wfau.firethorn.Delays-ogsadai-1d1af8cd-2e4d-438c-8699-2dd8df45a2e5)
    1.87 +2019-04-17 13:36:16,887 DEBUG activity.MatchedIterativeActivity [pool-1-thread-46,debug:84] performing first stage of processing
    1.88 +2019-04-17 13:36:16,887 DEBUG data.DelaysActivity [pool-1-thread-46,preprocess:102] preprocess()
    1.89 +2019-04-17 13:36:16,887 DEBUG activity.MatchedIterativeActivity [pool-1-thread-46,debug:84] performing iterative stage of processing
    1.90 +2019-04-17 13:36:16,889 DEBUG event.LoggingActivityListener [pool-1-thread-47,debug:84] PROCESSING: Activity uk.org.ogsadai.SQLQuery (instance name = uk.org.ogsadai.SQLQuery-ogsadai-4c660365-75de-4e62-b96e-aff634cd2ede)
    1.91 +2019-04-17 13:36:16,890 DEBUG activity.MatchedIterativeActivity [pool-1-thread-47,debug:84] performing first stage of processing
    1.92 +2019-04-17 13:36:16,890 DEBUG event.LoggingActivityListener [pool-1-thread-48,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.Limits (instance name = uk.ac.roe.wfau.firethorn.Limits-ogsadai-6cf18e79-eb0c-448b-87c9-8466a2505f48)
    1.93 +2019-04-17 13:36:16,890 DEBUG file.SimpleFileLoginProvider [pool-1-thread-47,debug:84] In SimpleFileLogin:getLogin
    1.94 +2019-04-17 13:36:16,890 DEBUG activity.MatchedIterativeActivity [pool-1-thread-48,debug:84] performing first stage of processing
    1.95 +2019-04-17 13:36:16,891 DEBUG data.LimitsActivity [pool-1-thread-48,preprocess:144] preprocess()
    1.96 +2019-04-17 13:36:16,891 DEBUG activity.MatchedIterativeActivity [pool-1-thread-48,debug:84] performing iterative stage of processing
    1.97 +2019-04-17 13:36:16,890 DEBUG file.SimpleFileLoginProvider [pool-1-thread-47,debug:84] In getLogin: ResourceID:  User ID: null
    1.98 +2019-04-17 13:36:16,892 DEBUG file.SimpleFileLoginProvider [pool-1-thread-47,debug:84] Found 4 lines that match
    1.99 +2019-04-17 13:36:16,892 DEBUG file.SimpleFileLoginProvider [pool-1-thread-47,debug:84] Found a login for null
   1.100 +2019-04-17 13:36:16,892 DEBUG jdbc.JDBCDataResource [pool-1-thread-47,debug:84] Using JDBC URL : jdbc:apache:commons:dbcp:ogsadai-jdbcpool-ogsadai-e276da99-d894-4732-88d3-9ab631334756
   1.101 +2019-04-17 13:36:16,892 DEBUG activity.MatchedIterativeActivity [pool-1-thread-47,debug:84] performing iterative stage of processing
   1.102 +2019-04-17 13:36:16,892 DEBUG sql.SQLQueryActivity [pool-1-thread-47,processIteration:259] SQL QUERY: SELECT TOP 10 [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_OICNN6LA7ZGE4AAAAFVCOLMU64] AS "filterID",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GA3L6QBDMJJBGAAAAFVCOLMU7I] AS "shortName",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_LKH44AVWZ57A6AAAAFVCOLMU7Q] AS "name",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GANXWEZOASLXSAAAAFVCOLMU7Y] AS "description",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_S4RM57SQGFNFIAAAAFVCOLMVAA] AS "cutOn",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_TV6YY3AG4TXQGAAAAFVCOLMVAI] AS "cutOff",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_WWBAXSUCWPDSEAAAAFVCOLMVAQ] AS "aebv",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_YCSK2LNXTXZZEAAAAFVCOLMVAY] AS "vegaToAB",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_P2BAI4NRHRD5MAAAAFVCOLMVBE] AS "oneSecMLVg",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_AUOSHIQIJPPJ2AAAAFVCOLMVBM] AS "isSectioned"
   1.103 +FROM [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE]
   1.104 +2019-04-17 13:36:16,893 DEBUG sql.SQLQueryActivity [pool-1-thread-47,processIteration:262] Initialising query
   1.105 +2019-04-17 13:36:16,893 DEBUG sql.SQLQueryActivity [pool-1-thread-47,processIteration:274] Executing query
   1.106 +2019-04-17 13:36:16,893 DEBUG sql.SQLQueryActivity [pool-1-thread-47,executeQuery:364] Creating CallableStatement for query
   1.107 +2019-04-17 13:36:16,893 DEBUG sql.SQLQueryActivity [pool-1-thread-47,executeQuery:369] Submitting CallableStatement to ExecutorService
   1.108 +2019-04-17 13:36:16,896 DEBUG sql.SQLQueryActivity [pool-1-thread-47,executeQuery:376] Initiating CallableStatement and starting background execution
   1.109 +2019-04-17 13:36:16,898 DEBUG sql.SQLQueryActivity [pool-1-thread-47,executeQuery:390] CallableStatement encountered problem in query execution
   1.110 +2019-04-17 13:36:16,898 DEBUG sql.SQLQueryActivity [pool-1-thread-47,executeQuery:391] Original cause [java.sql.SQLException]
   1.111 +2019-04-17 13:36:16,898 DEBUG sql.SQLQueryActivity [pool-1-thread-47,processIteration:323] Caught a SQLException, wrapping it in an ActivitySQLUserException
   1.112 +2019-04-17 13:36:16,899 DEBUG activity.MatchedIterativeActivity [pool-1-thread-47,debug:84] performing clean-up
   1.113 +2019-04-17 13:36:16,899 DEBUG sql.SQLQueryActivity [pool-1-thread-47,cleanUp:468] Shutting down ExecutorService
   1.114 +2019-04-17 13:36:16,899 DEBUG sql.SQLQueryActivity [pool-1-thread-47,cleanUp:473] Closing Statement
   1.115 +2019-04-17 13:36:16,899 DEBUG sql.SQLQueryActivity [pool-1-thread-47,cleanUp:480] Releasing Connection
   1.116 +2019-04-17 13:36:16,900 DEBUG event.LoggingActivityListener [pool-1-thread-47,debug:84] uk.org.ogsadai.activity.sql.ActivitySQLUserException: The activity encountered a problem while interacting with a relational database.
   1.117 +	at uk.ac.roe.wfau.firethorn.ogsadai.activity.server.sql.SQLQueryActivity.processIteration(SQLQueryActivity.java:324)
   1.118 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:90)
   1.119 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   1.120 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   1.121 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.122 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   1.123 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.124 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   1.125 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   1.126 +	at java.lang.Thread.run(Thread.java:748)
   1.127 +Caused by: java.sql.SQLException: Invalid object name 'FirethornUserdataTAP20181212LIVE.dbo.XX_V3XRF4TOX22AGAAAAFVCOLMUXE'.
   1.128 +	at net.sourceforge.jtds.jdbc.SQLDiagnostic.addDiagnostic(SQLDiagnostic.java:372)
   1.129 +	at net.sourceforge.jtds.jdbc.TdsCore.tdsErrorToken(TdsCore.java:2988)
   1.130 +	at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2421)
   1.131 +	at net.sourceforge.jtds.jdbc.TdsCore.getMoreResults(TdsCore.java:671)
   1.132 +	at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQLQuery(JtdsStatement.java:505)
   1.133 +	at net.sourceforge.jtds.jdbc.JtdsStatement.executeQuery(JtdsStatement.java:1427)
   1.134 +	at org.apache.commons.dbcp.DelegatingStatement.executeQuery(DelegatingStatement.java:208)
   1.135 +	at org.apache.commons.dbcp.DelegatingStatement.executeQuery(DelegatingStatement.java:208)
   1.136 +	at uk.org.ogsadai.activity.sql.CallableStatement.call(CallableStatement.java:66)
   1.137 +	at uk.ac.roe.wfau.firethorn.ogsadai.activity.server.sql.SQLQueryActivity$ChaoticCallableStatement.call(SQLQueryActivity.java:420)
   1.138 +	at uk.ac.roe.wfau.firethorn.ogsadai.activity.server.sql.SQLQueryActivity$ChaoticCallableStatement.call(SQLQueryActivity.java:409)
   1.139 +	... 4 more
   1.140 +
   1.141 +2019-04-17 13:36:16,900 WARN  event.LoggingActivityListener [pool-1-thread-47,warnExceptionAndChildren:343] #1555508176899:1029# A problem has occurred during processing of activity uk.org.ogsadai.SQLQuery with instance name uk.org.ogsadai.SQLQuery-ogsadai-4c660365-75de-4e62-b96e-aff634cd2ede.
   1.142 +2019-04-17 13:36:16,901 WARN  event.LoggingActivityListener [pool-1-thread-47,warnExceptionAndChildren:343] #1555508176899:1029# The activity encountered a problem while interacting with a relational database.
   1.143 +2019-04-17 13:36:16,901 WARN  event.LoggingActivityListener [pool-1-thread-47,warnExceptionAndChildren:343] #1555508176899:1029# java.sql.SQLException: Invalid object name 'FirethornUserdataTAP20181212LIVE.dbo.XX_V3XRF4TOX22AGAAAAFVCOLMUXE'.
   1.144 +2019-04-17 13:36:16,901 DEBUG activity.MatchedIterativeActivity [pool-1-thread-46,debug:84] performing clean-up
   1.145 +2019-04-17 13:36:16,902 DEBUG event.LoggingActivityListener [pool-1-thread-46,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   1.146 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   1.147 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   1.148 +	at uk.org.ogsadai.activity.io.TupleListActivityInput.read(TupleListActivityInput.java:77)
   1.149 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.performNextIteration(MatchedIterativeActivity.java:183)
   1.150 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:88)
   1.151 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   1.152 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   1.153 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.154 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   1.155 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.156 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   1.157 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   1.158 +	at java.lang.Thread.run(Thread.java:748)
   1.159 +
   1.160 +2019-04-17 13:36:16,902 WARN  event.LoggingActivityListener [pool-1-thread-46,warnExceptionAndChildren:343] #1555508176901:1032# A problem has occurred during processing of activity uk.ac.roe.wfau.firethorn.Delays with instance name uk.ac.roe.wfau.firethorn.Delays-ogsadai-1d1af8cd-2e4d-438c-8699-2dd8df45a2e5.
   1.161 +2019-04-17 13:36:16,902 WARN  event.LoggingActivityListener [pool-1-thread-46,warnExceptionAndChildren:343] #1555508176901:1032# The pipe has been closed due to an error that occurred at the data producer.
   1.162 +2019-04-17 13:36:16,903 DEBUG activity.MatchedIterativeActivity [pool-1-thread-48,debug:84] performing clean-up
   1.163 +2019-04-17 13:36:16,911 DEBUG context.RequestContextFactory [http-nio-8080-exec-2,createContext:62] createContext(HttpServletRequest)
   1.164 +2019-04-17 13:36:16,911 DEBUG context.RequestContextFactory [http-nio-8080-exec-2,createContext:64] remote [172.18.0.5]
   1.165 +2019-04-17 13:36:16,912 DEBUG event.LoggingActivityListener [pool-1-thread-48,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   1.166 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   1.167 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   1.168 +	at uk.org.ogsadai.activity.io.TupleListActivityInput.read(TupleListActivityInput.java:77)
   1.169 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.performNextIteration(MatchedIterativeActivity.java:183)
   1.170 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:88)
   1.171 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   1.172 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   1.173 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.174 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   1.175 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.176 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   1.177 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   1.178 +	at java.lang.Thread.run(Thread.java:748)
   1.179 +
   1.180 +2019-04-17 13:36:16,912 WARN  event.LoggingActivityListener [pool-1-thread-48,warnExceptionAndChildren:343] #1555508176903:1035# A problem has occurred during processing of activity uk.ac.roe.wfau.firethorn.Limits with instance name uk.ac.roe.wfau.firethorn.Limits-ogsadai-6cf18e79-eb0c-448b-87c9-8466a2505f48.
   1.181 +2019-04-17 13:36:16,913 WARN  event.LoggingActivityListener [pool-1-thread-48,warnExceptionAndChildren:343] #1555508176903:1035# The pipe has been closed due to an error that occurred at the data producer.
   1.182 +2019-04-17 13:36:16,914 DEBUG activity.MatchedIterativeActivity [pool-1-thread-44,debug:84] performing clean-up
   1.183 +2019-04-17 13:36:16,915 DEBUG event.LoggingActivityListener [pool-1-thread-44,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   1.184 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   1.185 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   1.186 +	at uk.org.ogsadai.activity.io.TupleListActivityInput.read(TupleListActivityInput.java:77)
   1.187 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.performNextIteration(MatchedIterativeActivity.java:183)
   1.188 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:88)
   1.189 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   1.190 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   1.191 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.192 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   1.193 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.194 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   1.195 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   1.196 +	at java.lang.Thread.run(Thread.java:748)
   1.197 +
   1.198 +2019-04-17 13:36:16,915 WARN  event.LoggingActivityListener [pool-1-thread-44,warnExceptionAndChildren:343] #1555508176914:1039# A problem has occurred during processing of activity uk.ac.roe.wfau.firethorn.JdbcInsertData with instance name uk.ac.roe.wfau.firethorn.JdbcInsertData-ogsadai-47cc78c5-bfe7-49ab-91b9-2394abe5c3f7.
   1.199 +2019-04-17 13:36:16,915 WARN  event.LoggingActivityListener [pool-1-thread-44,warnExceptionAndChildren:343] #1555508176914:1039# The pipe has been closed due to an error that occurred at the data producer.
   1.200 +2019-04-17 13:36:16,915 DEBUG event.LoggingActivityListener [pool-1-thread-45,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   1.201 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   1.202 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   1.203 +	at uk.org.ogsadai.activity.delivery.DeliverToRequestStatusActivity.process(DeliverToRequestStatusActivity.java:138)
   1.204 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   1.205 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   1.206 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.207 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   1.208 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   1.209 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   1.210 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   1.211 +	at java.lang.Thread.run(Thread.java:748)
   1.212 +
   1.213 +2019-04-17 13:36:16,916 WARN  event.LoggingActivityListener [pool-1-thread-45,warnExceptionAndChildren:343] #1555508176915:1042# A problem has occurred during processing of activity uk.org.ogsadai.DeliverToRequestStatus with instance name uk.org.ogsadai.DeliverToRequestStatus-ogsadai-15df7c00-a340-4e47-a7e7-ea8cb3c059c3.
   1.214 +2019-04-17 13:36:16,916 WARN  event.LoggingActivityListener [pool-1-thread-45,warnExceptionAndChildren:343] #1555508176915:1042# The pipe has been closed due to an error that occurred at the data producer.
   1.215 +
   1.216 +
   1.217 +f
     2.1 --- /dev/null	Thu Jan 01 00:00:00 1970 +0000
     2.2 +++ b/doc/notes/stv/20190417-Propagated-Fail.txt	Wed Apr 17 16:45:12 2019 +0300
     2.3 @@ -0,0 +1,197 @@
     2.4 +#
     2.5 +# <meta:header>
     2.6 +#   <meta:licence>
     2.7 +#     Copyright (c) 2018, ROE (http://www.roe.ac.uk/)
     2.8 +#
     2.9 +#     This information is free software: you can redistribute it and/or modify
    2.10 +#     it under the terms of the GNU General Public License as published by
    2.11 +#     the Free Software Foundation, either version 3 of the License, or
    2.12 +#     (at your option) any later version.
    2.13 +#
    2.14 +#     This information is distributed in the hope that it will be useful,
    2.15 +#     but WITHOUT ANY WARRANTY; without even the implied warranty of
    2.16 +#     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
    2.17 +#     GNU General Public License for more details.
    2.18 +#  
    2.19 +#     You should have received a copy of the GNU General Public License
    2.20 +#     along with this program.  If not, see <http://www.gnu.org/licenses/>.
    2.21 +#   </meta:licence>
    2.22 +# </meta:header>
    2.23 +#
    2.24 +#
    2.25 +
    2.26 +## The following runs a query on a Table that was deleted.
    2.27 +## In this particular case, the fail WAS properly propagated to Firethorn
    2.28 +## Need to compare output with Non-propagated example, to spot any differences
    2.29 +
    2.30 +
    2.31 +... query_str = "SELECT TOP 10 * from temp.XX_V3XRF4TOX22AGAAAAFVCOLMUXE"
    2.32 +>>> query_obj = workspace.create_query(
    2.33 +...     query_str,
    2.34 +...     "COMPLETED",
    2.35 +...     None,
    2.36 +...     3000000
    2.37 +...     )
    2.38 +
    2.39 +
    2.40 +## If we check the blue query status we see it as:
    2.41 +## "status": "FAILED",
    2.42 +
    2.43 +
    2.44 +
    2.45 +2019-04-17 13:40:55,566 DEBUG event.LoggingActivityListener [pool-1-thread-49,debug:84] PENDING: Activity uk.ac.roe.wfau.firethorn.Limits (instance name = uk.ac.roe.wfau.firethorn.Limits-ogsadai-907622ba-73d9-40c6-82d8-8281abb292e8)
    2.46 +2019-04-17 13:40:55,566 DEBUG event.LoggingActivityListener [pool-1-thread-49,debug:84] PENDING: Activity uk.org.ogsadai.DeliverToRequestStatus (instance name = uk.org.ogsadai.DeliverToRequestStatus-ogsadai-8775be3e-586b-4e04-9252-290e44bf668f)
    2.47 +2019-04-17 13:40:55,566 DEBUG event.LoggingActivityListener [pool-1-thread-49,debug:84] PENDING: Activity uk.ac.roe.wfau.firethorn.Context (instance name = uk.ac.roe.wfau.firethorn.Context-ogsadai-de0ceeca-bad9-4cac-8589-7aa3a73d7f47)
    2.48 +2019-04-17 13:40:55,566 DEBUG event.LoggingActivityListener [pool-1-thread-49,debug:84] PENDING: Activity uk.org.ogsadai.SQLQuery (instance name = uk.org.ogsadai.SQLQuery-ogsadai-06706101-43e6-4c60-9316-8983c0bfb240)
    2.49 +2019-04-17 13:40:55,567 DEBUG event.LoggingActivityListener [pool-1-thread-49,debug:84] PENDING: Activity uk.ac.roe.wfau.firethorn.Delays (instance name = uk.ac.roe.wfau.firethorn.Delays-ogsadai-6334ea8a-6685-4233-83bd-b7ea735cf38d)
    2.50 +2019-04-17 13:40:55,567 DEBUG event.LoggingActivityListener [pool-1-thread-50,debug:84] PROCESSING: Activity uk.org.ogsadai.DeliverToRequestStatus (instance name = uk.org.ogsadai.DeliverToRequestStatus-ogsadai-8775be3e-586b-4e04-9252-290e44bf668f)
    2.51 +2019-04-17 13:40:55,568 DEBUG event.LoggingActivityListener [pool-1-thread-51,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.Limits (instance name = uk.ac.roe.wfau.firethorn.Limits-ogsadai-907622ba-73d9-40c6-82d8-8281abb292e8)
    2.52 +2019-04-17 13:40:55,568 DEBUG activity.MatchedIterativeActivity [pool-1-thread-51,debug:84] performing first stage of processing
    2.53 +2019-04-17 13:40:55,569 DEBUG data.LimitsActivity [pool-1-thread-51,preprocess:144] preprocess()
    2.54 +2019-04-17 13:40:55,569 DEBUG event.LoggingActivityListener [pool-1-thread-53,debug:84] PROCESSING: Activity uk.org.ogsadai.SQLQuery (instance name = uk.org.ogsadai.SQLQuery-ogsadai-06706101-43e6-4c60-9316-8983c0bfb240)
    2.55 +2019-04-17 13:40:55,569 DEBUG event.LoggingActivityListener [pool-1-thread-54,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.Delays (instance name = uk.ac.roe.wfau.firethorn.Delays-ogsadai-6334ea8a-6685-4233-83bd-b7ea735cf38d)
    2.56 +2019-04-17 13:40:55,569 DEBUG event.LoggingActivityListener [pool-1-thread-52,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.Context (instance name = uk.ac.roe.wfau.firethorn.Context-ogsadai-de0ceeca-bad9-4cac-8589-7aa3a73d7f47)
    2.57 +2019-04-17 13:40:55,570 DEBUG activity.MatchedIterativeActivity [pool-1-thread-52,debug:84] performing first stage of processing
    2.58 +2019-04-17 13:40:55,570 DEBUG blue.ContextActivity [pool-1-thread-52,preprocess:126] preprocess()
    2.59 +2019-04-17 13:40:55,570 DEBUG activity.MatchedIterativeActivity [pool-1-thread-52,debug:84] performing iterative stage of processing
    2.60 +2019-04-17 13:40:55,569 DEBUG activity.MatchedIterativeActivity [pool-1-thread-51,debug:84] performing iterative stage of processing
    2.61 +2019-04-17 13:40:55,571 DEBUG activity.MatchedIterativeActivity [pool-1-thread-54,debug:84] performing first stage of processing
    2.62 +2019-04-17 13:40:55,571 DEBUG blue.ContextActivity [pool-1-thread-52,processIteration:150] processIteration(Object[])
    2.63 +2019-04-17 13:40:55,571 DEBUG blue.ContextActivity [pool-1-thread-52,processIteration:194]  value [SELECT TOP 10 [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_OICNN6LA7ZGE4AAAAFVCOLMU64] AS "filterID",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GA3L6QBDMJJBGAAAAFVCOLMU7I] AS "shortName",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_LKH44AVWZ57A6AAAAFVCOLMU7Q] AS "name",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GANXWEZOASLXSAAAAFVCOLMU7Y] AS "description",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_S4RM57SQGFNFIAAAAFVCOLMVAA] AS "cutOn",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_TV6YY3AG4TXQGAAAAFVCOLMVAI] AS "cutOff",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_WWBAXSUCWPDSEAAAAFVCOLMVAQ] AS "aebv",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_YCSK2LNXTXZZEAAAAFVCOLMVAY] AS "vegaToAB",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_P2BAI4NRHRD5MAAAAFVCOLMVBE] AS "oneSecMLVg",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_AUOSHIQIJPPJ2AAAAFVCOLMVBM] AS "isSectioned"
    2.64 +FROM [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE]]
    2.65 +2019-04-17 13:40:55,571 DEBUG activity.MatchedIterativeActivity [pool-1-thread-52,debug:84] performing last stage of processing
    2.66 +2019-04-17 13:40:55,572 DEBUG blue.ContextActivity [pool-1-thread-52,postprocess:227] postprocess()
    2.67 +2019-04-17 13:40:55,572 DEBUG activity.MatchedIterativeActivity [pool-1-thread-52,debug:84] performing clean-up
    2.68 +2019-04-17 13:40:55,572 DEBUG data.DelaysActivity [pool-1-thread-54,preprocess:102] preprocess()
    2.69 +2019-04-17 13:40:55,572 DEBUG activity.MatchedIterativeActivity [pool-1-thread-54,debug:84] performing iterative stage of processing
    2.70 +2019-04-17 13:40:55,570 DEBUG event.LoggingActivityListener [pool-1-thread-55,debug:84] PROCESSING: Activity uk.ac.roe.wfau.firethorn.JdbcInsertData (instance name = uk.ac.roe.wfau.firethorn.JdbcInsertData-ogsadai-8117c5bf-7c4f-4048-8718-4f4350376758)
    2.71 +2019-04-17 13:40:55,573 DEBUG activity.MatchedIterativeActivity [pool-1-thread-55,debug:84] performing first stage of processing
    2.72 +2019-04-17 13:40:55,573 DEBUG file.SimpleFileLoginProvider [pool-1-thread-55,debug:84] In SimpleFileLogin:getLogin
    2.73 +2019-04-17 13:40:55,569 DEBUG activity.MatchedIterativeActivity [pool-1-thread-53,debug:84] performing first stage of processing
    2.74 +2019-04-17 13:40:55,573 DEBUG event.LoggingActivityListener [pool-1-thread-52,debug:84] COMPLETED: Activity uk.ac.roe.wfau.firethorn.Context (instance name = uk.ac.roe.wfau.firethorn.Context-ogsadai-de0ceeca-bad9-4cac-8589-7aa3a73d7f47)
    2.75 +2019-04-17 13:40:55,575 DEBUG file.SimpleFileLoginProvider [pool-1-thread-55,debug:84] In getLogin: ResourceID:  User ID: null
    2.76 +2019-04-17 13:40:55,574 DEBUG file.SimpleFileLoginProvider [pool-1-thread-53,debug:84] In SimpleFileLogin:getLogin
    2.77 +2019-04-17 13:40:55,575 DEBUG file.SimpleFileLoginProvider [pool-1-thread-55,debug:84] Found 4 lines that match
    2.78 +2019-04-17 13:40:55,576 DEBUG file.SimpleFileLoginProvider [pool-1-thread-55,debug:84] Found a login for null
    2.79 +2019-04-17 13:40:55,576 DEBUG jdbc.JDBCDataResource [pool-1-thread-55,debug:84] Using JDBC URL : jdbc:apache:commons:dbcp:ogsadai-jdbcpool-ogsadai-e276da99-d894-4732-88d3-9ab631334756
    2.80 +2019-04-17 13:40:55,575 DEBUG file.SimpleFileLoginProvider [pool-1-thread-53,debug:84] In getLogin: ResourceID:  User ID: null
    2.81 +2019-04-17 13:40:55,577 DEBUG file.SimpleFileLoginProvider [pool-1-thread-53,debug:84] Found 4 lines that match
    2.82 +2019-04-17 13:40:55,577 DEBUG file.SimpleFileLoginProvider [pool-1-thread-53,debug:84] Found a login for null
    2.83 +2019-04-17 13:40:55,577 DEBUG jdbc.JDBCDataResource [pool-1-thread-53,debug:84] Using JDBC URL : jdbc:apache:commons:dbcp:ogsadai-jdbcpool-ogsadai-e276da99-d894-4732-88d3-9ab631334756
    2.84 +2019-04-17 13:40:55,578 DEBUG activity.MatchedIterativeActivity [pool-1-thread-53,debug:84] performing iterative stage of processing
    2.85 +2019-04-17 13:40:55,578 DEBUG sql.SQLQueryActivity [pool-1-thread-53,processIteration:259] SQL QUERY: SELECT TOP 10 [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_OICNN6LA7ZGE4AAAAFVCOLMU64] AS "filterID",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GA3L6QBDMJJBGAAAAFVCOLMU7I] AS "shortName",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_LKH44AVWZ57A6AAAAFVCOLMU7Q] AS "name",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_GANXWEZOASLXSAAAAFVCOLMU7Y] AS "description",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_S4RM57SQGFNFIAAAAFVCOLMVAA] AS "cutOn",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_TV6YY3AG4TXQGAAAAFVCOLMVAI] AS "cutOff",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_WWBAXSUCWPDSEAAAAFVCOLMVAQ] AS "aebv",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_YCSK2LNXTXZZEAAAAFVCOLMVAY] AS "vegaToAB",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_P2BAI4NRHRD5MAAAAFVCOLMVBE] AS "oneSecMLVg",[FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE].[XX_AUOSHIQIJPPJ2AAAAFVCOLMVBM] AS "isSectioned"
    2.86 +FROM [FirethornUserdataTAP20181212LIVE].[dbo].[XX_V3XRF4TOX22AGAAAAFVCOLMUXE]
    2.87 +2019-04-17 13:40:55,578 DEBUG sql.SQLQueryActivity [pool-1-thread-53,processIteration:262] Initialising query
    2.88 +2019-04-17 13:40:55,578 DEBUG sql.SQLQueryActivity [pool-1-thread-53,processIteration:274] Executing query
    2.89 +2019-04-17 13:40:55,578 DEBUG sql.SQLQueryActivity [pool-1-thread-53,executeQuery:364] Creating CallableStatement for query
    2.90 +2019-04-17 13:40:55,579 DEBUG sql.SQLQueryActivity [pool-1-thread-53,executeQuery:369] Submitting CallableStatement to ExecutorService
    2.91 +2019-04-17 13:40:55,579 DEBUG sql.SQLQueryActivity [pool-1-thread-53,executeQuery:376] Initiating CallableStatement and starting background execution
    2.92 +2019-04-17 13:40:55,577 DEBUG activity.MatchedIterativeActivity [pool-1-thread-55,debug:84] performing iterative stage of processing
    2.93 +2019-04-17 13:40:55,581 DEBUG sql.SQLQueryActivity [pool-1-thread-53,executeQuery:390] CallableStatement encountered problem in query execution
    2.94 +2019-04-17 13:40:55,581 DEBUG sql.SQLQueryActivity [pool-1-thread-53,executeQuery:391] Original cause [java.sql.SQLException]
    2.95 +2019-04-17 13:40:55,582 DEBUG sql.SQLQueryActivity [pool-1-thread-53,processIteration:323] Caught a SQLException, wrapping it in an ActivitySQLUserException
    2.96 +2019-04-17 13:40:55,582 DEBUG activity.MatchedIterativeActivity [pool-1-thread-53,debug:84] performing clean-up
    2.97 +2019-04-17 13:40:55,582 DEBUG sql.SQLQueryActivity [pool-1-thread-53,cleanUp:468] Shutting down ExecutorService
    2.98 +2019-04-17 13:40:55,582 DEBUG sql.SQLQueryActivity [pool-1-thread-53,cleanUp:473] Closing Statement
    2.99 +2019-04-17 13:40:55,582 DEBUG sql.SQLQueryActivity [pool-1-thread-53,cleanUp:480] Releasing Connection
   2.100 +2019-04-17 13:40:55,583 DEBUG event.LoggingActivityListener [pool-1-thread-53,debug:84] uk.org.ogsadai.activity.sql.ActivitySQLUserException: The activity encountered a problem while interacting with a relational database.
   2.101 +	at uk.ac.roe.wfau.firethorn.ogsadai.activity.server.sql.SQLQueryActivity.processIteration(SQLQueryActivity.java:324)
   2.102 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:90)
   2.103 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   2.104 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   2.105 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.106 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   2.107 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.108 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   2.109 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   2.110 +	at java.lang.Thread.run(Thread.java:748)
   2.111 +Caused by: java.sql.SQLException: Invalid object name 'FirethornUserdataTAP20181212LIVE.dbo.XX_V3XRF4TOX22AGAAAAFVCOLMUXE'.
   2.112 +	at net.sourceforge.jtds.jdbc.SQLDiagnostic.addDiagnostic(SQLDiagnostic.java:372)
   2.113 +	at net.sourceforge.jtds.jdbc.TdsCore.tdsErrorToken(TdsCore.java:2988)
   2.114 +	at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2421)
   2.115 +	at net.sourceforge.jtds.jdbc.TdsCore.getMoreResults(TdsCore.java:671)
   2.116 +	at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQLQuery(JtdsStatement.java:505)
   2.117 +	at net.sourceforge.jtds.jdbc.JtdsStatement.executeQuery(JtdsStatement.java:1427)
   2.118 +	at org.apache.commons.dbcp.DelegatingStatement.executeQuery(DelegatingStatement.java:208)
   2.119 +	at org.apache.commons.dbcp.DelegatingStatement.executeQuery(DelegatingStatement.java:208)
   2.120 +	at uk.org.ogsadai.activity.sql.CallableStatement.call(CallableStatement.java:66)
   2.121 +	at uk.ac.roe.wfau.firethorn.ogsadai.activity.server.sql.SQLQueryActivity$ChaoticCallableStatement.call(SQLQueryActivity.java:420)
   2.122 +	at uk.ac.roe.wfau.firethorn.ogsadai.activity.server.sql.SQLQueryActivity$ChaoticCallableStatement.call(SQLQueryActivity.java:409)
   2.123 +	... 4 more
   2.124 +
   2.125 +2019-04-17 13:40:55,584 WARN  event.LoggingActivityListener [pool-1-thread-53,warnExceptionAndChildren:343] #1555508455582:1062# A problem has occurred during processing of activity uk.org.ogsadai.SQLQuery with instance name uk.org.ogsadai.SQLQuery-ogsadai-06706101-43e6-4c60-9316-8983c0bfb240.
   2.126 +2019-04-17 13:40:55,584 WARN  event.LoggingActivityListener [pool-1-thread-53,warnExceptionAndChildren:343] #1555508455582:1062# The activity encountered a problem while interacting with a relational database.
   2.127 +2019-04-17 13:40:55,584 WARN  event.LoggingActivityListener [pool-1-thread-53,warnExceptionAndChildren:343] #1555508455582:1062# java.sql.SQLException: Invalid object name 'FirethornUserdataTAP20181212LIVE.dbo.XX_V3XRF4TOX22AGAAAAFVCOLMUXE'.
   2.128 +2019-04-17 13:40:55,584 DEBUG activity.MatchedIterativeActivity [pool-1-thread-54,debug:84] performing clean-up
   2.129 +2019-04-17 13:40:55,587 DEBUG event.LoggingActivityListener [pool-1-thread-54,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   2.130 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   2.131 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   2.132 +	at uk.org.ogsadai.activity.io.TupleListActivityInput.read(TupleListActivityInput.java:77)
   2.133 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.performNextIteration(MatchedIterativeActivity.java:183)
   2.134 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:88)
   2.135 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   2.136 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   2.137 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.138 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   2.139 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.140 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   2.141 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   2.142 +	at java.lang.Thread.run(Thread.java:748)
   2.143 +
   2.144 +2019-04-17 13:40:55,587 WARN  event.LoggingActivityListener [pool-1-thread-54,warnExceptionAndChildren:343] #1555508455584:1065# A problem has occurred during processing of activity uk.ac.roe.wfau.firethorn.Delays with instance name uk.ac.roe.wfau.firethorn.Delays-ogsadai-6334ea8a-6685-4233-83bd-b7ea735cf38d.
   2.145 +2019-04-17 13:40:55,587 WARN  event.LoggingActivityListener [pool-1-thread-54,warnExceptionAndChildren:343] #1555508455584:1065# The pipe has been closed due to an error that occurred at the data producer.
   2.146 +2019-04-17 13:40:55,588 DEBUG activity.MatchedIterativeActivity [pool-1-thread-51,debug:84] performing clean-up
   2.147 +2019-04-17 13:40:55,588 DEBUG event.LoggingActivityListener [pool-1-thread-51,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   2.148 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   2.149 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   2.150 +	at uk.org.ogsadai.activity.io.TupleListActivityInput.read(TupleListActivityInput.java:77)
   2.151 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.performNextIteration(MatchedIterativeActivity.java:183)
   2.152 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:88)
   2.153 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   2.154 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   2.155 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.156 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   2.157 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.158 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   2.159 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   2.160 +	at java.lang.Thread.run(Thread.java:748)
   2.161 +
   2.162 +2019-04-17 13:40:55,588 WARN  event.LoggingActivityListener [pool-1-thread-51,warnExceptionAndChildren:343] #1555508455588:1068# A problem has occurred during processing of activity uk.ac.roe.wfau.firethorn.Limits with instance name uk.ac.roe.wfau.firethorn.Limits-ogsadai-907622ba-73d9-40c6-82d8-8281abb292e8.
   2.163 +2019-04-17 13:40:55,589 WARN  event.LoggingActivityListener [pool-1-thread-51,warnExceptionAndChildren:343] #1555508455588:1068# The pipe has been closed due to an error that occurred at the data producer.
   2.164 +2019-04-17 13:40:55,589 DEBUG activity.MatchedIterativeActivity [pool-1-thread-55,debug:84] performing clean-up
   2.165 +2019-04-17 13:40:55,590 DEBUG event.LoggingActivityListener [pool-1-thread-55,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   2.166 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   2.167 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   2.168 +	at uk.org.ogsadai.activity.io.TupleListActivityInput.read(TupleListActivityInput.java:77)
   2.169 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.performNextIteration(MatchedIterativeActivity.java:183)
   2.170 +	at uk.org.ogsadai.activity.MatchedIterativeActivity.process(MatchedIterativeActivity.java:88)
   2.171 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   2.172 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   2.173 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.174 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   2.175 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.176 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   2.177 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   2.178 +	at java.lang.Thread.run(Thread.java:748)
   2.179 +
   2.180 +2019-04-17 13:40:55,590 WARN  event.LoggingActivityListener [pool-1-thread-55,warnExceptionAndChildren:343] #1555508455589:1071# A problem has occurred during processing of activity uk.ac.roe.wfau.firethorn.JdbcInsertData with instance name uk.ac.roe.wfau.firethorn.JdbcInsertData-ogsadai-8117c5bf-7c4f-4048-8718-4f4350376758.
   2.181 +2019-04-17 13:40:55,591 WARN  event.LoggingActivityListener [pool-1-thread-55,warnExceptionAndChildren:343] #1555508455589:1071# The pipe has been closed due to an error that occurred at the data producer.
   2.182 +2019-04-17 13:40:55,591 DEBUG event.LoggingActivityListener [pool-1-thread-50,debug:84] uk.org.ogsadai.activity.io.DataError: The pipe has been closed due to an error that occurred at the data producer.
   2.183 +	at uk.org.ogsadai.activity.io.BufferedPipe.read(BufferedPipe.java:154)
   2.184 +	at uk.org.ogsadai.activity.event.EventfulPipe.read(EventfulPipe.java:118)
   2.185 +	at uk.org.ogsadai.activity.delivery.DeliverToRequestStatusActivity.process(DeliverToRequestStatusActivity.java:138)
   2.186 +	at uk.org.ogsadai.activity.event.EventfulActivity.process(EventfulActivity.java:78)
   2.187 +	at uk.org.ogsadai.activity.concurrency.ActivityProcessingTask.call(ActivityProcessingTask.java:81)
   2.188 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.189 +	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   2.190 +	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   2.191 +	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   2.192 +	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   2.193 +	at java.lang.Thread.run(Thread.java:748)
   2.194 +
   2.195 +2019-04-17 13:40:55,591 WARN  event.LoggingActivityListener [pool-1-thread-50,warnExceptionAndChildren:343] #1555508455591:1074# A problem has occurred during processing of activity uk.org.ogsadai.DeliverToRequestStatus with instance name uk.org.ogsadai.DeliverToRequestStatus-ogsadai-8775be3e-586b-4e04-9252-290e44bf668f.
   2.196 +2019-04-17 13:40:55,591 WARN  event.LoggingActivityListener [pool-1-thread-50,warnExceptionAndChildren:343] #1555508455591:1074# The pipe has been closed due to an error that occurred at the data producer.
   2.197 +2019-04-17 13:40:55,616 DEBUG context.RequestContextFactory [http-nio-8080-exec-4,createContext:62] createContext(HttpServletRequest)
   2.198 +2019-04-17 13:40:55,617 DEBUG context.RequestContextFactory [http-nio-8080-exec-4,createContext:64] remote [172.18.0.5]
   2.199 +
   2.200 +