UnstableConsole Output

Skipping 3,030 KB.. Full Log
MinimumCumulus4jVersion] version=10100001
08:58:11,834 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:11,842 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.join.ElementASetOwner" not found !
08:58:11,843 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.join.ElementA" not found !
08:58:11,961 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
08:58:11,967 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
08:58:11,969 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.size() == 3" and param "ElementA[name="S.Element 3.2"]":
08:58:11,969 INFO  [main][General] >> result=Owner 3
08:58:11,969 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.3, S.Element 3.2, S.Element 3.1
08:58:11,972 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
08:58:11,972 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:11,974 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
08:58:11,979 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
08:58:11,980 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
08:58:11,982 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
08:58:11,983 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
08:58:11,984 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
08:58:11,985 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
08:58:11,986 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
08:58:11,987 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
08:58:11,988 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
08:58:11,989 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
08:58:11,990 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
08:58:11,991 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
08:58:11,993 INFO  [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "ElementA[name="S.Element 3.2"]":
08:58:11,993 INFO  [main][General] >> result=Owner 1
08:58:11,993 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.4, S.Element 1.1, S.Element 1.2, S.Element 1.3
08:58:11,993 INFO  [main][General] >> result=Owner 2
08:58:11,993 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.2, S.Element 2.4, S.Element 2.1, S.Element 2.3
08:58:11,993 INFO  [main][General] >> result=Owner 3
08:58:11,993 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.2, S.Element 3.3, S.Element 3.1
08:58:11,993 INFO  [main][General] >> result=Owner 4
08:58:11,994 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
08:58:11,997 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
08:58:11,997 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:11,999 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
08:58:12,001 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
08:58:12,002 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
08:58:12,003 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
08:58:12,004 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
08:58:12,005 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
08:58:12,006 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
08:58:12,007 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
08:58:12,008 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
08:58:12,008 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
08:58:12,009 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
08:58:12,010 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
08:58:12,011 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
08:58:12,012 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "ElementA[name="S.Element 4.3"]":
08:58:12,012 INFO  [main][General] >> result=Owner 1
08:58:12,012 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.3, S.Element 1.4, S.Element 1.1, S.Element 1.2
08:58:12,013 INFO  [main][General] >> result=Owner 2
08:58:12,013 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.4, S.Element 2.1, S.Element 2.2, S.Element 2.3
08:58:12,013 INFO  [main][General] >> result=Owner 3
08:58:12,013 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.1, S.Element 3.3, S.Element 3.2
08:58:12,014 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
08:58:12,015 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,023 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
08:58:12,025 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
08:58:12,026 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
08:58:12,027 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
08:58:12,027 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
08:58:12,029 INFO  [main][ElementASetQueryTest] invoke: found 2 ElementASetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
08:58:12,029 INFO  [main][General] >> result=Owner 3
08:58:12,029 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.1, S.Element 3.3, S.Element 3.2
08:58:12,029 INFO  [main][General] >> result=Owner 5
08:58:12,029 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
08:58:12,030 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
08:58:12,031 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,033 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
08:58:12,035 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
08:58:12,035 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,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.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
08:58:12,038 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
08:58:12,039 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
08:58:12,040 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.contains(:element)" and param "ElementA[name="S.Element 3.2"]":
08:58:12,040 INFO  [main][General] >> result=Owner 3
08:58:12,040 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.1, S.Element 3.3, S.Element 3.2
08:58:12,041 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
08:58:12,041 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,049 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
08:58:12,050 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
08:58:12,051 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
08:58:12,052 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
08:58:12,053 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
08:58:12,053 INFO  [main][General] >> result=Owner 1
08:58:12,053 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.1, S.Element 1.4, S.Element 1.3, S.Element 1.2
08:58:12,053 INFO  [main][General] >> result=Owner 2
08:58:12,053 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.4, S.Element 2.3, S.Element 2.1, S.Element 2.2
08:58:12,054 INFO  [main][General] >> result=Owner 4
08:58:12,054 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
08:58:12,055 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
08:58:12,055 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,057 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
08:58:12,060 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
08:58:12,061 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
08:58:12,062 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "ElementA[name="S.Element 3.2"]":
08:58:12,062 INFO  [main][General] >> result=Owner 3
08:58:12,062 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.2, S.Element 3.1, S.Element 3.3
08:58:12,063 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
08:58:12,064 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,065 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
08:58:12,067 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
08:58:12,068 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
08:58:12,069 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
08:58:12,070 INFO  [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "!this.set.contains(:element)" and param "ElementA[name="S.Element 3.2"]":
08:58:12,070 INFO  [main][General] >> result=Owner 4
08:58:12,070 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
08:58:12,070 INFO  [main][General] >> result=Owner 5
08:58:12,070 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
08:58:12,070 INFO  [main][General] >> result=Owner 1
08:58:12,071 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.3, S.Element 1.4, S.Element 1.2, S.Element 1.1
08:58:12,071 INFO  [main][General] >> result=Owner 2
08:58:12,071 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.3, S.Element 2.2, S.Element 2.4, S.Element 2.1
08:58:12,072 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
08:58:12,072 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,080 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
08:58:12,081 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
08:58:12,082 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,083 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
08:58:12,084 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
08:58:12,085 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
08:58:12,086 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
08:58:12,087 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
08:58:12,088 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
08:58:12,089 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
08:58:12,090 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
08:58:12,090 INFO  [main][General] >> result=Owner 1
08:58:12,090 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.4, S.Element 1.3, S.Element 1.2, S.Element 1.1
08:58:12,091 INFO  [main][General] >> result=Owner 2
08:58:12,091 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.3, S.Element 2.4, S.Element 2.1, S.Element 2.2
08:58:12,091 INFO  [main][General] >> result=Owner 3
08:58:12,091 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.1, S.Element 3.3, S.Element 3.2
08:58:12,093 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
08:58:12,093 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,101 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
08:58:12,102 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,104 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,105 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,105 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,106 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,107 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,108 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,109 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,110 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
08:58:12,112 INFO  [main][ElementASetQueryTest] invoke: found 3 ElementASetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
08:58:12,112 INFO  [main][General] >> result=Owner 1
08:58:12,112 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.3, S.Element 1.1, S.Element 1.4, S.Element 1.2
08:58:12,112 INFO  [main][General] >> result=Owner 2
08:58:12,112 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.2, S.Element 2.3, S.Element 2.4, S.Element 2.1
08:58:12,113 INFO  [main][General] >> result=Owner 3
08:58:12,113 INFO  [main][ElementASetQueryTest] invoke:   * Owner 3: S.Element 3.2, S.Element 3.3, S.Element 3.1
08:58:12,114 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
08:58:12,114 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,116 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
08:58:12,120 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
08:58:12,121 INFO  [main][Query] Reading in results for query "SELECT UNIQUE FROM org.cumulus4j.store.model.IndexEntryLong WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID && this.indexKey == :indexKey" since the connection used is closing
08:58:12,121 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
08:58:12,123 INFO  [main][ElementASetQueryTest] invoke: found 4 ElementASetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "ElementA[name="S.Element 3.2"]":
08:58:12,123 INFO  [main][General] >> result=Owner 4
08:58:12,123 INFO  [main][ElementASetQueryTest] invoke:   * Owner 4: S.Element 4.3
08:58:12,123 INFO  [main][General] >> result=Owner 5
08:58:12,123 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
08:58:12,123 INFO  [main][General] >> result=Owner 1
08:58:12,124 INFO  [main][ElementASetQueryTest] invoke:   * Owner 1: S.Element 1.1, S.Element 1.2, S.Element 1.3, S.Element 1.4
08:58:12,124 INFO  [main][General] >> result=Owner 2
08:58:12,124 INFO  [main][ElementASetQueryTest] invoke:   * Owner 2: S.Element 2.1, S.Element 2.2, S.Element 2.4, S.Element 2.3
08:58:12,125 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
08:58:12,125 INFO  [main][ElementASetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:12,127 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
08:58:12,129 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
08:58:12,130 INFO  [main][ElementASetQueryTest] invoke: found 1 ElementASetOwners for query-filter "this.set.isEmpty()" and param "ElementA[name="S.Element 3.2"]":
08:58:12,130 INFO  [main][General] >> result=Owner 5
08:58:12,130 INFO  [main][ElementASetQueryTest] invoke:   * Owner 5: 
08:58:12,130 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 26, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 13.407 sec
Running org.cumulus4j.store.test.collection.mappedby.Element3MapQueryTest
08:58:12,810 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
08:58:13,296 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
08:58:13,298 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:13,313 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
08:58:13,313 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
08:58:13,314 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:58:13,315 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:13,332 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:58:22,691 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
08:58:23,670 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:58:23,670 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:58:23,670 INFO  [main][Cumulus4jStoreManager] =======================================================
08:58:23,672 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:58:23,672 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:58:23,916 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:24,097 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:24,260 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element3MapOwner" not found !
08:58:24,264 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element3" not found !
08:58:24,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
08:58:24,481 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsKey(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
08:58:24,481 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="aaa", name="Element 1.1"]=aaa
08:58:24,481 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 2: Element3[value="aa", name="Element 2.1"]=aa, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="bb", name="Element 2.2"]=bb
08:58:24,481 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
08:58:24,483 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
08:58:24,484 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:24,488 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
08:58:24,491 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsValue(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
08:58:24,491 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="aaa", name="Element 1.1"]=aaa
08:58:24,492 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
08:58:24,492 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
08:58:24,493 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
08:58:24,494 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:24,501 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
08:58:24,509 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
08:58:24,510 INFO  [main][Element3MapQueryTest] queryContainsKeyParameter: found 1 Element3MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
08:58:24,510 INFO  [main][Element3MapQueryTest] queryContainsKeyParameter:   * Owner 3: Element3[value="a", name="Element 3.1"]=a, Element3[value="b", name="Element 3.2"]=b, Element3[value="c", name="Element 3.3"]=c
08:58:24,513 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
08:58:24,513 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:24,514 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
08:58:24,516 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
08:58:24,524 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
08:58:24,526 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter: found 5 Element3MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
08:58:24,527 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
08:58:24,527 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="ddd", name="Element 1.4"]=ddd
08:58:24,527 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
08:58:24,527 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
08:58:24,528 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 2: Element3[value="bb", name="Element 2.2"]=bb, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="dd", name="Element 2.4"]=dd, Element3[value="aa", name="Element 2.1"]=aa
08:58:24,529 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
08:58:24,530 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:24,532 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
08:58:24,534 INFO  [main][Element3MapQueryTest] queryContainsValueParameter: found 2 Element3MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "ccc":
08:58:24,535 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
08:58:24,535 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 1: Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="bbb", name="Element 1.2"]=bbb
08:58:24,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
08:58:24,537 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:24,539 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
08:58:24,541 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
08:58:24,542 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter: found 4 Element3MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "ccc":
08:58:24,543 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
08:58:24,543 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
08:58:24,543 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * 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
08:58:24,543 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 3: Element3[value="a", name="Element 3.1"]=a, Element3[value="b", name="Element 3.2"]=b, Element3[value="c", name="Element 3.3"]=c
08:58:26,193 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:58:26,194 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:26,222 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:58:27,181 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
08:58:33,922 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:58:33,922 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:58:33,922 INFO  [main][Cumulus4jStoreManager] =======================================================
08:58:33,923 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:58:33,923 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:58:33,957 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:33,957 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:33,969 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element3MapOwner" not found !
08:58:33,970 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element3" not found !
08:58:34,185 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
08:58:34,188 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsKey(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
08:58:34,188 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 1: Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="bbb", name="Element 1.2"]=bbb, Element3[value="aaa", name="Element 1.1"]=aaa
08:58:34,188 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 2: Element3[value="dd", name="Element 2.4"]=dd, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="bb", name="Element 2.2"]=bb
08:58:34,188 INFO  [main][Element3MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
08:58:34,189 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
08:58:34,190 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:34,193 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
08:58:34,195 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element3MapOwners for query-filter "this.map.containsValue(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
08:58:34,195 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 1: Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb
08:58:34,195 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * 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
08:58:34,195 INFO  [main][Element3MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
08:58:34,197 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
08:58:34,197 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:34,198 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
08:58:34,199 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
08:58:34,200 INFO  [main][Element3MapQueryTest] queryContainsKeyParameter: found 1 Element3MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
08:58:34,200 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
08:58:34,201 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
08:58:34,201 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:34,203 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
08:58:34,204 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
08:58:34,205 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
08:58:34,206 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter: found 5 Element3MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "Element3[value="b", name="Element 3.2"]":
08:58:34,207 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 2: Element3[value="bb", name="Element 2.2"]=bb, Element3[value="aa", name="Element 2.1"]=aa, Element3[value="cc", name="Element 2.3"]=cc, Element3[value="dd", name="Element 2.4"]=dd
08:58:34,207 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
08:58:34,207 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * 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
08:58:34,207 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
08:58:34,207 INFO  [main][Element3MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
08:58:34,208 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
08:58:34,209 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:34,210 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
08:58:34,212 INFO  [main][Element3MapQueryTest] queryContainsValueParameter: found 2 Element3MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "ccc":
08:58:34,212 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 1: Element3[value="ddd", name="Element 1.4"]=ddd, Element3[value="aaa", name="Element 1.1"]=aaa, Element3[value="ccc", name="Element 1.3"]=ccc, Element3[value="bbb", name="Element 1.2"]=bbb
08:58:34,212 INFO  [main][Element3MapQueryTest] queryContainsValueParameter:   * Owner 4: Element3[value="ccc", name="Element 4.3"]=ccc
08:58:34,213 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
08:58:34,213 INFO  [main][Element3MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:34,215 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
08:58:34,216 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
08:58:34,217 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter: found 4 Element3MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "ccc":
08:58:34,217 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * 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
08:58:34,217 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 3: Element3[value="a", name="Element 3.1"]=a, Element3[value="c", name="Element 3.3"]=c, Element3[value="b", name="Element 3.2"]=b
08:58:34,217 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
08:58:34,218 INFO  [main][Element3MapQueryTest] queryNotContainsValueParameter:   * Owner 6: Element3[value="bb", name="Element 6.2"]=bb
08:58:34,218 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
08:58:35,400 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
Tests run: 12, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 22.591 sec
Running org.cumulus4j.store.test.collection.mappedby.Element2MapQueryTest
08:58:35,406 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
08:58:35,923 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
08:58:35,924 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:35,938 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
08:58:35,938 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
08:58:35,939 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:58:35,940 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:35,961 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:58:39,352 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
08:58:40,924 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:58:40,924 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:58:40,924 INFO  [main][Cumulus4jStoreManager] =======================================================
08:58:40,926 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:58:40,926 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:58:41,017 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:41,136 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:41,263 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element2MapOwner" not found !
08:58:41,267 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element2" not found !
08:58:41,484 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
08:58:41,497 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
08:58:41,497 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"]
08:58:41,497 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"]
08:58:41,498 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:41,500 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
08:58:41,501 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,514 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
08:58:41,522 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) < 0" and param "bb":
08:58:41,522 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"]
08:58:41,522 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"]
08:58:41,522 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"]
08:58:41,523 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:41,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
08:58:41,525 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,535 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
08:58:41,538 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
08:58:41,538 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"]
08:58:41,538 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"]
08:58:41,538 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:41,540 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
08:58:41,541 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,545 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
08:58:41,550 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && !(variable.indexOf(:queryParam) >= 0)" and param "bb":
08:58:41,550 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"]
08:58:41,550 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"]
08:58:41,550 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"]
08:58:41,550 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:41,552 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
08:58:41,553 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,560 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) < :compareToArgument" since the connection used is closing
08:58:41,565 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && !(variable.name.indexOf(:queryParam) >= 0)" and param "4":
08:58:41,565 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 1: aaa=Element2[key="aaa", name="Element 1.1"], ccc=Element2[key="ccc", name="Element 1.3"], bbb=Element2[key="bbb", name="Element 1.2"], ddd=Element2[key="ddd", name="Element 1.4"]
08:58:41,566 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 2: aa=Element2[key="aa", name="Element 2.1"], bb=Element2[key="bb", name="Element 2.2"], cc=Element2[key="cc", name="Element 2.3"], dd=Element2[key="dd", name="Element 2.4"]
08:58:41,566 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 3: a=Element2[key="a", name="Element 3.1"], b=Element2[key="b", name="Element 3.2"], c=Element2[key="c", name="Element 3.3"]
08:58:41,566 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:41,567 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
08:58:41,568 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,575 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
08:58:41,580 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) < 0" and param "4":
08:58:41,581 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"]
08:58:41,581 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"]
08:58:41,581 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"]
08:58:41,581 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:41,582 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
08:58:41,583 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,590 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
08:58:41,592 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter: found 2 Element2MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "ccc":
08:58:41,592 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:41,592 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"]
08:58:41,593 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
08:58:41,594 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,596 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
08:58:41,602 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
08:58:41,604 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter: found 4 Element2MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "ccc":
08:58:41,604 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
08:58:41,604 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:41,604 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"]
08:58:41,605 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"]
08:58:41,606 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
08:58:41,607 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,609 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
08:58:41,616 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
08:58:41,617 INFO  [main][Element2MapQueryTest] queryContainsValueParameter: found 1 Element2MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
08:58:41,617 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"]
08:58:41,619 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
08:58:41,620 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:41,621 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
08:58:41,623 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
08:58:41,624 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
08:58:41,626 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter: found 5 Element2MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
08:58:41,626 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:41,626 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"]
08:58:41,626 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
08:58:41,626 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:41,626 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"]
08:58:42,498 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:58:42,501 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:42,525 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:58:45,342 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:58:45,342 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:58:45,342 INFO  [main][Cumulus4jStoreManager] =======================================================
08:58:45,344 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:58:45,344 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:58:45,369 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:45,370 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:45,378 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element2MapOwner" not found !
08:58:45,380 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element2" not found !
08:58:45,570 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
08:58:45,573 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) >= 0" and param "bb":
08:58:45,574 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"]
08:58:45,574 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"]
08:58:45,574 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:45,576 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
08:58:45,576 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,581 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
08:58:45,593 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && variable.indexOf(:queryParam) < 0" and param "bb":
08:58:45,593 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"]
08:58:45,593 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"]
08:58:45,593 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"]
08:58:45,594 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndIndexOfNotMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:45,596 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
08:58:45,596 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,603 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.indexKey.indexOf(:invokeArg) >= :compareToArgument" since the connection used is closing
08:58:45,606 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches: found 3 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) >= 0" and param "4":
08:58:45,606 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"]
08:58:45,606 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"]
08:58:45,606 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:45,608 INFO  [main][Query] Reading in results for query "SELECT this.classMeta_classID, this.objectID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
08:58:45,609 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,613 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
08:58:45,621 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsKey(variable) && !(variable.indexOf(:queryParam) >= 0)" and param "bb":
08:58:45,622 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"]
08:58:45,622 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"]
08:58:45,622 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"]
08:58:45,622 INFO  [main][Element2MapQueryTest] queryContainsKeyVariableAndNotIndexOfMatches:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:45,624 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
08:58:45,625 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,634 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
08:58:45,640 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && !(variable.name.indexOf(:queryParam) >= 0)" and param "4":
08:58:45,640 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"]
08:58:45,640 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"]
08:58:45,641 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"]
08:58:45,641 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndNotIndexOfMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:45,645 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
08:58:45,646 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,653 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
08:58:45,658 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches: found 4 Element2MapOwners for query-filter "this.map.containsValue(variable) && variable.name.indexOf(:queryParam) < 0" and param "4":
08:58:45,658 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"]
08:58:45,658 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"]
08:58:45,658 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"]
08:58:45,659 INFO  [main][Element2MapQueryTest] queryContainsValueVariableAndIndexOfNotMatches:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:45,660 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
08:58:45,661 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,662 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
08:58:45,664 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter: found 2 Element2MapOwners for query-filter "this.map.containsKey(:queryParam)" and param "ccc":
08:58:45,664 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"]
08:58:45,664 INFO  [main][Element2MapQueryTest] queryContainsKeyParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:45,665 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
08:58:45,666 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,667 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
08:58:45,669 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
08:58:45,670 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter: found 4 Element2MapOwners for query-filter "!this.map.containsKey(:queryParam)" and param "ccc":
08:58:45,670 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"]
08:58:45,670 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"]
08:58:45,670 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 5: 
08:58:45,671 INFO  [main][Element2MapQueryTest] queryNotContainsKeyParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:45,672 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
08:58:45,672 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,674 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
08:58:45,676 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
08:58:45,676 INFO  [main][Element2MapQueryTest] queryContainsValueParameter: found 1 Element2MapOwners for query-filter "this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
08:58:45,677 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"]
08:58:45,678 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
08:58:45,678 INFO  [main][Element2MapQueryTest] createTestData: There is already test data. Skipping creation.
08:58:45,680 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
08:58:45,682 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
08:58:45,682 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
08:58:45,684 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter: found 5 Element2MapOwners for query-filter "!this.map.containsValue(:queryParam)" and param "Element2[key="b", name="Element 3.2"]":
08:58:45,685 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"]
08:58:45,685 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 4: ccc=Element2[key="ccc", name="Element 4.3"]
08:58:45,685 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"]
08:58:45,685 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 5: 
08:58:45,685 INFO  [main][Element2MapQueryTest] queryNotContainsValueParameter:   * Owner 6: bb=Element2[key="bb", name="Element 6.2"]
08:58:45,686 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 11.057 sec
Running org.cumulus4j.store.test.collection.mappedby.Element1SetQueryTest
08:58:46,463 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
08:58:46,960 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
08:58:46,961 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:46,972 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
08:58:46,972 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
08:58:46,973 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:58:46,973 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:46,995 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:58:48,966 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
08:58:53,164 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:58:53,164 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:58:53,164 INFO  [main][Cumulus4jStoreManager] =======================================================
08:58:53,166 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:58:53,166 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:58:53,270 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:53,401 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:53,567 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element1SetOwner" not found !
08:58:53,572 INFO  [main][Retrieve] Object with id "1.org.cumulus4j.store.test.collection.mappedby.Element1" not found !
08:58:53,754 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
08:58:53,773 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
08:58:53,778 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 4.3"]":
08:58:53,780 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 1: Element 1.4, Element 1.2, Element 1.3, Element 1.1
08:58:53,780 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 2: Element 2.3, Element 2.1, Element 2.4, Element 2.2
08:58:53,781 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 3: Element 3.3, Element 3.1, Element 3.2
08:58:53,783 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
08:58:53,784 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,800 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
08:58:53,809 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
08:58:53,810 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: found 2 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
08:58:53,810 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 5: 
08:58:53,810 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 3: Element 3.1, Element 3.2, Element 3.3
08:58:53,812 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
08:58:53,812 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,814 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
08:58:53,824 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
08:58:53,825 INFO  [main][Element1SetQueryTest] queryContainsParameter: found 1 Element1SetOwners for query-filter "this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
08:58:53,825 INFO  [main][Element1SetQueryTest] queryContainsParameter:   * Owner 3: Element 3.2, Element 3.3, Element 3.1
08:58:53,827 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
08:58:53,828 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,837 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
08:58:53,841 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
08:58:53,841 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 1: Element 1.1, Element 1.4, Element 1.3, Element 1.2
08:58:53,841 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 2: Element 2.4, Element 2.3, Element 2.2, Element 2.1
08:58:53,841 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 4: Element 4.3
08:58:53,843 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
08:58:53,844 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,846 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
08:58:53,852 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
08:58:53,853 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: found 1 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
08:58:53,853 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals:   * Owner 3: Element 3.2, Element 3.3, Element 3.1
08:58:53,855 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
08:58:53,855 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,857 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
08:58:53,860 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
08:58:53,861 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
08:58:53,864 INFO  [main][Element1SetQueryTest] queryNotContainsParameter: found 4 Element1SetOwners for query-filter "!this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
08:58:53,864 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 4: Element 4.3
08:58:53,864 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 1: Element 1.1, Element 1.3, Element 1.4, Element 1.2
08:58:53,864 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 5: 
08:58:53,865 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 2: Element 2.4, Element 2.2, Element 2.1, Element 2.3
08:58:53,866 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
08:58:53,867 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,883 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
08:58:53,888 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
08:58:53,888 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 1: Element 1.1, Element 1.2, Element 1.4, Element 1.3
08:58:53,888 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 2: Element 2.3, Element 2.2, Element 2.1, Element 2.4
08:58:53,888 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 3: Element 3.3, Element 3.2, Element 3.1
08:58:53,890 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
08:58:53,891 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,899 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
08:58:53,903 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
08:58:53,903 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 1: Element 1.2, Element 1.1, Element 1.3, Element 1.4
08:58:53,903 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 2: Element 2.4, Element 2.2, Element 2.1, Element 2.3
08:58:53,904 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 3: Element 3.1, Element 3.2, Element 3.3
08:58:53,906 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
08:58:53,906 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,907 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
08:58:53,912 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
08:58:53,914 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
08:58:53,916 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: found 4 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
08:58:53,916 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 4: Element 4.3
08:58:53,916 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 1: Element 1.3, Element 1.1, Element 1.2, Element 1.4
08:58:53,916 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 5: 
08:58:53,917 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 2: Element 2.1, Element 2.4, Element 2.2, Element 2.3
08:58:53,918 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
08:58:53,919 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:53,921 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
08:58:53,923 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
08:58:53,928 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: found 4 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 3.2"]":
08:58:53,928 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 1: Element 1.4, Element 1.3, Element 1.1, Element 1.2
08:58:53,928 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 2: Element 2.1, Element 2.3, Element 2.2, Element 2.4
08:58:53,929 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 3: Element 3.3, Element 3.2, Element 3.1
08:58:53,929 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 4: Element 4.3
08:58:55,094 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:58:55,094 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:58:55,142 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:58:58,154 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
08:58:58,452 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:58:58,452 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:58:58,452 INFO  [main][Cumulus4jStoreManager] =======================================================
08:58:58,454 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:58:58,454 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:58:58,491 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:58,492 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:58:58,505 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element1SetOwner" not found !
08:58:58,506 INFO  [main][Retrieve] Object with id "2.org.cumulus4j.store.test.collection.mappedby.Element1" not found !
08:58:58,594 INFO  [main][Query] Reading in results for query "SELECT FROM org.cumulus4j.store.model.IndexEntryStringShort WHERE this.keyStoreRefID == :keyStoreRefID && this.fieldMeta_fieldID == :fieldMeta_fieldID && this.classMeta_classID == :classMeta_classID0 && this.indexKey == :value" since the connection used is closing
08:58:58,600 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
08:58:58,605 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 4.3"]":
08:58:58,605 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 1: Element 1.1, Element 1.3, Element 1.2, Element 1.4
08:58:58,605 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 2: Element 2.3, Element 2.1, Element 2.2, Element 2.4
08:58:58,605 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals2:   * Owner 3: Element 3.3, Element 3.1, Element 3.2
08:58:58,606 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
08:58:58,607 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,613 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
08:58:58,616 INFO  [main][Query] Reading in results for query "SELECT this.dataEntryID FROM org.cumulus4j.store.model.DataEntry WHERE this.keyStoreRefID == :keyStoreRefID && this.classMeta_classID == :classMeta_classID0" since the connection used is closing
08:58:58,622 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf: found 2 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
08:58:58,622 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 3: Element 3.3, Element 3.1, Element 3.2
08:58:58,622 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableIndexOf:   * Owner 5: 
08:58:58,624 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
08:58:58,624 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,625 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
08:58:58,627 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
08:58:58,628 INFO  [main][Element1SetQueryTest] queryContainsParameter: found 1 Element1SetOwners for query-filter "this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
08:58:58,628 INFO  [main][Element1SetQueryTest] queryContainsParameter:   * Owner 3: Element 3.3, Element 3.1, Element 3.2
08:58:58,630 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
08:58:58,630 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,637 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
08:58:58,640 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) >= 0" and param "4":
08:58:58,640 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 1: Element 1.3, Element 1.2, Element 1.1, Element 1.4
08:58:58,640 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 2: Element 2.3, Element 2.2, Element 2.1, Element 2.4
08:58:58,640 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableIndexOf:   * Owner 4: Element 4.3
08:58:58,642 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
08:58:58,642 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,643 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
08:58:58,647 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
08:58:58,648 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals: found 1 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
08:58:58,649 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableEquals:   * Owner 3: Element 3.2, Element 3.1, Element 3.3
08:58:58,652 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
08:58:58,652 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,653 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
08:58:58,655 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
08:58:58,656 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
08:58:58,658 INFO  [main][Element1SetQueryTest] queryNotContainsParameter: found 4 Element1SetOwners for query-filter "!this.set.contains(:element)" and param "Element1[name="Element 3.2"]":
08:58:58,658 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 4: Element 4.3
08:58:58,658 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 1: Element 1.4, Element 1.3, Element 1.1, Element 1.2
08:58:58,658 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 5: 
08:58:58,659 INFO  [main][Element1SetQueryTest] queryNotContainsParameter:   * Owner 2: Element 2.2, Element 2.3, Element 2.4, Element 2.1
08:58:58,660 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
08:58:58,661 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,668 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
08:58:58,672 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && elementVariable.name.indexOf(:elementPart) < 0" and param "4":
08:58:58,672 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 1: Element 1.2, Element 1.4, Element 1.3, Element 1.1
08:58:58,673 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 2: Element 2.1, Element 2.4, Element 2.2, Element 2.3
08:58:58,673 INFO  [main][Element1SetQueryTest] queryContainsVariableAndVariableNotIndexOf:   * Owner 3: Element 3.1, Element 3.3, Element 3.2
08:58:58,674 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
08:58:58,676 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,686 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
08:58:58,692 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf: found 3 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable.name.indexOf(:elementPart) >= 0)" and param "4":
08:58:58,692 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 1: Element 1.3, Element 1.4, Element 1.2, Element 1.1
08:58:58,692 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 2: Element 2.3, Element 2.1, Element 2.2, Element 2.4
08:58:58,693 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableIndexOf:   * Owner 3: Element 3.1, Element 3.2, Element 3.3
08:58:58,695 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
08:58:58,695 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,697 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
08:58:58,703 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
08:58:58,704 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
08:58:58,706 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals: found 4 Element1SetOwners for query-filter "!this.set.contains(elementVariable) && elementVariable == :element" and param "Element1[name="Element 3.2"]":
08:58:58,707 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 4: Element 4.3
08:58:58,707 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 1: Element 1.2, Element 1.4, Element 1.3, Element 1.1
08:58:58,707 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 5: 
08:58:58,708 INFO  [main][Element1SetQueryTest] queryNotContainsVariableAndVariableEquals:   * Owner 2: Element 2.3, Element 2.1, Element 2.2, Element 2.4
08:58:58,710 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
08:58:58,710 INFO  [main][Element1SetQueryTest] createTestData: There is already test data. Skipping creation.
08:58:58,712 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
08:58:58,714 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
08:58:58,719 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1: found 4 Element1SetOwners for query-filter "this.set.contains(elementVariable) && !(elementVariable == :element)" and param "Element1[name="Element 3.2"]":
08:58:58,720 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 1: Element 1.1, Element 1.3, Element 1.4, Element 1.2
08:58:58,720 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 2: Element 2.2, Element 2.1, Element 2.3, Element 2.4
08:58:58,720 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 3: Element 3.2, Element 3.3, Element 3.1
08:58:58,720 INFO  [main][Element1SetQueryTest] queryContainsVariableAndNotVariableEquals1:   * Owner 4: Element 4.3
08:58:58,721 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 13.108 sec
Running org.cumulus4j.store.test.datatype.StandardOneToOneTypesTest
08:58:59,769 INFO  [main][JDOTransactionalRunner] run: Shutting down Derby (in case it was used before).
08:59:00,593 INFO  [main][AbstractJDOTransactionalTestClearingDatabase] clearDatabase: Clearing database (dropping all tables).
08:59:00,594 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:59:00,617 INFO  [main][CleanupUtil] cleanoutRDBMS: derbyDatabaseDir="/tmp/derby/cumulus4j" was deleted successfully.
08:59:00,617 WARN  [main][CleanupUtil] dropAllTables: 'ConnectionURL' property is not set for index datastore! Skipping!
08:59:00,618 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:59:00,618 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:59:00,637 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:59:07,448 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
08:59:08,712 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:59:08,712 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:59:08,712 INFO  [main][Cumulus4jStoreManager] =======================================================
08:59:08,761 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:59:08,761 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:59:08,869 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:59:09,000 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:59:11,810 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
08:59:11,876 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
08:59:11,880 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 091b934b-2cc2-4690-81be-bbd405473017
08:59:11,880 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 0e6b2532-92fc-4176-a6e2-7240d7a67c5d
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 11c086c2-45f3-4df1-a7fa-1cca2b6b229b
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 1a3a682d-37c1-4a27-b6cf-66a28426e530
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4d35beca-1a39-45da-afcb-f6ecbb394765
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 52e8b2ee-ac3e-4fea-baa3-a55b85827929
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5447e604-8449-460e-ace4-2bc6de666ec1
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5549512e-5e66-4df8-9e8d-8809c386344d
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5e8a93f2-b5e4-4a90-a6fb-2bcca6601ff4
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 65b251e4-684d-4893-a791-d20447137a6d
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 68802f91-2e52-4f88-80ac-718a57796d7f
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6e1d79ec-ee45-48c7-8138-fa0f7dd7933e
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 732126ac-fe23-450d-9df8-0fde7e991234
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 75f6740f-ce0f-4d56-8360-3a2f6e894842
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7c2c8811-e7fc-464e-941d-db8752815602
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 88a77eb4-81f6-4bb3-8c90-d5766223f9bd
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 89ff9511-d63c-43c2-b8c1-62ad7b8f0fab
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 8d4f3af2-fc5e-4bb5-8625-ea012f45ec5a
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 9b5ac88f-c3f9-41c9-b130-16e15700702c
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = a9012d49-6e38-4255-ab4e-2e5d61948cfe
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = b5861ec1-5fba-49be-bc00-e6f49edcc2aa
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = b9094034-a12e-4b7b-96de-aed111152255
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = bc82e5af-0957-4374-afd9-9bc6124cd752
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = c29fe9ce-533d-4cd0-a386-fa910d20812f
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = c74bd49e-670f-4a24-ab0d-dbbe726e0c21
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = d732c9fd-6a02-4a89-8d27-7d9b78c5e4f3
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = e4b3c79c-dda0-4138-8224-f1cf9d717426
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fa38f3d2-1883-43d9-9334-d23e4099302d
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fe060c47-32ec-4c70-9046-048544fd85a5
08:59:11,881 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fef3a05b-78a3-4c0b-aae7-fde216f5d04e
08:59:13,261 INFO  [main][JDOTransactionalRunner] run: Setting up PersistenceManagerFactory.
08:59:13,264 INFO  [main][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
08:59:13,284 INFO  [main][Persistence] Property cumulus4j.index.clob.enabled unknown - will be ignored
08:59:15,787 INFO  [main][Cumulus4jStoreManager] ====================== Cumulus4j ======================
08:59:15,787 INFO  [main][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
08:59:15,787 INFO  [main][Cumulus4jStoreManager] =======================================================
08:59:15,789 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
08:59:15,789 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
08:59:15,813 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:59:15,814 INFO  [main][MinimumCumulus4jVersion] version=10100001
08:59:16,202 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
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 091b934b-2cc2-4690-81be-bbd405473017
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 0e6b2532-92fc-4176-a6e2-7240d7a67c5d
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 11c086c2-45f3-4df1-a7fa-1cca2b6b229b
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 1a3a682d-37c1-4a27-b6cf-66a28426e530
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 4d35beca-1a39-45da-afcb-f6ecbb394765
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 52e8b2ee-ac3e-4fea-baa3-a55b85827929
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5447e604-8449-460e-ace4-2bc6de666ec1
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5549512e-5e66-4df8-9e8d-8809c386344d
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 5e8a93f2-b5e4-4a90-a6fb-2bcca6601ff4
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 65b251e4-684d-4893-a791-d20447137a6d
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 68802f91-2e52-4f88-80ac-718a57796d7f
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 6e1d79ec-ee45-48c7-8138-fa0f7dd7933e
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 732126ac-fe23-450d-9df8-0fde7e991234
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 75f6740f-ce0f-4d56-8360-3a2f6e894842
08:59:16,205 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 7c2c8811-e7fc-464e-941d-db8752815602
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 88a77eb4-81f6-4bb3-8c90-d5766223f9bd
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 89ff9511-d63c-43c2-b8c1-62ad7b8f0fab
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 8d4f3af2-fc5e-4bb5-8625-ea012f45ec5a
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = 9b5ac88f-c3f9-41c9-b130-16e15700702c
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = a9012d49-6e38-4255-ab4e-2e5d61948cfe
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = b5861ec1-5fba-49be-bc00-e6f49edcc2aa
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = b9094034-a12e-4b7b-96de-aed111152255
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = bc82e5af-0957-4374-afd9-9bc6124cd752
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = c29fe9ce-533d-4cd0-a386-fa910d20812f
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = c74bd49e-670f-4a24-ab0d-dbbe726e0c21
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = d732c9fd-6a02-4a89-8d27-7d9b78c5e4f3
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = e4b3c79c-dda0-4138-8224-f1cf9d717426
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fa38f3d2-1883-43d9-9334-d23e4099302d
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fe060c47-32ec-4c70-9046-048544fd85a5
08:59:16,206 INFO  [main][StandardOneToOneTypesTest] * foundEntity.uuid = fef3a05b-78a3-4c0b-aae7-fde216f5d04e
08:59:16,232 INFO  [main][JDOTransactionalRunner] run: Shutting down PersistenceManagerFactory.
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 17.306 sec

Results :

Tests in error: 
  query0.1(org.cumulus4j.store.test.movie.MovieQueryTest): Unexpected exception caught.
  query1.1(org.cumulus4j.store.test.movie.MovieQueryTest): Unexpected exception caught.
  query2.1(org.cumulus4j.store.test.movie.MovieQueryTest): Unexpected exception caught.
  query3.1(org.cumulus4j.store.test.movie.MovieQueryTest): Unexpected exception caught.
  query4.1(org.cumulus4j.store.test.movie.MovieQueryTest): Unexpected exception caught.
  query5.1(org.cumulus4j.store.test.movie.MovieQueryTest): Unexpected exception caught.
  writeAndRead.0(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedWithPKOneToOneNestedTest): Unexpected exception caught.
  writeAndRead.1(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedWithPKOneToOneNestedTest): Unexpected exception caught.
  query2ndLevel.0(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedOneToOneNestedTest): Unexpected exception caught.
  writeAndRead.0(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedOneToOneNestedTest): Unexpected exception caught.
  query1stLevel.0(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedOneToOneNestedTest): Unexpected exception caught.
  query2ndLevel.1(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedOneToOneNestedTest): Unexpected exception caught.
  writeAndRead.1(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedOneToOneNestedTest): Unexpected exception caught.
  query1stLevel.1(org.cumulus4j.store.test.embedded.onetoone.nested.EmbeddedOneToOneNestedTest): Unexpected exception caught.
  updateData.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  extentIterator.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringEquals.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryAndWithTwoStringEquals_2shortStr.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryAndWithTwoStringEquals_1clob.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringIndexOf.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringStartsWith.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringEndsWith.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringEndsWith2.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringMatches.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringToUpperCase.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringToLowerCase.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryStringSubstring.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.
  queryDateYear.1(org.cumulus4j.store.test.account.JDOQLTest): Unexpected exception caught.

Tests run: 361, Failures: 0, Errors: 28, 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