artemp/mapnik — Issue #747: Deadlock in mapnik::proj_transform::backward()
Author: artemp
Created: 2011-10-11 16:34:50+00:00
State: open
Labels: Core_Library

This shapefile http://dbsgeo.com/tmp/Edgepave.zip

(originally downloaded from http://data.baltimorecity.gov/api/file_data/9XBWO2g9mNCjpb2Sr8nVzwT6g5XLI9Jnl12hJ9p8z7I?filename=Edgepave.zip)

can trigger a > 100% CPU hang in mapnik when used within TileMill and reprojection occurs to spherical mercator. TileMill is a nodejs application and is using both async rendering and worker processes during tile caching, when this occurs. It has happened both on Mac OSX and Ubuntu linux.

On OSX I tested with both proj 4.7 from homebrew and proj trunk (see below) built from source:
{{{
/usr/local/Cellar/proj/4.7.0/lib/libproj.0.dylib
}}}

This issue (and also this one: #722) hopefully should be resolved by upgrading to proj 4.8 which allows mapnik to avoid locking, but that is blocked by: #734

Note: the shapefile is able to render using nik2img.py but takes over 1 minute:

{{{
#!sh
d:loop dane$ nik2img.py t.xml t.png -v
Step: 1 // --> Nik2img starting...
Step: 2 // --> Format: png
Step: 3 // --> Loading mapfile...
Step: 4 // --> Loaded t.xml...
### WARNING Memory region does not exist file:/Users/dane/Desktop/loop/edgepave.index
Step: 5 // --> Setting Map view...
Step: 6 // --> Zoom to extent of all layers: "Box2d(-8553661.06111,4749982.77564,-8499813.58649,4785881.09205)"
Step: 7 // --> Finished setting extents...
Loading map took... 0.0018 seconds
Step: 8 // --> SRS: +proj=merc +a=6378137 +b=6378137 +lat_ts=0.0 +lon_0=0.0 +x_0=0.0 +y_0=0 +k=1.0 +units=m +nadgrids=@null +no_defs
Step: 9 // --> Map extent: Box2d(-8553661.06111,4749982.77564,-8499813.58649,4785881.09205)
Step: 10 // --> Map long/lat bbox: Box2d(-76.8388446637,39.197370575,-76.3551245691,39.446839333)
Step: 11 // --> Map center: Coord(-8526737.3238,4767931.93385)
Step: 12 // --> Map long/lat center: Coord(-76.5969846164,39.322104954)
Step: 13 // --> Map scale denominator: 320520.682265
Step: 14 // --> Extent of all layers: Box2d(-8539639.23711,4749982.77564,-8513835.41049,4785881.09205)
Step: 15 // --> Long/lat extent of all layers: Box2d(-76.7128844756,39.197370575,-76.4810847572,39.446839333)
Step: 16 // --> Long/lat center of all layers: Coord(-76.5969846164,39.322104954)
Step: 17 // --> Layers intersecting map: [edge]
Step: 18 // --> At current scale of '89.7457910343'...
Step: 19 // --> Layer 'edge' has 1 active rule(s) in styles: 'edge'
Step: 20 // --> Starting rendering...
Rendering image took... 1.56632666667 minutes
Step: 21 // --> Finished rendering map to... t.png
Total Nik2img run time: 1.56642166667 minutes
}}}

Here is the triggering XML:

{{{
#!xml

edge

edgepave.shp
shape

}}}

And here is the hang demonstrated in gdb when it is attempted to be rendered in the multi-threaded environment of nodejs:

{{{
Thread 5 (process 4163):
#0 0x00007fff86f65322 in semaphore_wait_signal_trap ()
#1 0x00007fff86f6a96d in pthread_mutex_lock ()
#2 0x000000012613660c in boost::unique_lock::lock ()
#3 0x00000001262a6f37 in mapnik::proj_transform::backward ()
#4 0x0000000126075214 in mapnik::coord_transform2, mapnik::vertex_vector> >::vertex () at /usr/local/include/mapnik/ctrans.hpp:77
#5 0x0000000126075214 in agg::conv_adaptor_vcgen, mapnik::vertex_vector> >, agg::vcgen_stroke, agg::null_markers>::vertex (this=0x12a2ba0e0, x=0x12a2ba068, y=0x12a2ba060) at ctrans.hpp:111
#6 0x00000001262cce57 in agg::rasterizer_scanline_aa >::add_path, mapnik::vertex_vector> >, agg::null_markers> > ()
#7 0x00000001262cec6e in mapnik::agg_renderer::process ()
#8 0x00000001260b6cb9 in __gnu_cxx::__normal_iterator const*, std::vector, std::allocator > > >::operator++ () at variant.hpp:1798
#9 0x00000001260b6cb9 in next, std::allocator > >, mpl_::bool_ > [inlined] () at /usr/local/include/boost/foreach.hpp:737
#10 0x00000001260b6cb9 in mapnik::feature_style_processor >::apply_to_layer (this=0x12a2bacc0, lay=@0x1006391d0, p=@0x12a2bacc0, proj0=, scale_denom=139770566.00717944) at variant.hpp:383
#11 0x00000001260b75c0 in mapnik::feature_style_processor >::apply (this=) at feature_style_processor.hpp:114
#12 0x0000000126070f70 in Map::EIO_Render (req=) at ../src/mapnik_map.cpp:679
#13 0x000000010002ca12 in etp_proc (thr_arg=) at ../deps/libeio/eio.c:1693
#14 0x00007fff86f9e536 in _pthread_start ()
#15 0x00007fff86f9e3e9 in thread_start ()

Thread 4 (process 4163):
#0 0x00007fff86f65322 in semaphore_wait_signal_trap ()
#1 0x00007fff86f6a96d in pthread_mutex_lock ()
#2 0x000000012613660c in boost::unique_lock::lock ()
#3 0x00000001262a6f37 in mapnik::proj_transform::backward ()
#4 0x0000000126075214 in mapnik::coord_transform2, mapnik::vertex_vector> >::vertex () at /usr/local/include/mapnik/ctrans.hpp:77
#5 0x0000000126075214 in agg::conv_adaptor_vcgen, mapnik::vertex_vector> >, agg::vcgen_stroke, agg::null_markers>::vertex (this=0x12a2a70e0, x=0x12a2a7068, y=0x12a2a7060) at ctrans.hpp:111
#6 0x00000001262cce57 in agg::rasterizer_scanline_aa >::add_path, mapnik::vertex_vector> >, agg::null_markers> > ()
#7 0x00000001262cec6e in mapnik::agg_renderer::process ()
#8 0x00000001260b6cb9 in __gnu_cxx::__normal_iterator const*, std::vector, std::allocator > > >::operator++ () at variant.hpp:1798
#9 0x00000001260b6cb9 in next, std::allocator > >, mpl_::bool_ > [inlined] () at /usr/local/include/boost/foreach.hpp:737
#10 0x00000001260b6cb9 in mapnik::feature_style_processor >::apply_to_layer (this=0x12a2a7cc0, lay=@0x1006308e0, p=@0x12a2a7cc0, proj0=, scale_denom=139770566.00717944) at variant.hpp:383
#11 0x00000001260b75c0 in mapnik::feature_style_processor >::apply (this=) at feature_style_processor.hpp:114
#12 0x0000000126070f70 in Map::EIO_Render (req=) at ../src/mapnik_map.cpp:679
#13 0x000000010002ca12 in etp_proc (thr_arg=) at ../deps/libeio/eio.c:1693
#14 0x00007fff86f9e536 in _pthread_start ()
#15 0x00007fff86f9e3e9 in thread_start ()

Thread 3 (process 4163):
#0 0x00007fff86f65322 in semaphore_wait_signal_trap ()
#1 0x00007fff86f6a96d in pthread_mutex_lock ()
#2 0x000000012613660c in boost::unique_lock::lock ()
#3 0x00000001262a6f37 in mapnik::proj_transform::backward ()
#4 0x00000001261fb151 in mapnik::coord_transform2, mapnik::vertex_vector> >::vertex ()
#5 0x00000001262c4ec0 in agg::rasterizer_scanline_aa >::add_path, mapnik::vertex_vector> > > ()
#6 0x00000001262d5559 in mapnik::agg_renderer::process ()
#7 0x00000001260b6cb9 in __gnu_cxx::__normal_iterator const*, std::vector, std::allocator > > >::operator++ () at variant.hpp:1798
#8 0x00000001260b6cb9 in next, std::allocator > >, mpl_::bool_ > [inlined] () at /usr/local/include/boost/foreach.hpp:737
#9 0x00000001260b6cb9 in mapnik::feature_style_processor >::apply_to_layer (this=0x12a294cc0, lay=@0x100636ee0, p=@0x12a294cc0, proj0=, scale_denom=139770566.00717944) at variant.hpp:383
#10 0x00000001260b75c0 in mapnik::feature_style_processor >::apply (this=) at feature_style_processor.hpp:114
#11 0x0000000126070f70 in Map::EIO_Render (req=) at ../src/mapnik_map.cpp:679
#12 0x000000010002ca12 in etp_proc (thr_arg=) at ../deps/libeio/eio.c:1693
#13 0x00007fff86f9e536 in _pthread_start ()
#14 0x00007fff86f9e3e9 in thread_start ()

Thread 2 (process 4163):
#0 0x00007fff86f65322 in semaphore_wait_signal_trap ()
#1 0x00007fff86f6a96d in pthread_mutex_lock ()
#2 0x000000012613660c in boost::unique_lock::lock ()
#3 0x00000001262a6f37 in mapnik::proj_transform::backward ()
#4 0x00000001261fb151 in mapnik::coord_transform2, mapnik::vertex_vector> >::vertex ()
#5 0x00000001262c4e8a in agg::rasterizer_scanline_aa >::add_path, mapnik::vertex_vector> > > ()
#6 0x00000001262d5559 in mapnik::agg_renderer::process ()
#7 0x00000001260b6cb9 in __gnu_cxx::__normal_iterator const*, std::vector, std::allocator > > >::operator++ () at variant.hpp:1798
#8 0x00000001260b6cb9 in next, std::allocator > >, mpl_::bool_ > [inlined] () at /usr/local/include/boost/foreach.hpp:737
#9 0x00000001260b6cb9 in mapnik::feature_style_processor >::apply_to_layer (this=0x125470cc0, lay=@0x1006359f0, p=@0x125470cc0, proj0=, scale_denom=139770566.00717944) at variant.hpp:383
#10 0x00000001260b75c0 in mapnik::feature_style_processor >::apply (this=) at feature_style_processor.hpp:114
#11 0x0000000126070f70 in Map::EIO_Render (req=) at ../src/mapnik_map.cpp:679
#12 0x000000010002ca12 in etp_proc (thr_arg=) at ../deps/libeio/eio.c:1693
#13 0x00007fff86f9e536 in _pthread_start ()
#14 0x00007fff86f9e3e9 in thread_start ()

Thread 1 (process 4163):
#0 0x00007fff86f7e16a in kevent ()
#1 0x0000000100034ead in kqueue_poll (timeout=0.98492717742919922) at ev_kqueue.c:99
#2 0x0000000100033e1e in ev_time [inlined] () at /Users/dane/projects/tilemill/src/node-0.2.6/deps/libev/ev.c:2337
#3 0x0000000100033e1e in time_update [inlined] () at /Users/dane/projects/tilemill/src/node-0.2.6/deps/libev/ev.c:2214
#4 0x0000000100033e1e in ev_loop (flags=) at ../deps/libev/ev.c:2341
#5 0x000000010000443f in node::Loop (args=) at ../src/node.cc:1025
#6 0x00000001000848b4 in v8::internal::Builtin_HandleApiCall ()
Previous frame inner to this frame (gdb could not unwind past this frame)
}}}