openstreetmap
"Failed to read cmd on fd" errors since mod_tile update on 2nd June
I have a fairly standard Ubuntu 14.04 based map server, set up as per http://wiki.openstreetmap.org/wiki/User:SomeoneElse/Ubuntu_1404_tileserver .
I installed it on 26th April, and everything worked as expected. On 2nd June I updated mod_tile from github and started seeing "Failed to read cmd on fd" errors in syslog:
Jun 9 12:20:52 ubuntuvm38 renderd[21354]: DEBUG: Got incoming request with protocol version 2 Jun 9 12:20:52 ubuntuvm38 renderd[21354]: DEBUG: Got command RenderPrio fd(14) xml(default), z(18), x(130734), y(85209), mime(image/png), options() Jun 9 12:20:55 ubuntuvm38 renderd[21354]: DEBUG: DONE TILE default 18 130728-130735 85208-85215 in 2.407 seconds Jun 9 12:20:55 ubuntuvm38 renderd[21354]: DEBUG: Sending render cmd(3 default 18/130735/85209) with protocol version 2 to fd 8 Jun 9 12:20:55 ubuntuvm38 renderd[21354]: DEBUG: Failed to read cmd on fd 8 Jun 9 12:20:55 ubuntuvm38 renderd[21354]: DEBUG: Connection 0, fd 8 closed, now 5 left
This doesn't stop it working (all tiles are still being rendered as expected) but it does seem odd. Other server updates between 26th April and 2nd June include Ubuntu apt-get updates, a database reload from a new PBF file, but no changes to osm2pgsql style or (presumably) database columns etc.
http://forum.openstreetmap.org/viewtopic.php?id=25587
(from May 23rd) looks like it might be a similar issue.
Same here except that it's a new server and not working, but my output looks exactly like yours. This doesn't feel right...
The "failed to read cmd" message was added by Kai in 9d4e10e7c0ee5533d479f7365f135409e11b3250. It will be triggered any time a connection is closed because recv() returns 0 for this case. I don't think it is any cause for concern but maybe we want to set this at LOG_DEBUG or differentiate between -1 (errors) and 0 (successful close).
I have followed this tutorial https://switch2osm.org/serving-tiles/manually-building-a-tile-server-14-04/ But I am getting this when I am running sudo -u egnaro renderd -f -c /usr/local/etc/renderd.conf
renderd[22238]: Rendering daemon started renderd[22238]: Initiating reqyest_queue renderd[22238]: Parsing section renderd renderd[22238]: Parsing render section 0 renderd[22238]: Parsing section renderd01 renderd[22238]: Parsing render section 1 renderd[22238]: Parsing section renderd02 renderd[22238]: Parsing render section 2 renderd[22238]: Parsing section mapnik renderd[22238]: Parsing section default renderd[22238]: Parsing section style2 renderd[22238]: config renderd: unix socketname=/var/run/renderd/renderd.sock renderd[22238]: config renderd: num_threads=4 renderd[22238]: config renderd: num_slaves=8 renderd[22238]: config renderd: tile_dir=/var/lib/mod_tile renderd[22238]: config renderd: stats_file=/var/run/renderd/renderd.stats renderd[22238]: config mapnik: plugins_dir=/usr/local/lib/mapnik/input renderd[22238]: config mapnik: font_dir=/usr/share/fonts/truetype/ttf-dejavu renderd[22238]: config mapnik: font_dir_recurse=1 renderd[22238]: config renderd(0): Active renderd[22238]: config renderd(0): unix socketname=/var/run/renderd/renderd.sock renderd[22238]: config renderd(0): num_threads=4 renderd[22238]: config renderd(0): tile_dir=/var/lib/mod_tile renderd[22238]: config renderd(0): stats_file=/var/run/renderd/renderd.stats renderd[22238]: config renderd(1): unix socketname=/var/run/renderd/renderd.sock renderd[22238]: config renderd(1): num_threads=4 renderd[22238]: config renderd(1): tile_dir=/var/lib/mod_tile renderd[22238]: config renderd(1): stats_file=(null) renderd[22238]: config renderd(2): unix socketname=/var/run/renderd/renderd.sock renderd[22238]: config renderd(2): num_threads=4 renderd[22238]: config renderd(2): tile_dir=/var/lib/mod_tile renderd[22238]: config renderd(2): stats_file=(null) renderd[22238]: config map 0: name(default) file(/usr/local/share/maps/style/OSMBright/OSMBright.xml) uri(/osm_tiles/) htcp() host(localhost) renderd[22238]: config map 1: name(style2) file() uri(/osm_tiles2/) htcp() host() renderd[22238]: Initialising unix server socket on /var/run/renderd/renderd.sock renderd[22238]: Created server socket 4 renderd[22238]: Renderd is using mapnik version 2.2.0 renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerifCondensed-Bold.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansMono-Oblique.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerif.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansCondensed-Oblique.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansCondensed-Bold.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerifCondensed.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansCondensed.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerif-Italic.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerifCondensed-BoldItalic.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSans.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansCondensed-BoldOblique.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSans-BoldOblique.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSans-ExtraLight.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSans-Oblique.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSans-Bold.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansMono-Bold.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerif-Bold.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerif-BoldItalic.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansMono-BoldOblique.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSerifCondensed-Italic.ttf renderd[22238]: DEBUG: Loading font: /usr/share/fonts/truetype/ttf-dejavu/DejaVuSansMono.ttf Running in foreground mode... renderd[22238]: Starting stats thread renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sock renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 5 renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sock renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 6 debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sock renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 7 renderd[22238]: Loading parameterization function for debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile
renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sock renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sock renderd[22238]: Loading parameterization function for renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 9 renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 8 renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sock renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 10 debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sockrenderd[22238]: DEBUG: Got incoming connection, fd 13, number 1
debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile renderd[22238]: DEBUG: Got incoming connection, fd 14, number 2 renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 15renderd[22238]: DEBUG: Got incoming connection, fd 16, number 3
renderd[22238]: DEBUG: Got incoming connection, fd 17, number 4 renderd[22238]: DEBUG: Got incoming connection, fd 18, number 5 renderd[22238]: Initialising unix client socket on /var/run/renderd/renderd.sockrenderd[22238]: DEBUG: Got incoming connection, fd 19, number 6
renderd[22238]: Loading parameterization function for renderd[22238]: DEBUG: Got incoming connection, fd 20, number 7
renderd[22238]: Loading parameterization function for renderd[22238]: socket /var/run/renderd/renderd.sock initialised to fd 21 renderd[22238]: DEBUG: Got incoming connection, fd 22, number 8 renderd[22238]: Using web mercator projection settings renderd[22238]: Using web mercator projection settings renderd[22238]: Using web mercator projection settings renderd[22238]: Using web mercator projection settings renderd[22238]: DEBUG: Got incoming connection, fd 23, number 9 renderd[22238]: DEBUG: Got incoming request with protocol version 2 renderd[22238]: DEBUG: Got command RenderLow fd(23) xml(default), z(0), x(0), y(0), mime(image/png), options() renderd[22238]: DEBUG: Failed to read cmd on fd 23 renderd[22238]: DEBUG: Connection 8, fd 23 closed, now 8 left renderd[22238]: Dispatching request to slave thread on fd 5 renderd[22238]: DEBUG: Sending render cmd(1 default 0/0/0) with protocol version 3 to fd 5 renderd[22238]: DEBUG: Got incoming request with protocol version 3 renderd[22238]: DEBUG: Got command Render fd(13) xml(default), z(0), x(0), y(0), mime(image/png), options() renderd[22238]: DEBUG: Got incoming connection, fd 23, number 9 renderd[22238]: DEBUG: Got incoming request with protocol version 2 renderd[22238]: DEBUG: Got command RenderLow fd(23) xml(default), z(0), x(0), y(0), mime(image/png), options() renderd[22238]: DEBUG: Failed to read cmd on fd 23 renderd[22238]: DEBUG: Connection 8, fd 23 closed, now 8 left renderd[22238]: DEBUG: Got incoming connection, fd 23, number 9 renderd[22238]: DEBUG: Got incoming request with protocol version 2 renderd[22238]: DEBUG: Got command RenderLow fd(23) xml(default), z(0), x(0), y(0), mime(image/png), options() renderd[22238]: DEBUG: Failed to read cmd on fd 23 renderd[22238]: DEBUG: Connection 8, fd 23 closed, now 8 left renderd[22238]: DEBUG: Got incoming connection, fd 23, number 9 renderd[22238]: DEBUG: Got incoming request with protocol version 2 renderd[22238]: DEBUG: Got command RenderLow fd(23) xml(default), z(0), x(0), y(0), mime(image/png), options() renderd[22238]: DEBUG: Failed to read cmd on fd 23 renderd[22238]: DEBUG: Connection 8, fd 23 closed, now 8 left renderd[22238]: DEBUG: Got incoming connection, fd 23, number 9 renderd[22238]: DEBUG: Got incoming request with protocol version 2 renderd[22238]: DEBUG: Got command RenderLow fd(23) xml(default), z(0), x(0), y(0), mime(image/png), options() renderd[22238]: DEBUG: Failed to read cmd on fd 23 renderd[22238]: DEBUG: Connection 8, fd 23 closed, now 8 left renderd[22238]: DEBUG: Got incoming connection, fd 23, number 9 renderd[22238]: DEBUG: Got incoming request with protocol version 2 renderd[22238]: DEBUG: Got command RenderLow fd(23) xml(default), z(0), x(0), y(0), mime(image/png), options() renderd[22238]: DEBUG: Failed to read cmd on fd 23 renderd[22238]: DEBUG: Connection 8, fd 23 closed, now 8 left
My renderd.conf file is as follows [renderd] socketname=/var/run/renderd/renderd.sock num_threads=4 tile_dir=/var/lib/mod_tile stats_file=/var/run/renderd/renderd.stats
[renderd01] ;iphostname=::1 ;ipport=7654 ;num_threads=4 ;tile_dir=rados://tiles/etc/ceph/ceph.conf ;stats_file=/var/run/renderd/renderd.stats
[renderd02] ;iphostname=::1 ;ipport=7654 ;num_threads=8 ;tile_dir=memcached:// ;stats_file=/var/run/renderd/renderd.stats
[mapnik] plugins_dir=/usr/local/lib/mapnik/input font_dir=/usr/share/fonts/truetype/ttf-dejavu font_dir_recurse=1
[default] URI=/osm_tiles/ TILEDIR=/var/lib/mod_tile XML=/usr/local/share/maps/style/OSMBright/OSMBright.xml HOST=localhost TILESIZE=256 ;HTCPHOST=proxy.openstreetmap.org ;MINZOOM=0 ;MAXZOOM=18 ;TYPE=png image/png ;DESCRIPTION=This is a description of the tile layer used in the tile json request ;ATTRIBUTION=©<a href="http://www.openstreetmap.org/">OpenStreetMap and <a href="http://wiki.openstreetmap.org/wiki/Contributors">contributors, <a href="http://opendatacommons.org/licenses/odbl/">ODbL ;SERVER_ALIAS=http://localhost/ ;CORS=http://www.openstreetmap.org ;ASPECTX=1 ;ASPECTY=1 ;SCALE=1.0
[style2] URI=/osm_tiles2/ ;TILEDIR=rados://tiles/etc/ceph/ceph.conf ;TILESIZE=512 ;XML=/home/jburgess/osm/svn.openstreetmap.org/applications/rendering/mapnik/osm-local2.xml ;HOST=tile.openstreetmap.org ;HTCPHOST=proxy.openstreetmap.org ;MINZOOM=0 ;MAXZOOM=22 ;TYPE=png image/png ;DESCRIPTION=This is a description of the tile layer used in the tile json request ;ATTRIBUTION=©<a href="http://www.openstreetmap.org/">OpenStreetMap and <a href="http://wiki.openstreetmap.org/wiki/Contributors">contributors, <a href="http://opendatacommons.org/licenses/odbl/">ODbL ;SERVER_ALIAS=http://localhost/ ;CORS=*
Please help me to know what I am doing wrong here.
@avirupd-egnaroinc I'll reply on https://lists.openstreetmap.org/listinfo/tile-serving to avoid everyone on Gihub seeing it.
help!! I have the same problem as @avirupd-egnaroinc.....Could anyone tell me the solution to this?
@liaomeng I replied to @avirupd-egnaroinc over on the tile-serving list. That's a better place than here for queries such as "I can't get this to work" (which in any case are unrelated to the issue here, which is that "Failed to read cmd on fd" messages are printed in a debug log, even when nothing is wrong).
I'd suggest that you post over there explaining what you've tried and what doesn't work. If you're unsure what information to provide try asking in the #osm or #osm-dev IRC channels on OFTC.
I would be interested in possible ways of finding what's the problem too. I have a very similar problem (metatiles are rendered correctly but PNG fail to be served). I couldn't find your answer on the list.
@cglacet The reply to @liaomeng applies to you too I think - this specific issue is about "Failed to read cmd on fd" messages are printed in a debug log when nothing is wrong. That doesn't sound like your main problem.
Sadly this is the only "bad thing" that seems to happen. I'm actually looking for a way to have any kind of debugging option (showing more debug messages would be nice) because I really have no idea what is happening, but renderD seems to never send anything to mod_tile (or apache I don't know). It may be a lot of things, but these tools are very laconic (or I have no idea on how to make them talk a bit to me).
Here is what is happening when the tile is built:
Jun 11 17:30:56 renderd[22663] <Debug>: Rendering projected coordinates 8 248 160 -> 18785164.071375|-6261721.357125 20037508.342800|-5009377.085700 to a 8 x 8 tile
Jun 11 17:31:00 renderd[22663] <Debug>: DEBUG: DONE TILE default 8 248-255 160-167 in 3.939 seconds
debug: Creating and writing a metatile to /var/lib/mod_tile/default/8/0/0/0/250/128.meta
Jun 11 17:31:00 renderd[22663] <Debug>: DEBUG: Sending render cmd(3 default 8/251/160) with protocol version 2 to fd 5
Jun 11 17:31:00 renderd[22663] <Info>: DEBUG: Failed to read cmd on fd 5
Jun 11 17:31:00 renderd[22663] <Debug>: DEBUG: Connection 0, fd 5 closed, now 0 left
You're seeing a "DEBUG: DONE TILE" message, which means that apache's sent the message via mod_tile to renderd, and renderd has created a metatile. You should be able to see a file in "/var/lib/mod_tile/default/8/0/0/0/250/128.meta" The fact that you can't then see that when you view it presumably in a web browser is a different issue - maybe there's a permissions issue somewhere, or whatever you've set up to view tiles isn't working.
The debug steps in https://switch2osm.org/manually-building-a-tile-server-16-04-2-lts/ may help a bit, specifically:
- Initiallly just try and view http://yourserveripaddress/hot/0/0/0.png (or whatever for your tile location)
- Run renderd in the foreground to see how it reacts to incoming commands
- Use something like “Switcheroo Redirector” to make your tiles appear via openstreetmap.org in Chrome or Chromium.
- Is already what I've done (the metatile is perfectly fine, I checked using meta2tile).
- Is the output I pasted just before (it stops there). Or outputs nothing if I ask for the same tile again.
- I'll try that now, thank you.
Is that normal that mapnik doesn't output anything btw (renderd is just wrapping everything even the outputs)?
"maybe there's a permissions issue somewhere" yes maybe, is there anything in particular you have in mind? My metatiles are owned by my postgresql user (is that the correct way to do?). Here is how my rights are defined:
$ ls -la /var/lib/mod_tile/default/8/0/0/0/250/128.meta /var/run/renderd/
-rw-r--r-- 1 postgres wheel 317572 Jun 11 17:31 /var/lib/mod_tile/default/8/0/0/0/250/128.meta
/var/run/renderd/:
drwxr-xr-x 5 postgres daemon 170 Jun 11 18:31 .
drwxrwxr-x 33 root daemon 1122 Jun 11 17:13 ..
-rw-r--r-- 1 postgres daemon 6 Jun 10 06:07 renderd.pid
srwxrwxrwx 1 postgres daemon 0 Jun 11 18:16 renderd.sock
-rw-r--r-- 1 postgres daemon 1143 Jun 11 18:31 renderd.stats
$ ls -la /usr/libexec/apache2/mod_tile.so
-rw-r--r-- 1 root wheel 130596 Jun 7 20:27 /usr/libexec/apache2/mod_tile.so
$ ls -la /usr/local/lib/mapnik
lrwxr-xr-x 1 cglacet admin 34 Jun 7 15:05 /usr/local/lib/mapnik -> ../Cellar/mapnik/3.0.13/lib/mapnik
$ dscacheutil -q group | grep -E -A 3 'daemon|wheel'
name: daemon
password: *
gid: 1
users: root
--
name: wheel
password: *
gid: 0
users: root
The commands I run to get started are:
$ sudo rm -rf /var/lib/mod_tile/default/*
$ sudo bash -c 'echo -e "\c" > /var/log/apache2/error-mode_tile.log'
$ sudo apachectl -k restart
and
$ sudo -u postgres renderd -f -c /usr/local/etc/renderd.conf
Thank you again for helping me 👍
ps, Apache says this:
[Sun Jun 11 18:46:33.398094 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(1289): [client ::1:58386] tile_translate: uri(/osm_tiles/8/251/160.png)
[Sun Jun 11 18:46:33.398104 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(1306): [client ::1:58386] tile_translate: testing baseuri(/osm_tiles/) name(default) extension(png)
[Sun Jun 11 18:46:33.398123 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(1352): [client ::1:58386] tile_translate: request for default was 251 160 256
[Sun Jun 11 18:46:33.398129 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(324): [client ::1:58386] get_storage_backend: Retrieving storage back end for tile layer 0 in pool 7fb683827628 and thread -1075362880
[Sun Jun 11 18:46:33.398134 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(338): [client ::1:58386] get_storage_backend: No storage backends for this lifecycle 7fb683827628, creating it in thread -1075362880
[Sun Jun 11 18:46:33.398138 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(353): [client ::1:58386] get_storage_backend: No storage backend in current lifecycle 7fb683827628 in thread -1075362880 for current tile layer 0
[Sun Jun 11 18:46:33.398180 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(1391): [client ::1:58386] tile_translate: op(tile_serve) xml(default) mime(image/png) z(8) x(251) y(160)
[Sun Jun 11 18:46:33.398188 2017] [tile:info] [pid 25867] [client ::1:58386] tile_storage_hook: handler(tile_serve), uri(/osm_tiles/8/251/160.png)
[Sun Jun 11 18:46:33.398213 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(374): [client ::1:58386] tile_state: determined state of default 251 160 8 on store 7fb68340c000: Tile size: -1, expired: 1 created: 0
[Sun Jun 11 18:46:33.398220 2017] [tile:debug] [pid 25867] ./src/mod_tile.c(176): [client ::1:58386] Connecting to renderd on Unix socket /var/run/renderd/renderd.sock
[Sun Jun 11 18:46:33.398241 2017] [tile:info] [pid 25867] [client ::1:58386] Requesting style(default) z(8) x(251) y(160) from renderer with priority 5
[Sun Jun 11 18:46:39.541360 2017] [authz_core:debug] [pid 25867] mod_authz_core.c(834): [client ::1:58386] AH01628: authorization result: granted (no directives)
[Sun Jun 11 18:46:39.541421 2017] [core:trace3] [pid 25867] request.c(296): [client ::1:58386] request authorized without authentication by access_checker_ex hook: /osm_tiles/8/251/160.png
And for the second request (once the tile has been generated):
...
[Sun Jun 11 18:51:02.012422 2017] [tile:debug] [pid 25869] ./src/mod_tile.c(1391): [client ::1:59381] tile_translate: op(tile_serve) xml(default) mime(image/png) z(8) x(251) y(160)
[Sun Jun 11 18:51:02.012433 2017] [tile:info] [pid 25869] [client ::1:59381] tile_storage_hook: handler(tile_serve), uri(/osm_tiles/8/251/160.png)
[Sun Jun 11 18:51:02.012472 2017] [tile:debug] [pid 25869] ./src/mod_tile.c(374): [client ::1:59381] tile_state: determined state of default 251 160 8 on store 7fb68340bfc0: Tile size: 317572, expired: 0 created: 1497199599
[Sun Jun 11 18:51:02.012540 2017] [authz_core:debug] [pid 25869] mod_authz_core.c(834): [client ::1:59381] AH01628: authorization result: granted (no directives)
[Sun Jun 11 18:51:02.012555 2017] [core:trace3] [pid 25869] request.c(296): [client ::1:59381] request authorized without authentication by access_checker_ex hook: /osm_tiles/8/251/160.png
What OS are you using? In an apache error log with "loglevel debug" set I see a "tile_state:" line but none of the "authorization" stuff that you get. I'm using Ubuntu 16.04 on a server that exactly matches https://wiki.openstreetmap.org/wiki/User:SomeoneElse/Ubuntu_1604_tileserver_load (which is very similar to but a different style from https://switch2osm.org/manually-building-a-tile-server-16-04-2-lts/ ). Perhaps you've got some different Apache modules loaded, perhaps manually or perhaps automatically because you're using a different OS or have installed something else that depends on them.
I haven't been through the older instructions https://switch2osm.org/serving-tiles/manually-building-a-tile-server-14-04/ for a while, and I suspect that you aren't following that to the letter since it says to use Mapnik 2.2 and you're using Mapnik 3.0 :)
Edit: I'm guessing that you're the same person as behind https://stackoverflow.com/questions/44469364 and my answer there may also help (briefly - it's on MacOS, so either find a "soup to nuts" guide for that platform or run Ubuntu in a VM).
I'm using OSX(10.12.4). The apache authorization stuff that I get is because my httpd.conf is loading mod_authz_core. The following line is displayed because I have LogLevel set to trace8 instead of debug.
Loaded Modules:
core_module (static)
so_module (static)
http_module (static)
mpm_prefork_module (static)
authn_file_module (shared)
authn_core_module (shared)
authz_host_module (shared)
authz_groupfile_module (shared)
authz_user_module (shared)
authz_core_module (shared)
access_compat_module (shared)
auth_basic_module (shared)
reqtimeout_module (shared)
ext_filter_module (shared)
filter_module (shared)
mime_module (shared)
log_config_module (shared)
env_module (shared)
headers_module (shared)
setenvif_module (shared)
version_module (shared)
slotmem_shm_module (shared)
unixd_module (shared)
status_module (shared)
autoindex_module (shared)
vhost_alias_module (shared)
negotiation_module (shared)
dir_module (shared)
alias_module (shared)
hfs_apple_module (shared)
tile_module (shared)
The complete apache configuration I use is the default one for my os.
Ah, I forgot to say that I've tried to use kosmtik, just to check if mapnik works, and everything works just fine.
Concerning Switcheroo Redirector, I don't think this would help since it just seems to be an URL rewriting plugin, for now I only try a simple "http://localhost/osm_tiles/8/251/160.png" which always get an empty response (ERR_EMPTY_RESPONSE).
I'm guessing that the problem comes from mod_tile (rights as you suggested), but I'm not entirely sure. I'll dig into this and come back as soon as I have something new, hopefully an error message somewhere or with gdb.
@cglacet Actually I'm guessing that there's a problem at the apache side, given that you can create metatiles, convert them manually to tiles at view them!
Ah, I think I found something. I found what a normal debug output is like, and it turns out there is something I'm completely missing:
[tile:info] [<pid>] tile_storage_hook: handler(tile_serve), uri(/osm_tiles/0/0/0.png)
[tile:debug] [<pid>] ./src/mod_tile.c(365): tile_state: determined state of default 0 0 0 on store 7f2cad89c790: Tile size: 8419, expired: 0 created: 1421366421
[authz_core:debug] [<pid>] mod_authz_core.c(828): AH01628: authorization result: granted (no directives)
[tile:debug] [<pid>] ./src/mod_tile.c(1183): tile_handler_serve: xml(default) z(0) x(0) y(0)
I never have tile_handler_serve in my log, I checked a bit deeper and the function is actually never called. Which is probably the reason why no tiles are ever served. I'm not sure to understand the process yet so I can't tell who is responsible for throwing that particular request.
The same bug I have also happens when I request "http://localhost/mod_tile":
[tile:debug] [pid 9785] ./src/mod_tile.c(1301): [client ::1:56175] tile_translate: uri(/mod_tile)
[tile:info] [pid 9785] [client ::1:56175] tile_translate: retrieving global mod_tile stats
[tile:info] [pid 9785] [client ::1:56175] tile_storage_hook: handler(tile_mod_stats), uri(/mod_tile)
[authz_core:debug] [pid 9785] mod_authz_core.c(834): [client ::1:56175] AH01628: authorization result: granted (no directives)
[core:trace3] [pid 9785] request.c(296): [client ::1:56175] request authorized without authentication by access_checker_ex hook: /mod_tile
And yes, I also asked the question on stackoverflow.
I finally found who was guilty ! I tried to remove all hooks except the tile_handler_serve from mod_tile.c, then a bunch of things happened:
mod_hfs_apple2.c(145): [client ::1:65478] mod_hfs_apple: / is case-insensitive
mod_hfs_apple2.c(145): [client ::1:65478] mod_hfs_apple: /var/ is case-insensitive
d_hfs_apple2.c(145): [client ::1:65478] mod_hfs_apple: /Library/WebServer/Documents/ is case-insensitive
mod_hfs_apple2.c(145): [client ::1:65478] mod_hfs_apple: /Library/WebServer/CGI-Executables/ is case-insensitive
mod_hfs_apple2.c(145): [client ::1:65478] mod_hfs_apple: /usr/share/httpd/icons/ is case-insensitive
mod_hfs_apple2.c(145): [client ::1:65478] mod_hfs_apple: .*\\.\\.namedfork/ is case-sensitive
mod_hfs_apple2.c(363): [client ::1:65478] mod_hfs_apple: compare_paths / vs /Library/WebServer/Documents/osm_tiles/, related=1
mod_hfs_apple2.c(363): [client ::1:65478] mod_hfs_apple: compare_paths /var/ vs /Library/WebServer/Documents/osm_tiles/, related=0
mod_hfs_apple2.c(363): [client ::1:65478] mod_hfs_apple: compare_paths /Library/WebServer/Documents/ vs /Library/WebServer/Documents/osm_tiles/, related=1
mod_hfs_apple2.c(363): [client ::1:65478] mod_hfs_apple: compare_paths /Library/WebServer/CGI-Executables/ vs /Library/WebServer/Documents/osm_tiles/, related=0
mod_hfs_apple2.c(363): [client ::1:65478] mod_hfs_apple: compare_paths /usr/share/httpd/icons/ vs /Library/WebServer/Documents/osm_tiles/, related=0
mod_hfs_apple2.c(363): [client ::1:65478] mod_hfs_apple: compare_paths .*\\.\\.namedfork/ vs /Library/WebServer/Documents/osm_tiles/, related=0
mod_hfs_apple2.c(384): [client ::1:65478] mod_hfs_apple: Final check compares: /Library/WebServer/Documents/osm_tiles vs /Library/WebServer/Documents/, length 28
mod_hfs_apple2.c(397): [client ::1:65478] mod_hfs_apple: Allowing access with matching directory. filename = /Library/WebServer/Documents/osm_tiles
To fix this problem simply went in /etc/apache2/httpd.conf and comment the following line:
LoadModule hfs_apple_module libexec/apache2/mod_hfs_apple.so
This hack is not very satisfactory to me, the goal would be to correct mod_tile. The part that looks to need a fix lies in mod_tile.c:1643:
static void register_hooks(__attribute__((unused)) apr_pool_t *p)
{
...
ap_hook_translate_name(tile_translate, NULL, NULL, APR_HOOK_MIDDLE);
...
}
For now I don't have the courage to find a real solution, just having a quick look I found this strange line that may cause a problem to anyone (eg., mod_hfs_apple) trying to read the request. In mod_tile.c:1278:
static int tile_translate(request_rec *r)
{
...
r->filename = NULL;
...
}
Thanks for your help @SomeoneElseOSM !!