Time attribute issue

[ustroetz]

For the following request I get a system error message:

Request

http://localhost:8080/otp/routers/default/plan?arriveBy=false&fromPlace=14.5885504,121.0213286&maxWalkDistance=50000&mode=TRANSIT%2CWALK&optimize=QUICK&showIntermediateStops=true&time=2015-04-03T05%3A33%3A21%2B08%3A00&toPlace=14.432727,121.01022

Response

{
    "requestParameters": {
        "mode": "TRANSIT,WALK",
        "arriveBy": "false",
        "optimize": "QUICK",
        "showIntermediateStops": "true",
        "fromPlace": "14.5885504,121.0213286",
        "toPlace": "14.432727,121.01022",
        "maxWalkDistance": "50000",
        "time": "2015-04-03T05:33:21+08:00"
    },
    "error": {
        "id": 500,
        "msg": "We're sorry. The trip planner is temporarily unavailable. Please try again later.",
        "message": "SYSTEM_ERROR",
        "noPath": true
    },
    "debugOutput": {
        "precalculationTime": 0,
        "pathCalculationTime": 0,
        "pathTimes": [],
        "renderingTime": 0,
        "totalTime": 0,
        "timedOut": false
    }
}

Log

16:17:45.615 WARN (AStar.java:233) Search timeout. origin=<Capt. T. Posadas Ave._14.4546106,121.0492766 lat,lng=14.454691673228204,121.04835672850638> target=<path_14.5607,121.016352 lat,lng=14.560726619014941,121.01639405235488>
16:17:45.617 ERROR (GraphPathFinder.java:334) A graph path leaves before the requested time. This implies a bug.
16:17:45.617 ERROR (GraphPathFinder.java:334) A graph path leaves before the requested time. This implies a bug.
16:17:45.629 ERROR (PlannerError.java:62) exception planning trip: 
java.lang.IndexOutOfBoundsException: Index: 0, Size: 0
    at java.util.ArrayList.rangeCheck(ArrayList.java:653) ~[na:1.8.0_31]
    at java.util.ArrayList.get(ArrayList.java:429) ~[na:1.8.0_31]
    at org.opentripplanner.api.resource.GraphPathToTripPlanConverter.generatePlan(GraphPathToTripPlanConverter.java:65) ~[otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.opentripplanner.api.resource.PlannerResource.plan(PlannerResource.java:79) ~[otp-0.15.0-SNAPSHOT.jar:1.1]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_31]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_31]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_31]
    at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_31]
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:151) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:171) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:195) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:104) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:384) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:342) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:101) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:271) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:297) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:254) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1030) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer.service(GrizzlyHttpContainer.java:378) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.grizzly.http.server.HttpHandler$1.run(HttpHandler.java:219) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:565) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:545) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_31]
16:17:45.632 WARN (PlannerResource.java:85) Error while planning path: 
java.lang.IndexOutOfBoundsException: Index: 0, Size: 0
    at java.util.ArrayList.rangeCheck(ArrayList.java:653) ~[na:1.8.0_31]
    at java.util.ArrayList.get(ArrayList.java:429) ~[na:1.8.0_31]
    at org.opentripplanner.api.resource.GraphPathToTripPlanConverter.generatePlan(GraphPathToTripPlanConverter.java:65) ~[otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.opentripplanner.api.resource.PlannerResource.plan(PlannerResource.java:79) ~[otp-0.15.0-SNAPSHOT.jar:1.1]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_31]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_31]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_31]
    at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_31]
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:151) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:171) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:195) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:104) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:384) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:342) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:101) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:271) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:297) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:254) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1030) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer.service(GrizzlyHttpContainer.java:378) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.grizzly.http.server.HttpHandler$1.run(HttpHandler.java:219) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:565) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:545) [otp-0.15.0-SNAPSHOT.jar:1.1]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_31]

OTP Version

otp-0.15.0-SNAPSHOT.jar

GTFS Dataset

http://www.dotc.gov.ph/images/Open_Data/gtfs_884416.zip

OSM Dataset

https://s3.amazonaws.com/metro-extracts.mapzen.com/manila_phillipines.osm.pbf

[laurentg]

This is caused by the gpi.remove() line in GraphPathFinder::graphPathFinderEntryPoint(), this cause the returned paths array to be empty, causing the exception further on in GraphPathToTripPlanConverter.generatePlan(). I guess the test if (paths == null || paths.size() == 0) should be moved down a bit.

@abyrd I leave you correct this?

[laurentg]

Oviously, this is not explaining the root cause A graph path leaves before the requested time. This implies a bug.