y populated). this=org.cumulus4j.store.model.FieldMeta@3354eedd[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,182 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@600e544b[null,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
11:04:04,182 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@600e544b[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
11:04:04,183 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3354eedd[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,183 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,183 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@399060fc[null,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,184 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,184 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@399060fc[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,184 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@399060fc[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,184 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,184 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@65f637ba[null,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,185 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,185 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,186 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,186 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,186 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,186 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@1a58aa46[null,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
11:04:04,186 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@1a58aa46[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
11:04:04,187 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,187 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,187 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@12769440[null,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,188 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,188 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,188 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,188 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,188 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@15c3dfda[null,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,189 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,189 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,189 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,189 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,189 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,189 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@5ed75055[null,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
11:04:04,190 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@5ed75055[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
11:04:04,190 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,190 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,190 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@777a93bd[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:04,190 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@d0d9063[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:04,190 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@235f4075[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
11:04:04,190 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3b29e9e5[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
11:04:04,190 DEBUG [qtp297354543-442][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@3b29e9e5[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
11:04:04,200 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3354eedd[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,200 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@399060fc[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,200 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,200 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,200 DEBUG [qtp297354543-442][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,201 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,202 DEBUG [qtp297354543-442][ClassMeta] jdoPostDetach: attached=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,202 DEBUG [qtp297354543-442][ClassMeta] jdoPostDetach: Detaching this.fieldName2FieldMeta: attached=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,202 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@43449485[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,202 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@777a93bd[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:04,202 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@777a93bd[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:04,202 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@777a93bd[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:04,202 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@655aa73[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
11:04:04,202 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@655aa73[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
11:04:04,202 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@655aa73[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
11:04:04,202 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@655aa73[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
11:04:04,202 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@777a93bd[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@d0d9063[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@d0d9063[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:04,203 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@d0d9063[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@55edc6bc[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@55edc6bc[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
11:04:04,203 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@55edc6bc[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@55edc6bc[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@d0d9063[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,203 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@12769440[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,203 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,203 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@5ed75055[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@5ed75055[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
11:04:04,204 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@5ed75055[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@5ed75055[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@15c3dfda[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@3b29e9e5[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@3b29e9e5[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
11:04:04,204 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3b29e9e5[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@3b29e9e5[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@399060fc[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@399060fc[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,204 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@399060fc[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@399060fc[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,204 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@1a58aa46[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@1a58aa46[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
11:04:04,204 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1a58aa46[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@1a58aa46[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
11:04:04,204 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@65f637ba[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@235f4075[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@235f4075[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@235f4075[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@235f4075[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@3354eedd[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@3354eedd[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3354eedd[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@600e544b[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@600e544b[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@600e544b[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@600e544b[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
11:04:04,205 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@3354eedd[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,205 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@539b9591[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@79327f16[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@cf0b23b[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@400908c4[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4f313a49[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@25112676[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2cf92985[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@243e5bf6[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@629bce4a[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
11:04:04,205 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,206 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2bc5dbbf[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
11:04:04,206 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@7df2c4da[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
11:04:04,206 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@41a7bcb0[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,206 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2460b8c3[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
11:04:04,206 DEBUG [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: end loading (took 561 ms). class=org.cumulus4j.store.test.movie.Movie
11:04:04,217 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:04,218 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=8 value=[]
11:04:04,218 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,218 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@25112676[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:04,218 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,218 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=6 value=[]
11:04:04,218 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,219 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:04,219 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=5 value=null
11:04:04,219 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,219 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=4 value=[]
11:04:04,219 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,219 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@41a7bcb0[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:04,219 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,219 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,219 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=1 value=[]
11:04:04,219 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,219 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@cf0b23b[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:04,219 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=0 value=[]
11:04:04,219 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:04,219 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@539b9591[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:04,219 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 1
11:04:04,219 INFO [qtp297354543-442][AbstractCryptoManager] getEncryptionAlgorithm: Property 'cumulus4j.encryptionAlgorithm' is not set. Using default algorithm 'Twofish/GCM/NoPadding'.
11:04:04,219 INFO [qtp297354543-442][AbstractCryptoManager] getMACAlgorithm: Property 'cumulus4j.macAlgorithm' is not set. Using default MAC algorithm 'NONE'.
11:04:04,637 DEBUG [CryptoCache][CryptoCache$CleanupTask] run: entered
11:04:04,638 INFO [CryptoCache][CryptoCache$CleanupTask] run: CryptoCache was garbage-collected. Cancelling this TimerTask.
11:04:04,909 DEBUG [qtp297354543-440][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsepvt-1r88p0v3v7axv_aimrj3l8]: Returning request: null
11:04:16,030 DEBUG [KeyStore][KeyStore$ExipreCacheEntryTimerTask] run: 1 users left in cache.
11:04:16,506 DEBUG [SessionManager][SessionManager$ExpireSessionTimerTask] run: 1 sessions left.
11:04:17,299 DEBUG [qtp297354543-550][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Returning request: null
11:04:17,308 DEBUG [Thread-503][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
11:04:17,310 DEBUG [qtp297354543-443][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
11:04:17,311 DEBUG [qtp297354543-549][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Returning request: null
11:04:17,315 DEBUG [qtp297354543-443][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Entered.
11:04:17,315 DEBUG [Thread-504][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
11:04:17,319 DEBUG [qtp297354543-413][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Returning request: null
11:04:17,320 DEBUG [qtp297354543-412][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
11:04:17,321 DEBUG [Thread-501][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
11:04:17,322 DEBUG [qtp297354543-412][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Entered.
11:04:17,323 DEBUG [qtp297354543-434][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
11:04:17,324 DEBUG [qtp297354543-434][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Entered.
11:04:18,047 DEBUG [qtp297354543-552][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Returning request: null
11:04:18,050 DEBUG [Thread-502][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
11:04:18,058 DEBUG [qtp297354543-550][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
11:04:18,061 DEBUG [qtp297354543-550][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsfc5n--kicbkm4h9co2_dwo6362g]: Entered.
11:04:18,712 INFO [qtp297354543-442][CryptoCache] Persistence property 'cumulus4j.CryptoCache.cleanupTimer.period' is not set. Using default value 60000.
11:04:18,712 DEBUG [qtp297354543-442][MessageBrokerPMF] [vys57d] _query[requestID=q03d0s0eyio3u78vjmi7vgsb4]: Entered with request: org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyRequest@9b294be7[q03d0s0eyio3u78vjmi7vgsb4,test-iotsg7jo-1q8cmlsp098d0_d2oicy9j*1*0kstq0]
11:04:18,774 DEBUG [qtp297354543-442][MessageBrokerPMF] [vys57d] _query[requestID=q03d0s0eyio3u78vjmi7vgsb4]: Request persisted.
11:04:18,835 ERROR [qtp297354543-441][Persistence] Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@74291845" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
11:04:18,836 DEBUG [qtp297354543-551][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsg7jo-1q8cmlsp098d0_d2oicy9j]: Returning request: org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyRequest@9b294be7[q03d0s0eyio3u78vjmi7vgsb4,test-iotsg7jo-1q8cmlsp098d0_d2oicy9j*1*0kstq0]
11:04:18,836 ERROR [qtp297354543-410][Persistence] Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@1511ef67" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
11:04:18,836 WARN [qtp297354543-441][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsg7jo-1q8cmlsp098d0_d2oicy9j]: javax.jdo.JDOOptimisticVerificationException: Transaction failed to commit
NestedThrowables:
javax.jdo.JDOOptimisticVerificationException: Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@74291845" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
FailedObject:org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@9b294be7
11:04:18,838 DEBUG [qtp297354543-551][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyRequest matching=true
11:04:18,838 ERROR [qtp297354543-439][Persistence] Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@64da863a" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
11:04:18,838 WARN [qtp297354543-410][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsg7jo-1q8cmlsp098d0_d2oicy9j]: javax.jdo.JDOOptimisticVerificationException: Transaction failed to commit
NestedThrowables:
javax.jdo.JDOOptimisticVerificationException: Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@1511ef67" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
FailedObject:org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@9b294be7
11:04:18,846 WARN [qtp297354543-439][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsg7jo-1q8cmlsp098d0_d2oicy9j]: javax.jdo.JDOOptimisticVerificationException: Transaction failed to commit
NestedThrowables:
javax.jdo.JDOOptimisticVerificationException: Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@64da863a" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
FailedObject:org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@9b294be7
11:04:18,846 ERROR [qtp297354543-408][Persistence] Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@56c618d9" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
11:04:18,846 WARN [qtp297354543-408][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsg7jo-1q8cmlsp098d0_d2oicy9j]: javax.jdo.JDOOptimisticVerificationException: Transaction failed to commit
NestedThrowables:
javax.jdo.JDOOptimisticVerificationException: Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@56c618d9" (id="q03d0s0eyio3u78vjmi7vgsb4") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
FailedObject:org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@9b294be7
11:04:18,849 DEBUG [Thread-517][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Request matching=true
11:04:18,858 DEBUG [Thread-517][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyResponse matching=true
11:04:18,860 DEBUG [qtp297354543-413][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
11:04:18,862 DEBUG [qtp297354543-413][MessageBrokerPMF] [vys57d] _pushResponse[requestID=q03d0s0eyio3u78vjmi7vgsb4]: Entered.
11:04:18,893 DEBUG [qtp297354543-413][MessageBrokerPMF] [vys57d] _pollRequest[cryptoSessionIDPrefix=test-iotsg7jo-1q8cmlsp098d0_d2oicy9j]: Entered.
11:04:19,113 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Created new Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with key and IV.
11:04:19,113 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,118 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 1
11:04:19,118 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,118 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,118 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@539b9591[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:19,127 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,128 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,133 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@cf0b23b[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:19,134 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,135 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,143 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,143 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,155 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,155 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,160 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@41a7bcb0[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:19,161 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,162 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,162 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:19,164 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,164 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,165 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@25112676[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:19,166 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,166 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,168 DEBUG [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: begin loading. class=org.cumulus4j.store.test.movie.Rating
11:04:19,168 DEBUG [qtp297354543-442][Cumulus4jStoreManager] registerClass: clazz=org.cumulus4j.store.test.movie.Rating
11:04:19,169 DEBUG [qtp297354543-442][ClassMeta] jdoPreStore: org.cumulus4j.store.model.ClassMeta@3b1d739a[null,org.cumulus4j.store.test.movie.Rating]
11:04:19,170 DEBUG [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta == null => populating. this=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,171 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@3ea98612[null,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,171 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,171 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,172 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,172 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,172 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@33a351da[null,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,173 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,173 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@33a351da[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,174 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@33a351da[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,174 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,175 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,175 DEBUG [qtp297354543-442][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,176 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@33a351da[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,176 DEBUG [qtp297354543-442][ClassMeta] jdoPostDetach: attached=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,176 DEBUG [qtp297354543-442][ClassMeta] jdoPostDetach: Detaching this.fieldName2FieldMeta: attached=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,176 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3b1d739a[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,177 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@33a351da[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,177 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@33a351da[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,177 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@33a351da[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,177 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@33a351da[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,177 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,177 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,177 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,177 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@3ea98612[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,177 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6e680597[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,177 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@27f91d79[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
11:04:19,177 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@7c5267f6[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
11:04:19,177 DEBUG [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: end loading (took 9 ms). class=org.cumulus4j.store.test.movie.Rating
11:04:19,177 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6e680597[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,177 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6e680597[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,177 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 1
11:04:19,177 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,178 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,179 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 1
11:04:19,180 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6e680597[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,180 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6e680597[2,org.cumulus4j.store.test.movie.Rating]
11:04:19,181 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,181 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,183 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,183 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,184 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:19,184 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=8 value=[]
11:04:19,184 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,184 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@25112676[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:19,184 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,184 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=6 value=[]
11:04:19,184 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,185 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:19,185 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=5 value=null
11:04:19,185 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,185 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=4 value=[]
11:04:19,185 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,185 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@41a7bcb0[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:19,185 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,185 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,185 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=1 value=[]
11:04:19,185 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,185 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@cf0b23b[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:19,185 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=0 value=[]
11:04:19,185 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,185 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@539b9591[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:19,185 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 2
11:04:19,185 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,185 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,186 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 2
11:04:19,186 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@539b9591[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
11:04:19,188 TRACE [qtp297354543-442][CryptoCache] getKeyData: Found cached key with keyID=1.
11:04:19,188 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Created new Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with key and IV.
11:04:19,188 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,189 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,189 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,189 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@cf0b23b[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
11:04:19,198 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,198 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,198 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,198 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,200 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,201 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,203 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,203 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,204 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@41a7bcb0[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
11:04:19,205 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,206 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,206 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,206 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,206 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:19,209 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,209 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,209 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,209 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,209 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@25112676[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
11:04:19,211 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,212 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,212 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,212 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,213 DEBUG [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: begin loading. class=org.cumulus4j.store.test.movie.Person
11:04:19,213 DEBUG [qtp297354543-442][Cumulus4jStoreManager] registerClass: clazz=org.cumulus4j.store.test.movie.Person
11:04:19,214 DEBUG [qtp297354543-442][ClassMeta] jdoPreStore: org.cumulus4j.store.model.ClassMeta@9b18382[null,org.cumulus4j.store.test.movie.Person]
11:04:19,215 DEBUG [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta == null => populating. this=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,216 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@6c69ceb0[null,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,217 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,217 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,217 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,217 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,217 DEBUG [qtp297354543-442][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@1cea796[null,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,218 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,218 DEBUG [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@1cea796[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,218 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1cea796[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,218 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,218 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,218 DEBUG [qtp297354543-442][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,219 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1cea796[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,220 DEBUG [qtp297354543-442][ClassMeta] jdoPostDetach: attached=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,220 DEBUG [qtp297354543-442][ClassMeta] jdoPostDetach: Detaching this.fieldName2FieldMeta: attached=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,220 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@9b18382[3,org.cumulus4j.store.test.movie.Person]
11:04:19,220 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,220 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,220 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,220 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@6c69ceb0[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,220 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@1cea796[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,220 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@1cea796[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,220 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1cea796[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,220 DEBUG [qtp297354543-442][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@1cea796[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,220 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@617b4214[3,org.cumulus4j.store.test.movie.Person]
11:04:19,220 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1ad05657[17,org.cumulus4j.store.test.movie.Person#name[primary]]
11:04:19,220 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@7ada26e7[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
11:04:19,220 DEBUG [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: end loading (took 7 ms). class=org.cumulus4j.store.test.movie.Person
11:04:19,221 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@617b4214[3,org.cumulus4j.store.test.movie.Person]
11:04:19,221 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@617b4214[3,org.cumulus4j.store.test.movie.Person]
11:04:19,221 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 1
11:04:19,221 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,221 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,222 TRACE [qtp297354543-442][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 1
11:04:19,222 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@617b4214[3,org.cumulus4j.store.test.movie.Person]
11:04:19,222 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@617b4214[3,org.cumulus4j.store.test.movie.Person]
11:04:19,223 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,223 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,226 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,226 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,227 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:19,237 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,237 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,237 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=5 value=org.cumulus4j.store.test.movie.Rating@1
11:04:19,237 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,237 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Rating
11:04:19,245 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,245 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,245 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,260 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,260 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,261 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:19,262 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,262 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,263 TRACE [qtp297354543-442][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=6 value=[org.cumulus4j.store.test.movie.Person@1]
11:04:19,263 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,263 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:19,264 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Person
11:04:19,265 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,265 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,266 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,266 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:19,268 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,268 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,268 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,268 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,268 TRACE [qtp297354543-442][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4e1576f9[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
11:04:19,270 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,270 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,272 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,272 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@800213994 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,287 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:19,288 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:19,295 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClassID: found cache entry. classID=1
11:04:19,295 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:19,303 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,303 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,304 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,304 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,304 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,304 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClassID: found cache entry. classID=1
11:04:19,304 TRACE [qtp297354543-442][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
11:04:19,306 TRACE [qtp297354543-442][CryptoCache] acquireCipherEntry: Found cached Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
11:04:19,306 TRACE [qtp297354543-442][CryptoCache] releaseCipherEntry: Releasing Cipher@559316301 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
11:04:19,306 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,306 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,306 TRACE [qtp297354543-442][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@5b82f6ef[1,org.cumulus4j.store.test.movie.Movie]
11:04:19,326 DEBUG [qtp1671943153-536][AbstractService] getAuth: 'Authorization' header: Basic ZGV2aWw6dGVzdHRlc3R0ZXN0
11:04:19,327 DEBUG [qtp1671943153-536][CryptoSessionService] open: authUserName='devil' cryptoSessionID='test-iotsg7jo-1q8cmlsp098d0_d2oicy9j*1*0kstq0'
11:04:20,195 INFO [qtp297354543-549][TestUtil] loadProperties: File /home/tomcat/cumulus4j-test-datanucleus.properties does not exist. Thus not overriding any settings with user-specific ones.
11:04:20,637 WARN [qtp297354543-549][MetaData] MetaData Parser encountered an error in file "jar:file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar!/org/cumulus4j/store/model/package.jdo" at line 10, column 6 : cvc-elt.1: Cannot find the declaration of element 'jdo'. - Please check your specification of DTD and the validity of the MetaData XML that you have specified.
11:04:20,639 WARN [qtp297354543-549][MetaData] MetaData Parser encountered an error in file "jar:file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar!/org/cumulus4j/store/model/package.jdo" at line 48, column 7 : The content of element type "jdo" is incomplete, it must match "(extension*,(package|query|fetch-plan)+,extension*)". - Please check your specification of DTD and the validity of the MetaData XML that you have specified.
[ERROR] The RuntimeException could not be mapped to a response, re-throwing to the HTTP container
javax.jdo.JDOFatalInternalException: Error creating transactional connection factory
at org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:587)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:781)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
NestedThrowablesStackTrace:
java.lang.reflect.InvocationTargetException
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:325)
at org.datanucleus.store.AbstractStoreManager.registerConnectionFactory(AbstractStoreManager.java:281)
at org.datanucleus.store.AbstractStoreManager.<init>(AbstractStoreManager.java:239)
at org.cumulus4j.store.Cumulus4jStoreManager.<init>(Cumulus4jStoreManager.java:108)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:301)
at org.datanucleus.NucleusContext.createStoreManagerForProperties(NucleusContext.java:1069)
at org.datanucleus.NucleusContext.initialise(NucleusContext.java:359)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:768)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
Caused by: javax.jdo.JDODataStoreException: Exception thrown while querying indices for table=classmeta
NestedThrowables:
java.sql.SQLException: Column 'PARAM1' already exists.
at org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:451)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1564)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1581)
at org.cumulus4j.store.Cumulus4jConnectionFactory.<init>(Cumulus4jConnectionFactory.java:185)
... 78 more
Caused by: java.sql.SQLException: Column 'PARAM1' already exists.
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(Unknown Source)
at org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.prepareMetaDataStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.prepareSPS(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQueryUsingSystemTables(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetIndexInfo(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getIndexInfo(Unknown Source)
at org.datanucleus.store.rdbms.datasource.dbcp.DelegatingDatabaseMetaData.getIndexInfo(DelegatingDatabaseMetaData.java:327)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:615)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:584)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getSchemaData(RDBMSSchemaHandler.java:201)
at org.datanucleus.store.rdbms.table.TableImpl.getExistingIndices(TableImpl.java:1141)
at org.datanucleus.store.rdbms.table.TableImpl.validateIndices(TableImpl.java:572)
at org.datanucleus.store.rdbms.table.TableImpl.validateConstraints(TableImpl.java:390)
at org.datanucleus.store.rdbms.table.ClassTable.validateConstraints(ClassTable.java:3432)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.performTablesValidation(RDBMSStoreManager.java:3429)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.addClassTablesAndValidate(RDBMSStoreManager.java:3155)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.run(RDBMSStoreManager.java:2806)
at org.datanucleus.store.rdbms.AbstractSchemaTransaction.execute(AbstractSchemaTransaction.java:122)
at org.datanucleus.store.rdbms.RDBMSStoreManager.addClasses(RDBMSStoreManager.java:1570)
at org.datanucleus.store.AbstractStoreManager.addClass(AbstractStoreManager.java:953)
at org.datanucleus.store.AbstractStoreManager.getExtent(AbstractStoreManager.java:1060)
at org.datanucleus.ExecutionContextImpl.getExtent(ExecutionContextImpl.java:5472)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1560)
... 80 more
Caused by: java.sql.SQLException: Column 'PARAM1' already exists.
at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown Source)
... 115 more
Caused by: ERROR X0Y68: Column 'PARAM1' already exists.
at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.duplicateDescriptorException(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.addDescriptor(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.addSPSParams(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepareInternalStatement(Unknown Source)
... 109 more
2016-05-30 11:04:23.342:WARN::/org.cumulus4j.integrationtest.webapp/App/Test
javax.jdo.JDOFatalInternalException: Error creating transactional connection factory|NestedThrowables:|java.lang.reflect.InvocationTargetException
at org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:587)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:781)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
Caused by:
java.lang.reflect.InvocationTargetException
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:325)
at org.datanucleus.store.AbstractStoreManager.registerConnectionFactory(AbstractStoreManager.java:281)
at org.datanucleus.store.AbstractStoreManager.<init>(AbstractStoreManager.java:239)
at org.cumulus4j.store.Cumulus4jStoreManager.<init>(Cumulus4jStoreManager.java:108)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:301)
at org.datanucleus.NucleusContext.createStoreManagerForProperties(NucleusContext.java:1069)
at org.datanucleus.NucleusContext.initialise(NucleusContext.java:359)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:768)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
Caused by:
javax.jdo.JDODataStoreException: Exception thrown while querying indices for table=classmeta|NestedThrowables:|java.sql.SQLException: Column 'PARAM1' already exists.
at org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:451)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1564)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1581)
at org.cumulus4j.store.Cumulus4jConnectionFactory.<init>(Cumulus4jConnectionFactory.java:185)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:325)
at org.datanucleus.store.AbstractStoreManager.registerConnectionFactory(AbstractStoreManager.java:281)
at org.datanucleus.store.AbstractStoreManager.<init>(AbstractStoreManager.java:239)
at org.cumulus4j.store.Cumulus4jStoreManager.<init>(Cumulus4jStoreManager.java:108)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:301)
at org.datanucleus.NucleusContext.createStoreManagerForProperties(NucleusContext.java:1069)
at org.datanucleus.NucleusContext.initialise(NucleusContext.java:359)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:768)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
Caused by:
java.sql.SQLException: Column 'PARAM1' already exists.
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(Unknown Source)
at org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.prepareMetaDataStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.prepareSPS(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQueryUsingSystemTables(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetIndexInfo(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getIndexInfo(Unknown Source)
at org.datanucleus.store.rdbms.datasource.dbcp.DelegatingDatabaseMetaData.getIndexInfo(DelegatingDatabaseMetaData.java:327)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:615)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:584)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getSchemaData(RDBMSSchemaHandler.java:201)
at org.datanucleus.store.rdbms.table.TableImpl.getExistingIndices(TableImpl.java:1141)
at org.datanucleus.store.rdbms.table.TableImpl.validateIndices(TableImpl.java:572)
at org.datanucleus.store.rdbms.table.TableImpl.validateConstraints(TableImpl.java:390)
at org.datanucleus.store.rdbms.table.ClassTable.validateConstraints(ClassTable.java:3432)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.performTablesValidation(RDBMSStoreManager.java:3429)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.addClassTablesAndValidate(RDBMSStoreManager.java:3155)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.run(RDBMSStoreManager.java:2806)
at org.datanucleus.store.rdbms.AbstractSchemaTransaction.execute(AbstractSchemaTransaction.java:122)
at org.datanucleus.store.rdbms.RDBMSStoreManager.addClasses(RDBMSStoreManager.java:1570)
at org.datanucleus.store.AbstractStoreManager.addClass(AbstractStoreManager.java:953)
at org.datanucleus.store.AbstractStoreManager.getExtent(AbstractStoreManager.java:1060)
at org.datanucleus.ExecutionContextImpl.getExtent(ExecutionContextImpl.java:5472)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1560)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1581)
at org.cumulus4j.store.Cumulus4jConnectionFactory.<init>(Cumulus4jConnectionFactory.java:185)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:325)
at org.datanucleus.store.AbstractStoreManager.registerConnectionFactory(AbstractStoreManager.java:281)
at org.datanucleus.store.AbstractStoreManager.<init>(AbstractStoreManager.java:239)
at org.cumulus4j.store.Cumulus4jStoreManager.<init>(Cumulus4jStoreManager.java:108)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:301)
at org.datanucleus.NucleusContext.createStoreManagerForProperties(NucleusContext.java:1069)
at org.datanucleus.NucleusContext.initialise(NucleusContext.java:359)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:768)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
Caused by:
java.sql.SQLException: Column 'PARAM1' already exists.
at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown Source)
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(Unknown Source)
at org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.prepareMetaDataStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.prepareSPS(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQueryUsingSystemTables(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetIndexInfo(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getIndexInfo(Unknown Source)
at org.datanucleus.store.rdbms.datasource.dbcp.DelegatingDatabaseMetaData.getIndexInfo(DelegatingDatabaseMetaData.java:327)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:615)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:584)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getSchemaData(RDBMSSchemaHandler.java:201)
at org.datanucleus.store.rdbms.table.TableImpl.getExistingIndices(TableImpl.java:1141)
at org.datanucleus.store.rdbms.table.TableImpl.validateIndices(TableImpl.java:572)
at org.datanucleus.store.rdbms.table.TableImpl.validateConstraints(TableImpl.java:390)
at org.datanucleus.store.rdbms.table.ClassTable.validateConstraints(ClassTable.java:3432)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.performTablesValidation(RDBMSStoreManager.java:3429)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.addClassTablesAndValidate(RDBMSStoreManager.java:3155)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.run(RDBMSStoreManager.java:2806)
at org.datanucleus.store.rdbms.AbstractSchemaTransaction.execute(AbstractSchemaTransaction.java:122)
at org.datanucleus.store.rdbms.RDBMSStoreManager.addClasses(RDBMSStoreManager.java:1570)
at org.datanucleus.store.AbstractStoreManager.addClass(AbstractStoreManager.java:953)
at org.datanucleus.store.AbstractStoreManager.getExtent(AbstractStoreManager.java:1060)
at org.datanucleus.ExecutionContextImpl.getExtent(ExecutionContextImpl.java:5472)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1560)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1581)
at org.cumulus4j.store.Cumulus4jConnectionFactory.<init>(Cumulus4jConnectionFactory.java:185)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:325)
at org.datanucleus.store.AbstractStoreManager.registerConnectionFactory(AbstractStoreManager.java:281)
at org.datanucleus.store.AbstractStoreManager.<init>(AbstractStoreManager.java:239)
at org.cumulus4j.store.Cumulus4jStoreManager.<init>(Cumulus4jStoreManager.java:108)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:301)
at org.datanucleus.NucleusContext.createStoreManagerForProperties(NucleusContext.java:1069)
at org.datanucleus.NucleusContext.initialise(NucleusContext.java:359)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:768)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
Caused by:
ERROR X0Y68: Column 'PARAM1' already exists.
at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.duplicateDescriptorException(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.addDescriptor(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.addSPSParams(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepareInternalStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(Unknown Source)
at org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.prepareMetaDataStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.prepareSPS(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQueryUsingSystemTables(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetIndexInfo(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getIndexInfo(Unknown Source)
at org.datanucleus.store.rdbms.datasource.dbcp.DelegatingDatabaseMetaData.getIndexInfo(DelegatingDatabaseMetaData.java:327)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:615)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:584)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getSchemaData(RDBMSSchemaHandler.java:201)
at org.datanucleus.store.rdbms.table.TableImpl.getExistingIndices(TableImpl.java:1141)
at org.datanucleus.store.rdbms.table.TableImpl.validateIndices(TableImpl.java:572)
at org.datanucleus.store.rdbms.table.TableImpl.validateConstraints(TableImpl.java:390)
at org.datanucleus.store.rdbms.table.ClassTable.validateConstraints(ClassTable.java:3432)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.performTablesValidation(RDBMSStoreManager.java:3429)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.addClassTablesAndValidate(RDBMSStoreManager.java:3155)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.run(RDBMSStoreManager.java:2806)
at org.datanucleus.store.rdbms.AbstractSchemaTransaction.execute(AbstractSchemaTransaction.java:122)
at org.datanucleus.store.rdbms.RDBMSStoreManager.addClasses(RDBMSStoreManager.java:1570)
at org.datanucleus.store.AbstractStoreManager.addClass(AbstractStoreManager.java:953)
at org.datanucleus.store.AbstractStoreManager.getExtent(AbstractStoreManager.java:1060)
at org.datanucleus.ExecutionContextImpl.getExtent(ExecutionContextImpl.java:5472)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1560)
at org.datanucleus.api.jdo.JDOPersistenceManager.getExtent(JDOPersistenceManager.java:1581)
at org.cumulus4j.store.Cumulus4jConnectionFactory.<init>(Cumulus4jConnectionFactory.java:185)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:325)
at org.datanucleus.store.AbstractStoreManager.registerConnectionFactory(AbstractStoreManager.java:281)
at org.datanucleus.store.AbstractStoreManager.<init>(AbstractStoreManager.java:239)
at org.cumulus4j.store.Cumulus4jStoreManager.<init>(Cumulus4jStoreManager.java:108)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:301)
at org.datanucleus.NucleusContext.createStoreManagerForProperties(NucleusContext.java:1069)
at org.datanucleus.NucleusContext.initialise(NucleusContext.java:359)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:768)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
at java.security.AccessController.doPrivileged(Native Method)
at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
at org.eclipse.jetty.server.Server.handle(Server.java:353)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Thread.java:745)
Tests run: 3, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 69.965 sec <<< FAILURE!
Results :
Tests in error:
testUnifiedAPIWithRemoteKeyServerThoroughly(org.cumulus4j.integrationtest.withkeyserver.IntegrationWithAppServerAndKeyServerTest): Error-code=500 error-message=<html>
Tests run: 3, Failures: 0, Errors: 1, Skipped: 0
[JENKINS] Recording test results
[INFO]
[INFO] --- maven-source-plugin:2.1.2:jar-no-fork (attach-sources) @ org.cumulus4j.integrationtest.withkeyserver ---
[INFO] No sources in project. Archive not created.
[INFO]
[INFO] --- maven-install-plugin:2.4:install (default-install) @ org.cumulus4j.integrationtest.withkeyserver ---
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.integrationtest.withkeyserver/target/org.cumulus4j.integrationtest.withkeyserver-1.2.1-SNAPSHOT.jar to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.integrationtest.withkeyserver/1.2.1-SNAPSHOT/org.cumulus4j.integrationtest.withkeyserver-1.2.1-SNAPSHOT.jar
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.integrationtest.withkeyserver/pom.xml to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.integrationtest.withkeyserver/1.2.1-SNAPSHOT/org.cumulus4j.integrationtest.withkeyserver-1.2.1-SNAPSHOT.pom
Console Output
Help us localize this page