[OSM-dev] Tirex - Rendering jobs stucked in the queue

Radek Bartoň blackhex at post.cz
Fri Jan 14 10:14:30 GMT 2011


Hello everyone.

I have a working setup of mod_tile+Tirex+Mapnik rendering server on one 
machine and recently I've tryied to setup another one on much more powerfull 
machine. I'm alost sure I've done exactly same configuration (except some 
paths are different) and I've checked if all the files/directories needed are 
existing and with proper permissions and that Mapnik is able to render the 
tiles with my styles from generate_tiles.py.

The problem is that rendering jobs comming from mod_tile are enqeued in tirex-
master rendering qeueu ("tirex-status -eo" shows them) but they are not 
processed and after they timeout after a long time period, the cached tile is 
empty. IMHO the problem is somewhere in tirex-master - tirex-backend-manager 
communication.

I'm racking my brain with this almost a week so please give me some thoughts 
what can be wrong?

Thank you.

-------------------------------------------------------------------------------
tirex-status -oe:

 Tirex Master Status (updated=2011-01-14 10:57:39)

 Master server:
  started=2011-01-13 16:08:28 pid=27222

 Statistics:
  count_error=0
  count_expired=0
  count_rendered[tracks]=0, 0, 0, 0, 0, 0, 0, 6
  count_requested=334
  count_timeouted=324
  sum_render_time[tracks]=0, 0, 0, 0, 0, 0, 0, 527

 Queue:
  Prio   Size Maxsize           Age
     1     17      95   53:24-75:41
                                   
   all     17      95   53:24-75:41

 Buckets: (load=0)
  Name                 Priority  Rendering  MaxRend  Maxload Active Can Queued           
Age
  live                   1-   9          4        4       20    yes  no     17   
53:24-75:41
  important             10-  19          0        3        8    yes  no      0
  background            20-              0        2        4    yes  no      0

 Currently rendering: (num=4)
  Map                           X          Y   Z Prio Age
  tiles                       136         88   8    1 371
  tracks                     1104        696  11    1 371
  tracks                      552        344  10    1 371
  tiles                       136         80   8    1 191

 Renderers:
  Name        Port  Procs  Path                               
  mapnik      9331      3  /usr/lib/tirex/backends/mapnik 
  test        9330      2  /usr/lib/tirex/backends/test   
  wms         9332      2  /usr/lib/tirex/backends/wms    

 Maps:
  Name                 Renderer    Zoom  Tiledir                               
  demowms              wms         0-10  /var/lib/tirex/tiles/demowms   
  example              mapnik      0- 4  /var/lib/tirex/tiles/example   
  test                 test        0-10  /var/lib/tirex/tiles/test      
  tiles                mapnik      0-20  /var/lib/tirex/tiles/tiles     
  tracks               mapnik      0-20  /var/lib/tirex/tiles/tracks    
  tracks-debug         mapnik      0-20  /var/lib/tirex/tiles/tracks-debug 

-------------------------------------------------------------------------------
/var/log/apache2/error.log:

[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
uri(/tracks/7/64/40.png), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/65/40.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/66/8.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/test/) name(test), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tiles/) name(tiles), referer: http://opentrackmap.no-ip.oqrg/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tracks/) name(tracks), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
op(tile_serve) xml(tracks) z(7) x(64) y(40), referer: http://opentrackmap.no-
ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/64/40.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/66/8.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
uri(/tracks/7/63/40.png), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/test/) name(test), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tiles/) name(tiles), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tracks/) name(tracks), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
op(tile_serve) xml(tracks) z(7) x(63) y(40), referer: http://opentrackmap.no-
ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/63/40.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(65) y(40), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(64) y(40), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] Requesting 
xml(tracks) z(7) x(63) y(40), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
uri(/tracks/7/63/41.png), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
uri(/tracks/7/63/42.png), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/test/) name(test), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/64/40.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/66/8.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/65/40.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/66/8.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/test/) name(test), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tiles/) name(tiles), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tiles/) name(tiles), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 348796\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 352215\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tracks/) name(tracks), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tracks/) name(tracks), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
op(tile_serve) xml(tracks) z(7) x(63) y(42), referer: http://opentrackmap.no-
ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/63/42.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
op(tile_serve) xml(tracks) z(7) x(63) y(41), referer: http://opentrackmap.no-
ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/63/41.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] Requesting 
xml(tracks) z(7) x(63) y(42), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] Requesting 
xml(tracks) z(7) x(63) y(41), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
uri(/tracks/7/63/43.png), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/test/) name(test), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tiles/) name(tiles), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tracks/) name(tracks), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
op(tile_serve) xml(tracks) z(7) x(63) y(43), referer: http://opentrackmap.no-
ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/63/43.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] Requesting 
xml(tracks) z(7) x(63) y(43), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
uri(/tracks/7/63/44.png), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/test/) name(test), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tiles/) name(tiles), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tracks/) name(tracks), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
op(tile_serve) xml(tracks) z(7) x(63) y(44), referer: http://opentrackmap.no-
ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/63/44.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
uri(/tracks/7/63/45.png), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/test/) name(test), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tiles/) name(tiles), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
baseuri(/tracks/) name(tracks), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] Requesting 
xml(tracks) z(7) x(63) y(44), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_translate: 
op(tile_serve) xml(tracks) z(7) x(63) y(45), referer: http://opentrackmap.no-
ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_storage_hook: 
handler(tile_serve), uri(/tracks/7/63/45.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null)), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] Requesting 
xml(tracks) z(7) x(63) y(45), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(693): [client 147.229.13.140] 
Update file info abs_path(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(63) y(45), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(693): [client 147.229.13.140] 
Update file info abs_path(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/63/45.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(63) y(41), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 352484\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(693): [client 147.229.13.140] 
Update file info abs_path(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/63/41.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 351261\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(63) y(40), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/63/40.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 352215\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(693): [client 147.229.13.140] 
Update file info abs_path(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(693): [client 147.229.13.140] 
Update file info abs_path(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(63) y(44), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(693): [client 147.229.13.140] 
Update file info abs_path(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(63) y(42), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/63/44.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [info] [client 147.229.13.140] tile_handler_serve: 
xml(tracks) z(7) x(63) y(43), referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 350929\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/63/42.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(288): [client 147.229.13.140] 
expires(tile_serve), uri(/tracks/7/63/43.png), 
filename(/var/lib/mod_tile/tracks/7/0/0/0/50/136.meta), path_info((null))\n, 
referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(326): [client 147.229.13.140] 
caching heuristics: next planet render 345599; zoom level based 10800; last 
modified 0\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 352484\n, referer: http://opentrackmap.no-ip.org/
[Thu Jan 13 16:08:48 2011] [debug] mod_tile.c(337): [client 147.229.13.140] 
Setting tiles maxAge to 348796\n, referer: http://opentrackmap.no-ip.org/

-------------------------------------------------------------------------------
/var/log/tirex/jobs.log:

2011-01-13T16:08:48 id=1294931328_172267672 map=tracks x=64 y=40 z=7 prio=1 
request_time=1294931328 expire= sources=MMMMMM render_time=86 success=1
2011-01-13T16:08:48 id=1294931328_173550768 map=tracks x=72 y=40 z=7 prio=1 
request_time=1294931328 expire= sources=MMMMMM render_time=89 success=1
2011-01-13T16:08:48 id=1294931328_173565296 map=tracks x=56 y=40 z=7 prio=1 
request_time=1294931328 expire= sources=MMMMMM render_time=87 success=1
2011-01-13T16:08:48 id=1294931328_173568768 map=tracks x=64 y=32 z=7 prio=1 
request_time=1294931328 expire= sources=MM render_time=85 success=1
2011-01-13T16:08:48 id=1294931328_173568080 map=tracks x=72 y=32 z=7 prio=1 
request_time=1294931328 expire= sources=MMMM render_time=90 success=1
2011-01-13T16:08:48 id=1294931328_173587752 map=tracks x=56 y=32 z=7 prio=1 
request_time=1294931328 expire= sources=M render_time=90 success=1

-------------------------------------------------------------------------------

PostgreSQL log even with all queries logging is empty becase it never gets to 
actual rendering.

-- 
Ing. Radek Bartoň

Faculty of Information Technology
Department of Computer Graphics and Multimedia
Brno University of Technology

E-mail: ibarton at fit.vutbr.cz
Web: http://blackhex.no-ip.org
Jabber: blackhex at jabber.cz

-- 
Ing. Radek Bartoň

Faculty of Information Technology
Department of Computer Graphics and Multimedia
Brno University of Technology

E-mail: blackhex at post.cz
Web: http://blackhex.no-ip.org
Jabber: blackhex at jabber.cz



More information about the dev mailing list