SuccessConsole Output

Skipping 395 KB.. Full Log
ring using org.datanucleus.store.types.converters.CalendarStringConverter
05:45:28,086 DEBUG [main][Persistence] Added converter for java.lang.Class<->java.lang.String using org.datanucleus.store.types.converters.ClassStringConverter
05:45:28,086 DEBUG [main][Persistence] Added converter for java.awt.Color<->java.lang.String using org.datanucleus.store.types.converters.ColorStringConverter
05:45:28,086 DEBUG [main][Persistence] Added converter for java.lang.Integer<->java.lang.String using org.datanucleus.store.types.converters.IntegerStringConverter
05:45:28,086 DEBUG [main][Persistence] Added converter for java.lang.Long<->java.lang.String using org.datanucleus.store.types.converters.LongStringConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.util.Currency<->java.lang.String using org.datanucleus.store.types.converters.CurrencyStringConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.util.Date<->java.lang.Long using org.datanucleus.store.types.converters.DateLongConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.util.Date<->java.lang.String using org.datanucleus.store.types.converters.DateStringConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.util.Locale<->java.lang.String using org.datanucleus.store.types.converters.LocaleStringConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.sql.Date<->java.lang.Long using org.datanucleus.store.types.converters.SqlDateLongConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.sql.Date<->java.lang.String using org.datanucleus.store.types.converters.SqlDateStringConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.sql.Time<->java.lang.Long using org.datanucleus.store.types.converters.SqlTimeLongConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.sql.Time<->java.lang.String using org.datanucleus.store.types.converters.SqlTimeStringConverter
05:45:28,087 DEBUG [main][Persistence] Added converter for java.sql.Timestamp<->java.lang.Long using org.datanucleus.store.types.converters.SqlTimestampLongConverter
05:45:28,088 DEBUG [main][Persistence] Added converter for java.lang.StringBuffer<->java.lang.String using org.datanucleus.store.types.converters.StringBufferStringConverter
05:45:28,088 DEBUG [main][Persistence] Added converter for java.util.TimeZone<->java.lang.String using org.datanucleus.store.types.converters.TimeZoneStringConverter
05:45:28,088 DEBUG [main][Persistence] Added converter for java.net.URI<->java.lang.String using org.datanucleus.store.types.converters.URIStringConverter
05:45:28,088 DEBUG [main][Persistence] Added converter for java.net.URL<->java.lang.String using org.datanucleus.store.types.converters.URLStringConverter
05:45:28,088 DEBUG [main][Persistence] Added converter for java.util.UUID<->java.lang.String using org.datanucleus.store.types.converters.UUIDStringConverter
05:45:28,088 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalDate<->java.lang.String ignored since java type not present in CLASSPATH
05:45:28,089 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalTime<->java.lang.String ignored since java type not present in CLASSPATH
05:45:28,089 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalTime<->java.lang.Long ignored since java type not present in CLASSPATH
05:45:28,090 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalDateTime<->java.lang.String ignored since java type not present in CLASSPATH
05:45:28,090 DEBUG [main][Persistence] Added converter for java.io.Serializable<->java.lang.String using org.datanucleus.store.types.converters.SerializableStringConverter
05:45:28,090 DEBUG [main][Persistence] Added converter for java.io.Serializable<->[B using org.datanucleus.store.types.converters.SerializableByteArrayConverter
05:45:28,090 DEBUG [main][Persistence] Type converter support loaded
05:45:28,091 DEBUG [main][MetaData] MetaDataManager : Input=(XML,Annotations), XML-Validation=false, XML-Suffices=(persistence=*.jdo, orm=orm, query=*.jdoquery), JDO-listener=true
05:45:28,091 DEBUG [main][MetaData] Registering listener for metadata initialisation
05:45:28,091 DEBUG [main][MetaData] Listener found initialisation for persistable class org.cumulus4j.store.model.EncryptionCoordinateSet
05:45:28,093 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /META-INF/package.jdo
05:45:28,093 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /WEB-INF/package.jdo
05:45:28,093 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /package.jdo
05:45:28,093 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/package.jdo
05:45:28,094 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org.jdo
05:45:28,094 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/package.jdo
05:45:28,095 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j.jdo
05:45:28,095 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/package.jdo
05:45:28,095 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store.jdo
05:45:28,096 DEBUG [main][MetaData] Parsing MetaData 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" using handler "jdo" (validation="false")
05:45:28,098 DEBUG [main][MetaData] XML Entity Public="" System="http://java.sun.com/dtd/jdo_3_0.dtd
05:45:28,617 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model.jdo
05:45:28,617 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/EncryptionCoordinateSet.jdo
05:45:28,618 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" not found
05:45:28,630 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" has been specified with JDO annotations so using those.
05:45:28,632 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" : Populating Meta-Data
05:45:28,632 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /META-INF/package.orm
05:45:28,632 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /WEB-INF/package.orm
05:45:28,632 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /package.orm
05:45:28,633 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/package.orm
05:45:28,633 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org.orm
05:45:28,633 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/package.orm
05:45:28,633 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j.orm
05:45:28,634 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/package.orm
05:45:28,634 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store.orm
05:45:28,634 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/package.orm
05:45:28,635 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model.orm
05:45:28,635 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/EncryptionCoordinateSet.orm
05:45:28,635 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" not found
05:45:28,635 DEBUG [main][Datastore] Creating StoreManager for datastore
05:45:28,641 DEBUG [main][Connection] Created tx data source using pooling type of dbcp-builtin
05:45:28,641 DEBUG [main][Connection] Registered transactional connection factory under name "rdbms/tx"
05:45:28,641 DEBUG [main][Connection] Registered nontransactional connection factory under name "rdbms/nontx"
05:45:28,646 DEBUG [main][Connection] Created nontx data source using pooling type of dbcp-builtin
05:45:30,113 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7343922c" opened
05:45:30,117 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:30,117 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=BOOLEAN, sql-type=BOOLEAN, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BooleanRDBMSMapping, default=false)
05:45:30,118 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:30,118 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Byte (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:30,118 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=true)
05:45:30,118 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:30,119 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:30,119 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Double (jdbc-type=DOUBLE, sql-type=DOUBLE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DoubleRDBMSMapping, default=true)
05:45:30,119 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Double (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=false)
05:45:30,120 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=FLOAT, sql-type=FLOAT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.FloatRDBMSMapping, default=true)
05:45:30,120 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=DOUBLE, sql-type=DOUBLE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DoubleRDBMSMapping, default=false)
05:45:30,120 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=REAL, sql-type=REAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.RealRDBMSMapping, default=false)
05:45:30,120 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=false)
05:45:30,121 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=true)
05:45:30,121 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:30,121 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:30,121 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=true)
05:45:30,121 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:30,122 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=true)
05:45:30,122 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:30,122 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:30,122 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=true)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=true)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=LONGVARCHAR, sql-type=LONGVARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.LongVarcharRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=CLOB, sql-type=CLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.ClobRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=BLOB, sql-type=BLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BlobRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=NVARCHAR, sql-type=NVARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NVarcharRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=NCHAR, sql-type=NCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NCharRDBMSMapping, default=false)
05:45:30,123 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigDecimal (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=true)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigDecimal (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigInteger (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=true)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=DATE, sql-type=DATE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DateRDBMSMapping, default=true)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=TIME, sql-type=TIME, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimeRDBMSMapping, default=true)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=true)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=true)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=DATE, sql-type=DATE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DateRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=TIME, sql-type=TIME, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimeRDBMSMapping, default=false)
05:45:30,124 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=LONGVARBINARY, sql-type=LONGVARBINARY, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.LongVarBinaryRDBMSMapping, default=true)
05:45:30,125 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=BLOB, sql-type=BLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BlobRDBMSMapping, default=false)
05:45:30,125 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=VARBINARY, sql-type=VARBINARY, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarBinaryRDBMSMapping, default=false)
05:45:30,125 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=true)
05:45:30,125 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:30,125 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:30,125 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:30,125 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:30,178 DEBUG [main][Datastore] Removing RDBMS support for Java type java.lang.String (jdbc-type=NVARCHAR, sql-type=NVARCHAR)
05:45:30,178 DEBUG [main][Datastore] Removing RDBMS support for Java type java.lang.String (jdbc-type=NCHAR, sql-type=NCHAR)
05:45:30,185 DEBUG [main][Datastore] ======================= Datastore =========================
05:45:30,186 DEBUG [main][Datastore] StoreManager : "rdbms" (org.datanucleus.store.rdbms.RDBMSStoreManager)
05:45:30,186 DEBUG [main][Datastore] Datastore : read-write
05:45:30,186 DEBUG [main][Datastore] Schema Control : AutoCreate(Tables), Validate(None)
05:45:30,186 DEBUG [main][Datastore] Query Languages : [JDOQL, JPQL, SQL, STOREDPROC]
05:45:30,186 DEBUG [main][Datastore] Queries : Timeout=0
05:45:30,186 DEBUG [main][Datastore] ===========================================================
05:45:30,186 DEBUG [main][Datastore] Datastore Adapter : org.datanucleus.store.rdbms.adapter.DerbyAdapter
05:45:30,186 DEBUG [main][Datastore] Datastore : name="Apache Derby" version="10.7.1.1 - (1040133)"
05:45:30,186 DEBUG [main][Datastore] Datastore Driver : name="Apache Derby Embedded JDBC Driver" version="10.7.1.1 - (1040133)"
05:45:30,186 DEBUG [main][Datastore] Primary Connection Factory : URL[jdbc:derby:/tmp/cumulus4j-test.iw5oeeve/derby/cumulus4j;create=true]
05:45:30,186 DEBUG [main][Datastore] Secondary Connection Factory : URL[jdbc:derby:/tmp/cumulus4j-test.iw5oeeve/derby/cumulus4j;create=true]
05:45:30,186 DEBUG [main][Datastore] Datastore Identifiers : factory="datanucleus2" case=UPPERCASE catalog= schema=ROOT
05:45:30,186 DEBUG [main][Datastore] Supported Identifier Cases : "MixedCase" UPPERCASE "MixedCase-Sensitive" 
05:45:30,186 DEBUG [main][Datastore] Supported Identifier Lengths (max) : Table=128 Column=128 Constraint=128 Index=128 Delimiter="
05:45:30,186 DEBUG [main][Datastore] Support for Identifiers in DDL : catalog=false schema=true
05:45:30,186 DEBUG [main][Datastore] Datastore : checkTableViewExistence, rdbmsConstraintCreateMode=DataNucleus, initialiseColumnInfo=ALL
05:45:30,186 DEBUG [main][Datastore] Support Statement Batching : yes (max-batch-size=50)
05:45:30,186 DEBUG [main][Datastore] Queries : Results direction=forward, type=forward-only, concurrency=read-only
05:45:30,186 DEBUG [main][Datastore] Java-Types : string-default-length=255
05:45:30,186 DEBUG [main][Datastore] JDBC-Types : VARCHAR, LONGVARCHAR, BINARY, BOOLEAN, VARBINARY, LONGVARBINARY, BIGINT, JAVA_OBJECT, [id=2009], CHAR, NUMERIC, DECIMAL, INTEGER, CLOB, SMALLINT, BLOB, FLOAT, REAL, DOUBLE, DATE, TIME, TIMESTAMP
05:45:30,186 DEBUG [main][Datastore] ===========================================================
05:45:30,204 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7343922c" non enlisted to a transaction is being committed.
05:45:30,205 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7343922c" closed
05:45:30,205 DEBUG [main][Datastore] StoreManager now created
05:45:30,205 DEBUG [main][Persistence] ================= NucleusContext ===============
05:45:30,205 DEBUG [main][Persistence] DataNucleus Context : Version "3.2.4" with JRE "1.8.0_91" on "Linux"
05:45:30,205 DEBUG [main][Persistence] Persistence API : JDO
05:45:30,205 DEBUG [main][Persistence] Plugin Registry : org.datanucleus.plugin.NonManagedPluginRegistry
05:45:30,205 DEBUG [main][Persistence] ClassLoading : datanucleus
05:45:30,206 DEBUG [main][Persistence] Persistence : pm-singlethreaded, nontransactional-read, nontransactional-write, reachability-at-commit, copy-on-attach, managed-relations(checked), deletion-policy=JDO2, serverTimeZone=Europe/Berlin
05:45:30,206 DEBUG [main][Persistence] AutoStart : mechanism=None, mode=Quiet
05:45:30,206 DEBUG [main][Persistence] Transactions : type=RESOURCE_LOCAL, mode=datastore, isolation=read-committed
05:45:30,206 DEBUG [main][Persistence] ValueGeneration : txn-isolation=read-committed connection=New
05:45:30,206 DEBUG [main][Persistence] Cache : Level1 (soft), Level2 (soft, mode=UNSPECIFIED), QueryResults (soft), Collections/Maps 
05:45:30,206 DEBUG [main][Persistence] ================================================
05:45:30,207 DEBUG [main][Cache] Level 2 Cache of type "soft" initialised
05:45:30,208 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:45:30,208 TRACE [main][AbstractCryptoSession] setCryptoSessionID: cryptoSessionID=832fc7ec-2988-4bf7-9e8d-8510d4cff6d5
05:45:30,208 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:45:30,209 DEBUG [main][Persistence] Started pool of ExecutionContext (maxPool=20, reaperThread=false)
05:45:30,210 DEBUG [main][Persistence] ExecutionContext "org.datanucleus.ExecutionContextImpl@28237492" opened for datastore "org.datanucleus.store.rdbms.RDBMSStoreManager@5ceecfee" with txn="org.datanucleus.TransactionImpl@7da31a40"
05:45:30,210 DEBUG [main][Cache] Level 1 Cache of type "soft" initialised
05:45:30,344 INFO  [main][AbstractCryptoManager] getEncryptionAlgorithm: Property 'cumulus4j.encryptionAlgorithm' is set to 'Twofish/CFB/NoPadding'. Using this encryption algorithm.
05:45:30,344 INFO  [main][AbstractCryptoManager] getMACAlgorithm: Property 'cumulus4j.macAlgorithm' is set to 'HMAC-SHA256'. Using this MAC algorithm.
05:45:30,344 DEBUG [main][Cache] Query Cache of type "org.datanucleus.query.cache.SoftQueryCompilationCache" initialised
05:45:30,345 DEBUG [main][Cache] Query Cache of type "org.datanucleus.store.query.cache.SoftQueryDatastoreCompilationCache" initialised
05:45:30,345 DEBUG [main][Cache] Query Cache of type "org.datanucleus.store.query.cache.SoftQueryResultsCache" initialised
05:45:30,345 DEBUG [main][Query] JDOQL Single-String with "SELECT UNIQUE WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm"
05:45:30,345 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" : Initialising Meta-Data
05:45:30,346 DEBUG [main][Persistence] Managing Persistence of Class : org.cumulus4j.store.model.EncryptionCoordinateSet [Table : ENCRYPTIONCOORDINATESET, InheritanceStrategy : new-table]
05:45:30,346 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.ENCRYPTIONCOORDINATESETID" added to internal representation of table.
05:45:30,346 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.encryptionCoordinateSetID] -> Column(s) [ENCRYPTIONCOORDINATESET.ENCRYPTIONCOORDINATESETID] using mapping of type "org.datanucleus.store.rdbms.mapping.java.LongMapping" (org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping)
05:45:30,346 DEBUG [main][Schema] Table ENCRYPTIONCOORDINATESET will manage the persistence of the fields for class org.cumulus4j.store.model.EncryptionCoordinateSet (inheritance strategy="new-table") 
05:45:30,347 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.CIPHERTRANSFORMATION" added to internal representation of table.
05:45:30,347 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.cipherTransformation] -> Column(s) [ENCRYPTIONCOORDINATESET.CIPHERTRANSFORMATION] using mapping of type "org.datanucleus.store.rdbms.mapping.java.StringMapping" (org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping)
05:45:30,347 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.MACALGORITHM" added to internal representation of table.
05:45:30,347 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.macAlgorithm] -> Column(s) [ENCRYPTIONCOORDINATESET.MACALGORITHM] using mapping of type "org.datanucleus.store.rdbms.mapping.java.StringMapping" (org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping)
05:45:30,348 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.VERSION" added to internal representation of table.
05:45:30,348 DEBUG [main][Schema] Table/View ENCRYPTIONCOORDINATESET has been initialised
05:45:30,349 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7a4d582c" opened with isolation level "serializable" and auto-commit=false
05:45:30,349 DEBUG [main][Schema] Schema Transaction started with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7a4d582c" with isolation "serializable"
05:45:30,381 DEBUG [main][Schema] Check of existence of ENCRYPTIONCOORDINATESET returned no table
05:45:30,382 DEBUG [main][Schema] Creating table ENCRYPTIONCOORDINATESET
05:45:30,382 DEBUG [main][Schema] CREATE TABLE ENCRYPTIONCOORDINATESET
(
    ENCRYPTIONCOORDINATESETID BIGINT NOT NULL generated always as identity (start with 1),
    CIPHERTRANSFORMATION VARCHAR(255) NOT NULL,
    MACALGORITHM VARCHAR(255) NOT NULL,
    VERSION BIGINT NOT NULL
)
05:45:30,396 DEBUG [main][Schema] Execution Time = 14 ms
05:45:30,396 DEBUG [main][Schema] ALTER TABLE ENCRYPTIONCOORDINATESET ADD CONSTRAINT ENCRYPTIONCOORDINATESET_PK PRIMARY KEY (ENCRYPTIONCOORDINATESETID)
05:45:30,425 DEBUG [main][Schema] Execution Time = 29 ms
05:45:30,446 DEBUG [main][Schema] Schema Transaction committing with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7a4d582c"
05:45:30,452 DEBUG [main][Schema] Schema Transaction closing with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7a4d582c"
05:45:30,452 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7a4d582c" non enlisted to a transaction is being committed.
05:45:30,452 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7a4d582c" closed
05:45:30,452 DEBUG [main][Query] JDOQL Query : Compiling "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm"
05:45:30,453 DEBUG [main][Query] JDOQL Query : Compile Time = 1 ms
05:45:30,453 DEBUG [main][Query] QueryCompilation:
  [filter:DyadicExpression{DyadicExpression{PrimaryExpression{this.cipherTransformation}  =  ParameterExpression{cipherTransformation}}  AND  DyadicExpression{PrimaryExpression{this.macAlgorithm}  =  ParameterExpression{macAlgorithm}}}]
  [symbols: macAlgorithm type=java.lang.String, this type=org.cumulus4j.store.model.EncryptionCoordinateSet, cipherTransformation type=java.lang.String]
05:45:30,453 DEBUG [main][Query] JDOQL Query : Compiling "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm" for datastore
05:45:30,456 DEBUG [main][Query] JDOQL Query : Compile Time for datastore = 3 ms
05:45:30,456 DEBUG [main][Query] SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm Query compiled to datastore query "SELECT 'org.cumulus4j.store.model.EncryptionCoordinateSet' AS NUCLEUS_TYPE,A0.CIPHERTRANSFORMATION,A0.ENCRYPTIONCOORDINATESETID,A0.MACALGORITHM,A0.VERSION FROM ENCRYPTIONCOORDINATESET A0 WHERE A0.CIPHERTRANSFORMATION = ? AND A0.MACALGORITHM = ?"
05:45:30,456 DEBUG [main][Connection] Connection added to the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@17aa8a11 [conn=null, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@28237492 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@71b639d0]
05:45:30,456 DEBUG [main][Query] JDOQL Query : Executing "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm" ...
05:45:30,457 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@18a25bbd" opened with isolation level "read-committed" and auto-commit=false
05:45:30,469 DEBUG [main][Datastore] Closing PreparedStatement "org.datanucleus.store.rdbms.datasource.dbcp.DelegatingPreparedStatement@316acbb5"
05:45:30,470 DEBUG [main][Native] SELECT 'org.cumulus4j.store.model.EncryptionCoordinateSet' AS NUCLEUS_TYPE,A0.CIPHERTRANSFORMATION,A0.ENCRYPTIONCOORDINATESETID,A0.MACALGORITHM,A0.VERSION FROM ENCRYPTIONCOORDINATESET A0 WHERE A0.CIPHERTRANSFORMATION = <'TWOFISH/CFB/NOPADDING'> AND A0.MACALGORITHM = <'HMAC-SHA256'>
05:45:30,471 DEBUG [main][Retrieve] Execution Time = 1 ms
05:45:30,471 DEBUG [main][Query] JDOQL Query : Execution Time = 15 ms
05:45:30,471 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@18a25bbd" non enlisted to a transaction is being committed.
05:45:30,472 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@18a25bbd" closed
05:45:30,472 DEBUG [main][Connection] Connection removed from the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@17aa8a11 [conn=org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@18a25bbd, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@28237492 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@71b639d0]
05:45:30,472 DEBUG [main][Persistence] Making object persistent : "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9"
05:45:30,472 DEBUG [main][Persistence] Started pool of ObjectProviders (maxPool=0, reaperThread=false)
05:45:30,473 DEBUG [main][Persistence] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" being inserted into table "ENCRYPTIONCOORDINATESET"
05:45:30,473 DEBUG [main][Connection] Connection added to the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1e60b459 [conn=null, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@28237492 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@71b639d0]
05:45:30,473 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@717d7587" opened with isolation level "read-committed" and auto-commit=false
05:45:30,478 DEBUG [main][Datastore] Using PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@7c0777b5" for connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@717d7587"
05:45:30,478 DEBUG [main][Native] INSERT INTO ENCRYPTIONCOORDINATESET (CIPHERTRANSFORMATION,MACALGORITHM,VERSION) VALUES (<'TWOFISH/CFB/NOPADDING'>,<'HMAC-SHA256'>,<1>)
05:45:30,480 DEBUG [main][Persist] Execution Time = 2 ms (number of rows = 1) on PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@7c0777b5"
05:45:30,484 DEBUG [main][Persist] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" was inserted in the datastore and was given strategy value of "1"
05:45:30,484 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") added to Level 1 cache (loadedFlags="[YYY]")
05:45:30,484 DEBUG [main][Datastore] Closing PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@7c0777b5"
05:45:30,489 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@717d7587" non enlisted to a transaction is being committed.
05:45:30,489 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@717d7587" closed
05:45:30,489 DEBUG [main][Connection] Connection removed from the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1e60b459 [conn=org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@717d7587, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@28237492 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@71b639d0]
05:45:30,490 DEBUG [main][Persistence] ExecutionContext.internalFlush() process started using ordered flush - 1 enlisted objects
05:45:30,490 DEBUG [main][Persistence] ExecutionContext.internalFlush() process finished
05:45:30,490 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" (id="1") added to Level 2 cache (fields="[0, 1, 2]", version="1")
05:45:30,490 DEBUG [main][Lifecycle] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") has a lifecycle change : "P_NEW"->"HOLLOW"
05:45:30,490 DEBUG [main][Transaction] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") being evicted from transactional cache
05:45:30,491 DEBUG [main][Persistence] Detaching copy of object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" (depth=0) as "org.cumulus4j.store.model.EncryptionCoordinateSet@5731d3a" with detached-fields [0, 1, 2] and fields-to-load=[0, 2]
05:45:30,491 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" (id="1") is loading the following fields from the Level 2 cache object : [0, 2]
05:45:30,491 DEBUG [main][Lifecycle] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") has a lifecycle change : "HOLLOW"->"P_NONTRANS"
05:45:37,158 INFO  [main][CryptoCache] Persistence property 'cumulus4j.CryptoCache.cleanupTimer.period' is not set. Using default value 60000.
05:45:37,256 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@1892062598 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:37,328 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@1892062598 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING keyID=123.
05:45:37,329 TRACE [main][CryptoCache] acquireCipherEntry: Found cached Cipher@1892062598 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING and keyID=123. Initialising it with new IV (without key).
05:45:37,372 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@1892062598 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING keyID=123.
05:45:37,372 TRACE [main][CryptoCache] clear: entered
05:45:37,471 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@1841421417 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:37,499 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@1841421417 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING keyID=123.
05:45:37,520 TRACE [main][CryptoCache] clear: entered
05:45:37,521 TRACE [main][CryptoCache] getKeyData: No cached key with keyID=123 found.
05:45:37,616 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@2124360754 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:37,663 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@2124360754 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING keyID=123.
05:45:37,772 TRACE [main][CryptoCache] acquireCipherEntry: Found cached Cipher@2124360754 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING and keyID=123. Initialising it with new IV (without key).
05:45:37,800 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@2124360754 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING keyID=123.
05:45:37,800 TRACE [main][CryptoCache] clear: entered
05:45:37,800 TRACE [main][CryptoCache] getKeyData: No cached key with keyID=123 found.
05:45:37,899 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@434167806 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:37,926 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@434167806 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/CFB/NOPADDING keyID=123.
05:45:37,941 DEBUG [main][Persistence] Disconnecting org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9 from StateManager[pc=org.cumulus4j.store.model.EncryptionCoordinateSet@7930ffa9, lifecycle=P_NONTRANS]
05:45:37,941 DEBUG [main][Cache] Object with id="org.cumulus4j.store.model.EncryptionCoordinateSet:1" being removed from Level 1 cache [current cache size = 1]
05:45:37,941 DEBUG [main][Cache] Level 1 Cache cleared
05:45:37,941 DEBUG [main][Persistence] ExecutionContext "org.datanucleus.ExecutionContextImpl@28237492" closed
05:45:38,047 DEBUG [main][Persistence] Unmanaging Persistence of all classes
05:45:38,047 DEBUG [main][MetaData] Deregistering listener for metadata initialisation
05:45:38,048 DEBUG [main][Cache] Level 2 Cache cleared
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 29.507 sec
Running org.cumulus4j.store.crypto.keymanager.test.TestKeyManagerCryptoSession_default
05:45:38,170 WARN  [main][MessageBrokerRegistry] setActiveMessageBroker: java.lang.IllegalStateException: An active MessageBroker already exists! Changing the active MessageBroker now is highly discouraged as it may cause errors!
java.lang.IllegalStateException: An active MessageBroker already exists! Changing the active MessageBroker now is highly discouraged as it may cause errors!
	at org.cumulus4j.store.crypto.keymanager.messagebroker.MessageBrokerRegistry.setActiveMessageBroker(MessageBrokerRegistry.java:117)
	at org.cumulus4j.store.crypto.keymanager.test.MockMessageBroker.setMockSharedInstance(MockMessageBroker.java:41)
	at org.cumulus4j.store.crypto.keymanager.test.AbstractKeyManagerCryptoSessionTest.beforeClass(AbstractKeyManagerCryptoSessionTest.java:74)
	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 org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:27)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:119)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:101)
	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 org.apache.maven.surefire.booter.ProviderFactory$ClassLoaderProxy.invoke(ProviderFactory.java:103)
	at com.sun.proxy.$Proxy0.invoke(Unknown Source)
	at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:150)
	at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcess(SurefireStarter.java:91)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:69)
05:45:38,171 INFO  [main][MessageBrokerRegistry] setActiveMessageBroker: New activeMessageBroker=org.cumulus4j.store.crypto.keymanager.test.MockMessageBroker@4833eff3
05:45:38,174 DEBUG [main][General] Plugin Registry "org.datanucleus.plugin.EclipsePluginRegistry" not found. Falling back to DataNucleus registry. Reason : Class "org.eclipse.core.runtime.RegistryFactory" was not found in the CLASSPATH. Please check your specification and your CLASSPATH..
05:45:38,174 DEBUG [main][General] Using PluginRegistry org.datanucleus.plugin.NonManagedPluginRegistry
05:45:38,177 DEBUG [main][General] Registering bundle org.cumulus4j.store version 1.2.1.SNAPSHOT at URL file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar.
05:45:38,179 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar!/plugin.xml.
05:45:38,180 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar!/plugin.xml.
05:45:38,180 DEBUG [main][General] Registering bundle org.datanucleus.api.jdo version 3.2.3 at URL file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-api-jdo/3.2.3/datanucleus-api-jdo-3.2.3.jar.
05:45:38,181 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-api-jdo/3.2.3/datanucleus-api-jdo-3.2.3.jar!/plugin.xml.
05:45:38,181 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-api-jdo/3.2.3/datanucleus-api-jdo-3.2.3.jar!/plugin.xml.
05:45:38,182 WARN  [main][General] Could not find MANIFEST.MF file for plugin file "file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.crypto.keymanager/target/classes/plugin.xml" so ignoring it
05:45:38,182 DEBUG [main][General] Registering bundle org.datanucleus.store.rdbms version 3.2.3 at URL file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-rdbms/3.2.3/datanucleus-rdbms-3.2.3.jar.
05:45:38,186 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-rdbms/3.2.3/datanucleus-rdbms-3.2.3.jar!/plugin.xml.
05:45:38,188 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-rdbms/3.2.3/datanucleus-rdbms-3.2.3.jar!/plugin.xml.
05:45:38,189 DEBUG [main][General] Registering bundle org.datanucleus version 3.2.4 at URL file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-core/3.2.4/datanucleus-core-3.2.4.jar.
05:45:38,191 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-core/3.2.4/datanucleus-core-3.2.4.jar!/plugin.xml.
05:45:38,195 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-core/3.2.4/datanucleus-core-3.2.4.jar!/plugin.xml.
05:45:38,197 DEBUG [main][Persistence] Java types support initialising ...
05:45:38,200 DEBUG [main][Persistence] Java types support loaded : supported java types=java.awt.Color, java.lang.Float, [Ljava.lang.Integer;, java.sql.Time, java.util.SortedSet, java.net.URL, java.util.Date, java.util.PriorityQueue, float, [Ljava.lang.Character;, [Ljava.lang.Double;, java.lang.Integer, java.math.BigDecimal, java.util.Vector, java.lang.Character, java.lang.Enum, java.lang.Long, java.lang.Short, java.util.Locale, java.util.Map, java.math.BigInteger, java.net.URI, java.lang.Byte, java.util.GregorianCalendar, java.awt.image.BufferedImage, byte, double, java.util.TimeZone, java.sql.Timestamp, java.util.Collection, java.util.Set, java.util.UUID, [Ljava.lang.String;, java.util.List, [Ljava.lang.Short;, java.util.Queue, java.util.SortedMap, [Ljava.lang.Enum;, [Ljava.lang.Boolean;, java.lang.Double, [Ljava.util.Date;, [B, [C, [D, java.util.HashMap, java.util.Currency, [F, long, java.util.Stack, java.util.TreeSet, [I, java.util.ArrayList, [J, java.util.HashSet, java.util.LinkedHashMap, java.util.Calendar, java.lang.StringBuffer, [S, [Ljava.math.BigInteger;, java.lang.Boolean, [Ljava.lang.Number;, java.lang.String, [Ljava.math.BigDecimal;, java.lang.Number, java.util.LinkedList, java.util.Hashtable, java.util.LinkedHashSet, [Z, [Ljava.lang.Float;, java.util.Properties, [Ljava.lang.Byte;, [Ljava.util.Locale;, int, java.sql.Date, boolean, java.util.TreeMap, [Ljava.lang.Long;, char, short, java.lang.Class, java.util.BitSet, java.util.Arrays$ArrayList
05:45:38,200 DEBUG [main][Persistence] Type converter support initialising ...
05:45:38,200 DEBUG [main][Persistence] Added converter for java.math.BigDecimal<->java.lang.String using org.datanucleus.store.types.converters.BigDecimalStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.math.BigInteger<->java.lang.String using org.datanucleus.store.types.converters.BigIntegerStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.util.BitSet<->java.lang.String using org.datanucleus.store.types.converters.BitSetStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.util.Calendar<->java.lang.String using org.datanucleus.store.types.converters.CalendarStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.lang.Class<->java.lang.String using org.datanucleus.store.types.converters.ClassStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.awt.Color<->java.lang.String using org.datanucleus.store.types.converters.ColorStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.lang.Integer<->java.lang.String using org.datanucleus.store.types.converters.IntegerStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.lang.Long<->java.lang.String using org.datanucleus.store.types.converters.LongStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.util.Currency<->java.lang.String using org.datanucleus.store.types.converters.CurrencyStringConverter
05:45:38,200 DEBUG [main][Persistence] Added converter for java.util.Date<->java.lang.Long using org.datanucleus.store.types.converters.DateLongConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.util.Date<->java.lang.String using org.datanucleus.store.types.converters.DateStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.util.Locale<->java.lang.String using org.datanucleus.store.types.converters.LocaleStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.sql.Date<->java.lang.Long using org.datanucleus.store.types.converters.SqlDateLongConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.sql.Date<->java.lang.String using org.datanucleus.store.types.converters.SqlDateStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.sql.Time<->java.lang.Long using org.datanucleus.store.types.converters.SqlTimeLongConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.sql.Time<->java.lang.String using org.datanucleus.store.types.converters.SqlTimeStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.sql.Timestamp<->java.lang.Long using org.datanucleus.store.types.converters.SqlTimestampLongConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.lang.StringBuffer<->java.lang.String using org.datanucleus.store.types.converters.StringBufferStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.util.TimeZone<->java.lang.String using org.datanucleus.store.types.converters.TimeZoneStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.net.URI<->java.lang.String using org.datanucleus.store.types.converters.URIStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.net.URL<->java.lang.String using org.datanucleus.store.types.converters.URLStringConverter
05:45:38,201 DEBUG [main][Persistence] Added converter for java.util.UUID<->java.lang.String using org.datanucleus.store.types.converters.UUIDStringConverter
05:45:38,201 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalDate<->java.lang.String ignored since java type not present in CLASSPATH
05:45:38,202 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalTime<->java.lang.String ignored since java type not present in CLASSPATH
05:45:38,202 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalTime<->java.lang.Long ignored since java type not present in CLASSPATH
05:45:38,203 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalDateTime<->java.lang.String ignored since java type not present in CLASSPATH
05:45:38,203 DEBUG [main][Persistence] Added converter for java.io.Serializable<->java.lang.String using org.datanucleus.store.types.converters.SerializableStringConverter
05:45:38,203 DEBUG [main][Persistence] Added converter for java.io.Serializable<->[B using org.datanucleus.store.types.converters.SerializableByteArrayConverter
05:45:38,203 DEBUG [main][Persistence] Type converter support loaded
05:45:38,203 DEBUG [main][MetaData] MetaDataManager : Input=(XML,Annotations), XML-Validation=false, XML-Suffices=(persistence=*.jdo, orm=orm, query=*.jdoquery), JDO-listener=true
05:45:38,203 DEBUG [main][MetaData] Registering listener for metadata initialisation
05:45:38,203 DEBUG [main][MetaData] Listener found initialisation for persistable class org.cumulus4j.store.model.EncryptionCoordinateSet
05:45:38,203 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /META-INF/package.jdo
05:45:38,204 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /WEB-INF/package.jdo
05:45:38,204 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /package.jdo
05:45:38,205 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/package.jdo
05:45:38,205 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org.jdo
05:45:38,205 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/package.jdo
05:45:38,205 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j.jdo
05:45:38,206 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/package.jdo
05:45:38,206 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store.jdo
05:45:38,206 DEBUG [main][MetaData] Parsing MetaData 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" using handler "jdo" (validation="false")
05:45:38,208 DEBUG [main][MetaData] XML Entity Public="" System="http://java.sun.com/dtd/jdo_3_0.dtd
05:45:38,589 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model.jdo
05:45:38,590 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/EncryptionCoordinateSet.jdo
05:45:38,590 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" not found
05:45:38,592 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" has been specified with JDO annotations so using those.
05:45:38,595 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" : Populating Meta-Data
05:45:38,595 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /META-INF/package.orm
05:45:38,595 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /WEB-INF/package.orm
05:45:38,596 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /package.orm
05:45:38,596 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/package.orm
05:45:38,596 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org.orm
05:45:38,596 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/package.orm
05:45:38,596 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j.orm
05:45:38,597 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/package.orm
05:45:38,597 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store.orm
05:45:38,597 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/package.orm
05:45:38,597 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model.orm
05:45:38,597 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/EncryptionCoordinateSet.orm
05:45:38,598 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" not found
05:45:38,598 DEBUG [main][Datastore] Creating StoreManager for datastore
05:45:38,603 DEBUG [main][Connection] Created tx data source using pooling type of dbcp-builtin
05:45:38,603 DEBUG [main][Connection] Registered transactional connection factory under name "rdbms/tx"
05:45:38,603 DEBUG [main][Connection] Registered nontransactional connection factory under name "rdbms/nontx"
05:45:38,607 DEBUG [main][Connection] Created nontx data source using pooling type of dbcp-builtin
05:45:39,847 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@53b1a3f8" opened
05:45:39,851 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:39,851 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=BOOLEAN, sql-type=BOOLEAN, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BooleanRDBMSMapping, default=false)
05:45:39,851 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:39,852 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Byte (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:39,852 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=true)
05:45:39,852 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:39,852 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:39,852 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Double (jdbc-type=DOUBLE, sql-type=DOUBLE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DoubleRDBMSMapping, default=true)
05:45:39,853 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Double (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=false)
05:45:39,853 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=FLOAT, sql-type=FLOAT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.FloatRDBMSMapping, default=true)
05:45:39,853 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=DOUBLE, sql-type=DOUBLE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DoubleRDBMSMapping, default=false)
05:45:39,853 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=REAL, sql-type=REAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.RealRDBMSMapping, default=false)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=false)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=true)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=true)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=true)
05:45:39,854 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=true)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=true)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=LONGVARCHAR, sql-type=LONGVARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.LongVarcharRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=CLOB, sql-type=CLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.ClobRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=BLOB, sql-type=BLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BlobRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=NVARCHAR, sql-type=NVARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NVarcharRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=NCHAR, sql-type=NCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NCharRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigDecimal (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=true)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigDecimal (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:39,855 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigInteger (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=true)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=DATE, sql-type=DATE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DateRDBMSMapping, default=true)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=TIME, sql-type=TIME, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimeRDBMSMapping, default=true)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=true)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=true)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=DATE, sql-type=DATE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DateRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=TIME, sql-type=TIME, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimeRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=LONGVARBINARY, sql-type=LONGVARBINARY, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.LongVarBinaryRDBMSMapping, default=true)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=BLOB, sql-type=BLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BlobRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=VARBINARY, sql-type=VARBINARY, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarBinaryRDBMSMapping, default=false)
05:45:39,856 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=true)
05:45:39,857 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:39,857 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:39,857 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:39,857 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:39,913 DEBUG [main][Datastore] Removing RDBMS support for Java type java.lang.String (jdbc-type=NVARCHAR, sql-type=NVARCHAR)
05:45:39,913 DEBUG [main][Datastore] Removing RDBMS support for Java type java.lang.String (jdbc-type=NCHAR, sql-type=NCHAR)
05:45:39,918 DEBUG [main][Datastore] ======================= Datastore =========================
05:45:39,918 DEBUG [main][Datastore] StoreManager : "rdbms" (org.datanucleus.store.rdbms.RDBMSStoreManager)
05:45:39,918 DEBUG [main][Datastore] Datastore : read-write
05:45:39,918 DEBUG [main][Datastore] Schema Control : AutoCreate(Tables), Validate(None)
05:45:39,918 DEBUG [main][Datastore] Query Languages : [JDOQL, JPQL, SQL, STOREDPROC]
05:45:39,918 DEBUG [main][Datastore] Queries : Timeout=0
05:45:39,918 DEBUG [main][Datastore] ===========================================================
05:45:39,918 DEBUG [main][Datastore] Datastore Adapter : org.datanucleus.store.rdbms.adapter.DerbyAdapter
05:45:39,918 DEBUG [main][Datastore] Datastore : name="Apache Derby" version="10.7.1.1 - (1040133)"
05:45:39,918 DEBUG [main][Datastore] Datastore Driver : name="Apache Derby Embedded JDBC Driver" version="10.7.1.1 - (1040133)"
05:45:39,918 DEBUG [main][Datastore] Primary Connection Factory : URL[jdbc:derby:/tmp/cumulus4j-test.r4x94meo/derby/cumulus4j;create=true]
05:45:39,918 DEBUG [main][Datastore] Secondary Connection Factory : URL[jdbc:derby:/tmp/cumulus4j-test.r4x94meo/derby/cumulus4j;create=true]
05:45:39,918 DEBUG [main][Datastore] Datastore Identifiers : factory="datanucleus2" case=UPPERCASE catalog= schema=ROOT
05:45:39,918 DEBUG [main][Datastore] Supported Identifier Cases : "MixedCase" UPPERCASE "MixedCase-Sensitive" 
05:45:39,918 DEBUG [main][Datastore] Supported Identifier Lengths (max) : Table=128 Column=128 Constraint=128 Index=128 Delimiter="
05:45:39,918 DEBUG [main][Datastore] Support for Identifiers in DDL : catalog=false schema=true
05:45:39,918 DEBUG [main][Datastore] Datastore : checkTableViewExistence, rdbmsConstraintCreateMode=DataNucleus, initialiseColumnInfo=ALL
05:45:39,918 DEBUG [main][Datastore] Support Statement Batching : yes (max-batch-size=50)
05:45:39,918 DEBUG [main][Datastore] Queries : Results direction=forward, type=forward-only, concurrency=read-only
05:45:39,918 DEBUG [main][Datastore] Java-Types : string-default-length=255
05:45:39,919 DEBUG [main][Datastore] JDBC-Types : VARCHAR, LONGVARCHAR, BINARY, BOOLEAN, VARBINARY, LONGVARBINARY, BIGINT, JAVA_OBJECT, [id=2009], CHAR, NUMERIC, DECIMAL, INTEGER, CLOB, SMALLINT, BLOB, FLOAT, REAL, DOUBLE, DATE, TIME, TIMESTAMP
05:45:39,919 DEBUG [main][Datastore] ===========================================================
05:45:39,936 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@53b1a3f8" non enlisted to a transaction is being committed.
05:45:39,936 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@53b1a3f8" closed
05:45:39,936 DEBUG [main][Datastore] StoreManager now created
05:45:39,936 DEBUG [main][Persistence] ================= NucleusContext ===============
05:45:39,936 DEBUG [main][Persistence] DataNucleus Context : Version "3.2.4" with JRE "1.8.0_91" on "Linux"
05:45:39,936 DEBUG [main][Persistence] Persistence API : JDO
05:45:39,936 DEBUG [main][Persistence] Plugin Registry : org.datanucleus.plugin.NonManagedPluginRegistry
05:45:39,936 DEBUG [main][Persistence] ClassLoading : datanucleus
05:45:39,936 DEBUG [main][Persistence] Persistence : pm-singlethreaded, nontransactional-read, nontransactional-write, reachability-at-commit, copy-on-attach, managed-relations(checked), deletion-policy=JDO2, serverTimeZone=Europe/Berlin
05:45:39,936 DEBUG [main][Persistence] AutoStart : mechanism=None, mode=Quiet
05:45:39,936 DEBUG [main][Persistence] Transactions : type=RESOURCE_LOCAL, mode=datastore, isolation=read-committed
05:45:39,936 DEBUG [main][Persistence] ValueGeneration : txn-isolation=read-committed connection=New
05:45:39,936 DEBUG [main][Persistence] Cache : Level1 (soft), Level2 (soft, mode=UNSPECIFIED), QueryResults (soft), Collections/Maps 
05:45:39,936 DEBUG [main][Persistence] ================================================
05:45:39,936 DEBUG [main][Cache] Level 2 Cache of type "soft" initialised
05:45:39,937 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:45:39,937 TRACE [main][AbstractCryptoSession] setCryptoSessionID: cryptoSessionID=2cc38731-b3e8-4beb-95e1-32365f396ba0
05:45:39,937 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:45:39,937 DEBUG [main][Persistence] Started pool of ExecutionContext (maxPool=20, reaperThread=false)
05:45:39,937 DEBUG [main][Persistence] ExecutionContext "org.datanucleus.ExecutionContextImpl@2c63762b" opened for datastore "org.datanucleus.store.rdbms.RDBMSStoreManager@7a9eccc4" with txn="org.datanucleus.TransactionImpl@78422efb"
05:45:39,937 DEBUG [main][Cache] Level 1 Cache of type "soft" initialised
05:45:39,937 INFO  [main][AbstractCryptoManager] getEncryptionAlgorithm: Property 'cumulus4j.encryptionAlgorithm' is not set. Using default algorithm 'Twofish/GCM/NoPadding'.
05:45:39,937 INFO  [main][AbstractCryptoManager] getMACAlgorithm: Property 'cumulus4j.macAlgorithm' is not set. Using default MAC algorithm 'NONE'.
05:45:39,938 DEBUG [main][Cache] Query Cache of type "org.datanucleus.query.cache.SoftQueryCompilationCache" initialised
05:45:39,938 DEBUG [main][Cache] Query Cache of type "org.datanucleus.store.query.cache.SoftQueryDatastoreCompilationCache" initialised
05:45:39,938 DEBUG [main][Cache] Query Cache of type "org.datanucleus.store.query.cache.SoftQueryResultsCache" initialised
05:45:39,938 DEBUG [main][Query] JDOQL Single-String with "SELECT UNIQUE WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm"
05:45:39,939 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" : Initialising Meta-Data
05:45:39,940 DEBUG [main][Persistence] Managing Persistence of Class : org.cumulus4j.store.model.EncryptionCoordinateSet [Table : ENCRYPTIONCOORDINATESET, InheritanceStrategy : new-table]
05:45:39,941 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.ENCRYPTIONCOORDINATESETID" added to internal representation of table.
05:45:39,942 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.encryptionCoordinateSetID] -> Column(s) [ENCRYPTIONCOORDINATESET.ENCRYPTIONCOORDINATESETID] using mapping of type "org.datanucleus.store.rdbms.mapping.java.LongMapping" (org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping)
05:45:39,942 DEBUG [main][Schema] Table ENCRYPTIONCOORDINATESET will manage the persistence of the fields for class org.cumulus4j.store.model.EncryptionCoordinateSet (inheritance strategy="new-table") 
05:45:39,943 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.CIPHERTRANSFORMATION" added to internal representation of table.
05:45:39,944 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.cipherTransformation] -> Column(s) [ENCRYPTIONCOORDINATESET.CIPHERTRANSFORMATION] using mapping of type "org.datanucleus.store.rdbms.mapping.java.StringMapping" (org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping)
05:45:39,944 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.MACALGORITHM" added to internal representation of table.
05:45:39,945 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.macAlgorithm] -> Column(s) [ENCRYPTIONCOORDINATESET.MACALGORITHM] using mapping of type "org.datanucleus.store.rdbms.mapping.java.StringMapping" (org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping)
05:45:39,945 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.VERSION" added to internal representation of table.
05:45:39,946 DEBUG [main][Schema] Table/View ENCRYPTIONCOORDINATESET has been initialised
05:45:39,947 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3c0e00a8" opened with isolation level "serializable" and auto-commit=false
05:45:39,947 DEBUG [main][Schema] Schema Transaction started with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3c0e00a8" with isolation "serializable"
05:45:39,985 DEBUG [main][Schema] Check of existence of ENCRYPTIONCOORDINATESET returned no table
05:45:39,985 DEBUG [main][Schema] Creating table ENCRYPTIONCOORDINATESET
05:45:39,985 DEBUG [main][Schema] CREATE TABLE ENCRYPTIONCOORDINATESET
(
    ENCRYPTIONCOORDINATESETID BIGINT NOT NULL generated always as identity (start with 1),
    CIPHERTRANSFORMATION VARCHAR(255) NOT NULL,
    MACALGORITHM VARCHAR(255) NOT NULL,
    VERSION BIGINT NOT NULL
)
05:45:39,999 DEBUG [main][Schema] Execution Time = 13 ms
05:45:39,999 DEBUG [main][Schema] ALTER TABLE ENCRYPTIONCOORDINATESET ADD CONSTRAINT ENCRYPTIONCOORDINATESET_PK PRIMARY KEY (ENCRYPTIONCOORDINATESETID)
05:45:40,034 DEBUG [main][Schema] Execution Time = 35 ms
05:45:40,050 DEBUG [main][Schema] Schema Transaction committing with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3c0e00a8"
05:45:40,056 DEBUG [main][Schema] Schema Transaction closing with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3c0e00a8"
05:45:40,056 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3c0e00a8" non enlisted to a transaction is being committed.
05:45:40,056 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3c0e00a8" closed
05:45:40,056 DEBUG [main][Query] JDOQL Query : Compiling "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm"
05:45:40,057 DEBUG [main][Query] JDOQL Query : Compile Time = 1 ms
05:45:40,057 DEBUG [main][Query] QueryCompilation:
  [filter:DyadicExpression{DyadicExpression{PrimaryExpression{this.cipherTransformation}  =  ParameterExpression{cipherTransformation}}  AND  DyadicExpression{PrimaryExpression{this.macAlgorithm}  =  ParameterExpression{macAlgorithm}}}]
  [symbols: macAlgorithm type=java.lang.String, this type=org.cumulus4j.store.model.EncryptionCoordinateSet, cipherTransformation type=java.lang.String]
05:45:40,057 DEBUG [main][Query] JDOQL Query : Compiling "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm" for datastore
05:45:40,063 DEBUG [main][Query] JDOQL Query : Compile Time for datastore = 5 ms
05:45:40,063 DEBUG [main][Query] SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm Query compiled to datastore query "SELECT 'org.cumulus4j.store.model.EncryptionCoordinateSet' AS NUCLEUS_TYPE,A0.CIPHERTRANSFORMATION,A0.ENCRYPTIONCOORDINATESETID,A0.MACALGORITHM,A0.VERSION FROM ENCRYPTIONCOORDINATESET A0 WHERE A0.CIPHERTRANSFORMATION = ? AND A0.MACALGORITHM = ?"
05:45:40,064 DEBUG [main][Connection] Connection added to the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@4ed5a1b0 [conn=null, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@2c63762b in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@18d003cd]
05:45:40,064 DEBUG [main][Query] JDOQL Query : Executing "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm" ...
05:45:40,064 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3135bf25" opened with isolation level "read-committed" and auto-commit=false
05:45:40,075 DEBUG [main][Datastore] Closing PreparedStatement "org.datanucleus.store.rdbms.datasource.dbcp.DelegatingPreparedStatement@388623ad"
05:45:40,075 DEBUG [main][Native] SELECT 'org.cumulus4j.store.model.EncryptionCoordinateSet' AS NUCLEUS_TYPE,A0.CIPHERTRANSFORMATION,A0.ENCRYPTIONCOORDINATESETID,A0.MACALGORITHM,A0.VERSION FROM ENCRYPTIONCOORDINATESET A0 WHERE A0.CIPHERTRANSFORMATION = <'TWOFISH/GCM/NOPADDING'> AND A0.MACALGORITHM = <'NONE'>
05:45:40,076 DEBUG [main][Retrieve] Execution Time = 1 ms
05:45:40,076 DEBUG [main][Query] JDOQL Query : Execution Time = 12 ms
05:45:40,076 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3135bf25" non enlisted to a transaction is being committed.
05:45:40,076 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3135bf25" closed
05:45:40,076 DEBUG [main][Connection] Connection removed from the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@4ed5a1b0 [conn=org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@3135bf25, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@2c63762b in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@18d003cd]
05:45:40,076 DEBUG [main][Persistence] Making object persistent : "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e"
05:45:40,076 DEBUG [main][Persistence] Started pool of ObjectProviders (maxPool=0, reaperThread=false)
05:45:40,077 DEBUG [main][Persistence] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" being inserted into table "ENCRYPTIONCOORDINATESET"
05:45:40,077 DEBUG [main][Connection] Connection added to the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@32118208 [conn=null, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@2c63762b in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@18d003cd]
05:45:40,078 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@414f87a9" opened with isolation level "read-committed" and auto-commit=false
05:45:40,083 DEBUG [main][Datastore] Using PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@416d56f2" for connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@414f87a9"
05:45:40,083 DEBUG [main][Native] INSERT INTO ENCRYPTIONCOORDINATESET (CIPHERTRANSFORMATION,MACALGORITHM,VERSION) VALUES (<'TWOFISH/GCM/NOPADDING'>,<'NONE'>,<1>)
05:45:40,087 DEBUG [main][Persist] Execution Time = 4 ms (number of rows = 1) on PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@416d56f2"
05:45:40,090 DEBUG [main][Persist] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" was inserted in the datastore and was given strategy value of "1"
05:45:40,090 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") added to Level 1 cache (loadedFlags="[YYY]")
05:45:40,090 DEBUG [main][Datastore] Closing PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@416d56f2"
05:45:40,095 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@414f87a9" non enlisted to a transaction is being committed.
05:45:40,095 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@414f87a9" closed
05:45:40,095 DEBUG [main][Connection] Connection removed from the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@32118208 [conn=org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@414f87a9, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@2c63762b in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@18d003cd]
05:45:40,095 DEBUG [main][Persistence] ExecutionContext.internalFlush() process started using ordered flush - 1 enlisted objects
05:45:40,096 DEBUG [main][Persistence] ExecutionContext.internalFlush() process finished
05:45:40,096 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" (id="1") added to Level 2 cache (fields="[0, 1, 2]", version="1")
05:45:40,096 DEBUG [main][Lifecycle] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") has a lifecycle change : "P_NEW"->"HOLLOW"
05:45:40,096 DEBUG [main][Transaction] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") being evicted from transactional cache
05:45:40,096 DEBUG [main][Persistence] Detaching copy of object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" (depth=0) as "org.cumulus4j.store.model.EncryptionCoordinateSet@47c7a9e5" with detached-fields [0, 1, 2] and fields-to-load=[0, 2]
05:45:40,097 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" (id="1") is loading the following fields from the Level 2 cache object : [0, 2]
05:45:40,097 DEBUG [main][Lifecycle] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") has a lifecycle change : "HOLLOW"->"P_NONTRANS"
05:45:41,736 INFO  [main][CryptoCache] Persistence property 'cumulus4j.CryptoCache.cleanupTimer.period' is not set. Using default value 60000.
05:45:41,836 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@1322907569 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:41,837 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@1322907569 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:41,837 TRACE [main][CryptoCache] getKeyData: Found cached key with keyID=123.
05:45:41,837 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@756126725 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:41,838 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@756126725 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:41,839 DEBUG [main][Persistence] Disconnecting org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e from StateManager[pc=org.cumulus4j.store.model.EncryptionCoordinateSet@3b83459e, lifecycle=P_NONTRANS]
05:45:41,839 DEBUG [main][Cache] Object with id="org.cumulus4j.store.model.EncryptionCoordinateSet:1" being removed from Level 1 cache [current cache size = 1]
05:45:41,839 DEBUG [main][Cache] Level 1 Cache cleared
05:45:41,839 DEBUG [main][Persistence] ExecutionContext "org.datanucleus.ExecutionContextImpl@2c63762b" closed
05:45:41,934 DEBUG [main][Persistence] Unmanaging Persistence of all classes
05:45:41,934 DEBUG [main][MetaData] Deregistering listener for metadata initialisation
05:45:41,935 DEBUG [main][Cache] Level 2 Cache cleared
05:45:42,032 DEBUG [main][General] Plugin Registry "org.datanucleus.plugin.EclipsePluginRegistry" not found. Falling back to DataNucleus registry. Reason : Class "org.eclipse.core.runtime.RegistryFactory" was not found in the CLASSPATH. Please check your specification and your CLASSPATH..
05:45:42,033 DEBUG [main][General] Using PluginRegistry org.datanucleus.plugin.NonManagedPluginRegistry
05:45:42,035 DEBUG [main][General] Registering bundle org.cumulus4j.store version 1.2.1.SNAPSHOT at URL file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar.
05:45:42,036 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar!/plugin.xml.
05:45:42,037 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store/target/org.cumulus4j.store-1.2.1-SNAPSHOT.jar!/plugin.xml.
05:45:42,037 DEBUG [main][General] Registering bundle org.datanucleus.api.jdo version 3.2.3 at URL file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-api-jdo/3.2.3/datanucleus-api-jdo-3.2.3.jar.
05:45:42,039 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-api-jdo/3.2.3/datanucleus-api-jdo-3.2.3.jar!/plugin.xml.
05:45:42,039 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-api-jdo/3.2.3/datanucleus-api-jdo-3.2.3.jar!/plugin.xml.
05:45:42,039 WARN  [main][General] Could not find MANIFEST.MF file for plugin file "file:/home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.crypto.keymanager/target/classes/plugin.xml" so ignoring it
05:45:42,040 DEBUG [main][General] Registering bundle org.datanucleus.store.rdbms version 3.2.3 at URL file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-rdbms/3.2.3/datanucleus-rdbms-3.2.3.jar.
05:45:42,043 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-rdbms/3.2.3/datanucleus-rdbms-3.2.3.jar!/plugin.xml.
05:45:42,045 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-rdbms/3.2.3/datanucleus-rdbms-3.2.3.jar!/plugin.xml.
05:45:42,046 DEBUG [main][General] Registering bundle org.datanucleus version 3.2.4 at URL file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-core/3.2.4/datanucleus-core-3.2.4.jar.
05:45:42,049 DEBUG [main][General] Loading extension points from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-core/3.2.4/datanucleus-core-3.2.4.jar!/plugin.xml.
05:45:42,053 DEBUG [main][General] Loading extensions from plug-in file jar:file:/home/tomcat/.m2/repository/org/datanucleus/datanucleus-core/3.2.4/datanucleus-core-3.2.4.jar!/plugin.xml.
05:45:42,055 DEBUG [main][Persistence] Java types support initialising ...
05:45:42,057 DEBUG [main][Persistence] Java types support loaded : supported java types=java.awt.Color, java.lang.Float, [Ljava.lang.Integer;, java.sql.Time, java.util.SortedSet, java.net.URL, java.util.Date, java.util.PriorityQueue, float, [Ljava.lang.Character;, [Ljava.lang.Double;, java.lang.Integer, java.math.BigDecimal, java.util.Vector, java.lang.Character, java.lang.Enum, java.lang.Long, java.lang.Short, java.util.Locale, java.util.Map, java.math.BigInteger, java.net.URI, java.lang.Byte, java.util.GregorianCalendar, java.awt.image.BufferedImage, byte, double, java.util.TimeZone, java.sql.Timestamp, java.util.Collection, java.util.Set, java.util.UUID, [Ljava.lang.String;, java.util.List, [Ljava.lang.Short;, java.util.Queue, java.util.SortedMap, [Ljava.lang.Enum;, [Ljava.lang.Boolean;, java.lang.Double, [Ljava.util.Date;, [B, [C, [D, java.util.HashMap, java.util.Currency, [F, long, java.util.Stack, java.util.TreeSet, [I, java.util.ArrayList, [J, java.util.HashSet, java.util.LinkedHashMap, java.util.Calendar, java.lang.StringBuffer, [S, [Ljava.math.BigInteger;, java.lang.Boolean, [Ljava.lang.Number;, java.lang.String, [Ljava.math.BigDecimal;, java.lang.Number, java.util.LinkedList, java.util.Hashtable, java.util.LinkedHashSet, [Z, [Ljava.lang.Float;, java.util.Properties, [Ljava.lang.Byte;, [Ljava.util.Locale;, int, java.sql.Date, boolean, java.util.TreeMap, [Ljava.lang.Long;, char, short, java.lang.Class, java.util.BitSet, java.util.Arrays$ArrayList
05:45:42,058 DEBUG [main][Persistence] Type converter support initialising ...
05:45:42,058 DEBUG [main][Persistence] Added converter for java.math.BigDecimal<->java.lang.String using org.datanucleus.store.types.converters.BigDecimalStringConverter
05:45:42,058 DEBUG [main][Persistence] Added converter for java.math.BigInteger<->java.lang.String using org.datanucleus.store.types.converters.BigIntegerStringConverter
05:45:42,058 DEBUG [main][Persistence] Added converter for java.util.BitSet<->java.lang.String using org.datanucleus.store.types.converters.BitSetStringConverter
05:45:42,058 DEBUG [main][Persistence] Added converter for java.util.Calendar<->java.lang.String using org.datanucleus.store.types.converters.CalendarStringConverter
05:45:42,058 DEBUG [main][Persistence] Added converter for java.lang.Class<->java.lang.String using org.datanucleus.store.types.converters.ClassStringConverter
05:45:42,058 DEBUG [main][Persistence] Added converter for java.awt.Color<->java.lang.String using org.datanucleus.store.types.converters.ColorStringConverter
05:45:42,058 DEBUG [main][Persistence] Added converter for java.lang.Integer<->java.lang.String using org.datanucleus.store.types.converters.IntegerStringConverter
05:45:42,058 DEBUG [main][Persistence] Added converter for java.lang.Long<->java.lang.String using org.datanucleus.store.types.converters.LongStringConverter
05:45:42,059 DEBUG [main][Persistence] Added converter for java.util.Currency<->java.lang.String using org.datanucleus.store.types.converters.CurrencyStringConverter
05:45:42,059 DEBUG [main][Persistence] Added converter for java.util.Date<->java.lang.Long using org.datanucleus.store.types.converters.DateLongConverter
05:45:42,059 DEBUG [main][Persistence] Added converter for java.util.Date<->java.lang.String using org.datanucleus.store.types.converters.DateStringConverter
05:45:42,059 DEBUG [main][Persistence] Added converter for java.util.Locale<->java.lang.String using org.datanucleus.store.types.converters.LocaleStringConverter
05:45:42,059 DEBUG [main][Persistence] Added converter for java.sql.Date<->java.lang.Long using org.datanucleus.store.types.converters.SqlDateLongConverter
05:45:42,059 DEBUG [main][Persistence] Added converter for java.sql.Date<->java.lang.String using org.datanucleus.store.types.converters.SqlDateStringConverter
05:45:42,059 DEBUG [main][Persistence] Added converter for java.sql.Time<->java.lang.Long using org.datanucleus.store.types.converters.SqlTimeLongConverter
05:45:42,060 DEBUG [main][Persistence] Added converter for java.sql.Time<->java.lang.String using org.datanucleus.store.types.converters.SqlTimeStringConverter
05:45:42,060 DEBUG [main][Persistence] Added converter for java.sql.Timestamp<->java.lang.Long using org.datanucleus.store.types.converters.SqlTimestampLongConverter
05:45:42,060 DEBUG [main][Persistence] Added converter for java.lang.StringBuffer<->java.lang.String using org.datanucleus.store.types.converters.StringBufferStringConverter
05:45:42,060 DEBUG [main][Persistence] Added converter for java.util.TimeZone<->java.lang.String using org.datanucleus.store.types.converters.TimeZoneStringConverter
05:45:42,060 DEBUG [main][Persistence] Added converter for java.net.URI<->java.lang.String using org.datanucleus.store.types.converters.URIStringConverter
05:45:42,060 DEBUG [main][Persistence] Added converter for java.net.URL<->java.lang.String using org.datanucleus.store.types.converters.URLStringConverter
05:45:42,060 DEBUG [main][Persistence] Added converter for java.util.UUID<->java.lang.String using org.datanucleus.store.types.converters.UUIDStringConverter
05:45:42,061 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalDate<->java.lang.String ignored since java type not present in CLASSPATH
05:45:42,061 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalTime<->java.lang.String ignored since java type not present in CLASSPATH
05:45:42,062 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalTime<->java.lang.Long ignored since java type not present in CLASSPATH
05:45:42,062 DEBUG [main][Persistence] TypeConverter for javax.time.calendar.LocalDateTime<->java.lang.String ignored since java type not present in CLASSPATH
05:45:42,062 DEBUG [main][Persistence] Added converter for java.io.Serializable<->java.lang.String using org.datanucleus.store.types.converters.SerializableStringConverter
05:45:42,063 DEBUG [main][Persistence] Added converter for java.io.Serializable<->[B using org.datanucleus.store.types.converters.SerializableByteArrayConverter
05:45:42,063 DEBUG [main][Persistence] Type converter support loaded
05:45:42,063 DEBUG [main][MetaData] MetaDataManager : Input=(XML,Annotations), XML-Validation=false, XML-Suffices=(persistence=*.jdo, orm=orm, query=*.jdoquery), JDO-listener=true
05:45:42,063 DEBUG [main][MetaData] Registering listener for metadata initialisation
05:45:42,063 DEBUG [main][MetaData] Listener found initialisation for persistable class org.cumulus4j.store.model.EncryptionCoordinateSet
05:45:42,063 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /META-INF/package.jdo
05:45:42,064 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /WEB-INF/package.jdo
05:45:42,064 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /package.jdo
05:45:42,064 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/package.jdo
05:45:42,065 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org.jdo
05:45:42,065 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/package.jdo
05:45:42,066 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j.jdo
05:45:42,066 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/package.jdo
05:45:42,066 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store.jdo
05:45:42,067 DEBUG [main][MetaData] Parsing MetaData 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" using handler "jdo" (validation="false")
05:45:42,069 DEBUG [main][MetaData] XML Entity Public="" System="http://java.sun.com/dtd/jdo_3_0.dtd
05:45:42,395 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model.jdo
05:45:42,396 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/EncryptionCoordinateSet.jdo
05:45:42,396 DEBUG [main][MetaData] MetaData of type "jdo" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" not found
05:45:42,398 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" has been specified with JDO annotations so using those.
05:45:42,399 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" : Populating Meta-Data
05:45:42,399 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /META-INF/package.orm
05:45:42,400 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /WEB-INF/package.orm
05:45:42,400 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /package.orm
05:45:42,400 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/package.orm
05:45:42,400 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org.orm
05:45:42,401 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/package.orm
05:45:42,401 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j.orm
05:45:42,401 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/package.orm
05:45:42,401 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store.orm
05:45:42,402 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/package.orm
05:45:42,402 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model.orm
05:45:42,402 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" NOT found at /org/cumulus4j/store/model/EncryptionCoordinateSet.orm
05:45:42,402 DEBUG [main][MetaData] MetaData of type "orm" for class "org.cumulus4j.store.model.EncryptionCoordinateSet" not found
05:45:42,403 DEBUG [main][Datastore] Creating StoreManager for datastore
05:45:42,408 DEBUG [main][Connection] Created tx data source using pooling type of dbcp-builtin
05:45:42,408 DEBUG [main][Connection] Registered transactional connection factory under name "rdbms/tx"
05:45:42,408 DEBUG [main][Connection] Registered nontransactional connection factory under name "rdbms/nontx"
05:45:42,411 DEBUG [main][Connection] Created nontx data source using pooling type of dbcp-builtin
05:45:43,772 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@413bef78" opened
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=BOOLEAN, sql-type=BOOLEAN, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BooleanRDBMSMapping, default=false)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Boolean (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Byte (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=true)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Character (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Double (jdbc-type=DOUBLE, sql-type=DOUBLE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DoubleRDBMSMapping, default=true)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Double (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=false)
05:45:43,774 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=FLOAT, sql-type=FLOAT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.FloatRDBMSMapping, default=true)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=DOUBLE, sql-type=DOUBLE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DoubleRDBMSMapping, default=false)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=REAL, sql-type=REAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.RealRDBMSMapping, default=false)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Float (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=false)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=true)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=true)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Integer (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=true)
05:45:43,775 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Long (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=SMALLINT, sql-type=SMALLINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.SmallIntRDBMSMapping, default=true)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.Short (jdbc-type=INTEGER, sql-type=INT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=true)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=LONGVARCHAR, sql-type=LONGVARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.LongVarcharRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=CLOB, sql-type=CLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.ClobRDBMSMapping, default=false)
05:45:43,776 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=BLOB, sql-type=BLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BlobRDBMSMapping, default=false)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=NVARCHAR, sql-type=NVARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NVarcharRDBMSMapping, default=false)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.lang.String (jdbc-type=NCHAR, sql-type=NCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NCharRDBMSMapping, default=false)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigDecimal (jdbc-type=DECIMAL, sql-type=DECIMAL, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DecimalRDBMSMapping, default=true)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigDecimal (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.math.BigInteger (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=true)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=DATE, sql-type=DATE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DateRDBMSMapping, default=true)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=false)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:43,777 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Date (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=TIME, sql-type=TIME, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimeRDBMSMapping, default=true)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=false)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Time (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=true)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:43,778 DEBUG [main][Datastore] Adding RDBMS support for Java type java.sql.Timestamp (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=TIMESTAMP, sql-type=TIMESTAMP, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimestampRDBMSMapping, default=true)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=DATE, sql-type=DATE, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.DateRDBMSMapping, default=false)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=false)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.util.Date (jdbc-type=TIME, sql-type=TIME, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.TimeRDBMSMapping, default=false)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=LONGVARBINARY, sql-type=LONGVARBINARY, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.LongVarBinaryRDBMSMapping, default=true)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=BLOB, sql-type=BLOB, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BlobRDBMSMapping, default=false)
05:45:43,779 DEBUG [main][Datastore] Adding RDBMS support for Java type java.io.Serializable (jdbc-type=VARBINARY, sql-type=VARBINARY, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarBinaryRDBMSMapping, default=false)
05:45:43,780 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=BIGINT, sql-type=BIGINT, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping, default=true)
05:45:43,780 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=INTEGER, sql-type=INTEGER, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.IntegerRDBMSMapping, default=false)
05:45:43,780 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=NUMERIC, sql-type=NUMERIC, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.NumericRDBMSMapping, default=false)
05:45:43,780 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=CHAR, sql-type=CHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping, default=false)
05:45:43,780 DEBUG [main][Datastore] Adding RDBMS support for Java type org.datanucleus.identity.OID (jdbc-type=VARCHAR, sql-type=VARCHAR, datastore-mapping-type=org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping, default=false)
05:45:43,835 DEBUG [main][Datastore] Removing RDBMS support for Java type java.lang.String (jdbc-type=NVARCHAR, sql-type=NVARCHAR)
05:45:43,835 DEBUG [main][Datastore] Removing RDBMS support for Java type java.lang.String (jdbc-type=NCHAR, sql-type=NCHAR)
05:45:43,840 DEBUG [main][Datastore] ======================= Datastore =========================
05:45:43,840 DEBUG [main][Datastore] StoreManager : "rdbms" (org.datanucleus.store.rdbms.RDBMSStoreManager)
05:45:43,840 DEBUG [main][Datastore] Datastore : read-write
05:45:43,840 DEBUG [main][Datastore] Schema Control : AutoCreate(Tables), Validate(None)
05:45:43,841 DEBUG [main][Datastore] Query Languages : [JDOQL, JPQL, SQL, STOREDPROC]
05:45:43,841 DEBUG [main][Datastore] Queries : Timeout=0
05:45:43,841 DEBUG [main][Datastore] ===========================================================
05:45:43,841 DEBUG [main][Datastore] Datastore Adapter : org.datanucleus.store.rdbms.adapter.DerbyAdapter
05:45:43,841 DEBUG [main][Datastore] Datastore : name="Apache Derby" version="10.7.1.1 - (1040133)"
05:45:43,841 DEBUG [main][Datastore] Datastore Driver : name="Apache Derby Embedded JDBC Driver" version="10.7.1.1 - (1040133)"
05:45:43,841 DEBUG [main][Datastore] Primary Connection Factory : URL[jdbc:derby:/tmp/cumulus4j-test.wiar22bw/derby/cumulus4j;create=true]
05:45:43,841 DEBUG [main][Datastore] Secondary Connection Factory : URL[jdbc:derby:/tmp/cumulus4j-test.wiar22bw/derby/cumulus4j;create=true]
05:45:43,841 DEBUG [main][Datastore] Datastore Identifiers : factory="datanucleus2" case=UPPERCASE catalog= schema=ROOT
05:45:43,841 DEBUG [main][Datastore] Supported Identifier Cases : "MixedCase" UPPERCASE "MixedCase-Sensitive" 
05:45:43,841 DEBUG [main][Datastore] Supported Identifier Lengths (max) : Table=128 Column=128 Constraint=128 Index=128 Delimiter="
05:45:43,841 DEBUG [main][Datastore] Support for Identifiers in DDL : catalog=false schema=true
05:45:43,841 DEBUG [main][Datastore] Datastore : checkTableViewExistence, rdbmsConstraintCreateMode=DataNucleus, initialiseColumnInfo=ALL
05:45:43,841 DEBUG [main][Datastore] Support Statement Batching : yes (max-batch-size=50)
05:45:43,841 DEBUG [main][Datastore] Queries : Results direction=forward, type=forward-only, concurrency=read-only
05:45:43,841 DEBUG [main][Datastore] Java-Types : string-default-length=255
05:45:43,841 DEBUG [main][Datastore] JDBC-Types : VARCHAR, LONGVARCHAR, BINARY, BOOLEAN, VARBINARY, LONGVARBINARY, BIGINT, JAVA_OBJECT, [id=2009], CHAR, NUMERIC, DECIMAL, INTEGER, CLOB, SMALLINT, BLOB, FLOAT, REAL, DOUBLE, DATE, TIME, TIMESTAMP
05:45:43,841 DEBUG [main][Datastore] ===========================================================
05:45:43,857 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@413bef78" non enlisted to a transaction is being committed.
05:45:43,857 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@413bef78" closed
05:45:43,857 DEBUG [main][Datastore] StoreManager now created
05:45:43,857 DEBUG [main][Persistence] ================= NucleusContext ===============
05:45:43,857 DEBUG [main][Persistence] DataNucleus Context : Version "3.2.4" with JRE "1.8.0_91" on "Linux"
05:45:43,857 DEBUG [main][Persistence] Persistence API : JDO
05:45:43,857 DEBUG [main][Persistence] Plugin Registry : org.datanucleus.plugin.NonManagedPluginRegistry
05:45:43,857 DEBUG [main][Persistence] ClassLoading : datanucleus
05:45:43,857 DEBUG [main][Persistence] Persistence : pm-singlethreaded, nontransactional-read, nontransactional-write, reachability-at-commit, copy-on-attach, managed-relations(checked), deletion-policy=JDO2, serverTimeZone=Europe/Berlin
05:45:43,857 DEBUG [main][Persistence] AutoStart : mechanism=None, mode=Quiet
05:45:43,857 DEBUG [main][Persistence] Transactions : type=RESOURCE_LOCAL, mode=datastore, isolation=read-committed
05:45:43,857 DEBUG [main][Persistence] ValueGeneration : txn-isolation=read-committed connection=New
05:45:43,857 DEBUG [main][Persistence] Cache : Level1 (soft), Level2 (soft, mode=UNSPECIFIED), QueryResults (soft), Collections/Maps 
05:45:43,857 DEBUG [main][Persistence] ================================================
05:45:43,857 DEBUG [main][Cache] Level 2 Cache of type "soft" initialised
05:45:43,858 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
05:45:43,858 TRACE [main][AbstractCryptoSession] setCryptoSessionID: cryptoSessionID=31bd5ce2-8d34-456b-8bb7-c1c1fe1807f1
05:45:43,858 INFO  [main][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
05:45:43,859 DEBUG [main][Persistence] Started pool of ExecutionContext (maxPool=20, reaperThread=false)
05:45:43,860 DEBUG [main][Persistence] ExecutionContext "org.datanucleus.ExecutionContextImpl@3c952a33" opened for datastore "org.datanucleus.store.rdbms.RDBMSStoreManager@70029d2d" with txn="org.datanucleus.TransactionImpl@1150d471"
05:45:43,861 DEBUG [main][Cache] Level 1 Cache of type "soft" initialised
05:45:44,155 INFO  [main][AbstractCryptoManager] getEncryptionAlgorithm: Property 'cumulus4j.encryptionAlgorithm' is not set. Using default algorithm 'Twofish/GCM/NoPadding'.
05:45:44,156 INFO  [main][AbstractCryptoManager] getMACAlgorithm: Property 'cumulus4j.macAlgorithm' is not set. Using default MAC algorithm 'NONE'.
05:45:44,156 DEBUG [main][Cache] Query Cache of type "org.datanucleus.query.cache.SoftQueryCompilationCache" initialised
05:45:44,156 DEBUG [main][Cache] Query Cache of type "org.datanucleus.store.query.cache.SoftQueryDatastoreCompilationCache" initialised
05:45:44,156 DEBUG [main][Cache] Query Cache of type "org.datanucleus.store.query.cache.SoftQueryResultsCache" initialised
05:45:44,156 DEBUG [main][Query] JDOQL Single-String with "SELECT UNIQUE WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm"
05:45:44,156 DEBUG [main][MetaData] Class "org.cumulus4j.store.model.EncryptionCoordinateSet" : Initialising Meta-Data
05:45:44,157 DEBUG [main][Persistence] Managing Persistence of Class : org.cumulus4j.store.model.EncryptionCoordinateSet [Table : ENCRYPTIONCOORDINATESET, InheritanceStrategy : new-table]
05:45:44,157 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.ENCRYPTIONCOORDINATESETID" added to internal representation of table.
05:45:44,157 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.encryptionCoordinateSetID] -> Column(s) [ENCRYPTIONCOORDINATESET.ENCRYPTIONCOORDINATESETID] using mapping of type "org.datanucleus.store.rdbms.mapping.java.LongMapping" (org.datanucleus.store.rdbms.mapping.datastore.BigIntRDBMSMapping)
05:45:44,158 DEBUG [main][Schema] Table ENCRYPTIONCOORDINATESET will manage the persistence of the fields for class org.cumulus4j.store.model.EncryptionCoordinateSet (inheritance strategy="new-table") 
05:45:44,158 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.CIPHERTRANSFORMATION" added to internal representation of table.
05:45:44,158 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.cipherTransformation] -> Column(s) [ENCRYPTIONCOORDINATESET.CIPHERTRANSFORMATION] using mapping of type "org.datanucleus.store.rdbms.mapping.java.StringMapping" (org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping)
05:45:44,158 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.MACALGORITHM" added to internal representation of table.
05:45:44,159 DEBUG [main][Schema] Field [org.cumulus4j.store.model.EncryptionCoordinateSet.macAlgorithm] -> Column(s) [ENCRYPTIONCOORDINATESET.MACALGORITHM] using mapping of type "org.datanucleus.store.rdbms.mapping.java.StringMapping" (org.datanucleus.store.rdbms.mapping.datastore.VarCharRDBMSMapping)
05:45:44,159 DEBUG [main][Schema] Column "ENCRYPTIONCOORDINATESET.VERSION" added to internal representation of table.
05:45:44,159 DEBUG [main][Schema] Table/View ENCRYPTIONCOORDINATESET has been initialised
05:45:44,159 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@10850d17" opened with isolation level "serializable" and auto-commit=false
05:45:44,159 DEBUG [main][Schema] Schema Transaction started with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@10850d17" with isolation "serializable"
05:45:44,192 DEBUG [main][Schema] Check of existence of ENCRYPTIONCOORDINATESET returned no table
05:45:44,192 DEBUG [main][Schema] Creating table ENCRYPTIONCOORDINATESET
05:45:44,192 DEBUG [main][Schema] CREATE TABLE ENCRYPTIONCOORDINATESET
(
    ENCRYPTIONCOORDINATESETID BIGINT NOT NULL generated always as identity (start with 1),
    CIPHERTRANSFORMATION VARCHAR(255) NOT NULL,
    MACALGORITHM VARCHAR(255) NOT NULL,
    VERSION BIGINT NOT NULL
)
05:45:44,213 DEBUG [main][Schema] Execution Time = 21 ms
05:45:44,213 DEBUG [main][Schema] ALTER TABLE ENCRYPTIONCOORDINATESET ADD CONSTRAINT ENCRYPTIONCOORDINATESET_PK PRIMARY KEY (ENCRYPTIONCOORDINATESETID)
05:45:44,239 DEBUG [main][Schema] Execution Time = 26 ms
05:45:44,259 DEBUG [main][Schema] Schema Transaction committing with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@10850d17"
05:45:44,265 DEBUG [main][Schema] Schema Transaction closing with connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@10850d17"
05:45:44,265 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@10850d17" non enlisted to a transaction is being committed.
05:45:44,266 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@10850d17" closed
05:45:44,266 DEBUG [main][Query] JDOQL Query : Compiling "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm"
05:45:44,268 DEBUG [main][Query] JDOQL Query : Compile Time = 2 ms
05:45:44,268 DEBUG [main][Query] QueryCompilation:
  [filter:DyadicExpression{DyadicExpression{PrimaryExpression{this.cipherTransformation}  =  ParameterExpression{cipherTransformation}}  AND  DyadicExpression{PrimaryExpression{this.macAlgorithm}  =  ParameterExpression{macAlgorithm}}}]
  [symbols: macAlgorithm type=java.lang.String, this type=org.cumulus4j.store.model.EncryptionCoordinateSet, cipherTransformation type=java.lang.String]
05:45:44,269 DEBUG [main][Query] JDOQL Query : Compiling "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm" for datastore
05:45:44,271 DEBUG [main][Query] JDOQL Query : Compile Time for datastore = 2 ms
05:45:44,271 DEBUG [main][Query] SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm Query compiled to datastore query "SELECT 'org.cumulus4j.store.model.EncryptionCoordinateSet' AS NUCLEUS_TYPE,A0.CIPHERTRANSFORMATION,A0.ENCRYPTIONCOORDINATESETID,A0.MACALGORITHM,A0.VERSION FROM ENCRYPTIONCOORDINATESET A0 WHERE A0.CIPHERTRANSFORMATION = ? AND A0.MACALGORITHM = ?"
05:45:44,272 DEBUG [main][Connection] Connection added to the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@7c241a9f [conn=null, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@3c952a33 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@58fd1214]
05:45:44,272 DEBUG [main][Query] JDOQL Query : Executing "SELECT UNIQUE FROM org.cumulus4j.store.model.EncryptionCoordinateSet WHERE this.cipherTransformation == :cipherTransformation && this.macAlgorithm == :macAlgorithm" ...
05:45:44,272 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7d8cf9ac" opened with isolation level "read-committed" and auto-commit=false
05:45:44,277 DEBUG [main][Datastore] Closing PreparedStatement "org.datanucleus.store.rdbms.datasource.dbcp.DelegatingPreparedStatement@673e76b3"
05:45:44,278 DEBUG [main][Native] SELECT 'org.cumulus4j.store.model.EncryptionCoordinateSet' AS NUCLEUS_TYPE,A0.CIPHERTRANSFORMATION,A0.ENCRYPTIONCOORDINATESETID,A0.MACALGORITHM,A0.VERSION FROM ENCRYPTIONCOORDINATESET A0 WHERE A0.CIPHERTRANSFORMATION = <'TWOFISH/GCM/NOPADDING'> AND A0.MACALGORITHM = <'NONE'>
05:45:44,278 DEBUG [main][Retrieve] Execution Time = 0 ms
05:45:44,278 DEBUG [main][Query] JDOQL Query : Execution Time = 6 ms
05:45:44,278 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7d8cf9ac" non enlisted to a transaction is being committed.
05:45:44,279 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7d8cf9ac" closed
05:45:44,279 DEBUG [main][Connection] Connection removed from the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@7c241a9f [conn=org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@7d8cf9ac, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@3c952a33 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@58fd1214]
05:45:44,279 DEBUG [main][Persistence] Making object persistent : "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b"
05:45:44,279 DEBUG [main][Persistence] Started pool of ObjectProviders (maxPool=0, reaperThread=false)
05:45:44,280 DEBUG [main][Persistence] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" being inserted into table "ENCRYPTIONCOORDINATESET"
05:45:44,280 DEBUG [main][Connection] Connection added to the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@5d878b25 [conn=null, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@3c952a33 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@58fd1214]
05:45:44,280 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@28279a49" opened with isolation level "read-committed" and auto-commit=false
05:45:44,284 DEBUG [main][Datastore] Using PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@566e142" for connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@28279a49"
05:45:44,284 DEBUG [main][Native] INSERT INTO ENCRYPTIONCOORDINATESET (CIPHERTRANSFORMATION,MACALGORITHM,VERSION) VALUES (<'TWOFISH/GCM/NOPADDING'>,<'NONE'>,<1>)
05:45:44,285 DEBUG [main][Persist] Execution Time = 1 ms (number of rows = 1) on PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@566e142"
05:45:44,288 DEBUG [main][Persist] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" was inserted in the datastore and was given strategy value of "1"
05:45:44,288 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") added to Level 1 cache (loadedFlags="[YYY]")
05:45:44,288 DEBUG [main][Datastore] Closing PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@566e142"
05:45:44,293 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@28279a49" non enlisted to a transaction is being committed.
05:45:44,294 DEBUG [main][Connection] Connection "org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@28279a49" closed
05:45:44,294 DEBUG [main][Connection] Connection removed from the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@5d878b25 [conn=org.datanucleus.store.rdbms.datasource.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@28279a49, commitOnRelease=true, closeOnRelease=true, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextImpl@3c952a33 in factory=ConnectionFactory:nontx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@58fd1214]
05:45:44,294 DEBUG [main][Persistence] ExecutionContext.internalFlush() process started using ordered flush - 1 enlisted objects
05:45:44,294 DEBUG [main][Persistence] ExecutionContext.internalFlush() process finished
05:45:44,294 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" (id="1") added to Level 2 cache (fields="[0, 1, 2]", version="1")
05:45:44,295 DEBUG [main][Lifecycle] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") has a lifecycle change : "P_NEW"->"HOLLOW"
05:45:44,295 DEBUG [main][Transaction] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") being evicted from transactional cache
05:45:44,295 DEBUG [main][Persistence] Detaching copy of object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" (depth=0) as "org.cumulus4j.store.model.EncryptionCoordinateSet@7f4596d0" with detached-fields [0, 1, 2] and fields-to-load=[0, 2]
05:45:44,295 DEBUG [main][Cache] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" (id="1") is loading the following fields from the Level 2 cache object : [0, 2]
05:45:44,296 DEBUG [main][Lifecycle] Object "org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b" (id="org.cumulus4j.store.model.EncryptionCoordinateSet:1") has a lifecycle change : "HOLLOW"->"P_NONTRANS"
05:45:49,044 DEBUG [CryptoCache][CryptoCache$CleanupTask] run: entered
05:45:49,046 INFO  [CryptoCache][CryptoCache$CleanupTask] run: CryptoCache was garbage-collected. Cancelling this TimerTask.
05:45:50,792 INFO  [main][CryptoCache] Persistence property 'cumulus4j.CryptoCache.cleanupTimer.period' is not set. Using default value 60000.
05:45:50,891 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@1485129132 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:50,976 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@1485129132 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:50,976 TRACE [main][CryptoCache] acquireCipherEntry: Found cached Cipher@1485129132 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with new IV (without key).
05:45:51,030 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@1485129132 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:51,030 TRACE [main][CryptoCache] clear: entered
05:45:51,126 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@721975085 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:51,179 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@721975085 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:51,221 TRACE [main][CryptoCache] clear: entered
05:45:51,222 TRACE [main][CryptoCache] getKeyData: No cached key with keyID=123 found.
05:45:51,315 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@2024314762 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:51,321 DEBUG [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: entered
05:45:51,322 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
05:45:51,369 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@2024314762 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:51,576 TRACE [main][CryptoCache] acquireCipherEntry: Found cached Cipher@2024314762 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with new IV (without key).
05:45:51,659 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@2024314762 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:51,659 TRACE [main][CryptoCache] clear: entered
05:45:51,659 TRACE [main][CryptoCache] getKeyData: No cached key with keyID=123 found.
05:45:51,761 TRACE [main][CryptoCache] acquireCipherEntry: Created new Cipher@253171986 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=123. Initialising it with key and IV.
05:45:51,817 TRACE [main][CryptoCache] releaseCipherEntry: Releasing Cipher@253171986 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=123.
05:45:51,846 DEBUG [main][Persistence] Disconnecting org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b from StateManager[pc=org.cumulus4j.store.model.EncryptionCoordinateSet@4998e74b, lifecycle=P_NONTRANS]
05:45:51,847 DEBUG [main][Cache] Object with id="org.cumulus4j.store.model.EncryptionCoordinateSet:1" being removed from Level 1 cache [current cache size = 1]
05:45:51,847 DEBUG [main][Cache] Level 1 Cache cleared
05:45:51,847 DEBUG [main][Persistence] ExecutionContext "org.datanucleus.ExecutionContextImpl@3c952a33" closed
05:45:51,925 DEBUG [main][Persistence] Unmanaging Persistence of all classes
05:45:51,925 DEBUG [main][MetaData] Deregistering listener for metadata initialisation
05:45:51,926 DEBUG [main][Cache] Level 2 Cache cleared
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 13.912 sec

Results :

Tests run: 10, Failures: 0, Errors: 0, Skipped: 0

[JENKINS] Recording test results
[INFO] 
[INFO] --- maven-bundle-plugin:2.3.4:bundle (default-bundle) @ org.cumulus4j.store.crypto.keymanager ---
[INFO] 
[INFO] --- maven-source-plugin:2.1.2:jar-no-fork (attach-sources) @ org.cumulus4j.store.crypto.keymanager ---
[INFO] org already added, skipping
[INFO] org/cumulus4j already added, skipping
[INFO] org/cumulus4j/store already added, skipping
[INFO] org/cumulus4j/store/crypto already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/rest already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/httppmf already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/inmemory already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/pmf already added, skipping
[INFO] LICENCE.txt already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/httppmf/messagebroker-datanucleus.properties already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/pmf/messagebroker-datanucleus.properties already added, skipping
[INFO] Building jar: /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.crypto.keymanager/target/org.cumulus4j.store.crypto.keymanager-1.2.1-SNAPSHOT-sources.jar
[INFO] org already added, skipping
[INFO] org/cumulus4j already added, skipping
[INFO] org/cumulus4j/store already added, skipping
[INFO] org/cumulus4j/store/crypto already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/rest already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/httppmf already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/inmemory already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/pmf already added, skipping
[INFO] LICENCE.txt already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/httppmf/messagebroker-datanucleus.properties already added, skipping
[INFO] org/cumulus4j/store/crypto/keymanager/messagebroker/pmf/messagebroker-datanucleus.properties already added, skipping
[INFO] 
[INFO] --- maven-install-plugin:2.4:install (default-install) @ org.cumulus4j.store.crypto.keymanager ---
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.crypto.keymanager/target/org.cumulus4j.store.crypto.keymanager-1.2.1-SNAPSHOT.jar to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.store.crypto.keymanager/1.2.1-SNAPSHOT/org.cumulus4j.store.crypto.keymanager-1.2.1-SNAPSHOT.jar
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.crypto.keymanager/pom.xml to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.store.crypto.keymanager/1.2.1-SNAPSHOT/org.cumulus4j.store.crypto.keymanager-1.2.1-SNAPSHOT.pom
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.store.crypto.keymanager/target/org.cumulus4j.store.crypto.keymanager-1.2.1-SNAPSHOT-sources.jar to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.store.crypto.keymanager/1.2.1-SNAPSHOT/org.cumulus4j.store.crypto.keymanager-1.2.1-SNAPSHOT-sources.jar
[INFO] 
[INFO] --- maven-bundle-plugin:2.3.4:install (default-install) @ org.cumulus4j.store.crypto.keymanager ---
[WARNING] Ignoring project type bundle - supportedProjectTypes = []