2022-04-14 16:17:11,931 (natcap.invest.utils) utils.prepare_workspace(162) Level 100 Writing log messages to F:/Luke_GIS/World Bank Mazowe/Crops2\InVEST-Crop-Production-Percentile-log-2022-04-14--16_17_11.txt
2022-04-14 16:17:11,934 (natcap.invest.ui.model) model._logged_target(1643) Level 100 Starting model with parameters: 
Arguments for InVEST natcap.invest.crop_production_percentile 3.10.2:
aggregate_polygon_path       
landcover_raster_path        F:/Luke_GIS/World Bank Mazowe/Habitats/habitats_utm.tif
landcover_to_crop_table_path F:/Luke_GIS/World Bank Mazowe/Crops/crop_type.csv
model_data_path              C:/InVEST_3.9.0_x64/sample_data/CropProduction/model_data
n_workers                    -1
results_suffix               
workspace_dir                F:/Luke_GIS/World Bank Mazowe/Crops2

2022-04-14 16:17:11,991 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(374) INFO Processing crop maize
2022-04-14 16:17:11,992 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(379) INFO Clipping global climate bin raster to landcover bounding box.
2022-04-14 16:17:12,203 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(410) INFO Map yield_25th to climate bins.
2022-04-14 16:17:12,303 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:17:12,304 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:17:12,304 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-137, started daemon 10352)>
2022-04-14 16:17:12,306 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:17:12,306 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:17:12,474 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(441) INFO Interpolate maize yield_25th yield raster to landcover resolution.
2022-04-14 16:17:17,531 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 43.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_25th_interpolated_yield.tif
2022-04-14 16:17:22,636 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 83.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_25th_interpolated_yield.tif
2022-04-14 16:17:24,772 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 100.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_25th_interpolated_yield.tif
2022-04-14 16:17:30,176 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(458) INFO Calculate yield for maize at yield_25th
2022-04-14 16:17:30,220 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:17:30,222 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:17:30,222 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-138, started daemon 13088)>
2022-04-14 16:17:32,757 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:17:32,757 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:17:34,657 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(410) INFO Map yield_50th to climate bins.
2022-04-14 16:17:34,677 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:17:34,678 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:17:34,678 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-139, started daemon 15052)>
2022-04-14 16:17:34,680 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:17:34,680 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:17:34,815 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(441) INFO Interpolate maize yield_50th yield raster to landcover resolution.
2022-04-14 16:17:39,935 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 43.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_50th_interpolated_yield.tif
2022-04-14 16:17:45,025 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 85.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_50th_interpolated_yield.tif
2022-04-14 16:17:46,709 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 100.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_50th_interpolated_yield.tif
2022-04-14 16:17:52,488 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(458) INFO Calculate yield for maize at yield_50th
2022-04-14 16:17:52,529 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:17:52,531 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:17:52,531 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-140, started daemon 16028)>
2022-04-14 16:17:55,087 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:17:55,088 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:17:57,188 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(410) INFO Map yield_75th to climate bins.
2022-04-14 16:17:57,212 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:17:57,213 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:17:57,213 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-141, started daemon 15004)>
2022-04-14 16:17:57,215 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:17:57,215 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:17:57,380 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(441) INFO Interpolate maize yield_75th yield raster to landcover resolution.
2022-04-14 16:18:02,516 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 44.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_75th_interpolated_yield.tif
2022-04-14 16:18:07,603 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 88.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_75th_interpolated_yield.tif
2022-04-14 16:18:08,940 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 100.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_75th_interpolated_yield.tif
2022-04-14 16:18:14,747 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(458) INFO Calculate yield for maize at yield_75th
2022-04-14 16:18:14,812 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:18:14,813 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:18:14,813 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-142, started daemon 16120)>
2022-04-14 16:18:17,267 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:18:17,268 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:18:19,087 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(410) INFO Map yield_95th to climate bins.
2022-04-14 16:18:19,118 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:18:19,119 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:18:19,119 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-143, started daemon 15832)>
2022-04-14 16:18:19,121 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:18:19,121 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:18:19,278 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(441) INFO Interpolate maize yield_95th yield raster to landcover resolution.
2022-04-14 16:18:24,419 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 45.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_95th_interpolated_yield.tif
2022-04-14 16:18:29,512 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 90.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_95th_interpolated_yield.tif
2022-04-14 16:18:30,606 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 100.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_yield_95th_interpolated_yield.tif
2022-04-14 16:18:36,349 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(458) INFO Calculate yield for maize at yield_95th
2022-04-14 16:18:36,412 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:18:36,413 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:18:36,413 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-144, started daemon 16096)>
2022-04-14 16:18:38,658 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:18:38,658 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:18:40,491 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(481) INFO Calculate observed yield for maize
2022-04-14 16:18:40,662 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:18:40,664 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:18:40,664 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-145, started daemon 13000)>
2022-04-14 16:18:40,666 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:18:40,667 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:18:40,821 (natcap.invest.crop_production_percentile) crop_production_percentile.execute(524) INFO Interpolating observed maize raster to landcover.
2022-04-14 16:18:45,921 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 46.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_interpolated_observed_yield.tif
2022-04-14 16:18:51,004 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 92.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_interpolated_observed_yield.tif
2022-04-14 16:18:51,857 (pygeoprocessing.geoprocessing) geoprocessing.logger_callback(3320) INFO Warp 100.0% complete F:/Luke_GIS/World Bank Mazowe/Crops2\intermediate_output\maize_interpolated_observed_yield.tif
2022-04-14 16:19:01,079 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(396) INFO starting stats_worker
2022-04-14 16:19:01,080 (pygeoprocessing.geoprocessing_core) threading.run(870) DEBUG stats worker PID: 14440
2022-04-14 16:19:01,080 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(402) INFO started stats_worker <Thread(Thread-146, started daemon 440)>
2022-04-14 16:19:03,631 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(482) INFO 100.0% complete
2022-04-14 16:19:03,632 (pygeoprocessing.geoprocessing) geoprocessing.raster_calculator(485) INFO Waiting for raster stats worker result.
2022-04-14 16:19:06,058 (natcap.invest.crop_production_percentile) crop_production_percentile.tabulate_results(734) INFO Generating report table
2022-04-14 16:19:06,059 (natcap.invest.crop_production_percentile) crop_production_percentile.tabulate_results(762) INFO Calculating production area and summing observed yield.
2022-04-14 16:19:06,066 (taskgraph.Task) Task.add_task(706) ERROR Something went wrong when adding task tabulate_results (17), terminating taskgraph.
Traceback (most recent call last):
  File "taskgraph\Task.py", line 674, in add_task
  File "taskgraph\Task.py", line 1093, in _call
  File "natcap\invest\crop_production_percentile.py", line 776, in tabulate_results
TypeError: unsupported operand type(s) for &: 'slice' and 'bool'
2022-04-14 16:19:06,070 (natcap.invest.utils) utils.prepare_workspace(167) ERROR Exception while executing Crop-Production-Percentile
Traceback (most recent call last):
  File "natcap\invest\utils.py", line 165, in prepare_workspace
  File "natcap\invest\ui\model.py", line 1649, in _logged_target
  File "natcap\invest\crop_production_percentile.py", line 563, in execute
  File "taskgraph\Task.py", line 674, in add_task
  File "taskgraph\Task.py", line 1093, in _call
  File "natcap\invest\crop_production_percentile.py", line 776, in tabulate_results
TypeError: unsupported operand type(s) for &: 'slice' and 'bool'
2022-04-14 16:19:06,071 (natcap.invest.utils) utils.prepare_workspace(170) INFO Elapsed time: 1m 54.14s
2022-04-14 16:19:06,072 (natcap.invest.utils) utils.prepare_workspace(173) INFO Execution finished