tilemill-project / tilemill

TileMill is a modern map design studio
https://tilemill-project.github.io/tilemill/
BSD 3-Clause "New" or "Revised" License
3.11k stars 527 forks source link

"Export process died" - but it didn't. #2163

Open stevage opened 10 years ago

stevage commented 10 years ago

On some freshly built servers, all exports are failing with "Export process died":

screenshot 2013-11-22 12 16 12

Meanwhile, some of these exports have actually succeeded:

-rw-rw-r-- 1 mapbox mapbox   6795538 Nov 21 17:37 Edglobe_36d3bd.pdf
-rw-rw-r-- 1 mapbox mapbox     61236 Nov 21 14:47 Edglobe_7c0b57.png
-rw-rw-r-- 1 mapbox mapbox     61236 Nov 21 14:38 Edglobe_f3f38b.png
-rw-rw-r-- 1 mapbox mapbox   5053326 Nov 21 17:36 Edglobe.pdf
-rw-rw-r-- 1 mapbox mapbox    215827 Nov 22 12:16 Edglobe.png
-rw-rw-r-- 1 mapbox mapbox     23563 Nov 21 16:55 Melbourne_ebe75d.export
-rw-rw-r-- 1 mapbox mapbox         0 Nov 21 16:49 Melbourne_ebe75d.export-failed
-rw-r--r-- 1 mapbox mapbox 312309760 Nov 21 16:55 Melbourne_ebe75d.mbtiles
-rw-rw-r-- 1 mapbox mapbox     23557 Nov 21 16:34 Melbourne.export
-rw-rw-r-- 1 mapbox mapbox         0 Nov 21 16:29 Melbourne.export-failed
-rw-rw-r-- 1 mapbox mapbox        35 Nov 21 16:30 Melbourne.mbtiles.crashlog

I don't see anything abnormal in the log:

[tilemill] [tilemill-ui] [millstone] detected extension of '.csv' for '/usr/share/mapbox/cache/43473991-Cities.csv'
[tilemill] [tilemill-ui] [millstone] finished processing '/usr/share/mapbox/project/Edglobe'
[tilemill] [tilemill-ui] Rendering file
[tilemill] [tilemill-ui] Completing export process
[tilemill] [tilemill-ui] Exiting process [tm-Edglobe_36d3bd.pdf]
[tilemill] [tilemill-ui] Note: Unknown option "updatesVersion" in config file.
[tilemill] [tilemill-ui] Note: Unknown option "updatesTime" in config file.
[tilemill] [tilemill-ui] [millstone] processing style 'style.mss'
[tilemill] [tilemill-ui] [millstone] processing style 'Label'
[tilemill] [tilemill-ui] [millstone] processing layer 'countries'
[tilemill] [tilemill-ui] [millstone] processing layer 'country'
[tilemill] [tilemill-ui] [millstone] processing layer 'lakes'
[tilemill] [tilemill-ui] [millstone] processing layer 'state'
[tilemill] [tilemill-ui] [millstone] processing layer 'immigrationline1'
[tilemill] [tilemill-ui] [millstone] processing layer 'immigrationline2'
[tilemill] [tilemill-ui] [millstone] processing layer 'immigrationline3'
[tilemill] [tilemill-ui] [millstone] processing layer 'immigrationline5'
[tilemill] [tilemill-ui] [millstone] processing layer 'immigrationline6'
[tilemill] [tilemill-ui] [millstone] processing layer 'immigrationline7'
[tilemill] [tilemill-ui] [millstone] processing layer 'the20school'
[tilemill] [tilemill-ui] [millstone] processing layer 'cities'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/da493aa5-10m-lakes/da493aa5-10m-lakes.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.kml' for '/usr/share/mapbox/cache/e4ec760c-ImmigrationLine1.kml'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/80b26bd1-10m-admin-1-states-provinces-lines/80b26bd1-10m-admin-1-states-provinces-lines.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.kml' for '/usr/share/mapbox/cache/9ffab7d0-ImmigrationLine2.kml'
[tilemill] [tilemill-ui] [millstone] detected extension of '.kml' for '/usr/share/mapbox/cache/41a8605c-ImmigrationLine3.kml'
[tilemill] [tilemill-ui] [millstone] detected extension of '.kml' for '/usr/share/mapbox/cache/9dc54ad9-ImmigrationLine5.kml'
[tilemill] [tilemill-ui] [millstone] detected extension of '.kml' for '/usr/share/mapbox/cache/81d1f5c1-ImmigrationLine6.kml'
[tilemill] [tilemill-ui] [millstone] detected extension of '.kml' for '/usr/share/mapbox/cache/e1e33427-ImmigrationLine7.kml'
[tilemill] [tilemill-ui] [millstone] detected extension of '.kml' for '/usr/share/mapbox/cache/e26c0332-The%20School.kml'
[tilemill] [tilemill-ui] [millstone] detected extension of '.csv' for '/usr/share/mapbox/cache/43473991-Cities.csv'
[tilemill] [tilemill-ui] [millstone] finished processing '/usr/share/mapbox/project/Edglobe'
[tilemill] [tilemill-ui] Rendering file
[tilemill] [tilemill-ui] Completing export process
[tilemill] [tilemill-ui] Exiting process [tm-Edglobe.png]

The biggest problem here is there no download link for the exported image, so I need to actually SSH in to the server to get it.

Happy to provide more information if needed. Tilemill "Version 0.10.1 (v0.10.1)" installed using http://github.com/stevage/tilemill-server.

springmeyer commented 10 years ago

hmmm, not seen this before. What does:

apt-cache policy libmapnik

Give? I worry you may have a conflicting mapnik version coming from: https://github.com/stevage/tilemill-server/blob/9027d8b147e72c0db91f74f42dba0fdd20b0510b/install-postgis.sh#L31

stevage commented 10 years ago
libmapnik:
  Installed: 2.2.0+dev20121011.git.38d9163-1~quantal1
  Candidate: 2.2.0+dev20121011.git.38d9163-1~quantal1
  Version table:
 *** 2.2.0+dev20121011.git.38d9163-1~quantal1 0
        500 http://ppa.launchpad.net/developmentseed/mapbox/ubuntu/ quantal/main amd64 Packages
        100 /var/lib/dpkg/status

Do you have any suggested changes to my script? Happy to try them out...

stevage commented 10 years ago

Hi Dane, I'm still getting this same issue, new servers with the latest version of my build scripts (which have no more kakrueger): https://github.com/stevage/saltymill

apt-cache policy libmapnik
libmapnik:
  Installed: 2.2.0+dev20121011.git.38d9163-1~quantal1
  Candidate: 2.2.0+dev20121011.git.38d9163-1~quantal1
  Version table:
 *** 2.2.0+dev20121011.git.38d9163-1~quantal1 0
        500 http://ppa.launchpad.net/developmentseed/mapbox/ubuntu/ quantal/main amd64 Packages
        100 /var/lib/dpkg/status

Any ideas? No one else reports this? Again nothing suspicious in /var/log/tilemill.log:

[tilemill] [tilemill-ui] [millstone] finished processing '/usr/share/mapbox/project/control-room'
[tilemill] [tilemill-ui] Rendering export
[tilemill] [tilemill-ui] Persisting state in /usr/share/mapbox/export/control-room.export every minute
[tilemill] [tilemill-ui] Completing export process
[tilemill] [tilemill-ui] Exiting process [tm-control-room.mbtiles]
springmeyer commented 10 years ago

I presume given the exports are actually working fine there is some communication problem between the client and server. Perhaps it is just a delay of some sort that is triggering this....

springmeyer commented 10 years ago

Could you try putting a console.log(data) inside this function: https://github.com/mapbox/tilemill/blob/master/models/Exports.server.bones#L104. And then run some exports that seemingly fail and share the logs again?

stevage commented 10 years ago

Thanks Dane. (Please ignore the 'check' and 'done' in the following

[tilemill] { progress: 0,
[tilemill]   status: 'waiting',
[tilemill]   id: '1392943346566',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 8 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ 32.4316, 37.3702, 33.5742, 37.7881 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 8 }
[tilemill] { progress: 0,
[tilemill]   status: 'processing',
[tilemill]   id: '1392943346566',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 8 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ 32.4316, 37.3702, 33.5742, 37.7881 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 8,
[tilemill]   pid: 6706,
[tilemill]   created: 1392943360232 }
[tilemill] { progress: 0,
[tilemill]   status: 'error',
[tilemill]   id: '1392811630599',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'road-trip',
[tilemill]   zooms: [ 0, 7 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'road-trip.mbtiles',
[tilemill]   bbox: [ -180, -85.0511, 180, 85.0511 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 7,
[tilemill]   pid: 16993,
[tilemill]   created: 1392811645135,
[tilemill]   error: 'Export process failed (see tilemill log for details)' }
[tilemill] { progress: 0,
[tilemill]   status: 'error',
[tilemill]   id: '1392812232786',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 6 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ -180, -85.0511, 180, 85.0511 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 6,
[tilemill]   pid: 17187,
[tilemill]   created: 1392812243712,
[tilemill]   error: 'Export process died' }
[tilemill] { progress: 0,
[tilemill]   status: 'error',
[tilemill]   id: '1392943109263',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 4 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ 22.5, 42.033, 25.3125, 42.5531 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 4,
[tilemill]   pid: 6438,
[tilemill]   created: 1392943123175,
[tilemill]   error: 'Export process died' }
[tilemill] { progress: 0,
[tilemill]   status: 'processing',
[tilemill]   id: '1392943346566',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 8 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ 32.4316, 37.3702, 33.5742, 37.7881 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 8,
[tilemill]   pid: 6706,
[tilemill]   created: 1392943360232 }
[tilemill] [tilemill-ui] Note: Unknown option "updatesVersion" in config file.
[tilemill] [tilemill-ui] Note: Unknown option "updatesTime" in config file.
[tilemill] [tilemill-ui] [millstone] processing style 'style.mss'
[tilemill] [tilemill-ui] [millstone] processing style 'labels.mss'
[tilemill] [tilemill-ui] [millstone] processing layer 'land'
[tilemill] [tilemill-ui] [millstone] processing layer 'urban'
[tilemill] [tilemill-ui] [millstone] processing layer 'lakes'
[tilemill] [tilemill-ui] [millstone] processing layer 'geo-lines'
[tilemill] [tilemill-ui] [millstone] processing layer 'international_boundaries'
[tilemill] [tilemill-ui] [millstone] processing layer 'map-units'
[tilemill] [tilemill-ui] [millstone] processing layer 'subnational_boundaries'
[tilemill] [tilemill-ui] [millstone] processing layer 'country-labels'
[tilemill] [tilemill-ui] [millstone] processing layer 'cities'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/3d2a6643-10m-land/3d2a6643-10m-land.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/da493aa5-10m-lakes/da493aa5-10m-lakes.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/0d81b6b2-10m-geographic-lines/0d81b6b2-10m-geographic-lines.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/ee9451c2-10m-urban-areas/ee9451c2-10m-urban-areas.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/54519c81-10m-admin-0-boundary-lines-map-units/54519c81-10m-admin-0-boundary-lines-map-units.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/16c795c6-10m-admin-0-boundary-lines-land/16c795c6-10m-admin-0-boundary-lines-land.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/80b26bd1-10m-admin-1-states-provinces-lines/80b26bd1-10m-admin-1-states-provinces-lines.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/3e1431a6-10m-admin-0-country-points/3e1431a6-10m-admin-0-country-points.zip'
[tilemill] [tilemill-ui] [millstone] detected extension of '.zip' for '/usr/share/mapbox/cache/14bd1506-10m-populated-places-simple/14bd1506-10m-populated-places-simple.zip'
[tilemill] [tilemill-ui] [millstone] finished processing '/usr/share/mapbox/project/control-room'
[tilemill] [tilemill-ui] Rendering export
[tilemill] [tilemill-ui] Persisting state in /usr/share/mapbox/export/control-room_4fb244.export every minute
[tilemill] [tilemill-ui] Completing export process
[tilemill] [tilemill-ui] Exiting process [tm-control-room_4fb244.mbtiles]
[tilemill] { progress: 0,
[tilemill]   status: 'error',
[tilemill]   id: '1392811630599',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'road-trip',
[tilemill]   zooms: [ 0, 7 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'road-trip.mbtiles',
[tilemill]   bbox: [ -180, -85.0511, 180, 85.0511 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 7,
[tilemill]   pid: 16993,
[tilemill]   created: 1392811645135,
[tilemill]   error: 'Export process failed (see tilemill log for details)' }
[tilemill] { progress: 0,
[tilemill]   status: 'error',
[tilemill]   id: '1392812232786',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 6 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ -180, -85.0511, 180, 85.0511 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 6,
[tilemill]   pid: 17187,
[tilemill]   created: 1392812243712,
[tilemill]   error: 'Export process died' }
[tilemill] { progress: 0,
[tilemill]   status: 'error',
[tilemill]   id: '1392943109263',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 4 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ 22.5, 42.033, 25.3125, 42.5531 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 4,
[tilemill]   pid: 6438,
[tilemill]   created: 1392943123175,
[tilemill]   error: 'Export process died' }
[tilemill] { progress: 0,
[tilemill]   status: 'processing',
[tilemill]   id: '1392943346566',
[tilemill]   format: 'mbtiles',
[tilemill]   project: 'control-room',
[tilemill]   zooms: [ 0, 8 ],
[tilemill]   metatile: 2,
[tilemill]   filename: 'control-room.mbtiles',
[tilemill]   bbox: [ 32.4316, 37.3702, 33.5742, 37.7881 ],
[tilemill]   minzoom: 0,
[tilemill]   maxzoom: 8,
[tilemill]   pid: 6706,
[tilemill]   created: 1392943360232 }
springmeyer commented 10 years ago

thanks. can you also share the logs? and are you testing one export at a time or sending multiple?

stevage commented 10 years ago

Sorry, that server's been rebuilt now so I can't immediately grab that output, but I just noticed something interesting while doing a command line export (which I didn't know existed):

...

[millstone] processing layer 'waterpoly'
[millstone] finished processing '/usr/share/mapbox/project/cycletour'
 done.
Rendering export
Creating new job /mnt/mapbox/cycletour-new.export
Persisting state in /mnt/mapbox/cycletour-new.export every minute
Writing errors to /mnt/mapbox/cycletour-new.export-failed
[1m 59s] Part(1/1) 100.0000% 170/170 @ 6/s | 0s left | ✓ 162 ■ 8 □ 0 fail 0
finished
Completing export process
Exiting process [tm-cycletour-new.mbtiles]
Segmentation fault

So, the export seems to crash right at the very end.

springmeyer commented 10 years ago

thanks a lot for the further details. It looks like this is a symptom of https://github.com/mapnik/node-mapnik/issues/251. So basically yes, the crash is during the exit and should not be happening. It has seemed like a minor problem but this case underlines why its not minor.

stevage commented 10 years ago

Just mentioning that this is still happening on newly built servers (using apt-get install). Do you still want those logs?

springmeyer commented 10 years ago

The most useful thing would be to test with the latest node v0.10.x version and see if it still occurs and if it does then try to document the simplest and most reliable way to replicate it.

stevage commented 10 years ago

Ok, I've upgraded to NodeJS v0.10.29 and it still occurs with TileMill v0.10.1-293-g697c86c.

Now, this is interesting. I set up a clean (Ubuntu Trusty) server and installed TileMill manually, rather than through my automatic deployment system (http://github.com/stevage/saltymill). The export failure doesn't happen.

So that gives us something to work with. Most likely some kind of clash with salt, nginx, PostGIS, OSM2PGSQL or OSRM. I should be able to narrow it down further.

springmeyer commented 10 years ago

If you are installing tilemill master (like I see you are doing here: https://github.com/stevage/saltymill/blob/master/tilemill/tilemillinstall.sls#L89), you don't anymore need to install an external mapnik because node-mapnik is shipped with standalone binaries. So, you should be able to remove all mapnik ppas and apt-get installs.

stevage commented 10 years ago

FYI, I'm just installing the APT version, like so:

sudo apt-get install -y python-software-properties
sudo add-apt-repository ppa:developmentseed/mapbox
sudo apt-get update
sudo apt-get install -y tilemill
springmeyer commented 10 years ago

sure, when installing the apt version its safer to do:

sudo apt-get install -y tilemill libmapnik

But, I'm confused: the APT version is the one that has the problem but tilemill master with npm install does not and works fine?

stevage commented 10 years ago

Narrowing it down even further, this configuration also produces the export failure:

{
  "files": "/usr/share/mapbox",
  "server": true,
  "port": "20009",
  "tilePort": "5008",
  "coreUrl": "130.56.250.5:5002",
  "tileUrl": "130.56.250.5:5008",
  "listenHost": "0.0.0.0"
}

That is - the tile server is exposed directly to the world on port 5008, but the interface goes through HTTP auth from 5002 to 20009. I was really hoping this would work, because that's a configuration that would work for me.

So...I think my question now becomes, "How can I make HTTP auth and map exports work at the same time?"

But, I'm confused: the APT version is the one that has the problem but tilemill master with npm install does not and works fine?

Everything I've reported in the last few days is from APT installs. My scripts for installing dev builds broke when I switched to using Trusty, so I haven't been able to test that.

springmeyer commented 10 years ago

So...I think my question now becomes, "How can I make HTTP auth and map exports work at the same time?"

Good job narrowing it down. However this seems like something that will be tricky to debug and not something I feel like I have time to pursue right now.

stevage commented 10 years ago

Understood. Do you happen to know if anyone else has made this work? How else do people run TileMill server-side without giving the whole internet access to their projects?

springmeyer commented 10 years ago

Do you happen to know if anyone else has made this work?

No I don't.

How else do people run TileMill server-side without giving the whole internet access to their projects?

The primary usecase of TileMill on servers is only for command line/batch rendering and not exports through the UI. So I think this bug has likely always exited and few if no others have run into it.

stevage commented 10 years ago

SOLVED! :D

Ok, it turns out that part of the problem was my misunderstanding of this line in /etc/tilemill/tilemill.config:

  "coreUrl": "192.168.1.50:80",

I thought it had to be a publicly accessible URL (ie, presented to the browser), but I guess it's used for some internal facing services.

So the simple solution for me is to leave TileMill running on 20009 locally, port forwarded through nginx on port 80 with HTTP auth, and to leave the config line as 20009:

  "coreUrl": "192.168.1.50:80",

So I don't know if it's even a bug at this point, but just a kind of limitation: "coreUrl must be a locally accessible IP address and port combination that does not require any authentication".

Thanks very much for your help in figuring it out.