2020-03-05 14:37:28,817 utils.prepare_workspace(115) INFO Writing log messages to F:/NDR\InVEST-Nutrient-Delivery-Ratio-Model-(NDR)-log-2020-03-05--14_37_28.txt 2020-03-05 14:37:28,820 model._logged_target(1642) Level 100 Starting model with parameters: Arguments for InVEST natcap.invest.ndr.ndr 3.8.0: biophysical_table_path F:/Models/Data/NDR/JD_NDR_last2020/INPUT_DATA/Bio_Table_NDR_antigo_s532.csv calc_n True calc_p True dem_path F:/Models/Data/NDR/JD_NDR_last2020/INPUT_DATA/dem_30m/dem_Clipbacias.tif k_param 2 lulc_path F:/CLC/CLC_TIFF/CLC1990/CLC1990.tif n_workers -1 results_suffix runoff_proxy_path F:/Models/Data/NDR/JD_NDR_last2020/INPUT_DATA/Nutrient_Proxy_antigo/Nut_proxy.tif subsurface_critical_length_n 200 subsurface_critical_length_p 200 subsurface_eff_n 0.8 subsurface_eff_p 0.8 threshold_flow_accumulation 1000 watersheds_path F:/Models/Data/NDR/JD_NDR_last2020/INPUT_DATA/Bacias_Hidrograficas/bacias_clip_ws.shp workspace_dir F:/NDR 2020-03-05 14:37:35,558 geoprocessing.logger_callback(3239) INFO Warp 19.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_dem.tif 2020-03-05 14:37:40,611 geoprocessing.logger_callback(3239) INFO Warp 39.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_dem.tif 2020-03-05 14:37:45,786 geoprocessing.logger_callback(3239) INFO Warp 57.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_dem.tif 2020-03-05 14:37:51,052 geoprocessing.logger_callback(3239) INFO Warp 82.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_dem.tif 2020-03-05 14:37:53,821 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_dem.tif 2020-03-05 14:38:03,999 geoprocessing.logger_callback(3243) INFO p_progress_arg is None df_complete: 0.9824478402800776, message: RasterizeLayer %.1f%% complete %s 2020-03-05 14:38:04,200 geoprocessing.logger_callback(3243) INFO p_progress_arg is None df_complete: 1.0, message: RasterizeLayer %.1f%% complete %s 2020-03-05 14:38:04,704 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-03-05 14:38:04,711 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-03-05 14:38:09,709 geoprocessing.(451) INFO 27.2% complete 2020-03-05 14:38:14,721 geoprocessing.(451) INFO 45.2% complete 2020-03-05 14:38:19,722 geoprocessing.(451) INFO 64.3% complete 2020-03-05 14:38:24,723 geoprocessing.(451) INFO 87.7% complete 2020-03-05 14:38:26,783 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-03-05 14:38:26,783 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-03-05 14:38:26,784 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-03-05 14:38:26,784 threading.run(870) DEBUG payload is None, terminating 2020-03-05 14:38:27,573 geoprocessing.align_and_resize_raster_stack(752) INFO 1 of 3 aligned: aligned_dem.tif 2020-03-05 14:38:32,805 geoprocessing.logger_callback(3239) INFO Warp 63.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_lulc.tif 2020-03-05 14:38:35,332 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_lulc.tif 2020-03-05 14:38:45,934 geoprocessing.logger_callback(3243) INFO p_progress_arg is None df_complete: 0.9824478402800776, message: RasterizeLayer %.1f%% complete %s 2020-03-05 14:38:46,156 geoprocessing.logger_callback(3243) INFO p_progress_arg is None df_complete: 1.0, message: RasterizeLayer %.1f%% complete %s 2020-03-05 14:38:46,702 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-03-05 14:38:46,706 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-03-05 14:38:51,703 geoprocessing.(451) INFO 65.1% complete 2020-03-05 14:38:54,286 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-03-05 14:38:54,287 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-03-05 14:38:54,287 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-03-05 14:38:54,408 threading.run(870) DEBUG payload is None, terminating 2020-03-05 14:38:54,789 geoprocessing.align_and_resize_raster_stack(752) INFO 2 of 3 aligned: aligned_lulc.tif 2020-03-05 14:38:59,840 geoprocessing.logger_callback(3239) INFO Warp 93.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_runoff_proxy.tif 2020-03-05 14:39:00,195 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete F:/NDR\intermediate_outputs\cache_dir\aligned_runoff_proxy.tif 2020-03-05 14:39:10,761 geoprocessing.logger_callback(3243) INFO p_progress_arg is None df_complete: 0.9824478402800776, message: RasterizeLayer %.1f%% complete %s 2020-03-05 14:39:10,981 geoprocessing.logger_callback(3243) INFO p_progress_arg is None df_complete: 1.0, message: RasterizeLayer %.1f%% complete %s 2020-03-05 14:39:11,504 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-03-05 14:39:11,505 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-03-05 14:39:16,351 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-03-05 14:39:16,352 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-03-05 14:39:16,352 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-03-05 14:39:16,550 threading.run(870) DEBUG payload is None, terminating 2020-03-05 14:39:17,003 geoprocessing.align_and_resize_raster_stack(752) INFO 3 of 3 aligned: aligned_runoff_proxy.tif 2020-03-05 14:39:17,004 geoprocessing.align_and_resize_raster_stack(754) INFO aligned all 3 rasters. 2020-03-05 14:39:26,203 geoprocessing.(886) INFO 71.1% complete 2020-03-05 14:39:52,193 Task._call(1071) INFO 0.0% complete 2020-03-05 14:39:58,157 Task._call(1071) INFO 6.1% complete 2020-03-05 14:40:04,091 Task._call(1071) INFO 7.3% complete 2020-03-05 14:40:10,095 Task._call(1071) INFO 9.7% complete 2020-03-05 14:40:16,027 Task._call(1071) INFO 10.9% complete 2020-03-05 14:40:22,196 Task._call(1071) INFO 13.3% complete 2020-03-05 14:40:28,027 Task._call(1071) INFO 14.5% complete 2020-03-05 14:40:34,001 Task._call(1071) INFO 15.7% complete 2020-03-05 14:40:40,101 Task._call(1071) INFO 18.2% complete 2020-03-05 14:40:46,002 Task._call(1071) INFO 20.6% complete 2020-03-05 14:40:52,003 Task._call(1071) INFO 24.2% complete 2020-03-05 14:40:58,010 Task._call(1071) INFO 25.4% complete 2020-03-05 14:41:04,055 Task._call(1071) INFO 27.9% complete 2020-03-05 14:41:10,074 Task._call(1071) INFO 30.3% complete 2020-03-05 14:41:16,085 Task._call(1071) INFO 32.7% complete 2020-03-05 14:41:22,014 Task._call(1071) INFO 35.1% complete 2020-03-05 14:41:28,091 Task._call(1071) INFO 37.5% complete 2020-03-05 14:41:34,131 Task._call(1071) INFO 40.0% complete 2020-03-05 14:41:40,085 Task._call(1071) INFO 41.2% complete 2020-03-05 14:41:46,042 Task._call(1071) INFO 43.6% complete 2020-03-05 14:41:52,090 Task._call(1071) INFO 44.8% complete 2020-03-05 14:41:58,269 Task._call(1071) INFO 47.2% complete 2020-03-05 14:42:04,072 Task._call(1071) INFO 50.9% complete 2020-03-05 14:42:10,020 Task._call(1071) INFO 52.1% complete 2020-03-05 14:42:16,091 Task._call(1071) INFO 54.5% complete 2020-03-05 14:42:22,012 Task._call(1071) INFO 56.9% complete 2020-03-05 14:42:28,070 Task._call(1071) INFO 58.1% complete 2020-03-05 14:42:34,126 Task._call(1071) INFO 59.3% complete 2020-03-05 14:42:40,030 Task._call(1071) INFO 61.8% complete 2020-03-05 14:42:46,111 Task._call(1071) INFO 63.0% complete 2020-03-05 14:42:52,057 Task._call(1071) INFO 64.2% complete 2020-03-05 14:42:58,042 Task._call(1071) INFO 66.6% complete 2020-03-05 14:43:04,016 Task._call(1071) INFO 69.0% complete 2020-03-05 14:43:10,108 Task._call(1071) INFO 70.2% complete 2020-03-05 14:43:16,020 Task._call(1071) INFO 72.7% complete 2020-03-05 14:43:22,151 Task._call(1071) INFO 76.3% complete 2020-03-05 14:43:28,118 Task._call(1071) INFO 78.7% complete 2020-03-05 14:43:34,067 Task._call(1071) INFO 79.9% complete 2020-03-05 14:43:40,057 Task._call(1071) INFO 83.6% complete 2020-03-05 14:43:46,039 Task._call(1071) INFO 89.6% complete 2020-03-05 14:43:52,058 Task._call(1071) INFO 94.5% complete 2020-03-05 14:43:56,221 Task._call(1071) INFO 100.0% complete 2020-03-05 14:44:05,257 geoprocessing.(886) INFO 83.3% complete 2020-03-05 14:44:15,998 geoprocessing.(886) INFO 45.8% complete 2020-03-05 14:44:20,999 geoprocessing.(886) INFO 82.8% complete 2020-03-05 14:44:23,893 Task._call(1071) INFO 0.0% complete 2020-03-05 14:44:29,406 Task._call(1071) INFO 4.8% complete 2020-03-05 14:44:35,107 Task._call(1071) INFO 6.1% complete 2020-03-05 14:44:41,355 Task._call(1071) INFO 6.1% complete 2020-03-05 14:44:47,226 Task._call(1071) INFO 7.3% complete 2020-03-05 14:44:53,075 Task._call(1071) INFO 7.3% complete 2020-03-05 14:44:59,235 Task._call(1071) INFO 8.5% complete 2020-03-05 14:45:05,110 Task._call(1071) INFO 8.5% complete 2020-03-05 14:45:11,429 Task._call(1071) INFO 9.7% complete 2020-03-05 14:45:17,342 Task._call(1071) INFO 9.7% complete 2020-03-05 14:45:23,303 Task._call(1071) INFO 10.9% complete 2020-03-05 14:45:29,102 Task._call(1071) INFO 10.9% complete 2020-03-05 14:45:35,035 Task._call(1071) INFO 10.9% complete 2020-03-05 14:45:41,285 Task._call(1071) INFO 12.1% complete 2020-03-05 14:45:47,228 Task._call(1071) INFO 12.1% complete 2020-03-05 14:45:53,225 Task._call(1071) INFO 13.3% complete 2020-03-05 14:45:59,411 Task._call(1071) INFO 13.3% complete 2020-03-05 14:46:05,213 Task._call(1071) INFO 14.5% complete 2020-03-05 14:46:11,104 Task._call(1071) INFO 14.5% complete 2020-03-05 14:46:17,269 Task._call(1071) INFO 15.7% complete 2020-03-05 14:46:23,168 Task._call(1071) INFO 15.7% complete 2020-03-05 14:46:29,356 Task._call(1071) INFO 17.0% complete 2020-03-05 14:46:35,181 Task._call(1071) INFO 17.0% complete 2020-03-05 14:46:41,336 Task._call(1071) INFO 18.2% complete 2020-03-05 14:46:47,066 Task._call(1071) INFO 19.4% complete 2020-03-05 14:46:53,105 Task._call(1071) INFO 19.4% complete 2020-03-05 14:46:59,208 Task._call(1071) INFO 20.6% complete 2020-03-05 14:47:05,380 Task._call(1071) INFO 21.8% complete 2020-03-05 14:47:11,128 Task._call(1071) INFO 21.8% complete 2020-03-05 14:47:17,113 Task._call(1071) INFO 23.0% complete 2020-03-05 14:47:23,003 Task._call(1071) INFO 24.2% complete 2020-03-05 14:47:29,741 Task._call(1071) INFO 25.4% complete 2020-03-05 14:47:35,040 Task._call(1071) INFO 25.4% complete 2020-03-05 14:47:41,285 Task._call(1071) INFO 26.6% complete 2020-03-05 14:47:47,046 Task._call(1071) INFO 26.6% complete 2020-03-05 14:47:53,308 Task._call(1071) INFO 27.9% complete 2020-03-05 14:47:59,163 Task._call(1071) INFO 27.9% complete 2020-03-05 14:48:05,010 Task._call(1071) INFO 29.1% complete 2020-03-05 14:48:11,292 Task._call(1071) INFO 30.3% complete 2020-03-05 14:48:17,332 Task._call(1071) INFO 30.3% complete 2020-03-05 14:48:23,122 Task._call(1071) INFO 31.5% complete 2020-03-05 14:48:29,163 Task._call(1071) INFO 31.5% complete 2020-03-05 14:48:35,186 Task._call(1071) INFO 32.7% complete 2020-03-05 14:48:41,056 Task._call(1071) INFO 33.9% complete 2020-03-05 14:48:47,014 Task._call(1071) INFO 33.9% complete 2020-03-05 14:48:53,065 Task._call(1071) INFO 35.1% complete 2020-03-05 14:48:59,298 Task._call(1071) INFO 35.1% complete 2020-03-05 14:49:05,285 Task._call(1071) INFO 36.3% complete 2020-03-05 14:49:11,232 Task._call(1071) INFO 37.5% complete 2020-03-05 14:49:17,381 Task._call(1071) INFO 37.5% complete 2020-03-05 14:49:23,568 Task._call(1071) INFO 38.8% complete 2020-03-05 14:49:29,040 Task._call(1071) INFO 38.8% complete 2020-03-05 14:49:34,999 Task._call(1071) INFO 40.0% complete 2020-03-05 14:49:41,043 Task._call(1071) INFO 40.0% complete 2020-03-05 14:49:47,057 Task._call(1071) INFO 41.2% complete 2020-03-05 14:49:53,277 Task._call(1071) INFO 42.4% complete 2020-03-05 14:49:59,002 Task._call(1071) INFO 42.4% complete 2020-03-05 14:50:05,544 Task._call(1071) INFO 43.6% complete 2020-03-05 14:50:11,381 Task._call(1071) INFO 43.6% complete 2020-03-05 14:50:17,515 Task._call(1071) INFO 43.6% complete 2020-03-05 14:50:23,007 Task._call(1071) INFO 44.8% complete 2020-03-05 14:50:29,126 Task._call(1071) INFO 46.0% complete 2020-03-05 14:50:35,330 Task._call(1071) INFO 46.0% complete 2020-03-05 14:50:41,204 Task._call(1071) INFO 47.2% complete 2020-03-05 14:50:47,246 Task._call(1071) INFO 47.2% complete 2020-03-05 14:50:53,186 Task._call(1071) INFO 48.4% complete 2020-03-05 14:50:59,044 Task._call(1071) INFO 48.4% complete 2020-03-05 14:51:05,398 Task._call(1071) INFO 50.9% complete 2020-03-05 14:51:11,392 Task._call(1071) INFO 50.9% complete 2020-03-05 14:51:17,227 Task._call(1071) INFO 52.1% complete 2020-03-05 14:51:23,311 Task._call(1071) INFO 52.1% complete 2020-03-05 14:51:29,174 Task._call(1071) INFO 53.3% complete 2020-03-05 14:51:35,205 Task._call(1071) INFO 53.3% complete 2020-03-05 14:51:41,240 Task._call(1071) INFO 54.5% complete 2020-03-05 14:51:47,350 Task._call(1071) INFO 54.5% complete 2020-03-05 14:51:53,349 Task._call(1071) INFO 55.7% complete 2020-03-05 14:51:59,447 Task._call(1071) INFO 56.9% complete 2020-03-05 14:52:05,027 Task._call(1071) INFO 56.9% complete 2020-03-05 14:52:11,079 Task._call(1071) INFO 56.9% complete 2020-03-05 14:52:17,036 Task._call(1071) INFO 58.1% complete 2020-03-05 14:52:23,003 Task._call(1071) INFO 58.1% complete 2020-03-05 14:52:30,409 Task._call(1071) INFO 59.3% complete 2020-03-05 14:52:36,439 Task._call(1071) INFO 59.3% complete 2020-03-05 14:52:42,124 Task._call(1071) INFO 59.3% complete 2020-03-05 14:52:48,381 Task._call(1071) INFO 60.6% complete 2020-03-05 14:52:54,054 Task._call(1071) INFO 60.6% complete 2020-03-05 14:53:00,498 Task._call(1071) INFO 61.8% complete 2020-03-05 14:53:06,133 Task._call(1071) INFO 61.8% complete 2020-03-05 14:53:12,129 Task._call(1071) INFO 63.0% complete 2020-03-05 14:53:18,210 Task._call(1071) INFO 63.0% complete 2020-03-05 14:53:24,374 Task._call(1071) INFO 63.0% complete 2020-03-05 14:53:30,196 Task._call(1071) INFO 64.2% complete 2020-03-05 14:53:36,254 Task._call(1071) INFO 64.2% complete 2020-03-05 14:53:42,368 Task._call(1071) INFO 65.4% complete 2020-03-05 14:53:48,310 Task._call(1071) INFO 65.4% complete 2020-03-05 14:53:54,166 Task._call(1071) INFO 66.6% complete 2020-03-05 14:54:00,535 Task._call(1071) INFO 66.6% complete 2020-03-05 14:54:06,443 Task._call(1071) INFO 67.8% complete 2020-03-05 14:54:12,168 Task._call(1071) INFO 67.8% complete 2020-03-05 14:54:19,258 Task._call(1071) INFO 69.0% complete 2020-03-05 14:54:25,038 Task._call(1071) INFO 69.0% complete 2020-03-05 14:54:31,175 Task._call(1071) INFO 70.2% complete 2020-03-05 14:54:37,311 Task._call(1071) INFO 70.2% complete 2020-03-05 14:54:43,533 Task._call(1071) INFO 71.5% complete 2020-03-05 14:54:50,348 Task._call(1071) INFO 71.5% complete 2020-03-05 14:54:56,302 Task._call(1071) INFO 72.7% complete 2020-03-05 14:55:02,046 Task._call(1071) INFO 73.9% complete 2020-03-05 14:55:08,060 Task._call(1071) INFO 75.1% complete 2020-03-05 14:55:14,255 Task._call(1071) INFO 76.3% complete 2020-03-05 14:55:20,474 Task._call(1071) INFO 77.5% complete 2020-03-05 14:55:26,305 Task._call(1071) INFO 77.5% complete 2020-03-05 14:55:32,164 Task._call(1071) INFO 78.7% complete 2020-03-05 14:55:40,086 Task._call(1071) INFO 78.7% complete 2020-03-05 14:55:46,046 Task._call(1071) INFO 79.9% complete 2020-03-05 14:55:52,438 Task._call(1071) INFO 79.9% complete 2020-03-05 14:55:58,062 Task._call(1071) INFO 81.1% complete 2020-03-05 14:56:04,031 Task._call(1071) INFO 82.4% complete 2020-03-05 14:56:10,018 Task._call(1071) INFO 83.6% complete 2020-03-05 14:56:16,300 Task._call(1071) INFO 86.0% complete 2020-03-05 14:56:22,153 Task._call(1071) INFO 87.2% complete 2020-03-05 14:56:28,063 Task._call(1071) INFO 89.6% complete 2020-03-05 14:56:34,108 Task._call(1071) INFO 90.8% complete 2020-03-05 14:56:40,036 Task._call(1071) INFO 93.3% complete 2020-03-05 14:56:46,021 Task._call(1071) INFO 95.7% complete 2020-03-05 14:56:52,027 Task._call(1071) INFO 96.9% complete 2020-03-05 14:56:55,213 Task._call(1071) INFO 100.0% complete 2020-03-05 14:56:55,247 Task._call(1071) DEBUG creating target flow accum raster layer 2020-03-05 14:57:00,257 geoprocessing.(886) INFO 38.1% complete 2020-03-05 14:57:05,260 geoprocessing.(886) INFO 72.6% complete 2020-03-05 14:57:10,358 Task._call(1071) DEBUG creating visited raster layer 2020-03-05 14:57:10,389 Task._call(1071) DEBUG starting search 2020-03-05 14:57:10,390 Task._call(1071) INFO 0.0% complete 2020-03-05 14:57:16,000 Task._call(1071) INFO mfd flow accum 0.9% complete 2020-03-05 14:57:22,030 Task._call(1071) INFO mfd flow accum 1.7% complete 2020-03-05 14:57:27,999 Task._call(1071) INFO mfd flow accum 2.4% complete 2020-03-05 14:57:34,030 Task._call(1071) INFO mfd flow accum 3.2% complete 2020-03-05 14:57:40,033 Task._call(1071) INFO mfd flow accum 4.1% complete 2020-03-05 14:57:46,090 Task._call(1071) INFO mfd flow accum 4.8% complete 2020-03-05 14:57:51,999 Task._call(1071) INFO mfd flow accum 5.4% complete 2020-03-05 14:57:58,000 Task._call(1071) INFO mfd flow accum 6.3% complete 2020-03-05 14:58:04,000 Task._call(1071) INFO mfd flow accum 7.1% complete 2020-03-05 14:58:10,000 Task._call(1071) INFO mfd flow accum 7.7% complete 2020-03-05 14:58:16,133 Task._call(1071) INFO mfd flow accum 8.6% complete 2020-03-05 14:58:22,074 Task._call(1071) INFO mfd flow accum 9.3% complete 2020-03-05 14:58:27,999 Task._call(1071) INFO mfd flow accum 10.0% complete 2020-03-05 14:58:34,000 Task._call(1071) INFO mfd flow accum 10.9% complete 2020-03-05 14:58:40,011 Task._call(1071) INFO mfd flow accum 11.7% complete 2020-03-05 14:58:46,129 Task._call(1071) INFO mfd flow accum 12.5% complete 2020-03-05 14:58:52,057 Task._call(1071) INFO mfd flow accum 13.1% complete 2020-03-05 14:58:58,062 Task._call(1071) INFO mfd flow accum 13.8% complete 2020-03-05 14:59:04,000 Task._call(1071) INFO 21.8% complete 2020-03-05 14:59:10,041 Task._call(1071) INFO mfd flow accum 15.2% complete 2020-03-05 14:59:16,000 Task._call(1071) INFO mfd flow accum 15.9% complete 2020-03-05 14:59:22,053 Task._call(1071) INFO mfd flow accum 17.0% complete 2020-03-05 14:59:27,999 Task._call(1071) INFO mfd flow accum 17.5% complete 2020-03-05 14:59:34,024 Task._call(1071) INFO mfd flow accum 18.0% complete 2020-03-05 14:59:40,031 Task._call(1071) INFO mfd flow accum 18.7% complete 2020-03-05 14:59:46,000 Task._call(1071) INFO mfd flow accum 19.6% complete 2020-03-05 14:59:51,999 Task._call(1071) INFO mfd flow accum 20.6% complete 2020-03-05 14:59:58,007 Task._call(1071) INFO mfd flow accum 21.2% complete 2020-03-05 15:00:03,999 Task._call(1071) INFO mfd flow accum 21.8% complete 2020-03-05 15:00:09,999 Task._call(1071) INFO mfd flow accum 22.4% complete 2020-03-05 15:00:16,000 Task._call(1071) INFO mfd flow accum 23.1% complete 2020-03-05 15:00:22,000 Task._call(1071) INFO mfd flow accum 23.9% complete 2020-03-05 15:00:28,049 Task._call(1071) INFO mfd flow accum 24.6% complete 2020-03-05 15:00:34,062 Task._call(1071) INFO mfd flow accum 25.4% complete 2020-03-05 15:00:40,034 Task._call(1071) INFO mfd flow accum 26.1% complete 2020-03-05 15:00:46,000 Task._call(1071) INFO mfd flow accum 26.8% complete 2020-03-05 15:00:52,004 Task._call(1071) INFO mfd flow accum 27.7% complete 2020-03-05 15:00:58,002 Task._call(1071) INFO mfd flow accum 28.4% complete 2020-03-05 15:01:04,010 Task._call(1071) INFO mfd flow accum 29.4% complete 2020-03-05 15:01:09,999 Task._call(1071) INFO mfd flow accum 30.0% complete 2020-03-05 15:01:15,999 Task._call(1071) INFO mfd flow accum 31.0% complete 2020-03-05 15:01:21,999 Task._call(1071) INFO mfd flow accum 31.7% complete 2020-03-05 15:01:28,206 Task._call(1071) INFO mfd flow accum 32.6% complete 2020-03-05 15:01:34,060 Task._call(1071) INFO mfd flow accum 33.4% complete 2020-03-05 15:01:40,016 Task._call(1071) INFO mfd flow accum 34.0% complete 2020-03-05 15:01:46,000 Task._call(1071) INFO mfd flow accum 34.8% complete 2020-03-05 15:01:51,999 Task._call(1071) INFO mfd flow accum 35.5% complete 2020-03-05 15:01:58,000 Task._call(1071) INFO mfd flow accum 36.2% complete 2020-03-05 15:02:04,027 Task._call(1071) INFO mfd flow accum 37.3% complete 2020-03-05 15:02:10,007 Task._call(1071) INFO mfd flow accum 38.0% complete 2020-03-05 15:02:16,017 Task._call(1071) INFO mfd flow accum 38.6% complete 2020-03-05 15:02:22,028 Task._call(1071) INFO mfd flow accum 39.2% complete 2020-03-05 15:02:28,000 Task._call(1071) INFO mfd flow accum 40.1% complete 2020-03-05 15:02:33,999 Task._call(1071) INFO mfd flow accum 40.7% complete 2020-03-05 15:02:40,000 Task._call(1071) INFO mfd flow accum 41.8% complete 2020-03-05 15:02:46,023 Task._call(1071) INFO mfd flow accum 42.7% complete 2020-03-05 15:02:51,999 Task._call(1071) INFO mfd flow accum 43.5% complete 2020-03-05 15:02:58,000 Task._call(1071) INFO mfd flow accum 44.3% complete 2020-03-05 15:03:03,999 Task._call(1071) INFO mfd flow accum 45.1% complete 2020-03-05 15:03:10,046 Task._call(1071) INFO mfd flow accum 45.7% complete 2020-03-05 15:03:16,000 Task._call(1071) INFO mfd flow accum 46.6% complete 2020-03-05 15:03:22,018 Task._call(1071) INFO mfd flow accum 47.1% complete 2020-03-05 15:03:28,000 Task._call(1071) INFO mfd flow accum 47.7% complete 2020-03-05 15:03:34,000 Task._call(1071) INFO mfd flow accum 48.6% complete 2020-03-05 15:03:40,001 Task._call(1071) INFO mfd flow accum 49.3% complete 2020-03-05 15:03:45,999 Task._call(1071) INFO mfd flow accum 50.3% complete 2020-03-05 15:03:51,999 Task._call(1071) INFO mfd flow accum 51.2% complete 2020-03-05 15:03:58,034 Task._call(1071) INFO mfd flow accum 52.0% complete 2020-03-05 15:04:04,028 Task._call(1071) INFO mfd flow accum 52.9% complete 2020-03-05 15:04:10,044 Task._call(1071) INFO mfd flow accum 53.6% complete 2020-03-05 15:04:16,026 Task._call(1071) INFO mfd flow accum 54.6% complete 2020-03-05 15:04:23,624 Task._call(1071) INFO 100.0% complete 2020-03-05 15:04:33,004 Task._call(1071) INFO 6.1% complete 2020-03-05 15:04:39,000 Task._call(1071) INFO 9.7% complete 2020-03-05 15:04:44,999 Task._call(1071) INFO 12.1% complete 2020-03-05 15:04:51,010 Task._call(1071) INFO 14.5% complete 2020-03-05 15:04:57,002 Task._call(1071) INFO 18.2% complete 2020-03-05 15:05:13,452 Task._call(1071) INFO 19.4% complete 2020-03-05 15:05:21,010 Task._call(1071) INFO 20.6% complete 2020-03-05 15:05:27,011 Task._call(1071) INFO 25.4% complete 2020-03-05 15:05:35,407 Task._call(1071) INFO 29.1% complete 2020-03-05 15:05:40,999 Task._call(1071) INFO 32.7% complete 2020-03-05 15:05:46,999 Task._call(1071) INFO 33.9% complete 2020-03-05 15:05:59,428 Task._call(1071) INFO 37.5% complete 2020-03-05 15:06:05,002 Task._call(1071) INFO 41.2% complete 2020-03-05 15:06:11,165 Task._call(1071) INFO 43.6% complete 2020-03-05 15:06:16,999 Task._call(1071) INFO 46.0% complete 2020-03-05 15:06:23,000 Task._call(1071) INFO 47.2% complete 2020-03-05 15:06:29,057 Task._call(1071) INFO 52.1% complete 2020-03-05 15:06:34,999 Task._call(1071) INFO 55.7% complete 2020-03-05 15:06:40,999 Task._call(1071) INFO 59.3% complete 2020-03-05 15:07:01,630 Task._call(1071) INFO 63.0% complete 2020-03-05 15:07:11,897 Task._call(1071) INFO 63.0% complete 2020-03-05 15:07:17,025 Task._call(1071) INFO 65.4% complete 2020-03-05 15:07:23,023 Task._call(1071) INFO 69.0% complete 2020-03-05 15:07:32,310 Task._call(1071) INFO 70.2% complete 2020-03-05 15:07:38,014 Task._call(1071) INFO 72.7% complete 2020-03-05 15:07:43,999 Task._call(1071) INFO 78.7% complete 2020-03-05 15:07:50,002 Task._call(1071) INFO 83.6% complete 2020-03-05 15:07:56,000 Task._call(1071) INFO 88.4% complete 2020-03-05 15:08:02,196 Task._call(1071) INFO 88.4% complete 2020-03-05 15:08:07,999 Task._call(1071) INFO 94.5% complete 2020-03-05 15:08:14,004 Task._call(1071) INFO filter out incomplete divergent streams 2020-03-05 15:08:16,504 Task._call(1071) INFO 100.0% complete 2020-03-05 15:08:21,586 geoprocessing.(886) INFO 85.1% complete 2020-03-05 15:09:24,350 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-03-05 15:09:24,352 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-03-05 15:09:29,375 geoprocessing.(451) INFO 15.4% complete 2020-03-05 15:09:34,394 geoprocessing.(451) INFO 22.3% complete 2020-03-05 15:09:39,410 geoprocessing.(451) INFO 28.3% complete 2020-03-05 15:09:44,417 geoprocessing.(451) INFO 35.8% complete 2020-03-05 15:09:49,444 geoprocessing.(451) INFO 43.1% complete 2020-03-05 15:09:54,474 geoprocessing.(451) INFO 50.1% complete 2020-03-05 15:09:59,497 geoprocessing.(451) INFO 57.3% complete 2020-03-05 15:10:04,502 geoprocessing.(451) INFO 65.6% complete 2020-03-05 15:10:09,508 geoprocessing.(451) INFO 73.7% complete 2020-03-05 15:10:14,517 geoprocessing.(451) INFO 84.2% complete 2020-03-05 15:10:19,522 geoprocessing.(451) INFO 96.2% complete 2020-03-05 15:10:21,990 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-03-05 15:10:21,991 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-03-05 15:10:21,992 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-03-05 15:10:21,992 threading.run(870) DEBUG payload is None, terminating 2020-03-05 15:10:28,423 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-03-05 15:10:28,424 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-03-05 15:10:33,424 geoprocessing.(451) INFO 34.2% complete 2020-03-05 15:10:38,426 geoprocessing.(451) INFO 63.8% complete 2020-03-05 15:10:43,427 geoprocessing.(451) INFO 98.0% complete 2020-03-05 15:10:43,839 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-03-05 15:10:43,839 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-03-05 15:10:43,840 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-03-05 15:10:43,841 threading.run(870) DEBUG payload is None, terminating 2020-03-05 15:10:44,453 Task._call(1071) DEBUG creating target flow accum raster layer 2020-03-05 15:10:49,468 geoprocessing.(886) INFO 32.1% complete 2020-03-05 15:10:54,468 geoprocessing.(886) INFO 56.7% complete 2020-03-05 15:10:59,469 geoprocessing.(886) INFO 83.9% complete 2020-03-05 15:11:03,757 Task._call(1071) DEBUG creating visited raster layer 2020-03-05 15:11:03,797 Task._call(1071) DEBUG starting search 2020-03-05 15:11:03,798 Task._call(1071) INFO 0.0% complete 2020-03-05 15:11:08,999 Task._call(1071) INFO mfd flow accum 0.8% complete 2020-03-05 15:11:14,999 Task._call(1071) INFO mfd flow accum 1.6% complete 2020-03-05 15:11:20,999 Task._call(1071) INFO mfd flow accum 2.3% complete 2020-03-05 15:11:26,999 Task._call(1071) INFO mfd flow accum 3.2% complete 2020-03-05 15:11:33,000 Task._call(1071) INFO 18.2% complete 2020-03-05 15:11:38,999 Task._call(1071) INFO mfd flow accum 4.7% complete 2020-03-05 15:11:45,053 Task._call(1071) INFO mfd flow accum 5.3% complete 2020-03-05 15:11:50,999 Task._call(1071) INFO mfd flow accum 6.1% complete 2020-03-05 15:11:57,024 Task._call(1071) INFO mfd flow accum 7.0% complete 2020-03-05 15:12:03,000 Task._call(1071) INFO mfd flow accum 7.5% complete 2020-03-05 15:12:09,039 Task._call(1071) INFO mfd flow accum 8.4% complete 2020-03-05 15:12:15,020 Task._call(1071) INFO mfd flow accum 9.2% complete 2020-03-05 15:12:21,070 Task._call(1071) INFO mfd flow accum 9.7% complete 2020-03-05 15:12:27,066 Task._call(1071) INFO mfd flow accum 10.7% complete 2020-03-05 15:12:33,039 Task._call(1071) INFO mfd flow accum 11.4% complete 2020-03-05 15:12:38,999 Task._call(1071) INFO mfd flow accum 12.2% complete 2020-03-05 15:12:45,046 Task._call(1071) INFO mfd flow accum 12.8% complete 2020-03-05 15:12:50,999 Task._call(1071) INFO mfd flow accum 13.3% complete 2020-03-05 15:12:57,100 Task._call(1071) INFO mfd flow accum 14.3% complete 2020-03-05 15:13:02,999 Task._call(1071) INFO mfd flow accum 14.9% complete 2020-03-05 15:13:09,015 Task._call(1071) INFO mfd flow accum 15.4% complete 2020-03-05 15:13:15,109 Task._call(1071) INFO mfd flow accum 16.3% complete 2020-03-05 15:13:21,003 Task._call(1071) INFO 29.1% complete 2020-03-05 15:13:27,002 Task._call(1071) INFO 36.3% complete 2020-03-05 15:13:33,043 Task._call(1071) INFO mfd flow accum 18.1% complete 2020-03-05 15:13:39,039 Task._call(1071) INFO mfd flow accum 18.7% complete 2020-03-05 15:13:45,000 Task._call(1071) INFO mfd flow accum 19.7% complete 2020-03-05 15:13:51,109 Task._call(1071) INFO mfd flow accum 20.6% complete 2020-03-05 15:13:56,999 Task._call(1071) INFO mfd flow accum 21.3% complete 2020-03-05 15:14:03,028 Task._call(1071) INFO mfd flow accum 21.9% complete 2020-03-05 15:14:09,005 Task._call(1071) INFO mfd flow accum 22.5% complete 2020-03-05 15:14:14,999 Task._call(1071) INFO mfd flow accum 23.1% complete 2020-03-05 15:14:21,019 Task._call(1071) INFO mfd flow accum 23.9% complete 2020-03-05 15:14:27,014 Task._call(1071) INFO mfd flow accum 24.6% complete 2020-03-05 15:14:33,069 Task._call(1071) INFO mfd flow accum 25.4% complete 2020-03-05 15:14:39,003 Task._call(1071) INFO 60.6% complete 2020-03-05 15:14:44,999 Task._call(1071) INFO mfd flow accum 26.7% complete 2020-03-05 15:14:51,005 Task._call(1071) INFO mfd flow accum 27.5% complete 2020-03-05 15:14:57,007 Task._call(1071) INFO mfd flow accum 28.0% complete 2020-03-05 15:15:02,999 Task._call(1071) INFO mfd flow accum 29.0% complete 2020-03-05 15:15:09,059 Task._call(1071) INFO mfd flow accum 29.8% complete 2020-03-05 15:15:14,999 Task._call(1071) INFO mfd flow accum 30.3% complete 2020-03-05 15:15:21,116 Task._call(1071) INFO mfd flow accum 31.3% complete 2020-03-05 15:15:26,999 Task._call(1071) INFO mfd flow accum 32.1% complete 2020-03-05 15:15:33,000 Task._call(1071) INFO mfd flow accum 32.8% complete 2020-03-05 15:15:38,999 Task._call(1071) INFO mfd flow accum 33.6% complete 2020-03-05 15:15:45,000 Task._call(1071) INFO mfd flow accum 34.0% complete 2020-03-05 15:15:51,035 Task._call(1071) INFO mfd flow accum 34.9% complete 2020-03-05 15:15:56,999 Task._call(1071) INFO mfd flow accum 35.6% complete 2020-03-05 15:16:02,999 Task._call(1071) INFO mfd flow accum 36.1% complete 2020-03-05 15:16:08,999 Task._call(1071) INFO mfd flow accum 37.2% complete 2020-03-05 15:16:15,000 Task._call(1071) INFO mfd flow accum 37.9% complete 2020-03-05 15:16:21,006 Task._call(1071) INFO mfd flow accum 38.5% complete 2020-03-05 15:16:27,069 Task._call(1071) INFO mfd flow accum 38.9% complete 2020-03-05 15:16:32,999 Task._call(1071) INFO mfd flow accum 39.5% complete 2020-03-05 15:16:38,999 Task._call(1071) INFO mfd flow accum 40.4% complete 2020-03-05 15:16:44,999 Task._call(1071) INFO mfd flow accum 41.0% complete 2020-03-05 15:16:51,084 Task._call(1071) INFO mfd flow accum 41.9% complete 2020-03-05 15:16:56,999 Task._call(1071) INFO mfd flow accum 42.7% complete 2020-03-05 15:17:03,035 Task._call(1071) INFO mfd flow accum 43.4% complete 2020-03-05 15:17:09,135 Task._call(1071) INFO mfd flow accum 44.2% complete 2020-03-05 15:17:14,999 Task._call(1071) INFO mfd flow accum 45.0% complete 2020-03-05 15:17:21,195 Task._call(1071) INFO mfd flow accum 45.5% complete 2020-03-05 15:17:27,018 Task._call(1071) INFO mfd flow accum 46.3% complete 2020-03-05 15:17:32,999 Task._call(1071) INFO mfd flow accum 46.9% complete 2020-03-05 15:17:39,064 Task._call(1071) INFO mfd flow accum 47.4% complete 2020-03-05 15:17:45,000 Task._call(1071) INFO mfd flow accum 48.1% complete 2020-03-05 15:17:51,000 Task._call(1071) INFO mfd flow accum 48.9% complete 2020-03-05 15:17:57,000 Task._call(1071) INFO mfd flow accum 49.5% complete 2020-03-05 15:18:03,060 Task._call(1071) INFO mfd flow accum 50.5% complete 2020-03-05 15:18:08,999 Task._call(1071) INFO mfd flow accum 51.3% complete 2020-03-05 15:18:15,136 Task._call(1071) INFO mfd flow accum 52.0% complete 2020-03-05 15:18:20,999 Task._call(1071) INFO mfd flow accum 52.8% complete 2020-03-05 15:18:26,999 Task._call(1071) INFO mfd flow accum 53.4% complete 2020-03-05 15:18:32,999 Task._call(1071) INFO mfd flow accum 54.4% complete 2020-03-05 15:18:42,847 Task._call(1071) INFO 100.0% complete 2020-03-05 15:18:42,928 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-03-05 15:18:42,929 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-03-05 15:18:47,930 geoprocessing.(451) INFO 9.3% complete 2020-03-05 15:18:49,229 utils._log_gdal_errors(72) ERROR [errno 1] LZWDecode:Corrupted LZW table at scanline 7424 2020-03-05 15:18:49,230 utils._log_gdal_errors(72) ERROR [errno 1] TIFFReadEncodedTile() failed. 2020-03-05 15:18:49,230 utils._log_gdal_errors(72) ERROR [errno 1] F:/NDR\intermediate_outputs\s_accumulation.tif, band 1: IReadBlock failed at X offset 29, Y offset 8: TIFFReadEncodedTile() failed. 2020-03-05 15:18:52,978 geoprocessing.raster_calculator(486) INFO Waiting for raster stats worker result. 2020-03-05 15:18:52,980 threading.run(870) DEBUG payload is None, terminating 2020-03-05 15:18:52,981 Task.add_task(641) ERROR Something went wrong when adding task calculate s bar (10), terminating taskgraph. Traceback (most recent call last): File "site-packages\taskgraph\Task.py", line 607, in add_task File "site-packages\taskgraph\Task.py", line 1071, in _call File "site-packages\natcap\invest\ndr\ndr.py", line 1145, in s_bar_calculate File "site-packages\pygeoprocessing\geoprocessing.py", line 405, in raster_calculator ValueError: ('got a %s when trying to read %s at %s', None, ['F:/NDR\\intermediate_outputs\\s_accumulation.tif'], {'xoff': 7424, 'yoff': 2048, 'win_xsize': 256, 'win_ysize': 256}) 2020-03-05 15:18:52,983 model._logged_target(1648) ERROR Exception while executing Traceback (most recent call last): File "site-packages\natcap\invest\ui\model.py", line 1645, in _logged_target File "site-packages\natcap\invest\ndr\ndr.py", line 514, in execute File "site-packages\taskgraph\Task.py", line 607, in add_task File "site-packages\taskgraph\Task.py", line 1071, in _call File "site-packages\natcap\invest\ndr\ndr.py", line 1145, in s_bar_calculate File "site-packages\pygeoprocessing\geoprocessing.py", line 405, in raster_calculator ValueError: ('got a %s when trying to read %s at %s', None, ['F:/NDR\\intermediate_outputs\\s_accumulation.tif'], {'xoff': 7424, 'yoff': 2048, 'win_xsize': 256, 'win_ysize': 256}) 2020-03-05 15:18:52,985 model._logged_target(1651) INFO Execution finished 2020-03-05 15:18:52,989 utils.prepare_workspace(121) INFO Elapsed time: 41m 24.170000000000073s