2020-08-20 15:16:15,057 utils.prepare_workspace(111) INFO Writing log messages to /Users/mauromasiero/Desktop/Workspace/InVEST-UrbanFloodRiskMitigation-log-2020-08-20--15_16_15.txt 2020-08-20 15:16:15,058 model._logged_target(1629) Level 100 Starting model with parameters: Arguments for InVEST natcap.invest.urban_flood_risk_mitigation 3.8.7: aoi_watersheds_path /Volumes/Mauro Backup MAC TeSAF/Torino ES_GIS/Valutazione ES/Urban Flood Risk/TO_Bacini idrografici_completi.shp built_infrastructure_vector_path /Volumes/Mauro Backup MAC TeSAF/Torino ES_GIS/Valutazione ES/Urban Flood Risk/TO_Edifici_2.shp curve_number_table_path /Volumes/Mauro Backup MAC TeSAF/Torino ES_GIS/Valutazione ES/Urban Flood Risk/Biophysical Urban-Flood-Risk_1.csv infrastructure_damage_loss_table_path /Volumes/Mauro Backup MAC TeSAF/Torino ES_GIS/Valutazione ES/Urban Flood Risk/Damage.csv lulc_path /Volumes/Mauro Backup MAC TeSAF/Torino ES_GIS/Valutazione ES/Urban Flood Risk/TO_Uso suolo_Flood Risk Mitigation_1.tif n_workers -1 rainfall_depth 32.21 results_suffix _test1 soils_hydrological_group_raster_path /Volumes/Mauro Backup MAC TeSAF/Torino ES_GIS/Valutazione ES/Urban Flood Risk/Hydrologic Soil Grooups Torino_250m_1.tif workspace_dir /Users/mauromasiero/Desktop/Workspace 2020-08-20 15:16:15,059 validation._wrapped_validate_func(839) DEBUG Using ARG_SPEC for validation 2020-08-20 15:16:15,059 validation._wrapped_validate_func(843) INFO Starting whole-model validation with ARGS_SPEC 2020-08-20 15:16:15,193 validation._wrapped_validate_func(889) DEBUG Validation warnings: [] 2020-08-20 15:16:20,588 geoprocessing.logger_callback(3239) INFO Warp 54.0% complete /Users/mauromasiero/Desktop/Workspace/temp_working_dir_not_for_humans/aligned_lulc_test1.tif 2020-08-20 15:16:25,731 geoprocessing.logger_callback(3239) INFO Warp 97.0% complete /Users/mauromasiero/Desktop/Workspace/temp_working_dir_not_for_humans/aligned_lulc_test1.tif 2020-08-20 15:16:25,871 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete /Users/mauromasiero/Desktop/Workspace/temp_working_dir_not_for_humans/aligned_lulc_test1.tif 2020-08-20 15:16:27,687 geoprocessing.align_and_resize_raster_stack(752) INFO 1 of 2 aligned: aligned_lulc_test1.tif 2020-08-20 15:16:32,800 geoprocessing.logger_callback(3239) INFO Warp 54.0% complete /Users/mauromasiero/Desktop/Workspace/temp_working_dir_not_for_humans/aligned_soils_hydrological_group_test1.tif 2020-08-20 15:16:36,729 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete /Users/mauromasiero/Desktop/Workspace/temp_working_dir_not_for_humans/aligned_soils_hydrological_group_test1.tif 2020-08-20 15:16:39,668 geoprocessing.align_and_resize_raster_stack(752) INFO 2 of 2 aligned: aligned_soils_hydrological_group_test1.tif 2020-08-20 15:16:39,669 geoprocessing.align_and_resize_raster_stack(754) INFO aligned all 2 rasters. 2020-08-20 15:16:39,694 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-08-20 15:16:39,695 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-08-20 15:16:44,700 geoprocessing.(451) INFO 36.0% complete 2020-08-20 15:16:49,702 geoprocessing.(451) INFO 63.0% complete 2020-08-20 15:16:54,704 geoprocessing.(451) INFO 95.5% complete 2020-08-20 15:16:55,200 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-08-20 15:16:55,200 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-08-20 15:16:55,201 threading.run(870) DEBUG payload is None, terminating 2020-08-20 15:16:55,201 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-08-20 15:16:56,355 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-08-20 15:16:56,356 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-08-20 15:17:01,356 geoprocessing.(451) INFO 90.1% complete 2020-08-20 15:17:02,152 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-08-20 15:17:02,152 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-08-20 15:17:02,153 threading.run(870) DEBUG payload is None, terminating 2020-08-20 15:17:02,153 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-08-20 15:17:04,105 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-08-20 15:17:04,118 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-08-20 15:17:09,106 geoprocessing.(451) INFO 75.3% complete 2020-08-20 15:17:11,122 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-08-20 15:17:11,123 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-08-20 15:17:11,123 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-08-20 15:17:11,123 threading.run(870) DEBUG payload is None, terminating 2020-08-20 15:17:12,975 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-08-20 15:17:12,976 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-08-20 15:17:17,976 geoprocessing.(451) INFO 81.3% complete 2020-08-20 15:17:19,605 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-08-20 15:17:19,605 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-08-20 15:17:19,606 threading.run(870) DEBUG payload is None, terminating 2020-08-20 15:17:19,606 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-08-20 15:17:21,594 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-08-20 15:17:21,595 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-08-20 15:17:26,486 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-08-20 15:17:26,486 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-08-20 15:17:26,486 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-08-20 15:17:26,487 threading.run(870) DEBUG payload is None, terminating 2020-08-20 15:17:28,422 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-08-20 15:17:28,423 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-08-20 15:17:33,296 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-08-20 15:17:33,296 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-08-20 15:17:33,296 threading.run(870) DEBUG payload is None, terminating 2020-08-20 15:17:33,296 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-08-20 15:17:35,174 geoprocessing.reproject_vector(1594) WARNING /Users/mauromasiero/Desktop/Workspace/intermediate_files/reprojected_aoi.gpkg already exists, removing and overwriting 2020-08-20 15:17:35,180 geoprocessing.reproject_vector(1640) INFO starting reprojection 2020-08-20 15:17:35,196 geoprocessing.reproject_vector(1683) INFO reprojection 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:17:35,211 geoprocessing.zonal_statistics(1129) DEBUG > 2020-08-20 15:17:40,239 geoprocessing.logger_callback(3239) INFO Warp 74.0% complete /var/folders/wr/3jd6x5j94fb7nj2rr33dxysm0000gn/T/clipped_rasterxbkild5r.tif 2020-08-20 15:17:42,410 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete /var/folders/wr/3jd6x5j94fb7nj2rr33dxysm0000gn/T/clipped_rasterxbkild5r.tif 2020-08-20 15:17:44,504 geoprocessing.align_and_resize_raster_stack(752) INFO 1 of 1 aligned: clipped_rasterxbkild5r.tif 2020-08-20 15:17:44,505 geoprocessing.align_and_resize_raster_stack(754) INFO aligned all 1 rasters. 2020-08-20 15:17:44,506 geoprocessing.zonal_statistics(1189) INFO build a lookup of aggregate field value to FID 2020-08-20 15:17:44,506 geoprocessing.zonal_statistics(1196) INFO creating disjoint polygon set 2020-08-20 15:17:44,510 geoprocessing.calculate_disjoint_polygon_set(2082) INFO build shapely polygon list 2020-08-20 15:17:44,511 geoprocessing.calculate_disjoint_polygon_set(2096) INFO build shapely rtree index 2020-08-20 15:17:44,513 geoprocessing.calculate_disjoint_polygon_set(2111) INFO poly feature lookup 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:17:44,513 geoprocessing.calculate_disjoint_polygon_set(2113) INFO build poly intersection lookup 2020-08-20 15:17:44,517 geoprocessing.calculate_disjoint_polygon_set(2137) INFO poly intersection feature lookup 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:17:44,517 geoprocessing.calculate_disjoint_polygon_set(2171) INFO maximal subset build 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:17:44,544 geoprocessing.zonal_statistics(1219) INFO processing 3 disjoint polygon sets 2020-08-20 15:17:44,545 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 1 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:17:45,066 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 1 of 3 reprojected_aoi.gpkg 2020-08-20 15:17:51,586 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 1 of 3 reprojected_aoi.gpkg 2020-08-20 15:17:55,394 geoprocessing.(1225) INFO zonal stats approximately 66.7% complete on reprojected_aoi.gpkg 2020-08-20 15:17:55,395 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 2 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:17:55,609 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 2 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:02,154 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 2 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:05,789 geoprocessing.(1225) INFO zonal stats approximately 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:18:05,790 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 3 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:18:06,011 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 3 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:12,613 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 3 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:16,947 geoprocessing.zonal_statistics(1322) DEBUG unset_fids: 0 of 4 2020-08-20 15:18:16,947 geoprocessing.zonal_statistics(1325) DEBUG gt [ 1.3880541e+06 1.0000000e+00 0.0000000e+00 4.9993675e+06 0.0000000e+00 -1.0000000e+00] for ('/Users/mauromasiero/Desktop/Workspace/intermediate_files/Q_m3_test1.tif', 1) 2020-08-20 15:18:16,947 geoprocessing.zonal_statistics(1399) DEBUG remaining unset_fids: 0 of 4 2020-08-20 15:18:16,947 geoprocessing.zonal_statistics(1407) INFO all done processing polygon sets for reprojected_aoi.gpkg 2020-08-20 15:18:17,045 geoprocessing.zonal_statistics(1129) DEBUG > 2020-08-20 15:18:22,276 geoprocessing.logger_callback(3239) INFO Warp 79.0% complete /var/folders/wr/3jd6x5j94fb7nj2rr33dxysm0000gn/T/clipped_raster13do4dkf.tif 2020-08-20 15:18:23,896 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete /var/folders/wr/3jd6x5j94fb7nj2rr33dxysm0000gn/T/clipped_raster13do4dkf.tif 2020-08-20 15:18:25,997 geoprocessing.align_and_resize_raster_stack(752) INFO 1 of 1 aligned: clipped_raster13do4dkf.tif 2020-08-20 15:18:25,998 geoprocessing.align_and_resize_raster_stack(754) INFO aligned all 1 rasters. 2020-08-20 15:18:25,999 geoprocessing.zonal_statistics(1189) INFO build a lookup of aggregate field value to FID 2020-08-20 15:18:26,000 geoprocessing.zonal_statistics(1196) INFO creating disjoint polygon set 2020-08-20 15:18:26,003 geoprocessing.calculate_disjoint_polygon_set(2082) INFO build shapely polygon list 2020-08-20 15:18:26,004 geoprocessing.calculate_disjoint_polygon_set(2096) INFO build shapely rtree index 2020-08-20 15:18:26,006 geoprocessing.calculate_disjoint_polygon_set(2111) INFO poly feature lookup 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:18:26,006 geoprocessing.calculate_disjoint_polygon_set(2113) INFO build poly intersection lookup 2020-08-20 15:18:26,010 geoprocessing.calculate_disjoint_polygon_set(2137) INFO poly intersection feature lookup 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:18:26,011 geoprocessing.calculate_disjoint_polygon_set(2171) INFO maximal subset build 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:18:26,032 geoprocessing.zonal_statistics(1219) INFO processing 3 disjoint polygon sets 2020-08-20 15:18:26,033 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 1 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:18:26,550 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 1 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:33,101 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 1 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:36,899 geoprocessing.(1225) INFO zonal stats approximately 66.7% complete on reprojected_aoi.gpkg 2020-08-20 15:18:36,900 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 2 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:18:37,113 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 2 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:43,610 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 2 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:47,164 geoprocessing.(1225) INFO zonal stats approximately 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:18:47,165 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 3 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:18:47,384 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 3 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:54,078 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 3 of 3 reprojected_aoi.gpkg 2020-08-20 15:18:58,415 geoprocessing.zonal_statistics(1322) DEBUG unset_fids: 0 of 4 2020-08-20 15:18:58,415 geoprocessing.zonal_statistics(1325) DEBUG gt [ 1.3880541e+06 1.0000000e+00 0.0000000e+00 4.9993675e+06 0.0000000e+00 -1.0000000e+00] for ('/Users/mauromasiero/Desktop/Workspace/Runoff_retention_test1.tif', 1) 2020-08-20 15:18:58,415 geoprocessing.zonal_statistics(1399) DEBUG remaining unset_fids: 0 of 4 2020-08-20 15:18:58,415 geoprocessing.zonal_statistics(1407) INFO all done processing polygon sets for reprojected_aoi.gpkg 2020-08-20 15:18:58,520 geoprocessing.zonal_statistics(1129) DEBUG > 2020-08-20 15:19:03,687 geoprocessing.logger_callback(3239) INFO Warp 79.0% complete /var/folders/wr/3jd6x5j94fb7nj2rr33dxysm0000gn/T/clipped_rasterc1w4_mwr.tif 2020-08-20 15:19:05,309 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete /var/folders/wr/3jd6x5j94fb7nj2rr33dxysm0000gn/T/clipped_rasterc1w4_mwr.tif 2020-08-20 15:19:07,440 geoprocessing.align_and_resize_raster_stack(752) INFO 1 of 1 aligned: clipped_rasterc1w4_mwr.tif 2020-08-20 15:19:07,441 geoprocessing.align_and_resize_raster_stack(754) INFO aligned all 1 rasters. 2020-08-20 15:19:07,442 geoprocessing.zonal_statistics(1189) INFO build a lookup of aggregate field value to FID 2020-08-20 15:19:07,443 geoprocessing.zonal_statistics(1196) INFO creating disjoint polygon set 2020-08-20 15:19:07,446 geoprocessing.calculate_disjoint_polygon_set(2082) INFO build shapely polygon list 2020-08-20 15:19:07,447 geoprocessing.calculate_disjoint_polygon_set(2096) INFO build shapely rtree index 2020-08-20 15:19:07,448 geoprocessing.calculate_disjoint_polygon_set(2111) INFO poly feature lookup 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:19:07,448 geoprocessing.calculate_disjoint_polygon_set(2113) INFO build poly intersection lookup 2020-08-20 15:19:07,452 geoprocessing.calculate_disjoint_polygon_set(2137) INFO poly intersection feature lookup 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:19:07,452 geoprocessing.calculate_disjoint_polygon_set(2171) INFO maximal subset build 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:19:07,479 geoprocessing.zonal_statistics(1219) INFO processing 3 disjoint polygon sets 2020-08-20 15:19:07,479 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 1 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:19:07,993 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 1 of 3 reprojected_aoi.gpkg 2020-08-20 15:19:14,498 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 1 of 3 reprojected_aoi.gpkg 2020-08-20 15:19:18,330 geoprocessing.(1225) INFO zonal stats approximately 66.7% complete on reprojected_aoi.gpkg 2020-08-20 15:19:18,331 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 2 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:19:18,546 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 2 of 3 reprojected_aoi.gpkg 2020-08-20 15:19:25,040 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 2 of 3 reprojected_aoi.gpkg 2020-08-20 15:19:28,572 geoprocessing.(1225) INFO zonal stats approximately 100.0% complete on reprojected_aoi.gpkg 2020-08-20 15:19:28,573 geoprocessing.zonal_statistics(1253) INFO disjoint polygon set 3 of 3 100.0% processed on reprojected_aoi.gpkg 2020-08-20 15:19:28,788 geoprocessing.zonal_statistics(1261) INFO rasterizing disjoint polygon set 3 of 3 reprojected_aoi.gpkg 2020-08-20 15:19:35,285 geoprocessing.zonal_statistics(1279) INFO summarizing rasterized disjoint polygon set 3 of 3 reprojected_aoi.gpkg 2020-08-20 15:19:39,789 geoprocessing.zonal_statistics(1322) DEBUG unset_fids: 0 of 4 2020-08-20 15:19:39,789 geoprocessing.zonal_statistics(1325) DEBUG gt [ 1.3880541e+06 1.0000000e+00 0.0000000e+00 4.9993675e+06 0.0000000e+00 -1.0000000e+00] for ('/Users/mauromasiero/Desktop/Workspace/Runoff_retention_m3_test1.tif', 1) 2020-08-20 15:19:39,789 geoprocessing.zonal_statistics(1399) DEBUG remaining unset_fids: 0 of 4 2020-08-20 15:19:39,789 geoprocessing.zonal_statistics(1407) INFO all done processing polygon sets for reprojected_aoi.gpkg 2020-08-20 15:19:39,875 geoprocessing.reproject_vector(1594) WARNING /Users/mauromasiero/Desktop/Workspace/intermediate_files/structures_reprojected.gpkg already exists, removing and overwriting 2020-08-20 15:19:39,916 geoprocessing.reproject_vector(1640) INFO starting reprojection 2020-08-20 15:19:44,916 geoprocessing.(1646) INFO reprojection approximately 43.0% complete on structures_reprojected.gpkg 2020-08-20 15:19:50,013 geoprocessing.(1646) INFO reprojection approximately 85.0% complete on structures_reprojected.gpkg 2020-08-20 15:19:51,994 geoprocessing.reproject_vector(1683) INFO reprojection 100.0% complete on structures_reprojected.gpkg 2020-08-20 15:22:04,234 Task.add_task(731) ERROR Something went wrong when adding task calculate damage to infrastructure in aoi (12), terminating taskgraph. Traceback (most recent call last): File "site-packages/taskgraph/Task.py", line 697, in add_task File "site-packages/taskgraph/Task.py", line 1174, in _call File "site-packages/natcap/invest/urban_flood_risk_mitigation.py", line 606, in _calculate_damage_to_infrastructure_in_aoi KeyError: None 2020-08-20 15:22:04,236 model._logged_target(1635) ERROR Exception while executing Traceback (most recent call last): File "site-packages/natcap/invest/ui/model.py", line 1632, in _logged_target File "site-packages/natcap/invest/urban_flood_risk_mitigation.py", line 384, in execute File "site-packages/taskgraph/Task.py", line 697, in add_task File "site-packages/taskgraph/Task.py", line 1174, in _call File "site-packages/natcap/invest/urban_flood_risk_mitigation.py", line 606, in _calculate_damage_to_infrastructure_in_aoi KeyError: None 2020-08-20 15:22:04,236 model._logged_target(1638) INFO Execution finished 2020-08-20 15:22:04,237 utils.prepare_workspace(117) INFO Elapsed time: 5m 49.18000000000001s