Rendering/extracting .png tiles from metatiles: "Failed to read cmd on fd 4" (OSX)

Question

I am trying to run a tile server using mapnik and mod_tile. For now, I am able to produce metatiles from (zoom,x,y)-requests but I don't understand why tiles are never actually served (as png). The reasons seems to be the following error: Failed to read cmd on FD 4

I have checked that metatiles correspond to what I am asking using this tool and everything looks just fine.

Just in case, here is what I have in terms of debug/info:

$ sudo -u postgres renderd -f -c /usr/local/etc/renderd.conf
renderd[16811] <Info>: config renderd: unix socketname=/var/run/renderd/renderd.sock
renderd[16811] <Info>: config renderd: num_threads=4
renderd[16811] <Info>: config renderd: num_slaves=0
renderd[16811] <Info>: config renderd: tile_dir=/var/lib/mod_tile
renderd[16811] <Info>: config renderd: stats_file=/var/run/renderd/renderd.stats
renderd[16811] <Info>: config mapnik:  plugins_dir=/usr/local/lib/mapnik/input
renderd[16811] <Info>: config mapnik:  font_dir=/usr/local/lib/mapnik/fonts
renderd[16811] <Info>: config mapnik:  font_dir_recurse=1
renderd[16811] <Info>: config renderd(0): Active
renderd[16811] <Info>: config renderd(0): unix socketname=/var/run/renderd/renderd.sock
renderd[16811] <Info>: config renderd(0): num_threads=4
renderd[16811] <Info>: config renderd(0): tile_dir=/var/lib/mod_tile
renderd[16811] <Info>: config renderd(0): stats_file=/var/run/renderd/renderd.stats
renderd[16811] <Info>: config map 0:   name(default) file(openstreetmap-carto/mapnik.xml) uri(/osm_tiles/) htcp() host(localhost)
renderd[16811] <Info>: Initialising unix server socket on /var/run/renderd/renderd.sock
renderd[16811] <Debug>: Created server socket 3
renderd[16811] <Info>: Renderd is using mapnik version 3.0.13  
...
...
Running in foreground mode...
renderd[16811] <Debug>: Starting stats thread
debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile
debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile
renderd[16811] <Info>: Loading parameterization function for
debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile
debug: init_storage_backend: initialising file storage backend at: /var/lib/mod_tile
renderd[16811] <Info>: Loading parameterization function for
renderd[16811] <Info>: Loading parameterization function for
renderd[16811] <Info>: Loading parameterization function for
Mapnik LOG> 2017-06-10 04:07:37: warning: unable to find face-name 'unifont Medium' in FontSet 'fontset-0'

This particular font fails to load, but I'm quite sure its just a duplicate in my mapnik.xml file (it comes with an upper and lower 'u'). The final output after starting the render daemon is (4 times):

Jun 10 04:07:39  renderd[16811] <Debug>: Using web Mercator projection settings

Then I just clean everything and restart apache:

$ rm -rf /var/lib/mod_tile/default/*
$ sudo bash -c 'echo -e "\c" > /var/log/apache2/error-mode_tile.log'
$ sudo apachectl -k restart

Finally I try to load a particular tile, say tile(8,251,160) using my local address: localhost/osm_tiles/8/251/160.png. The render daemon gives the following debug output:

renderd[17950] <Debug>: DEBUG: Got incoming connection, fd 4, number 1
renderd[17950] <Debug>: DEBUG: Got incoming request with protocol version 2
renderd[17950] <Debug>: DEBUG: Got command RenderPrio fd(4) xml(default), z(8), x(251), y(160), mime(image/png), options()
renderd[17950] <Debug>: DEBUG: START TILE default 8 248-255 160-167, new metatile
renderd[17950] <Debug>: Rendering projected coordinates 8 248 160 -> 18785164.071375|-6261721.357125 20037508.342800|-5009377.085700 to a 8 x 8 tile
renderd[17950] <Debug>: DEBUG: DONE TILE default 8 248-255 160-167 in 6.177 seconds
debug: Creating and writing a metatile to /var/lib/mod_tile/default/8/0/0/0/250/128.meta
renderd[17950] <Debug>: DEBUG: Sending render cmd(3 default 8/251/160) with protocol version 2 to fd 4
renderd[17950] <Info>: DEBUG: Failed to read cmd on fd 4
renderd[17950] <Debug>: DEBUG: Connection 0, fd 4 closed, now 0 left

Here is where the problem appears "Failed to read cmd on fd 4", I tried to look for this online but couldn't find a clear answer to it. Here is the corresponding apache trace:

[core:trace5] [pid 18636] protocol.c(643): [client ::1:56548] Request received from client: GET /osm_tiles/8/251/160.png HTTP/1.1
...
[tile:debug] [pid 18636] ./src/mod_tile.c(1306): [client ::1:56548] tile_translate: testing baseuri(/osm_tiles/) name(default) extension(png)
[tile:debug] [pid 18636] ./src/mod_tile.c(1352): [client ::1:56548] tile_translate: request for default was 251 160 256
[tile:debug] [pid 18636] ./src/mod_tile.c(324): [client ::1:56548] get_storage_backend: Retrieving storage back end for tile layer 0 in pool 7fb684031628 and thread -1075362880
[tile:debug] [pid 18636] ./src/mod_tile.c(338): [client ::1:56548] get_storage_backend: No storage backends for this lifecycle 7fb684031628, creating it in thread -1075362880
[tile:debug] [pid 18636] ./src/mod_tile.c(353): [client ::1:56548] get_storage_backend: No storage backend in current lifecycle 7fb684031628 in thread -1075362880 for current tile layer 0
[tile:debug] [pid 18636] ./src/mod_tile.c(1391): [client ::1:56548] tile_translate: op(tile_serve) xml(default) mime(image/png) z(8) x(251) y(160)
[tile:info] [pid 18636] [client ::1:56548] tile_storage_hook: handler(tile_serve), uri(/osm_tiles/8/251/160.png)
[tile:debug] [pid 18636] ./src/mod_tile.c(374): [client ::1:56548] tile_state: determined state of default 251 160 8 on store 7fb683502f90: Tile size: 317572, expired: 0 created: 1497065892
[tile:debug] [pid 18335] ./src/mod_tile.c(176): [client ::1:56547] Connecting to renderd on Unix socket /var/run/renderd/renderd.sock
[tile:info] [pid 18335] [client ::1:56547] Requesting style(default) z(8) x(251) y(160) from renderer with priority 5
[authz_core:debug] [pid 18636] mod_authz_core.c(834): [client ::1:56548] AH01628: authorization result: granted (no directives)
[core:trace3] [pid 18636] request.c(296): [client ::1:56548] request authorized without authentication by access_checker_ex hook: /osm_tiles/8/251/160.png

And then it's over, nothing else happens. I really don't know much about this, so any suggestion is welcome. I can also give my config files if it helps.

Answer 1

Just in case someone happen to have the save issue. The problem came from an apple module that is loaded by default by apache (mod_hfs_apple.so). To fix this problem I simply went in /etc/apache2/httpd.conf and commented 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; 
   ...
}

Answer 2

The "Failed to read cmd on fd" message isn't actually an error, it's actually just a bit of debug logging. See the top of https://github.com/openstreetmap/mod_tile/issues/77 for details about the change that introduced it. If you just want to "not see that message", then the version that I forked from that (for some other changes) https://github.com/SomeoneElseOSM/mod_tile might be useful, as I removed that message there.

However, this won't fix your underlying problem (getting a working tile server) - for that I'd suggest either finding a "soup to nuts" installation guide for MacOS, or to start with so that you can understand how things fit together, a tile server in an Ubuntu VM.