2020-04-14 21:38:39,713 utils.prepare_workspace(109) INFO Writing log messages to C:\Users\cfanslcp\Documents\ndr_workspace\InVEST-Nutrient-Delivery-Ratio-Model-(NDR)-log-2020-04-14--21_38_39.txt
2020-04-14 21:38:39,714 model._logged_target(1633) Level 100 Starting model with parameters: 
Arguments for InVEST natcap.invest.ndr.ndr 3.7.0:
biophysical_table_path       C:/Users/cfanslcp/Downloads/biophysical table.csv
calc_n                       True
calc_p                       True
dem_path                     C:/Users/cfanslcp/Downloads/Fill_DEM/fill_digital1.tif
k_param                      2
lulc_path                    C:/Users/cfanslcp/Downloads/drive-download-20200415T023746Z-001/N2016_TC.tif
n_workers                    -1
results_suffix               
runoff_proxy_path            C:/Users/cfanslcp/Downloads/precitipitation_tif-20200415T021402Z-001/precitipitation_tif/precip_1981_2010_annual1.tif
subsurface_critical_length_n 50
subsurface_critical_length_p 50
subsurface_eff_n             0.5
subsurface_eff_p             0.5
threshold_flow_accumulation  100
watersheds_path              C:/Users/cfanslcp/Downloads/watershed_04major_output-20200415T021610Z-001/watershed_04major_output/Export_Output.shp
workspace_dir                C:\Users\cfanslcp\Documents\ndr_workspace

2020-04-14 21:38:39,822 utils._log_gdal_errors(66) WARNING [errno 1] Value 52059861510.5 of field Shape_Area of feature 0 not successfully written. Possibly due to too larger number with respect to field width
2020-04-14 21:38:39,825 utils._log_gdal_errors(66) WARNING [errno 1] Value 38784418878.800003 of field Shape_Area of feature 1 not successfully written. Possibly due to too larger number with respect to field width
2020-04-14 21:38:39,825 utils._log_gdal_errors(66) WARNING [errno 1] Value 9105648344.3299999 of field Shape_Area of feature 2 not successfully written. Possibly due to too larger number with respect to field width
2020-04-14 21:38:39,826 utils._log_gdal_errors(66) WARNING [errno 1] Value 15272597794.799999 of field Shape_Area of feature 3 not successfully written. Possibly due to too larger number with respect to field width
2020-04-14 21:38:39,871 geoprocessing.align_and_resize_raster_stack(752) DEBUG n_workers == 1 so a threadpool is sufficient
2020-04-14 21:38:48,368 geoprocessing.logger_callback(3155) INFO Warp 80.0% complete C:\Users\cfanslcp\Documents\ndr_workspace\intermediate_outputs\cache_dir\aligned_dem.tif
2020-04-14 21:38:48,496 geoprocessing.logger_callback(3155) INFO Warp 100.0% complete C:\Users\cfanslcp\Documents\ndr_workspace\intermediate_outputs\cache_dir\aligned_dem.tif
2020-04-14 21:38:50,625 geoprocessing.align_and_resize_raster_stack(779) INFO 1 of 3 aligned: aligned_dem.tif
2020-04-14 21:38:56,632 geoprocessing.align_and_resize_raster_stack(779) INFO 2 of 3 aligned: aligned_lulc.tif
2020-04-14 21:38:58,194 geoprocessing.align_and_resize_raster_stack(779) INFO 3 of 3 aligned: aligned_runoff_proxy.tif
2020-04-14 21:38:58,296 geoprocessing.align_and_resize_raster_stack(788) INFO aligned all 3 rasters.
2020-04-14 21:39:04,030 Task._call(1068) INFO 22.0% complete
2020-04-14 21:39:10,009 Task._call(1068) INFO 95.1% complete
2020-04-14 21:39:10,392 Task._call(1068) INFO 100.0% complete
2020-04-14 21:39:16,066 Task._call(1068) INFO 7.3% complete
2020-04-14 21:39:22,178 Task._call(1068) INFO 29.3% complete
2020-04-14 21:39:28,253 Task._call(1068) INFO 51.2% complete
2020-04-14 21:39:34,003 Task._call(1068) INFO 65.9% complete
2020-04-14 21:39:40,058 Task._call(1068) INFO 87.8% complete
2020-04-14 21:39:44,890 Task._call(1068) INFO 100.0% complete
2020-04-14 21:40:01,822 Task._call(1068) INFO 65.9% complete
2020-04-14 21:40:04,976 Task._call(1068) INFO 100.0% complete
2020-04-14 21:40:13,701 Task._call(1068) INFO 65.9% complete
2020-04-14 21:40:15,357 Task._call(1068) INFO filter out incomplete divergent streams
2020-04-14 21:40:15,729 Task._call(1068) INFO 100.0% complete
2020-04-14 21:40:19,696 geoprocessing.raster_calculator(366) INFO starting stats_worker
2020-04-14 21:40:19,697 geoprocessing.raster_calculator(372) INFO started stats_worker <Thread(Thread-18, started daemon 18136)>
2020-04-14 21:40:20,063 geoprocessing.raster_calculator(445) INFO 100.0%% complete
2020-04-14 21:40:20,063 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate
2020-04-14 21:40:20,065 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result.
2020-04-14 21:40:20,065 threading.run(754) DEBUG payload is None, terminating
2020-04-14 21:40:22,653 geoprocessing.raster_calculator(366) INFO starting stats_worker
2020-04-14 21:40:22,654 geoprocessing.raster_calculator(372) INFO started stats_worker <Thread(Thread-19, started daemon 13824)>
2020-04-14 21:40:23,012 geoprocessing.raster_calculator(445) INFO 100.0%% complete
2020-04-14 21:40:23,012 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate
2020-04-14 21:40:23,012 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result.
2020-04-14 21:40:23,012 threading.run(754) DEBUG payload is None, terminating
2020-04-14 21:40:41,831 Task._call(1068) INFO 65.9% complete
2020-04-14 21:40:45,111 Task._call(1068) INFO 100.0% complete
2020-04-14 21:40:45,160 geoprocessing.raster_calculator(366) INFO starting stats_worker
2020-04-14 21:40:45,161 geoprocessing.raster_calculator(372) INFO started stats_worker <Thread(Thread-20, started daemon 27124)>
2020-04-14 21:40:48,029 geoprocessing.raster_calculator(445) INFO 100.0%% complete
2020-04-14 21:40:48,029 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate
2020-04-14 21:40:48,029 threading.run(754) DEBUG payload is None, terminating
2020-04-14 21:40:48,029 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result.
2020-04-14 21:40:49,009 geoprocessing.raster_calculator(366) INFO starting stats_worker
2020-04-14 21:40:49,009 geoprocessing.raster_calculator(372) INFO started stats_worker <Thread(Thread-21, started daemon 23592)>
2020-04-14 21:40:51,322 geoprocessing.raster_calculator(445) INFO 100.0%% complete
2020-04-14 21:40:51,323 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate
2020-04-14 21:40:51,325 threading.run(754) DEBUG payload is None, terminating
2020-04-14 21:40:51,323 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result.
2020-04-14 21:40:52,494 geoprocessing.raster_calculator(366) INFO starting stats_worker
2020-04-14 21:40:52,496 geoprocessing.raster_calculator(372) INFO started stats_worker <Thread(Thread-22, started daemon 27212)>
2020-04-14 21:40:52,959 geoprocessing.raster_calculator(445) INFO 100.0%% complete
2020-04-14 21:40:52,959 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate
2020-04-14 21:40:52,959 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result.
2020-04-14 21:40:52,960 threading.run(754) DEBUG payload is None, terminating
2020-04-14 21:41:01,061 Task._call(1068) INFO 36.6% complete
2020-04-14 21:41:07,049 Task._call(1068) INFO 73.2% complete
2020-04-14 21:41:12,190 Task._call(1068) INFO 100.0% complete
2020-04-14 21:41:18,009 Task._call(1068) INFO 43.9% complete
2020-04-14 21:41:24,022 Task._call(1068) INFO 87.8% complete
2020-04-14 21:41:26,092 Task._call(1068) INFO 100.0% complete
2020-04-14 21:41:26,134 geoprocessing.raster_calculator(366) INFO starting stats_worker
2020-04-14 21:41:26,135 geoprocessing.raster_calculator(372) INFO started stats_worker <Thread(Thread-23, started daemon 11160)>
2020-04-14 21:41:28,398 geoprocessing.raster_calculator(445) INFO 100.0%% complete
2020-04-14 21:41:28,398 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate
2020-04-14 21:41:28,398 threading.run(754) DEBUG payload is None, terminating
2020-04-14 21:41:28,398 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result.
2020-04-14 21:41:29,569 geoprocessing.raster_calculator(366) INFO starting stats_worker
2020-04-14 21:41:29,571 geoprocessing.raster_calculator(372) INFO started stats_worker <Thread(Thread-24, started daemon 15960)>
2020-04-14 21:41:29,582 threading.run(754) DEBUG payload is None, terminating
2020-04-14 21:41:29,582 geoprocessing.raster_calculator(477) INFO Waiting for raster stats worker result.
2020-04-14 21:41:29,582 threading.run(754) WARNING No valid pixels were received, sending None.
2020-04-14 21:41:29,585 Task.add_task(636) ERROR Something went wrong when adding task n load (16), terminating taskgraph.
Traceback (most recent call last):
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 602, in add_task
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 1068, in _call
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\ndr\ndr.py", line 771, in _calculate_load
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\pygeoprocessing\geoprocessing.py", line 415, in raster_calculator
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\ndr\ndr.py", line 765, in _map_load_op
KeyError: 128
2020-04-14 21:41:29,585 model._logged_target(1639) ERROR Exception while executing <function execute at 0x11B508B0>
Traceback (most recent call last):
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\ui\model.py", line 1636, in _logged_target
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\ndr\ndr.py", line 375, in execute
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 602, in add_task
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 1068, in _call
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\ndr\ndr.py", line 771, in _calculate_load
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\pygeoprocessing\geoprocessing.py", line 415, in raster_calculator
  File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\ndr\ndr.py", line 765, in _map_load_op
KeyError: 128
2020-04-14 21:41:29,585 model._logged_target(1642) INFO Execution finished
2020-04-14 21:41:29,586 utils.prepare_workspace(115) INFO Elapsed time: 2m 49.87s