Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Parallel temp feature writes using --write-threads argument #213

Merged
merged 5 commits into from
May 6, 2022

Conversation

msbarry
Copy link
Contributor

@msbarry msbarry commented May 5, 2022

Fixes #118 by adding a --write-threads argument that can control the number of threads writing temporary features in parallel. It defaults to 1 thread for <48 cpus, then an additional writer thread per 32 cpus after that.

Since this could result in smaller unfinished chunks, also pack small chunks into fewer larger chunks that can be sorted in-memory together during the sort step.

@github-actions
Copy link

github-actions bot commented May 5, 2022

Base 3589fc6 This Branch 74ef7cd
0:01:38 DEB [mbtiles] - Tile stats:
0:01:38 DEB [mbtiles] - z0 avg:7.9k max:7.9k
0:01:38 DEB [mbtiles] - z1 avg:4k max:4k
0:01:38 DEB [mbtiles] - z2 avg:9.4k max:9.4k
0:01:38 DEB [mbtiles] - z3 avg:3.9k max:6.4k
0:01:38 DEB [mbtiles] - z4 avg:1.6k max:4.6k
0:01:38 DEB [mbtiles] - z5 avg:1.4k max:8.1k
0:01:38 DEB [mbtiles] - z6 avg:1.4k max:24k
0:01:38 DEB [mbtiles] - z7 avg:1k max:56k
0:01:38 DEB [mbtiles] - z8 avg:475 max:113k
0:01:38 DEB [mbtiles] - z9 avg:298 max:279k
0:01:38 DEB [mbtiles] - z10 avg:165 max:232k
0:01:38 DEB [mbtiles] - z11 avg:107 max:132k
0:01:38 DEB [mbtiles] - z12 avg:86 max:118k
0:01:38 DEB [mbtiles] - z13 avg:72 max:109k
0:01:38 DEB [mbtiles] - z14 avg:68 max:257k
0:01:38 DEB [mbtiles] - all avg:71 max:0
0:01:38 DEB [mbtiles] -  # features: 5,286,636
0:01:38 DEB [mbtiles] -     # tiles: 4,115,449
0:01:38 INF [mbtiles] - Finished in 23s cpu:42s avg:1.8
0:01:38 INF [mbtiles] -   read    1x(7% 2s wait:19s)
0:01:38 INF [mbtiles] -   encode  2x(45% 10s wait:6s)
0:01:38 INF [mbtiles] -   write   1x(37% 9s sys:1s wait:13s)
0:01:39 INF - Finished in 1m39s cpu:2m51s gc:3s avg:1.7
0:01:39 INF - FINISHED!
0:01:39 INF - 
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	overall          1m39s cpu:2m51s gc:3s avg:1.7
0:01:39 INF - 	lake_centerlines 2s cpu:3s avg:1.8
0:01:39 INF - 	  read     1x(80% 2s)
0:01:39 INF - 	  process  2x(13% 0.3s wait:2s)
0:01:39 INF - 	  write    1x(0% 0s wait:2s)
0:01:39 INF - 	water_polygons   23s cpu:39s gc:2s avg:1.7
0:01:39 INF - 	  read     1x(64% 14s sys:1s wait:2s)
0:01:39 INF - 	  process  2x(26% 6s wait:12s)
0:01:39 INF - 	  write    1x(3% 0.7s wait:22s)
0:01:39 INF - 	natural_earth    10s cpu:14s avg:1.4
0:01:39 INF - 	  read     1x(75% 8s sys:1s done:1s)
0:01:39 INF - 	  process  2x(16% 2s wait:8s)
0:01:39 INF - 	  write    1x(0% 0s wait:9s)
0:01:39 INF - 	osm_pass1        3s cpu:6s avg:1.8
0:01:39 INF - 	  read     1x(2% 0.1s wait:3s)
0:01:39 INF - 	  parse    1x(63% 2s)
0:01:39 INF - 	  process  1x(50% 2s wait:1s)
0:01:39 INF - 	osm_pass2        26s cpu:52s avg:2
0:01:39 INF - 	  read     1x(0% 0s wait:13s done:13s)
0:01:39 INF - 	  process  2x(74% 19s)
0:01:39 INF - 	  write    1x(1% 0.4s wait:26s)
0:01:39 INF - 	boundaries       0s cpu:0.1s avg:1.9
0:01:39 INF - 	sort             4s cpu:5s avg:1.2
0:01:39 INF - 	  worker  1x(69% 3s)
0:01:39 INF - 	mbtiles          23s cpu:42s avg:1.8
0:01:39 INF - 	  read    1x(7% 2s wait:19s)
0:01:39 INF - 	  encode  2x(45% 10s wait:6s)
0:01:39 INF - 	  write   1x(37% 9s sys:1s wait:13s)
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	features	269MB
0:01:39 INF - 	mbtiles	514MB
-rw-r--r-- 1 runner docker 55M May  6 01:58 run.jar
0:01:39 DEB [mbtiles] - Tile stats:
0:01:39 DEB [mbtiles] - z0 avg:7.9k max:7.9k
0:01:39 DEB [mbtiles] - z1 avg:4k max:4k
0:01:39 DEB [mbtiles] - z2 avg:9.4k max:9.4k
0:01:39 DEB [mbtiles] - z3 avg:3.9k max:6.4k
0:01:39 DEB [mbtiles] - z4 avg:1.6k max:4.6k
0:01:39 DEB [mbtiles] - z5 avg:1.4k max:8.1k
0:01:39 DEB [mbtiles] - z6 avg:1.4k max:24k
0:01:39 DEB [mbtiles] - z7 avg:1k max:56k
0:01:39 DEB [mbtiles] - z8 avg:475 max:113k
0:01:39 DEB [mbtiles] - z9 avg:298 max:279k
0:01:39 DEB [mbtiles] - z10 avg:165 max:232k
0:01:39 DEB [mbtiles] - z11 avg:107 max:132k
0:01:39 DEB [mbtiles] - z12 avg:86 max:118k
0:01:39 DEB [mbtiles] - z13 avg:72 max:109k
0:01:39 DEB [mbtiles] - z14 avg:68 max:257k
0:01:39 DEB [mbtiles] - all avg:71 max:0
0:01:39 DEB [mbtiles] -  # features: 5,286,636
0:01:39 DEB [mbtiles] -     # tiles: 4,115,449
0:01:39 INF [mbtiles] - Finished in 25s cpu:44s avg:1.8
0:01:39 INF [mbtiles] -   read    1x(7% 2s wait:21s)
0:01:39 INF [mbtiles] -   encode  2x(44% 11s wait:6s)
0:01:39 INF [mbtiles] -   write   1x(35% 9s wait:13s)
0:01:39 INF - Finished in 1m39s cpu:2m50s gc:3s avg:1.7
0:01:39 INF - FINISHED!
0:01:39 INF - 
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	overall          1m39s cpu:2m50s gc:3s avg:1.7
0:01:39 INF - 	lake_centerlines 2s cpu:4s avg:1.8
0:01:39 INF - 	  read     1x(75% 1s)
0:01:39 INF - 	  process  2x(11% 0.2s wait:2s)
0:01:39 INF - 	  write    1x(0% 0s wait:2s)
0:01:39 INF - 	water_polygons   23s cpu:40s gc:2s avg:1.8
0:01:39 INF - 	  read     1x(63% 14s wait:2s)
0:01:39 INF - 	  process  2x(27% 6s wait:11s)
0:01:39 INF - 	  write    1x(4% 0.9s wait:22s)
0:01:39 INF - 	natural_earth    8s cpu:13s avg:1.6
0:01:39 INF - 	  read     1x(87% 7s sys:1s)
0:01:39 INF - 	  process  2x(18% 2s wait:7s)
0:01:39 INF - 	  write    1x(0% 0s wait:8s)
0:01:39 INF - 	osm_pass1        3s cpu:6s avg:1.8
0:01:39 INF - 	  read     1x(3% 0.1s wait:3s)
0:01:39 INF - 	  parse    1x(61% 2s)
0:01:39 INF - 	  process  1x(50% 2s wait:1s)
0:01:39 INF - 	osm_pass2        25s cpu:49s avg:2
0:01:39 INF - 	  read     1x(0% 0s wait:12s done:13s)
0:01:39 INF - 	  process  2x(76% 19s)
0:01:39 INF - 	  write    1x(2% 0.4s wait:24s)
0:01:39 INF - 	boundaries       0s cpu:0.1s avg:1.8
0:01:39 INF - 	sort             4s cpu:4s avg:1.2
0:01:39 INF - 	  worker  1x(83% 3s)
0:01:39 INF - 	mbtiles          25s cpu:44s avg:1.8
0:01:39 INF - 	  read    1x(7% 2s wait:21s)
0:01:39 INF - 	  encode  2x(44% 11s wait:6s)
0:01:39 INF - 	  write   1x(35% 9s wait:13s)
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	features	269MB
0:01:39 INF - 	mbtiles	514MB
-rw-r--r-- 1 runner docker 55M May  6 01:57 run.jar

https://github.com/onthegomap/planetiler/actions/runs/2279266013

ℹ️ Base Logs 3589fc6
0:00:00 DEB - argument: config=null (path to config file)
0:00:00 DEB - argument: area=rhode island (name of the extract to download if osm_url/osm_path not specified (i.e. 'monaco' 'rhode island' 'australia' or 'planet'))
0:00:00 INF - Using in-memory stats
0:00:00 INF [overall] - 
0:00:00 INF [overall] - Starting...
0:00:00 DEB - argument: madvise=true (default value for whether to use linux madvise(random) to improve memory-mapped read performance for temporary storage)
0:00:00 DEB - argument: storage=mmap (default storage type for temporary data, one of [ram, mmap, direct])
0:00:00 DEB - argument: bounds=Env[-74.07 : -17.84, 21.34 : 43.55] (bounds)
0:00:00 DEB - argument: threads=2 (num threads)
0:00:00 DEB - argument: loginterval=10 seconds (time between logs)
0:00:00 DEB - argument: minzoom=0 (minimum zoom level)
0:00:00 DEB - argument: maxzoom=14 (maximum zoom level (limit 14))
0:00:00 DEB - argument: defer_mbtiles_index_creation=false (skip adding index to mbtiles file)
0:00:00 DEB - argument: optimize_db=false (optimize mbtiles after writing)
0:00:00 DEB - argument: emit_tiles_in_order=true (emit tiles in index order)
0:00:00 DEB - argument: force=false (overwriting output file and ignore disk/RAM warnings)
0:00:00 DEB - argument: gzip_temp=false (gzip temporary feature storage (uses more CPU, but less disk space))
0:00:00 DEB - argument: mmap_temp=false (use memory-mapped IO for temp feature files)
0:00:00 DEB - argument: sort_max_readers=6 (maximum number of concurrent read threads to use when sorting chunks)
0:00:00 DEB - argument: sort_max_writers=6 (maximum number of concurrent write threads to use when sorting chunks)
0:00:00 DEB - argument: nodemap_type=sparsearray (type of node location map, one of [noop, sortedtable, sparsearray, array])
0:00:00 DEB - argument: nodemap_storage=mmap (storage for node location map, one of [ram, mmap, direct])
0:00:00 DEB - argument: nodemap_madvise=true (use linux madvise(random) for node locations)
0:00:00 DEB - argument: multipolygon_geometry_storage=mmap (storage for multipolygon geometries, one of [ram, mmap, direct])
0:00:00 DEB - argument: multipolygon_geometry_madvise=true (use linux madvise(random) for temporary multipolygon geometry storage)
0:00:00 DEB - argument: http_user_agent=Planetiler downloader (https://github.com/onthegomap/planetiler) (User-Agent header to set when downloading files over HTTP)
0:00:00 DEB - argument: http_timeout=30 seconds (Timeout to use when downloading files over HTTP)
0:00:00 DEB - argument: http_retries=1 (Retries to use when downloading files over HTTP)
0:00:00 DEB - argument: download_chunk_size_mb=100 (Size of file chunks to download in parallel in megabytes)
0:00:00 DEB - argument: download_threads=1 (Number of parallel threads to use when downloading each file)
0:00:00 DEB - argument: min_feature_size_at_max_zoom=0.0625 (Default value for the minimum size in tile pixels of features to emit at the maximum zoom level to allow for overzooming)
0:00:00 DEB - argument: min_feature_size=1.0 (Default value for the minimum size in tile pixels of features to emit below the maximum zoom level)
0:00:00 DEB - argument: simplify_tolerance_at_max_zoom=0.0625 (Default value for the tile pixel tolerance to use when simplifying features at the maximum zoom level to allow for overzooming)
0:00:00 DEB - argument: simplify_tolerance=0.1 (Default value for the tile pixel tolerance to use when simplifying features below the maximum zoom level)
0:00:00 DEB - argument: osm_lazy_reads=false (Read OSM blocks from disk in worker threads)
0:00:00 DEB - argument: tmpdir=data/tmp (temp directory)
0:00:00 DEB - argument: only_download=false (download source data then exit)
0:00:00 DEB - argument: download=false (download sources)
0:00:00 DEB - argument: temp_nodes=data/tmp/node.db (temp node db location)
0:00:00 DEB - argument: temp_multipolygons=data/tmp/multipolygon.db (temp multipolygon db location)
0:00:00 DEB - argument: temp_features=data/tmp/feature.db (temp feature db location)
0:00:00 DEB - argument: only_fetch_wikidata=false (fetch wikidata translations then quit)
0:00:00 DEB - argument: fetch_wikidata=false (fetch wikidata translations then continue)
0:00:00 DEB - argument: use_wikidata=true (use wikidata translations)
0:00:00 DEB - argument: wikidata_cache=data/sources/wikidata_names.json (wikidata cache file)
0:00:00 DEB - argument: lake_centerlines_path=data/sources/lake_centerline.shp.zip (lake_centerlines shapefile path)
0:00:00 DEB - argument: free_lake_centerlines_after_read=false (delete lake_centerlines input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: water_polygons_path=data/sources/water-polygons-split-3857.zip (water_polygons shapefile path)
0:00:00 DEB - argument: free_water_polygons_after_read=false (delete water_polygons input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: natural_earth_path=data/sources/natural_earth_vector.sqlite.zip (natural_earth sqlite db path)
0:00:00 DEB - argument: free_natural_earth_after_read=false (delete natural_earth input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: osm_path=data/sources/rhode_island.osm.pbf (osm OSM input file path)
0:00:00 DEB - argument: free_osm_after_read=false (delete osm input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: mbtiles=data/out.mbtiles (mbtiles output file)
0:00:00 DEB - argument: transliterate=true (attempt to transliterate latin names)
0:00:00 DEB - argument: languages=am,ar,az,be,bg,br,bs,ca,co,cs,cy,da,de,el,en,eo,es,et,eu,fi,fr,fy,ga,gd,he,hi,hr,hu,hy,id,is,it,ja,ja_kana,ja_rm,ja-Latn,ja-Hira,ka,kk,kn,ko,ko-Latn,ku,la,lb,lt,lv,mk,mt,ml,nl,no,oc,pl,pt,rm,ro,ru,sk,sl,sq,sr,sr-Latn,sv,ta,te,th,tr,uk,zh (languages to use)
0:00:00 DEB - argument: only_layers= (Include only certain layers)
0:00:00 DEB - argument: exclude_layers= (Exclude certain layers)
0:00:00 DEB - argument: boundary_country_names=true (boundary layer: add left/right codes of neighboring countries)
0:00:00 DEB - argument: transportation_z13_paths=false (transportation(_name) layer: show all paths on z13)
0:00:00 DEB - argument: building_merge_z13=true (building layer: merge nearby buildings at z13)
0:00:00 DEB - argument: transportation_name_brunnel=false (transportation_name layer: set to false to omit brunnel and help merge long highways)
0:00:00 DEB - argument: transportation_name_size_for_shield=false (transportation_name layer: allow road names on shorter segments (ie. they will have a shield))
0:00:00 DEB - argument: transportation_name_limit_merge=false (transportation_name layer: limit merge so we don't combine different relations to help merge long highways)
0:00:00 DEB - argument: transportation_name_minor_refs=false (transportation_name layer: include name and refs from minor road networks if not present on a way)
0:00:00 DEB - argument: mbtiles_name=OpenMapTiles ('name' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_description=A tileset showcasing all layers in OpenMapTiles. https://openmaptiles.org ('description' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_attribution=<a href="https://www.openmaptiles.org/" target="_blank">&copy; OpenMapTiles</a> <a href="https://www.openstreetmap.org/copyright" target="_blank">&copy; OpenStreetMap contributors</a> ('attribution' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_version=3.13.0 ('version' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_type=baselayer ('type' attribute for mbtiles metadata)
0:00:00 DEB - argument: help=false (show arguments then exit)
0:00:00 INF - Building BasemapProfile profile into data/out.mbtiles in these phases:
0:00:00 INF -   lake_centerlines: Process features in data/sources/lake_centerline.shp.zip
0:00:00 INF -   water_polygons: Process features in data/sources/water-polygons-split-3857.zip
0:00:00 INF -   natural_earth: Process features in data/sources/natural_earth_vector.sqlite.zip
0:00:00 INF -   osm_pass1: Pre-process OpenStreetMap input (store node locations then relation members)
0:00:00 INF -   osm_pass2: Process OpenStreetMap nodes, ways, then relations
0:00:00 INF -   sort: Sort rendered features by tile ID
0:00:00 INF -   mbtiles: Encode each tile and write to data/out.mbtiles
0:00:00 INF - no wikidata translations found, run with --fetch-wikidata to download
0:00:00 DEB - ✓ 194M storage on / (/dev/root) requested for read phase disk, 30G available
0:00:00 DEB -  - 43M used for temporary node location cache
0:00:00 DEB -  - 6.6M used for temporary multipolygon geometry cache
0:00:00 DEB -  - 143M used for temporary feature storage
0:00:00 DEB - ✓ 215M storage on / (/dev/root) requested for write phase disk, 30G available
0:00:00 DEB -  - 143M used for temporary feature storage
0:00:00 DEB -  - 71M used for mbtiles output
0:00:00 DEB - ✓ 50M storage on / (/dev/root) requested for read phase, 30G available
0:00:00 DEB -  - 43M used for sparsearray node location cache
0:00:00 DEB -  - 6.6M used for multipolygon way geometries
0:00:00 DEB - ✓ 312M JVM heap requested for read phase, 4.2G available
0:00:00 DEB -  - 300M used for sparsearray node location in-memory index
0:00:00 DEB -  - 12M used for temporary profile storage
0:00:00 DEB - ✓ 50M temporary files and 2.9G of free memory for OS to cache them
0:00:00 INF - Using merge sort feature map, chunk size=1431mb max workers=2
0:00:01 INF - dataFileCache open start
0:00:01 INF [lake_centerlines] - 
0:00:01 INF [lake_centerlines] - Starting...
0:00:03 INF [lake_centerlines] -  read: [  59k 100%  32k/s ] write: [    0    0/s ] 0    
    cpus: 1.8 gc:  5% heap: 174M/4.2G direct: 237k postGC: 79M
    read( -%) ->    (0/1k) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:00:03 INF [lake_centerlines] - Finished in 2s cpu:3s avg:1.8
0:00:03 INF [lake_centerlines] -   read     1x(80% 2s)
0:00:03 INF [lake_centerlines] -   process  2x(13% 0.3s wait:2s)
0:00:03 INF [lake_centerlines] -   write    1x(0% 0s wait:2s)
0:00:03 INF [water_polygons] - 
0:00:03 INF [water_polygons] - Starting...
0:00:13 INF [water_polygons] -  read: [ 2.2k  16%  224/s ] write: [  53k 5.2k/s ] 3.8M 
    cpus: 1.9 gc: 11% heap: 1.1G/4.2G direct: 54M postGC: 1.2G
    read(60%) ->  (280/1k) -> process(20% 37%) -> (1.9k/53k) -> write( 0%)
0:00:23 INF [water_polygons] -  read: [ 6.2k  43%  401/s ] write: [ 337k  28k/s ] 17M  
    cpus: 1.6 gc:  5% heap: 2.7G/4.2G direct: 54M postGC: 1.4G
    read(80%) ->    (0/1k) -> process(18% 16%) ->  (1k/53k) -> write( 1%)
0:00:26 INF [water_polygons] -  read: [  14k 100% 3.2k/s ] write: [ 4.3M 1.5M/s ] 186M 
    cpus: 1.8 gc:  7% heap: 2.4G/4.2G direct: 54M postGC: 1.5G
    read( -%) ->    (0/1k) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:00:26 INF [water_polygons] - Finished in 23s cpu:39s gc:2s avg:1.7
0:00:26 INF [water_polygons] -   read     1x(64% 14s sys:1s wait:2s)
0:00:26 INF [water_polygons] -   process  2x(26% 6s wait:12s)
0:00:26 INF [water_polygons] -   write    1x(3% 0.7s wait:22s)
0:00:26 INF [natural_earth] - unzipping /home/runner/work/planetiler/planetiler/data/sources/natural_earth_vector.sqlite.zip to data/tmp/natearth.sqlite
0:00:31 INF [natural_earth] - 
0:00:31 INF [natural_earth] - Starting...
0:00:41 INF [natural_earth] -  read: [ 349k 100%  38k/s ] write: [  181   19/s ] 186M 
    cpus: 1.4 gc:  0% heap: 1.5G/4.2G direct: 54M postGC: 1.5G
    read( -%) ->    (0/1k) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:00:41 INF [natural_earth] - Finished in 10s cpu:14s avg:1.4
0:00:41 INF [natural_earth] -   read     1x(75% 8s sys:1s done:1s)
0:00:41 INF [natural_earth] -   process  2x(16% 2s wait:8s)
0:00:41 INF [natural_earth] -   write    1x(0% 0s wait:9s)
0:00:42 INF [osm_pass1] - 
0:00:42 INF [osm_pass1] - Starting...
0:00:44 INF [osm_pass1:process] - Finished nodes: 4,584,967 (1.9M/s) in 2s cpu:4s avg:1.7
0:00:45 INF [osm_pass1:process] - Finished ways: 328,988 (419k/s) in 0.8s cpu:2s avg:2
0:00:45 INF [osm_pass1:process] - Finished relations: 7,682 (130k/s) in 0.1s cpu:0.1s avg:1.9
0:00:45 INF [osm_pass1] -  nodes: [ 4.5M 1.4M/s ] 412M  ways: [ 328k 101k/s ] rels: [ 7.6k 2.3k/s ] blocks: [  617  190/s ]
    cpus: 1.8 gc:  1% heap: 850M/4.2G direct: 54M postGC: 820M hppc: 879k
    read( -%) ->     (0/4) -> parse( -%) ->     (0/4) -> process( -%)
0:00:45 DEB [osm_pass1] - Processed 617 blocks:
0:00:45 DEB [osm_pass1] -   nodes: 4,584,967 (1.9M/s) in 2s cpu:4s avg:1.7
0:00:45 DEB [osm_pass1] -   ways: 328,988 (419k/s) in 0.8s cpu:2s avg:2
0:00:45 DEB [osm_pass1] -   relations: 7,682 (130k/s) in 0.1s cpu:0.1s avg:1.9
0:00:45 INF [osm_pass1] - Finished in 3s cpu:6s avg:1.8
0:00:45 INF [osm_pass1] -   read     1x(2% 0.1s wait:3s)
0:00:45 INF [osm_pass1] -   parse    1x(63% 2s)
0:00:45 INF [osm_pass1] -   process  1x(50% 2s wait:1s)
0:00:45 INF [osm_pass2] - 
0:00:45 INF [osm_pass2] - Starting...
0:00:47 DEB [osm_pass2:process] - Sorting long long multimap...
0:00:47 INF [osm_pass2:process] - Finished nodes: 4,584,967 (1.9M/s) in 2s cpu:5s avg:2
0:00:47 DEB [osm_pass2:process] - Sorted long long multimap 0s cpu:0s avg:2.3
0:00:47 WAR [osm_pass2:process] - No GB polygon for inferring route network types
0:00:55 INF [osm_pass2] -  nodes: [ 4.5M 100% 458k/s ] 412M  ways: [ 210k  64%  21k/s ] rels: [    0   0%    0/s ] features: [   5M  69k/s ] 233M  blocks: [  600  97%   59/s ]
    cpus: 2 gc:  0% heap: 3G/4.2G direct: 55M postGC: 832M relInfo: 825k mpGeoms: 849k 
    read( 0%) ->   (11/13) -> process(65% 63%) -> (986/53k) -> write( 3%)
0:01:01 INF [osm_pass2:process] - Finished ways: 328,988 (23k/s) in 14s cpu:28s avg:2
0:01:05 INF [osm_pass2] -  nodes: [ 4.5M 100%    0/s ] 412M  ways: [ 328k 100%  11k/s ] rels: [ 3.1k  42%  319/s ] features: [ 5.2M  24k/s ] 258M  blocks: [  616 100%    1/s ]
    cpus: 2 gc:  1% heap: 2.6G/4.2G direct: 54M postGC: 836M relInfo: 825k mpGeoms: 19M  
    read( -%) ->    (0/13) -> process(77% 78%) -> (1.2k/53k) -> write( 1%)
0:01:09 INF [osm_pass2:process] - Finished relations: 7,682 (1k/s) in 7s cpu:15s avg:2
0:01:11 INF [osm_pass2] -  nodes: [ 4.5M 100%    0/s ] 412M  ways: [ 328k 100%    0/s ] rels: [ 7.6k 100%  730/s ] features: [ 5.2M 3.8k/s ] 269M  blocks: [  617 100%   <1/s ]
    cpus: 2 gc:  0% heap: 3G/4.2G direct: 54M postGC: 833M relInfo: 825k mpGeoms: 19M  
    read( -%) ->    (0/13) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:01:11 DEB [osm_pass2] - Processed 617 blocks:
0:01:11 DEB [osm_pass2] -   nodes: 4,584,967 (1.9M/s) in 2s cpu:5s avg:2
0:01:11 DEB [osm_pass2] -   ways: 328,988 (23k/s) in 14s cpu:28s avg:2
0:01:11 DEB [osm_pass2] -   relations: 7,682 (1k/s) in 7s cpu:15s avg:2
0:01:11 INF [osm_pass2] - Finished in 26s cpu:52s avg:2
0:01:11 INF [osm_pass2] -   read     1x(0% 0s wait:13s done:13s)
0:01:11 INF [osm_pass2] -   process  2x(74% 19s)
0:01:11 INF [osm_pass2] -   write    1x(1% 0.4s wait:26s)
0:01:11 INF [boundaries] - 
0:01:11 INF [boundaries] - Starting...
0:01:11 INF [boundaries] - Creating polygons for 1 boundaries
0:01:11 WAR [boundaries] - Unable to form closed polygon for OSM relation 148838 (likely missing edges)
0:01:11 INF [boundaries] - Finished creating 0 country polygons
0:01:11 INF [boundaries] - Finished in 0s cpu:0.1s avg:1.9
0:01:11 INF - Deleting node.db to make room for output file
0:01:11 INF [sort] - 
0:01:11 INF [sort] - Starting...
0:01:15 INF [sort] -  chunks: [   1 /   1 100% ] 269M 
    cpus: 1.2 gc: 12% heap: 588M/4.2G direct: 54M postGC: 656M
    ->     (0/3) -> worker( -%)
0:01:15 INF [sort] - Finished in 4s cpu:5s avg:1.2
0:01:15 INF [sort] -   worker  1x(69% 3s)
0:01:15 INF - read:1s write:1s sort:0s
0:01:15 INF [mbtiles] - 
0:01:15 INF [mbtiles] - Starting...
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create table metadata (name text, value text);
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create unique index name on metadata (name);
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create table tiles (zoom_level integer, tile_column integer, tile_row, tile_data blob);
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create unique index tile_index on tiles (zoom_level, tile_column, tile_row)
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: name=OpenMapTiles
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: format=pbf
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: description=A tileset showcasing all layers in OpenMapTiles. https://openmaptiles.org
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: attribution=<a href="https://www.openmaptiles.org/" target="_blank">&copy; OpenMapTiles</a> <a href="https://www.openstreetmap.org/copyright" target="_blank">&copy; OpenStreetMap contributors</a>
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: version=3.13.0
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: type=baselayer
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: bounds=-74.07,21.34,-17.84,43.55
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: center=-45.955,32.445,3
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: minzoom=0
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: maxzoom=14
0:01:16 DEB [mbtiles:write] - Set mbtiles metadata: json={"vector_layers":[{"id":"aerodrome_label","fields":{"name_int":"String","iata":"String","ele_ft":"Number","name_de":"String","name":"String","icao":"String","name:en":"String","class":"String","ele":"Number","name_en":"String","name:latin":"String"},"minzoom":10,"maxzoom":14},{"id":"aeroway","fields":{"ref":"String","class":"String"},"minzoom":10,"maxzoom":14},{"id":"boundary","fields":{"disputed":"Number","admin_level":"Number","maritime":"Number","disputed_name":"String"},"minzoom":0,"maxzoom":14},{"id":"building","fields":{"colour":"String","render_height":"Number","render_min_height":"Number"},"minzoom":13,"maxzoom":14},{"id":"housenumber","fields":{"housenumber":"String"},"minzoom":14,"maxzoom":14},{"id":"landcover","fields":{"subclass":"String","class":"String","_numpoints":"Number"},"minzoom":7,"maxzoom":14},{"id":"landuse","fields":{"class":"String"},"minzoom":4,"maxzoom":14},{"id":"mountain_peak","fields":{"name_int":"String","customary_ft":"Number","ele_ft":"Number","name_de":"String","name":"String","rank":"Number","class":"String","name_en":"String","name:latin":"String","ele":"Number"},"minzoom":7,"maxzoom":14},{"id":"park","fields":{"name_int":"String","name_de":"String","name":"String","name:en":"String","class":"String","name_en":"String","name:latin":"String"},"minzoom":6,"maxzoom":14},{"id":"place","fields":{"name:fy":"String","name_int":"String","capital":"Number","name:uk":"String","name:pl":"String","name:nl":"String","name:be":"String","name:ru":"String","name:ko":"String","name_de":"String","name":"String","rank":"Number","name:en":"String","name:eo":"String","class":"String","name:hu":"String","name:ta":"String","name:zh":"String","name_en":"String","name:latin":"String"},"minzoom":2,"maxzoom":14},{"id":"poi","fields":{"name_int":"String","level":"Number","name_de":"String","name":"String","subclass":"String","indoor":"Number","name:en":"String","class":"String","layer":"Number","name:zh":"String","name_en":"String","name:latin":"String"},"minzoom":12,"maxzoom":14},{"id":"transportation","fields":{"access":"String","brunnel":"String","expressway":"Number","surface":"String","bicycle":"String","level":"Number","ramp":"Number","mtb_scale":"String","toll":"Number","oneway":"Number","layer":"Number","network":"String","horse":"String","service":"String","subclass":"String","class":"String","foot":"String"},"minzoom":4,"maxzoom":14},{"id":"transportation_name","fields":{"name_int":"String","route_4":"String","route_3":"String","route_2":"String","route_1":"String","layer":"Number","network":"String","ref":"String","name_de":"String","name":"String","subclass":"String","ref_length":"Number","class":"String","name_en":"String","name:latin":"String"},"minzoom":6,"maxzoom":14},{"id":"water","fields":{"intermittent":"Number","class":"String"},"minzoom":0,"maxzoom":14},{"id":"water_name","fields":{"name_int":"String","name_de":"String","name":"String","intermittent":"Number","class":"String","name_en":"String","name:latin":"String"},"minzoom":9,"maxzoom":14},{"id":"waterway","fields":{"name_int":"String","brunnel":"String","name_de":"String","_relid":"Number","intermittent":"Number","name":"String","class":"String","name:latin":"String","name_en":"String"},"minzoom":4,"maxzoom":14}]}
0:01:16 INF [mbtiles:write] - Starting z0
0:01:16 INF [mbtiles:write] - Finished z0 in 0s cpu:0s avg:0, now starting z1
0:01:16 INF [mbtiles:write] - Finished z1 in 0s cpu:0s avg:0, now starting z2
0:01:16 INF [mbtiles:write] - Finished z2 in 0s cpu:0s avg:0, now starting z3
0:01:16 INF [mbtiles:write] - Finished z3 in 0s cpu:0s avg:0, now starting z4
0:01:16 INF [mbtiles:write] - Finished z4 in 0s cpu:0s avg:0, now starting z5
0:01:16 INF [mbtiles:write] - Finished z5 in 0s cpu:0s avg:0, now starting z6
0:01:16 INF [mbtiles:write] - Finished z6 in 0s cpu:0s avg:0, now starting z7
0:01:16 INF [mbtiles:write] - Finished z7 in 0.5s cpu:0.9s avg:1.9, now starting z8
0:01:17 INF [mbtiles:write] - Finished z8 in 0.5s cpu:0.9s avg:2, now starting z9
0:01:18 INF [mbtiles:write] - Finished z9 in 1s cpu:3s avg:2, now starting z10
0:01:18 INF [mbtiles:write] - Finished z10 in 0.1s cpu:0.1s avg:2, now starting z11
0:01:19 INF [mbtiles:write] - Finished z11 in 0.6s cpu:1s avg:2, now starting z12
0:01:21 INF [mbtiles:write] - Finished z12 in 2s cpu:4s avg:2, now starting z13
0:01:25 INF [mbtiles] -  features: [ 733k  14%  73k/s ] 269M  tiles: [ 291k  29k/s ] 47M  
    cpus: 2 gc:  4% heap: 1.3G/4.2G direct: 54M postGC: 821M
    read( 4%) -> (214/217) -> encode(56% 58%) -> (215/216) -> write( 8%)
    last tile: 13/2470/3047 (z13 4%) https://www.openstreetmap.org/#map=13/41.80408/-71.45508
0:01:31 INF [mbtiles:write] - Finished z13 in 10s cpu:19s avg:2, now starting z14
0:01:35 INF [mbtiles] -  features: [ 3.9M  75% 323k/s ] 269M  tiles: [ 2.6M 233k/s ] 340M 
    cpus: 1.8 gc:  1% heap: 3.1G/4.2G direct: 54M postGC: 862M
    read( 9%) ->   (0/217) -> encode(46% 44%) -> (215/216) -> write(47%)
    last tile: 14/6155/6920 (z14 52%) https://www.openstreetmap.org/#map=14/26.90248/-44.75830
0:01:38 INF [mbtiles:write] - Finished z14 in 8s cpu:11s avg:1.5
0:01:38 INF [mbtiles] -  features: [ 5.2M 100% 426k/s ] 269M  tiles: [ 4.1M 483k/s ] 514M 
    cpus: 1.4 gc:  2% heap: 1.3G/4.2G direct: 54M postGC: 809M
    read( -%) ->   (0/217) -> encode( -%  -%) ->   (0/216) -> write( -%)
    last tile: 14/7380/5985 (z14 100%) https://www.openstreetmap.org/#map=14/43.56447/-17.84180
0:01:38 DEB [mbtiles] - Tile stats:
0:01:38 DEB [mbtiles] - z0 avg:7.9k max:7.9k
0:01:38 DEB [mbtiles] - z1 avg:4k max:4k
0:01:38 DEB [mbtiles] - z2 avg:9.4k max:9.4k
0:01:38 DEB [mbtiles] - z3 avg:3.9k max:6.4k
0:01:38 DEB [mbtiles] - z4 avg:1.6k max:4.6k
0:01:38 DEB [mbtiles] - z5 avg:1.4k max:8.1k
0:01:38 DEB [mbtiles] - z6 avg:1.4k max:24k
0:01:38 DEB [mbtiles] - z7 avg:1k max:56k
0:01:38 DEB [mbtiles] - z8 avg:475 max:113k
0:01:38 DEB [mbtiles] - z9 avg:298 max:279k
0:01:38 DEB [mbtiles] - z10 avg:165 max:232k
0:01:38 DEB [mbtiles] - z11 avg:107 max:132k
0:01:38 DEB [mbtiles] - z12 avg:86 max:118k
0:01:38 DEB [mbtiles] - z13 avg:72 max:109k
0:01:38 DEB [mbtiles] - z14 avg:68 max:257k
0:01:38 DEB [mbtiles] - all avg:71 max:0
0:01:38 DEB [mbtiles] -  # features: 5,286,636
0:01:38 DEB [mbtiles] -     # tiles: 4,115,449
0:01:38 INF [mbtiles] - Finished in 23s cpu:42s avg:1.8
0:01:38 INF [mbtiles] -   read    1x(7% 2s wait:19s)
0:01:38 INF [mbtiles] -   encode  2x(45% 10s wait:6s)
0:01:38 INF [mbtiles] -   write   1x(37% 9s sys:1s wait:13s)
0:01:39 INF - Finished in 1m39s cpu:2m51s gc:3s avg:1.7
0:01:39 INF - FINISHED!
0:01:39 INF - 
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	overall          1m39s cpu:2m51s gc:3s avg:1.7
0:01:39 INF - 	lake_centerlines 2s cpu:3s avg:1.8
0:01:39 INF - 	  read     1x(80% 2s)
0:01:39 INF - 	  process  2x(13% 0.3s wait:2s)
0:01:39 INF - 	  write    1x(0% 0s wait:2s)
0:01:39 INF - 	water_polygons   23s cpu:39s gc:2s avg:1.7
0:01:39 INF - 	  read     1x(64% 14s sys:1s wait:2s)
0:01:39 INF - 	  process  2x(26% 6s wait:12s)
0:01:39 INF - 	  write    1x(3% 0.7s wait:22s)
0:01:39 INF - 	natural_earth    10s cpu:14s avg:1.4
0:01:39 INF - 	  read     1x(75% 8s sys:1s done:1s)
0:01:39 INF - 	  process  2x(16% 2s wait:8s)
0:01:39 INF - 	  write    1x(0% 0s wait:9s)
0:01:39 INF - 	osm_pass1        3s cpu:6s avg:1.8
0:01:39 INF - 	  read     1x(2% 0.1s wait:3s)
0:01:39 INF - 	  parse    1x(63% 2s)
0:01:39 INF - 	  process  1x(50% 2s wait:1s)
0:01:39 INF - 	osm_pass2        26s cpu:52s avg:2
0:01:39 INF - 	  read     1x(0% 0s wait:13s done:13s)
0:01:39 INF - 	  process  2x(74% 19s)
0:01:39 INF - 	  write    1x(1% 0.4s wait:26s)
0:01:39 INF - 	boundaries       0s cpu:0.1s avg:1.9
0:01:39 INF - 	sort             4s cpu:5s avg:1.2
0:01:39 INF - 	  worker  1x(69% 3s)
0:01:39 INF - 	mbtiles          23s cpu:42s avg:1.8
0:01:39 INF - 	  read    1x(7% 2s wait:19s)
0:01:39 INF - 	  encode  2x(45% 10s wait:6s)
0:01:39 INF - 	  write   1x(37% 9s sys:1s wait:13s)
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	features	269MB
0:01:39 INF - 	mbtiles	514MB
-rw-r--r-- 1 runner docker 55M May  6 01:58 run.jar
ℹ️ This Branch Logs 74ef7cd
0:00:00 DEB - argument: config=null (path to config file)
0:00:00 DEB - argument: area=rhode island (name of the extract to download if osm_url/osm_path not specified (i.e. 'monaco' 'rhode island' 'australia' or 'planet'))
0:00:00 INF - Using in-memory stats
0:00:00 INF [overall] - 
0:00:00 INF [overall] - Starting...
0:00:00 DEB - argument: madvise=true (default value for whether to use linux madvise(random) to improve memory-mapped read performance for temporary storage)
0:00:00 DEB - argument: storage=mmap (default storage type for temporary data, one of [ram, mmap, direct])
0:00:00 DEB - argument: threads=2 (num threads)
0:00:00 DEB - argument: write_threads=1 (number of threads to use when writing temp features)
0:00:00 DEB - argument: process_threads=2 (number of threads to use when processing input features)
0:00:00 DEB - argument: bounds=Env[-74.07 : -17.84, 21.34 : 43.55] (bounds)
0:00:00 DEB - argument: loginterval=10 seconds (time between logs)
0:00:00 DEB - argument: minzoom=0 (minimum zoom level)
0:00:00 DEB - argument: maxzoom=14 (maximum zoom level (limit 14))
0:00:00 DEB - argument: defer_mbtiles_index_creation=false (skip adding index to mbtiles file)
0:00:00 DEB - argument: optimize_db=false (optimize mbtiles after writing)
0:00:00 DEB - argument: emit_tiles_in_order=true (emit tiles in index order)
0:00:00 DEB - argument: force=false (overwriting output file and ignore disk/RAM warnings)
0:00:00 DEB - argument: gzip_temp=false (gzip temporary feature storage (uses more CPU, but less disk space))
0:00:00 DEB - argument: mmap_temp=false (use memory-mapped IO for temp feature files)
0:00:00 DEB - argument: sort_max_readers=6 (maximum number of concurrent read threads to use when sorting chunks)
0:00:00 DEB - argument: sort_max_writers=6 (maximum number of concurrent write threads to use when sorting chunks)
0:00:00 DEB - argument: nodemap_type=sparsearray (type of node location map, one of [noop, sortedtable, sparsearray, array])
0:00:00 DEB - argument: nodemap_storage=mmap (storage for node location map, one of [ram, mmap, direct])
0:00:00 DEB - argument: nodemap_madvise=true (use linux madvise(random) for node locations)
0:00:00 DEB - argument: multipolygon_geometry_storage=mmap (storage for multipolygon geometries, one of [ram, mmap, direct])
0:00:00 DEB - argument: multipolygon_geometry_madvise=true (use linux madvise(random) for temporary multipolygon geometry storage)
0:00:00 DEB - argument: http_user_agent=Planetiler downloader (https://github.com/onthegomap/planetiler) (User-Agent header to set when downloading files over HTTP)
0:00:00 DEB - argument: http_timeout=30 seconds (Timeout to use when downloading files over HTTP)
0:00:00 DEB - argument: http_retries=1 (Retries to use when downloading files over HTTP)
0:00:00 DEB - argument: download_chunk_size_mb=100 (Size of file chunks to download in parallel in megabytes)
0:00:00 DEB - argument: download_threads=1 (Number of parallel threads to use when downloading each file)
0:00:00 DEB - argument: min_feature_size_at_max_zoom=0.0625 (Default value for the minimum size in tile pixels of features to emit at the maximum zoom level to allow for overzooming)
0:00:00 DEB - argument: min_feature_size=1.0 (Default value for the minimum size in tile pixels of features to emit below the maximum zoom level)
0:00:00 DEB - argument: simplify_tolerance_at_max_zoom=0.0625 (Default value for the tile pixel tolerance to use when simplifying features at the maximum zoom level to allow for overzooming)
0:00:00 DEB - argument: simplify_tolerance=0.1 (Default value for the tile pixel tolerance to use when simplifying features below the maximum zoom level)
0:00:00 DEB - argument: osm_lazy_reads=false (Read OSM blocks from disk in worker threads)
0:00:00 DEB - argument: tmpdir=data/tmp (temp directory)
0:00:00 DEB - argument: only_download=false (download source data then exit)
0:00:00 DEB - argument: download=false (download sources)
0:00:00 DEB - argument: temp_nodes=data/tmp/node.db (temp node db location)
0:00:00 DEB - argument: temp_multipolygons=data/tmp/multipolygon.db (temp multipolygon db location)
0:00:00 DEB - argument: temp_features=data/tmp/feature.db (temp feature db location)
0:00:00 DEB - argument: only_fetch_wikidata=false (fetch wikidata translations then quit)
0:00:00 DEB - argument: fetch_wikidata=false (fetch wikidata translations then continue)
0:00:00 DEB - argument: use_wikidata=true (use wikidata translations)
0:00:00 DEB - argument: wikidata_cache=data/sources/wikidata_names.json (wikidata cache file)
0:00:00 DEB - argument: lake_centerlines_path=data/sources/lake_centerline.shp.zip (lake_centerlines shapefile path)
0:00:00 DEB - argument: free_lake_centerlines_after_read=false (delete lake_centerlines input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: water_polygons_path=data/sources/water-polygons-split-3857.zip (water_polygons shapefile path)
0:00:00 DEB - argument: free_water_polygons_after_read=false (delete water_polygons input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: natural_earth_path=data/sources/natural_earth_vector.sqlite.zip (natural_earth sqlite db path)
0:00:00 DEB - argument: free_natural_earth_after_read=false (delete natural_earth input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: osm_path=data/sources/rhode_island.osm.pbf (osm OSM input file path)
0:00:00 DEB - argument: free_osm_after_read=false (delete osm input file after reading to make space for output (reduces peak disk usage))
0:00:00 DEB - argument: mbtiles=data/out.mbtiles (mbtiles output file)
0:00:00 DEB - argument: transliterate=true (attempt to transliterate latin names)
0:00:00 DEB - argument: languages=am,ar,az,be,bg,br,bs,ca,co,cs,cy,da,de,el,en,eo,es,et,eu,fi,fr,fy,ga,gd,he,hi,hr,hu,hy,id,is,it,ja,ja_kana,ja_rm,ja-Latn,ja-Hira,ka,kk,kn,ko,ko-Latn,ku,la,lb,lt,lv,mk,mt,ml,nl,no,oc,pl,pt,rm,ro,ru,sk,sl,sq,sr,sr-Latn,sv,ta,te,th,tr,uk,zh (languages to use)
0:00:00 DEB - argument: only_layers= (Include only certain layers)
0:00:00 DEB - argument: exclude_layers= (Exclude certain layers)
0:00:00 DEB - argument: boundary_country_names=true (boundary layer: add left/right codes of neighboring countries)
0:00:00 DEB - argument: transportation_z13_paths=false (transportation(_name) layer: show all paths on z13)
0:00:00 DEB - argument: building_merge_z13=true (building layer: merge nearby buildings at z13)
0:00:00 DEB - argument: transportation_name_brunnel=false (transportation_name layer: set to false to omit brunnel and help merge long highways)
0:00:00 DEB - argument: transportation_name_size_for_shield=false (transportation_name layer: allow road names on shorter segments (ie. they will have a shield))
0:00:00 DEB - argument: transportation_name_limit_merge=false (transportation_name layer: limit merge so we don't combine different relations to help merge long highways)
0:00:00 DEB - argument: transportation_name_minor_refs=false (transportation_name layer: include name and refs from minor road networks if not present on a way)
0:00:00 DEB - argument: mbtiles_name=OpenMapTiles ('name' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_description=A tileset showcasing all layers in OpenMapTiles. https://openmaptiles.org ('description' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_attribution=<a href="https://www.openmaptiles.org/" target="_blank">&copy; OpenMapTiles</a> <a href="https://www.openstreetmap.org/copyright" target="_blank">&copy; OpenStreetMap contributors</a> ('attribution' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_version=3.13.0 ('version' attribute for mbtiles metadata)
0:00:00 DEB - argument: mbtiles_type=baselayer ('type' attribute for mbtiles metadata)
0:00:00 DEB - argument: help=false (show arguments then exit)
0:00:00 INF - Building BasemapProfile profile into data/out.mbtiles in these phases:
0:00:00 INF -   lake_centerlines: Process features in data/sources/lake_centerline.shp.zip
0:00:00 INF -   water_polygons: Process features in data/sources/water-polygons-split-3857.zip
0:00:00 INF -   natural_earth: Process features in data/sources/natural_earth_vector.sqlite.zip
0:00:00 INF -   osm_pass1: Pre-process OpenStreetMap input (store node locations then relation members)
0:00:00 INF -   osm_pass2: Process OpenStreetMap nodes, ways, then relations
0:00:00 INF -   sort: Sort rendered features by tile ID
0:00:00 INF -   mbtiles: Encode each tile and write to data/out.mbtiles
0:00:00 INF - no wikidata translations found, run with --fetch-wikidata to download
0:00:00 DEB - ✓ 194M storage on / (/dev/root) requested for read phase disk, 30G available
0:00:00 DEB -  - 43M used for temporary node location cache
0:00:00 DEB -  - 6.6M used for temporary multipolygon geometry cache
0:00:00 DEB -  - 143M used for temporary feature storage
0:00:00 DEB - ✓ 215M storage on / (/dev/root) requested for write phase disk, 30G available
0:00:00 DEB -  - 143M used for temporary feature storage
0:00:00 DEB -  - 71M used for mbtiles output
0:00:00 DEB - ✓ 50M storage on / (/dev/root) requested for read phase, 30G available
0:00:00 DEB -  - 43M used for sparsearray node location cache
0:00:00 DEB -  - 6.6M used for multipolygon way geometries
0:00:00 DEB - ✓ 312M JVM heap requested for read phase, 4.2G available
0:00:00 DEB -  - 300M used for sparsearray node location in-memory index
0:00:00 DEB -  - 12M used for temporary profile storage
0:00:00 DEB - ✓ 50M temporary files and 2.9G of free memory for OS to cache them
0:00:00 INF - Using merge sort feature map, chunk size=1431mb max workers=2
0:00:02 INF - dataFileCache open start
0:00:02 INF [lake_centerlines] - 
0:00:02 INF [lake_centerlines] - Starting...
0:00:04 INF [lake_centerlines] -  read: [  59k 100%  31k/s ] write: [    0    0/s ] 0    
    cpus: 1.8 gc:  4% heap: 171M/4.2G direct: 237k postGC: 79M
    read( -%) ->    (0/1k) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:00:04 INF [lake_centerlines] - Finished in 2s cpu:4s avg:1.8
0:00:04 INF [lake_centerlines] -   read     1x(75% 1s)
0:00:04 INF [lake_centerlines] -   process  2x(11% 0.2s wait:2s)
0:00:04 INF [lake_centerlines] -   write    1x(0% 0s wait:2s)
0:00:04 INF [water_polygons] - 
0:00:04 INF [water_polygons] - Starting...
0:00:14 INF [water_polygons] -  read: [ 2.2k  16%  224/s ] write: [  53k 5.2k/s ] 3.8M 
    cpus: 1.9 gc: 10% heap: 1.2G/4.2G direct: 54M postGC: 969M
    read(62%) ->  (319/1k) -> process(40% 19%) -> (1.5k/53k) -> write( 0%)
0:00:24 INF [water_polygons] -  read: [ 6.2k  43%  398/s ] write: [ 337k  28k/s ] 17M  
    cpus: 1.6 gc:  9% heap: 1.5G/4.2G direct: 54M postGC: 1.3G
    read(77%) ->    (0/1k) -> process(22% 13%) ->  (1k/53k) -> write( 1%)
0:00:26 INF [water_polygons] -  read: [  14k 100% 3.2k/s ] write: [ 4.3M 1.5M/s ] 186M 
    cpus: 1.8 gc:  3% heap: 2.8G/4.2G direct: 54M postGC: 1.5G
    read( -%) ->    (0/1k) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:00:26 INF [water_polygons] - Finished in 23s cpu:40s gc:2s avg:1.8
0:00:26 INF [water_polygons] -   read     1x(63% 14s wait:2s)
0:00:26 INF [water_polygons] -   process  2x(27% 6s wait:11s)
0:00:26 INF [water_polygons] -   write    1x(4% 0.9s wait:22s)
0:00:26 INF [natural_earth] - unzipping /home/runner/work/planetiler/planetiler/data/sources/natural_earth_vector.sqlite.zip to data/tmp/natearth.sqlite
0:00:34 INF [natural_earth] - 
0:00:34 INF [natural_earth] - Starting...
0:00:42 INF [natural_earth] -  read: [ 349k 100%  44k/s ] write: [  181   22/s ] 186M 
    cpus: 1.6 gc:  0% heap: 1.7G/4.2G direct: 54M postGC: 1.5G
    read( -%) ->    (0/1k) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:00:42 INF [natural_earth] - Finished in 8s cpu:13s avg:1.6
0:00:42 INF [natural_earth] -   read     1x(87% 7s sys:1s)
0:00:42 INF [natural_earth] -   process  2x(18% 2s wait:7s)
0:00:42 INF [natural_earth] -   write    1x(0% 0s wait:8s)
0:00:42 INF [osm_pass1] - 
0:00:42 INF [osm_pass1] - Starting...
0:00:45 INF [osm_pass1:process] - Finished nodes: 4,584,967 (1.9M/s) in 2s cpu:4s avg:1.7
0:00:45 INF [osm_pass1:process] - Finished ways: 328,988 (479k/s) in 0.7s cpu:1s avg:2
0:00:46 INF [osm_pass1:process] - Finished relations: 7,682 (94k/s) in 0.1s cpu:0.2s avg:2
0:00:46 INF [osm_pass1] -  nodes: [ 4.5M 1.4M/s ] 412M  ways: [ 328k 101k/s ] rels: [ 7.6k 2.3k/s ] blocks: [  617  191/s ]
    cpus: 1.8 gc:  1% heap: 784M/4.2G direct: 54M postGC: 844M hppc: 879k
    read( -%) ->     (0/4) -> parse( -%) ->     (0/4) -> process( -%)
0:00:46 DEB [osm_pass1] - Processed 617 blocks:
0:00:46 DEB [osm_pass1] -   nodes: 4,584,967 (1.9M/s) in 2s cpu:4s avg:1.7
0:00:46 DEB [osm_pass1] -   ways: 328,988 (479k/s) in 0.7s cpu:1s avg:2
0:00:46 DEB [osm_pass1] -   relations: 7,682 (94k/s) in 0.1s cpu:0.2s avg:2
0:00:46 INF [osm_pass1] - Finished in 3s cpu:6s avg:1.8
0:00:46 INF [osm_pass1] -   read     1x(3% 0.1s wait:3s)
0:00:46 INF [osm_pass1] -   parse    1x(61% 2s)
0:00:46 INF [osm_pass1] -   process  1x(50% 2s wait:1s)
0:00:46 INF [osm_pass2] - 
0:00:46 INF [osm_pass2] - Starting...
0:00:48 DEB [osm_pass2:process] - Sorting long long multimap...
0:00:48 INF [osm_pass2:process] - Finished nodes: 4,584,967 (2.2M/s) in 2s cpu:4s avg:2
0:00:48 DEB [osm_pass2:process] - Sorted long long multimap 0s cpu:0s avg:1.9
0:00:48 WAR [osm_pass2:process] - No GB polygon for inferring route network types
0:00:56 INF [osm_pass2] -  nodes: [ 4.5M 100% 458k/s ] 412M  ways: [ 219k  67%  21k/s ] rels: [    0   0%    0/s ] features: [   5M  71k/s ] 235M  blocks: [  601  97%   60/s ]
    cpus: 2 gc:  1% heap: 1.2G/4.2G direct: 55M postGC: 855M relInfo: 825k mpGeoms: 2.3M 
    read( 0%) ->   (11/13) -> process(63% 67%) -> (981/53k) -> write( 3%)
0:01:01 INF [osm_pass2:process] - Finished ways: 328,988 (23k/s) in 14s cpu:28s avg:2
0:01:06 INF [osm_pass2] -  nodes: [ 4.5M 100%    0/s ] 412M  ways: [ 328k 100%  10k/s ] rels: [ 3.8k  49%  379/s ] features: [ 5.2M  23k/s ] 260M  blocks: [  616 100%    1/s ]
    cpus: 2 gc:  0% heap: 1.3G/4.2G direct: 54M postGC: 833M relInfo: 825k mpGeoms: 19M  
    read( -%) ->    (0/13) -> process(82% 82%) -> (1.4k/53k) -> write( 1%)
0:01:08 INF [osm_pass2:process] - Finished relations: 7,682 (1k/s) in 7s cpu:14s avg:2
0:01:10 INF [osm_pass2] -  nodes: [ 4.5M 100%    0/s ] 412M  ways: [ 328k 100%    0/s ] rels: [ 7.6k 100%  819/s ] features: [ 5.2M   4k/s ] 269M  blocks: [  617 100%   <1/s ]
    cpus: 2 gc:  0% heap: 769M/4.2G direct: 54M postGC: 826M relInfo: 825k mpGeoms: 19M  
    read( -%) ->    (0/13) -> process( -%  -%) ->   (0/53k) -> write( -%)
0:01:10 DEB [osm_pass2] - Processed 617 blocks:
0:01:10 DEB [osm_pass2] -   nodes: 4,584,967 (2.2M/s) in 2s cpu:4s avg:2
0:01:10 DEB [osm_pass2] -   ways: 328,988 (23k/s) in 14s cpu:28s avg:2
0:01:10 DEB [osm_pass2] -   relations: 7,682 (1k/s) in 7s cpu:14s avg:2
0:01:10 INF [osm_pass2] - Finished in 25s cpu:49s avg:2
0:01:10 INF [osm_pass2] -   read     1x(0% 0s wait:12s done:13s)
0:01:10 INF [osm_pass2] -   process  2x(76% 19s)
0:01:10 INF [osm_pass2] -   write    1x(2% 0.4s wait:24s)
0:01:10 INF [boundaries] - 
0:01:10 INF [boundaries] - Starting...
0:01:10 INF [boundaries] - Creating polygons for 1 boundaries
0:01:10 WAR [boundaries] - Unable to form closed polygon for OSM relation 148838 (likely missing edges)
0:01:10 INF [boundaries] - Finished creating 0 country polygons
0:01:10 INF [boundaries] - Finished in 0s cpu:0.1s avg:1.8
0:01:10 INF - Deleting node.db to make room for output file
0:01:10 INF [sort] - 
0:01:10 INF [sort] - Starting...
0:01:10 INF [sort] - Grouped 8 chunks into 1
0:01:14 INF [sort] -  chunks: [   1 /   8  12% ] 269M 
    cpus: 1.2 gc:  0% heap: 1.2G/4.2G direct: 54M postGC: 826M
    ->     (0/3) -> worker( -%)
0:01:14 INF [sort] - Finished in 4s cpu:4s avg:1.2
0:01:14 INF [sort] -   worker  1x(83% 3s)
0:01:14 INF - read:1s write:1s sort:0s
0:01:14 INF [mbtiles] - 
0:01:14 INF [mbtiles] - Starting...
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create table metadata (name text, value text);
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create unique index name on metadata (name);
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create table tiles (zoom_level integer, tile_column integer, tile_row, tile_data blob);
0:01:15 DEB [mbtiles:write] - Execute mbtiles: create unique index tile_index on tiles (zoom_level, tile_column, tile_row)
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: name=OpenMapTiles
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: format=pbf
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: description=A tileset showcasing all layers in OpenMapTiles. https://openmaptiles.org
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: attribution=<a href="https://www.openmaptiles.org/" target="_blank">&copy; OpenMapTiles</a> <a href="https://www.openstreetmap.org/copyright" target="_blank">&copy; OpenStreetMap contributors</a>
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: version=3.13.0
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: type=baselayer
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: bounds=-74.07,21.34,-17.84,43.55
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: center=-45.955,32.445,3
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: minzoom=0
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: maxzoom=14
0:01:15 DEB [mbtiles:write] - Set mbtiles metadata: json={"vector_layers":[{"id":"aerodrome_label","fields":{"name_int":"String","iata":"String","ele_ft":"Number","name_de":"String","name":"String","icao":"String","name:en":"String","class":"String","ele":"Number","name_en":"String","name:latin":"String"},"minzoom":10,"maxzoom":14},{"id":"aeroway","fields":{"ref":"String","class":"String"},"minzoom":10,"maxzoom":14},{"id":"boundary","fields":{"disputed":"Number","admin_level":"Number","maritime":"Number","disputed_name":"String"},"minzoom":0,"maxzoom":14},{"id":"building","fields":{"colour":"String","render_height":"Number","render_min_height":"Number"},"minzoom":13,"maxzoom":14},{"id":"housenumber","fields":{"housenumber":"String"},"minzoom":14,"maxzoom":14},{"id":"landcover","fields":{"subclass":"String","class":"String","_numpoints":"Number"},"minzoom":7,"maxzoom":14},{"id":"landuse","fields":{"class":"String"},"minzoom":4,"maxzoom":14},{"id":"mountain_peak","fields":{"name_int":"String","customary_ft":"Number","ele_ft":"Number","name_de":"String","name":"String","rank":"Number","class":"String","name_en":"String","name:latin":"String","ele":"Number"},"minzoom":7,"maxzoom":14},{"id":"park","fields":{"name_int":"String","name_de":"String","name":"String","name:en":"String","class":"String","name_en":"String","name:latin":"String"},"minzoom":6,"maxzoom":14},{"id":"place","fields":{"name:fy":"String","name_int":"String","capital":"Number","name:uk":"String","name:pl":"String","name:nl":"String","name:be":"String","name:ru":"String","name:ko":"String","name_de":"String","name":"String","rank":"Number","name:en":"String","name:eo":"String","class":"String","name:hu":"String","name:ta":"String","name:zh":"String","name_en":"String","name:latin":"String"},"minzoom":2,"maxzoom":14},{"id":"poi","fields":{"name_int":"String","level":"Number","name_de":"String","name":"String","subclass":"String","indoor":"Number","name:en":"String","class":"String","layer":"Number","name:zh":"String","name_en":"String","name:latin":"String"},"minzoom":12,"maxzoom":14},{"id":"transportation","fields":{"brunnel":"String","access":"String","expressway":"Number","bicycle":"String","surface":"String","level":"Number","ramp":"Number","mtb_scale":"String","toll":"Number","layer":"Number","oneway":"Number","network":"String","horse":"String","service":"String","subclass":"String","class":"String","foot":"String"},"minzoom":4,"maxzoom":14},{"id":"transportation_name","fields":{"name_int":"String","route_4":"String","route_3":"String","route_2":"String","route_1":"String","layer":"Number","network":"String","ref":"String","name_de":"String","name":"String","subclass":"String","ref_length":"Number","class":"String","name_en":"String","name:latin":"String"},"minzoom":6,"maxzoom":14},{"id":"water","fields":{"intermittent":"Number","class":"String"},"minzoom":0,"maxzoom":14},{"id":"water_name","fields":{"name_int":"String","name_de":"String","name":"String","intermittent":"Number","class":"String","name_en":"String","name:latin":"String"},"minzoom":9,"maxzoom":14},{"id":"waterway","fields":{"name_int":"String","brunnel":"String","name_de":"String","_relid":"Number","intermittent":"Number","name":"String","class":"String","name:latin":"String","name_en":"String"},"minzoom":4,"maxzoom":14}]}
0:01:15 INF [mbtiles:write] - Starting z0
0:01:15 INF [mbtiles:write] - Finished z0 in 0s cpu:0s avg:0, now starting z1
0:01:15 INF [mbtiles:write] - Finished z1 in 0s cpu:0s avg:0, now starting z2
0:01:15 INF [mbtiles:write] - Finished z2 in 0s cpu:0s avg:0, now starting z3
0:01:15 INF [mbtiles:write] - Finished z3 in 0s cpu:0s avg:0, now starting z4
0:01:15 INF [mbtiles:write] - Finished z4 in 0s cpu:0s avg:0, now starting z5
0:01:15 INF [mbtiles:write] - Finished z5 in 0s cpu:0s avg:0, now starting z6
0:01:15 INF [mbtiles:write] - Finished z6 in 0s cpu:0s avg:0, now starting z7
0:01:16 INF [mbtiles:write] - Finished z7 in 0.8s cpu:2s avg:2, now starting z8
0:01:17 INF [mbtiles:write] - Finished z8 in 0.9s cpu:2s avg:1.9, now starting z9
0:01:18 INF [mbtiles:write] - Finished z9 in 1s cpu:2s avg:2, now starting z10
0:01:18 INF [mbtiles:write] - Finished z10 in 0.1s cpu:0.1s avg:2, now starting z11
0:01:18 INF [mbtiles:write] - Finished z11 in 0.6s cpu:1s avg:2, now starting z12
0:01:21 INF [mbtiles:write] - Finished z12 in 2s cpu:4s avg:2, now starting z13
0:01:25 INF [mbtiles] -  features: [ 719k  14%  71k/s ] 269M  tiles: [ 291k  29k/s ] 47M  
    cpus: 2 gc:  3% heap: 1.5G/4.2G direct: 54M postGC: 393M
    read( 4%) -> (214/217) -> encode(58% 55%) -> (215/216) -> write( 8%)
    last tile: 13/2470/3048 (z13 4%) https://www.openstreetmap.org/#map=13/41.77131/-71.45508
0:01:31 INF [mbtiles:write] - Finished z13 in 10s cpu:20s avg:2, now starting z14
0:01:35 INF [mbtiles] -  features: [ 3.6M  69% 294k/s ] 269M  tiles: [ 2.3M 203k/s ] 305M 
    cpus: 1.8 gc:  2% heap: 721M/4.2G direct: 54M postGC: 380M
    read( 8%) ->   (1/217) -> encode(47% 46%) -> (212/216) -> write(41%)
    last tile: 14/5908/6309 (z14 42%) https://www.openstreetmap.org/#map=14/38.18639/-50.18555
0:01:39 INF [mbtiles:write] - Finished z14 in 8s cpu:11s avg:1.4
0:01:39 INF [mbtiles] -  features: [ 5.2M 100% 396k/s ] 269M  tiles: [ 4.1M 436k/s ] 514M 
    cpus: 1.2 gc:  0% heap: 1.5G/4.2G direct: 54M postGC: 380M
    read( -%) ->   (0/217) -> encode( -%  -%) ->   (0/216) -> write( -%)
    last tile: 14/7380/5985 (z14 100%) https://www.openstreetmap.org/#map=14/43.56447/-17.84180
0:01:39 DEB [mbtiles] - Tile stats:
0:01:39 DEB [mbtiles] - z0 avg:7.9k max:7.9k
0:01:39 DEB [mbtiles] - z1 avg:4k max:4k
0:01:39 DEB [mbtiles] - z2 avg:9.4k max:9.4k
0:01:39 DEB [mbtiles] - z3 avg:3.9k max:6.4k
0:01:39 DEB [mbtiles] - z4 avg:1.6k max:4.6k
0:01:39 DEB [mbtiles] - z5 avg:1.4k max:8.1k
0:01:39 DEB [mbtiles] - z6 avg:1.4k max:24k
0:01:39 DEB [mbtiles] - z7 avg:1k max:56k
0:01:39 DEB [mbtiles] - z8 avg:475 max:113k
0:01:39 DEB [mbtiles] - z9 avg:298 max:279k
0:01:39 DEB [mbtiles] - z10 avg:165 max:232k
0:01:39 DEB [mbtiles] - z11 avg:107 max:132k
0:01:39 DEB [mbtiles] - z12 avg:86 max:118k
0:01:39 DEB [mbtiles] - z13 avg:72 max:109k
0:01:39 DEB [mbtiles] - z14 avg:68 max:257k
0:01:39 DEB [mbtiles] - all avg:71 max:0
0:01:39 DEB [mbtiles] -  # features: 5,286,636
0:01:39 DEB [mbtiles] -     # tiles: 4,115,449
0:01:39 INF [mbtiles] - Finished in 25s cpu:44s avg:1.8
0:01:39 INF [mbtiles] -   read    1x(7% 2s wait:21s)
0:01:39 INF [mbtiles] -   encode  2x(44% 11s wait:6s)
0:01:39 INF [mbtiles] -   write   1x(35% 9s wait:13s)
0:01:39 INF - Finished in 1m39s cpu:2m50s gc:3s avg:1.7
0:01:39 INF - FINISHED!
0:01:39 INF - 
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	overall          1m39s cpu:2m50s gc:3s avg:1.7
0:01:39 INF - 	lake_centerlines 2s cpu:4s avg:1.8
0:01:39 INF - 	  read     1x(75% 1s)
0:01:39 INF - 	  process  2x(11% 0.2s wait:2s)
0:01:39 INF - 	  write    1x(0% 0s wait:2s)
0:01:39 INF - 	water_polygons   23s cpu:40s gc:2s avg:1.8
0:01:39 INF - 	  read     1x(63% 14s wait:2s)
0:01:39 INF - 	  process  2x(27% 6s wait:11s)
0:01:39 INF - 	  write    1x(4% 0.9s wait:22s)
0:01:39 INF - 	natural_earth    8s cpu:13s avg:1.6
0:01:39 INF - 	  read     1x(87% 7s sys:1s)
0:01:39 INF - 	  process  2x(18% 2s wait:7s)
0:01:39 INF - 	  write    1x(0% 0s wait:8s)
0:01:39 INF - 	osm_pass1        3s cpu:6s avg:1.8
0:01:39 INF - 	  read     1x(3% 0.1s wait:3s)
0:01:39 INF - 	  parse    1x(61% 2s)
0:01:39 INF - 	  process  1x(50% 2s wait:1s)
0:01:39 INF - 	osm_pass2        25s cpu:49s avg:2
0:01:39 INF - 	  read     1x(0% 0s wait:12s done:13s)
0:01:39 INF - 	  process  2x(76% 19s)
0:01:39 INF - 	  write    1x(2% 0.4s wait:24s)
0:01:39 INF - 	boundaries       0s cpu:0.1s avg:1.8
0:01:39 INF - 	sort             4s cpu:4s avg:1.2
0:01:39 INF - 	  worker  1x(83% 3s)
0:01:39 INF - 	mbtiles          25s cpu:44s avg:1.8
0:01:39 INF - 	  read    1x(7% 2s wait:21s)
0:01:39 INF - 	  encode  2x(44% 11s wait:6s)
0:01:39 INF - 	  write   1x(35% 9s wait:13s)
0:01:39 INF - ----------------------------------------
0:01:39 INF - 	features	269MB
0:01:39 INF - 	mbtiles	514MB
-rw-r--r-- 1 runner docker 55M May  6 01:57 run.jar

@sonarqubecloud
Copy link

sonarqubecloud bot commented May 6, 2022

Kudos, SonarCloud Quality Gate passed!    Quality Gate passed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 0 Code Smells

90.5% 90.5% Coverage
0.0% 0.0% Duplication

@msbarry msbarry merged commit 726e6d0 into main May 6, 2022
@msbarry msbarry deleted the parallel-feature-writes branch May 6, 2022 02:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[FEATURE] Parallel chunk writing in OSM pass2
1 participant