search

conveyal / analysis-backend

Server component of Conveyal Analysis
http://conveyal.com/analysis
MIT License
23 stars 12 forks source link

Jobs status API endpoint fails #214

Closed abyrd closed 5 years ago

abyrd commented 5 years ago

I'm running a regional analysis on staging of the Basel region, using a car-wait modification. All frontend requests for job status are failing with a 400 response code, with a stacktrace from the backend implicating a MongoDB fetch. This seems to fail consistently on staging but on production it's returning a valid jobs list.

10:27:30.538 [qtp210426703-49] ERROR com.conveyal.taui.AnalysisServer - RUNTIME java.lang.RuntimeException: IOException encountered while reading from a byte array input stream -> GET /api/jobs by abyrd@conveyal.com of conveyal
10:27:30.538 [qtp210426703-49] ERROR com.conveyal.taui.AnalysisServer - IOException encountered while reading from a byte array input stream
java.lang.RuntimeException: IOException encountered while reading from a byte array input stream
    at org.mongojack.internal.stream.JacksonDBDecoder.decode(JacksonDBDecoder.java:67)
    at com.mongodb.DBDecoderAdapter.decode(DBDecoderAdapter.java:49)
    at com.mongodb.DBDecoderAdapter.decode(DBDecoderAdapter.java:29)
    at com.mongodb.operation.CommandResultArrayCodec.decode(CommandResultArrayCodec.java:52)
    at com.mongodb.operation.CommandResultDocumentCodec.readValue(CommandResultDocumentCodec.java:60)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:84)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:41)
    at org.bson.codecs.configuration.LazyCodec.decode(LazyCodec.java:47)
    at org.bson.codecs.BsonDocumentCodec.readValue(BsonDocumentCodec.java:101)
    at com.mongodb.operation.CommandResultDocumentCodec.readValue(CommandResultDocumentCodec.java:63)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:84)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:41)
    at com.mongodb.internal.connection.ReplyMessage.<init>(ReplyMessage.java:48)
    at com.mongodb.internal.connection.InternalStreamConnection.getCommandResult(InternalStreamConnection.java:393)
    at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:299)
    at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:255)
    at com.mongodb.internal.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:99)
    at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:444)
    at com.mongodb.internal.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:72)
    at com.mongodb.internal.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:200)
    at com.mongodb.internal.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:269)
    at com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:131)
    at com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:123)
    at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:242)
    at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:233)
    at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:136)
    at com.mongodb.operation.FindOperation$1.call(FindOperation.java:701)
    at com.mongodb.operation.FindOperation$1.call(FindOperation.java:695)
    at com.mongodb.operation.OperationHelper.withConnectionSource(OperationHelper.java:462)
    at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:406)
    at com.mongodb.operation.FindOperation.execute(FindOperation.java:695)
    at com.mongodb.operation.FindOperation.execute(FindOperation.java:83)
    at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:179)
    at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:161)
    at com.mongodb.DBCursor.initializeCursor(DBCursor.java:896)
    at com.mongodb.DBCursor.hasNext(DBCursor.java:148)
    at com.mongodb.DBCursor.next(DBCursor.java:168)
    at org.mongojack.DBCursor.next(DBCursor.java:342)
    at com.conveyal.taui.controllers.BrokerController.getAllJobs(BrokerController.java:243)
    at spark.RouteImpl$1.handle(RouteImpl.java:72)
    at spark.http.matching.Routes.execute(Routes.java:61)
    at spark.http.matching.MatcherFilter.doFilter(MatcherFilter.java:130)
    at spark.embeddedserver.jetty.JettyHandler.doHandle(JettyHandler.java:50)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1568)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
    at org.eclipse.jetty.server.Server.handle(Server.java:564)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:317)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
    at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128)
    at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591)
    at java.lang.Thread.run(Thread.java:748)
Caused by: com.fasterxml.jackson.databind.JsonMappingException: Unrecognized Type: [null] (through reference chain: com.conveyal.taui.models.RegionalAnalysis["request"]->com.conveyal.r5.analyst.cluster.RegionalTask["scenario"]->com.conveyal.r5.analyst.scenario.Scenario["modifications"]->java.util.ArrayList[0])
    at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:210)
    at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:189)
    at com.fasterxml.jackson.databind.deser.std.CollectionDeserializer.deserialize(CollectionDeserializer.java:266)
    at com.fasterxml.jackson.databind.deser.std.CollectionDeserializer.deserialize(CollectionDeserializer.java:217)
    at com.fasterxml.jackson.databind.deser.std.CollectionDeserializer.deserialize(CollectionDeserializer.java:25)
    at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java:520)
    at com.fasterxml.jackson.databind.deser.impl.FieldProperty.deserializeAndSet(FieldProperty.java:101)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:256)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:125)
    at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java:520)
    at com.fasterxml.jackson.databind.deser.impl.FieldProperty.deserializeAndSet(FieldProperty.java:101)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:256)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer._deserializeOther(BeanDeserializer.java:159)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:134)
    at com.fasterxml.jackson.databind.jsontype.impl.AsPropertyTypeDeserializer._deserializeTypedForId(AsPropertyTypeDeserializer.java:122)
    at com.fasterxml.jackson.databind.jsontype.impl.AsPropertyTypeDeserializer.deserializeTypedFromObject(AsPropertyTypeDeserializer.java:93)
    at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.deserializeWithType(BeanDeserializerBase.java:992)
    at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java:518)
    at com.fasterxml.jackson.databind.deser.impl.FieldProperty.deserializeAndSet(FieldProperty.java:101)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserializeFromObject(BeanDeserializer.java:337)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:131)
    at com.fasterxml.jackson.databind.ObjectMapper._readValue(ObjectMapper.java:3674)
    at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2062)
    at org.mongojack.internal.stream.JacksonDBDecoder.decode(JacksonDBDecoder.java:77)
    at org.mongojack.internal.stream.JacksonDBDecoder.decode(JacksonDBDecoder.java:64)
    ... 58 more
Caused by: java.lang.IllegalArgumentException: Unrecognized Type: [null]
    at com.fasterxml.jackson.databind.type.TypeFactory._constructType(TypeFactory.java:498)
    at com.fasterxml.jackson.databind.type.TypeFactory.constructType(TypeFactory.java:447)
    at com.conveyal.r5.analyst.scenario.ModificationTypeResolver.typeFromId(ModificationTypeResolver.java:73)
    at com.fasterxml.jackson.databind.jsontype.impl.TypeDeserializerBase._findDeserializer(TypeDeserializerBase.java:154)
    at com.fasterxml.jackson.databind.jsontype.impl.AsPropertyTypeDeserializer._deserializeTypedForId(AsPropertyTypeDeserializer.java:108)
    at com.fasterxml.jackson.databind.jsontype.impl.AsPropertyTypeDeserializer.deserializeTypedFromObject(AsPropertyTypeDeserializer.java:93)
    at com.fasterxml.jackson.databind.deser.AbstractDeserializer.deserializeWithType(AbstractDeserializer.java:131)
    at com.fasterxml.jackson.databind.deser.std.CollectionDeserializer.deserialize(CollectionDeserializer.java:247)
    ... 80 more
abyrd commented 5 years ago

The same problem can be seen when fetching a completed regional analysis. In that case the URL fetched is https://analysis-staging.conveyal.com/api/regional/[ID]/grid/grid?redirect=false and the resulting stack trace is very similar, except that our code causing the database problem is in RegionalAnalysisController.java:99 instead of BrokerController.java:243.

In both cases this is a call finding an element in Persistence.regionalAnalyses by ID. It's probably failing because the backend doesn't know how to deserialize these custom modification types, which are known only to the worker.

Note this reference chain in the stack trace: Unrecognized Type: [null] (through reference chain: com.conveyal.taui.models.RegionalAnalysis["request"]->com.conveyal.r5.analyst.cluster.RegionalTask["scenario"]->com.conveyal.r5.analyst.scenario.Scenario["modifications"]->java.util.ArrayList[0]).

The backend is saving the list of modifications in each regional analysis, after they are converted to R5 modifications. It attempts to deserialize these into R5 objects whenever it fetches the regional analysis.

abyrd commented 5 years ago

@trevorgerhardt has pointed out that we're already excluding the scenarios from being fetched at https://github.com/conveyal/analysis-backend/blob/dev/src/main/java/com/conveyal/taui/controllers/RegionalAnalysisController.java#L61

but this is in only one endpoint. There are at least two other places we can make this exclusion.

In the future we may want to store the UI/backend version of the modifications, or not store them at all and clean them out of the database entirely, since the R5 modifications are always saved on S3 as a JSON file for each regional analysis.