firethorn

changeset 4204:d5d257db4923 2.1.28-tap-issues

Some Notes
author Stelios <stv@roe.ac.uk>
date Fri Apr 19 21:24:27 2019 +0300 (2019-04-19)
parents ce08d680813f
children edf5bd3168f0
files doc/notes/stv/20190419-CORRECT-FAILED-Query.txt doc/notes/stv/20190419-Debuging-Failing-Queries.txt doc/notes/stv/20190419-FAILED-Query.txt
line diff
     1.1 --- /dev/null	Thu Jan 01 00:00:00 1970 +0000
     1.2 +++ b/doc/notes/stv/20190419-CORRECT-FAILED-Query.txt	Fri Apr 19 21:24:27 2019 +0300
     1.3 @@ -0,0 +1,585 @@
     1.4 +2019-04-19 14:39:20,145 DEBUG [FireThornTaskExecutor-11] [SQLServerTranslator] SELECT TOP 10 [ATLASDR1].[dbo].[Filter].[filterID] AS "filterID",[ATLASDR1].[dbo].[Filter].[shortName] AS "shortName",[ATLASDR1].[dbo].[Filter].[name] AS "name",[ATLASDR1].[dbo].[Filter].[description] AS "description",[ATLASDR1].[dbo].[Filter].[cutOn] AS "cutOn",[ATLASDR1].[dbo].[Filter].[cutOff] AS "cutOff",[ATLASDR1].[dbo].[Filter].[aebv] AS "aebv",[ATLASDR1].[dbo].[Filter].[vegaToAB] AS "vegaToAB",[ATLASDR1].[dbo].[Filter].[oneSecMLVg] AS "oneSecMLVg",[ATLASDR1].[dbo].[Filter].[isSectioned] AS "isSectioned"
     1.5 +FROM [ATLASDR1].[dbo].[Filter] 
     1.6 +2019-04-19 14:39:20,145 DEBUG [FireThornTaskExecutor-11] [SQLServerTranslator] -------- 
     1.7 +2019-04-19 14:39:20,145 INFO  [FireThornTaskExecutor-11] [AdqlQueryTimings] TIMING - adqldone() 
     1.8 +2019-04-19 14:39:20,145 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] transition(TaskState) 
     1.9 +2019-04-19 14:39:20,145 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   ident [2954] 
    1.10 +2019-04-19 14:39:20,146 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [READY][READY] 
    1.11 +2019-04-19 14:39:20,146 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] No-op status change [READY] 
    1.12 +2019-04-19 14:39:20,146 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] After prepare() 
    1.13 +2019-04-19 14:39:20,146 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [READY] 
    1.14 +2019-04-19 14:39:20,146 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] Before execute() 
    1.15 +2019-04-19 14:39:20,146 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [READY] 
    1.16 +2019-04-19 14:39:20,146 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] execute() [2954][READY] 
    1.17 +2019-04-19 14:39:20,147 DEBUG [FireThornTaskExecutor-11] [BlueTaskLogEntity] LogEntryEntity() 
    1.18 +2019-04-19 14:39:20,147 DEBUG [FireThornTaskExecutor-11] [BlueTaskLogEntity]   task    [entity[class[uk.ac.roe.wfau.firethorn.adql.query.blue.BlueQueryEntity] ident[2954]]] 
    1.19 +2019-04-19 14:39:20,147 DEBUG [FireThornTaskExecutor-11] [BlueTaskLogEntity]   level   [INFO] 
    1.20 +2019-04-19 14:39:20,147 DEBUG [FireThornTaskExecutor-11] [BlueTaskLogEntity]   source  [uk.ac.roe.wfau.firethorn.adql.query.blue.BlueTaskLogEntity$EntityFactory] 
    1.21 +2019-04-19 14:39:20,147 DEBUG [FireThornTaskExecutor-11] [BlueTaskLogEntity]   message [Executing query] 
    1.22 +2019-04-19 14:39:20,154 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity$TaskRunner] thread(Updator) [2954] 
    1.23 +2019-04-19 14:39:20,165 DEBUG [FireThornTaskExecutor-12] [BlueTaskEntity$TaskRunner] future(Updator) [2954] 
    1.24 +2019-04-19 14:39:20,166 DEBUG [FireThornTaskExecutor-12] [BlueQueryEntity] Converting current instance [2954] 
    1.25 +2019-04-19 14:39:20,172 DEBUG [FireThornTaskExecutor-12] [AdqlQueryTimings] AdqlQueryTimings() 
    1.26 +2019-04-19 14:39:20,173 DEBUG [FireThornTaskExecutor-12] [AdqlQueryTimings] AdqlQueryTimings() 
    1.27 +2019-04-19 14:39:20,173 DEBUG [FireThornTaskExecutor-12] [BlueQueryEntity] build() 
    1.28 +2019-04-19 14:39:20,173 INFO  [FireThornTaskExecutor-12] [AdqlQueryTimings] TIMING - jdbcstart() 
    1.29 +2019-04-19 14:39:20,175 DEBUG [FireThornTaskExecutor-12] [IdentityEntity] jdbcschema() 
    1.30 +2019-04-19 14:39:20,177 DEBUG [FireThornTaskExecutor-12] [IdentityEntity] adqlschema() 
    1.31 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [JdbcSchemaEntity] tables() for [442][LIVEFirethornUserdataULOV20180719.dbo] 
    1.32 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [442][LIVEFirethornUserdataULOV20180719.dbo] 
    1.33 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [442][LIVEFirethornUserdataULOV20180719.dbo] 
    1.34 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [JdbcSchemaEntity] factory() 
    1.35 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
    1.36 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
    1.37 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
    1.38 +2019-04-19 14:39:20,181 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:35:05.764Z] 
    1.39 +2019-04-19 14:39:20,182 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
    1.40 +2019-04-19 14:39:20,182 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
    1.41 +2019-04-19 14:39:20,182 DEBUG [FireThornTaskExecutor-12] [JdbcTableEntity] JdbcTableEntity [LIVEFirethornUserdataULOV20180719.dbo][XX_Q345NPYJSVNIUAAAAFVDMCM2OY][2019-04-19T14:39:20.182Z] 
    1.42 +2019-04-19 14:39:20,182 DEBUG [FireThornTaskExecutor-12] [AdqlSchemaEntity] tables() for [445][temp] 
    1.43 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [445][temp] 
    1.44 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [445][temp] 
    1.45 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [AdqlSchemaEntity] factory() 
    1.46 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
    1.47 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
    1.48 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
    1.49 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.278Z] 
    1.50 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
    1.51 +2019-04-19 14:39:20,183 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
    1.52 +2019-04-19 14:39:20,184 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.53 +2019-04-19 14:39:20,184 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.54 +2019-04-19 14:39:20,184 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.55 +2019-04-19 14:39:20,184 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
    1.56 +2019-04-19 14:39:20,184 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
    1.57 +2019-04-19 14:39:20,184 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
    1.58 +2019-04-19 14:39:20,184 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [null] 
    1.59 +2019-04-19 14:39:20,185 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
    1.60 +2019-04-19 14:39:20,185 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is null - scanning 
    1.61 +2019-04-19 14:39:20,185 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Checking for existing lock [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.62 +2019-04-19 14:39:20,185 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] No existing lock found [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.63 +2019-04-19 14:39:20,185 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Adding new lock [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY][2019-04-19T14:39:20.185Z] 
    1.64 +2019-04-19 14:39:20,185 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Running scan [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.65 +2019-04-19 14:39:20,185 DEBUG [FireThornTaskExecutor-12] [JdbcTableEntity] scanimpl() for [2642][LIVEFirethornUserdataULOV20180719.dbo.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.66 +2019-04-19 14:39:20,187 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] scanner() for [mssql] 
    1.67 +2019-04-19 14:39:20,190 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.68 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] open [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
    1.69 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.70 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
    1.71 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.72 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] initialValue() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
    1.73 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.74 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] connect [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
    1.75 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] Source is null, updating to EMPTY 
    1.76 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] State is EMPTY, initialising DataSource 
    1.77 +2019-04-19 14:39:20,191 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.78 +2019-04-19 14:39:20,192 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.79 +2019-04-19 14:39:20,192 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] State is READY, initialising Connection 
    1.80 +2019-04-19 14:39:20,192 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] With user/pass 
    1.81 +2019-04-19 14:39:20,192 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] connecting .... 
    1.82 +2019-04-19 14:39:20,198 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] .... connected 
    1.83 +2019-04-19 14:39:20,245 DEBUG [FireThornTaskExecutor-12] [SQLServerScanner] Including schema [dbo] 
    1.84 +2019-04-19 14:39:20,627 DEBUG [FireThornTaskExecutor-12] [JdbcTableEntity] scanning table [null] 
    1.85 +2019-04-19 14:39:20,628 DEBUG [FireThornTaskExecutor-12] [JdbcTableEntity] Null table, skipping scan 
    1.86 +2019-04-19 14:39:20,628 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.87 +2019-04-19 14:39:20,628 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] close [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
    1.88 +2019-04-19 14:39:20,628 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
    1.89 +2019-04-19 14:39:20,628 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
    1.90 +2019-04-19 14:39:20,628 DEBUG [FireThornTaskExecutor-12] [JdbcTableEntity] columns() scan done for [2642][LIVEFirethornUserdataULOV20180719.dbo.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.91 +2019-04-19 14:39:20,629 DEBUG [FireThornTaskExecutor-12] [JdbcTableEntity] Matching columns [0] 
    1.92 +2019-04-19 14:39:20,629 DEBUG [FireThornTaskExecutor-12] [JdbcTableEntity] Listed but not matched [0] 
    1.93 +2019-04-19 14:39:20,629 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Releasing locks [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
    1.94 +2019-04-19 14:39:20,629 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Found existing lock [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY][2019-04-19T14:39:20.185Z] 
    1.95 +2019-04-19 14:39:20,629 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Removing .... 
    1.96 +2019-04-19 14:39:20,629 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Notifying .... 
    1.97 +2019-04-19 14:39:20,630 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][VARBINARY][0] 
    1.98 +2019-04-19 14:39:20,630 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
    1.99 +2019-04-19 14:39:20,630 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.100 +2019-04-19 14:39:20,630 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_GEOBEAS7O4YL4AAAAFVDMCM4GU] 
   1.101 +2019-04-19 14:39:20,630 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.102 +2019-04-19 14:39:20,630 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.103 +2019-04-19 14:39:20,630 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.104 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.105 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.106 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.107 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [null] 
   1.108 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.109 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is null - scanning 
   1.110 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Checking for existing lock [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.111 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] No existing lock found [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.112 +2019-04-19 14:39:20,631 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Adding new lock [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY][2019-04-19T14:39:20.631Z] 
   1.113 +2019-04-19 14:39:20,632 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Running scan [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.114 +2019-04-19 14:39:20,632 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Releasing locks [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.115 +2019-04-19 14:39:20,632 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Found existing lock [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY][2019-04-19T14:39:20.631Z] 
   1.116 +2019-04-19 14:39:20,632 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Removing .... 
   1.117 +2019-04-19 14:39:20,632 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Notifying .... 
   1.118 +2019-04-19 14:39:20,632 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.119 +2019-04-19 14:39:20,633 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.120 +2019-04-19 14:39:20,633 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.121 +2019-04-19 14:39:20,633 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.122 +2019-04-19 14:39:20,633 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.123 +2019-04-19 14:39:20,633 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.124 +2019-04-19 14:39:20,633 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.125 +2019-04-19 14:39:20,633 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.126 +2019-04-19 14:39:20,634 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.127 +2019-04-19 14:39:20,634 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][CHAR][10] 
   1.128 +2019-04-19 14:39:20,634 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.129 +2019-04-19 14:39:20,634 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.130 +2019-04-19 14:39:20,634 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_EUKQ5PTXZLKLCAAAAFVDMCM4HI] 
   1.131 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.132 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.133 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.134 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.135 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.136 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.137 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.138 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.139 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.140 +2019-04-19 14:39:20,635 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.141 +2019-04-19 14:39:20,636 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.142 +2019-04-19 14:39:20,636 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.143 +2019-04-19 14:39:20,636 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.144 +2019-04-19 14:39:20,636 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.145 +2019-04-19 14:39:20,637 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.146 +2019-04-19 14:39:20,637 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.147 +2019-04-19 14:39:20,637 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.148 +2019-04-19 14:39:20,637 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.149 +2019-04-19 14:39:20,637 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][CHAR][16] 
   1.150 +2019-04-19 14:39:20,637 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.151 +2019-04-19 14:39:20,637 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.152 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_EIT2PP64Z2FN4AAAAFVDMCM4HU] 
   1.153 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.154 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.155 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.156 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.157 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.158 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.159 +2019-04-19 14:39:20,638 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.160 +2019-04-19 14:39:20,639 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.161 +2019-04-19 14:39:20,639 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.162 +2019-04-19 14:39:20,639 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.163 +2019-04-19 14:39:20,639 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.164 +2019-04-19 14:39:20,639 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.165 +2019-04-19 14:39:20,640 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.166 +2019-04-19 14:39:20,640 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.167 +2019-04-19 14:39:20,640 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.168 +2019-04-19 14:39:20,640 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.169 +2019-04-19 14:39:20,640 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.170 +2019-04-19 14:39:20,640 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.171 +2019-04-19 14:39:20,640 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][CHAR][256] 
   1.172 +2019-04-19 14:39:20,641 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.173 +2019-04-19 14:39:20,641 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.174 +2019-04-19 14:39:20,641 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_DTNEBZRGEGGTCAAAAFVDMCM4IA] 
   1.175 +2019-04-19 14:39:20,641 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.176 +2019-04-19 14:39:20,641 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.177 +2019-04-19 14:39:20,641 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.178 +2019-04-19 14:39:20,641 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.179 +2019-04-19 14:39:20,642 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.180 +2019-04-19 14:39:20,642 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.181 +2019-04-19 14:39:20,642 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.182 +2019-04-19 14:39:20,642 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.183 +2019-04-19 14:39:20,642 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.184 +2019-04-19 14:39:20,642 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.185 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.186 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.187 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.188 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.189 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.190 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.191 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.192 +2019-04-19 14:39:20,643 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.193 +2019-04-19 14:39:20,644 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   1.194 +2019-04-19 14:39:20,644 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.195 +2019-04-19 14:39:20,644 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.196 +2019-04-19 14:39:20,644 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_P6LV7YETCUXHCAAAAFVDMCM4IM] 
   1.197 +2019-04-19 14:39:20,644 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.198 +2019-04-19 14:39:20,644 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.199 +2019-04-19 14:39:20,644 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.200 +2019-04-19 14:39:20,645 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.201 +2019-04-19 14:39:20,645 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.202 +2019-04-19 14:39:20,645 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.203 +2019-04-19 14:39:20,645 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.204 +2019-04-19 14:39:20,645 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.205 +2019-04-19 14:39:20,645 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.206 +2019-04-19 14:39:20,645 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.207 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.208 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.209 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.210 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.211 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.212 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.213 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.214 +2019-04-19 14:39:20,646 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.215 +2019-04-19 14:39:20,647 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   1.216 +2019-04-19 14:39:20,647 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.217 +2019-04-19 14:39:20,647 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.218 +2019-04-19 14:39:20,647 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_NO4I2O3KFBAPSAAAAFVDMCM4I4] 
   1.219 +2019-04-19 14:39:20,647 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.220 +2019-04-19 14:39:20,647 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.221 +2019-04-19 14:39:20,647 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.222 +2019-04-19 14:39:20,648 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.223 +2019-04-19 14:39:20,648 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.224 +2019-04-19 14:39:20,648 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.225 +2019-04-19 14:39:20,648 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.226 +2019-04-19 14:39:20,648 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.227 +2019-04-19 14:39:20,648 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.228 +2019-04-19 14:39:20,648 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.229 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.230 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.231 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.232 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.233 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.234 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.235 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.236 +2019-04-19 14:39:20,649 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.237 +2019-04-19 14:39:20,650 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   1.238 +2019-04-19 14:39:20,650 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.239 +2019-04-19 14:39:20,650 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.240 +2019-04-19 14:39:20,650 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_TVX4DG3OIW2K4AAAAFVDMCM4JI] 
   1.241 +2019-04-19 14:39:20,650 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.242 +2019-04-19 14:39:20,650 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.243 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.244 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.245 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.246 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.247 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.248 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.249 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.250 +2019-04-19 14:39:20,651 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.251 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.252 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.253 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.254 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.255 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.256 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.257 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.258 +2019-04-19 14:39:20,652 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.259 +2019-04-19 14:39:20,653 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   1.260 +2019-04-19 14:39:20,653 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.261 +2019-04-19 14:39:20,653 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.262 +2019-04-19 14:39:20,653 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_SGB6GSDWPKQCYAAAAFVDMCM4JU] 
   1.263 +2019-04-19 14:39:20,653 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.264 +2019-04-19 14:39:20,653 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.265 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.266 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.267 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.268 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.269 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.270 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.271 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.272 +2019-04-19 14:39:20,654 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.273 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.274 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.275 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.276 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.277 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.278 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.279 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.280 +2019-04-19 14:39:20,655 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.281 +2019-04-19 14:39:20,656 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   1.282 +2019-04-19 14:39:20,656 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.283 +2019-04-19 14:39:20,656 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.284 +2019-04-19 14:39:20,656 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_5AMRP2WPM4UUEAAAAFVDMCM4KA] 
   1.285 +2019-04-19 14:39:20,656 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.286 +2019-04-19 14:39:20,656 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.287 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.288 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.289 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.290 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.291 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.292 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.293 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.294 +2019-04-19 14:39:20,657 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.295 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.296 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.297 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.298 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.299 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.300 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.301 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.302 +2019-04-19 14:39:20,658 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.303 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity] JdbcColumnEntity [null][VARBINARY][0] 
   1.304 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   1.305 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  ident [null] 
   1.306 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [JdbcColumnEntity$EntityListener]  name  [XX_OQC65GDZ6EAKAAAAAFVDMCM4KI] 
   1.307 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] columns() for [2643][temp.XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.308 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.309 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.310 +2019-04-19 14:39:20,659 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.311 +2019-04-19 14:39:20,660 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.312 +2019-04-19 14:39:20,660 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.313 +2019-04-19 14:39:20,660 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.632Z] 
   1.314 +2019-04-19 14:39:20,660 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.315 +2019-04-19 14:39:20,660 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.316 +2019-04-19 14:39:20,660 DEBUG [FireThornTaskExecutor-12] [AdqlTableEntity] realize() [2643][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.317 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
   1.318 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcTable [XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.319 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scan for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.320 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scantest for [2642][XX_Q345NPYJSVNIUAAAAFVDMCM2OY] 
   1.321 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.322 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   1.323 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   1.324 +2019-04-19 14:39:20,661 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prevscan   [2019-04-19T14:39:20.629Z] 
   1.325 +2019-04-19 14:39:20,662 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] scanperiod [PT25H] 
   1.326 +2019-04-19 14:39:20,662 DEBUG [FireThornTaskExecutor-12] [BaseComponentEntity] prev scan is recent - skipping 
   1.327 +2019-04-19 14:39:20,692 DEBUG [FireThornTaskExecutor-12] [AdqlQueryTimings] AdqlQueryTimings() 
   1.328 +2019-04-19 14:39:20,696 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_GEOBEAS7O4YL4AAAAFVDMCM4GU] 
   1.329 +2019-04-19 14:39:20,697 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.330 +2019-04-19 14:39:20,697 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_GEOBEAS7O4YL4AAAAFVDMCM4GU] 
   1.331 +2019-04-19 14:39:20,697 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [VARBINARY] 
   1.332 +2019-04-19 14:39:20,697 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [0] 
   1.333 +2019-04-19 14:39:20,697 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [VARBINARY(MAX)] 
   1.334 +2019-04-19 14:39:20,697 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_EUKQ5PTXZLKLCAAAAFVDMCM4HI] 
   1.335 +2019-04-19 14:39:20,697 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.336 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_EUKQ5PTXZLKLCAAAAFVDMCM4HI] 
   1.337 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [CHAR] 
   1.338 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [10] 
   1.339 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [CHAR(10)] 
   1.340 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_EIT2PP64Z2FN4AAAAFVDMCM4HU] 
   1.341 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.342 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_EIT2PP64Z2FN4AAAAFVDMCM4HU] 
   1.343 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [CHAR] 
   1.344 +2019-04-19 14:39:20,698 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [16] 
   1.345 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [CHAR(16)] 
   1.346 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_DTNEBZRGEGGTCAAAAFVDMCM4IA] 
   1.347 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.348 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_DTNEBZRGEGGTCAAAAFVDMCM4IA] 
   1.349 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [CHAR] 
   1.350 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [256] 
   1.351 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [CHAR(256)] 
   1.352 +2019-04-19 14:39:20,699 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_P6LV7YETCUXHCAAAAFVDMCM4IM] 
   1.353 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.354 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_P6LV7YETCUXHCAAAAFVDMCM4IM] 
   1.355 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [FLOAT] 
   1.356 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [0] 
   1.357 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [FLOAT] 
   1.358 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_NO4I2O3KFBAPSAAAAFVDMCM4I4] 
   1.359 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.360 +2019-04-19 14:39:20,700 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_NO4I2O3KFBAPSAAAAFVDMCM4I4] 
   1.361 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [FLOAT] 
   1.362 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [0] 
   1.363 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [FLOAT] 
   1.364 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_TVX4DG3OIW2K4AAAAFVDMCM4JI] 
   1.365 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.366 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_TVX4DG3OIW2K4AAAAFVDMCM4JI] 
   1.367 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [FLOAT] 
   1.368 +2019-04-19 14:39:20,701 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [0] 
   1.369 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [FLOAT] 
   1.370 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_SGB6GSDWPKQCYAAAAFVDMCM4JU] 
   1.371 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.372 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_SGB6GSDWPKQCYAAAAFVDMCM4JU] 
   1.373 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [FLOAT] 
   1.374 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [0] 
   1.375 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [FLOAT] 
   1.376 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_5AMRP2WPM4UUEAAAAFVDMCM4KA] 
   1.377 +2019-04-19 14:39:20,702 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.378 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_5AMRP2WPM4UUEAAAAFVDMCM4KA] 
   1.379 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [FLOAT] 
   1.380 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [0] 
   1.381 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [FLOAT] 
   1.382 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] Create JdbcColumn [XX_OQC65GDZ6EAKAAAAAFVDMCM4KI] 
   1.383 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] sqltype() 
   1.384 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   name [XX_OQC65GDZ6EAKAAAAAFVDMCM4KI] 
   1.385 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   type [VARBINARY] 
   1.386 +2019-04-19 14:39:20,703 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   size [0] 
   1.387 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator]   temp [VARBINARY(MAX)] 
   1.388 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] SQL statement [CREATE TABLE [LIVEFirethornUserdataULOV20180719].[dbo].[XX_Q345NPYJSVNIUAAAAFVDMCM2OY] ([XX_GEOBEAS7O4YL4AAAAFVDMCM4GU] VARBINARY(MAX) , [XX_EUKQ5PTXZLKLCAAAAFVDMCM4HI] CHAR(10) , [XX_EIT2PP64Z2FN4AAAAFVDMCM4HU] CHAR(16) , [XX_DTNEBZRGEGGTCAAAAFVDMCM4IA] CHAR(256) , [XX_P6LV7YETCUXHCAAAAFVDMCM4IM] FLOAT , [XX_NO4I2O3KFBAPSAAAAFVDMCM4I4] FLOAT , [XX_TVX4DG3OIW2K4AAAAFVDMCM4JI] FLOAT , [XX_SGB6GSDWPKQCYAAAAFVDMCM4JU] FLOAT , [XX_5AMRP2WPM4UUEAAAAFVDMCM4KA] FLOAT , [XX_OQC65GDZ6EAKAAAAAFVDMCM4KI] VARBINARY(MAX) )] 
   1.389 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
   1.390 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] open [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
   1.391 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
   1.392 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   1.393 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
   1.394 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] initialValue() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   1.395 +2019-04-19 14:39:20,704 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
   1.396 +2019-04-19 14:39:20,705 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] connect [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   1.397 +2019-04-19 14:39:20,705 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] State is CLOSED, updating to READY 
   1.398 +2019-04-19 14:39:20,705 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] State is READY, initialising Connection 
   1.399 +2019-04-19 14:39:20,705 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] With user/pass 
   1.400 +2019-04-19 14:39:20,705 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] connecting .... 
   1.401 +2019-04-19 14:39:20,710 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] .... connected 
   1.402 +2019-04-19 14:39:20,715 DEBUG [FireThornTaskExecutor-12] [SQLServerOperator] SQL result [0] 
   1.403 +2019-04-19 14:39:20,716 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
   1.404 +2019-04-19 14:39:20,716 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] close [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
   1.405 +2019-04-19 14:39:20,716 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] operator() for [mssql] 
   1.406 +2019-04-19 14:39:20,716 DEBUG [FireThornTaskExecutor-12] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   1.407 +2019-04-19 14:39:20,716 INFO  [FireThornTaskExecutor-12] [AdqlQueryTimings] TIMING - jdbcdone() 
   1.408 +2019-04-19 14:39:20,720 DEBUG [FireThornTaskExecutor-12] [AdqlQueryTimings] AdqlQueryTimings() 
   1.409 +2019-04-19 14:39:20,726 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] before refresh() 
   1.410 +2019-04-19 14:39:20,733 DEBUG [FireThornTaskExecutor-11] [AdqlQueryTimings] AdqlQueryTimings() 
   1.411 +2019-04-19 14:39:20,733 DEBUG [FireThornTaskExecutor-11] [AdqlQueryTimings] AdqlQueryTimings() 
   1.412 +2019-04-19 14:39:20,734 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] after refresh() 
   1.413 +2019-04-19 14:39:20,735 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Getting base BaseResource 
   1.414 +2019-04-19 14:39:20,735 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Found base BaseResource [OSA JDBC] 
   1.415 +2019-04-19 14:39:20,735 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Getting direct resource 
   1.416 +2019-04-19 14:39:20,735 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] primary(JdbcResource) [53] 
   1.417 +2019-04-19 14:39:20,735 DEBUG [FireThornTaskExecutor-11] [OgsaServiceEntity] primary() 
   1.418 +2019-04-19 14:39:20,738 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] primary(OgsaService, JdbcResource) [3052][53] 
   1.419 +2019-04-19 14:39:20,741 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] Found primary OgsaJdbcResource [3102] 
   1.420 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] Checking ogsaid ... 
   1.421 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   1.422 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scan for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   1.423 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] scantest() 
   1.424 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   1.425 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3102] 
   1.426 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   1.427 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   1.428 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   1.429 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scantest for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   1.430 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity] factory() 
   1.431 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.432 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   1.433 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   1.434 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   1.435 +2019-04-19 14:39:20,742 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scanperiod [PT11M] 
   1.436 +2019-04-19 14:39:20,743 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prev scan is recent - skipping 
   1.437 +2019-04-19 14:39:20,743 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] Found ogsaid [ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48][ACTIVE] 
   1.438 +2019-04-19 14:39:20,743 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Using direct resource [XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   1.439 +2019-04-19 14:39:20,743 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Getting source OgsaService 
   1.440 +2019-04-19 14:39:20,743 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Found source OgsaService [http://jarmila:8080/ogsadai/services] 
   1.441 +2019-04-19 14:39:20,743 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Getting target table 
   1.442 +2019-04-19 14:39:20,746 DEBUG [FireThornTaskExecutor-11] [JdbcConnectionEntity] operator() for [mssql] 
   1.443 +2019-04-19 14:39:20,747 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Found target table [[LIVEFirethornUserdataULOV20180719].[dbo].[XX_Q345NPYJSVNIUAAAAFVDMCM2OY]] 
   1.444 +2019-04-19 14:39:20,747 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Getting target OgsaBaseResource 
   1.445 +2019-04-19 14:39:20,747 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] primary(JdbcResource) [52] 
   1.446 +2019-04-19 14:39:20,747 DEBUG [FireThornTaskExecutor-11] [OgsaServiceEntity] primary() 
   1.447 +2019-04-19 14:39:20,748 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] primary(OgsaService, JdbcResource) [3052][52] 
   1.448 +2019-04-19 14:39:20,750 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] Found primary OgsaJdbcResource [3103] 
   1.449 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] Checking ogsaid ... 
   1.450 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   1.451 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scan for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   1.452 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] scantest() 
   1.453 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   1.454 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3103] 
   1.455 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   1.456 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   1.457 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   1.458 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scantest for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   1.459 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity] factory() 
   1.460 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.461 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   1.462 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   1.463 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   1.464 +2019-04-19 14:39:20,751 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scanperiod [PT11M] 
   1.465 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prev scan is recent - skipping 
   1.466 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity$EntityFactory] Found ogsaid [ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d][ACTIVE] 
   1.467 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Found target OgsaBaseResource [XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   1.468 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Setting state to [RUNNING] [2954] 
   1.469 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] transition(TaskState) 
   1.470 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   ident [2954] 
   1.471 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [READY][RUNNING] 
   1.472 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] accept(TaskState) 
   1.473 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   ident [2954] 
   1.474 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [READY][RUNNING] 
   1.475 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Activating handler [2954] 
   1.476 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] handle() [] 
   1.477 +2019-04-19 14:39:20,752 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity$Handle] event() [2954]:[RUNNING]->[RUNNING]:[false]->[true] 
   1.478 +2019-04-19 14:39:20,753 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Creating workflow [2954] 
   1.479 +2019-04-19 14:39:20,753 DEBUG [FireThornTaskExecutor-11] [OgsaExecResourceEntity$EntityFactory] primary(OgsaService) [3052] 
   1.480 +2019-04-19 14:39:20,755 DEBUG [FireThornTaskExecutor-11] [OgsaExecResourceEntity$EntityFactory] No primary OgsaExecResource, creating a new one 
   1.481 +2019-04-19 14:39:20,755 DEBUG [FireThornTaskExecutor-11] [OgsaExecResourceEntity$EntityFactory] simple(OgsaService) [3052] 
   1.482 +2019-04-19 14:39:20,755 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] ogsaid [CREATED][DataRequestExecutionResource] 
   1.483 +2019-04-19 14:39:20,755 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scan for [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.484 +2019-04-19 14:39:20,755 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] scantest() 
   1.485 +2019-04-19 14:39:20,755 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.486 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3106] 
   1.487 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   1.488 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] prevscan   [null] 
   1.489 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   1.490 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scantest for [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.491 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [OgsaExecResourceEntity] factory() 
   1.492 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.493 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   1.494 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   1.495 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prevscan   [null] 
   1.496 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scanperiod [PT11M] 
   1.497 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prev scan is null - scanning 
   1.498 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Checking for existing lock [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.499 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] No existing lock found [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.500 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Adding new lock [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM][2019-04-19T14:39:20.756Z] 
   1.501 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Running scan [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.502 +2019-04-19 14:39:20,756 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] scanimpl() 
   1.503 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.504 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3106] 
   1.505 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   1.506 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] ping() 
   1.507 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.508 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3106] 
   1.509 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   1.510 +2019-04-19 14:39:20,757 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] Service request [3106][http://jarmila:8080/ogsadai/services/dataResources/DataRequestExecutionResource] 
   1.511 +2019-04-19 14:39:20,766 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] Service response [3106][null] 
   1.512 +2019-04-19 14:39:20,766 ERROR [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] Ping test failed [3106][DataRequestExecutionResource][404] 
   1.513 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] status(status) 
   1.514 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.515 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3106] 
   1.516 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   1.517 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   status [ERROR] 
   1.518 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Releasing locks [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM] 
   1.519 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Found existing lock [3106][XX_53BKMDT76VSM4AAAAFVDMCM4WM][2019-04-19T14:39:20.756Z] 
   1.520 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Removing .... 
   1.521 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Notifying .... 
   1.522 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   1.523 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scan for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   1.524 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] scantest() 
   1.525 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   1.526 +2019-04-19 14:39:20,767 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3102] 
   1.527 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   1.528 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   1.529 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   1.530 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scantest for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   1.531 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity] factory() 
   1.532 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.533 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   1.534 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   1.535 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   1.536 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scanperiod [PT11M] 
   1.537 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prev scan is recent - skipping 
   1.538 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   1.539 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scan for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   1.540 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] scantest() 
   1.541 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   name   [XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   1.542 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ident  [3103] 
   1.543 +2019-04-19 14:39:20,768 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity]   ogsaid [ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   1.544 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   1.545 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   1.546 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scantest for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   1.547 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [OgsaJdbcResourceEntity] factory() 
   1.548 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory] scanperiod() 
   1.549 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   1.550 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   1.551 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   1.552 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] scanperiod [PT11M] 
   1.553 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BaseComponentEntity] prev scan is recent - skipping 
   1.554 +2019-04-19 14:39:20,769 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Executing workflow [2954] 
   1.555 +2019-04-19 14:39:20,915 DEBUG [FireThornTaskExecutor-11] [OgsaContextClient] monkey(MonkeyParam) 
   1.556 +2019-04-19 14:39:21,021 DEBUG [FireThornTaskExecutor-11] [SimpleWorkflowResult] RequestExecutionStatus [uk.org.ogsadai.resource.request.status.COMPLETED_WITH_ERROR] 
   1.557 +2019-04-19 14:39:21,021 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] After workflow [2954] 
   1.558 +2019-04-19 14:39:21,021 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Before refresh [2954][RUNNING] 
   1.559 +2019-04-19 14:39:21,025 DEBUG [FireThornTaskExecutor-11] [AdqlQueryTimings] AdqlQueryTimings() 
   1.560 +2019-04-19 14:39:21,026 DEBUG [FireThornTaskExecutor-11] [AdqlQueryTimings] AdqlQueryTimings() 
   1.561 +2019-04-19 14:39:21,026 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] After refresh [2954][READY] 
   1.562 +2019-04-19 14:39:21,026 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Workflow result [2954][FAILED] 
   1.563 +2019-04-19 14:39:21,026 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] transition(TaskState) 
   1.564 +2019-04-19 14:39:21,026 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   ident [2954] 
   1.565 +2019-04-19 14:39:21,026 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [READY][FAILED] 
   1.566 +2019-04-19 14:39:21,027 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] accept(TaskState) 
   1.567 +2019-04-19 14:39:21,027 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   ident [2954] 
   1.568 +2019-04-19 14:39:21,027 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [READY][FAILED] 
   1.569 +2019-04-19 14:39:21,027 DEBUG [FireThornTaskExecutor-11] [BlueQueryEntity] Finishing execute() [2954][FAILED] 
   1.570 +2019-04-19 14:39:21,027 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity] After execute() 
   1.571 +2019-04-19 14:39:21,027 DEBUG [FireThornTaskExecutor-11] [BlueTaskEntity]   state [FAILED] 
   1.572 +2019-04-19 14:39:21,029 DEBUG [FireThornTaskExecutor-11] [AdqlQueryTimings] AdqlQueryTimings() 
   1.573 +2019-04-19 14:39:21,043 DEBUG [FireThornTaskExecutor-10] [BlueTaskEntity] Finished thread() 
   1.574 +2019-04-19 14:39:21,043 DEBUG [FireThornTaskExecutor-10] [BlueTaskEntity]   state [READY] 
   1.575 +2019-04-19 14:39:21,043 DEBUG [FireThornTaskExecutor-10] [BlueTaskEntity] Refreshing state 
   1.576 +2019-04-19 14:39:21,047 DEBUG [FireThornTaskExecutor-10] [AdqlQueryTimings] AdqlQueryTimings() 
   1.577 +2019-04-19 14:39:21,047 DEBUG [FireThornTaskExecutor-10] [AdqlQueryTimings] AdqlQueryTimings() 
   1.578 +2019-04-19 14:39:21,048 DEBUG [FireThornTaskExecutor-10] [BlueTaskEntity] Finished running() 
   1.579 +2019-04-19 14:39:21,049 DEBUG [FireThornTaskExecutor-10] [BlueTaskEntity]   state [FAILED] 
   1.580 +2019-04-19 14:39:21,049 DEBUG [main-interface-5] [BlueQueryEntity] Converting current instance [2954] 
   1.581 +2019-04-19 14:39:21,055 DEBUG [main-interface-5] [AdqlQueryTimings] AdqlQueryTimings() 
   1.582 +2019-04-19 14:39:21,055 DEBUG [main-interface-5] [AdqlQueryTimings] AdqlQueryTimings() 
   1.583 +2019-04-19 14:39:21,055 DEBUG [main-interface-5] [BlueTaskEntity] waitfor() [2954]:[FAILED]->[FAILED]->[COMPLETED]:[3000000] 
   1.584 +2019-04-19 14:39:21,057 DEBUG [main-interface-5] [BlueTaskEntity] handle() [] 
   1.585 +2019-04-19 14:39:21,057 DEBUG [main-interface-5] [BlueQueryEntity] update(Handle) [2954][FAILED][RUNNING] 
   1.586 +2019-04-19 14:39:21,057 DEBUG [main-interface-5] [BlueQueryEntity] transition() [2954][EMPTY][EMPTY][0] 
   1.587 +2019-04-19 14:39:21,057 DEBUG [main-interface-5] [BlueQueryEntity] No-op state change [EMPTY][EMPTY] 
   1.588 +
     2.1 --- /dev/null	Thu Jan 01 00:00:00 1970 +0000
     2.2 +++ b/doc/notes/stv/20190419-Debuging-Failing-Queries.txt	Fri Apr 19 21:24:27 2019 +0300
     2.3 @@ -0,0 +1,92 @@
     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 +
    2.27 +## Testing OGSA resources after a Non-Propagating Failed query (using ChaosMonkey)
    2.28 +
    2.29 +
    2.30 +## In Ogsadai Container :
    2.31 +bash-4.4$ curl http://localhost:8080/ogsadai/services/dataResources/
    2.32 +["firethorn-dqp-001","ogsadai-bfedaee6-da3e-483e-9ebf-75c04919100f","ogsadai-4ec571ee-61e0-4468-bb7f-d7daa875a64e"]
    2.33 +
    2.34 +
    2.35 +## In Metadata Database:
    2.36 +
    2.37 +## Check OGSA Resources
    2.38 +postgres=# select * from ft020116ogsajdbcresourceentity;
    2.39 + ident |         created         |        modified         |     uidhi     |        uidlo         |             name              | text |        scandate         | scanperiod | status  |                  
    2.40 +  ogsaid                    | ogstatus | owner | service | resource 
    2.41 +-------+-------------------------+-------------------------+---------------+----------------------+-------------------------------+------+-------------------------+------------+---------+------------------
    2.42 +----------------------------+----------+-------+---------+----------
    2.43 +  3102 | 2019-04-19 14:35:06.015 | 2019-04-19 14:35:06.016 | 1555684506015 | -5990492090341040022 | XX_VTOX6LWNN5QGUAAAAFVDMBNZT4 |      | 2019-04-19 17:04:07.293 |            | CREATED | ogsadai-ba7cd6f0-
    2.44 +d6a0-49c6-84ca-4f242f91ad48 | ERROR    |   166 |    3052 |       53
    2.45 +  3103 | 2019-04-19 14:35:06.032 | 2019-04-19 14:35:06.032 | 1555684506032 |  6631794971527698851 | XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA |      | 2019-04-19 17:04:07.331 |            | CREATED | ogsadai-a052f525-
    2.46 +6dea-413e-b5d1-ba8ad55a333d | ERROR    |   166 |    3052 |       52
    2.47 +  4852 | 2019-04-19 17:04:07.294 | 2019-04-19 17:04:07.295 | 1555693447294 | -8115330116846123003 | XX_R5QI4QLOLOEAKAAAAFVDNDRIPY |      | 2019-04-19 17:19:52.442 |            | CREATED | ogsadai-b30f4e08-
    2.48 +2244-4630-9c31-ce10b108d7ec | ERROR    |  4456 |    3052 |       53
    2.49 +  4853 | 2019-04-19 17:04:07.333 | 2019-04-19 17:04:07.333 | 1555693447333 | -1222187757109834120 | XX_54E6VNOYUMHHQAAAAFVDNDRIUU |      | 2019-04-19 17:19:52.5   |            | CREATED | ogsadai-61974082-
    2.50 +6fae-422a-aef4-9b4a79adb1d9 | ERROR    |  4456 |    3052 |       52
    2.51 +  5352 | 2019-04-19 17:19:52.443 | 2019-04-19 17:19:52.455 | 1555694392443 |  8517361695587168083 | XX_OYZ36VOQ7XXVGAAAAFVDNHEUPM |      | 2019-04-19 17:48:32.404 |            | CREATED | ogsadai-5d1ade1d-
    2.52 +6d4f-42ff-a82b-f659525cf1e5 | ERROR    |  4957 |    3052 |       53
    2.53 +  5353 | 2019-04-19 17:19:52.5   | 2019-04-19 17:19:52.501 | 1555694392500 | -8826415763085932194 | XX_QWBELIFZLLEV4AAAAFVDNHEUWQ |      | 2019-04-19 17:48:32.437 |            | CREATED | ogsadai-d56022fd-
    2.54 +138f-41b0-b6ff-bbf225f3f2c0 | ERROR    |  4957 |    3052 |       52
    2.55 +  6002 | 2019-04-19 17:48:32.405 | 2019-04-19 17:48:32.407 | 1555696112405 | -8539280855216382307 | XX_RF7GCTRDRCPJ2AAAAFVDNNWTCU |      | 2019-04-19 18:04:52.248 |            | CREATED | ogsadai-28eeb504-
    2.56 +1068-4602-892a-1c780c0e11b9 | ERROR    |  5606 |    3052 |       53
    2.57 +  6552 | 2019-04-19 18:04:52.248 | 2019-04-19 18:04:52.25  | 1555697092248 | -8666973590146405320 | XX_Q64LS4DZUGWDQAAAAFVDNROGTA |      | 2019-04-19 18:04:53.541 |            | CREATED | ogsadai-4ec571ee-
    2.58 +61e0-4468-bb7f-d7daa875a64e | ACTIVE   |  6156 |    3052 |       53
    2.59 +  6003 | 2019-04-19 17:48:32.437 | 2019-04-19 17:48:32.438 | 1555696112437 | -3815049966156708500 | XX_ZMHDQRGO3UCWYAAAAFVDNNWTGU |      | 2019-04-19 18:04:52.275 |            | CREATED | ogsadai-a4f97a02-
    2.60 +5da3-486c-b972-65c51b574a91 | ERROR    |  5606 |    3052 |       52
    2.61 +  6553 | 2019-04-19 18:04:52.276 | 2019-04-19 18:04:52.276 | 1555697092276 |  5598837196533693748 | XX_JWZRBRBOUJ6TIAAAAFVDNROGWQ |      | 2019-04-19 18:04:53.692 |            | CREATED | ogsadai-bfedaee6-
    2.62 +da3e-483e-9ebf-75c04919100f | ACTIVE   |  6156 |    3052 |       52
    2.63 +(10 rows)
    2.64 +
    2.65 +
    2.66 +
    2.67 +postgres=# select ident,created,status,ogsaid, ogstatus,resource from ft020116ogsajdbcresourceentity;
    2.68 + ident |         created         | status  |                    ogsaid                    | ogstatus | resource 
    2.69 +-------+-------------------------+---------+----------------------------------------------+----------+----------
    2.70 +  3102 | 2019-04-19 14:35:06.015 | CREATED | ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48 | ERROR    |       53
    2.71 +  3103 | 2019-04-19 14:35:06.032 | CREATED | ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d | ERROR    |       52
    2.72 +  4852 | 2019-04-19 17:04:07.294 | CREATED | ogsadai-b30f4e08-2244-4630-9c31-ce10b108d7ec | ERROR    |       53
    2.73 +  4853 | 2019-04-19 17:04:07.333 | CREATED | ogsadai-61974082-6fae-422a-aef4-9b4a79adb1d9 | ERROR    |       52
    2.74 +  5352 | 2019-04-19 17:19:52.443 | CREATED | ogsadai-5d1ade1d-6d4f-42ff-a82b-f659525cf1e5 | ERROR    |       53
    2.75 +  5353 | 2019-04-19 17:19:52.5   | CREATED | ogsadai-d56022fd-138f-41b0-b6ff-bbf225f3f2c0 | ERROR    |       52
    2.76 +  6002 | 2019-04-19 17:48:32.405 | CREATED | ogsadai-28eeb504-1068-4602-892a-1c780c0e11b9 | ERROR    |       53
    2.77 +  6552 | 2019-04-19 18:04:52.248 | CREATED | ogsadai-4ec571ee-61e0-4468-bb7f-d7daa875a64e | ACTIVE   |       53
    2.78 +  6003 | 2019-04-19 17:48:32.437 | CREATED | ogsadai-a4f97a02-5da3-486c-b972-65c51b574a91 | ERROR    |       52
    2.79 +  6553 | 2019-04-19 18:04:52.276 | CREATED | ogsadai-bfedaee6-da3e-483e-9ebf-75c04919100f | ACTIVE   |       52
    2.80 +(10 rows)
    2.81 +
    2.82 +
    2.83 +
    2.84 +postgres=# select * from ft020116ogsaserviceentity;
    2.85 + ident |         created         |        modified         |     uidhi     |        uidlo        |                 name                 | text | scandate | scanperiod | status  |               endpoint    
    2.86 +           | http | ogstatus | version | owner 
    2.87 +-------+-------------------------+-------------------------+---------------+---------------------+--------------------------------------+------+----------+------------+---------+---------------------------
    2.88 +-----------+------+----------+---------+-------
    2.89 +  3052 | 2019-04-19 14:35:06.003 | 2019-04-19 14:35:06.006 | 1555684506003 | -257637931932058849 | http://jarmila:8080/ogsadai/services |      |          |            | CREATED | http://jarmila:8080/ogsada
    2.90 +i/services |      | ACTIVE   |         |   166
    2.91 +(1 row)
    2.92 +
    2.93 +
    2.94 +## Testing OGSA resources after a Correctly Propagating Failed query (using ChaosMonkey) shows the same results
    2.95 +
     3.1 --- /dev/null	Thu Jan 01 00:00:00 1970 +0000
     3.2 +++ b/doc/notes/stv/20190419-FAILED-Query.txt	Fri Apr 19 21:24:27 2019 +0300
     3.3 @@ -0,0 +1,630 @@
     3.4 +].[dbo].[Filter].[name] AS "name",[ATLASDR1].[dbo].[Filter].[description] AS "description",[ATLASDR1].[dbo].[Filter].[cutOn] AS "cutOn",[ATLASDR1].[dbo].[Filter].[cutOff] AS "cutOff",[ATLASDR1].[dbo].[Filter].[aebv] AS "aebv",[ATLASDR1].[dbo].[Filter].[vegaToAB] AS "vegaToAB",[ATLASDR1].[dbo].[Filter].[oneSecMLVg] AS "oneSecMLVg",[ATLASDR1].[dbo].[Filter].[isSectioned] AS "isSectioned"
     3.5 +FROM [ATLASDR1].[dbo].[Filter] 
     3.6 +2019-04-19 14:36:30,223 DEBUG [FireThornTaskExecutor-7] [SQLServerTranslator] -------- 
     3.7 +2019-04-19 14:36:30,223 INFO  [FireThornTaskExecutor-7] [AdqlQueryTimings] TIMING - adqldone() 
     3.8 +2019-04-19 14:36:30,223 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] transition(TaskState) 
     3.9 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   ident [2953] 
    3.10 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [READY][READY] 
    3.11 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] No-op status change [READY] 
    3.12 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] After prepare() 
    3.13 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [READY] 
    3.14 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] Before execute() 
    3.15 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [READY] 
    3.16 +2019-04-19 14:36:30,224 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] execute() [2953][READY] 
    3.17 +2019-04-19 14:36:30,225 DEBUG [FireThornTaskExecutor-7] [BlueTaskLogEntity] LogEntryEntity() 
    3.18 +2019-04-19 14:36:30,225 DEBUG [FireThornTaskExecutor-7] [BlueTaskLogEntity]   task    [entity[class[uk.ac.roe.wfau.firethorn.adql.query.blue.BlueQueryEntity] ident[2953]]] 
    3.19 +2019-04-19 14:36:30,225 DEBUG [FireThornTaskExecutor-7] [BlueTaskLogEntity]   level   [INFO] 
    3.20 +2019-04-19 14:36:30,225 DEBUG [FireThornTaskExecutor-7] [BlueTaskLogEntity]   source  [uk.ac.roe.wfau.firethorn.adql.query.blue.BlueTaskLogEntity$EntityFactory] 
    3.21 +2019-04-19 14:36:30,225 DEBUG [FireThornTaskExecutor-7] [BlueTaskLogEntity]   message [Executing query] 
    3.22 +2019-04-19 14:36:30,245 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity$TaskRunner] thread(Updator) [2953] 
    3.23 +2019-04-19 14:36:30,247 DEBUG [FireThornTaskExecutor-8] [BlueTaskEntity$TaskRunner] future(Updator) [2953] 
    3.24 +2019-04-19 14:36:30,247 DEBUG [FireThornTaskExecutor-8] [BlueQueryEntity] Converting current instance [2953] 
    3.25 +2019-04-19 14:36:30,254 DEBUG [FireThornTaskExecutor-8] [AdqlQueryTimings] AdqlQueryTimings() 
    3.26 +2019-04-19 14:36:30,254 DEBUG [FireThornTaskExecutor-8] [AdqlQueryTimings] AdqlQueryTimings() 
    3.27 +2019-04-19 14:36:30,255 DEBUG [FireThornTaskExecutor-8] [BlueQueryEntity] build() 
    3.28 +2019-04-19 14:36:30,255 INFO  [FireThornTaskExecutor-8] [AdqlQueryTimings] TIMING - jdbcstart() 
    3.29 +2019-04-19 14:36:30,257 DEBUG [FireThornTaskExecutor-8] [IdentityEntity] jdbcschema() 
    3.30 +2019-04-19 14:36:30,259 DEBUG [FireThornTaskExecutor-8] [CommunityEntity] space(boolean) [true] 
    3.31 +2019-04-19 14:36:30,260 DEBUG [FireThornTaskExecutor-8] [JdbcResourceEntity] schemas() for [52][Userdata resource] 
    3.32 +2019-04-19 14:36:30,261 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [52][Userdata resource] 
    3.33 +2019-04-19 14:36:30,261 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [52][Userdata resource] 
    3.34 +2019-04-19 14:36:30,261 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
    3.35 +2019-04-19 14:36:30,261 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
    3.36 +2019-04-19 14:36:30,261 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
    3.37 +2019-04-19 14:36:30,262 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:35:05.686Z] 
    3.38 +2019-04-19 14:36:30,262 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
    3.39 +2019-04-19 14:36:30,262 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
    3.40 +2019-04-19 14:36:30,262 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity] JdbcSchema select(JdbcResource, String, String) 
    3.41 +2019-04-19 14:36:30,262 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity]   Parent  [52] 
    3.42 +2019-04-19 14:36:30,263 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity]   Catalog [LIVEFirethornUserdataULOV20180719] 
    3.43 +2019-04-19 14:36:30,263 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity]   Schema  [dbo] 
    3.44 +2019-04-19 14:36:30,263 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity] JdbcSchema search(JdbcResource, String, String) 
    3.45 +2019-04-19 14:36:30,263 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity]   Parent  [52] 
    3.46 +2019-04-19 14:36:30,263 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity]   Catalog [LIVEFirethornUserdataULOV20180719] 
    3.47 +2019-04-19 14:36:30,264 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity]   Schema  [dbo] 
    3.48 +2019-04-19 14:36:30,268 DEBUG [FireThornTaskExecutor-8] [IdentityEntity] adqlschema() 
    3.49 +2019-04-19 14:36:30,269 DEBUG [FireThornTaskExecutor-8] [AdqlResourceEntity] schemas() for [59][user space] 
    3.50 +2019-04-19 14:36:30,269 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [59][user space] 
    3.51 +2019-04-19 14:36:30,269 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [59][user space] 
    3.52 +2019-04-19 14:36:30,269 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
    3.53 +2019-04-19 14:36:30,269 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
    3.54 +2019-04-19 14:36:30,270 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
    3.55 +2019-04-19 14:36:30,270 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [null] 
    3.56 +2019-04-19 14:36:30,270 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
    3.57 +2019-04-19 14:36:30,270 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is null - scanning 
    3.58 +2019-04-19 14:36:30,270 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Checking for existing lock [59][user space] 
    3.59 +2019-04-19 14:36:30,270 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] No existing lock found [59][user space] 
    3.60 +2019-04-19 14:36:30,271 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Adding new lock [59][user space][2019-04-19T14:36:30.271Z] 
    3.61 +2019-04-19 14:36:30,271 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Running scan [59][user space] 
    3.62 +2019-04-19 14:36:30,271 DEBUG [FireThornTaskExecutor-8] [AdqlResourceEntity] scanimpl() for [59][user space] 
    3.63 +2019-04-19 14:36:30,271 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Releasing locks [59][user space] 
    3.64 +2019-04-19 14:36:30,271 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Found existing lock [59][user space][2019-04-19T14:36:30.271Z] 
    3.65 +2019-04-19 14:36:30,272 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Removing .... 
    3.66 +2019-04-19 14:36:30,272 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Notifying .... 
    3.67 +2019-04-19 14:36:30,273 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity] tables() for [442][LIVEFirethornUserdataULOV20180719.dbo] 
    3.68 +2019-04-19 14:36:30,273 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [442][LIVEFirethornUserdataULOV20180719.dbo] 
    3.69 +2019-04-19 14:36:30,273 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [442][LIVEFirethornUserdataULOV20180719.dbo] 
    3.70 +2019-04-19 14:36:30,273 DEBUG [FireThornTaskExecutor-8] [JdbcSchemaEntity] factory() 
    3.71 +2019-04-19 14:36:30,273 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
    3.72 +2019-04-19 14:36:30,274 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
    3.73 +2019-04-19 14:36:30,274 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
    3.74 +2019-04-19 14:36:30,274 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:35:05.764Z] 
    3.75 +2019-04-19 14:36:30,274 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
    3.76 +2019-04-19 14:36:30,274 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
    3.77 +2019-04-19 14:36:30,275 DEBUG [FireThornTaskExecutor-8] [JdbcTableEntity] JdbcTableEntity [LIVEFirethornUserdataULOV20180719.dbo][XX_6N55BZC2OMMASAAAAFVDMBYCYM][2019-04-19T14:36:30.275Z] 
    3.78 +2019-04-19 14:36:30,275 DEBUG [FireThornTaskExecutor-8] [AdqlSchemaEntity] tables() for [445][temp] 
    3.79 +2019-04-19 14:36:30,275 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [445][temp] 
    3.80 +2019-04-19 14:36:30,276 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [445][temp] 
    3.81 +2019-04-19 14:36:30,276 DEBUG [FireThornTaskExecutor-8] [AdqlSchemaEntity] factory() 
    3.82 +2019-04-19 14:36:30,276 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
    3.83 +2019-04-19 14:36:30,276 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
    3.84 +2019-04-19 14:36:30,276 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
    3.85 +2019-04-19 14:36:30,277 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [null] 
    3.86 +2019-04-19 14:36:30,277 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
    3.87 +2019-04-19 14:36:30,277 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is null - scanning 
    3.88 +2019-04-19 14:36:30,277 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Checking for existing lock [445][temp] 
    3.89 +2019-04-19 14:36:30,277 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] No existing lock found [445][temp] 
    3.90 +2019-04-19 14:36:30,277 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Adding new lock [445][temp][2019-04-19T14:36:30.277Z] 
    3.91 +2019-04-19 14:36:30,278 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Running scan [445][temp] 
    3.92 +2019-04-19 14:36:30,278 DEBUG [FireThornTaskExecutor-8] [AdqlSchemaEntity] scanimpl() for [445][temp] 
    3.93 +2019-04-19 14:36:30,278 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Releasing locks [445][temp] 
    3.94 +2019-04-19 14:36:30,278 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Found existing lock [445][temp][2019-04-19T14:36:30.277Z] 
    3.95 +2019-04-19 14:36:30,278 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Removing .... 
    3.96 +2019-04-19 14:36:30,279 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Notifying .... 
    3.97 +2019-04-19 14:36:30,279 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
    3.98 +2019-04-19 14:36:30,279 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
    3.99 +2019-04-19 14:36:30,280 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.100 +2019-04-19 14:36:30,280 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.101 +2019-04-19 14:36:30,280 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.102 +2019-04-19 14:36:30,280 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.103 +2019-04-19 14:36:30,280 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [null] 
   3.104 +2019-04-19 14:36:30,280 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.105 +2019-04-19 14:36:30,281 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is null - scanning 
   3.106 +2019-04-19 14:36:30,281 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Checking for existing lock [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.107 +2019-04-19 14:36:30,281 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] No existing lock found [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.108 +2019-04-19 14:36:30,281 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Adding new lock [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM][2019-04-19T14:36:30.281Z] 
   3.109 +2019-04-19 14:36:30,281 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Running scan [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.110 +2019-04-19 14:36:30,282 DEBUG [FireThornTaskExecutor-8] [JdbcTableEntity] scanimpl() for [2640][LIVEFirethornUserdataULOV20180719.dbo.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.111 +2019-04-19 14:36:30,282 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] scanner() for [mssql] 
   3.112 +2019-04-19 14:36:30,284 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.113 +2019-04-19 14:36:30,284 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] open [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
   3.114 +2019-04-19 14:36:30,285 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.115 +2019-04-19 14:36:30,285 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.116 +2019-04-19 14:36:30,285 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.117 +2019-04-19 14:36:30,285 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] initialValue() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.118 +2019-04-19 14:36:30,285 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.119 +2019-04-19 14:36:30,285 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] connect [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.120 +2019-04-19 14:36:30,285 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] Source is null, updating to EMPTY 
   3.121 +2019-04-19 14:36:30,286 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] State is EMPTY, initialising DataSource 
   3.122 +2019-04-19 14:36:30,286 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.123 +2019-04-19 14:36:30,286 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.124 +2019-04-19 14:36:30,286 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] State is READY, initialising Connection 
   3.125 +2019-04-19 14:36:30,286 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] With user/pass 
   3.126 +2019-04-19 14:36:30,286 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] connecting .... 
   3.127 +2019-04-19 14:36:30,292 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] .... connected 
   3.128 +2019-04-19 14:36:30,337 DEBUG [FireThornTaskExecutor-8] [SQLServerScanner] Including schema [dbo] 
   3.129 +2019-04-19 14:36:30,340 DEBUG [FireThornTaskExecutor-8] [JdbcTableEntity] scanning table [null] 
   3.130 +2019-04-19 14:36:30,340 DEBUG [FireThornTaskExecutor-8] [JdbcTableEntity] Null table, skipping scan 
   3.131 +2019-04-19 14:36:30,340 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.132 +2019-04-19 14:36:30,341 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] close [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
   3.133 +2019-04-19 14:36:30,341 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.134 +2019-04-19 14:36:30,342 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.135 +2019-04-19 14:36:30,342 DEBUG [FireThornTaskExecutor-8] [JdbcTableEntity] columns() scan done for [2640][LIVEFirethornUserdataULOV20180719.dbo.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.136 +2019-04-19 14:36:30,343 DEBUG [FireThornTaskExecutor-8] [JdbcTableEntity] Matching columns [0] 
   3.137 +2019-04-19 14:36:30,343 DEBUG [FireThornTaskExecutor-8] [JdbcTableEntity] Listed but not matched [0] 
   3.138 +2019-04-19 14:36:30,344 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Releasing locks [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.139 +2019-04-19 14:36:30,344 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Found existing lock [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM][2019-04-19T14:36:30.281Z] 
   3.140 +2019-04-19 14:36:30,344 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Removing .... 
   3.141 +2019-04-19 14:36:30,344 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Notifying .... 
   3.142 +2019-04-19 14:36:30,345 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][VARBINARY][0] 
   3.143 +2019-04-19 14:36:30,345 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.144 +2019-04-19 14:36:30,345 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.145 +2019-04-19 14:36:30,346 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_O7YNCMMEC2XCKAAAAFVDMBYDBE] 
   3.146 +2019-04-19 14:36:30,346 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.147 +2019-04-19 14:36:30,347 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.148 +2019-04-19 14:36:30,347 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.149 +2019-04-19 14:36:30,347 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.150 +2019-04-19 14:36:30,347 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.151 +2019-04-19 14:36:30,347 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.152 +2019-04-19 14:36:30,348 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [null] 
   3.153 +2019-04-19 14:36:30,348 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.154 +2019-04-19 14:36:30,348 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is null - scanning 
   3.155 +2019-04-19 14:36:30,349 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Checking for existing lock [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.156 +2019-04-19 14:36:30,349 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] No existing lock found [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.157 +2019-04-19 14:36:30,349 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Adding new lock [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM][2019-04-19T14:36:30.349Z] 
   3.158 +2019-04-19 14:36:30,350 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Running scan [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.159 +2019-04-19 14:36:30,350 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Releasing locks [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.160 +2019-04-19 14:36:30,350 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Found existing lock [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM][2019-04-19T14:36:30.349Z] 
   3.161 +2019-04-19 14:36:30,351 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Removing .... 
   3.162 +2019-04-19 14:36:30,351 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Notifying .... 
   3.163 +2019-04-19 14:36:30,351 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.164 +2019-04-19 14:36:30,352 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.165 +2019-04-19 14:36:30,352 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.166 +2019-04-19 14:36:30,352 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.167 +2019-04-19 14:36:30,352 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.168 +2019-04-19 14:36:30,353 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.169 +2019-04-19 14:36:30,353 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.170 +2019-04-19 14:36:30,353 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.171 +2019-04-19 14:36:30,353 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.172 +2019-04-19 14:36:30,354 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][CHAR][10] 
   3.173 +2019-04-19 14:36:30,354 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.174 +2019-04-19 14:36:30,355 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.175 +2019-04-19 14:36:30,355 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_YBJJBHEUHB7Z6AAAAFVDMBYDCI] 
   3.176 +2019-04-19 14:36:30,355 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.177 +2019-04-19 14:36:30,356 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.178 +2019-04-19 14:36:30,356 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.179 +2019-04-19 14:36:30,356 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.180 +2019-04-19 14:36:30,356 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.181 +2019-04-19 14:36:30,357 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.182 +2019-04-19 14:36:30,357 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.183 +2019-04-19 14:36:30,357 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.184 +2019-04-19 14:36:30,357 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.185 +2019-04-19 14:36:30,358 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.186 +2019-04-19 14:36:30,358 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.187 +2019-04-19 14:36:30,359 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.188 +2019-04-19 14:36:30,359 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.189 +2019-04-19 14:36:30,359 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.190 +2019-04-19 14:36:30,359 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.191 +2019-04-19 14:36:30,360 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.192 +2019-04-19 14:36:30,360 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.193 +2019-04-19 14:36:30,360 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.194 +2019-04-19 14:36:30,361 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][CHAR][16] 
   3.195 +2019-04-19 14:36:30,361 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.196 +2019-04-19 14:36:30,362 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.197 +2019-04-19 14:36:30,362 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_NGFMLS4PLOBGEAAAAFVDMBYDDE] 
   3.198 +2019-04-19 14:36:30,362 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.199 +2019-04-19 14:36:30,363 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.200 +2019-04-19 14:36:30,363 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.201 +2019-04-19 14:36:30,363 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.202 +2019-04-19 14:36:30,364 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.203 +2019-04-19 14:36:30,364 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.204 +2019-04-19 14:36:30,365 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.205 +2019-04-19 14:36:30,365 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.206 +2019-04-19 14:36:30,365 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.207 +2019-04-19 14:36:30,365 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.208 +2019-04-19 14:36:30,366 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.209 +2019-04-19 14:36:30,366 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.210 +2019-04-19 14:36:30,366 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.211 +2019-04-19 14:36:30,367 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.212 +2019-04-19 14:36:30,367 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.213 +2019-04-19 14:36:30,367 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.214 +2019-04-19 14:36:30,368 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.215 +2019-04-19 14:36:30,368 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.216 +2019-04-19 14:36:30,369 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][CHAR][256] 
   3.217 +2019-04-19 14:36:30,369 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.218 +2019-04-19 14:36:30,369 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.219 +2019-04-19 14:36:30,370 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_BEGWXWVRBVBVSAAAAFVDMBYDEE] 
   3.220 +2019-04-19 14:36:30,370 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.221 +2019-04-19 14:36:30,371 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.222 +2019-04-19 14:36:30,371 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.223 +2019-04-19 14:36:30,371 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.224 +2019-04-19 14:36:30,372 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.225 +2019-04-19 14:36:30,372 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.226 +2019-04-19 14:36:30,372 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.227 +2019-04-19 14:36:30,373 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.228 +2019-04-19 14:36:30,373 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.229 +2019-04-19 14:36:30,373 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.230 +2019-04-19 14:36:30,374 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.231 +2019-04-19 14:36:30,374 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.232 +2019-04-19 14:36:30,375 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.233 +2019-04-19 14:36:30,375 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.234 +2019-04-19 14:36:30,375 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.235 +2019-04-19 14:36:30,375 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.236 +2019-04-19 14:36:30,376 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.237 +2019-04-19 14:36:30,376 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.238 +2019-04-19 14:36:30,377 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   3.239 +2019-04-19 14:36:30,377 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.240 +2019-04-19 14:36:30,377 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.241 +2019-04-19 14:36:30,378 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_SKPS2XRFG4HSAAAAAFVDMBYDFE] 
   3.242 +2019-04-19 14:36:30,378 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.243 +2019-04-19 14:36:30,378 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.244 +2019-04-19 14:36:30,379 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.245 +2019-04-19 14:36:30,379 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.246 +2019-04-19 14:36:30,379 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.247 +2019-04-19 14:36:30,379 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.248 +2019-04-19 14:36:30,380 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.249 +2019-04-19 14:36:30,380 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.250 +2019-04-19 14:36:30,380 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.251 +2019-04-19 14:36:30,380 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.252 +2019-04-19 14:36:30,381 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.253 +2019-04-19 14:36:30,381 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.254 +2019-04-19 14:36:30,382 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.255 +2019-04-19 14:36:30,382 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.256 +2019-04-19 14:36:30,382 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.257 +2019-04-19 14:36:30,382 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.258 +2019-04-19 14:36:30,382 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.259 +2019-04-19 14:36:30,383 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.260 +2019-04-19 14:36:30,383 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   3.261 +2019-04-19 14:36:30,384 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.262 +2019-04-19 14:36:30,384 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.263 +2019-04-19 14:36:30,384 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_7TUPXJI7RRY72AAAAFVDMBYDF4] 
   3.264 +2019-04-19 14:36:30,385 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.265 +2019-04-19 14:36:30,385 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.266 +2019-04-19 14:36:30,385 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.267 +2019-04-19 14:36:30,385 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.268 +2019-04-19 14:36:30,386 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.269 +2019-04-19 14:36:30,386 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.270 +2019-04-19 14:36:30,386 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.271 +2019-04-19 14:36:30,386 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.272 +2019-04-19 14:36:30,387 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.273 +2019-04-19 14:36:30,387 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.274 +2019-04-19 14:36:30,388 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.275 +2019-04-19 14:36:30,388 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.276 +2019-04-19 14:36:30,388 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.277 +2019-04-19 14:36:30,388 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.278 +2019-04-19 14:36:30,388 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.279 +2019-04-19 14:36:30,389 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.280 +2019-04-19 14:36:30,389 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.281 +2019-04-19 14:36:30,389 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.282 +2019-04-19 14:36:30,390 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   3.283 +2019-04-19 14:36:30,390 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.284 +2019-04-19 14:36:30,391 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.285 +2019-04-19 14:36:30,391 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_SALVMQGVJVBRCAAAAFVDMBYDGY] 
   3.286 +2019-04-19 14:36:30,392 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.287 +2019-04-19 14:36:30,392 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.288 +2019-04-19 14:36:30,392 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.289 +2019-04-19 14:36:30,393 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.290 +2019-04-19 14:36:30,393 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.291 +2019-04-19 14:36:30,393 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.292 +2019-04-19 14:36:30,394 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.293 +2019-04-19 14:36:30,394 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.294 +2019-04-19 14:36:30,394 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.295 +2019-04-19 14:36:30,394 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.296 +2019-04-19 14:36:30,395 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.297 +2019-04-19 14:36:30,395 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.298 +2019-04-19 14:36:30,395 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.299 +2019-04-19 14:36:30,396 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.300 +2019-04-19 14:36:30,396 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.301 +2019-04-19 14:36:30,396 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.302 +2019-04-19 14:36:30,397 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.303 +2019-04-19 14:36:30,397 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.304 +2019-04-19 14:36:30,398 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   3.305 +2019-04-19 14:36:30,398 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.306 +2019-04-19 14:36:30,398 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.307 +2019-04-19 14:36:30,399 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_4CUANRZOICXMUAAAAFVDMBYDHY] 
   3.308 +2019-04-19 14:36:30,400 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.309 +2019-04-19 14:36:30,400 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.310 +2019-04-19 14:36:30,401 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.311 +2019-04-19 14:36:30,401 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.312 +2019-04-19 14:36:30,401 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.313 +2019-04-19 14:36:30,401 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.314 +2019-04-19 14:36:30,402 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.315 +2019-04-19 14:36:30,402 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.316 +2019-04-19 14:36:30,403 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.317 +2019-04-19 14:36:30,403 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.318 +2019-04-19 14:36:30,404 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.319 +2019-04-19 14:36:30,404 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.320 +2019-04-19 14:36:30,404 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.321 +2019-04-19 14:36:30,404 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.322 +2019-04-19 14:36:30,405 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.323 +2019-04-19 14:36:30,405 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.324 +2019-04-19 14:36:30,405 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.325 +2019-04-19 14:36:30,405 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.326 +2019-04-19 14:36:30,406 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][FLOAT][0] 
   3.327 +2019-04-19 14:36:30,406 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.328 +2019-04-19 14:36:30,407 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.329 +2019-04-19 14:36:30,407 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_GFYVJU3GGH2JWAAAAFVDMBYDIY] 
   3.330 +2019-04-19 14:36:30,407 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.331 +2019-04-19 14:36:30,408 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.332 +2019-04-19 14:36:30,408 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.333 +2019-04-19 14:36:30,409 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.334 +2019-04-19 14:36:30,409 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.335 +2019-04-19 14:36:30,409 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.336 +2019-04-19 14:36:30,409 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.337 +2019-04-19 14:36:30,410 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.338 +2019-04-19 14:36:30,410 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.339 +2019-04-19 14:36:30,410 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.340 +2019-04-19 14:36:30,411 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.341 +2019-04-19 14:36:30,411 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.342 +2019-04-19 14:36:30,411 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.343 +2019-04-19 14:36:30,411 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.344 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.345 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.346 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.347 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.348 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity] JdbcColumnEntity [null][VARBINARY][0] 
   3.349 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener] save(JdbcColumnEntity) 
   3.350 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  ident [null] 
   3.351 +2019-04-19 14:36:30,412 DEBUG [FireThornTaskExecutor-8] [JdbcColumnEntity$EntityListener]  name  [XX_N4M7MT2XR3F66AAAAFVDMBYDJQ] 
   3.352 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] columns() for [2641][temp.XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.353 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.354 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.355 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.356 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.357 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.358 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.350Z] 
   3.359 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.360 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.361 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [AdqlTableEntity] realize() [2641][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.362 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.363 +2019-04-19 14:36:30,413 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcTable [XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.364 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scan for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.365 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scantest for [2640][XX_6N55BZC2OMMASAAAAFVDMBYCYM] 
   3.366 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.367 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity$EntityFactory]   value [PT25H] 
   3.368 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] Factory scanperiod  [PT25H] 
   3.369 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prevscan   [2019-04-19T14:36:30.343Z] 
   3.370 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] scanperiod [PT25H] 
   3.371 +2019-04-19 14:36:30,414 DEBUG [FireThornTaskExecutor-8] [BaseComponentEntity] prev scan is recent - skipping 
   3.372 +2019-04-19 14:36:30,444 DEBUG [FireThornTaskExecutor-8] [AdqlQueryTimings] AdqlQueryTimings() 
   3.373 +2019-04-19 14:36:30,452 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_O7YNCMMEC2XCKAAAAFVDMBYDBE] 
   3.374 +2019-04-19 14:36:30,452 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.375 +2019-04-19 14:36:30,452 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_O7YNCMMEC2XCKAAAAFVDMBYDBE] 
   3.376 +2019-04-19 14:36:30,452 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [VARBINARY] 
   3.377 +2019-04-19 14:36:30,453 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [0] 
   3.378 +2019-04-19 14:36:30,453 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [VARBINARY(MAX)] 
   3.379 +2019-04-19 14:36:30,453 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_YBJJBHEUHB7Z6AAAAFVDMBYDCI] 
   3.380 +2019-04-19 14:36:30,453 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.381 +2019-04-19 14:36:30,453 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_YBJJBHEUHB7Z6AAAAFVDMBYDCI] 
   3.382 +2019-04-19 14:36:30,454 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [CHAR] 
   3.383 +2019-04-19 14:36:30,454 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [10] 
   3.384 +2019-04-19 14:36:30,454 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [CHAR(10)] 
   3.385 +2019-04-19 14:36:30,454 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_NGFMLS4PLOBGEAAAAFVDMBYDDE] 
   3.386 +2019-04-19 14:36:30,454 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.387 +2019-04-19 14:36:30,455 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_NGFMLS4PLOBGEAAAAFVDMBYDDE] 
   3.388 +2019-04-19 14:36:30,455 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [CHAR] 
   3.389 +2019-04-19 14:36:30,455 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [16] 
   3.390 +2019-04-19 14:36:30,455 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [CHAR(16)] 
   3.391 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_BEGWXWVRBVBVSAAAAFVDMBYDEE] 
   3.392 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.393 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_BEGWXWVRBVBVSAAAAFVDMBYDEE] 
   3.394 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [CHAR] 
   3.395 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [256] 
   3.396 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [CHAR(256)] 
   3.397 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_SKPS2XRFG4HSAAAAAFVDMBYDFE] 
   3.398 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.399 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_SKPS2XRFG4HSAAAAAFVDMBYDFE] 
   3.400 +2019-04-19 14:36:30,456 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [FLOAT] 
   3.401 +2019-04-19 14:36:30,457 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [0] 
   3.402 +2019-04-19 14:36:30,457 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [FLOAT] 
   3.403 +2019-04-19 14:36:30,457 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_7TUPXJI7RRY72AAAAFVDMBYDF4] 
   3.404 +2019-04-19 14:36:30,457 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.405 +2019-04-19 14:36:30,457 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_7TUPXJI7RRY72AAAAFVDMBYDF4] 
   3.406 +2019-04-19 14:36:30,457 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [FLOAT] 
   3.407 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [0] 
   3.408 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [FLOAT] 
   3.409 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_SALVMQGVJVBRCAAAAFVDMBYDGY] 
   3.410 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.411 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_SALVMQGVJVBRCAAAAFVDMBYDGY] 
   3.412 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [FLOAT] 
   3.413 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [0] 
   3.414 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [FLOAT] 
   3.415 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_4CUANRZOICXMUAAAAFVDMBYDHY] 
   3.416 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.417 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_4CUANRZOICXMUAAAAFVDMBYDHY] 
   3.418 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [FLOAT] 
   3.419 +2019-04-19 14:36:30,458 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [0] 
   3.420 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [FLOAT] 
   3.421 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_GFYVJU3GGH2JWAAAAFVDMBYDIY] 
   3.422 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.423 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_GFYVJU3GGH2JWAAAAFVDMBYDIY] 
   3.424 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [FLOAT] 
   3.425 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [0] 
   3.426 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [FLOAT] 
   3.427 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] Create JdbcColumn [XX_N4M7MT2XR3F66AAAAFVDMBYDJQ] 
   3.428 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] sqltype() 
   3.429 +2019-04-19 14:36:30,459 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   name [XX_N4M7MT2XR3F66AAAAFVDMBYDJQ] 
   3.430 +2019-04-19 14:36:30,460 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   type [VARBINARY] 
   3.431 +2019-04-19 14:36:30,460 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   size [0] 
   3.432 +2019-04-19 14:36:30,460 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator]   temp [VARBINARY(MAX)] 
   3.433 +2019-04-19 14:36:30,460 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] SQL statement [CREATE TABLE [LIVEFirethornUserdataULOV20180719].[dbo].[XX_6N55BZC2OMMASAAAAFVDMBYCYM] ([XX_O7YNCMMEC2XCKAAAAFVDMBYDBE] VARBINARY(MAX) , [XX_YBJJBHEUHB7Z6AAAAFVDMBYDCI] CHAR(10) , [XX_NGFMLS4PLOBGEAAAAFVDMBYDDE] CHAR(16) , [XX_BEGWXWVRBVBVSAAAAFVDMBYDEE] CHAR(256) , [XX_SKPS2XRFG4HSAAAAAFVDMBYDFE] FLOAT , [XX_7TUPXJI7RRY72AAAAFVDMBYDF4] FLOAT , [XX_SALVMQGVJVBRCAAAAFVDMBYDGY] FLOAT , [XX_4CUANRZOICXMUAAAAFVDMBYDHY] FLOAT , [XX_GFYVJU3GGH2JWAAAAFVDMBYDIY] FLOAT , [XX_N4M7MT2XR3F66AAAAFVDMBYDJQ] VARBINARY(MAX) )] 
   3.434 +2019-04-19 14:36:30,460 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.435 +2019-04-19 14:36:30,460 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] open [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
   3.436 +2019-04-19 14:36:30,460 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.437 +2019-04-19 14:36:30,461 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.438 +2019-04-19 14:36:30,461 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.439 +2019-04-19 14:36:30,461 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] initialValue() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.440 +2019-04-19 14:36:30,461 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.441 +2019-04-19 14:36:30,461 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] connect [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.442 +2019-04-19 14:36:30,461 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] State is CLOSED, updating to READY 
   3.443 +2019-04-19 14:36:30,461 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] State is READY, initialising Connection 
   3.444 +2019-04-19 14:36:30,462 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] With user/pass 
   3.445 +2019-04-19 14:36:30,462 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] connecting .... 
   3.446 +2019-04-19 14:36:30,467 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] .... connected 
   3.447 +2019-04-19 14:36:30,473 DEBUG [FireThornTaskExecutor-8] [SQLServerOperator] SQL result [0] 
   3.448 +2019-04-19 14:36:30,473 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.449 +2019-04-19 14:36:30,473 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] close [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719][1] 
   3.450 +2019-04-19 14:36:30,473 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] operator() for [mssql] 
   3.451 +2019-04-19 14:36:30,473 DEBUG [FireThornTaskExecutor-8] [JdbcConnectionEntity] get() [jdbc:jtds:sqlserver://ramses2/LIVEFirethornUserdataULOV20180719] 
   3.452 +2019-04-19 14:36:30,474 INFO  [FireThornTaskExecutor-8] [AdqlQueryTimings] TIMING - jdbcdone() 
   3.453 +2019-04-19 14:36:30,478 DEBUG [FireThornTaskExecutor-8] [AdqlQueryTimings] AdqlQueryTimings() 
   3.454 +2019-04-19 14:36:30,496 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] before refresh() 
   3.455 +2019-04-19 14:36:30,503 DEBUG [FireThornTaskExecutor-7] [AdqlQueryTimings] AdqlQueryTimings() 
   3.456 +2019-04-19 14:36:30,503 DEBUG [FireThornTaskExecutor-7] [AdqlQueryTimings] AdqlQueryTimings() 
   3.457 +2019-04-19 14:36:30,504 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] after refresh() 
   3.458 +2019-04-19 14:36:30,504 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Getting base BaseResource 
   3.459 +2019-04-19 14:36:30,505 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Found base BaseResource [OSA JDBC] 
   3.460 +2019-04-19 14:36:30,505 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Getting direct resource 
   3.461 +2019-04-19 14:36:30,505 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] primary(JdbcResource) [53] 
   3.462 +2019-04-19 14:36:30,505 DEBUG [FireThornTaskExecutor-7] [OgsaServiceEntity] primary() 
   3.463 +2019-04-19 14:36:30,511 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] primary(OgsaService, JdbcResource) [3052][53] 
   3.464 +2019-04-19 14:36:30,516 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] Found primary OgsaJdbcResource [3102] 
   3.465 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] Checking ogsaid ... 
   3.466 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   3.467 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scan for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   3.468 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] scantest() 
   3.469 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   3.470 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3102] 
   3.471 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   3.472 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   3.473 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   3.474 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scantest for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   3.475 +2019-04-19 14:36:30,517 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity] factory() 
   3.476 +2019-04-19 14:36:30,518 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.477 +2019-04-19 14:36:30,518 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   3.478 +2019-04-19 14:36:30,518 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   3.479 +2019-04-19 14:36:30,518 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   3.480 +2019-04-19 14:36:30,518 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scanperiod [PT11M] 
   3.481 +2019-04-19 14:36:30,518 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prev scan is recent - skipping 
   3.482 +2019-04-19 14:36:30,518 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] Found ogsaid [ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48][ACTIVE] 
   3.483 +2019-04-19 14:36:30,519 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Using direct resource [XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   3.484 +2019-04-19 14:36:30,519 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Getting source OgsaService 
   3.485 +2019-04-19 14:36:30,519 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Found source OgsaService [http://jarmila:8080/ogsadai/services] 
   3.486 +2019-04-19 14:36:30,519 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Getting target table 
   3.487 +2019-04-19 14:36:30,523 DEBUG [FireThornTaskExecutor-7] [JdbcConnectionEntity] operator() for [mssql] 
   3.488 +2019-04-19 14:36:30,524 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Found target table [[LIVEFirethornUserdataULOV20180719].[dbo].[XX_6N55BZC2OMMASAAAAFVDMBYCYM]] 
   3.489 +2019-04-19 14:36:30,524 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Getting target OgsaBaseResource 
   3.490 +2019-04-19 14:36:30,524 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] primary(JdbcResource) [52] 
   3.491 +2019-04-19 14:36:30,524 DEBUG [FireThornTaskExecutor-7] [OgsaServiceEntity] primary() 
   3.492 +2019-04-19 14:36:30,525 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] primary(OgsaService, JdbcResource) [3052][52] 
   3.493 +2019-04-19 14:36:30,528 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] Found primary OgsaJdbcResource [3103] 
   3.494 +2019-04-19 14:36:30,528 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] Checking ogsaid ... 
   3.495 +2019-04-19 14:36:30,528 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   3.496 +2019-04-19 14:36:30,528 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scan for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   3.497 +2019-04-19 14:36:30,528 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] scantest() 
   3.498 +2019-04-19 14:36:30,528 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   3.499 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3103] 
   3.500 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   3.501 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   3.502 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   3.503 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scantest for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   3.504 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity] factory() 
   3.505 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.506 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   3.507 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   3.508 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   3.509 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scanperiod [PT11M] 
   3.510 +2019-04-19 14:36:30,529 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prev scan is recent - skipping 
   3.511 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity$EntityFactory] Found ogsaid [ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d][ACTIVE] 
   3.512 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Found target OgsaBaseResource [XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   3.513 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Setting state to [RUNNING] [2953] 
   3.514 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] transition(TaskState) 
   3.515 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   ident [2953] 
   3.516 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [READY][RUNNING] 
   3.517 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] accept(TaskState) 
   3.518 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   ident [2953] 
   3.519 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [READY][RUNNING] 
   3.520 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Activating handler [2953] 
   3.521 +2019-04-19 14:36:30,530 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] handle() [] 
   3.522 +2019-04-19 14:36:30,531 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity$Handle] event() [2953]:[RUNNING]->[RUNNING]:[false]->[true] 
   3.523 +2019-04-19 14:36:30,531 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Creating workflow [2953] 
   3.524 +2019-04-19 14:36:30,531 DEBUG [FireThornTaskExecutor-7] [OgsaExecResourceEntity$EntityFactory] primary(OgsaService) [3052] 
   3.525 +2019-04-19 14:36:30,533 DEBUG [FireThornTaskExecutor-7] [OgsaExecResourceEntity$EntityFactory] No primary OgsaExecResource, creating a new one 
   3.526 +2019-04-19 14:36:30,533 DEBUG [FireThornTaskExecutor-7] [OgsaExecResourceEntity$EntityFactory] simple(OgsaService) [3052] 
   3.527 +2019-04-19 14:36:30,534 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] ogsaid [CREATED][DataRequestExecutionResource] 
   3.528 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scan for [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.529 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] scantest() 
   3.530 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.531 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3105] 
   3.532 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   3.533 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] prevscan   [null] 
   3.534 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   3.535 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scantest for [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.536 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [OgsaExecResourceEntity] factory() 
   3.537 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.538 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   3.539 +2019-04-19 14:36:30,535 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   3.540 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prevscan   [null] 
   3.541 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scanperiod [PT11M] 
   3.542 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prev scan is null - scanning 
   3.543 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Checking for existing lock [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.544 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] No existing lock found [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.545 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Adding new lock [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU][2019-04-19T14:36:30.536Z] 
   3.546 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Running scan [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.547 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] scanimpl() 
   3.548 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.549 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3105] 
   3.550 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   3.551 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] ping() 
   3.552 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.553 +2019-04-19 14:36:30,536 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3105] 
   3.554 +2019-04-19 14:36:30,537 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   3.555 +2019-04-19 14:36:30,538 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] Service request [3105][http://jarmila:8080/ogsadai/services/dataResources/DataRequestExecutionResource] 
   3.556 +2019-04-19 14:36:30,549 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] Service response [3105][null] 
   3.557 +2019-04-19 14:36:30,549 ERROR [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] Ping test failed [3105][DataRequestExecutionResource][404] 
   3.558 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] status(status) 
   3.559 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.560 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3105] 
   3.561 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [DataRequestExecutionResource] 
   3.562 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   status [ERROR] 
   3.563 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Releasing locks [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU] 
   3.564 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Found existing lock [3105][XX_JTUT75H5KKSFUAAAAFVDMBYDYU][2019-04-19T14:36:30.536Z] 
   3.565 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Removing .... 
   3.566 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Notifying .... 
   3.567 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   3.568 +2019-04-19 14:36:30,551 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scan for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   3.569 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] scantest() 
   3.570 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   3.571 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3102] 
   3.572 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [ogsadai-ba7cd6f0-d6a0-49c6-84ca-4f242f91ad48] 
   3.573 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   3.574 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   3.575 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scantest for [3102][XX_VTOX6LWNN5QGUAAAAFVDMBNZT4] 
   3.576 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity] factory() 
   3.577 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.578 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   3.579 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   3.580 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.706Z] 
   3.581 +2019-04-19 14:36:30,552 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scanperiod [PT11M] 
   3.582 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prev scan is recent - skipping 
   3.583 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] ogsaid [ACTIVE][ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   3.584 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scan for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   3.585 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] scantest() 
   3.586 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   name   [XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   3.587 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ident  [3103] 
   3.588 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity]   ogsaid [ogsadai-a052f525-6dea-413e-b5d1-ba8ad55a333d] 
   3.589 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   3.590 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaBaseResourceEntity] start time [2019-04-19T14:32:32.225Z] 
   3.591 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scantest for [3103][XX_LQEN4Y6NEFM2GAAAAFVDMBNZWA] 
   3.592 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [OgsaJdbcResourceEntity] factory() 
   3.593 +2019-04-19 14:36:30,553 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory] scanperiod() 
   3.594 +2019-04-19 14:36:30,554 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity$EntityFactory]   value [PT11M] 
   3.595 +2019-04-19 14:36:30,554 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] Factory scanperiod  [PT11M] 
   3.596 +2019-04-19 14:36:30,554 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prevscan   [2019-04-19T14:35:07.880Z] 
   3.597 +2019-04-19 14:36:30,554 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] scanperiod [PT11M] 
   3.598 +2019-04-19 14:36:30,554 DEBUG [FireThornTaskExecutor-7] [BaseComponentEntity] prev scan is recent - skipping 
   3.599 +2019-04-19 14:36:30,554 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Executing workflow [2953] 
   3.600 +2019-04-19 14:36:30,682 DEBUG [FireThornTaskExecutor-7] [OgsaContextClient] monkey(MonkeyParam) 
   3.601 +2019-04-19 14:36:30,804 DEBUG [FireThornTaskExecutor-7] [SimpleWorkflowResult] RequestExecutionStatus [uk.org.ogsadai.resource.request.status.PROCESSING] 
   3.602 +2019-04-19 14:36:30,805 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] After workflow [2953] 
   3.603 +2019-04-19 14:36:30,805 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Before refresh [2953][RUNNING] 
   3.604 +2019-04-19 14:36:30,809 DEBUG [FireThornTaskExecutor-7] [AdqlQueryTimings] AdqlQueryTimings() 
   3.605 +2019-04-19 14:36:30,809 DEBUG [FireThornTaskExecutor-7] [AdqlQueryTimings] AdqlQueryTimings() 
   3.606 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] After refresh [2953][READY] 
   3.607 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Workflow result [2953][RUNNING] 
   3.608 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] transition(TaskState) 
   3.609 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   ident [2953] 
   3.610 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [READY][RUNNING] 
   3.611 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] accept(TaskState) 
   3.612 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   ident [2953] 
   3.613 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [READY][RUNNING] 
   3.614 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueQueryEntity] Finishing execute() [2953][RUNNING] 
   3.615 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity] After execute() 
   3.616 +2019-04-19 14:36:30,810 DEBUG [FireThornTaskExecutor-7] [BlueTaskEntity]   state [RUNNING] 
   3.617 +2019-04-19 14:36:30,812 DEBUG [FireThornTaskExecutor-7] [AdqlQueryTimings] AdqlQueryTimings() 
   3.618 +2019-04-19 14:36:30,816 DEBUG [FireThornTaskExecutor-6] [BlueTaskEntity] Finished thread() 
   3.619 +2019-04-19 14:36:30,816 DEBUG [FireThornTaskExecutor-6] [BlueTaskEntity]   state [READY] 
   3.620 +2019-04-19 14:36:30,816 DEBUG [FireThornTaskExecutor-6] [BlueTaskEntity] Refreshing state 
   3.621 +2019-04-19 14:36:30,821 DEBUG [FireThornTaskExecutor-6] [AdqlQueryTimings] AdqlQueryTimings() 
   3.622 +2019-04-19 14:36:30,821 DEBUG [FireThornTaskExecutor-6] [AdqlQueryTimings] AdqlQueryTimings() 
   3.623 +2019-04-19 14:36:30,822 DEBUG [FireThornTaskExecutor-6] [BlueTaskEntity] Finished running() 
   3.624 +2019-04-19 14:36:30,822 DEBUG [FireThornTaskExecutor-6] [BlueTaskEntity]   state [RUNNING] 
   3.625 +2019-04-19 14:36:30,823 DEBUG [main-interface-4] [BlueQueryEntity] Converting current instance [2953] 
   3.626 +2019-04-19 14:36:30,826 DEBUG [main-interface-4] [AdqlQueryTimings] AdqlQueryTimings() 
   3.627 +2019-04-19 14:36:30,827 DEBUG [main-interface-4] [AdqlQueryTimings] AdqlQueryTimings() 
   3.628 +2019-04-19 14:36:30,827 DEBUG [main-interface-4] [BlueTaskEntity] waitfor() [2953]:[RUNNING]->[RUNNING]->[COMPLETED]:[3000000] 
   3.629 +2019-04-19 14:36:30,827 DEBUG [main-interface-4] [BlueTaskEntity] handle() [] 
   3.630 +2019-04-19 14:36:30,827 DEBUG [main-interface-4] [BlueTaskEntity$BaseEventListener] waitfor(Handle) [2953][RUNNING] 
   3.631 +2019-04-19 14:36:30,827 DEBUG [main-interface-4] [BlueTaskEntity$StatusEventListener] test() [2953][RUNNING]->[RUNNING]->[COMPLETED] 
   3.632 +2019-04-19 14:36:30,827 DEBUG [main-interface-4] [BlueTaskEntity$BaseEventListener] test() [2953][0][3000000] 
   3.633 +