[OSM-dev] 404 from Apache2/mod_tile

Stefan Elspaß stefan.elspass at gmail.com
Fri Nov 9 19:37:44 GMT 2012 

Hi Kai,

> If I read your renderd log correctly, mod_tile is sending rendering requests
> with priority "dirty" rather than the "missing" priority. The dirty priority
> is a background priority in which mod_tile does not wait for the result and
> immediately returns the tile (or in case of a missing tile a 404).

This is indeed the case, but sometimes - in these seldom cases when rendering on the first request works - the "command RenderPrio" instead of "command Dirty" appears in /var/log/syslog (see below). Does that indicate that it might by a load-related decision from mod_tile?

> So the question is why does mod_tile send the requests with the incorrect
> priority? This should only happen if the load average is above the
> configured max missing load. Your configurations do look fine though.

Do you know by chance what unit "ModTileMaxLoadMissing" uses? Is it a percentage? The settings for the log below were as follows:

ModTileRequestTimeout 900
ModTileMissingRequestTimeout 300
ModTileMaxLoadMissing 500

> Can you increase the debug level of mod_tile to debug and then post your
> apache error.log again? The debug output unfortunately currently doesn't
> tell you what mod_tile thinks the load on the server is, but at least it
> would confirm if this is the cause and what the configuration is set to.

In /etc/apache2/site-available/default I changed the log-value by changing the line to "LogLevel debug". Is there any other way to increase the debug level of mod_tile?

Greetings, Stefan

/var/log/syslog
-------------
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 12, number 2
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got command RenderPrio fd(12) xml(default), z(17), x(69332), y(43350)
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 13, number 3
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 14, number 4
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got command RenderPrio fd(14) xml(default), z(17), x(69331), y(43349)
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got command RenderPrio fd(13) xml(default), z(17), x(69332), y(43348)
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got command RenderPrio fd(11) xml(default), z(17), x(69332), y(43349)
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 16, number 5
Nov  9 20:15:44 xxxxxx renderd[16476]: DEBUG: Got command RenderPrio fd(16) xml(default), z(17), x(69331), y(43348)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: DONE TILE default 17 69328-69335 43344-43351
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: DONE TILE default 17 69328-69335 43344-43351 in 3.495 seconds
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 1, fd 12 closed, now 4 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 2, fd 14 closed, now 3 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 1, fd 13 closed, now 2 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 1, fd 16 closed, now 1 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138663), y(86698)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 12, number 2
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138663), y(86699)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 13, number 3
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 2 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 3
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(12) xml(default), z(18), x(138662), y(86698)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(13) xml(default), z(18), x(138662), y(86697)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 12 closed, now 2 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138663), y(86697)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 13 closed, now 1 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138662), y(86699)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 12, number 2
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138664), y(86699)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 13, number 3
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 2 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 3
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(12) xml(default), z(18), x(138664), y(86698)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(13) xml(default), z(18), x(138661), y(86698)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 12 closed, now 2 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138664), y(86697)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 13 closed, now 1 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138661), y(86699)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 12, number 2
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138665), y(86697)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 1 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(12) xml(default), z(18), x(138661), y(86697)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 12 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138665), y(86698)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138660), y(86698)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138660), y(86699)
Nov  9 20:15:47 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:48 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:48 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138660), y(86697)
Nov  9 20:15:48 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:48 xxxxxx renderd[16476]: DEBUG: Got incoming connection, fd 11, number 1
Nov  9 20:15:48 xxxxxx renderd[16476]: DEBUG: Got command Dirty fd(11) xml(default), z(18), x(138665), y(86699)
Nov  9 20:15:48 xxxxxx renderd[16476]: DEBUG: Connection 0, fd 11 closed, now 0 left
Nov  9 20:15:49 xxxxxx renderd[16476]: DEBUG: DONE TILE default 18 138656-138663 86696-86703
Nov  9 20:15:49 xxxxxx renderd[16476]: DEBUG: DONE TILE default 18 138656-138663 86696-86703 in 1.814 seconds
Nov  9 20:15:49 xxxxxx renderd[16476]: DEBUG: DONE TILE default 18 138664-138671 86696-86703
Nov  9 20:15:49 xxxxxx renderd[16476]: DEBUG: DONE TILE default 18 138664-138671 86696-86703 in 2.012 seconds

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstreetmap.org/pipermail/dev/attachments/20121109/330b150d/attachment-0001.html>

More information about the dev mailing list