osrm-extract stuck in a loop

[danpat]

Using master at bb244e2, and the unprocessed-osm.pbf linked from here, #2832, osrm-extract seems to take an extrodinarily long amount of time (I haven't yet seen it finish).

After a period (a couple of hours) of normal busy-ness on all CPUs, activity seems to reduce to just one CPU. I attached a debugger and took a look at the only busy thread, here's the backtrace:

#0  0x00007ffff5aca7bd in __kernel_rem_pio2 (x=x@entry=0x7fffffff8df0, y=y@entry=0x7fffffff8e10, e0=e0@entry=-24, nx=nx@entry=3, prec=prec@entry=2,
    ipio2=ipio2@entry=0x7ffff5b5c620 <two_over_pi>) at ../sysdeps/ieee754/dbl-64/k_rem_pio2.c:327
#1  0x00007ffff5aeedc9 in __ieee754_rem_pio2l (x=0.91289970124339009762207131082334399, x@entry=0.91289970124339009762207131082334399, y=y@entry=0x7fffffff8e70)
    at ../sysdeps/ieee754/ldbl-96/e_rem_pio2l.c:220
#2  0x00007ffff5af0ead in __sinl (x=x@entry=0.91289970124339009762207131082334399) at ../sysdeps/ieee754/ldbl-96/s_sinl.c:78
#3  0x000000000052febb in sin (__x=<optimized out>) at /usr/include/c++/4.8/cmath:449
#4  latToY (latitude=...) at /mnt/data/x/osrm-backend/include/util/web_mercator.hpp:44
#5  osrm::util::coordinate_calculation::computeAngle (first=..., first@entry=..., second=..., third=...)
    at /mnt/data/x/osrm-backend/src/util/coordinate_calculation.cpp:172
#6  0x00000000005a76d3 in osrm::extractor::guidance::IntersectionGenerator::GetConnectedRoads (this=this@entry=0x7fffffff9688, from_node=from_node@entry=4953888,
    via_eid=via_eid@entry=11009625) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:129
#7  0x00000000005a7f45 in osrm::extractor::guidance::IntersectionGenerator::GetActualNextIntersection (this=this@entry=0x7fffffff9688,
    starting_node=starting_node@entry=4953997, via_edge=<optimized out>, resulting_from_node=resulting_from_node@entry=0x0,
    resulting_via_edge=resulting_via_edge@entry=0x7fffffff9150) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:583
#8  0x00000000005a826e in operator() (index=0, __closure=<synthetic pointer>) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:239
#9  operator() (other_index=<optimized out>, index=0, __closure=0x7fffffff91e0) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:243
#10 osrm::extractor::guidance::IntersectionGenerator::CanMerge (this=this@entry=0x7fffffff9688, node_at_intersection=node_at_intersection@entry=4953997,
    intersection=std::vector of length 2, capacity 2 = {...}, first_index=first_index@entry=0, second_index=1)
    at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:272
#11 0x00000000005a8a5c in osrm::extractor::guidance::IntersectionGenerator::MergeSegregatedRoads (this=this@entry=0x7fffffff9688,
    intersection_node=intersection_node@entry=4953997, intersection=std::vector of length 2, capacity 2 = {...})
    at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:416
#12 0x00000000005a952d in osrm::extractor::guidance::IntersectionGenerator::operator() (this=this@entry=0x7fffffff9688, from_node=from_node@entry=4953888,
    via_eid=via_eid@entry=11009626) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:37
#13 0x00000000005278fd in osrm::extractor::guidance::TurnAnalysis::getIntersection (this=this@entry=0x7fffffff9680, from_nid=from_nid@entry=4953888,
    via_eid=via_eid@entry=11009626) at /mnt/data/x/osrm-backend/src/extractor/guidance/turn_analysis.cpp:123
#14 0x0000000000501a5a in osrm::extractor::EdgeBasedGraphFactory::GenerateEdgeExpandedEdges (this=this@entry=0x7fffffffb3d0, scripting_environment=...,
    original_edge_data_filename="../../unprocessed-osm.osrm.edges", turn_lane_data_filename="../../unprocessed-osm.osrm.tld",
    edge_segment_lookup_filename="../../unprocessed-osm.osrm.edge_segment_lookup", edge_fixed_penalties_filename="../../unprocessed-osm.osrm.edge_penalties",
    generate_edge_lookup=generate_edge_lookup@entry=false) at /mnt/data/x/osrm-backend/src/extractor/edge_based_graph_factory.cpp:366
#15 0x0000000000503fce in osrm::extractor::EdgeBasedGraphFactory::Run (this=this@entry=0x7fffffffb3d0, scripting_environment=...,
    original_edge_data_filename="../../unprocessed-osm.osrm.edges", turn_lane_data_filename="../../unprocessed-osm.osrm.tld",
    edge_segment_lookup_filename="../../unprocessed-osm.osrm.edge_segment_lookup", edge_penalty_filename="../../unprocessed-osm.osrm.edge_penalties",
    generate_edge_lookup=false) at /mnt/data/x/osrm-backend/src/extractor/edge_based_graph_factory.cpp:207
#16 0x00000000004cd10c in osrm::extractor::Extractor::BuildEdgeExpandedGraph (this=this@entry=0x7fffffffd7d0, scripting_environment=...,
    internal_to_external_node_map=std::vector of length 195404826, capacity 268435456 = {...}, node_based_edge_list=std::vector of length 0, capacity 0,
    node_is_startpoint=std::vector<bool> of length 0, capacity 0, edge_based_node_weights=std::vector of length 0, capacity 0, edge_based_edge_list=...,
    intersection_class_output_file="../../unprocessed-osm.osrm.icd") at /mnt/data/x/osrm-backend/src/extractor/extractor.cpp:472
#17 0x00000000004cee54 in osrm::extractor::Extractor::run (this=this@entry=0x7fffffffd7d0, scripting_environment=...)
    at /mnt/data/x/osrm-backend/src/extractor/extractor.cpp:228
#18 0x0000000000494328 in main (argc=4, argv=<optimized out>) at /mnt/data/x/osrm-backend/src/tools/extract.cpp:156

All other threads were in a wait condition of one form or another.

I resumed the process, waited a few seconds, then interrupted it again, and I got this backtrace on the same thread:

#0  osrm::extractor::guidance::detail::getCoordinateFromCompressedRange<__gnu_cxx::__normal_iterator<osrm::extractor::CompressedEdgeContainer::CompressedEdge const*, std::vector<osrm::extractor::CompressedEdgeContainer::CompressedEdge, std::allocator<osrm::extractor::CompressedEdgeContainer::CompressedEdge> > > > (
    current_coordinate=..., compressed_geometry_begin=..., compressed_geometry_end=..., final_coordinate=...,
    query_nodes=std::vector of length 195404826, capacity 268435456 = {...}) at /mnt/data/x/osrm-backend/include/extractor/guidance/toolkit.hpp:84
#1  0x00000000005a7a6a in getRepresentativeCoordinate (traverse_in_reverse=false, query_nodes=std::vector of length 195404826, capacity 268435456 = {...},
    compressed_geometries=..., via_edge_id=11009858, to_node=<optimized out>, from_node=4953996)
    at /mnt/data/x/osrm-backend/include/extractor/guidance/toolkit.hpp:150
#2  osrm::extractor::guidance::IntersectionGenerator::GetConnectedRoads (this=this@entry=0x7fffffff9688, from_node=from_node@entry=4953888,
    via_eid=via_eid@entry=11009625) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:127
#3  0x00000000005a7f45 in osrm::extractor::guidance::IntersectionGenerator::GetActualNextIntersection (this=this@entry=0x7fffffff9688,
    starting_node=starting_node@entry=4953997, via_edge=<optimized out>, resulting_from_node=resulting_from_node@entry=0x0,
    resulting_via_edge=resulting_via_edge@entry=0x7fffffff9150) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:583
#4  0x00000000005a826e in operator() (index=0, __closure=<synthetic pointer>) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:239
#5  operator() (other_index=<optimized out>, index=0, __closure=0x7fffffff91e0) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:243
#6  osrm::extractor::guidance::IntersectionGenerator::CanMerge (this=this@entry=0x7fffffff9688, node_at_intersection=node_at_intersection@entry=4953997,
    intersection=std::vector of length 2, capacity 2 = {...}, first_index=first_index@entry=0, second_index=1)
    at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:272
#7  0x00000000005a8a5c in osrm::extractor::guidance::IntersectionGenerator::MergeSegregatedRoads (this=this@entry=0x7fffffff9688,
    intersection_node=intersection_node@entry=4953997, intersection=std::vector of length 2, capacity 2 = {...})
    at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:416
#8  0x00000000005a952d in osrm::extractor::guidance::IntersectionGenerator::operator() (this=this@entry=0x7fffffff9688, from_node=from_node@entry=4953888,
    via_eid=via_eid@entry=11009626) at /mnt/data/x/osrm-backend/src/extractor/guidance/intersection_generator.cpp:37
#9  0x00000000005278fd in osrm::extractor::guidance::TurnAnalysis::getIntersection (this=this@entry=0x7fffffff9680, from_nid=from_nid@entry=4953888,
    via_eid=via_eid@entry=11009626) at /mnt/data/x/osrm-backend/src/extractor/guidance/turn_analysis.cpp:123
#10 0x0000000000501a5a in osrm::extractor::EdgeBasedGraphFactory::GenerateEdgeExpandedEdges (this=this@entry=0x7fffffffb3d0, scripting_environment=...,
    original_edge_data_filename="../../unprocessed-osm.osrm.edges", turn_lane_data_filename="../../unprocessed-osm.osrm.tld",
    edge_segment_lookup_filename="../../unprocessed-osm.osrm.edge_segment_lookup", edge_fixed_penalties_filename="../../unprocessed-osm.osrm.edge_penalties",
    generate_edge_lookup=generate_edge_lookup@entry=false) at /mnt/data/x/osrm-backend/src/extractor/edge_based_graph_factory.cpp:366
#11 0x0000000000503fce in osrm::extractor::EdgeBasedGraphFactory::Run (this=this@entry=0x7fffffffb3d0, scripting_environment=...,
    original_edge_data_filename="../../unprocessed-osm.osrm.edges", turn_lane_data_filename="../../unprocessed-osm.osrm.tld",
    edge_segment_lookup_filename="../../unprocessed-osm.osrm.edge_segment_lookup", edge_penalty_filename="../../unprocessed-osm.osrm.edge_penalties",
    generate_edge_lookup=false) at /mnt/data/x/osrm-backend/src/extractor/edge_based_graph_factory.cpp:207
#12 0x00000000004cd10c in osrm::extractor::Extractor::BuildEdgeExpandedGraph (this=this@entry=0x7fffffffd7d0, scripting_environment=...,
    internal_to_external_node_map=std::vector of length 195404826, capacity 268435456 = {...}, node_based_edge_list=std::vector of length 0, capacity 0,
    node_is_startpoint=std::vector<bool> of length 0, capacity 0, edge_based_node_weights=std::vector of length 0, capacity 0, edge_based_edge_list=...,
    intersection_class_output_file="../../unprocessed-osm.osrm.icd") at /mnt/data/x/osrm-backend/src/extractor/extractor.cpp:472
#13 0x00000000004cee54 in osrm::extractor::Extractor::run (this=this@entry=0x7fffffffd7d0, scripting_environment=...)
    at /mnt/data/x/osrm-backend/src/extractor/extractor.cpp:228
#14 0x0000000000494328 in main (argc=4, argv=<optimized out>) at /mnt/data/x/osrm-backend/src/tools/extract.cpp:156

Frame 12 in the first trace and frame 8 in the second trace look identical - this seems unexpected, I wouldn't imagine we'd still be looking at the same from_node for several seconds unless I got ridiculously unlucky with my interrupt. It looks like we might be stuck in a loop starting here: https://github.com/Project-OSRM/osrm-backend/blob/master/src/extractor/guidance/intersection_generator.cpp#L36-L37

[MoKob]

Should be solved in #2854, requires some validation on the larger extract though

[TheCoolRob]

I picked up the same issue on the australia-latest.osm.pbf yesterday if you're looking for a bigger problem set to reproduce the issue. I let it run for about 50 hours before killing the process.

[MoKob]

Just verified that this fix works on australia-latest.osm.pbf from Geofabrik.

[stavskal]

I can confirm I'm facing the same problem for belgium-latest.osm.pbf . Might be a noob question but is the fix already available? If so, is it in the master branch already?

[MoKob]

@stavskal you can either cherry-pick it from #2854 or wait for the review process to be finished. Should make it's way into master by today.

[stavskal]

@MoKob thanks for the quick reply, I'll be patient and wait for master :)

[MoKob]

Fix got merged. Most recent master should be without this problem.

[danpat]

Re-running with my test data now.

[TheCoolRob]

I tested on my data that was failing and the master works now. Thanks for the speedy patch.

[stavskal]

Can confirm fix on belgium-latest.osm.pbf