Debugging crashes with no output

Open Source Routing Engine
1

Hi, I’m trying to run an import on all of europe using the default osm data provider and have experienced some crashes with no useful logging output. I’m running Graphhopper 2.0 in Docker on a 4 CPU 32GB RAM Ubuntu cloud instance and I have two routing profiles:

...
graph.flag_encoders: car,motorcycle
profiles:
- name: motorbike_curves
  vehicle: motorcycle
  weighting: curvature
profiles_ch:
- profile: car
- profile: motorbike_curves
...

The command I’m running it with is:
sudo docker run -v graphhopper:/graphhopper/data -d -e JAVA_OPTS="-Xmx28g -Xms28g -Ddw.server.application_connectors[0].bind_host=0.0.0.0 -Ddw.server.application_connectors[0].port=8989" -p 8989:8989 graphhopper:latest -fd -i data/europe.pbf

This runs ./graphhopper.sh -a web.

Before I saw Java heap out of memory errors so I’ve been adding more ram to my instance but now I’m not seeing any of those. This is the most recent console output:

2020-12-15 01:00:20.165 [car] INFO c.g.r.c.PrepareContractionHierarchies - node, nodes: 0, shortcuts: 56 470 855, updates: 5, checked-nodes: 76 248 733, t(total): 4374.26, t(period): 1939.22, t(lazy): 484.88, t(neighbor): 845.28, t(contr): 968.30, t(other) : 136.58, dijkstra-ratio: 86.97%, meanDegree: 1.36, dijkstras: 1 308 827 393, mem: 1124MB, totalMB:28672, usedMB:18767 2020-12-15 01:00:20.166 [car] INFO c.g.r.c.PrepareContractionHierarchies - new shortcuts: 56 470 855, initSize:73 684 262, fastest|car, periodic:20, lazy:10, neighbor:20, t(total): 4374.26, t(period): 1939.22, t(lazy): 484.88, t(neighbor): 845.28, t(contr): 968.30, t(other) : 136.58, dijkstra-ratio: 86.97%, lazy-overhead: 3%, totalMB:28672, usedMB:18767 2020-12-15 01:00:20.166 [car] INFO c.g.r.c.PrepareContractionHierarchies - took: 4374s, graph now - num edges: 89 322 691, num nodes: 73 684 262, num shortcuts: 56 470 855 2020-12-15 01:00:20.170 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - Creating CH prepare graph, totalMB:28672, usedMB:18771 2020-12-15 01:00:20.736 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - Building CH prepare graph, totalMB:28672, usedMB:13109 2020-12-15 01:01:36.778 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - Finished building CH prepare graph, took: 76.04224s, totalMB:28672, usedMB:20900 2020-12-15 01:01:37.199 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - Building initial queue of nodes to be contracted: 73684262 nodes, totalMB:28672, usedMB:21468 2020-12-15 01:03:39.325 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - Finished building queue, took: 122.12126s, totalMB:28672, usedMB:22024 2020-12-15 01:03:39.327 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - node, nodes: 73 684 262, shortcuts: 0, updates: 0, checked-nodes: 0, t(total): 199.16, t(period): 122.12, t(lazy): 0.00, t(neighbor): 0.00, t(contr): 0.00, t(other) : 77.04, dijkstra-ratio: 40.53%, meanDegree: 1.00, dijkstras: 264 587 209, mem: 1124MB, totalMB:28672, usedMB:22024 2020-12-15 01:11:52.050 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - node, nodes: 58 947 410, shortcuts: 2 620, updates: 1, checked-nodes: 14 736 852, t(total): 691.87, t(period): 564.15, t(lazy): 0.00, t(neighbor): 29.26, t(contr): 15.28, t(other) : 83.18, dijkstra-ratio: 74.20%, meanDegree: 1.00, dijkstras: 478 834 229, mem: 1124MB, totalMB:28672, usedMB:22256 2020-12-15 01:14:20.857 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 47.51913933126195,-2.4949728137621165 nodeB 47.519767228955786,-2.494386825585071 2020-12-15 01:14:23.912 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 45.99658279113284,8.571677846573543 nodeB 45.99501947302415,8.571428252117967 2020-12-15 01:14:29.532 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 45.06356481604796,4.4271555787434185 nodeB 45.06144773352402,4.430813441369238 2020-12-15 01:20:37.581 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - node, nodes: 44 210 558, shortcuts: 1 494 110, updates: 2, checked-nodes: 29 473 704, t(total): 1217.41, t(period): 913.35, t(lazy): 0.00, t(neighbor): 81.85, t(contr): 131.81, t(other) : 90.41, dijkstra-ratio: 79.41%, meanDegree: 1.96, dijkstras: 659 705 237, mem: 1124MB, totalMB:28672, usedMB:21272 2020-12-15 01:21:50.378 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 50.09288862555225,6.8365558647339615 nodeB 50.09200927075764,6.837679784842129 2020-12-15 01:21:51.029 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 55.504210602586205,36.92137718770006 nodeB 55.503695208661895,36.92544278335816 2020-12-15 01:23:12.684 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 43.75738692486406,7.381444775643455 nodeB 43.75800867582877,7.379953914432687 2020-12-15 01:23:25.887 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 41.59771911645798,1.7311646058670715 nodeB 41.5975153430741,1.7302707224399758 2020-12-15 01:23:25.891 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 41.5975153430741,1.7302707224399758 nodeB 41.59821364875615,1.7312055840612706 2020-12-15 01:23:37.009 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 43.7578684186459,5.922943672305577 nodeB 43.75456557619346,5.933803638826392 2020-12-15 01:24:35.006 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 42.13126321430347,1.9922210348893934 nodeB 42.12987256340398,1.991759098882059 2020-12-15 01:29:57.604 [motorbike_curves] INFO c.g.r.c.PrepareContractionHierarchies - node, nodes: 29 473 706, shortcuts: 7 691 062, updates: 3, checked-nodes: 44 210 556, t(total): 1777.43, t(period): 1224.73, t(lazy): 0.00, t(neighbor): 164.94, t(contr): 289.80, t(other) : 97.96, dijkstra-ratio: 81.49%, meanDegree: 2.00, dijkstras: 809 303 687, mem: 1124MB, totalMB:28672, usedMB:22272 2020-12-15 01:31:01.891 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 47.28568730396824,12.48147701803171 nodeB 47.28490685563326,12.481322791009905 2020-12-15 01:31:02.747 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 47.448815348345384,10.642965375847341 nodeB 47.44973437748256,10.64161961469694 2020-12-15 01:31:02.747 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 47.448205145780854,10.63827821548905 nodeB 47.44973437748256,10.64161961469694 2020-12-15 01:31:10.938 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 50.95598364523017,8.144760872679074 nodeB 50.95380733058916,8.145839157980065 2020-12-15 01:31:28.602 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 38.966940841829945,22.296338840492194 nodeB 38.9800594519092,22.27983654915921 2020-12-15 01:31:53.494 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 48.96134284797332,15.679545492221687 nodeB 48.95922874568169,15.681280546216977 2020-12-15 01:31:59.663 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 42.456505837809424,1.4799220818263759 nodeB 42.45941026045554,1.482170294571749 2020-12-15 01:32:03.628 [motorbike_curves] WARN com.graphhopper.storage.CHGraphImpl - Setting weights smaller than 0.001 is not allowed in CHGraphImpl#setWeight. You passed: 0.0 for the edge -1 nodeA 45.592103054943,14.23949146806057 nodeB 45.59494489271071,14.23954269080332

There is no more output and the Docker container died. The program crashed. How would I go about debugging this? I had not problems running this just for Great Britain.

Thanks

2

Never mind, found the answer in /var/sys/log:

/var/log/syslog:Dec 15 01:32:54 graphhopper-prod kernel: [16140.787809] Out of memory: Killed process 12747 (java) total-vm:35348228kB, anon-rss:32276848kB, file-rss:0kB, shmem-rss:0kB, UID:0 pgtables:63556kB oom_score_adj:0

It would be good to have the some minimum requirements in the docs taking into account the import size. I will try decreasing the Java heap size whilst keeping the instance RAM the same because this wasn’t the Java exception I was seeing then the JVM ran out of memory.

3

See Deployed Graphhopper Instance Crashes Every Few Days and https://github.com/graphhopper/graphhopper/blob/master/docs/core/deploy.md

4

Could I ask for some of your anecdotal experience? Would you expect -Xmx17000m -Xms17000m to be enough to import the whole world file with just one routing profile? Also how much of an impact on memory can you expect for each additional routing profile to have (doubling, 50% extra) roughly?

5

When running GraphHopper you need to have Xmx to be at least the size of the graph files in the folder.

When doing the import you need X% more (except you use the MMAP_STORE option). And X depends on the number of profiles and how many CH threads you use.

Also how much of an impact on memory can you expect for each additional routing profile to have (doubling, 50% extra) roughly?

Hard to tell. As sizes differ by a lot for node-based vs. edge-based CH preparation (only edge-based CH supports turn restrictions). I would start with node-based & one profile and a 32GB machine and increase by at least the size of the profile (there are a couple of files per profile in the graph folder)

6

One thing I learned from these kind of errors is that the JVM might use (a lot) more memory than specified by Xmx, because the heap is not necessarily the only significant contribution to the total memory that is used. Especially the garbage collector (and especially G1) needs memory besides the heap and this is why the memory killer killed your process and you did not see the more common Java out of heap space error.

7

Yes that was exactly it, I didn’t leave enough RAM available to the OS by setting the java heap size so large. I re-ran the import on the same machine with a lower heap size and it didn’t get killed by the OS.

Thanks for your insight @karussell

8

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.