2020-09-12 19:05:43,856 utils.prepare_workspace(123) INFO Writing log messages to D:/SanDiskSecureAccess Vault/Colombia/WY/Output\InVEST-Hydropower-Water-Yield-log-2020-09-12--19_05_43.txt
2020-09-12 19:05:43,858 model._logged_target(1629) Level 100 Starting model with parameters: 
Arguments for InVEST natcap.invest.hydropower.hydropower_water_yield 3.8.6.post249+ge7d67881:
biophysical_table_path        D:/SanDiskSecureAccess Vault/Colombia/WY/wy_biophysical_table_lulc300.csv
depth_to_root_rest_layer_path D:/SanDiskSecureAccess Vault/Colombia/WY/processing/depth_comp_0.tif
do_scarcity_and_valuation     False
eto_path                      D:/SanDiskSecureAccess Vault/Colombia/WY/processing/et0_comp_0.tif
lulc_path                     D:/SanDiskSecureAccess Vault/Colombia/WY/processing/lulc_300_clip-2.tif
n_workers                     -1
pawc_path                     D:/SanDiskSecureAccess Vault/Colombia/WY/processing/pawc_comp_0.tif
precipitation_path            D:/SanDiskSecureAccess Vault/Colombia/WY/processing/1970-_comp_0.tif
results_suffix                
seasonality_constant          5
sub_watersheds_path           
watersheds_path               D:/SanDiskSecureAccess Vault/Colombia/selectedWB3857.gpkg
workspace_dir                 D:/SanDiskSecureAccess Vault/Colombia/WY/Output

2020-09-12 19:05:43,957 hydropower_water_yield.execute(269) INFO Validating arguments
2020-09-12 19:05:43,958 validation._wrapped_validate_func(839) DEBUG Using ARG_SPEC for validation
2020-09-12 19:05:43,958 validation._wrapped_validate_func(843) INFO Starting whole-model validation with ARGS_SPEC
2020-09-12 19:05:44,376 validation._wrapped_validate_func(889) DEBUG Validation warnings: []
2020-09-12 19:05:53,020 geoprocessing.logger_callback(3287) INFO Warp 1.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:06:04,165 geoprocessing.logger_callback(3287) INFO Warp 13.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:06:16,987 geoprocessing.logger_callback(3287) INFO Warp 26.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:06:30,681 geoprocessing.logger_callback(3287) INFO Warp 38.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:06:44,278 geoprocessing.logger_callback(3287) INFO Warp 51.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:06:58,110 geoprocessing.logger_callback(3287) INFO Warp 63.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:07:11,627 geoprocessing.logger_callback(3287) INFO Warp 76.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:07:24,367 geoprocessing.logger_callback(3287) INFO Warp 88.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:07:27,949 geoprocessing.logger_callback(3287) INFO Warp 100.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\eto.tif
2020-09-12 19:07:28,704 geoprocessing.align_and_resize_raster_stack(738) INFO 1 of 5 aligned: eto.tif
2020-09-12 19:07:37,129 geoprocessing.logger_callback(3287) INFO Warp 1.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:07:50,172 geoprocessing.logger_callback(3287) INFO Warp 13.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:08:04,534 geoprocessing.logger_callback(3287) INFO Warp 26.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:08:19,676 geoprocessing.logger_callback(3287) INFO Warp 38.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:08:33,983 geoprocessing.logger_callback(3287) INFO Warp 51.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:08:39,128 geoprocessing.logger_callback(3287) INFO Warp 61.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:08:52,102 geoprocessing.logger_callback(3287) INFO Warp 63.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:09:06,854 geoprocessing.logger_callback(3287) INFO Warp 76.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:09:20,705 geoprocessing.logger_callback(3287) INFO Warp 88.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:09:24,537 geoprocessing.logger_callback(3287) INFO Warp 100.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\precip.tif
2020-09-12 19:09:25,658 geoprocessing.align_and_resize_raster_stack(738) INFO 2 of 5 aligned: precip.tif
2020-09-12 19:09:33,976 geoprocessing.logger_callback(3287) INFO Warp 1.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:09:47,383 geoprocessing.logger_callback(3287) INFO Warp 13.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:10:01,679 geoprocessing.logger_callback(3287) INFO Warp 26.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:10:06,992 geoprocessing.logger_callback(3287) INFO Warp 36.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:10:18,240 geoprocessing.logger_callback(3287) INFO Warp 38.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:10:23,427 geoprocessing.logger_callback(3287) INFO Warp 49.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:10:36,745 geoprocessing.logger_callback(3287) INFO Warp 51.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:10:42,513 geoprocessing.logger_callback(3287) INFO Warp 61.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:10:57,757 geoprocessing.logger_callback(3287) INFO Warp 63.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:11:03,477 geoprocessing.logger_callback(3287) INFO Warp 74.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:11:37,275 geoprocessing.logger_callback(3287) INFO Warp 76.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:11:52,754 geoprocessing.logger_callback(3287) INFO Warp 88.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:11:57,002 geoprocessing.logger_callback(3287) INFO Warp 100.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\depth_to_root_rest_layer.tif
2020-09-12 19:11:59,701 geoprocessing.align_and_resize_raster_stack(738) INFO 3 of 5 aligned: depth_to_root_rest_layer.tif
2020-09-12 19:12:08,126 geoprocessing.logger_callback(3287) INFO Warp 1.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:12:21,119 geoprocessing.logger_callback(3287) INFO Warp 13.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:12:34,457 geoprocessing.logger_callback(3287) INFO Warp 26.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:12:56,235 geoprocessing.logger_callback(3287) INFO Warp 38.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:13:10,333 geoprocessing.logger_callback(3287) INFO Warp 51.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:13:24,551 geoprocessing.logger_callback(3287) INFO Warp 63.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:13:39,078 geoprocessing.logger_callback(3287) INFO Warp 76.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:13:52,497 geoprocessing.logger_callback(3287) INFO Warp 88.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:13:56,187 geoprocessing.logger_callback(3287) INFO Warp 100.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\pawc.tif
2020-09-12 19:13:57,468 geoprocessing.align_and_resize_raster_stack(738) INFO 4 of 5 aligned: pawc.tif
2020-09-12 19:14:02,549 geoprocessing.logger_callback(3287) INFO Warp 16.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\clipped_lulc.tif
2020-09-12 19:14:07,607 geoprocessing.logger_callback(3287) INFO Warp 31.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\clipped_lulc.tif
2020-09-12 19:14:13,862 geoprocessing.logger_callback(3287) INFO Warp 51.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\clipped_lulc.tif
2020-09-12 19:14:20,404 geoprocessing.logger_callback(3287) INFO Warp 76.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\clipped_lulc.tif
2020-09-12 19:14:23,548 geoprocessing.logger_callback(3287) INFO Warp 100.0% complete D:/SanDiskSecureAccess Vault/Colombia/WY/Output\intermediate\clipped_lulc.tif
2020-09-12 19:14:24,101 geoprocessing.align_and_resize_raster_stack(738) INFO 5 of 5 aligned: clipped_lulc.tif
2020-09-12 19:14:24,101 geoprocessing.align_and_resize_raster_stack(740) INFO aligned all 5 rasters.
2020-09-12 19:14:24,435 hydropower_water_yield.execute(404) DEBUG bio_lucodes {0, 130, 10, 11, 12, 140, 20, 150, 151, 152, 153, 30, 160, 40, 170, None, 50, 180, 60, 61, 62, 190, 70, 71, 72, 200, 201, 202, 80, 81, 82, 210, 90, 220, 100, 110, 120, 121, 122}
2020-09-12 19:14:24,450 hydropower_water_yield._check_missing_lucodes(904) INFO Checking that input tables have landcover codes for every value in the landcover map.
2020-09-12 19:14:32,185 hydropower_water_yield.execute(458) INFO Reclassifying temp_Kc raster
2020-09-12 19:14:32,316 geoprocessing.raster_calculator(352) INFO starting stats_worker
2020-09-12 19:14:32,318 geoprocessing.raster_calculator(358) INFO started stats_worker <Thread(Thread-2, started daemon 10860)>
2020-09-12 19:14:37,317 geoprocessing.<lambda>(428) INFO 17.2% complete
2020-09-12 19:14:42,323 geoprocessing.<lambda>(428) INFO 31.0% complete
2020-09-12 19:14:47,325 geoprocessing.<lambda>(428) INFO 44.0% complete
2020-09-12 19:14:52,328 geoprocessing.<lambda>(428) INFO 57.5% complete
2020-09-12 19:14:57,331 geoprocessing.<lambda>(428) INFO 71.1% complete
2020-09-12 19:15:02,333 geoprocessing.<lambda>(428) INFO 85.6% complete
2020-09-12 19:15:06,976 geoprocessing.raster_calculator(431) INFO 100.0%% complete
2020-09-12 19:15:06,977 geoprocessing.raster_calculator(434) INFO signaling stats worker to terminate
2020-09-12 19:15:06,977 geoprocessing.raster_calculator(436) INFO Waiting for raster stats worker result.
2020-09-12 19:15:06,978 threading.run(870) DEBUG payload is None, terminating
2020-09-12 19:15:07,989 hydropower_water_yield.execute(470) INFO Reclassifying tmp_root raster
2020-09-12 19:15:08,108 geoprocessing.raster_calculator(352) INFO starting stats_worker
2020-09-12 19:15:08,109 geoprocessing.raster_calculator(358) INFO started stats_worker <Thread(Thread-3, started daemon 5896)>
2020-09-12 19:15:13,113 geoprocessing.<lambda>(428) INFO 19.5% complete
2020-09-12 19:15:18,115 geoprocessing.<lambda>(428) INFO 34.3% complete
2020-09-12 19:15:23,118 geoprocessing.<lambda>(428) INFO 49.1% complete
2020-09-12 19:15:28,123 geoprocessing.<lambda>(428) INFO 64.3% complete
2020-09-12 19:15:33,126 geoprocessing.<lambda>(428) INFO 80.4% complete
2020-09-12 19:15:38,127 geoprocessing.<lambda>(428) INFO 98.0% complete
2020-09-12 19:15:38,701 geoprocessing.raster_calculator(431) INFO 100.0%% complete
2020-09-12 19:15:38,702 geoprocessing.raster_calculator(434) INFO signaling stats worker to terminate
2020-09-12 19:15:38,702 geoprocessing.raster_calculator(436) INFO Waiting for raster stats worker result.
2020-09-12 19:15:38,702 threading.run(870) DEBUG payload is None, terminating
2020-09-12 19:15:39,466 hydropower_water_yield.execute(484) INFO Reclassifying tmp_veg raster
2020-09-12 19:15:39,585 geoprocessing.raster_calculator(352) INFO starting stats_worker
2020-09-12 19:15:39,586 geoprocessing.raster_calculator(358) INFO started stats_worker <Thread(Thread-4, started daemon 12364)>
2020-09-12 19:15:44,589 geoprocessing.<lambda>(428) INFO 20.1% complete
2020-09-12 19:15:49,591 geoprocessing.<lambda>(428) INFO 36.1% complete
2020-09-12 19:15:54,596 geoprocessing.<lambda>(428) INFO 52.1% complete
2020-09-12 19:15:59,596 geoprocessing.<lambda>(428) INFO 68.2% complete
2020-09-12 19:16:04,598 geoprocessing.<lambda>(428) INFO 84.9% complete
2020-09-12 19:16:08,681 geoprocessing.raster_calculator(431) INFO 100.0%% complete
2020-09-12 19:16:08,681 geoprocessing.raster_calculator(434) INFO signaling stats worker to terminate
2020-09-12 19:16:08,682 geoprocessing.raster_calculator(436) INFO Waiting for raster stats worker result.
2020-09-12 19:16:08,682 threading.run(870) DEBUG payload is None, terminating
2020-09-12 19:16:09,403 hydropower_water_yield.execute(497) INFO Calculate PET from Ref Evap times Kc
2020-09-12 19:16:09,520 geoprocessing.raster_calculator(352) INFO starting stats_worker
2020-09-12 19:16:09,521 geoprocessing.raster_calculator(358) INFO started stats_worker <Thread(Thread-5, started daemon 6084)>
2020-09-12 19:16:10,289 geoprocessing.raster_calculator(463) INFO Waiting for raster stats worker result.
2020-09-12 19:16:10,290 threading.run(870) DEBUG payload is None, terminating
2020-09-12 19:16:10,290 threading.run(870) WARNING No valid pixels were received, sending None.
2020-09-12 19:16:10,290 Task.add_task(731) ERROR Something went wrong when adding task calculate_pet (5), 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\pygeoprocessing\geoprocessing.py", line 401, in raster_calculator
  File "site-packages\natcap\invest\hydropower\hydropower_water_yield.py", line 874, in pet_op
  File "<__array_function__ internals>", line 6, in isclose
  File "site-packages\numpy\core\numeric.py", line 2288, in isclose
TypeError: ufunc 'isfinite' not supported for the input types, and the inputs could not be safely coerced to any supported types according to the casting rule ''safe''
2020-09-12 19:16:10,292 model._logged_target(1635) ERROR Exception while executing <function execute at 0x10256B28>
Traceback (most recent call last):
  File "site-packages\natcap\invest\ui\model.py", line 1632, in _logged_target
  File "site-packages\natcap\invest\hydropower\hydropower_water_yield.py", line 507, 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\pygeoprocessing\geoprocessing.py", line 401, in raster_calculator
  File "site-packages\natcap\invest\hydropower\hydropower_water_yield.py", line 874, in pet_op
  File "<__array_function__ internals>", line 6, in isclose
  File "site-packages\numpy\core\numeric.py", line 2288, in isclose
TypeError: ufunc 'isfinite' not supported for the input types, and the inputs could not be safely coerced to any supported types according to the casting rule ''safe''
2020-09-12 19:16:10,293 model._logged_target(1638) INFO Execution finished
2020-09-12 19:16:10,295 utils.prepare_workspace(129) INFO Elapsed time: 10m 26.440000000000055s