2020-11-06 15:41:53,677 utils.prepare_workspace(115) INFO Writing log messages to H:/SIG/Procesos SIG/Invest_sediment_retention/maule/invest_output\InVEST-Sediment-Delivery-Ratio-Model-(SDR)-log-2020-11-06--15_41_53.txt 2020-11-06 15:41:53,681 model._logged_target(1642) Level 100 Starting model with parameters: Arguments for InVEST natcap.invest.sdr.sdr 3.8.0: biophysical_table_path H:/SIG/Procesos SIG/Invest_sediment_retention/SDR_bioph_table.csv dem_path H:/SIG/Procesos SIG/Invest_sediment_retention/maule/DEM/maule_v3_lineal.tif drainage_path erodibility_path H:/SIG/Procesos SIG/Invest_sediment_retention/maule/Soil erodibility/k_factor_maule.tif erosivity_path H:/SIG/Procesos SIG/Invest_sediment_retention/maule/Rainfall erositity index/erosivity_maule.tif ic_0_param 0.5 k_param 2 lulc_path H:/SIG/Procesos SIG/Invest_sediment_retention/maule/landuse/LU_maule_lineal1.tif n_workers -1 results_suffix 1 sdr_max 0.8 threshold_flow_accumulation 100 watersheds_path H:/SIG/Procesos SIG/Invest_sediment_retention/maule/Watersheds/subcuencas_maule_lineal.shp workspace_dir H:/SIG/Procesos SIG/Invest_sediment_retention/maule/invest_output 2020-11-06 15:42:01,302 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-11-06 15:42:01,305 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-11-06 15:42:03,357 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-11-06 15:42:03,360 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-11-06 15:42:03,362 threading.run(870) DEBUG payload is None, terminating 2020-11-06 15:42:03,362 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-11-06 15:42:03,834 geoprocessing.align_and_resize_raster_stack(752) INFO 1 of 4 aligned: aligned_dem_1.tif 2020-11-06 15:42:08,905 geoprocessing.logger_callback(3239) INFO Warp 86.0% complete H:/SIG/Procesos SIG/Invest_sediment_retention/maule/invest_output\intermediate_outputs\churn_dir_not_for_humans\aligned_lulc_1.tif 2020-11-06 15:42:09,626 geoprocessing.logger_callback(3239) INFO Warp 100.0% complete H:/SIG/Procesos SIG/Invest_sediment_retention/maule/invest_output\intermediate_outputs\churn_dir_not_for_humans\aligned_lulc_1.tif 2020-11-06 15:42:11,321 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-11-06 15:42:11,324 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-11-06 15:42:12,038 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-11-06 15:42:12,040 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-11-06 15:42:12,043 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-11-06 15:42:12,103 threading.run(870) DEBUG payload is None, terminating 2020-11-06 15:42:12,328 geoprocessing.align_and_resize_raster_stack(752) INFO 2 of 4 aligned: aligned_lulc_1.tif 2020-11-06 15:42:19,536 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-11-06 15:42:19,539 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-11-06 15:42:24,212 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-11-06 15:42:24,214 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-11-06 15:42:24,216 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-11-06 15:42:24,242 threading.run(870) DEBUG payload is None, terminating 2020-11-06 15:42:24,636 geoprocessing.align_and_resize_raster_stack(752) INFO 3 of 4 aligned: aligned_erosivity_1.tif 2020-11-06 15:42:31,009 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-11-06 15:42:31,011 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-11-06 15:42:34,513 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-11-06 15:42:34,516 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-11-06 15:42:34,518 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-11-06 15:42:34,536 threading.run(870) DEBUG payload is None, terminating 2020-11-06 15:42:34,846 geoprocessing.align_and_resize_raster_stack(752) INFO 4 of 4 aligned: aligned_erodibility_1.tif 2020-11-06 15:42:34,848 geoprocessing.align_and_resize_raster_stack(754) INFO aligned all 4 rasters. 2020-11-06 15:42:41,016 Task._call(1071) INFO 0.0% complete 2020-11-06 15:42:47,075 Task._call(1071) INFO 10.3% complete 2020-11-06 15:42:53,170 Task._call(1071) INFO 17.2% complete 2020-11-06 15:42:59,166 Task._call(1071) INFO 20.7% complete 2020-11-06 15:43:05,097 Task._call(1071) INFO 24.1% complete 2020-11-06 15:43:11,134 Task._call(1071) INFO 27.6% complete 2020-11-06 15:43:17,087 Task._call(1071) INFO 31.0% complete 2020-11-06 15:43:23,043 Task._call(1071) INFO 34.5% complete 2020-11-06 15:43:29,183 Task._call(1071) INFO 37.9% complete 2020-11-06 15:43:35,270 Task._call(1071) INFO 41.4% complete 2020-11-06 15:43:41,065 Task._call(1071) INFO 44.8% complete 2020-11-06 15:43:47,007 Task._call(1071) INFO 48.2% complete 2020-11-06 15:43:53,155 Task._call(1071) INFO 48.2% complete 2020-11-06 15:43:59,137 Task._call(1071) INFO 51.7% complete 2020-11-06 15:44:05,445 Task._call(1071) INFO 55.1% complete 2020-11-06 15:44:11,059 Task._call(1071) INFO 58.6% complete 2020-11-06 15:44:17,169 Task._call(1071) INFO 62.0% complete 2020-11-06 15:44:23,089 Task._call(1071) INFO 62.0% complete 2020-11-06 15:44:29,082 Task._call(1071) INFO 65.5% complete 2020-11-06 15:44:35,326 Task._call(1071) INFO 68.9% complete 2020-11-06 15:44:41,169 Task._call(1071) INFO 72.4% complete 2020-11-06 15:44:47,002 Task._call(1071) INFO 72.4% complete 2020-11-06 15:44:53,115 Task._call(1071) INFO 75.8% complete 2020-11-06 15:44:59,027 Task._call(1071) INFO 79.3% complete 2020-11-06 15:45:05,012 Task._call(1071) INFO 89.6% complete 2020-11-06 15:45:08,150 Task._call(1071) INFO 100.0% complete 2020-11-06 15:45:16,956 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-11-06 15:45:16,959 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-11-06 15:45:21,054 geoprocessing.raster_calculator(454) INFO 100.0%% complete 2020-11-06 15:45:21,056 geoprocessing.raster_calculator(457) INFO signaling stats worker to terminate 2020-11-06 15:45:21,058 threading.run(870) DEBUG payload is None, terminating 2020-11-06 15:45:21,058 geoprocessing.raster_calculator(459) INFO Waiting for raster stats worker result. 2020-11-06 15:45:28,206 Task._call(1071) INFO 3.4% complete 2020-11-06 15:45:34,046 Task._call(1071) INFO 17.2% complete 2020-11-06 15:45:40,250 Task._call(1071) INFO 24.1% complete 2020-11-06 15:45:46,170 Task._call(1071) INFO 27.6% complete 2020-11-06 15:45:52,077 Task._call(1071) INFO 31.0% complete 2020-11-06 15:45:58,081 Task._call(1071) INFO 31.0% complete 2020-11-06 15:46:04,171 Task._call(1071) INFO 34.5% complete 2020-11-06 15:46:10,173 Task._call(1071) INFO 37.9% complete 2020-11-06 15:46:16,255 Task._call(1071) INFO 41.4% complete 2020-11-06 15:46:22,367 Task._call(1071) INFO 44.8% complete 2020-11-06 15:46:28,029 Task._call(1071) INFO 44.8% complete 2020-11-06 15:46:34,058 Task._call(1071) INFO 48.2% complete 2020-11-06 15:46:40,253 Task._call(1071) INFO 51.7% complete 2020-11-06 15:46:46,169 Task._call(1071) INFO 55.1% complete 2020-11-06 15:46:52,083 Task._call(1071) INFO 58.6% complete 2020-11-06 15:46:58,103 Task._call(1071) INFO 58.6% complete 2020-11-06 15:47:04,039 Task._call(1071) INFO 62.0% complete 2020-11-06 15:47:10,377 Task._call(1071) INFO 65.5% complete 2020-11-06 15:47:16,050 Task._call(1071) INFO 68.9% complete 2020-11-06 15:47:22,054 Task._call(1071) INFO 68.9% complete 2020-11-06 15:47:28,061 Task._call(1071) INFO 72.4% complete 2020-11-06 15:47:34,402 Task._call(1071) INFO 75.8% complete 2020-11-06 15:47:40,054 Task._call(1071) INFO 79.3% complete 2020-11-06 15:47:45,674 Task._call(1071) INFO 100.0% complete 2020-11-06 15:47:46,195 Task._call(1071) DEBUG creating target flow accum raster layer 2020-11-06 15:47:49,076 Task._call(1071) DEBUG creating visited raster layer 2020-11-06 15:47:49,161 Task._call(1071) DEBUG starting search 2020-11-06 15:47:52,001 Task._call(1071) INFO mfd flow accum 1.5% complete 2020-11-06 15:47:58,039 Task._call(1071) INFO mfd flow accum 4.6% complete 2020-11-06 15:48:04,095 Task._call(1071) INFO mfd flow accum 6.3% complete 2020-11-06 15:48:10,011 Task._call(1071) INFO mfd flow accum 9.1% complete 2020-11-06 15:48:15,999 Task._call(1071) INFO mfd flow accum 12.2% complete 2020-11-06 15:48:22,057 Task._call(1071) INFO mfd flow accum 15.2% complete 2020-11-06 15:48:28,054 Task._call(1071) INFO mfd flow accum 17.1% complete 2020-11-06 15:48:34,003 Task._call(1071) INFO mfd flow accum 18.9% complete 2020-11-06 15:48:40,079 Task._call(1071) INFO mfd flow accum 21.1% complete 2020-11-06 15:48:46,085 Task._call(1071) INFO mfd flow accum 24.5% complete 2020-11-06 15:48:52,021 Task._call(1071) INFO mfd flow accum 27.7% complete 2020-11-06 15:48:58,099 Task._call(1071) INFO mfd flow accum 30.7% complete 2020-11-06 15:49:03,999 Task._call(1071) INFO mfd flow accum 32.2% complete 2020-11-06 15:49:10,042 Task._call(1071) INFO mfd flow accum 35.2% complete 2020-11-06 15:49:16,014 Task._call(1071) INFO mfd flow accum 37.9% complete 2020-11-06 15:49:22,018 Task._call(1071) INFO mfd flow accum 41.4% complete 2020-11-06 15:49:28,050 Task._call(1071) INFO mfd flow accum 43.7% complete 2020-11-06 15:49:34,064 Task._call(1071) INFO mfd flow accum 47.6% complete 2020-11-06 15:49:40,017 Task._call(1071) INFO mfd flow accum 50.1% complete 2020-11-06 15:49:46,087 Task._call(1071) INFO mfd flow accum 53.4% complete 2020-11-06 15:49:52,053 Task._call(1071) INFO mfd flow accum 55.7% complete 2020-11-06 15:49:58,054 Task._call(1071) INFO mfd flow accum 58.1% complete 2020-11-06 15:50:04,036 Task._call(1071) INFO mfd flow accum 59.5% complete 2020-11-06 15:50:10,021 Task._call(1071) INFO mfd flow accum 61.0% complete 2020-11-06 15:50:13,262 Task._call(1071) INFO 100.0% complete 2020-11-06 15:50:16,488 geoprocessing.raster_calculator(375) INFO starting stats_worker 2020-11-06 15:50:16,491 geoprocessing.raster_calculator(381) INFO started stats_worker 2020-11-06 15:50:21,495 geoprocessing.(451) INFO 26.8% complete 2020-11-06 15:50:26,540 geoprocessing.(451) INFO 42.1% complete 2020-11-06 15:50:31,563 geoprocessing.(451) INFO 55.9% complete 2020-11-06 15:50:36,580 geoprocessing.(451) INFO 68.8% complete 2020-11-06 15:50:36,934 utils._log_gdal_errors(72) ERROR [errno 1] LZWDecode:Corrupted LZW table at scanline 2304 2020-11-06 15:50:36,937 utils._log_gdal_errors(72) ERROR [errno 1] TIFFReadEncodedTile() failed. 2020-11-06 15:50:36,939 utils._log_gdal_errors(72) ERROR [errno 1] H:/SIG/Procesos SIG/Invest_sediment_retention/maule/invest_output\intermediate_outputs\flow_accumulation_1.tif, band 1: IReadBlock failed at X offset 9, Y offset 20: TIFFReadEncodedTile() failed. 2020-11-06 15:50:37,633 threading.run(870) DEBUG payload is None, terminating 2020-11-06 15:50:37,633 geoprocessing.raster_calculator(486) INFO Waiting for raster stats worker result. 2020-11-06 15:50:37,639 Task.add_task(641) ERROR Something went wrong when adding task ls factor calculation (6), 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\sdr\sdr.py", line 811, in _calculate_ls_factor File "site-packages\pygeoprocessing\geoprocessing.py", line 405, in raster_calculator ValueError: ('got a %s when trying to read %s at %s', None, ['H:/SIG/Procesos SIG/Invest_sediment_retention/maule/invest_output\\intermediate_outputs\\flow_accumulation_1.tif'], {'xoff': 2304, 'yoff': 5120, 'win_xsize': 256, 'win_ysize': 256}) 2020-11-06 15:50:37,642 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\sdr\sdr.py", line 414, 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\sdr\sdr.py", line 811, in _calculate_ls_factor File "site-packages\pygeoprocessing\geoprocessing.py", line 405, in raster_calculator ValueError: ('got a %s when trying to read %s at %s', None, ['H:/SIG/Procesos SIG/Invest_sediment_retention/maule/invest_output\\intermediate_outputs\\flow_accumulation_1.tif'], {'xoff': 2304, 'yoff': 5120, 'win_xsize': 256, 'win_ysize': 256}) 2020-11-06 15:50:37,644 model._logged_target(1651) INFO Execution finished 2020-11-06 15:50:37,648 utils.prepare_workspace(121) INFO Elapsed time: 8m 43.97000000000003s