Mapper error updating Key array field with $set

[d4nirod]

Morphia 1.1.1 MongoDB Java Driver version: 2.14.0 MongoDB version: 3.0.12

Error:

161122 15:26:53,310 ERROR [Mapper] Error converting value([]) to reference.
java.lang.NullPointerException
  at org.mongodb.morphia.mapping.Mapper.getDBRefs(Mapper.java:725)
  at org.mongodb.morphia.mapping.Mapper.toMongoObject(Mapper.java:559)
  at org.mongodb.morphia.query.UpdateOpsImpl.add(UpdateOpsImpl.java:216)
  at org.mongodb.morphia.query.UpdateOpsImpl.set(UpdateOpsImpl.java:155)
  at com.farmerswife.cloudwife.server.services.dao.AbstractDAO.set(AbstractDAO.java:146)
  at com.farmerswife.cloudwife.server.services.dao.TaskDAO.updateAssignees(TaskDAO.java:661)
  at com.farmerswife.cloudwife.server.services.utils.UserConsumerUtils.consumeTaskAssignments(UserConsumerUtils.java:358)

xxxDAO methods on stack trace:

public void updateAssignees(EntityId<CWTask> taskId, List<Key<? extends Assignable>> assignees) {
  set(taskId, ASSIGNEES_FIELD, assignees);
}

protected boolean set(EntityId<T> entityId, String fieldExpr, Object value) {
  Query<T> q = q().field(Mapper.ID_KEY).equal(entityId);
  UpdateOperations<T> uops = ds.createUpdateOperations(entityClazz);
  uops.set(fieldExpr, value);   
  ds.update(q, uops);
  return true;
}

Entities:

@Entity(value = "cw_task")
@Converters(EntityIdConverter.class)
public class CWTask extends SyncableEntity implements Serializable {
   @Id
   private EntityId<CWTask> id;
   private String name;
   private String description;
   private Date dueDate;
   @Indexed 
   private EntityId<CWProject> projectId;

   private List<Key<? extends Assignable>> assignees = new ArrayList<>();
}

Note: EntityId basically extends ObjectId and provides type-safety (I know this breaks after Morphia 1.2 as ObjectId has been made final but at this point it's not relevant). Assignable is just a marker interface to restrict the type of entities that a CWTask can be assigned to, ie. CWUser, CWGroup, etc

---

The error is caused by line 558 of org.mongodb.morphia.mapping.Mapper.toMongoObject(MappedField, MappedClass, Object):

  if (mapped != null && (Key.class.isAssignableFrom(mapped.getClazz()) || mapped.getEntityAnnotation() != null))

where if we pass in an empty list as field value, being the CWTask.assignees field of type List<Key> with no annotation (Key.class.isAssignableFrom(mapped.getClazz()) evals as true and mapped.getEntityAnnotation() != null evaluates as false so getDBRefs() is then invoked resulting in NPE at line 725

[evanchooly]

Does the error remain with 1.3.0-rc0?

[d4nirod]

Can't easily tell as we can't go to version above 1.1.x without breaking the build due to the ObjectId been made final so we are stuck here until we find a work around for our class EntityId extends ObjectId thing or the Morphia devs un-final it ;-P, in any case the offending line from Mapper.toMongoObject() is still there now in line 616 and so is the Mapper.getDBRefs() which is unchanged so it would be quite safe to say it still happens.

[evanchooly]

ObjectId comes from the Java driver. Morphia itself has no control over its finalness.

[d4nirod]

Ah, yes of course... sorry. But that's not the main thing, let me clarify that as not to muddle the issue:

Just tested up to Morphia 1.2.1 and the mapping error using $set to update a non-annotated Key array field with an empty array is still happening as described earlier.

---

Note: can't test with Morphia 1.3.x since needs Java Driver 3.x which we can't use because it has made ObjectId final so it breaks our code.

[d4nirod]

Actually now that I dug a bit deeper I think that this is not related to an empty list, I think it all boils down to the fact that if one uses a List of Keys for an entity field, org.mongodb.morphia.mapping.Mapper expects it to be always annotated with @Reference, otherwise it will throw up a NPE:

private Object getDBRefs(final MappedField field, final Iterable value) {
    final List<Object> refs = new ArrayList<Object>();
    boolean idOnly = field.getAnnotation(Reference.class).idOnly();  // <---HERE
    for (final Object o : value) {
        Key<?> key = (o instanceof Key) ? (Key<?>) o : getKey(o);
        refs.add(idOnly ? key.getId() : keyToDBRef(key));
    }
    return refs;
}

So is this a bug of a feature? I mean, is it mandatory to use Key fields annotated with @Reference only...? and if so, why does this error happen only with update() operations (aka $set) and not with save()?

[d4nirod]

@evanchooly: any comments on this?

[evanchooly]

I'm probably missing something but this seems to work on master. Here's my attempt to reproduce your test case. If it's not quite right let me know but everything seems ok so far.

        CWTask task = new CWTask();
        task.id = new ObjectId();
        Key<CWTask> key = getDs().getKey(task);
        task.assignees = new ArrayList<Key<? extends CWTask>>(singletonList(key));
        getDs().save(task);

        getDs().update(getDs().find(CWTask.class),
                       getDs().createUpdateOperations(CWTask.class).set("assignees", task.assignees));

[d4nirod]

Ok, I still get the error. Pushed a little standalone test to https://github.com/d4nirod/morphiatest (check that jdk >= 1.70) With Mongo Java driver 3.4.x and Morphia 1.3.0-rc0

11201 13:12:01,906 INFO  [MapperIssueTest] ********** STARTING morphiatest.MapperIssueTest *************
161201 13:12:01,907 INFO  [MapperIssueTest] Using Java version: 1.8.0_73
161201 13:12:02,165 INFO  [cluster] Cluster created with settings {hosts=[127.0.0.1:27017], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}
161201 13:12:02,261 INFO  [MorphiaLoggerFactory] LoggerImplFactory set to org.mongodb.morphia.logging.slf4j.SLF4JLoggerImplFactory
161201 13:12:02,283 INFO  [connection] Opened connection [connectionId{localValue:1, serverValue:841}] to 127.0.0.1:27017
161201 13:12:02,285 INFO  [cluster] Monitor thread successfully connected to server with description ServerDescription{address=127.0.0.1:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 0, 12]}, minWireVersion=0, maxWireVersion=3, maxDocumentSize=16777216, roundTripTimeNanos=750273}
161201 13:12:02,345 INFO  [connection] Opened connection [connectionId{localValue:2, serverValue:842}] to 127.0.0.1:27017
161201 13:12:02,359 INFO  [MapperIssueTest] Using MongoDB version: 3.0.12
161201 13:12:02,359 INFO  [MapperIssueTest] Using: mongo-java-driver version: 3.4.0
161201 13:12:02,360 INFO  [MapperIssueTest] Using: Morphia Core version: 1.3.0.rc0
161201 13:12:02,360 INFO  [MapperIssueTest] Configured MongoDB to URI: 'mongodb://127.0.0.1:27017', DB name: 'cloudwife
161201 13:12:02,417 INFO  [MapperIssueTest] 'Testing Mapper 2016-12-01T13:12:02.361' saved with ID: 58401392f3352dda901f9bd1
161201 13:12:02,420 WARN  [MappedField] Parameterized types are treated as untyped Objects. See field 'type' on class org.mongodb.morphia.Key
161201 13:12:02,421 WARN  [MappedField] Parameterized types are treated as untyped Objects. See field 'id' on class org.mongodb.morphia.Key
161201 13:12:02,421 ERROR [Mapper] Error converting value([Key{collection=cw_task, id=58401392f3352dda901f9bd1}]) to reference.
java.lang.NullPointerException
    at org.mongodb.morphia.mapping.Mapper.getDBRefs(Mapper.java:786)
    at org.mongodb.morphia.mapping.Mapper.toMongoObject(Mapper.java:617)
    at org.mongodb.morphia.query.UpdateOpsImpl.add(UpdateOpsImpl.java:285)
    at org.mongodb.morphia.query.UpdateOpsImpl.set(UpdateOpsImpl.java:223)
    at morphiatest.MapperIssueTest.main(MapperIssueTest.java:44)

This is with Mongo Java Driver 2.14.x and Morphia 1.2.1:

161201 13:25:28,529 INFO  [MapperIssueTest] ********** STARTING morphiatest.MapperIssueTest *************
161201 13:25:28,530 INFO  [MapperIssueTest] Using Java version: 1.8.0_73
161201 13:25:29,575 INFO  [MorphiaLoggerFactory] LoggerImplFactory set to org.mongodb.morphia.logging.slf4j.SLF4JLoggerImplFactory
161201 13:25:29,675 INFO  [MapperIssueTest] Using MongoDB version: 3.0.12
161201 13:25:29,676 INFO  [MapperIssueTest] Using: MongoDB Java Driver version: 2.14.0.RELEASE
161201 13:25:29,677 INFO  [MapperIssueTest] Using: Morphia Core version: 1.2.1
161201 13:25:29,677 INFO  [MapperIssueTest] Configured MongoDB to URI: 'mongodb://127.0.0.1:27017', DB name: 'cloudwife
161201 13:25:29,717 INFO  [MapperIssueTest] 'Testing Mapper 2016-12-01T13:25:29.678' saved with ID: 584016b93acaadc92e937551
161201 13:25:29,720 WARN  [MappedField] Parameterized types are treated as untyped Objects. See field 'type' on class org.mongodb.morphia.Key
161201 13:25:29,720 WARN  [MappedField] Parameterized types are treated as untyped Objects. See field 'id' on class org.mongodb.morphia.Key
161201 13:25:29,721 ERROR [Mapper] Error converting value([Key{collection=cw_task, id=584016b93acaadc92e937551}]) to reference.
java.lang.NullPointerException
    at org.mongodb.morphia.mapping.Mapper.getDBRefs(Mapper.java:750)
    at org.mongodb.morphia.mapping.Mapper.toMongoObject(Mapper.java:584)
    at org.mongodb.morphia.query.UpdateOpsImpl.add(UpdateOpsImpl.java:216)
    at org.mongodb.morphia.query.UpdateOpsImpl.set(UpdateOpsImpl.java:155)
    at morphiatest.MapperIssueTest.main(MapperIssueTest.java:44)

[edited]

[evanchooly]

This is actually working for me with Morphia 1.3.0, driver 3.4.0, and MongoDB 3.4.0-rc0. Well, I'm not getting any exceptions at least. assignees is always null which i'm exploring but definitely not seeing the exception you are.

[d4nirod]

@evanchooly do you mean you actually don't see the errors when running the little Maven project I posted? That would be puzzling... If not it might be a case of log levels or config in your log4j? Looking at the stack trace I could see that the exception was actually caught within Mapper.toMongoObject(final MappedField mf, final MappedClass mc, final Object value) if I remember correctly (away from my computer at the mo) which logs the "Error converting blah" message and then gets the mapped value from Mapper.toMongoObject(final Object javaObj, final boolean includeClassName) instead which may return null if empty array value or akternatively attempts some default conversion...?

[evanchooly]

When I step through that project with a debugger all is fine. When I add new output, i see it all.

[d4nirod]

Ahh. Weird, well I put that project together quickly as a test case by taking our pom.xml and removing most of the stuff so it might be best if you could try reproduce on oneof your projects but at least we agree there is an issue here?

[d4nirod]

@evanchooly sorry there was I bug in the test code I pushed where the key in the assignees Key List was always assigned to null since ds.getKey(task) was returning null. I've fixed it and pushed it to the repo so now we can see the original error message I've been talking about all along: ERROR [Mapper] Error converting value([Key{...}]) to reference. java.lang.NullPointerException I've updated my earlier post with the correct error messages.

[evanchooly]

I've rolled all the way back to mongodb 3.0.14. I've used morphia 1.2.1 and 1.3.0. I can't recreate your bug. Even with your updated tests.

[d4nirod]

Hmm, there is something missing here ... I'm a bit in the dark with regards of the actual test output on your side but I strongly suspect it might be Log4J not working as this error is caught and logged inside Morphia's Mapper.toMongoObject(). If logging was not configured properly, you wouldn't see the error message, just the test program console output.

What IDE are you using? I'm with Eclipse and it picked the log4j.xml file ok from it's original location but I think it wasn't very "standard" so I've moved it to src/main/resources. I believe both Eclipse and IntelliJ should pick it up now. I've also replaced all System.out.println() calls for log calls so if logging doesn't work there won't be any messages from the test program and we'll know it's not working. (updated the output on the earlier post again to reflect what you should see).

Can you please pull the changes, re-run the test and paste the output?

Thank you.

[evanchooly]

That did it. I see the NPE now. I'll dig in to it. Thanks.

[d4nirod]

Any chance to fix it also on v1.2.x? We're stuck with Morphia 1.2.x + Mongo Java Driver 2.14.x until we can figure out how to workaround ObjectId finalness introduced on Java Driver r3.0.0.

---

Note: I've just remembered discussing this with you in Groups a while ago. The way we have started using Key in CWTask.assignees as a loose foreign key/entity reference it's our attempt to explore usage of said class to perhaps later substitute our class EntityId<T> extends ObjectId for Key as type-safe entity ID.

[d4nirod]

Any chance to fix it also on v1.2.x? We're stuck with Morphia 1.2.x + Mongo Java Driver 2.14.x until we can figure out how to workaround ObjectId finalness introduced on Java Driver r3.0.0.

@evanchooly: bump

[evanchooly]

I've opened https://github.com/mongodb/morphia/issues/1108 to backport this.

[evanchooly]

I just pushed 1.2.2 to maven central. It should be available soon.

[d4nirod]

Thank you. Much obliged.