2021-05-12 15:29:24,113 utils.prepare_workspace(123) INFO Writing log messages to E:/thesis/invest/INVEST/INVEST/NDR/data\InVEST-Nutrient-Delivery-Ratio-Model-(NDR)-log-2021-05-12--15_29_24.txt
2021-05-12 15:29:24,115 model._logged_target(1646) Level 100 Starting model with parameters: 
Arguments for InVEST natcap.invest.ndr.ndr 3.9.0:
biophysical_table_path       E:/thesis/invest/INVEST/INVEST/NDR/data/biophysical_table1.csv
calc_n                       True
calc_p                       False
dem_path                     E:/thesis/invest/INVEST/INVEST/NDR/data/Fill_dem_100m.tif
k_param                      2
lulc_path                    E:/thesis/invest/INVEST/INVEST/NDR/data/Landuse2009.tif
n_workers                    -1
results_suffix               Corine2009
runoff_proxy_path            E:/thesis/invest/INVEST/INVEST/NDR/data/precipitation09.tif
subsurface_critical_length_n 200
subsurface_critical_length_p 
subsurface_eff_n             0.8
subsurface_eff_p             
threshold_flow_accumulation  200
watersheds_path              E:/thesis/invest/INVEST/INVEST/NDR/data/Export_Output.shp
workspace_dir                E:/thesis/invest/INVEST/INVEST/NDR/data

2021-05-12 15:29:24,184 utils.build_lookup_from_csv(528) WARNING Empty or NaN values were found in the table: E:/thesis/invest/INVEST/INVEST/NDR/data/biophysical_table1.csv.
2021-05-12 15:29:26,149 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:26,150 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:26,150 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-236, started daemon 13972)>
2021-05-12 15:29:26,356 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:26,356 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:26,635 geoprocessing.align_and_resize_raster_stack(795) INFO 1 of 3 aligned: aligned_dem_Corine2009.tif
2021-05-12 15:29:27,723 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:27,724 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:27,724 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-237, started daemon 13144)>
2021-05-12 15:29:27,894 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:27,894 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:28,069 geoprocessing.align_and_resize_raster_stack(795) INFO 2 of 3 aligned: aligned_lulc_Corine2009.tif
2021-05-12 15:29:29,247 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:29,248 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:29,248 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-238, started daemon 13348)>
2021-05-12 15:29:29,468 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:29,468 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:29,760 geoprocessing.align_and_resize_raster_stack(795) INFO 3 of 3 aligned: aligned_runoff_proxy_Corine2009.tif
2021-05-12 15:29:29,760 geoprocessing.align_and_resize_raster_stack(797) INFO aligned all 3 rasters.
2021-05-12 15:29:32,646 Task._call(1234) INFO 100.0% complete
2021-05-12 15:29:36,251 Task._call(1234) INFO 100.0% complete
2021-05-12 15:29:36,269 Task._call(1234) DEBUG creating target flow accum raster layer
2021-05-12 15:29:36,659 Task._call(1234) DEBUG creating visited raster layer
2021-05-12 15:29:36,740 Task._call(1234) DEBUG starting search
2021-05-12 15:29:40,302 Task._call(1234) INFO 100.0% complete
2021-05-12 15:29:42,110 Task._call(1234) INFO filter out incomplete divergent streams
2021-05-12 15:29:42,177 Task._call(1234) INFO 100.0% complete
2021-05-12 15:29:42,930 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:42,932 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:42,932 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-239, started daemon 18504)>
2021-05-12 15:29:43,170 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:43,170 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:43,763 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:43,764 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:43,764 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-240, started daemon 14204)>
2021-05-12 15:29:44,064 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:44,064 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:44,193 Task._call(1234) DEBUG creating target flow accum raster layer
2021-05-12 15:29:44,582 Task._call(1234) DEBUG creating visited raster layer
2021-05-12 15:29:44,709 Task._call(1234) DEBUG starting search
2021-05-12 15:29:48,572 Task._call(1234) INFO 100.0% complete
2021-05-12 15:29:48,703 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:48,703 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:48,703 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-241, started daemon 16908)>
2021-05-12 15:29:49,386 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:49,386 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:49,784 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:49,785 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:49,785 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-242, started daemon 13608)>
2021-05-12 15:29:50,324 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:50,325 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:50,723 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:50,723 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:50,723 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-243, started daemon 19168)>
2021-05-12 15:29:50,971 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:50,971 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:54,666 Task._call(1234) INFO 100.0% complete
2021-05-12 15:29:57,634 Task._call(1234) INFO 100.0% complete
2021-05-12 15:29:57,752 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:57,753 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:57,753 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-244, started daemon 17880)>
2021-05-12 15:29:58,355 geoprocessing.raster_calculator(477) INFO 100.0% complete
2021-05-12 15:29:58,356 geoprocessing.raster_calculator(480) INFO Waiting for raster stats worker result.
2021-05-12 15:29:58,752 geoprocessing.raster_calculator(391) INFO starting stats_worker
2021-05-12 15:29:58,753 threading.run(870) DEBUG stats worker PID: 12092
2021-05-12 15:29:58,753 geoprocessing.raster_calculator(397) INFO started stats_worker <Thread(Thread-245, started daemon 3384)>
2021-05-12 15:29:58,756 geoprocessing.raster_calculator(507) INFO Waiting for raster stats worker result.
2021-05-12 15:29:58,756 threading.run(870) WARNING No valid pixels were received, sending None.
2021-05-12 15:29:58,757 Task.add_task(781) ERROR Something went wrong when adding task n load (16), terminating taskgraph.
Traceback (most recent call last):
  File "site-packages\natcap\invest\ndr\ndr.py", line 934, in _map_load_op
KeyError: -3.4e+38

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "site-packages\taskgraph\Task.py", line 747, in add_task
  File "site-packages\taskgraph\Task.py", line 1234, in _call
  File "site-packages\natcap\invest\ndr\ndr.py", line 944, in _calculate_load
  File "site-packages\pygeoprocessing\geoprocessing.py", line 438, in raster_calculator
  File "site-packages\natcap\invest\ndr\ndr.py", line 939, in _map_load_op
KeyError: 'lucode: -339999995214436424907732413799364296704 is present in the landuse raster but missing from the biophysical table'
2021-05-12 15:29:58,758 model._logged_target(1652) ERROR Exception while executing <function execute at 0x0000029AE7147CA8>
Traceback (most recent call last):
  File "site-packages\natcap\invest\ndr\ndr.py", line 934, in _map_load_op
KeyError: -3.4e+38

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "site-packages\natcap\invest\ui\model.py", line 1649, in _logged_target
  File "site-packages\natcap\invest\ndr\ndr.py", line 568, in execute
  File "site-packages\taskgraph\Task.py", line 747, in add_task
  File "site-packages\taskgraph\Task.py", line 1234, in _call
  File "site-packages\natcap\invest\ndr\ndr.py", line 944, in _calculate_load
  File "site-packages\pygeoprocessing\geoprocessing.py", line 438, in raster_calculator
  File "site-packages\natcap\invest\ndr\ndr.py", line 939, in _map_load_op
KeyError: 'lucode: -339999995214436424907732413799364296704 is present in the landuse raster but missing from the biophysical table'
2021-05-12 15:29:58,759 model._logged_target(1655) INFO Execution finished
2021-05-12 15:29:58,761 utils.prepare_workspace(129) INFO Elapsed time: 34.65s