10:53:43,824 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
10:53:43,824 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:43,826 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
10:53:43,833 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
10:53:43,833 INFO [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.isEmpty()" and param "ElementA[name="S.Element 3.2"]":
10:53:43,833 INFO [main][General] >> result=Owner 5
10:53:43,833 INFO [main][ElementASetQueryTest] invoke: * Owner 5:
10:53:44,597 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:53:44,599 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:53:44,612 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:53:44,615 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:53:47,106 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:53:47,106 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:53:47,106 INFO [main][Cumulus4jStoreManager] =======================================================
10:53:47,108 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:53:47,108 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:53:47,130 INFO [main][MinimumCumulus4jVersion] version=10100001
10:53:47,131 INFO [main][MinimumCumulus4jVersion] version=10100001
10:53:47,137 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.join.ElementASetOwner" not found !
10:53:47,138 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.join.ElementA" not found !
10:53:47,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
10:53:47,253 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
10:53:47,254 INFO [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.size() == 3" and param "ElementA[name="S.Element 3.2"]":
10:53:47,254 INFO [main][General] >> result=Owner 3
10:53:47,254 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.1, S.Element 3.3, S.Element 3.2
10:53:47,255 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
10:53:47,256 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,256 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
10:53:47,260 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
10:53:47,261 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
10:53:47,261 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
10:53:47,262 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
10:53:47,263 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
10:53:47,264 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
10:53:47,264 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
10:53:47,265 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
10:53:47,266 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
10:53:47,266 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
10:53:47,267 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
10:53:47,268 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
10:53:47,269 INFO [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "ElementA[name="S.Element 3.2"]":
10:53:47,269 INFO [main][General] >> result=Owner 1
10:53:47,269 INFO [main][ElementASetQueryTest] invoke: * Owner 1: S.Element 1.2, S.Element 1.4, S.Element 1.3, S.Element 1.1
10:53:47,269 INFO [main][General] >> result=Owner 2
10:53:47,269 INFO [main][ElementASetQueryTest] invoke: * Owner 2: S.Element 2.1, S.Element 2.2, S.Element 2.3, S.Element 2.4
10:53:47,269 INFO [main][General] >> result=Owner 3
10:53:47,269 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.1, S.Element 3.3, S.Element 3.2
10:53:47,270 INFO [main][General] >> result=Owner 4
10:53:47,270 INFO [main][ElementASetQueryTest] invoke: * Owner 4: S.Element 4.3
10:53:47,272 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
10:53:47,272 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,273 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
10:53:47,275 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
10:53:47,276 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
10:53:47,277 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
10:53:47,278 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
10:53:47,278 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
10:53:47,279 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
10:53:47,280 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
10:53:47,281 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
10:53:47,281 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
10:53:47,282 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
10:53:47,283 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
10:53:47,284 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
10:53:47,285 INFO [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "ElementA[name="S.Element 4.3"]":
10:53:47,285 INFO [main][General] >> result=Owner 1
10:53:47,285 INFO [main][ElementASetQueryTest] invoke: * Owner 1: S.Element 1.4, S.Element 1.1, S.Element 1.2, S.Element 1.3
10:53:47,285 INFO [main][General] >> result=Owner 2
10:53:47,285 INFO [main][ElementASetQueryTest] invoke: * Owner 2: S.Element 2.4, S.Element 2.1, S.Element 2.2, S.Element 2.3
10:53:47,285 INFO [main][General] >> result=Owner 3
10:53:47,285 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.2, S.Element 3.1, S.Element 3.3
10:53:47,286 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
10:53:47,287 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,294 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
10:53:47,295 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
10:53:47,296 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
10:53:47,297 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
10:53:47,297 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
10:53:47,298 INFO [main][ElementASetQueryTest] invoke: found 2 ElementASetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
10:53:47,298 INFO [main][General] >> result=Owner 3
10:53:47,298 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.2, S.Element 3.1, S.Element 3.3
10:53:47,298 INFO [main][General] >> result=Owner 5
10:53:47,298 INFO [main][ElementASetQueryTest] invoke: * Owner 5:
10:53:47,300 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
10:53:47,300 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,302 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
10:53:47,304 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
10:53:47,304 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,305 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
10:53:47,306 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
10:53:47,307 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
10:53:47,308 INFO [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.contains(:element)" and param "ElementA[name="S.Element 3.2"]":
10:53:47,308 INFO [main][General] >> result=Owner 3
10:53:47,308 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.2, S.Element 3.1, S.Element 3.3
10:53:47,309 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
10:53:47,310 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,317 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
10:53:47,318 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
10:53:47,319 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
10:53:47,320 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
10:53:47,321 INFO [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
10:53:47,321 INFO [main][General] >> result=Owner 1
10:53:47,321 INFO [main][ElementASetQueryTest] invoke: * Owner 1: S.Element 1.4, S.Element 1.1, S.Element 1.3, S.Element 1.2
10:53:47,321 INFO [main][General] >> result=Owner 2
10:53:47,321 INFO [main][ElementASetQueryTest] invoke: * Owner 2: S.Element 2.3, S.Element 2.2, S.Element 2.4, S.Element 2.1
10:53:47,321 INFO [main][General] >> result=Owner 4
10:53:47,321 INFO [main][ElementASetQueryTest] invoke: * Owner 4: S.Element 4.3
10:53:47,323 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
10:53:47,323 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,324 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
10:53:47,328 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
10:53:47,329 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
10:53:47,330 INFO [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "ElementA[name="S.Element 3.2"]":
10:53:47,330 INFO [main][General] >> result=Owner 3
10:53:47,330 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.2, S.Element 3.1, S.Element 3.3
10:53:47,331 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
10:53:47,332 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,333 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
10:53:47,335 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
10:53:47,336 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
10:53:47,336 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
10:53:47,338 INFO [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "!this.set.contains(:element)" and param "ElementA[name="S.Element 3.2"]":
10:53:47,338 INFO [main][General] >> result=Owner 4
10:53:47,338 INFO [main][ElementASetQueryTest] invoke: * Owner 4: S.Element 4.3
10:53:47,338 INFO [main][General] >> result=Owner 5
10:53:47,338 INFO [main][ElementASetQueryTest] invoke: * Owner 5:
10:53:47,338 INFO [main][General] >> result=Owner 1
10:53:47,338 INFO [main][ElementASetQueryTest] invoke: * Owner 1: S.Element 1.1, S.Element 1.3, S.Element 1.4, S.Element 1.2
10:53:47,338 INFO [main][General] >> result=Owner 2
10:53:47,338 INFO [main][ElementASetQueryTest] invoke: * Owner 2: S.Element 2.2, S.Element 2.1, S.Element 2.4, S.Element 2.3
10:53:47,340 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
10:53:47,340 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,347 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
10:53:47,349 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
10:53:47,349 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
10:53:47,350 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
10:53:47,351 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
10:53:47,352 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
10:53:47,353 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
10:53:47,354 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
10:53:47,354 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
10:53:47,355 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
10:53:47,356 INFO [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
10:53:47,357 INFO [main][General] >> result=Owner 1
10:53:47,357 INFO [main][ElementASetQueryTest] invoke: * Owner 1: S.Element 1.4, S.Element 1.1, S.Element 1.3, S.Element 1.2
10:53:47,357 INFO [main][General] >> result=Owner 2
10:53:47,357 INFO [main][ElementASetQueryTest] invoke: * Owner 2: S.Element 2.1, S.Element 2.2, S.Element 2.3, S.Element 2.4
10:53:47,357 INFO [main][General] >> result=Owner 3
10:53:47,357 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.3, S.Element 3.1, S.Element 3.2
10:53:47,358 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
10:53:47,358 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,365 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
10:53:47,366 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
10:53:47,367 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
10:53:47,368 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
10:53:47,369 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
10:53:47,370 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
10:53:47,371 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
10:53:47,372 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
10:53:47,373 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
10:53:47,373 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
10:53:47,375 INFO [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
10:53:47,375 INFO [main][General] >> result=Owner 1
10:53:47,375 INFO [main][ElementASetQueryTest] invoke: * Owner 1: S.Element 1.4, S.Element 1.1, S.Element 1.3, S.Element 1.2
10:53:47,375 INFO [main][General] >> result=Owner 2
10:53:47,375 INFO [main][ElementASetQueryTest] invoke: * Owner 2: S.Element 2.1, S.Element 2.4, S.Element 2.3, S.Element 2.2
10:53:47,375 INFO [main][General] >> result=Owner 3
10:53:47,375 INFO [main][ElementASetQueryTest] invoke: * Owner 3: S.Element 3.3, S.Element 3.2, S.Element 3.1
10:53:47,377 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
10:53:47,377 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,378 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
10:53:47,382 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
10:53:47,383 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
10:53:47,384 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
10:53:47,386 INFO [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "ElementA[name="S.Element 3.2"]":
10:53:47,386 INFO [main][General] >> result=Owner 4
10:53:47,386 INFO [main][ElementASetQueryTest] invoke: * Owner 4: S.Element 4.3
10:53:47,386 INFO [main][General] >> result=Owner 5
10:53:47,386 INFO [main][ElementASetQueryTest] invoke: * Owner 5:
10:53:47,386 INFO [main][General] >> result=Owner 1
10:53:47,386 INFO [main][ElementASetQueryTest] invoke: * Owner 1: S.Element 1.4, S.Element 1.1, S.Element 1.2, S.Element 1.3
10:53:47,386 INFO [main][General] >> result=Owner 2
10:53:47,386 INFO [main][ElementASetQueryTest] invoke: * Owner 2: S.Element 2.3, S.Element 2.2, S.Element 2.4, S.Element 2.1
10:53:47,388 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
10:53:47,388 INFO [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
10:53:47,390 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
10:53:47,392 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
10:53:47,392 INFO [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.isEmpty()" and param "ElementA[name="S.Element 3.2"]":
10:53:47,392 INFO [main][General] >> result=Owner 5
10:53:47,392 INFO [main][ElementASetQueryTest] invoke: * Owner 5:
10:53:47,393 INFO [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 26, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.831 sec
Running org.cumulus4j.store.test.collection.mappedby.Element3MapQueryTest
10:53:48,266 INFO [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
10:53:48,911 INFO [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
10:53:48,912 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:53:48,923 INFO [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
10:53:48,923 WARN [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
10:53:48,924 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:53:48,924 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:53:48,938 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:53:49,164 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:53:55,276 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:53:55,276 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:53:55,276 INFO [main][Cumulus4jStoreManager] =======================================================
10:53:55,278 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:53:55,278 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:53:55,413 INFO [main][MinimumCumulus4jVersion] version=10100001
10:53:55,545 INFO [main][MinimumCumulus4jVersion] version=10100001
10:53:55,664 INFO [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element3MapOwner" not found !
10:53:55,669 INFO [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element3" not found !
10:53:55,852 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
10:53:55,862 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsKey(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
10:53:55,863 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ccc", name="Element 1.3"]=ccc
10:53:55,863 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * Owner 2: Element3[value="dd", name="Element 2.4"]=dd, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="cc", name="Element 2.3"]=cc
10:53:55,863 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
10:53:55,865 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
10:53:55,865 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:55,869 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
10:53:55,871 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsValue(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
10:53:55,872 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * Owner 1: Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="aaa", name="Element 1.1"]=aaa
10:53:55,872 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * Owner 2: Element3[value="aa", name="Element 2.1"]=aa, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="dd", name="Element 2.4"]=dd
10:53:55,872 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
10:53:55,873 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
10:53:55,874 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:55,881 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
10:53:55,887 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
10:53:55,888 INFO [main][Element3MapQueryTest] queryContainsKeyParameter: found 1 Element3MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
10:53:55,888 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
10:53:55,889 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
10:53:55,890 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:55,891 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
10:53:55,893 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
10:53:55,898 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
10:53:55,900 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: found 5 Element3MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
10:53:55,900 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
10:53:55,901 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ddd", name="Element 1.4"]=ddd
10:53:55,901 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 5:
10:53:55,901 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
10:53:55,901 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 2: Element3[value="aa", name="Element 2.1"]=aa, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="dd", name="Element 2.4"]=dd
10:53:55,902 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
10:53:55,903 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:55,905 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
10:53:55,907 INFO [main][Element3MapQueryTest] queryContainsValueParameter: found 2 Element3MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "ccc":
10:53:55,908 INFO [main][Element3MapQueryTest] queryContainsValueParameter: * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
10:53:55,908 INFO [main][Element3MapQueryTest] queryContainsValueParameter: * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="bbb", name="Element 1.2"]=bbb
10:53:55,909 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
10:53:55,910 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:55,911 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
10:53:55,912 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
10:53:55,914 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: found 4 Element3MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "ccc":
10:53:55,914 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * Owner 5:
10:53:55,914 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
10:53:55,914 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * Owner 2: Element3[value="dd", name="Element 2.4"]=dd, Element3[value="bb", name="Element 2.2"]=bb, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="cc", name="Element 2.3"]=cc
10:53:55,914 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * 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
10:53:56,430 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:53:56,434 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:53:56,460 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:53:56,932 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:53:58,943 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:53:58,943 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:53:58,943 INFO [main][Cumulus4jStoreManager] =======================================================
10:53:58,944 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:53:58,944 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:53:58,973 INFO [main][MinimumCumulus4jVersion] version=10100001
10:53:58,974 INFO [main][MinimumCumulus4jVersion] version=10100001
10:53:58,982 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element3MapOwner" not found !
10:53:58,984 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element3" not found !
10:53:59,123 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
10:53:59,125 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsKey(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
10:53:59,126 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ccc", name="Element 1.3"]=ccc
10:53:59,126 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * 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
10:53:59,126 INFO [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
10:53:59,128 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
10:53:59,128 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:59,132 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
10:53:59,134 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsValue(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
10:53:59,134 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ddd", name="Element 1.4"]=ddd
10:53:59,134 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * 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
10:53:59,134 INFO [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
10:53:59,136 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
10:53:59,136 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:59,137 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
10:53:59,139 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
10:53:59,140 INFO [main][Element3MapQueryTest] queryContainsKeyParameter: found 1 Element3MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
10:53:59,140 INFO [main][Element3MapQueryTest] queryContainsKeyParameter: * 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
10:53:59,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
10:53:59,141 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:59,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
10:53:59,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
10:53:59,145 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
10:53:59,147 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: found 5 Element3MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
10:53:59,147 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 2: Element3[value="cc", name="Element 2.3"]=cc, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="bb", name="Element 2.2"]=bb
10:53:59,148 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
10:53:59,148 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
10:53:59,148 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 5:
10:53:59,148 INFO [main][Element3MapQueryTest] queryNotContainsKeyParameter: * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
10:53:59,150 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
10:53:59,150 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:59,152 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
10:53:59,153 INFO [main][Element3MapQueryTest] queryContainsValueParameter: found 2 Element3MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "ccc":
10:53:59,153 INFO [main][Element3MapQueryTest] queryContainsValueParameter: * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ddd", name="Element 1.4"]=ddd
10:53:59,153 INFO [main][Element3MapQueryTest] queryContainsValueParameter: * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
10:53:59,155 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
10:53:59,155 INFO [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
10:53:59,157 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
10:53:59,158 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
10:53:59,160 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: found 4 Element3MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "ccc":
10:53:59,160 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * Owner 2: Element3[value="bb", name="Element 2.2"]=bb, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="cc", name="Element 2.3"]=cc
10:53:59,160 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * 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
10:53:59,160 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * Owner 5:
10:53:59,160 INFO [main][Element3MapQueryTest] queryNotContainsValueParameter: * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
10:53:59,160 INFO [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 12, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.669 sec
Running org.cumulus4j.store.test.collection.mappedby.Element2MapQueryTest
10:53:59,941 INFO [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
10:54:00,866 INFO [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
10:54:00,867 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:00,878 INFO [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
10:54:00,878 WARN [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
10:54:00,879 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:54:00,879 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:00,897 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:54:01,309 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:54:06,650 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:54:06,651 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:54:06,651 INFO [main][Cumulus4jStoreManager] =======================================================
10:54:06,654 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:54:06,655 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:54:06,766 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:06,892 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:07,028 INFO [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element2MapOwner" not found !
10:54:07,032 INFO [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element2" not found !
10:54:07,206 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
10:54:07,216 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
10:54:07,217 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"]
10:54:07,217 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"]
10:54:07,217 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:07,218 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
10:54:07,219 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,228 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
10:54:07,234 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) < 0" and param "bb":
10:54:07,234 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"]
10:54:07,234 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"]
10:54:07,234 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"]
10:54:07,235 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:07,236 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
10:54:07,236 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,243 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
10:54:07,245 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
10:54:07,245 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"]
10:54:07,246 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"]
10:54:07,246 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:07,247 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
10:54:07,247 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,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.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
10:54:07,255 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && !(variable.indexOf(:queryParam) >= 0)" and param "bb":
10:54:07,255 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"]
10:54:07,255 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"]
10:54:07,256 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"]
10:54:07,256 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:07,257 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
10:54:07,258 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,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.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
10:54:07,269 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && !(variable.name.indexOf(:queryParam) >= 0)" and param "4":
10:54:07,269 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"]
10:54:07,270 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"]
10:54:07,270 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"]
10:54:07,270 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:07,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
10:54:07,271 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,278 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
10:54:07,282 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) < 0" and param "4":
10:54:07,283 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"]
10:54:07,283 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"]
10:54:07,283 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"]
10:54:07,283 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:07,285 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
10:54:07,285 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,292 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
10:54:07,294 INFO [main][Element2MapQueryTest] queryContainsKeyParameter: found 2 Element2MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "ccc":
10:54:07,294 INFO [main][Element2MapQueryTest] queryContainsKeyParameter: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:07,294 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"]
10:54:07,295 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
10:54:07,296 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,297 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
10:54:07,303 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
10:54:07,305 INFO [main][Element2MapQueryTest] queryNotContainsKeyParameter: found 4 Element2MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "ccc":
10:54:07,305 INFO [main][Element2MapQueryTest] queryNotContainsKeyParameter: * Owner 5:
10:54:07,305 INFO [main][Element2MapQueryTest] queryNotContainsKeyParameter: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:07,305 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"]
10:54:07,305 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"]
10:54:07,306 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
10:54:07,307 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,308 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
10:54:07,315 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
10:54:07,316 INFO [main][Element2MapQueryTest] queryContainsValueParameter: found 1 Element2MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
10:54:07,316 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"]
10:54:07,317 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
10:54:07,318 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:07,319 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
10:54:07,321 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
10:54:07,322 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
10:54:07,325 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: found 5 Element2MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
10:54:07,325 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:07,325 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"]
10:54:07,325 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: * Owner 5:
10:54:07,325 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:07,325 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"]
10:54:08,279 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:54:08,282 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:08,300 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:54:08,478 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:54:10,814 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:54:10,814 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:54:10,814 INFO [main][Cumulus4jStoreManager] =======================================================
10:54:10,815 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:54:10,815 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:54:10,835 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:10,836 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:10,844 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element2MapOwner" not found !
10:54:10,845 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element2" not found !
10:54:11,001 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
10:54:11,004 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
10:54:11,004 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"]
10:54:11,004 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"]
10:54:11,004 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:11,006 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
10:54:11,006 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,009 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
10:54:11,018 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) < 0" and param "bb":
10:54:11,019 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"]
10:54:11,019 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"]
10:54:11,019 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"]
10:54:11,019 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:11,021 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
10:54:11,021 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,028 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
10:54:11,030 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
10:54:11,030 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"]
10:54:11,030 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"]
10:54:11,030 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:11,032 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
10:54:11,032 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,036 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
10:54:11,041 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && !(variable.indexOf(:queryParam) >= 0)" and param "bb":
10:54:11,041 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"]
10:54:11,041 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"]
10:54:11,041 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"]
10:54:11,041 INFO [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:11,043 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
10:54:11,043 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,050 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
10:54:11,054 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && !(variable.name.indexOf(:queryParam) >= 0)" and param "4":
10:54:11,054 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"]
10:54:11,055 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"]
10:54:11,055 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"]
10:54:11,055 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:11,058 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
10:54:11,059 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,066 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
10:54:11,070 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) < 0" and param "4":
10:54:11,071 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"]
10:54:11,071 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"]
10:54:11,071 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"]
10:54:11,071 INFO [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:11,073 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
10:54:11,073 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,075 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
10:54:11,077 INFO [main][Element2MapQueryTest] queryContainsKeyParameter: found 2 Element2MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "ccc":
10:54:11,077 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"]
10:54:11,077 INFO [main][Element2MapQueryTest] queryContainsKeyParameter: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:11,078 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
10:54:11,078 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,080 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
10:54:11,081 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
10:54:11,082 INFO [main][Element2MapQueryTest] queryNotContainsKeyParameter: found 4 Element2MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "ccc":
10:54:11,083 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"]
10:54:11,083 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"]
10:54:11,083 INFO [main][Element2MapQueryTest] queryNotContainsKeyParameter: * Owner 5:
10:54:11,083 INFO [main][Element2MapQueryTest] queryNotContainsKeyParameter: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:11,084 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
10:54:11,085 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,086 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
10:54:11,087 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
10:54:11,088 INFO [main][Element2MapQueryTest] queryContainsValueParameter: found 1 Element2MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
10:54:11,088 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"]
10:54:11,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
10:54:11,089 INFO [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
10:54:11,091 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
10:54:11,092 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
10:54:11,093 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
10:54:11,095 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: found 5 Element2MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
10:54:11,096 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"]
10:54:11,096 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
10:54:11,096 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"]
10:54:11,096 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: * Owner 5:
10:54:11,096 INFO [main][Element2MapQueryTest] queryNotContainsValueParameter: * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
10:54:11,096 INFO [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.936 sec
Running org.cumulus4j.store.test.collection.mappedby.Element1SetQueryTest
10:54:11,876 INFO [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
10:54:12,255 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:54:12,383 INFO [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
10:54:12,384 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:12,395 INFO [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
10:54:12,395 WARN [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
10:54:12,396 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:54:12,396 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:12,409 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:54:17,955 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:54:17,956 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:54:17,956 INFO [main][Cumulus4jStoreManager] =======================================================
10:54:17,957 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:54:17,957 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:54:18,110 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:18,218 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:18,320 INFO [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element1SetOwner" not found !
10:54:18,323 INFO [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element1" not found !
10:54:18,440 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
10:54:18,453 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
10:54:18,456 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 4.3"]":
10:54:18,457 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: * Owner 1: Element 1.3, Element 1.1, Element 1.2, Element 1.4
10:54:18,457 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: * Owner 2: Element 2.3, Element 2.2, Element 2.4, Element 2.1
10:54:18,457 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: * Owner 3: Element 3.3, Element 3.1, Element 3.2
10:54:18,458 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
10:54:18,458 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,469 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
10:54:18,476 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
10:54:18,476 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: found 2 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
10:54:18,477 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: * Owner 5:
10:54:18,477 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: * Owner 3: Element 3.3, Element 3.1, Element 3.2
10:54:18,478 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
10:54:18,478 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,479 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
10:54:18,484 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
10:54:18,485 INFO [main][Element1SetQueryTest] queryContainsParameter: found 1 Element1SetOwners for query-filter "this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
10:54:18,485 INFO [main][Element1SetQueryTest] queryContainsParameter: * Owner 3: Element 3.3, Element 3.1, Element 3.2
10:54: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
10:54:18,486 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,492 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
10:54:18,494 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
10:54:18,494 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: * Owner 1: Element 1.1, Element 1.4, Element 1.3, Element 1.2
10:54:18,494 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: * Owner 2: Element 2.2, Element 2.1, Element 2.3, Element 2.4
10:54:18,494 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: * Owner 4: Element 4.3
10:54:18,495 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
10:54:18,495 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,496 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
10:54:18,500 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
10:54:18,500 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: found 1 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
10:54:18,501 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: * Owner 3: Element 3.1, Element 3.2, Element 3.3
10:54:18,502 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
10:54:18,502 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,503 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
10:54:18,504 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
10:54:18,505 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
10:54:18,506 INFO [main][Element1SetQueryTest] queryNotContainsParameter: found 4 Element1SetOwners for query-filter "!this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
10:54:18,507 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 4: Element 4.3
10:54:18,507 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 1: Element 1.2, Element 1.1, Element 1.3, Element 1.4
10:54:18,507 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 5:
10:54:18,507 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 2: Element 2.3, Element 2.1, Element 2.4, Element 2.2
10:54:18,508 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
10:54:18,508 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,520 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
10:54:18,523 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
10:54:18,523 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: * Owner 1: Element 1.1, Element 1.3, Element 1.2, Element 1.4
10:54:18,524 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: * Owner 2: Element 2.3, Element 2.1, Element 2.2, Element 2.4
10:54:18,524 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: * Owner 3: Element 3.3, Element 3.2, Element 3.1
10:54:18,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
10:54:18,525 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,531 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
10:54:18,535 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
10:54:18,535 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: * Owner 1: Element 1.4, Element 1.3, Element 1.2, Element 1.1
10:54:18,535 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: * Owner 2: Element 2.2, Element 2.3, Element 2.4, Element 2.1
10:54:18,535 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: * Owner 3: Element 3.3, Element 3.2, Element 3.1
10:54:18,537 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
10:54:18,537 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,538 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
10:54:18,541 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
10:54:18,542 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
10:54:18,543 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: found 4 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
10:54:18,543 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 4: Element 4.3
10:54:18,543 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 1: Element 1.2, Element 1.1, Element 1.3, Element 1.4
10:54:18,543 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 5:
10:54:18,544 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 2: Element 2.4, Element 2.2, Element 2.1, Element 2.3
10:54:18,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
10:54:18,545 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:18,546 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
10:54:18,547 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
10:54:18,551 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: found 4 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 3.2"]":
10:54:18,551 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 1: Element 1.1, Element 1.4, Element 1.3, Element 1.2
10:54:18,551 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 2: Element 2.1, Element 2.2, Element 2.3, Element 2.4
10:54:18,551 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 3: Element 3.1, Element 3.2, Element 3.3
10:54:18,551 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 4: Element 4.3
10:54:19,396 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:54:19,397 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:54:19,398 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:19,414 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:54:22,108 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:54:22,108 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:54:22,108 INFO [main][Cumulus4jStoreManager] =======================================================
10:54:22,109 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:54:22,109 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:54:22,142 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:22,143 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:22,153 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element1SetOwner" not found !
10:54:22,155 INFO [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element1" not found !
10:54:22,278 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
10:54:22,284 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
10:54:22,287 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 4.3"]":
10:54:22,287 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: * Owner 1: Element 1.2, Element 1.4, Element 1.3, Element 1.1
10:54:22,288 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: * Owner 2: Element 2.2, Element 2.1, Element 2.3, Element 2.4
10:54:22,288 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: * Owner 3: Element 3.1, Element 3.3, Element 3.2
10:54:22,289 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
10:54:22,290 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,296 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
10:54:22,298 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
10:54:22,304 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: found 2 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
10:54:22,304 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: * Owner 3: Element 3.1, Element 3.2, Element 3.3
10:54:22,304 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: * Owner 5:
10:54:22,306 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
10:54:22,306 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,307 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
10:54:22,309 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
10:54:22,310 INFO [main][Element1SetQueryTest] queryContainsParameter: found 1 Element1SetOwners for query-filter "this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
10:54:22,310 INFO [main][Element1SetQueryTest] queryContainsParameter: * Owner 3: Element 3.2, Element 3.1, Element 3.3
10:54:22,311 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
10:54:22,311 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,318 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
10:54:22,320 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
10:54:22,320 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: * Owner 1: Element 1.4, Element 1.3, Element 1.2, Element 1.1
10:54:22,321 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: * Owner 2: Element 2.4, Element 2.1, Element 2.2, Element 2.3
10:54:22,321 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: * Owner 4: Element 4.3
10:54:22,322 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
10:54:22,322 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,324 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
10:54:22,328 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
10:54:22,328 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: found 1 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
10:54:22,329 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: * Owner 3: Element 3.3, Element 3.1, Element 3.2
10:54:22,331 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
10:54:22,332 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,333 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
10:54:22,334 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
10:54:22,335 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
10:54:22,337 INFO [main][Element1SetQueryTest] queryNotContainsParameter: found 4 Element1SetOwners for query-filter "!this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
10:54:22,337 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 4: Element 4.3
10:54:22,337 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 1: Element 1.1, Element 1.4, Element 1.3, Element 1.2
10:54:22,337 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 5:
10:54:22,337 INFO [main][Element1SetQueryTest] queryNotContainsParameter: * Owner 2: Element 2.1, Element 2.3, Element 2.2, Element 2.4
10:54:22,339 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
10:54:22,339 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,346 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
10:54:22,349 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
10:54:22,350 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: * Owner 1: Element 1.2, Element 1.1, Element 1.4, Element 1.3
10:54:22,350 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: * Owner 2: Element 2.1, Element 2.2, Element 2.4, Element 2.3
10:54:22,350 INFO [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: * Owner 3: Element 3.3, Element 3.2, Element 3.1
10:54:22,351 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
10:54:22,352 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,359 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
10:54:22,363 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
10:54:22,363 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: * Owner 1: Element 1.4, Element 1.3, Element 1.1, Element 1.2
10:54:22,363 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: * Owner 2: Element 2.2, Element 2.1, Element 2.4, Element 2.3
10:54:22,364 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: * Owner 3: Element 3.3, Element 3.1, Element 3.2
10:54:22,365 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
10:54:22,365 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,367 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
10:54:22,371 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
10:54:22,372 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
10:54:22,373 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: found 4 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
10:54:22,373 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 4: Element 4.3
10:54:22,373 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 1: Element 1.3, Element 1.2, Element 1.4, Element 1.1
10:54:22,373 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 5:
10:54:22,373 INFO [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: * Owner 2: Element 2.4, Element 2.3, Element 2.2, Element 2.1
10:54:22,375 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
10:54:22,375 INFO [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
10:54:22,376 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
10:54:22,378 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
10:54:22,382 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: found 4 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 3.2"]":
10:54:22,382 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 1: Element 1.3, Element 1.2, Element 1.1, Element 1.4
10:54:22,382 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 2: Element 2.4, Element 2.1, Element 2.2, Element 2.3
10:54:22,382 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 3: Element 3.2, Element 3.3, Element 3.1
10:54:22,382 INFO [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: * Owner 4: Element 4.3
10:54:22,383 INFO [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.233 sec
Running org.cumulus4j.store.test.datatype.StandardOneToOneTypesTest
10:54:23,121 INFO [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
10:54:23,207 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:54:23,883 INFO [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
10:54:23,885 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:23,893 INFO [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
10:54:23,893 WARN [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
10:54:23,894 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:54:23,894 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:23,908 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:54:29,634 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:54:29,635 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:54:29,635 INFO [main][Cumulus4jStoreManager] =======================================================
10:54:29,682 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:54:29,682 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:54:29,781 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:29,913 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:31,112 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:54:31,351 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
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 05869d85-927a-442e-8a69-b6da408a2be3
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 18340b8c-6758-40bd-831d-491df7d6ac4b
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 19519458-a886-491a-9cdc-eb874e4ca4f3
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 22328b0f-f980-40d0-ac13-2fb69fb4d6e9
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 229dbd5d-55e0-483a-80a0-aabc25ab5722
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 2ed2bbb3-9e70-4d35-8c80-f285ed69735c
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 31da5282-84cc-4bbd-b76b-9f1527f37110
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 32807abd-ebc9-4a0a-a3b8-fc1a9dbcae35
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 3475e5f8-1719-4f72-9ec7-d25082708df7
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 45d1d03f-924e-4682-88c5-d770e8c87839
10:54:31,356 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5516d54e-ef3e-497b-951e-6983e22b1913
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5517853a-afe2-4fa2-8cce-7c3b18a78cd1
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 58555f85-8b42-4d39-8e11-7b9d4590efd2
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6120c244-ef2c-4f5b-a2b5-5a25f9521256
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 614ca3dc-6c6e-4240-b72d-0fd250435b86
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6636dacd-d4d8-45df-99fb-f76fdb957b35
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = b80572c7-a050-4ac2-a530-d6f73265f644
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = be1b6f6a-f3e5-413f-9616-80431d154567
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = be3e9891-119c-4fe9-af8d-1a5927c8273c
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = c68dbd49-b16a-4255-8139-3764404e397c
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = ce5c5c44-0a90-47f0-9073-71685ac439c0
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = cfd8552e-c579-4bce-b13a-001700ac0700
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = d46cd4dc-786a-4138-8167-0bfb2b095501
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = e594434d-9370-460c-bcd4-40f7a5883a8c
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = e9dbc3eb-0d31-4f2b-9945-5df4255da630
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = f362522d-9c09-40d3-8ec5-c55ad95b07a4
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = f79a5985-56ff-4122-8246-69a716914529
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = f8410039-e107-4da9-b0c0-1989a6f08f18
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = fa1faa26-569a-43c8-b648-e03023aaa604
10:54:31,357 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = fd01ffff-ddb2-42b1-8d1b-0bac1248751c
10:54:32,567 INFO [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
10:54:32,570 INFO [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
10:54:32,594 INFO [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
10:54:35,329 INFO [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:54:35,451 INFO [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:54:35,451 INFO [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:54:35,451 INFO [main][Cumulus4jStoreManager] =======================================================
10:54:35,453 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:54:35,453 INFO [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:54:35,475 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:35,476 INFO [main][MinimumCumulus4jVersion] version=10100001
10:54:35,960 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
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 05869d85-927a-442e-8a69-b6da408a2be3
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 18340b8c-6758-40bd-831d-491df7d6ac4b
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 19519458-a886-491a-9cdc-eb874e4ca4f3
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 22328b0f-f980-40d0-ac13-2fb69fb4d6e9
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 229dbd5d-55e0-483a-80a0-aabc25ab5722
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 2ed2bbb3-9e70-4d35-8c80-f285ed69735c
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 31da5282-84cc-4bbd-b76b-9f1527f37110
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 32807abd-ebc9-4a0a-a3b8-fc1a9dbcae35
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 3475e5f8-1719-4f72-9ec7-d25082708df7
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 45d1d03f-924e-4682-88c5-d770e8c87839
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5516d54e-ef3e-497b-951e-6983e22b1913
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5517853a-afe2-4fa2-8cce-7c3b18a78cd1
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 58555f85-8b42-4d39-8e11-7b9d4590efd2
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6120c244-ef2c-4f5b-a2b5-5a25f9521256
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 614ca3dc-6c6e-4240-b72d-0fd250435b86
10:54:35,964 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6636dacd-d4d8-45df-99fb-f76fdb957b35
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = b80572c7-a050-4ac2-a530-d6f73265f644
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = be1b6f6a-f3e5-413f-9616-80431d154567
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = be3e9891-119c-4fe9-af8d-1a5927c8273c
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = c68dbd49-b16a-4255-8139-3764404e397c
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = ce5c5c44-0a90-47f0-9073-71685ac439c0
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = cfd8552e-c579-4bce-b13a-001700ac0700
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = d46cd4dc-786a-4138-8167-0bfb2b095501
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = e594434d-9370-460c-bcd4-40f7a5883a8c
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = e9dbc3eb-0d31-4f2b-9945-5df4255da630
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = f362522d-9c09-40d3-8ec5-c55ad95b07a4
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = f79a5985-56ff-4122-8246-69a716914529
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = f8410039-e107-4da9-b0c0-1989a6f08f18
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = fa1faa26-569a-43c8-b648-e03023aaa604
10:54:35,965 INFO [main][StandardOneToOneTypesTest] * foundEntity.uuid = fd01ffff-ddb2-42b1-8d1b-0bac1248751c
10:54:35,989 INFO [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 13.786 sec
Results :
Failed tests:
queryQueryableField.0(org.cumulus4j.store.test.metadata.MetaDataTest): Wrong number of result elements! expected:<2> but was:<4>
queryQueryableField.1(org.cumulus4j.store.test.metadata.MetaDataTest): Wrong number of result elements! expected:<2> but was:<4>
Tests run: 361, Failures: 2, Errors: 0, Skipped: 2
[ERROR] There are test failures.
Please refer to /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.test/target/surefire-reports for the individual test results.
[JENKINS] Recording test results
[INFO]
[INFO] --- maven-jar-plugin:2.3.1:jar (default-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.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