otp-1.4.0-shaded.jar does not save (write) big graph to file after building it

opentripplanner / OpenTripPlanner

An open source multi-modal trip planner

http://www.opentripplanner.org

Other

2.21k stars 1.03k forks source link

otp-1.4.0-shaded.jar does not save (write) big graph to file after building it #3128

Closed SRN1973 closed 2 years ago

SRN1973 commented 4 years ago

I realized that the otp-1.4.0-shaded.jar does not write back a calculated Graph.obj when the input files cover a whole country. (the otp-1.3.0-shaded.jar as well as the otp-2.0-shaded.jar both write the graph as expected)

Input files:

germany-latest-osm.pbf (https://download.geofabrik.de/europe/germany-latest.osm.pbf) -GTFS files: https://download.gtfs.de/germany/fv_free/latest.zip https://download.gtfs.de/germany/nv_free/latest.zip https://download.gtfs.de/germany/rv_free/latest.zip

-> no custom build-config.json -> all files are in the directory otp/graphs/current_14

Command to build and save the Graph: /usr/lib/jvm/java-1.8.0-openjdk-amd64/bin/java -Xmx300G -jar otp-1.4.0-shaded.jar --build graphs/current_14 respectively with openjdk-11-jre-headless (I tried both but the result is the same) java -Xmx300G -jar otp-1.4.0-shaded.jar --build graphs/current_14

Operating System: Ubuntu 18.04.4 LTS RAM: 1 TB 120 cernels

Error message of otp: 3:10:31.235 INFO (DirectTransferGenerator.java:100) Done connecting stops to one another. Created a total of 999488 transfers from 348928 stops. 23:10:31.247 INFO (Graph.java:963) Summary (number of each type of annotation):
23:10:31.434 INFO (Graph.java:969) TripDegenerate - 2540
23:10:31.434 INFO (Graph.java:969) NoFutureDates - 3
23:10:31.434 INFO (Graph.java:969) TurnRestrictionBad - 11646
23:10:31.434 INFO (Graph.java:969) RepeatedStops - 1754
23:10:31.434 INFO (Graph.java:969) HopZeroTime - 1152895
23:10:31.434 INFO (Graph.java:969) HopSpeedSlow - 9256
23:10:31.434 INFO (Graph.java:969) StopNotLinkedForTransfers - 54007
23:10:31.434 INFO (Graph.java:969) LevelAmbiguous - 17896
23:10:31.434 INFO (Graph.java:969) HopSpeedFast - 52846
23:10:31.434 INFO (Graph.java:969) StopLinkedTooFar - 3088
23:10:31.435 INFO (Graph.java:969) TurnRestrictionUnknown - 439
23:10:31.435 INFO (Graph.java:969) GraphConnectivity - 81826
23:10:31.435 INFO (Graph.java:969) StopUnlinked - 2950
23:10:31.435 INFO (Graph.java:969) TurnRestrictionException - 1394
23:10:31.435 INFO (Graph.java:969) Graphwide - 1
23:10:40.580 INFO (Graph.java:814) Main graph size: |V|=24870759 |E|=60642402
23:10:40.580 INFO (Graph.java:815) Writing graph /media/vol2/stefan/b/Open_Trip_Planner/graphs/current_14/Graph.obj ...
Exception in thread "main" java.lang.IllegalStateException: com.esotericsoftware.kryo.KryoException: java.lang.NegativeArraySizeException Serialization trace: compactGeometry (org.opentripplanner.routing.edgetype.StreetEdge)
at org.opentripplanner.graph_builder.GraphBuilder.run(GraphBuilder.java:146)
at org.opentripplanner.standalone.OTPMain.run(OTPMain.java:103)
at org.opentripplanner.standalone.OTPMain.main(OTPMain.java:73)
Caused by: com.esotericsoftware.kryo.KryoException: java.lang.NegativeArraySizeException Serialization trace: compactGeometry (org.opentripplanner.routing.edgetype.StreetEdge)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:101)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651)
at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:100)
at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:40)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651)

at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:100)
at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:40)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651)
at org.opentripplanner.routing.graph.Graph.save(Graph.java:841)
at org.opentripplanner.routing.graph.Graph.save(Graph.java:817)
at org.opentripplanner.graph_builder.GraphBuilder.run(GraphBuilder.java:144)
... 2 more
Caused by: java.lang.NegativeArraySizeException
at com.esotericsoftware.kryo.util.IdentityObjectIntMap.resize(IdentityObjectIntMap.java:542)
at com.esotericsoftware.kryo.util.IdentityObjectIntMap.putStash(IdentityObjectIntMap.java:306)
at com.esotericsoftware.kryo.util.IdentityObjectIntMap.push(IdentityObjectIntMap.java:300)
at com.esotericsoftware.kryo.util.IdentityObjectIntMap.put(IdentityObjectIntMap.java:162)
at com.esotericsoftware.kryo.util.MapReferenceResolver.addWrittenObject(MapReferenceResolver.java:41)
at com.esotericsoftware.kryo.Kryo.writeReferenceOrNull(Kryo.java:681)
at com.esotericsoftware.kryo.Kryo.writeObjectOrNull(Kryo.java:616)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:86)

pkamenarsky commented 4 years ago

I'm hitting the same issue, which is most probably related to https://github.com/EsotericSoftware/kryo/issues/382. Unfortunately, this seems to be fixed in kryo > 4.0.0, which is the version used in OTP 1.4.0.

I've tried the workaround described here https://github.com/hail-is/hail/issues/5564 (by calling setReferences(false) in src/main/java/org/opentripplanner/routing/graph/Graph.java), but then the graph serialisation fails due to a stack overflow, which indicates that the object graph contains cycles and reference tracking can not be disabled.

I'm out of ideas currently, save for maybe patching IdentityObjectIntMap to use something bigger than Integer, but I'm not sure whether this won't mess with the used hashing function.

ra0e commented 4 years ago

I have the same issue.

abyrd commented 4 years ago

It does look like this is due to integer overflow in a table expecting less than 2^16 entries. And it does look like a related problem was resolved in https://github.com/EsotericSoftware/kryo/pull/400 and included in release https://github.com/EsotericSoftware/kryo/releases/tag/kryo-parent-4.0.0. But as you say, OTP1 is using Kryo 4.0.2 so shouldn't have this problem.

You are correct that the suggested workaround of turning off entity references will not work in OTP. We will have to dig into this further to understand why EsotericSoftware/kryo#400 does not fix it. I'm looking at the source code of the Kryo version used in OTP1.x, and although it does set the isBigTable boolean field introduced in EsotericSoftware/kryo#400, it looks like this resize method is still using a 32 bit signed int to represent the capacity and new size of the resized table, even when sizes are larger than 2^16. I would really need to work through this to see how it's intended to work.

In the mean time, could you try using OTP2 RC1? OTP2 should have a lot less objects in the graph so may not run up against this MAX_INT limit.

A side note based on code I was just looking at: I was thinking again about calling kryo.reset() to reduce the number of referenced objects, but OTP1's method Graph#save(OutputStream) already calls kryo.writeClassAndObject twice per Graph (once for the edges and vertices, and once for the rest of the Graph fields) with autoReset enabled, so the number of referenced objects is already smaller than it would be with a single call.

abyrd commented 4 years ago

@t2gran my sense is that this has not been a problem in OTP2 due to transit data not being stored as edges and vertices. We may eventually run into this same size constraint though. We should research whether Kryo 5 will eliminate these overflow issues.

SRN1973 commented 4 years ago

Today I tried it with the Open Street Map "tile" covering whole Germany (from Geofabrik) as well as the "free" GTFS datasets for Germany as a whole (see gtfs.de) and the OTP2 RC as recommended but encountered the same issue.

Operating System: Ubuntu 18.04.4 LTS RAM: 1 TB 120 cernels

The graph saving process stops after 4.5 GB are written to file with following error message:

14:30:21.942 INFO (SerializedGraphObject.java:250) Save graph progress: 4.5 GB done 14:30:22.146 ERROR (OTPMain.java:45) An uncaught error occurred inside OTP: java.lang.NegativeArraySizeException: -2147483645 Serialization trace: serviceId (org.opentripplanner.model.Trip) trip (org.opentripplanner.routing.trippattern.TripTimes) tripTimes (org.opentripplanner.model.Timetable) scheduledTimetable (org.opentripplanner.model.TripPattern) tripPatternForId (org.opentripplanner.routing.graph.Graph) graph (org.opentripplanner.routing.graph.SerializedGraphObject) com.esotericsoftware.kryo.KryoException: java.lang.NegativeArraySizeException: -2147483645 Serialization trace: serviceId (org.opentripplanner.model.Trip) trip (org.opentripplanner.routing.trippattern.TripTimes) tripTimes (org.opentripplanner.model.Timetable) scheduledTimetable (org.opentripplanner.model.TripPattern) tripPatternForId (org.opentripplanner.routing.graph.Graph) graph (org.opentripplanner.routing.graph.SerializedGraphObject) at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:101) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObjectOrNull(Kryo.java:629) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:86) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:100) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:40) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:113) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:39) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651) ~[otp-2.0.0-rc1-shaded.jar:1.1] at org.opentripplanner.routing.graph.SerializedGraphObject.save(SerializedGraphObject.java:235) ~[otp-2.0.0-rc1-shaded.jar:1.1] at org.opentripplanner.routing.graph.SerializedGraphObject.save(SerializedGraphObject.java:127) ~[otp-2.0.0-rc1-shaded.jar:1.1] at org.opentripplanner.standalone.OTPMain.startOTPServer(OTPMain.java:128) ~[otp-2.0.0-rc1-shaded.jar:1.1] at org.opentripplanner.standalone.OTPMain.main(OTPMain.java:38) ~[otp-2.0.0-rc1-shaded.jar:1.1] Caused by: java.lang.NegativeArraySizeException: -2147483645 at com.esotericsoftware.kryo.util.IdentityObjectIntMap.resize(IdentityObjectIntMap.java:542) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.util.IdentityObjectIntMap.putStash(IdentityObjectIntMap.java:306) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.util.IdentityObjectIntMap.push(IdentityObjectIntMap.java:300) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.util.IdentityObjectIntMap.put(IdentityObjectIntMap.java:162) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.util.MapReferenceResolver.addWrittenObject(MapReferenceResolver.java:41) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeReferenceOrNull(Kryo.java:681) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObjectOrNull(Kryo.java:616) ~[otp-2.0.0-rc1-shaded.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:86) ~[otp-2.0.0-rc1-shaded.jar:1.1] ... 27 common frames omitted

pkamenarsky commented 4 years ago

Unfortunately, OTP2 RC didn't solve the issue for me either:

17:32:48.797 ERROR (OTPMain.java:45) An uncaught error occurred inside OTP: java.lang.NegativeArraySizeException: -2147483645
Serialization trace:
serviceDatesByServiceId (org.opentripplanner.model.calendar.CalendarServiceData)
services (org.opentripplanner.routing.graph.Graph)
graph (org.opentripplanner.routing.graph.SerializedGraphObject)
com.esotericsoftware.kryo.KryoException: java.lang.NegativeArraySizeException: -2147483645

tim1e1ing commented 3 years ago

Problem still existing in OTP 2.1.0-Snapshot

ERROR (OTPMain.java:46) An uncaught error occurred inside OTP: java.lang.NegativeArraySizeException: -2147483645 Serialization trace: edges (org.opentripplanner.model.SimpleTransfer) transfersByStop (org.opentripplanner.routing.graph.Graph) graph (org.opentripplanner.routing.graph.SerializedGraphObject) com.esotericsoftware.kryo.KryoException: java.lang.NegativeArraySizeException: -2147483645 Serialization trace: edges (org.opentripplanner.model.SimpleTransfer) transfersByStop (org.opentripplanner.routing.graph.Graph) graph (org.opentripplanner.routing.graph.SerializedGraphObject) at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:101) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651) ~[otp2.1.0.jar:1.1] at de.javakaffee.kryoserializers.guava.MultimapSerializerBase.writeMultimap(MultimapSerializerBase.java:22) ~[otp2.1.0.jar:1.1] at de.javakaffee.kryoserializers.guava.HashMultimapSerializer.write(HashMultimapSerializer.java:26) ~[otp2.1.0.jar:1.1] at de.javakaffee.kryoserializers.guava.HashMultimapSerializer.write(HashMultimapSerializer.java:14) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651) ~[otp2.1.0.jar:1.1] at org.opentripplanner.routing.graph.SerializedGraphObject.save(SerializedGraphObject.java:235) ~[otp2.1.0.jar:1.1] at org.opentripplanner.routing.graph.SerializedGraphObject.save(SerializedGraphObject.java:127) ~[otp2.1.0.jar:1.1] at org.opentripplanner.standalone.OTPMain.startOTPServer(OTPMain.java:132) ~[otp2.1.0.jar:1.1] at org.opentripplanner.standalone.OTPMain.main(OTPMain.java:39) ~[otp2.1.0.jar:1.1] Caused by: java.lang.NegativeArraySizeException: -2147483645 at com.esotericsoftware.kryo.util.IdentityObjectIntMap.resize(IdentityObjectIntMap.java:542) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.util.IdentityObjectIntMap.putStash(IdentityObjectIntMap.java:306) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.util.IdentityObjectIntMap.push(IdentityObjectIntMap.java:300) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.util.IdentityObjectIntMap.put(IdentityObjectIntMap.java:162) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.util.MapReferenceResolver.addWrittenObject(MapReferenceResolver.java:41) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeReferenceOrNull(Kryo.java:681) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:570) ~[otp2.1.0.jar:1.1] at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79) ~[otp2.1.0.jar:1.1] ... 16 common frames omitted

SRN1973 commented 3 years ago

Maybe this helps (however i have not tested it with OTP yet)... I encountered a similar error with the R5 routing engine. From the programmers I got following hint which worked for me as a workaround (and as I am not interested in car routing the described downside of the workaround is not a problem for me):

"This is definitely an upstream bug in R5, and it has to do with turn restrictions. If you don't care about turn restrictions (which really only matter for driving, and to a lesser extent biking, but you can always walk your bike), you can use osmconvert with the --drop-relations option to remove them from your PBF. Then R5 should build the network, albeit without information on turn restrictions."

tim1e1ing commented 3 years ago

Error accures while adding the GTFS layer to the streetgraph. The latter was created before and saved without error.

Following your linked hint osmconvert in.pbf --drop-relations -o=out.pbf is not aworkaround.

17:03:33.966 INFO (SerializedGraphObject.java:205) Reading graph from './streetGraph.obj' WARNING: An illegal reflective access operation has occurred WARNING: Illegal reflective access by com.esotericsoftware.kryo.util.UnsafeUtil (file:/home/holthaus/otp2/otp2.1.0.jar) to constructor java.nio.DirectByteBuffer(long,int,java.lang.Object) WARNING: Please consider reporting this to the maintainers of com.esotericsoftware.kryo.util.UnsafeUtil WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations WARNING: All illegal access operations will be denied in a future release 17:06:26.776 INFO (Graph.java:643) Graph version: MavenVersion(2, 1, 0, SNAPSHOT, 04af5a1a2f4fc7c2c3533fc54f7d99ab08c58cf9) 17:06:26.777 INFO (Graph.java:644) OTP version: MavenVersion(2, 1, 0, SNAPSHOT, 04af5a1a2f4fc7c2c3533fc54f7d99ab08c58cf9)

jannefleischer commented 3 years ago

just checked with 1.5.0 - problem still exists, but has now a different traceback.

opentripplanner_de | 12:26:17.024 INFO (DirectTransferGenerator.java:100) Done connecting stops to one another. Created a total of 20519555 transfers from 889866 stops.
opentripplanner_de | 12:26:17.118 INFO (Graph.java:963) Summary (number of each type of annotation):
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     StopNotLinkedForTransfers - 6169
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     StopLinkedTooFar - 8995
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     LevelAmbiguous - 18489
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     StopUnlinked - 5021
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     HopSpeedFast - 478814
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     HopSpeedSlow - 52654
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     HopZeroTime - 1387278
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     BogusShapeGeometryCaught - 3749
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     NoFutureDates - 3
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     GraphConnectivity - 48800
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     Graphwide - 1
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     TripDegenerate - 857
opentripplanner_de | 12:26:17.168 INFO (Graph.java:969)     RepeatedStops - 18564
opentripplanner_de | 12:26:22.024 INFO (Graph.java:814) Main graph size: |V|=36803365 |E|=102677533
opentripplanner_de | 12:26:22.024 INFO (Graph.java:815) Writing graph /var/otp/graphs/germany/Graph.obj ...
opentripplanner_de | Exception in thread "main" java.lang.OutOfMemoryError: GC overhead limit exceeded
opentripplanner_de |    at java.util.AbstractList.iterator(AbstractList.java:288)
opentripplanner_de |    at org.opentripplanner.routing.graph.Graph.addEdgesToIndex(Graph.java:599)
opentripplanner_de |    at org.opentripplanner.routing.graph.Graph.rebuildVertexAndEdgeIndices(Graph.java:630)
opentripplanner_de |    at org.opentripplanner.routing.graph.Graph.save(Graph.java:838)
opentripplanner_de |    at org.opentripplanner.routing.graph.Graph.save(Graph.java:817)
opentripplanner_de |    at org.opentripplanner.graph_builder.GraphBuilder.run(GraphBuilder.java:144)
opentripplanner_de |    at org.opentripplanner.standalone.OTPMain.run(OTPMain.java:103)
opentripplanner_de |    at org.opentripplanner.standalone.OTPMain.main(OTPMain.java:73)

With JAVA_OPTIONS=-Xmx80G

MichHeilig commented 3 years ago

With both versions 1.5.0 and 2.0.0, I could reproduce the error using the same data (in newer versions) and JAVA_OPTIONS=-Xmx80G. However, when skipping the urban GTFS data file from gtfs.de, the error does not occur. Hence, I suppose the error is rather caused by corrupted GTFS files than by OTP.

OS: Windows Server 2019 Standard Intel Xeon E-2288G 3.70 GHz 128 GB RAM

I then tried to use the German wide GTFS file from Delphi (https://www.delfi.de/de/leistungen-produkte/daten-dienste/), which raises another error:

ERROR (OTPMain.java:46) An uncaught error occurred inside OTP: Expected type 0, but got 2 java.lang.IllegalArgumentException: Expected type 0, but got 2 at org.opentripplanner.gtfs.mapping.StopMapper.doMap(StopMapper.java:32) ~[otp-2.0.0-shaded.jar:1.1] at java.base/java.util.HashMap.computeIfAbsent(HashMap.java:1133) ~[na:na] at org.opentripplanner.gtfs.mapping.StopMapper.map(StopMapper.java:25) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.gtfs.mapping.StopTimeMapper.doMap(StopTimeMapper.java:38) ~[otp-2.0.0-shaded.jar:1.1] at java.base/java.util.HashMap.computeIfAbsent(HashMap.java:1133) ~[na:na] at org.opentripplanner.gtfs.mapping.StopTimeMapper.map(StopTimeMapper.java:31) ~[otp-2.0.0-shaded.jar:1.1] at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195) ~[na:na] at java.base/java.util.HashMap$ValueSpliterator.forEachRemaining(HashMap.java:1672) ~[na:na] at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[na:na] at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[na:na] at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[na:na] at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[na:na] at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[na:na] at org.opentripplanner.util.MapUtils.mapToList(MapUtils.java:82) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.gtfs.mapping.StopTimeMapper.map(StopTimeMapper.java:26) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.gtfs.mapping.GTFSToOtpTransitServiceMapper.map(GTFSToOtpTransitServiceMapper.java:104) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.gtfs.mapping.GTFSToOtpTransitServiceMapper.mapGtfsDaoToInternalTransitServiceBuilder(GTFSToOtpTransitServiceMapper.java:83) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.graph_builder.module.GtfsModule.buildGraph(GtfsModule.java:129) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.graph_builder.GraphBuilder.run(GraphBuilder.java:80) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.standalone.OTPMain.startOTPServer(OTPMain.java:123) ~[otp-2.0.0-shaded.jar:1.1] at org.opentripplanner.standalone.OTPMain.main(OTPMain.java:39) ~[otp-2.0.0-shaded.jar:1.1]

jannefleischer commented 2 years ago

The Issue @MichHeilig has mentioned is related to the broken Delfi-dataset which can be manually "fixed" (I did it here: https://gitlab.com/ils-research/delfi-dataset-fixer/-/blob/master/CheckDelfiDataset.ipynb).

Nevertheless even with a "fixed" dataset (and 95GB of RAM allocation) otp2 still shuts down with this Trace:

13:33:18.545 INFO (SerializedGraphObject.java:173) Save graph progress: 3.9 GB done
opentripplanner2  | 13:33:18.835 ERROR (OTPMain.java:59) An uncaught error occurred inside OTP: java.lang.NegativeArraySizeException: -2147483645
opentripplanner2  | Serialization trace:
opentripplanner2  | serviceDatesByServiceId (org.opentripplanner.model.calendar.CalendarServiceData)
opentripplanner2  | services (org.opentripplanner.routing.graph.Graph)
opentripplanner2  | graph (org.opentripplanner.routing.graph.SerializedGraphObject)
opentripplanner2  | com.esotericsoftware.kryo.KryoException: java.lang.NegativeArraySizeException: -2147483645
opentripplanner2  | Serialization trace:
opentripplanner2  | serviceDatesByServiceId (org.opentripplanner.model.calendar.CalendarServiceData)
opentripplanner2  | services (org.opentripplanner.routing.graph.Graph)
opentripplanner2  | graph (org.opentripplanner.routing.graph.SerializedGraphObject)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:101)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:113)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:39)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:508)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651)
opentripplanner2  |     at org.opentripplanner.routing.graph.SerializedGraphObject.save(SerializedGraphObject.java:158)
opentripplanner2  |     at org.opentripplanner.routing.graph.SerializedGraphObject.save(SerializedGraphObject.java:112)
opentripplanner2  |     at org.opentripplanner.standalone.OTPMain.startOTPServer(OTPMain.java:145)
opentripplanner2  |     at org.opentripplanner.standalone.OTPMain.main(OTPMain.java:52)
opentripplanner2  | Caused by: java.lang.NegativeArraySizeException: -2147483645
opentripplanner2  |     at com.esotericsoftware.kryo.util.IdentityObjectIntMap.resize(IdentityObjectIntMap.java:542)
opentripplanner2  |     at com.esotericsoftware.kryo.util.IdentityObjectIntMap.putStash(IdentityObjectIntMap.java:306)
opentripplanner2  |     at com.esotericsoftware.kryo.util.IdentityObjectIntMap.push(IdentityObjectIntMap.java:300)
opentripplanner2  |     at com.esotericsoftware.kryo.util.IdentityObjectIntMap.put(IdentityObjectIntMap.java:162)
opentripplanner2  |     at com.esotericsoftware.kryo.util.MapReferenceResolver.addWrittenObject(MapReferenceResolver.java:41)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeReferenceOrNull(Kryo.java:681)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:646)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:100)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:40)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651)
opentripplanner2  |     at de.javakaffee.kryoserializers.UnmodifiableCollectionsSerializer.write(UnmodifiableCollectionsSerializer.java:81)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:651)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:113)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:39)
opentripplanner2  |     at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:575)
opentripplanner2  |     at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:79)
opentripplanner2  |     ... 15 common frames omitted
opentripplanner2  | 13:33:18.838 INFO (OtpStartupInfo.java:47) OTP SHUTTING DOWN (version: 2.1.0, ser.ver.id: 2.1.0, commit: 7d66960dee981172685d912bdaad396d0cb951f3, branch: sign-central)

leonardehrenfried commented 2 years ago

Does anyone know if kryo 5 is improving this situation? If it is, then using the latest dev-2.x commit would be worth a try as we recently moved to kryo 5.

jannefleischer commented 2 years ago

If anyone tells my how to use the latest dev-2.x, I could give it a try. Are there any nightlies that I can just use in my docker stack?

leonardehrenfried commented 2 years ago

If you trust a stranger on the internet, you can use my unofficial mirror of the GitHub Packages: https://otp.leonard.io/snapshots/2.2-SNAPSHOT/

It contains the jars built by the CI pipeline.

leonardehrenfried commented 2 years ago

@tim1e1ing Are you also trying to load the Germany-wide Delfi GTFS feed?

tim1e1ing commented 2 years ago

If you trust a stranger on the internet, you can use my unofficial mirror of the GitHub Packages: https://otp.leonard.io/snapshots/2.2-SNAPSHOT/

It contains the jars built by the CI pipeline.

latest snapshot works like a charm.

Issue is closeable.

jannefleischer commented 2 years ago

@leonardehrenfried Hi, what jdk-version should I use for the SNAPSHOTS?

openjdk:11.0.10 istn't the right one, it seems.


opentripplanner2  | Error: LinkageError occurred while loading main class org.opentripplanner.standalone.OTPMain
opentripplanner2  |     java.lang.UnsupportedClassVersionError: org/opentripplanner/standalone/OTPMain has been compiled by a more recent version of the Java Runtime (class file version 61.0), this version of the Java Runtime only recognizes class file versions up to 55.0

jannefleischer commented 2 years ago

Ah, found it: https://javaalmanac.io/bytecode/versions/

leonardehrenfried commented 2 years ago

You need Java 17.

tim1e1ing commented 2 years ago

@tim1e1ing Are you also trying to load the Germany-wide Delfi GTFS feed?

Yes. for https://mapdiscover.org/. worked well. @leonardehrenfried maybe you are interested in participating :)

Until now we had two different backends. Now maintaining will be much easier.

funfact: Next month we planned to solve the problem inhouse. Nice to see, that the same approach is already included.

tim1e1ing commented 2 years ago

Ah, found it: https://javaalmanac.io/bytecode/versions/

Terminal gives also hint to 61.

jannefleischer commented 2 years ago

I can report: It is working with otp-2.2.0-20220510.170140-175-shaded.jar and my "fixed" Delfi-Dataset.

It took around 90Gig of RAM and 54minutes on Ryzen 9 3900 (with NVM) plus around 7minutes to launch until service is provided:

opentripplanner2  | 16:24:59.754 INFO (OtpStartupInfo.java:40) OTP STARTING UP (version: 2.2.0-SNAPSHOT, ser.ver.id: 23, commit: c7293457abfa15daed812d6b214c4a9a4238b27f, branch: dev-2.x)
opentripplanner2  | 16:24:59.755 INFO (OtpStartupInfo.java:46)
opentripplanner2  |   ___                 _____     _       ____  _
opentripplanner2  |  / _ \ _ __   ___ _ _|_   _| __(_)_ __ |  _ \| | __ _ _ __  _ __   ___ _ __
opentripplanner2  | | | | | '_ \ / _ \ '_ \| || '__| | '_ \| |_) | |/ _` | '_ \| '_ \ / _ \ '__|
opentripplanner2  | | |_| | |_) |  __/ | | | || |  | | |_) |  __/| | (_| | | | | | | |  __/ |
opentripplanner2  |  \___/| .__/ \___|_| |_|_||_|  |_| .__/|_|   |_|\__,_|_| |_|_| |_|\___|_|
opentripplanner2  |       |_|                        |_|
opentripplanner2  | Version:    2.2.0-SNAPSHOT
opentripplanner2  | Ser.ver.id: 23
opentripplanner2  | Commit:     c7293457abfa15daed812d6b214c4a9a4238b27f
opentripplanner2  | Branch:     dev-2.x
opentripplanner2  | Build:      2022-05-10T17:02:15+0000
opentripplanner2  |
opentripplanner2  | 16:24:59.755 INFO (OTPMain.java:103) Searching for configuration and input files in /var/otp/graphs/de
opentripplanner2  | 16:24:59.822 INFO (ConfigLoader.java:224) File '/var/otp/graphs/de/otp-config.json' is not present. Using default configuration.
opentripplanner2  | 16:24:59.825 INFO (ConfigLoader.java:224) File '/var/otp/graphs/de/build-config.json' is not present. Using default configuration.
opentripplanner2  | 16:24:59.838 INFO (ConfigLoader.java:224) File '/var/otp/graphs/de/router-config.json' is not present. Using default configuration.
opentripplanner2  | 16:24:59.857 INFO (OTPFeature.java:59) Features turned on:
opentripplanner2  |     APIBikeRental
opentripplanner2  |     APIServerInfo
opentripplanner2  |     APIGraphInspectorTile
opentripplanner2  |     APIUpdaterStatus
opentripplanner2  |     OptimizeTransfers
opentripplanner2  |     TransferConstraints
opentripplanner2  |     FloatingBike
opentripplanner2  | 16:24:59.857 INFO (OTPFeature.java:60) Features turned off:
opentripplanner2  |     MinimumTransferTimeIsDefinitive
opentripplanner2  |     ParallelRouting
opentripplanner2  |     ActuatorAPI
opentripplanner2  |     DataOverlay
opentripplanner2  |     FlexRouting
opentripplanner2  |     GoogleCloudStorage
opentripplanner2  |     ReportApi
opentripplanner2  |     SandboxAPIGeocoder
opentripplanner2  |     SandboxAPILegacyGraphQLApi
opentripplanner2  |     SandboxAPIMapboxVectorTilesApi
opentripplanner2  |     SandboxAPITransmodelApi
opentripplanner2  |     SandboxAPIParkAndRideApi
opentripplanner2  |     TransferAnalyzer
opentripplanner2  |     VehicleToStopHeuristics
opentripplanner2  | 16:24:59.867 INFO (GraphBuilderDataSources.java:116) Data source location(s): /var/otp/graphs/de
opentripplanner2  | 16:24:59.867 INFO (GraphBuilderDataSources.java:119) Existing files expected to be read or written:
opentripplanner2  | 16:24:59.869 INFO (GraphBuilderDataSources.java:122) - 🌐 graph.obj  /var/otp/graphs/de  2022-05-18 16:15:16  6.6 GB
opentripplanner2  | 16:24:59.870 INFO (GraphBuilderDataSources.java:127) Files excluded due to command line switches or unknown type:
opentripplanner2  | 16:24:59.870 INFO (GraphBuilderDataSources.java:130) - 🌍 germany-latest.osm.pbf  /var/otp/graphs/de  2022-05-11 11:13:09  3.9 GB
opentripplanner2  | 16:24:59.870 INFO (GraphBuilderDataSources.java:130) - 🚌 20220509_fahrplaene_gesamtdeutschland_gtfs_fix1.zip  /var/otp/graphs/de  2022-05-11 11:12:53  357.8 MB
opentripplanner2  | 16:24:59.871 INFO (SerializedGraphObject.java:127) Reading graph from '/var/otp/graphs/de/graph.obj'
opentripplanner2  | 16:28:22.376 INFO (SerializedGraphObject.java:140) Graph read. |V|=21587691 |E|=54694276
opentripplanner2  | 16:28:22.376 INFO (OTPConfiguration.java:83) Using the graph embedded JSON build configuration.
opentripplanner2  | 16:28:22.376 INFO (OTPConfiguration.java:87) Using the graph embedded JSON router configuration.
opentripplanner2  | 16:28:22.376 INFO (Graph.java:560) Index graph...
opentripplanner2  | 16:28:23.717 INFO (null:-1) dataFileCache open start
opentripplanner2  | 16:30:31.849 INFO (StreetVertexIndex.java:405) Index steet graph progress tracking started.
opentripplanner2  | 16:30:36.850 INFO (StreetVertexIndex.java:434) Index steet graph progress: 1,784,000 of 21,587,691 ( 8%)
opentripplanner2  | 16:30:45.757 INFO (StreetVertexIndex.java:434) Index steet graph progress: 3,111,000 of 21,587,691 (14%)
opentripplanner2  | 16:30:50.759 INFO (StreetVertexIndex.java:434) Index steet graph progress: 4,721,000 of 21,587,691 (21%)
opentripplanner2  | 16:30:55.760 INFO (StreetVertexIndex.java:434) Index steet graph progress: 6,445,000 of 21,587,691 (29%)
opentripplanner2  | 16:31:00.762 INFO (StreetVertexIndex.java:434) Index steet graph progress: 8,159,000 of 21,587,691 (37%)
opentripplanner2  | 16:31:11.334 INFO (StreetVertexIndex.java:434) Index steet graph progress: 9,306,000 of 21,587,691 (43%)
opentripplanner2  | 16:31:16.590 INFO (StreetVertexIndex.java:434) Index steet graph progress: 9,661,000 of 21,587,691 (44%)
opentripplanner2  | 16:31:21.590 INFO (StreetVertexIndex.java:434) Index steet graph progress: 11,092,000 of 21,587,691 (51%)
opentripplanner2  | 16:31:26.592 INFO (StreetVertexIndex.java:434) Index steet graph progress: 12,453,000 of 21,587,691 (57%)
opentripplanner2  | 16:31:31.593 INFO (StreetVertexIndex.java:434) Index steet graph progress: 13,754,000 of 21,587,691 (63%)
opentripplanner2  | 16:31:36.595 INFO (StreetVertexIndex.java:434) Index steet graph progress: 15,238,000 of 21,587,691 (70%)
opentripplanner2  | 16:31:42.185 INFO (StreetVertexIndex.java:434) Index steet graph progress: 15,610,000 of 21,587,691 (72%)
opentripplanner2  | 16:31:54.056 INFO (StreetVertexIndex.java:434) Index steet graph progress: 16,994,000 of 21,587,691 (78%)
opentripplanner2  | 16:31:59.058 INFO (StreetVertexIndex.java:434) Index steet graph progress: 18,619,000 of 21,587,691 (86%)
opentripplanner2  | 16:32:04.845 INFO (StreetVertexIndex.java:434) Index steet graph progress: 19,608,000 of 21,587,691 (90%)
opentripplanner2  | 16:32:09.846 INFO (StreetVertexIndex.java:434) Index steet graph progress: 21,223,000 of 21,587,691 (98%)
opentripplanner2  | 16:32:10.946 INFO (StreetVertexIndex.java:436) Index steet graph progress tracking complete. 21,587,691 done in 1m39s (217,842 per second).
opentripplanner2  | 16:32:11.092 INFO (GraphIndex.java:64) GraphIndex init...
opentripplanner2  | 16:32:15.546 INFO (GraphIndex.java:135) GraphIndex init complete.
opentripplanner2  | 16:32:15.546 INFO (Graph.java:569) Index graph complete.
opentripplanner2  | 16:32:15.555 INFO (Router.java:81) Incoming requests will not be logged.
opentripplanner2  | 16:32:15.555 INFO (Router.java:86) Creating transit layer for Raptor routing.
opentripplanner2  | 16:32:15.556 INFO (TransitLayerMapper.java:74) Mapping transitLayer from Graph...
opentripplanner2  | 16:33:43.692 INFO (TransitLayerMapper.java:100) Mapping complete.
opentripplanner2  | 16:33:43.704 INFO (GraphUpdaterManager.java:211) OTP UPDATERS INITIALIZED - OTP is ready for routing!
opentripplanner2  | 16:33:43.783 INFO (Router.java:107) Computed ellipsoid/geoid offset at (-10.211779499999999, 4.900599) as 10.140169560817641
opentripplanner2  | 16:33:43.786 INFO (OTPServer.java:26) Wiring up and configuring server.
opentripplanner2  | 16:33:43.832 INFO (GrizzlyServer.java:50) Starting OTP Grizzly server on ports 8080 (HTTP) and 8081 (HTTPS) of interface 0.0.0.0
opentripplanner2  | 16:33:43.832 INFO (GrizzlyServer.java:56) OTP server base directory is: [/var/otp/graphs/de]
opentripplanner2  | 16:33:43.845 INFO (GrizzlyServer.java:166) Java reports that this machine has 24 available processors.
opentripplanner2  | 16:33:43.846 INFO (GrizzlyServer.java:171) Based on configuration, forced max thread pool size to 6 threads.
opentripplanner2  | 16:33:43.846 INFO (GrizzlyServer.java:177) Maximum HTTP handler thread pool size will be 6 threads.
opentripplanner2  | 16:33:44.303 WARN (PropertiesHelper.java:309) There is no way how to transform value "true" [java.lang.Boolean] to type [java.lang.String].
opentripplanner2  | 16:33:44.345 INFO (NetworkListener.java:790) Started listener bound to [0.0.0.0:8080]
opentripplanner2  | 16:33:44.639 INFO (NetworkListener.java:790) Started listener bound to [0.0.0.0:8081]
opentripplanner2  | 16:33:44.640 INFO (HttpServer.java:278) [HttpServer] Started.
opentripplanner2  | 16:33:44.640 INFO (GrizzlyServer.java:145) Grizzly server running.

tim1e1ing commented 2 years ago

I can report: It is working with otp-2.2.0-20220510.170140-175-shaded.jar and my "fixed" Delfi-Dataset.

It took around 90Gig of RAM and 54minutes on Ryzen 9 3900 (with NVM) plus around 7minutes to launch until service is provided:

opentripplanner2  | 16:24:59.754 INFO (OtpStartupInfo.java:40) OTP STARTING UP (version: 2.2.0-SNAPSHOT, ser.ver.id: 23, commit: c7293457abfa15daed812d6b214c4a9a4238b27f, branch: dev-2.x)
opentripplanner2  | 16:24:59.755 INFO (OtpStartupInfo.java:46)
opentripplanner2  |   ___                 _____     _       ____  _
opentripplanner2  |  / _ \ _ __   ___ _ _|_   _| __(_)_ __ |  _ \| | __ _ _ __  _ __   ___ _ __
opentripplanner2  | | | | | '_ \ / _ \ '_ \| || '__| | '_ \| |_) | |/ _` | '_ \| '_ \ / _ \ '__|
opentripplanner2  | | |_| | |_) |  __/ | | | || |  | | |_) |  __/| | (_| | | | | | | |  __/ |
opentripplanner2  |  \___/| .__/ \___|_| |_|_||_|  |_| .__/|_|   |_|\__,_|_| |_|_| |_|\___|_|
opentripplanner2  |       |_|                        |_|
opentripplanner2  | Version:    2.2.0-SNAPSHOT
opentripplanner2  | Ser.ver.id: 23
opentripplanner2  | Commit:     c7293457abfa15daed812d6b214c4a9a4238b27f
opentripplanner2  | Branch:     dev-2.x
opentripplanner2  | Build:      2022-05-10T17:02:15+0000
opentripplanner2  |
opentripplanner2  | 16:24:59.755 INFO (OTPMain.java:103) Searching for configuration and input files in /var/otp/graphs/de
opentripplanner2  | 16:24:59.822 INFO (ConfigLoader.java:224) File '/var/otp/graphs/de/otp-config.json' is not present. Using default configuration.
opentripplanner2  | 16:24:59.825 INFO (ConfigLoader.java:224) File '/var/otp/graphs/de/build-config.json' is not present. Using default configuration.
opentripplanner2  | 16:24:59.838 INFO (ConfigLoader.java:224) File '/var/otp/graphs/de/router-config.json' is not present. Using default configuration.
opentripplanner2  | 16:24:59.857 INFO (OTPFeature.java:59) Features turned on:
opentripplanner2  |     APIBikeRental
opentripplanner2  |     APIServerInfo
opentripplanner2  |     APIGraphInspectorTile
opentripplanner2  |     APIUpdaterStatus
opentripplanner2  |     OptimizeTransfers
opentripplanner2  |     TransferConstraints
opentripplanner2  |     FloatingBike
opentripplanner2  | 16:24:59.857 INFO (OTPFeature.java:60) Features turned off:
opentripplanner2  |     MinimumTransferTimeIsDefinitive
opentripplanner2  |     ParallelRouting
opentripplanner2  |     ActuatorAPI
opentripplanner2  |     DataOverlay
opentripplanner2  |     FlexRouting
opentripplanner2  |     GoogleCloudStorage
opentripplanner2  |     ReportApi
opentripplanner2  |     SandboxAPIGeocoder
opentripplanner2  |     SandboxAPILegacyGraphQLApi
opentripplanner2  |     SandboxAPIMapboxVectorTilesApi
opentripplanner2  |     SandboxAPITransmodelApi
opentripplanner2  |     SandboxAPIParkAndRideApi
opentripplanner2  |     TransferAnalyzer
opentripplanner2  |     VehicleToStopHeuristics
opentripplanner2  | 16:24:59.867 INFO (GraphBuilderDataSources.java:116) Data source location(s): /var/otp/graphs/de
opentripplanner2  | 16:24:59.867 INFO (GraphBuilderDataSources.java:119) Existing files expected to be read or written:
opentripplanner2  | 16:24:59.869 INFO (GraphBuilderDataSources.java:122) - 🌐 graph.obj  /var/otp/graphs/de  2022-05-18 16:15:16  6.6 GB
opentripplanner2  | 16:24:59.870 INFO (GraphBuilderDataSources.java:127) Files excluded due to command line switches or unknown type:
opentripplanner2  | 16:24:59.870 INFO (GraphBuilderDataSources.java:130) - 🌍 germany-latest.osm.pbf  /var/otp/graphs/de  2022-05-11 11:13:09  3.9 GB
opentripplanner2  | 16:24:59.870 INFO (GraphBuilderDataSources.java:130) - 🚌 20220509_fahrplaene_gesamtdeutschland_gtfs_fix1.zip  /var/otp/graphs/de  2022-05-11 11:12:53  357.8 MB
opentripplanner2  | 16:24:59.871 INFO (SerializedGraphObject.java:127) Reading graph from '/var/otp/graphs/de/graph.obj'
opentripplanner2  | 16:28:22.376 INFO (SerializedGraphObject.java:140) Graph read. |V|=21587691 |E|=54694276
opentripplanner2  | 16:28:22.376 INFO (OTPConfiguration.java:83) Using the graph embedded JSON build configuration.
opentripplanner2  | 16:28:22.376 INFO (OTPConfiguration.java:87) Using the graph embedded JSON router configuration.
opentripplanner2  | 16:28:22.376 INFO (Graph.java:560) Index graph...
opentripplanner2  | 16:28:23.717 INFO (null:-1) dataFileCache open start
opentripplanner2  | 16:30:31.849 INFO (StreetVertexIndex.java:405) Index steet graph progress tracking started.
opentripplanner2  | 16:30:36.850 INFO (StreetVertexIndex.java:434) Index steet graph progress: 1,784,000 of 21,587,691 ( 8%)
opentripplanner2  | 16:30:45.757 INFO (StreetVertexIndex.java:434) Index steet graph progress: 3,111,000 of 21,587,691 (14%)
opentripplanner2  | 16:30:50.759 INFO (StreetVertexIndex.java:434) Index steet graph progress: 4,721,000 of 21,587,691 (21%)
opentripplanner2  | 16:30:55.760 INFO (StreetVertexIndex.java:434) Index steet graph progress: 6,445,000 of 21,587,691 (29%)
opentripplanner2  | 16:31:00.762 INFO (StreetVertexIndex.java:434) Index steet graph progress: 8,159,000 of 21,587,691 (37%)
opentripplanner2  | 16:31:11.334 INFO (StreetVertexIndex.java:434) Index steet graph progress: 9,306,000 of 21,587,691 (43%)
opentripplanner2  | 16:31:16.590 INFO (StreetVertexIndex.java:434) Index steet graph progress: 9,661,000 of 21,587,691 (44%)
opentripplanner2  | 16:31:21.590 INFO (StreetVertexIndex.java:434) Index steet graph progress: 11,092,000 of 21,587,691 (51%)
opentripplanner2  | 16:31:26.592 INFO (StreetVertexIndex.java:434) Index steet graph progress: 12,453,000 of 21,587,691 (57%)
opentripplanner2  | 16:31:31.593 INFO (StreetVertexIndex.java:434) Index steet graph progress: 13,754,000 of 21,587,691 (63%)
opentripplanner2  | 16:31:36.595 INFO (StreetVertexIndex.java:434) Index steet graph progress: 15,238,000 of 21,587,691 (70%)
opentripplanner2  | 16:31:42.185 INFO (StreetVertexIndex.java:434) Index steet graph progress: 15,610,000 of 21,587,691 (72%)
opentripplanner2  | 16:31:54.056 INFO (StreetVertexIndex.java:434) Index steet graph progress: 16,994,000 of 21,587,691 (78%)
opentripplanner2  | 16:31:59.058 INFO (StreetVertexIndex.java:434) Index steet graph progress: 18,619,000 of 21,587,691 (86%)
opentripplanner2  | 16:32:04.845 INFO (StreetVertexIndex.java:434) Index steet graph progress: 19,608,000 of 21,587,691 (90%)
opentripplanner2  | 16:32:09.846 INFO (StreetVertexIndex.java:434) Index steet graph progress: 21,223,000 of 21,587,691 (98%)
opentripplanner2  | 16:32:10.946 INFO (StreetVertexIndex.java:436) Index steet graph progress tracking complete. 21,587,691 done in 1m39s (217,842 per second).
opentripplanner2  | 16:32:11.092 INFO (GraphIndex.java:64) GraphIndex init...
opentripplanner2  | 16:32:15.546 INFO (GraphIndex.java:135) GraphIndex init complete.
opentripplanner2  | 16:32:15.546 INFO (Graph.java:569) Index graph complete.
opentripplanner2  | 16:32:15.555 INFO (Router.java:81) Incoming requests will not be logged.
opentripplanner2  | 16:32:15.555 INFO (Router.java:86) Creating transit layer for Raptor routing.
opentripplanner2  | 16:32:15.556 INFO (TransitLayerMapper.java:74) Mapping transitLayer from Graph...
opentripplanner2  | 16:33:43.692 INFO (TransitLayerMapper.java:100) Mapping complete.
opentripplanner2  | 16:33:43.704 INFO (GraphUpdaterManager.java:211) OTP UPDATERS INITIALIZED - OTP is ready for routing!
opentripplanner2  | 16:33:43.783 INFO (Router.java:107) Computed ellipsoid/geoid offset at (-10.211779499999999, 4.900599) as 10.140169560817641
opentripplanner2  | 16:33:43.786 INFO (OTPServer.java:26) Wiring up and configuring server.
opentripplanner2  | 16:33:43.832 INFO (GrizzlyServer.java:50) Starting OTP Grizzly server on ports 8080 (HTTP) and 8081 (HTTPS) of interface 0.0.0.0
opentripplanner2  | 16:33:43.832 INFO (GrizzlyServer.java:56) OTP server base directory is: [/var/otp/graphs/de]
opentripplanner2  | 16:33:43.845 INFO (GrizzlyServer.java:166) Java reports that this machine has 24 available processors.
opentripplanner2  | 16:33:43.846 INFO (GrizzlyServer.java:171) Based on configuration, forced max thread pool size to 6 threads.
opentripplanner2  | 16:33:43.846 INFO (GrizzlyServer.java:177) Maximum HTTP handler thread pool size will be 6 threads.
opentripplanner2  | 16:33:44.303 WARN (PropertiesHelper.java:309) There is no way how to transform value "true" [java.lang.Boolean] to type [java.lang.String].
opentripplanner2  | 16:33:44.345 INFO (NetworkListener.java:790) Started listener bound to [0.0.0.0:8080]
opentripplanner2  | 16:33:44.639 INFO (NetworkListener.java:790) Started listener bound to [0.0.0.0:8081]
opentripplanner2  | 16:33:44.640 INFO (HttpServer.java:278) [HttpServer] Started.
opentripplanner2  | 16:33:44.640 INFO (GrizzlyServer.java:145) Grizzly server running.

do you read this feed?

leonardehrenfried commented 2 years ago

@jannefleischer That's great to hear! 🍾🍾 Does it take 90GB of RAM during graph build or at runtime?

@tim1e1ing If you have the know-how to modify OTP it really pays off to become a contributor. There are video calls twice a week where you can ask questions and developers coordinate testing and code review tasks: https://github.com/opentripplanner/OpenTripPlanner/blob/dev-2.x/CONTRIBUTING.md#primary-channels-of-communication

tim1e1ing commented 2 years ago

@jannefleischer That's great to hear! 🍾🍾 Does it take 90GB of RAM during graph build or at runtime?

@tim1e1ing If you have the know-how to modify OTP I really pays off to become a contributor. There are video calls twice a week where you can ask questions and developers coordinate testing a code review tasks: https://github.com/opentripplanner/OpenTripPlanner/blob/dev-2.x/CONTRIBUTING.md#primary-channels-of-communication

90GB is the max use but it's used until the end.

I would love to have the time to contribute in a large scale. But my research takes more or less all my freetime. And the rest of my time goes to mapdiscover and other stuff.

leonardehrenfried commented 2 years ago

And how much memory does it consume when you save the graph and then start it up as a second step?

tim1e1ing commented 2 years ago

And how much memory does it consume when you save the graph and then start it up as a second step?

I skipped starting on that server. Only build flag was set. Will report how much memory serving takes tomorrow.

tim1e1ing commented 2 years ago

IT'S working with 32Gb of ram. But it's very slow

jannefleischer commented 2 years ago

@leonardehrenfried The memory consumption is almost the same either by directly serving after built, or if I start it later without building. Maybe 5 gb more if built and served in same time (but I can only recall from remembering, haven't actually noted something down then...)

leonardehrenfried commented 2 years ago

Ok, thanks for those numbers.

What is the speed like?

jannefleischer commented 2 years ago

I outsourced that kind of question to a collegue. Once I know I'll post here.

This can be closed, I think. (and marked as "nofix" for OTP1.4?)

leonardehrenfried commented 2 years ago

OK, lets close it then.

tim1e1ing commented 2 years ago

I outsourced that kind of question to a collegue. Once I know I'll post here.

This can be closed, I think. (and marked as "nofix" for OTP1.4?)

Speed would be very interesting. The test with 32G serve was very slow. will try next week on bigger backend server.