SuccessConsole Output

Skipping 3,166 KB.. Full Log
 >> result=Owner 5
05:39:06,512 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
05:39:06,512 INFO  [main][General] >> result=Owner 3
05:39:06,512 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.2, S.Element 3.1, S.Element 3.3
05:39:06,514 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:06,514 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:06,523 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && :paramColl.contains(this.indexKey)" since the connection used is closing
05:39:07,416 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:07,418 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:07,440 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:09,687 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:09,920 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:09,920 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:09,920 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:09,921 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:09,922 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:09,945 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:09,946 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:09,954 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.join.ElementASetOwner" not found !
05:39:09,956 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.join.ElementA" not found !
05:39:10,069 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:10,070 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,071 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,072 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,073 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
05:39:10,073 INFO  [main][General] >> result=Owner 1
05:39:10,074 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.3, S.Element 1.2, S.Element 1.1, S.Element 1.4
05:39:10,074 INFO  [main][General] >> result=Owner 2
05:39:10,074 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.1, S.Element 2.2, S.Element 2.3, S.Element 2.4
05:39:10,074 INFO  [main][General] >> result=Owner 4
05:39:10,074 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
05:39:10,075 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,076 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,077 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,081 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:10,082 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,083 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "ElementA[name="S.Element 3.2"]":
05:39:10,083 INFO  [main][General] >> result=Owner 3
05:39:10,083 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.2, S.Element 3.3, S.Element 3.1
05:39:10,086 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,086 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,087 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,089 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:10,090 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,090 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,092 INFO  [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "!this.set.contains(:element)" and param "ElementA[name="S.Element 3.2"]":
05:39:10,092 INFO  [main][General] >> result=Owner 4
05:39:10,092 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
05:39:10,092 INFO  [main][General] >> result=Owner 5
05:39:10,092 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
05:39:10,092 INFO  [main][General] >> result=Owner 1
05:39:10,092 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.4, S.Element 1.3, S.Element 1.2, S.Element 1.1
05:39:10,092 INFO  [main][General] >> result=Owner 2
05:39:10,092 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.1, S.Element 2.3, S.Element 2.4, S.Element 2.2
05:39:10,094 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,094 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,100 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:10,102 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,103 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,104 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,105 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,105 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,106 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,107 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,108 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,109 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,110 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
05:39:10,110 INFO  [main][General] >> result=Owner 1
05:39:10,110 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.2, S.Element 1.3, S.Element 1.4, S.Element 1.1
05:39:10,110 INFO  [main][General] >> result=Owner 2
05:39:10,110 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.1, S.Element 2.4, S.Element 2.3, S.Element 2.2
05:39:10,110 INFO  [main][General] >> result=Owner 3
05:39:10,110 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.3, S.Element 3.1, S.Element 3.2
05:39:10,112 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,112 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,118 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:10,120 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,120 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,121 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,122 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,123 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,124 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,125 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,126 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,126 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,128 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
05:39:10,128 INFO  [main][General] >> result=Owner 1
05:39:10,128 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.4, S.Element 1.3, S.Element 1.1, S.Element 1.2
05:39:10,128 INFO  [main][General] >> result=Owner 2
05:39:10,128 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.2, S.Element 2.1, S.Element 2.4, S.Element 2.3
05:39:10,128 INFO  [main][General] >> result=Owner 3
05:39:10,128 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.1, S.Element 3.2, S.Element 3.3
05:39:10,130 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,130 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,131 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,135 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:10,136 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,137 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,138 INFO  [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "ElementA[name="S.Element 3.2"]":
05:39:10,138 INFO  [main][General] >> result=Owner 4
05:39:10,138 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
05:39:10,138 INFO  [main][General] >> result=Owner 5
05:39:10,138 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
05:39:10,139 INFO  [main][General] >> result=Owner 1
05:39:10,139 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.4, S.Element 1.2, S.Element 1.1, S.Element 1.3
05:39:10,139 INFO  [main][General] >> result=Owner 2
05:39:10,139 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.3, S.Element 2.1, S.Element 2.2, S.Element 2.4
05:39:10,140 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,141 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,142 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,144 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryContainerSize WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey == 0" since the connection used is closing
05:39:10,144 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.isEmpty()" and param "ElementA[name="S.Element 3.2"]":
05:39:10,145 INFO  [main][General] >> result=Owner 5
05:39:10,145 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
05:39:10,146 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,146 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,147 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,149 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryContainerSize WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey == :compareToArgument" since the connection used is closing
05:39:10,150 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.size() == 3" and param "ElementA[name="S.Element 3.2"]":
05:39:10,150 INFO  [main][General] >> result=Owner 3
05:39:10,150 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.1, S.Element 3.3, S.Element 3.2
05:39:10,151 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,152 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,153 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,155 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:10,156 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,156 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.contains(:element)" and param "ElementA[name="S.Element 3.2"]":
05:39:10,156 INFO  [main][General] >> result=Owner 3
05:39:10,156 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.2, S.Element 3.1, S.Element 3.3
05:39:10,158 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,158 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,159 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,163 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID != :notThisObjectID" since the connection used is closing
05:39:10,164 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,165 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,166 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,167 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,168 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,168 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,169 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,170 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,171 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,172 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,172 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,174 INFO  [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "ElementA[name="S.Element 3.2"]":
05:39:10,174 INFO  [main][General] >> result=Owner 1
05:39:10,174 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.4, S.Element 1.2, S.Element 1.1, S.Element 1.3
05:39:10,174 INFO  [main][General] >> result=Owner 2
05:39:10,174 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.4, S.Element 2.3, S.Element 2.1, S.Element 2.2
05:39:10,175 INFO  [main][General] >> result=Owner 3
05:39:10,175 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.1, S.Element 3.2, S.Element 3.3
05:39:10,175 INFO  [main][General] >> result=Owner 4
05:39:10,175 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
05:39:10,176 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,176 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,178 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:10,180 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID != :notThisObjectID" since the connection used is closing
05:39:10,181 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,181 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,182 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,183 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,184 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,185 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,186 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,186 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,187 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,188 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,189 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,190 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "ElementA[name="S.Element 4.3"]":
05:39:10,190 INFO  [main][General] >> result=Owner 1
05:39:10,190 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.4, S.Element 1.2, S.Element 1.1, S.Element 1.3
05:39:10,190 INFO  [main][General] >> result=Owner 2
05:39:10,190 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.2, S.Element 2.3, S.Element 2.1, S.Element 2.4
05:39:10,190 INFO  [main][General] >> result=Owner 3
05:39:10,190 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.2, S.Element 3.3, S.Element 3.1
05:39:10,192 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,192 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,198 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:10,200 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,201 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,202 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:10,202 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,203 INFO  [main][ElementASetQueryTest] invoke: found 2 ElementASetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
05:39:10,203 INFO  [main][General] >> result=Owner 3
05:39:10,203 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.3, S.Element 3.1, S.Element 3.2
05:39:10,203 INFO  [main][General] >> result=Owner 5
05:39:10,204 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
05:39:10,205 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:10,205 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:10,207 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && :paramColl.contains(this.indexKey)" since the connection used is closing
05:39:10,207 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 26, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 12.051 sec
Running org.cumulus4j.store.test.collection.mappedby.Element3MapQueryTest
05:39:11,102 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
05:39:11,580 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
05:39:11,581 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:11,595 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
05:39:11,595 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
05:39:11,596 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:11,596 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:11,613 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:17,527 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:17,831 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:17,832 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:17,832 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:17,833 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:17,834 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:17,994 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:18,121 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:18,239 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element3MapOwner" not found !
05:39:18,243 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element3" not found !
05:39:18,425 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:18,436 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsValue(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
05:39:18,436 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ddd", name="Element 1.4"]=ddd
05:39:18,436 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 2: Element3[value="cc", name="Element 2.3"]=cc, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="bb", name="Element 2.2"]=bb
05:39:18,436 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
05:39:18,438 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:18,438 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:18,445 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:18,447 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsKey(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
05:39:18,448 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 1: Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="ddd", name="Element 1.4"]=ddd
05:39:18,448 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 2: Element3[value="dd", name="Element 2.4"]=dd, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="aa", name="Element 2.1"]=aa
05:39:18,448 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
05:39:18,449 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:18,450 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:18,456 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:18,463 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:18,464 INFO  [main][Element3MapQueryTest] queryContainsKeyParameter: found 1 Element3MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
05:39:18,464 INFO  [main][Element3MapQueryTest] queryContainsKeyParameter:   * Owner 3: Element3[value="a", name="Element 3.1"]=a, Element3[value="c", name="Element 3.3"]=c, Element3[value="b", name="Element 3.2"]=b
05:39:18,466 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:18,466 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:18,467 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:18,469 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:18,475 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:18,478 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter: found 5 Element3MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
05:39:18,478 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
05:39:18,478 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ddd", name="Element 1.4"]=ddd
05:39:18,478 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
05:39:18,478 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
05:39:18,478 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 2: Element3[value="cc", name="Element 2.3"]=cc, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="aa", name="Element 2.1"]=aa
05:39:18,480 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:18,480 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:18,482 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:18,484 INFO  [main][Element3MapQueryTest] queryContainsValueParameter: found 2 Element3MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "ccc":
05:39:18,484 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
05:39:18,485 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 1: Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="aaa", name="Element 1.1"]=aaa
05:39:18,486 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:18,486 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:18,488 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:18,489 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:18,491 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter: found 4 Element3MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "ccc":
05:39:18,491 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
05:39:18,491 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
05:39:18,491 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 2: Element3[value="cc", name="Element 2.3"]=cc, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="dd", name="Element 2.4"]=dd
05:39:18,492 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 3: Element3[value="b", name="Element 3.2"]=b, Element3[value="c", name="Element 3.3"]=c, Element3[value="a", name="Element 3.1"]=a
05:39:19,326 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:19,329 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:19,346 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:21,647 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:22,060 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:22,060 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:22,060 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:22,061 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:22,061 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:22,086 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:22,087 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:22,094 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element3MapOwner" not found !
05:39:22,095 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element3" not found !
05:39:22,239 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:22,246 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsValue(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
05:39:22,246 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="ccc", name="Element 1.3"]=ccc
05:39:22,246 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 2: Element3[value="cc", name="Element 2.3"]=cc, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="aa", name="Element 2.1"]=aa
05:39:22,246 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
05:39:22,248 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:22,248 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:22,254 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:22,256 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsKey(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
05:39:22,256 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb
05:39:22,256 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 2: Element3[value="aa", name="Element 2.1"]=aa, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="bb", name="Element 2.2"]=bb
05:39:22,257 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
05:39:22,258 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:22,258 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:22,260 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:22,261 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:22,262 INFO  [main][Element3MapQueryTest] queryContainsKeyParameter: found 1 Element3MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
05:39:22,262 INFO  [main][Element3MapQueryTest] queryContainsKeyParameter:   * Owner 3: Element3[value="c", name="Element 3.3"]=c, Element3[value="a", name="Element 3.1"]=a, Element3[value="b", name="Element 3.2"]=b
05:39:22,263 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:22,263 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:22,264 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:22,266 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:22,267 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:22,269 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter: found 5 Element3MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
05:39:22,269 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 2: Element3[value="bb", name="Element 2.2"]=bb, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="dd", name="Element 2.4"]=dd
05:39:22,269 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
05:39:22,269 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="ddd", name="Element 1.4"]=ddd
05:39:22,269 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
05:39:22,270 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
05:39:22,271 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:22,271 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:22,273 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:22,274 INFO  [main][Element3MapQueryTest] queryContainsValueParameter: found 2 Element3MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "ccc":
05:39:22,274 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 1: Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="bbb", name="Element 1.2"]=bbb
05:39:22,274 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
05:39:22,276 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:22,276 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:22,277 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:22,278 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:22,280 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter: found 4 Element3MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "ccc":
05:39:22,280 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 2: Element3[value="bb", name="Element 2.2"]=bb, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="aa", name="Element 2.1"]=aa
05:39:22,280 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 3: Element3[value="c", name="Element 3.3"]=c, Element3[value="b", name="Element 3.2"]=b, Element3[value="a", name="Element 3.1"]=a
05:39:22,280 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
05:39:22,280 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
05:39:22,281 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 12, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.841 sec
Running org.cumulus4j.store.test.collection.mappedby.Element2MapQueryTest
05:39:22,946 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
05:39:23,284 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
05:39:23,285 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:23,294 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
05:39:23,294 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
05:39:23,295 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:23,296 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:23,308 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:29,006 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:29,006 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:29,006 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:29,008 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:29,008 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:29,100 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:29,145 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:29,209 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:29,321 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element2MapOwner" not found !
05:39:29,325 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element2" not found !
05:39:29,504 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:29,514 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
05:39:29,514 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,515 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:29,515 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:29,516 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,517 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,521 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:29,523 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
05:39:29,524 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,524 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:29,524 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:29,525 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,525 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,535 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:29,540 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) < 0" and param "bb":
05:39:29,540 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,540 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:29,540 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:29,541 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:29,542 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,543 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,547 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:29,551 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && !(variable.indexOf(:queryParam) >= 0)" and param "bb":
05:39:29,551 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,551 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:29,551 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:29,552 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:29,553 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,553 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,560 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:29,565 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && !(variable.name.indexOf(:queryParam) >= 0)" and param "4":
05:39:29,565 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,566 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:29,566 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:29,566 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:29,567 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,567 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,574 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:29,578 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) < 0" and param "4":
05:39:29,579 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,579 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:29,579 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:29,579 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:29,580 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,581 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,587 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:29,588 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter: found 2 Element2MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "ccc":
05:39:29,588 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:29,588 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,590 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,590 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,592 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:29,597 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,599 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter: found 4 Element2MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "ccc":
05:39:29,599 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
05:39:29,599 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:29,599 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:29,600 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:29,601 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,601 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,603 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:29,609 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:29,610 INFO  [main][Element2MapQueryTest] queryContainsValueParameter: found 1 Element2MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
05:39:29,610 INFO  [main][Element2MapQueryTest] queryContainsValueParameter:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:29,612 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,612 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:29,614 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:29,615 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:29,616 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:29,618 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter: found 5 Element2MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
05:39:29,618 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:29,618 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:29,618 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
05:39:29,618 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:29,618 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:30,506 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:30,511 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:30,531 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:32,928 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:32,928 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:32,928 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:32,929 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:32,929 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:32,960 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:32,961 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:32,972 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element2MapOwner" not found !
05:39:32,973 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element2" not found !
05:39:33,148 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:33,151 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
05:39:33,151 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,151 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,151 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:33,153 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,154 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,158 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:33,161 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
05:39:33,161 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,162 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,162 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:33,164 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,164 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,170 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:33,181 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) < 0" and param "bb":
05:39:33,182 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,182 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,182 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:33,182 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:33,184 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,184 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,189 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:33,195 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && !(variable.indexOf(:queryParam) >= 0)" and param "bb":
05:39:33,195 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,195 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,196 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:33,196 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:33,197 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,198 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,205 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:33,210 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && !(variable.name.indexOf(:queryParam) >= 0)" and param "4":
05:39:33,210 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,210 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,211 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:33,211 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:33,215 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,215 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,223 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:33,224 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:33,228 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) < 0" and param "4":
05:39:33,228 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,228 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,228 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:33,229 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:33,230 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,230 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,232 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:33,234 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter: found 2 Element2MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "ccc":
05:39:33,234 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,234 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:33,235 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,236 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,237 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
05:39:33,239 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,241 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter: found 4 Element2MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "ccc":
05:39:33,241 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,241 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:33,241 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
05:39:33,241 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:33,243 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,243 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,244 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:33,246 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:33,247 INFO  [main][Element2MapQueryTest] queryContainsValueParameter: found 1 Element2MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
05:39:33,247 INFO  [main][Element2MapQueryTest] queryContainsValueParameter:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
05:39:33,249 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,249 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
05:39:33,251 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:33,253 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:33,254 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:33,256 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter: found 5 Element2MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
05:39:33,256 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
05:39:33,256 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
05:39:33,256 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
05:39:33,257 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
05:39:33,257 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
05:39:33,257 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.142 sec
Running org.cumulus4j.store.test.collection.mappedby.Element1SetQueryTest
05:39:34,091 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
05:39:34,450 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
05:39:34,450 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:34,460 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
05:39:34,460 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
05:39:34,460 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:34,461 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:34,476 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:40,945 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:40,945 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:40,945 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:40,947 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:40,948 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:41,136 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:41,246 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:41,353 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element1SetOwner" not found !
05:39:41,357 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element1" not found !
05:39:41,502 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:41,510 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:41,513 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
05:39:41,513 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 1: Element 1.4, Element 1.3, Element 1.2, Element 1.1
05:39:41,513 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 2: Element 2.2, Element 2.1, Element 2.4, Element 2.3
05:39:41,513 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 4: Element 4.3
05:39:41,515 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,515 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,521 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:41,525 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:41,526 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: found 1 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
05:39:41,526 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals:   * Owner 3: Element 3.1, Element 3.2, Element 3.3
05:39:41,528 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,528 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,529 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:41,536 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:41,541 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,543 INFO  [main][Element1SetQueryTest] queryNotContainsParameter: found 4 Element1SetOwners for query-filter "!this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
05:39:41,543 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 4: Element 4.3
05:39:41,543 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 1: Element 1.4, Element 1.3, Element 1.1, Element 1.2
05:39:41,543 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 5: 
05:39:41,543 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 2: Element 2.1, Element 2.4, Element 2.3, Element 2.2
05:39:41,545 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,545 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,557 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:41,562 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
05:39:41,562 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 1: Element 1.2, Element 1.3, Element 1.1, Element 1.4
05:39:41,562 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 2: Element 2.2, Element 2.1, Element 2.3, Element 2.4
05:39:41,562 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 3: Element 3.3, Element 3.2, Element 3.1
05:39:41,564 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,564 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,571 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:41,576 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
05:39:41,576 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 1: Element 1.3, Element 1.1, Element 1.4, Element 1.2
05:39:41,576 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 2: Element 2.2, Element 2.3, Element 2.1, Element 2.4
05:39:41,576 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 3: Element 3.3, Element 3.1, Element 3.2
05:39:41,578 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,578 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,580 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:41,583 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:41,584 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,586 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: found 4 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
05:39:41,586 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 4: Element 4.3
05:39:41,586 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 1: Element 1.4, Element 1.2, Element 1.1, Element 1.3
05:39:41,586 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 5: 
05:39:41,586 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 2: Element 2.3, Element 2.4, Element 2.1, Element 2.2
05:39:41,587 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,588 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,589 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:41,590 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:41,591 INFO  [main][Element1SetQueryTest] queryContainsParameter: found 1 Element1SetOwners for query-filter "this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
05:39:41,591 INFO  [main][Element1SetQueryTest] queryContainsParameter:   * Owner 3: Element 3.3, Element 3.1, Element 3.2
05:39:41,592 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,593 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,594 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:41,602 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID != :notThisObjectID" since the connection used is closing
05:39:41,606 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 4.3"]":
05:39:41,606 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 1: Element 1.4, Element 1.2, Element 1.3, Element 1.1
05:39:41,606 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 2: Element 2.2, Element 2.1, Element 2.4, Element 2.3
05:39:41,606 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 3: Element 3.3, Element 3.2, Element 3.1
05:39:41,608 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,608 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,614 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:41,616 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,617 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: found 2 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
05:39:41,617 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 5: 
05:39:41,617 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 3: Element 3.3, Element 3.2, Element 3.1
05:39:41,618 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:41,618 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:41,619 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:41,621 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID != :notThisObjectID" since the connection used is closing
05:39:41,624 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: found 4 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 3.2"]":
05:39:41,625 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 1: Element 1.4, Element 1.2, Element 1.3, Element 1.1
05:39:41,625 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 2: Element 2.1, Element 2.4, Element 2.3, Element 2.2
05:39:41,625 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 3: Element 3.2, Element 3.1, Element 3.3
05:39:41,625 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 4: Element 4.3
05:39:42,380 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:42,382 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:42,403 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:44,946 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:44,946 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:44,946 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:44,947 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:44,947 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:44,966 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:44,966 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:44,972 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element1SetOwner" not found !
05:39:44,973 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element1" not found !
05:39:45,085 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:45,087 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
05:39:45,087 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 1: Element 1.2, Element 1.1, Element 1.3, Element 1.4
05:39:45,087 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 2: Element 2.2, Element 2.1, Element 2.3, Element 2.4
05:39:45,087 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 4: Element 4.3
05:39:45,089 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,089 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,090 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:45,093 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:45,094 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: found 1 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
05:39:45,094 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals:   * Owner 3: Element 3.2, Element 3.3, Element 3.1
05:39:45,095 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,096 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,097 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:45,098 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:45,099 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,100 INFO  [main][Element1SetQueryTest] queryNotContainsParameter: found 4 Element1SetOwners for query-filter "!this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
05:39:45,100 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 4: Element 4.3
05:39:45,100 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 1: Element 1.3, Element 1.4, Element 1.2, Element 1.1
05:39:45,100 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 5: 
05:39:45,100 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 2: Element 2.4, Element 2.1, Element 2.3, Element 2.2
05:39:45,102 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,102 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,108 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:45,116 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
05:39:45,116 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 1: Element 1.3, Element 1.2, Element 1.1, Element 1.4
05:39:45,116 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 2: Element 2.3, Element 2.2, Element 2.4, Element 2.1
05:39:45,116 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 3: Element 3.1, Element 3.3, Element 3.2
05:39:45,118 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,118 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,125 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
05:39:45,129 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
05:39:45,129 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 1: Element 1.4, Element 1.1, Element 1.2, Element 1.3
05:39:45,129 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 2: Element 2.4, Element 2.3, Element 2.1, Element 2.2
05:39:45,130 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 3: Element 3.2, Element 3.1, Element 3.3
05:39:45,132 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,133 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,134 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:45,137 INFO  [main][Query] Reading in results for query "SELECT UNIQUE this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:45,138 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,140 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: found 4 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
05:39:45,140 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 4: Element 4.3
05:39:45,140 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 1: Element 1.4, Element 1.3, Element 1.2, Element 1.1
05:39:45,140 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 5: 
05:39:45,140 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 2: Element 2.3, Element 2.4, Element 2.1, Element 2.2
05:39:45,141 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,142 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,143 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:45,145 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID == :objectID" since the connection used is closing
05:39:45,145 INFO  [main][Element1SetQueryTest] queryContainsParameter: found 1 Element1SetOwners for query-filter "this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
05:39:45,145 INFO  [main][Element1SetQueryTest] queryContainsParameter:   * Owner 3: Element 3.2, Element 3.3, Element 3.1
05:39:45,147 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,147 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,148 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:45,152 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID != :notThisObjectID" since the connection used is closing
05:39:45,155 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 4.3"]":
05:39:45,156 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 1: Element 1.1, Element 1.2, Element 1.3, Element 1.4
05:39:45,156 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 2: Element 2.4, Element 2.3, Element 2.1, Element 2.2
05:39:45,156 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 3: Element 3.2, Element 3.1, Element 3.3
05:39:45,157 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,157 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,164 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
05:39:45,165 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,166 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: found 2 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
05:39:45,166 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 3: Element 3.1, Element 3.3, Element 3.2
05:39:45,166 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 5: 
05:39:45,168 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:45,168 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
05:39:45,169 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
05:39:45,170 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID && this.objectID != :notThisObjectID" since the connection used is closing
05:39:45,175 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: found 4 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 3.2"]":
05:39:45,175 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 1: Element 1.1, Element 1.3, Element 1.4, Element 1.2
05:39:45,175 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 2: Element 2.4, Element 2.2, Element 2.1, Element 2.3
05:39:45,175 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 3: Element 3.2, Element 3.1, Element 3.3
05:39:45,175 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 4: Element 4.3
05:39:45,175 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
05:39:45,900 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.81 sec
Running org.cumulus4j.store.test.datatype.StandardOneToOneTypesTest
05:39:45,908 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
05:39:46,622 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
05:39:46,623 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:46,634 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
05:39:46,634 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
05:39:46,635 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:46,635 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:46,647 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:52,896 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:52,896 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:52,896 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:52,928 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:52,929 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:53,025 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:53,135 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:53,622 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:54,512 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 1e78c15f-2d3d-498e-b28d-1454c9662f6a
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 1f884d31-5921-4681-b5b6-8d3b47745bbd
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 25585480-a092-4315-995c-f2f47beffa72
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 26832eb4-9f2e-4a4f-849c-d4ac9f7c9df0
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 2ee4c7c7-f856-4973-a1f5-fc61a43acea2
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4033f439-ca6c-4d50-8382-a240a70a87f1
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4a37938c-eef7-4b86-a789-b5e5577581f1
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4c9f55aa-cd1a-48fb-a456-4b1a088e0aaa
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5e439a9c-296e-4dae-b409-3bbcb93a5cc2
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6a6d02c1-4496-475b-abdd-c5d08e89efef
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6f839204-f228-4f32-acc6-b51b275af939
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 704912c7-35d2-4d3a-95c6-66888222ff56
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 71a0681c-64b1-420f-86c0-635ebd94e481
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 72557124-0165-4b3f-a637-b78949f37afb
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7563be11-9b9c-4484-a9f7-890b0eefed07
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7723c4e1-6b0f-4291-b4ad-d3a77adb4370
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7d435d80-91d5-4840-b7c3-ae9a531e22ea
05:39:54,516 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7e5e032f-2d74-4203-9faa-dbf039ffc2c5
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 843346e2-c55b-46f7-a2a6-ecaddde47195
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 8ec00b40-2e34-4e93-86ec-db88091379ae
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 90fb281f-1e41-4d06-a40f-97cf8d26f376
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 9263ba2d-0a86-4715-9b14-064df325282f
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 9d13e416-da04-45d9-ab16-457856cee986
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = a0640370-65a5-4485-a78d-406cb898e9ca
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = ab2d6ac3-b4e8-4542-abb3-39c071fadac7
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = aeb53471-b8ed-4558-b04f-f54e6563bb24
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = b5491198-c1df-4a20-9426-8a41059aacba
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = ba1f31af-24df-489c-a105-fcfead42a568
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = e735db82-274d-4218-aa26-dae15890faf0
05:39:54,517 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fda28f3a-f8bd-47f6-b66a-698fba6f9c25
05:39:55,823 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
05:39:55,829 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
05:39:55,848 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
05:39:57,956 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:39:58,477 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
05:39:58,477 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
05:39:58,477 INFO  [main][Cumulus4jStoreManager] =======================================================
05:39:58,478 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:39:58,479 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:39:58,501 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:58,502 INFO  [main][MinimumCumulus4jVersion] version=10100001
05:39:58,934 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 1e78c15f-2d3d-498e-b28d-1454c9662f6a
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 1f884d31-5921-4681-b5b6-8d3b47745bbd
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 25585480-a092-4315-995c-f2f47beffa72
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 26832eb4-9f2e-4a4f-849c-d4ac9f7c9df0
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 2ee4c7c7-f856-4973-a1f5-fc61a43acea2
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4033f439-ca6c-4d50-8382-a240a70a87f1
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4a37938c-eef7-4b86-a789-b5e5577581f1
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4c9f55aa-cd1a-48fb-a456-4b1a088e0aaa
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5e439a9c-296e-4dae-b409-3bbcb93a5cc2
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6a6d02c1-4496-475b-abdd-c5d08e89efef
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6f839204-f228-4f32-acc6-b51b275af939
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 704912c7-35d2-4d3a-95c6-66888222ff56
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 71a0681c-64b1-420f-86c0-635ebd94e481
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 72557124-0165-4b3f-a637-b78949f37afb
05:39:58,942 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7563be11-9b9c-4484-a9f7-890b0eefed07
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7723c4e1-6b0f-4291-b4ad-d3a77adb4370
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7d435d80-91d5-4840-b7c3-ae9a531e22ea
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7e5e032f-2d74-4203-9faa-dbf039ffc2c5
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 843346e2-c55b-46f7-a2a6-ecaddde47195
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 8ec00b40-2e34-4e93-86ec-db88091379ae
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 90fb281f-1e41-4d06-a40f-97cf8d26f376
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 9263ba2d-0a86-4715-9b14-064df325282f
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 9d13e416-da04-45d9-ab16-457856cee986
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = a0640370-65a5-4485-a78d-406cb898e9ca
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = ab2d6ac3-b4e8-4542-abb3-39c071fadac7
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = aeb53471-b8ed-4558-b04f-f54e6563bb24
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = b5491198-c1df-4a20-9426-8a41059aacba
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = ba1f31af-24df-489c-a105-fcfead42a568
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = e735db82-274d-4218-aa26-dae15890faf0
05:39:58,943 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fda28f3a-f8bd-47f6-b66a-698fba6f9c25
05:39:58,968 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 13.819 sec

Results :

Tests run: 361, Failures: 0, Errors: 0, Skipped: 2

[JENKINS] Recording test results
[INFO] 
[INFO] --- maven-jar-plugin:2.3.1:jar (default-jar) @ org.cumulus4j.store.test ---
Downloading: http://www.datanucleus.org/downloads/maven2/commons-lang/commons-lang/2.1/commons-lang-2.1.pom
Downloading: http://onejar-maven-plugin.googlecode.com/svn/mavenrepo/commons-lang/commons-lang/2.1/commons-lang-2.1.pom
Downloading: http://mc-repo.googlecode.com/svn/maven2/releases/commons-lang/commons-lang/2.1/commons-lang-2.1.pom
Downloading: http://repo.maven.apache.org/maven2/commons-lang/commons-lang/2.1/commons-lang-2.1.pom
Downloaded: http://repo.maven.apache.org/maven2/commons-lang/commons-lang/2.1/commons-lang-2.1.pom (10 KB at 570.3 KB/sec)
Downloading: http://www.datanucleus.org/downloads/maven2/commons-lang/commons-lang/2.1/commons-lang-2.1.jar
Downloading: http://onejar-maven-plugin.googlecode.com/svn/mavenrepo/commons-lang/commons-lang/2.1/commons-lang-2.1.jar
Downloading: http://mc-repo.googlecode.com/svn/maven2/releases/commons-lang/commons-lang/2.1/commons-lang-2.1.jar
Downloading: http://repo.maven.apache.org/maven2/commons-lang/commons-lang/2.1/commons-lang-2.1.jar
Downloaded: http://repo.maven.apache.org/maven2/commons-lang/commons-lang/2.1/commons-lang-2.1.jar (203 KB at 5201.4 KB/sec)
[INFO] Building jar: /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/target/org.cumulus4j.store.test-1.2.1-SNAPSHOT.jar
[INFO] 
[INFO] --- maven-jar-plugin:2.3.1:test-jar (test-jar) @ org.cumulus4j.store.test ---
[INFO] Building jar: /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/target/org.cumulus4j.store.test-1.2.1-SNAPSHOT-tests.jar
[INFO] 
[INFO] --- maven-source-plugin:2.1.2:jar-no-fork (attach-sources) @ org.cumulus4j.store.test ---
[INFO] META-INF already added, skipping
[INFO] org already added, skipping
[INFO] org/cumulus4j already added, skipping
[INFO] org/cumulus4j/store already added, skipping
[INFO] org/cumulus4j/store/test already added, skipping
[INFO] org/cumulus4j/store/test/movie already added, skipping
[INFO] org/cumulus4j/store/test/embedded already added, skipping
[INFO] org/cumulus4j/store/test/embedded/onetoone already added, skipping
[INFO] org/cumulus4j/store/test/embedded/onetoone/nested already added, skipping
[INFO] org/cumulus4j/store/test/embedded/onetomany already added, skipping
[INFO] org/cumulus4j/store/test/inheritance already added, skipping
[INFO] org/cumulus4j/store/test/inheritance/sources already added, skipping
[INFO] org/cumulus4j/store/test/account already added, skipping
[INFO] org/cumulus4j/store/test/account/id already added, skipping
[INFO] org/cumulus4j/store/test/onetoone already added, skipping
[INFO] org/cumulus4j/store/test/onetoone/mappedby already added, skipping
[INFO] org/cumulus4j/store/test/metadata already added, skipping
[INFO] org/cumulus4j/store/test/valuestrategy already added, skipping
[INFO] org/cumulus4j/store/test/framework already added, skipping
[INFO] org/cumulus4j/store/test/collection already added, skipping
[INFO] org/cumulus4j/store/test/collection/join already added, skipping
[INFO] org/cumulus4j/store/test/collection/mappedby already added, skipping
[INFO] org/cumulus4j/store/test/datatype already added, skipping
[INFO] LICENCE.txt already added, skipping
[INFO] META-INF/MANIFEST.MF already added, skipping
[INFO] Building jar: /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/target/org.cumulus4j.store.test-1.2.1-SNAPSHOT-sources.jar
[INFO] META-INF already added, skipping
[INFO] org already added, skipping
[INFO] org/cumulus4j already added, skipping
[INFO] org/cumulus4j/store already added, skipping
[INFO] org/cumulus4j/store/test already added, skipping
[INFO] org/cumulus4j/store/test/movie already added, skipping
[INFO] org/cumulus4j/store/test/embedded already added, skipping
[INFO] org/cumulus4j/store/test/embedded/onetoone already added, skipping
[INFO] org/cumulus4j/store/test/embedded/onetoone/nested already added, skipping
[INFO] org/cumulus4j/store/test/embedded/onetomany already added, skipping
[INFO] org/cumulus4j/store/test/inheritance already added, skipping
[INFO] org/cumulus4j/store/test/inheritance/sources already added, skipping
[INFO] org/cumulus4j/store/test/account already added, skipping
[INFO] org/cumulus4j/store/test/account/id already added, skipping
[INFO] org/cumulus4j/store/test/onetoone already added, skipping
[INFO] org/cumulus4j/store/test/onetoone/mappedby already added, skipping
[INFO] org/cumulus4j/store/test/metadata already added, skipping
[INFO] org/cumulus4j/store/test/valuestrategy already added, skipping
[INFO] org/cumulus4j/store/test/framework already added, skipping
[INFO] org/cumulus4j/store/test/collection already added, skipping
[INFO] org/cumulus4j/store/test/collection/join already added, skipping
[INFO] org/cumulus4j/store/test/collection/mappedby already added, skipping
[INFO] org/cumulus4j/store/test/datatype already added, skipping
[INFO] LICENCE.txt already added, skipping
[INFO] META-INF/MANIFEST.MF already added, skipping
[INFO] 
[INFO] --- maven-install-plugin:2.4:install (default-install) @ org.cumulus4j.store.test ---
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/target/org.cumulus4j.store.test-1.2.1-SNAPSHOT.jar to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.store.test/1.2.1-SNAPSHOT/org.cumulus4j.store.test-1.2.1-SNAPSHOT.jar
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/pom.xml to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.store.test/1.2.1-SNAPSHOT/org.cumulus4j.store.test-1.2.1-SNAPSHOT.pom
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/target/org.cumulus4j.store.test-1.2.1-SNAPSHOT-tests.jar to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.store.test/1.2.1-SNAPSHOT/org.cumulus4j.store.test-1.2.1-SNAPSHOT-tests.jar
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/target/org.cumulus4j.store.test-1.2.1-SNAPSHOT-sources.jar to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.store.test/1.2.1-SNAPSHOT/org.cumulus4j.store.test-1.2.1-SNAPSHOT-sources.jar