Tags: Spring Boot
My experience of programming on the Spring platform is that you'll be coding along, everything is going great, until an inscrutable complex error message emerges from the depths of who knows where. This message seemed to involve some module or another having created a round peg to fit into a square hole. That is, I'd sent a GET request to retrieve a large object tree, and it seemed that while filling data into a field of a subsidiary object Spring/Hibernate/etc chose the wrong data type, and it threw up an error. The specific type of error was receiving no discussion anywhere, so it was impossible to see how others had solved the problem. The documentation was of no use in explaining anything about this. But, after a couple days of trials and errors and more errors, a solution was found. And, indeed, Spring/Hibernate had chosen the wrong data type to fill into one of the fields, and the solution is fairly simple.
First, let's start with the error:
2017-10-14 15:19:11.869 DEBUG 77461 --- [nio-8080-exec-4] o.s.w.s.m.m.a.HttpEntityMethodProcessor : Written [{timestamp=Sat Oct 14 15:19:11 PDT 2017, status=500, error=Internal Server Error, exception=org.springframework.http.converter.HttpMessageNotWritableException, message=Could not write JSON: Could not set field value [class PowerMeasurementMetaData {
class MeasurementMetadata {
accumulationCharacteristic: null
dataQualifier: null
description: null
itemDescription: null
itemUnits: null
measurementQuality: null
resolution: null
siScaleCode: null
} measuringPeriod: null
powerDataKind: null
}] value by reflection : [class com.amzur.orangebuttonapi.model.measurementsets.WeatherHistoricalProfile.measurementMetaData] setter of com.amzur.orangebuttonapi.model.measurementsets.WeatherHistoricalProfile.measurementMetaData; nested exception is com.fasterxml.jackson.databind.JsonMappingException: Could not set field value [class PowerMeasurementMetaData {
class MeasurementMetadata {
accumulationCharacteristic: null
dataQualifier: null
description: null
itemDescription: null
itemUnits: null
measurementQuality: null
resolution: null
siScaleCode: null
} measuringPeriod: null
powerDataKind: null
}] value by reflection : [class com.amzur.orangebuttonapi.model.measurementsets.WeatherHistoricalProfile.measurementMetaData] setter of com.amzur.orangebuttonapi.model.measurementsets.WeatherHistoricalProfile.measurementMetaData (through reference chain: java.util.LinkedList[0]->com.amzur.orangebuttonapi.model.system.PVSystem["weatherProfiles"]), path=/systems}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@4e8b36af]
It first took quite awhile to puzzle through what I was being told by this error message. No stack trace was available, unfortunately. You see at the beginning Could not write JSON followed by Could not set field value, which is pretty clear. Some field, during the phase of serializing an object tree to JSON, could not be assigned. The rest of the error is unclear, but seems to indicate the setter for WeatherHistoricalProfile.measurementMetaData was being given a PowerMeasurementMetaData object. That field is supposed to receive a WeatherMeasurementMetaData object, so of course that would cause an error. But, is that actually what the error said? The error message is not clear, and could be read other ways around.
Even if that is what the error message said, it's not possible by the code for that to occur. A review of the code showed no instance of that combination. But, you need to see the relevant portion of the code.
The goal was to retrieve a PVSystem from the database. That class models a photovoltaic system that could be built from several photovoltaic arrays, subarrays, combiner boxes, inverters, weather stations, utility meters, and so on. The PVSystem object is the top of a sprawling tree of other objects corresponding to those real world thingymajigs.
@Entity
@ApiModel
@AttributeOverride(name = "identifier", column = @Column(name = "systemID"))
public class PVSystem extends LogicalBase {
...
@JsonProperty("weatherProfiles")
@OneToMany(cascade = CascadeType.ALL)
@JoinColumn(name = "systemID", nullable = true)
private List<WeatherHistoricalProfile> weatherProfiles = null;
...
@JsonProperty("energyProfiles")
@OneToMany(cascade = CascadeType.ALL)
@JoinColumn(name = "systemID", nullable = true)
private List<SolarEnergyProfile> energyProfiles = null;
@JsonProperty("actualPerformance")
@OneToOne(cascade = CascadeType.ALL)
@JoinColumn(name = "actualPerformanceID", nullable = true)
private ActualPerformance actualPerformance = null;
@JsonProperty("expectedPerformance")
@OneToOne(cascade = CascadeType.ALL)
@JoinColumn(name = "expectedPerformanceID", nullable = true)
private ExpectedPerformance expectedPerformance = null;
@JsonProperty("predictedPerformance")
@OneToOne(cascade = CascadeType.ALL)
@JoinColumn(name = "predictedPerformanceID", nullable = true)
private ForecastPerformance predictedPerformance = null;
@JsonProperty("powerProfiles")
@OneToMany(cascade = CascadeType.ALL)
@JoinColumn(name = "systemID", nullable = true)
private List<PowerProfile> powerProfiles = null;
...
}
The classes related to the error message:
@Entity
public class WeatherHistoricalProfile extends WeatherProfile {
@JsonProperty("measurementSource")
@Embedded
private MeasurementSource measurementSource = null;
}
@Entity
public class WeatherProfile extends MeasurementSet {
@JsonProperty("measurementMetaData")
@OneToOne(cascade=CascadeType.ALL)
@JoinColumn(name = "weatherMeasurementMetaID", nullable = true)
private WeatherMeasurementMetaData measurementMetaData = null;
}
@Entity
public class PowerProfile extends MeasurementSet {
@JsonProperty("measurementMetaData")
@OneToOne(cascade=CascadeType.ALL)
@JoinColumn(name = "powerMeasurementMetaID", nullable = true)
private PowerMeasurementMetaData measurementMetaData = null;
@JsonProperty("measurementSource")
@Embedded
private MeasurementSource measurementSource = null;
}
@Entity
public class EnergyProfile extends MeasurementSet {
@JsonProperty("measurementMetaData")
@OneToOne(cascade=CascadeType.ALL)
@JoinColumn(name = "energyMeasurementMetaID", nullable = true)
private EnergyMeasurementMetaData measurementMetaData = null;
}
@Entity
public class MeasurementSet extends Measurement {
}
@Entity
public class Measurement {
@JsonProperty("measurementID")
@Id
@GeneratedValue
private Integer measurementID;
@JsonProperty("timeReference")
@Embedded
private UTCDateTimeInterval timeReference = null;
@JsonProperty("measurementMetaData")
@OneToOne(cascade=CascadeType.ALL)
@JoinColumn(name = "measurementMetaID", nullable = true)
private MeasurementMetadata measurementMetaData = null;
}
And the MeasurementMetadata subclass tree
@Entity(name="WeatherMeasurementMetaData")
@AttributeOverride(name="measurementMetaID",
column=@Column(name="weatherMeasurementMetaID"))
public class WeatherMeasurementMetaData extends MeasurementMetadata {
@JsonProperty("weatherDataKind")
@Enumerated
private WeatherDataKind weatherDataKind = null;
}
@Entity(name="PowerMeasurementMetaData")
@AttributeOverride(name="measurementMetaID",
column=@Column(name="powerMeasurementMetaID"))
public class PowerMeasurementMetaData extends MeasurementMetadata {
@JsonProperty("measuringPeriod")
@Enumerated
private MeasuringPeriodKind measuringPeriod = null;
@JsonProperty("powerDataKind")
@Enumerated
private PowerDataKind powerDataKind = null;
}
@Entity(name="EnergyMeasurementMetaData")
@AttributeOverride(name="measurementMetaID",
column=@Column(name="energyMeasurementMetaID"))
public class EnergyMeasurementMetaData extends MeasurementMetadata {
@JsonProperty("energyDataKind")
@Enumerated
private EnergyDataKind energyDataKind = null;
@JsonProperty("measuringPeriod")
@Enumerated
private MeasuringPeriodKind measuringPeriod = null;
}
@Entity
public class MeasurementMetadata {
@JsonProperty("measurementMetaID")
@Id
@GeneratedValue
private Integer measurementMetaID;
@JsonProperty("accumulationCharacteristic")
@Enumerated
@AttributeOverrides(@AttributeOverride(name = "value", column =
@Column(name = "accumulationCharacteristic")))
private AccumulationKind accumulationCharacteristic = null;
@JsonProperty("dataQualifier")
@Enumerated
@AttributeOverrides(@AttributeOverride(name = "value", column =
@Column(name = "dataQualifier")))
private DataQualifierKind dataQualifier = null;
@JsonProperty("description")
private String description = null;
@JsonProperty("itemDescription")
private String itemDescription = null;
@Embedded
@JsonProperty("itemUnits")
private XBRLItemType itemUnits = null;
@JsonProperty("measurementQuality")
@Enumerated
@AttributeOverrides(@AttributeOverride(name = "value", column =
@Column(name = "measurementQuality")))
private QualityOfReading measurementQuality = null;
@JsonProperty("resolution")
private Float resolution = null;
@JsonProperty("siScaleCode")
@Enumerated
@AttributeOverrides(@AttributeOverride(name = "value", column =
@Column(name = "siScaleCode")))
private SiScaleCodeType siScaleCode = null;
}
The Profile objects are subclassed from Measurement. Each Profile object has a MeasurementMetadata object, and in some cases a subclass of MeasurementMetadata is used. For example WeatherProfile.measurementMetaData takes a WeatherMeasurementMetaData object, EnergyProfile.measurementMetaData takes a EnergyMeasurementMetaData object, and PowerProfile.measurementMetaData takes a PowerMeasurementMetaData object.
We still haven't determined whether the interpretation of the above error message was correct. After some reading and pondering I first tried implementing JsonSerializer objects using the procedure outlined in the Spring Boot documentation.
docs.spring.io spring-boot 1.5.7.RELEASE reference #boot-features-json-components Since it seemed to be related to the Serialization process, perhaps a custom Serializer would do the trick.
With Spring Boot this task is simpler than with straight Spring. You create a class:
import java.io.*;
import com.fasterxml.jackson.core.*;
import com.fasterxml.jackson.databind.*;
import org.springframework.boot.jackson.*;
@JsonComponent
public class Example {
public static class Serializer extends JsonSerializer<SomeObject> {
// ...
}
public static class Deserializer extends JsonDeserializer<SomeObject> {
// ...
}
}
It contains a pair of inner classes for each class you wish to implement a custom Serializer and Deserializer. Unfortunately the documentation doesn't include a clear example of what to do next. Fortunately there's a bit of a clue in the Spring Boot source code, at
github.com spring-projects spring-boot v1.5.7.RELEASE spring-boot src main java org springframework boot jackson JsonObjectSerializer.java
For a different way to implement @JsonSerialize see
stackoverflow.com/questions/7161638/
@JsonComponent
public class MeasurementsSerializers {
private static final Logger logger = LoggerFactory.getLogger(MeasurementsSerializers.class);
public static class EnergyProfileSerializer extends JsonSerializer<EnergyProfile> {
@Override
public void serialize(EnergyProfile value, JsonGenerator jgen, SerializerProvider serializers)
throws IOException, JsonProcessingException {
try {
logger.info("MeasurementsSerializers serialize EnergyProfile "+ value.toString());
jgen.writeStartObject();
jgen.writeNumberField("measurementID", value.getMeasurementID());
jgen.writeObjectField("timeReference", value.getTimeReference());
jgen.writeObjectField("measurementMetaData", value.getMeasurementMetaData());
if (value instanceof SolarEnergyProfile) {
jgen.writeObjectField("measurementSource", ((SolarEnergyProfile) value).getMeasurementSource());
}
if (value instanceof SolarEnergyForecastProfile) {
jgen.writeObjectField("measurementSource", ((SolarEnergyForecastProfile) value).getMeasurementSource());
}
jgen.writeEndObject();
}
catch (Exception ex) {
if (ex instanceof IOException) {
throw (IOException) ex;
}
throw new JsonMappingException(jgen, "Object serialize error", ex);
}
}
}
...
}
Unfortunately this didn't make any difference in the behavior of the error. But it did give a solid indication that code was being executed and the objects looked correct.
I later decided to implement empty EntityListener classes to again see if I could gain some more insight. I discussed these classes in Persisting complex Embeddable/Embedded objects in Spring/Hibernate
For example:
@Entity
@EntityListeners(EnergyProfileEntityListener.class)
public class EnergyProfile extends MeasurementSet {
...
}
The @EntityListeners references an EntityListener class. It looks like so:
public class EnergyProfileEntityListener {
private static final Logger logger = LoggerFactory.getLogger(EnergyProfileEntityListener.class);
@PrePersist
public void energyPrePersist(EnergyProfile profile) {
logger.info("EnergyProfileEntityListener prePersist "+ profile.toString());
}
@PostUpdate
@PostLoad
public void energyPostLoad(EnergyProfile profile) {
logger.info("EnergyProfileEntityListener @PostUpdate @PostLoad "+ profile.toString());
}
}
In case it's not obvious, EntityListener methods are triggered at certain points in the lifecycle of an Entity instance. In this case we're triggering just before the Entity is to be persisted to a database, and then just after the Entity is constructed. One can do quite powerful things with EntityListener methods, but we just want to print something to show what the status of the object is at each moment in time.
THIS step made for a useful change in the behavior of the application in that we could see more data about the error message. The error still occurred but we knew more about what happened.
2017-10-16 16:25:52.595 ERROR 19710 --- [nio-8080-exec-6] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.orm.jpa.JpaSystemException: Could not set field value [class PowerMeasurementMetaData {
class MeasurementMetadata {
accumulationCharacteristic: null
dataQualifier: null
description: null
itemDescription: null
itemUnits: null
measurementQuality: null
resolution: null
siScaleCode: null
} measuringPeriod: null
powerDataKind: null
}] value by reflection : [class com.amzur.orangebuttonapi.model.measurementsets.SolarEnergyProfile.measurementMetaData] setter of com.amzur.orangebuttonapi.model.measurementsets.SolarEnergyProfile.measurementMetaData; nested exception is org.hibernate.PropertyAccessException: Could not set field value [class PowerMeasurementMetaData {
class MeasurementMetadata {
accumulationCharacteristic: null
dataQualifier: null
description: null
itemDescription: null
itemUnits: null
measurementQuality: null
resolution: null
siScaleCode: null
} measuringPeriod: null
powerDataKind: null
}] value by reflection : [class com.amzur.orangebuttonapi.model.measurementsets.SolarEnergyProfile.measurementMetaData] setter of com.amzur.orangebuttonapi.model.measurementsets.SolarEnergyProfile.measurementMetaData] with root cause
java.lang.IllegalArgumentException: Can not set com.amzur.orangebuttonapi.model.measurementsets.EnergyMeasurementMetaData field com.amzur.orangebuttonapi.model.measurementsets.EnergyProfile.measurementMetaData to com.amzur.orangebuttonapi.model.measurementsets.PowerMeasurementMetaData
at sun.reflect.UnsafeFieldAccessorImpl.throwSetIllegalArgumentException(UnsafeFieldAccessorImpl.java:167) ~[na:1.8.0_101]
at sun.reflect.UnsafeFieldAccessorImpl.throwSetIllegalArgumentException(UnsafeFieldAccessorImpl.java:171) ~[na:1.8.0_101]
at sun.reflect.UnsafeObjectFieldAccessorImpl.set(UnsafeObjectFieldAccessorImpl.java:81) ~[na:1.8.0_101]
at java.lang.reflect.Field.set(Field.java:764) ~[na:1.8.0_101]
at org.hibernate.property.access.spi.SetterFieldImpl.set(SetterFieldImpl.java:38) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.tuple.entity.AbstractEntityTuplizer.setPropertyValues(AbstractEntityTuplizer.java:612) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.tuple.entity.PojoEntityTuplizer.setPropertyValues(PojoEntityTuplizer.java:220) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.persister.entity.AbstractEntityPersister.setPropertyValues(AbstractEntityPersister.java:4647) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.engine.internal.TwoPhaseLoad.doInitializeEntity(TwoPhaseLoad.java:172) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.engine.internal.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:128) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.performTwoPhaseLoad(AbstractRowReader.java:238) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.finishUp(AbstractRowReader.java:209) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.loader.plan.exec.process.internal.ResultSetProcessorImpl.extractResults(ResultSetProcessorImpl.java:133) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:122) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.loader.collection.plan.AbstractLoadPlanBasedCollectionInitializer.initialize(AbstractLoadPlanBasedCollectionInitializer.java:88) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:688) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.event.internal.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:75) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.internal.SessionImpl.initializeCollection(SessionImpl.java:1991) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.collection.internal.AbstractPersistentCollection$4.doWork(AbstractPersistentCollection.java:570) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:252) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:566) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.collection.internal.AbstractPersistentCollection.read(AbstractPersistentCollection.java:135) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.collection.internal.PersistentBag.toString(PersistentBag.java:509) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
at com.amzur.orangebuttonapi.model.systemperformance.ActualPerformance.toIndentedString(ActualPerformance.java:155) ~[classes!/:0.0.1-SNAPSHOT]
at com.amzur.orangebuttonapi.model.systemperformance.ActualPerformance.toString(ActualPerformance.java:140) ~[classes!/:0.0.1-SNAPSHOT]
at com.amzur.orangebuttonapi.model.systemperformance.ActualPerformanceEntityListener.metaDataPostLoad(ActualPerformanceEntityListener.java:22) ~[classes!/:0.0.1-SNAPSHOT]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_101]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_101]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_101]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_101]
at org.hibernate.jpa.event.internal.jpa.ListenerCallback.performCallback(ListenerCallback.java:35) ~[hibernate-entitymanager-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.jpa.event.internal.jpa.CallbackRegistryImpl.callback(CallbackRegistryImpl.java:94) ~[hibernate-entitymanager-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.jpa.event.internal.jpa.CallbackRegistryImpl.postLoad(CallbackRegistryImpl.java:88) ~[hibernate-entitymanager-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.jpa.event.internal.core.JpaPostLoadEventListener.onPostLoad(JpaPostLoadEventListener.java:36) ~[hibernate-entitymanager-5.0.12.Final.jar!/:5.0.12.Final]
at org.hibernate.engine.internal.TwoPhaseLoad.postLoad(TwoPhaseLoad.java:314) ~[hibernate-core-5.0.12.Final.jar!/:5.0.12.Final]
We have essentially the same error message, but it's morphed a bit. We have a stack trace, not that it's entirely useful, and we have verification that something -- Hibernate to be precise -- was trying to fit a square peg into a round hole. That is, assigning a PowerMeasurementMetaData to a EnergyMeasurementMetaData field.
After quite a bit of reviewing the code I had an intuitive hunch and made this change.
@Entity
@Inheritance(strategy = InheritanceType.TABLE_PER_CLASS)
public class Measurement {
....
}
What we had was the case of an Entity class with several subclasses. By default, Hibernate uses a single table to represent all the variants of this class and its subclasses. Clearly Hibernate got confused about which class to assign to the object it was instantiating.
Making this change means Hibernate sets up a separate table for each subclass. In that circumstance, Hibernate does not get confused as to which class to instantiate when retrieving some data.
As a test - I've stripped out the EntityListener and Serializer classes which I'd implemented along the way. The problem is fixed.
