2019-06-22 16:48:08,545 utils.prepare_workspace(109) INFO Writing log messages to E:\InVEST\SDR\Pranhita Sub_basin\Trial Run\Trial 2\InVEST-Sediment-Delivery-Ratio-Model-(SDR)-log-2019-06-22--16_48_08.txt 2019-06-22 16:48:08,549 model._logged_target(1633) Level 100 Starting model with parameters: Arguments for InVEST natcap.invest.sdr 3.7.0: biophysical_table_path E:/InVEST/SDR/Pranhita Sub_basin/INPUTS/Pranhita_Biophysical_table.csv dem_path E:/InVEST/SDR/Pranhita Sub_basin/INPUTS/DEM/pranhita_elevation_buffer.tif drainage_path erodibility_path E:/InVEST/SDR/Pranhita Sub_basin/INPUTS/Erodibility/pranhita_Erodibility.tif erosivity_path E:/InVEST/SDR/Pranhita Sub_basin/INPUTS/Erosivity/pranhita_erosivity.tif ic_0_param 0.5 k_param 2 lulc_path E:/InVEST/SDR/Pranhita Sub_basin/INPUTS/LULC/pranhita_lulc.tif n_workers -1 results_suffix sdr_max 0.8 threshold_flow_accumulation 5000 watersheds_path E:/InVEST/SDR/Pranhita Sub_basin/INPUTS/Watershed/pranhita.shp workspace_dir E:\InVEST\SDR\Pranhita Sub_basin\Trial Run\Trial 2 2019-06-22 16:48:11,500 geoprocessing.align_and_resize_raster_stack(729) INFO n_workers > 1 (2) so starting a processes pool. 2019-06-22 16:48:32,951 geoprocessing.align_and_resize_raster_stack(779) INFO 1 of 4 aligned: aligned_dem.tif 2019-06-22 16:48:32,953 geoprocessing.align_and_resize_raster_stack(779) INFO 2 of 4 aligned: aligned_lulc.tif 2019-06-22 16:48:45,305 geoprocessing.align_and_resize_raster_stack(779) INFO 3 of 4 aligned: aligned_erosivity.tif 2019-06-22 16:48:45,428 geoprocessing.align_and_resize_raster_stack(779) INFO 4 of 4 aligned: aligned_erodibility.tif 2019-06-22 16:48:45,578 geoprocessing.align_and_resize_raster_stack(788) INFO aligned all 4 rasters. 2019-06-22 16:49:04,049 Task._call(1068) INFO 0.0% complete 2019-06-22 16:49:10,013 Task._call(1068) INFO 6.7% complete 2019-06-22 16:49:16,157 Task._call(1068) INFO 13.3% complete 2019-06-22 16:49:22,394 Task._call(1068) INFO 13.3% complete 2019-06-22 16:49:28,105 Task._call(1068) INFO 16.7% complete 2019-06-22 16:49:34,184 Task._call(1068) INFO 20.0% complete 2019-06-22 16:49:40,065 Task._call(1068) INFO 20.0% complete 2019-06-22 16:49:46,273 Task._call(1068) INFO 23.3% complete 2019-06-22 16:49:52,125 Task._call(1068) INFO 23.3% complete 2019-06-22 16:49:58,282 Task._call(1068) INFO 26.6% complete 2019-06-22 16:50:04,170 Task._call(1068) INFO 26.7% complete 2019-06-22 16:50:10,292 Task._call(1068) INFO 30.0% complete 2019-06-22 16:50:16,016 Task._call(1068) INFO 33.3% complete 2019-06-22 16:50:22,190 Task._call(1068) INFO 33.3% complete 2019-06-22 16:50:28,105 Task._call(1068) INFO 36.6% complete 2019-06-22 16:50:34,315 Task._call(1068) INFO 36.6% complete 2019-06-22 16:50:40,237 Task._call(1068) INFO 40.0% complete 2019-06-22 16:50:46,293 Task._call(1068) INFO 43.3% complete 2019-06-22 16:50:52,252 Task._call(1068) INFO 43.3% complete 2019-06-22 16:50:58,315 Task._call(1068) INFO 46.6% complete 2019-06-22 16:51:04,035 Task._call(1068) INFO 46.6% complete 2019-06-22 16:51:10,203 Task._call(1068) INFO 50.0% complete 2019-06-22 16:51:24,049 Task._call(1068) INFO 50.0% complete 2019-06-22 16:51:30,190 Task._call(1068) INFO 50.0% complete 2019-06-22 16:51:36,095 Task._call(1068) INFO 53.3% complete 2019-06-22 16:51:59,095 Task._call(1068) INFO 53.3% complete 2019-06-22 16:52:05,102 Task._call(1068) INFO 53.3% complete 2019-06-22 16:52:11,098 Task._call(1068) INFO 56.6% complete 2019-06-22 16:52:17,153 Task._call(1068) INFO 56.6% complete 2019-06-22 16:52:23,198 Task._call(1068) INFO 59.9% complete 2019-06-22 16:52:29,549 Task._call(1068) INFO 59.9% complete 2019-06-22 16:52:35,220 Task._call(1068) INFO 63.3% complete 2019-06-22 16:52:41,045 Task._call(1068) INFO 63.3% complete 2019-06-22 16:52:47,075 Task._call(1068) INFO 66.6% complete 2019-06-22 16:52:53,085 Task._call(1068) INFO 69.9% complete 2019-06-22 16:52:59,200 Task._call(1068) INFO 69.9% complete 2019-06-22 16:53:05,288 Task._call(1068) INFO 73.3% complete 2019-06-22 16:53:11,052 Task._call(1068) INFO 76.6% complete 2019-06-22 16:53:17,105 Task._call(1068) INFO 76.6% complete 2019-06-22 16:53:23,762 Task._call(1068) INFO 79.9% complete 2019-06-22 16:53:29,219 Task._call(1068) INFO 83.3% complete 2019-06-22 16:53:35,019 Task._call(1068) INFO 86.6% complete 2019-06-22 16:53:41,188 Task._call(1068) INFO 89.9% complete 2019-06-22 16:53:44,717 Task._call(1068) INFO 100.0% complete 2019-06-22 16:54:19,335 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 16:54:20,073 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 16:54:24,368 geoprocessing.(442) INFO 37.3% complete 2019-06-22 16:54:29,371 geoprocessing.(442) INFO 52.2% complete 2019-06-22 16:54:34,382 geoprocessing.(442) INFO 67.8% complete 2019-06-22 16:54:39,417 geoprocessing.(442) INFO 82.0% complete 2019-06-22 16:54:44,444 geoprocessing.(442) INFO 97.5% complete 2019-06-22 16:54:46,723 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 16:54:46,723 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 16:54:46,724 threading.run(754) DEBUG payload is None, terminating 2019-06-22 16:54:46,724 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 16:55:09,789 geoprocessing.(918) INFO 86.1% complete 2019-06-22 16:55:12,140 Task._call(1068) INFO 0.0% complete 2019-06-22 16:55:18,019 Task._call(1068) INFO 6.7% complete 2019-06-22 16:55:26,013 Task._call(1068) INFO 10.0% complete 2019-06-22 16:55:32,026 Task._call(1068) INFO 13.3% complete 2019-06-22 16:55:38,589 Task._call(1068) INFO 13.3% complete 2019-06-22 16:55:44,194 Task._call(1068) INFO 16.7% complete 2019-06-22 16:55:50,325 Task._call(1068) INFO 16.7% complete 2019-06-22 16:55:56,733 Task._call(1068) INFO 16.7% complete 2019-06-22 16:56:02,385 Task._call(1068) INFO 20.0% complete 2019-06-22 16:56:08,348 Task._call(1068) INFO 20.0% complete 2019-06-22 16:56:14,598 Task._call(1068) INFO 20.0% complete 2019-06-22 16:56:20,605 Task._call(1068) INFO 23.3% complete 2019-06-22 16:56:26,345 Task._call(1068) INFO 23.3% complete 2019-06-22 16:56:32,426 Task._call(1068) INFO 23.3% complete 2019-06-22 16:56:38,013 Task._call(1068) INFO 26.6% complete 2019-06-22 16:56:44,039 Task._call(1068) INFO 26.6% complete 2019-06-22 16:56:50,148 Task._call(1068) INFO 26.6% complete 2019-06-22 16:56:56,029 Task._call(1068) INFO 30.0% complete 2019-06-22 16:57:02,023 Task._call(1068) INFO 30.0% complete 2019-06-22 16:57:08,440 Task._call(1068) INFO 30.0% complete 2019-06-22 16:57:14,191 Task._call(1068) INFO 33.3% complete 2019-06-22 16:57:20,177 Task._call(1068) INFO 33.3% complete 2019-06-22 16:57:26,854 Task._call(1068) INFO 33.3% complete 2019-06-22 16:57:32,424 Task._call(1068) INFO 36.6% complete 2019-06-22 16:57:38,086 Task._call(1068) INFO 36.6% complete 2019-06-22 16:57:44,030 Task._call(1068) INFO 36.6% complete 2019-06-22 16:57:50,269 Task._call(1068) INFO 40.0% complete 2019-06-22 16:57:56,555 Task._call(1068) INFO 40.0% complete 2019-06-22 16:58:02,592 Task._call(1068) INFO 43.3% complete 2019-06-22 16:58:08,107 Task._call(1068) INFO 43.3% complete 2019-06-22 16:58:14,260 Task._call(1068) INFO 43.3% complete 2019-06-22 16:58:20,081 Task._call(1068) INFO 43.3% complete 2019-06-22 16:58:26,236 Task._call(1068) INFO 46.6% complete 2019-06-22 16:58:32,111 Task._call(1068) INFO 46.6% complete 2019-06-22 16:58:38,217 Task._call(1068) INFO 49.9% complete 2019-06-22 16:58:44,404 Task._call(1068) INFO 50.0% complete 2019-06-22 16:58:50,407 Task._call(1068) INFO 50.0% complete 2019-06-22 16:58:56,002 Task._call(1068) INFO 50.0% complete 2019-06-22 16:59:02,292 Task._call(1068) INFO 53.3% complete 2019-06-22 16:59:08,233 Task._call(1068) INFO 53.3% complete 2019-06-22 16:59:14,263 Task._call(1068) INFO 53.3% complete 2019-06-22 17:00:18,855 Task._call(1068) INFO 56.6% complete 2019-06-22 17:00:39,234 Task._call(1068) INFO 56.6% complete 2019-06-22 17:01:00,298 Task._call(1068) INFO 56.6% complete 2019-06-22 17:01:58,390 Task._call(1068) INFO 56.6% complete 2019-06-22 17:02:09,943 Task._call(1068) INFO 56.6% complete 2019-06-22 17:02:15,582 Task._call(1068) INFO 56.6% complete 2019-06-22 17:02:21,446 Task._call(1068) INFO 56.6% complete 2019-06-22 17:02:27,380 Task._call(1068) INFO 56.6% complete 2019-06-22 17:02:33,329 Task._call(1068) INFO 59.9% complete 2019-06-22 17:02:39,483 Task._call(1068) INFO 59.9% complete 2019-06-22 17:02:45,309 Task._call(1068) INFO 59.9% complete 2019-06-22 17:02:51,658 Task._call(1068) INFO 63.3% complete 2019-06-22 17:02:57,066 Task._call(1068) INFO 63.3% complete 2019-06-22 17:03:03,036 Task._call(1068) INFO 63.3% complete 2019-06-22 17:03:09,410 Task._call(1068) INFO 66.6% complete 2019-06-22 17:04:23,275 Task._call(1068) INFO 66.6% complete 2019-06-22 17:04:55,914 Task._call(1068) INFO 66.6% complete 2019-06-22 17:05:27,740 Task._call(1068) INFO 66.6% complete 2019-06-22 17:05:58,987 Task._call(1068) INFO 66.6% complete 2019-06-22 17:06:10,053 Task._call(1068) INFO 66.6% complete 2019-06-22 17:06:16,532 Task._call(1068) INFO 66.6% complete 2019-06-22 17:06:22,140 Task._call(1068) INFO 69.9% complete 2019-06-22 17:06:28,427 Task._call(1068) INFO 69.9% complete 2019-06-22 17:06:34,173 Task._call(1068) INFO 69.9% complete 2019-06-22 17:06:40,257 Task._call(1068) INFO 73.3% complete 2019-06-22 17:06:46,059 Task._call(1068) INFO 73.3% complete 2019-06-22 17:06:52,131 Task._call(1068) INFO 73.3% complete 2019-06-22 17:06:58,615 Task._call(1068) INFO 76.6% complete 2019-06-22 17:07:04,311 Task._call(1068) INFO 76.6% complete 2019-06-22 17:07:10,095 Task._call(1068) INFO 76.6% complete 2019-06-22 17:07:16,204 Task._call(1068) INFO 79.9% complete 2019-06-22 17:07:22,602 Task._call(1068) INFO 79.9% complete 2019-06-22 17:07:28,424 Task._call(1068) INFO 83.2% complete 2019-06-22 17:07:34,223 Task._call(1068) INFO 83.3% complete 2019-06-22 17:07:40,096 Task._call(1068) INFO 83.3% complete 2019-06-22 17:07:46,243 Task._call(1068) INFO 86.6% complete 2019-06-22 17:07:52,010 Task._call(1068) INFO 89.9% complete 2019-06-22 17:08:02,608 Task._call(1068) INFO 100.0% complete 2019-06-22 17:08:08,431 geoprocessing.(918) INFO 90.2% complete 2019-06-22 17:08:10,483 Task._call(1068) INFO 0.0% complete 2019-06-22 17:08:16,002 Task._call(1068) INFO 16.7% complete 2019-06-22 17:08:22,003 Task._call(1068) INFO 46.6% complete 2019-06-22 17:10:39,147 Task._call(1068) INFO 56.6% complete 2019-06-22 17:10:45,036 Task._call(1068) INFO 79.9% complete 2019-06-22 17:10:51,513 Task._call(1068) INFO 93.2% complete 2019-06-22 17:10:54,421 Task._call(1068) INFO 100.0% complete 2019-06-22 17:10:58,516 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:10:58,517 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:11:03,585 geoprocessing.(442) INFO 14.5% complete 2019-06-22 17:11:08,595 geoprocessing.(442) INFO 20.9% complete 2019-06-22 17:11:13,631 geoprocessing.(442) INFO 26.0% complete 2019-06-22 17:11:18,676 geoprocessing.(442) INFO 31.2% complete 2019-06-22 17:11:23,678 geoprocessing.(442) INFO 36.2% complete 2019-06-22 17:11:28,779 geoprocessing.(442) INFO 42.1% complete 2019-06-22 17:11:33,798 geoprocessing.(442) INFO 47.7% complete 2019-06-22 17:11:38,888 geoprocessing.(442) INFO 52.8% complete 2019-06-22 17:11:43,927 geoprocessing.(442) INFO 57.9% complete 2019-06-22 17:11:49,030 geoprocessing.(442) INFO 62.6% complete 2019-06-22 17:11:54,079 geoprocessing.(442) INFO 67.9% complete 2019-06-22 17:11:59,151 geoprocessing.(442) INFO 73.7% complete 2019-06-22 17:12:04,190 geoprocessing.(442) INFO 79.4% complete 2019-06-22 17:12:09,206 geoprocessing.(442) INFO 86.3% complete 2019-06-22 17:12:14,221 geoprocessing.(442) INFO 95.7% complete 2019-06-22 17:12:15,733 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:12:15,733 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:12:15,733 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:12:15,733 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:12:27,009 Task._call(1068) INFO 16.7% complete 2019-06-22 17:12:33,000 Task._call(1068) INFO 23.3% complete 2019-06-22 17:12:39,000 Task._call(1068) INFO 33.3% complete 2019-06-22 17:12:45,009 Task._call(1068) INFO 43.3% complete 2019-06-22 17:12:51,009 Task._call(1068) INFO 53.3% complete 2019-06-22 17:13:19,003 Task._call(1068) INFO 56.6% complete 2019-06-22 17:13:25,002 Task._call(1068) INFO 69.9% complete 2019-06-22 17:13:31,019 Task._call(1068) INFO 83.3% complete 2019-06-22 17:13:36,776 Task._call(1068) INFO filter out incomplete divergent streams 2019-06-22 17:13:38,426 Task._call(1068) INFO 100.0% complete 2019-06-22 17:13:38,558 Task._scrub_task_args(1406) WARNING C:\INVEST~2.0_X\INVEST~1\taskgraph\Task.py:1406: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal 2019-06-22 17:13:38,565 Task._get_file_stats(1281) WARNING C:\INVEST~2.0_X\INVEST~1\taskgraph\Task.py:1281: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal 2019-06-22 17:13:38,579 Task._filter_non_files(1329) WARNING C:\INVEST~2.0_X\INVEST~1\taskgraph\Task.py:1329: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal 2019-06-22 17:13:38,601 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:13:38,601 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:13:43,604 geoprocessing.(442) INFO 69.3% complete 2019-06-22 17:13:46,433 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:13:46,434 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:13:46,434 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:13:46,434 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:13:47,487 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:13:47,490 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:13:51,884 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:13:51,884 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:13:51,884 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:13:51,885 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:13:52,691 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:13:52,693 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:13:57,698 geoprocessing.(442) INFO 68.7% complete 2019-06-22 17:14:00,617 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:14:00,618 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:14:00,618 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:14:00,618 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:14:02,653 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:14:02,654 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:14:07,657 geoprocessing.(442) INFO 31.1% complete 2019-06-22 17:14:12,687 geoprocessing.(442) INFO 48.3% complete 2019-06-22 17:14:17,691 geoprocessing.(442) INFO 64.9% complete 2019-06-22 17:14:22,694 geoprocessing.(442) INFO 81.4% complete 2019-06-22 17:14:27,490 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:14:27,490 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:14:27,490 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:14:27,492 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:14:29,444 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:14:29,447 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:14:34,467 geoprocessing.(442) INFO 37.3% complete 2019-06-22 17:14:39,496 geoprocessing.(442) INFO 57.5% complete 2019-06-22 17:14:44,505 geoprocessing.(442) INFO 77.0% complete 2019-06-22 17:14:49,517 geoprocessing.(442) INFO 99.9% complete 2019-06-22 17:14:49,729 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:14:49,730 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:14:49,730 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:14:49,730 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:14:53,111 sdr._calculate_bar_factor(858) DEBUG doing flow accumulation mfd on E:\InVEST\SDR\Pranhita Sub_basin\Trial Run\Trial 2\intermediate_outputs\w_threshold.tif 2019-06-22 17:14:58,127 geoprocessing.(918) INFO 67.9% complete 2019-06-22 17:15:03,243 sdr._calculate_bar_factor(866) INFO 0.0% complete 2019-06-22 17:15:09,174 sdr._calculate_bar_factor(866) INFO 16.6% complete 2019-06-22 17:15:15,009 sdr._calculate_bar_factor(866) INFO 40.0% complete 2019-06-22 17:17:50,815 sdr._calculate_bar_factor(866) INFO 56.6% complete 2019-06-22 17:17:56,295 sdr._calculate_bar_factor(866) INFO 79.9% complete 2019-06-22 17:18:02,158 sdr._calculate_bar_factor(866) INFO 93.2% complete 2019-06-22 17:18:06,203 sdr._calculate_bar_factor(866) INFO 100.0% complete 2019-06-22 17:18:06,252 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:18:06,253 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:18:11,266 geoprocessing.(442) INFO 22.3% complete 2019-06-22 17:18:16,296 geoprocessing.(442) INFO 37.2% complete 2019-06-22 17:18:21,305 geoprocessing.(442) INFO 52.9% complete 2019-06-22 17:18:26,323 geoprocessing.(442) INFO 68.2% complete 2019-06-22 17:18:31,331 geoprocessing.(442) INFO 85.3% complete 2019-06-22 17:18:34,861 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:18:34,861 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:18:34,862 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:18:34,864 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:18:39,380 sdr._calculate_bar_factor(858) DEBUG doing flow accumulation mfd on E:\InVEST\SDR\Pranhita Sub_basin\Trial Run\Trial 2\intermediate_outputs\slope_threshold.tif 2019-06-22 17:18:44,388 geoprocessing.(918) INFO 70.8% complete 2019-06-22 17:18:49,092 sdr._calculate_bar_factor(866) INFO 0.0% complete 2019-06-22 17:18:55,043 sdr._calculate_bar_factor(866) INFO 13.3% complete 2019-06-22 17:19:01,058 sdr._calculate_bar_factor(866) INFO 33.3% complete 2019-06-22 17:21:31,354 sdr._calculate_bar_factor(866) INFO 56.6% complete 2019-06-22 17:21:37,005 sdr._calculate_bar_factor(866) INFO 79.9% complete 2019-06-22 17:21:43,243 sdr._calculate_bar_factor(866) INFO 93.2% complete 2019-06-22 17:21:47,053 sdr._calculate_bar_factor(866) INFO 100.0% complete 2019-06-22 17:21:47,092 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:21:47,095 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:21:52,108 geoprocessing.(442) INFO 21.8% complete 2019-06-22 17:21:57,142 geoprocessing.(442) INFO 33.2% complete 2019-06-22 17:22:02,161 geoprocessing.(442) INFO 44.8% complete 2019-06-22 17:22:07,170 geoprocessing.(442) INFO 55.7% complete 2019-06-22 17:22:12,203 geoprocessing.(442) INFO 67.5% complete 2019-06-22 17:22:17,213 geoprocessing.(442) INFO 78.7% complete 2019-06-22 17:22:22,230 geoprocessing.(442) INFO 91.3% complete 2019-06-22 17:22:25,272 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:22:25,272 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:22:25,272 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:22:25,272 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:22:30,924 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:22:30,926 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:22:35,947 geoprocessing.(442) INFO 26.0% complete 2019-06-22 17:22:40,957 geoprocessing.(442) INFO 39.7% complete 2019-06-22 17:22:45,967 geoprocessing.(442) INFO 53.0% complete 2019-06-22 17:22:51,025 geoprocessing.(442) INFO 66.0% complete 2019-06-22 17:22:56,045 geoprocessing.(442) INFO 80.5% complete 2019-06-22 17:23:01,049 geoprocessing.(442) INFO 99.9% complete 2019-06-22 17:23:01,279 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:23:01,279 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:23:01,280 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:23:01,279 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:23:02,717 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:23:02,720 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:23:07,746 geoprocessing.(442) INFO 38.0% complete 2019-06-22 17:23:12,776 geoprocessing.(442) INFO 55.9% complete 2019-06-22 17:23:17,808 geoprocessing.(442) INFO 72.5% complete 2019-06-22 17:23:22,816 geoprocessing.(442) INFO 89.2% complete 2019-06-22 17:23:25,915 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:23:25,917 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:23:25,917 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:23:25,917 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:23:33,038 geoprocessing.(918) INFO 88.2% complete 2019-06-22 17:23:35,286 Task._call(1068) INFO 0.0% complete 2019-06-22 17:23:41,039 Task._call(1068) INFO 10.0% complete 2019-06-22 17:23:47,072 Task._call(1068) INFO 13.3% complete 2019-06-22 17:23:53,206 Task._call(1068) INFO 16.7% complete 2019-06-22 17:23:59,269 Task._call(1068) INFO 20.0% complete 2019-06-22 17:24:05,147 Task._call(1068) INFO 20.0% complete 2019-06-22 17:24:11,028 Task._call(1068) INFO 23.3% complete 2019-06-22 17:24:17,118 Task._call(1068) INFO 26.6% complete 2019-06-22 17:24:23,107 Task._call(1068) INFO 30.0% complete 2019-06-22 17:24:29,470 Task._call(1068) INFO 30.0% complete 2019-06-22 17:24:35,119 Task._call(1068) INFO 33.3% complete 2019-06-22 17:24:41,002 Task._call(1068) INFO 36.6% complete 2019-06-22 17:24:47,226 Task._call(1068) INFO 40.0% complete 2019-06-22 17:24:53,226 Task._call(1068) INFO 43.3% complete 2019-06-22 17:24:59,233 Task._call(1068) INFO 46.6% complete 2019-06-22 17:25:05,216 Task._call(1068) INFO 46.6% complete 2019-06-22 17:25:11,161 Task._call(1068) INFO 50.0% complete 2019-06-22 17:25:17,262 Task._call(1068) INFO 53.3% complete 2019-06-22 17:25:23,119 Task._call(1068) INFO 56.6% complete 2019-06-22 17:25:29,105 Task._call(1068) INFO 56.6% complete 2019-06-22 17:25:35,246 Task._call(1068) INFO 59.9% complete 2019-06-22 17:25:41,062 Task._call(1068) INFO 63.3% complete 2019-06-22 17:25:47,118 Task._call(1068) INFO 66.6% complete 2019-06-22 17:25:53,190 Task._call(1068) INFO 66.6% complete 2019-06-22 17:25:59,062 Task._call(1068) INFO 69.9% complete 2019-06-22 17:26:05,177 Task._call(1068) INFO 73.3% complete 2019-06-22 17:26:11,082 Task._call(1068) INFO 76.6% complete 2019-06-22 17:26:17,289 Task._call(1068) INFO 79.9% complete 2019-06-22 17:26:23,160 Task._call(1068) INFO 83.3% complete 2019-06-22 17:26:29,003 Task._call(1068) INFO 89.9% complete 2019-06-22 17:26:35,252 Task._call(1068) INFO 100.0% complete 2019-06-22 17:26:38,819 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:26:38,822 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:26:43,823 geoprocessing.(442) INFO 29.9% complete 2019-06-22 17:26:48,836 geoprocessing.(442) INFO 44.6% complete 2019-06-22 17:26:53,869 geoprocessing.(442) INFO 59.0% complete 2019-06-22 17:26:58,875 geoprocessing.(442) INFO 72.7% complete 2019-06-22 17:27:03,878 geoprocessing.(442) INFO 88.7% complete 2019-06-22 17:27:06,635 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:27:06,637 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:27:06,638 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:27:06,638 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:27:08,436 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:27:08,437 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:27:13,436 geoprocessing.(442) INFO 41.8% complete 2019-06-22 17:27:18,441 geoprocessing.(442) INFO 60.0% complete 2019-06-22 17:27:23,470 geoprocessing.(442) INFO 78.7% complete 2019-06-22 17:27:28,471 geoprocessing.(442) INFO 99.9% complete 2019-06-22 17:27:29,022 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:27:29,023 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:27:29,025 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:27:29,023 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:27:32,407 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:27:32,408 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:27:37,424 geoprocessing.(442) INFO 37.4% complete 2019-06-22 17:27:42,430 geoprocessing.(442) INFO 56.1% complete 2019-06-22 17:27:47,450 geoprocessing.(442) INFO 75.1% complete 2019-06-22 17:27:52,460 geoprocessing.(442) INFO 98.3% complete 2019-06-22 17:27:53,092 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:27:53,092 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:27:53,092 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:27:53,092 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:27:56,418 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:27:56,421 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:28:01,437 geoprocessing.(442) INFO 34.1% complete 2019-06-22 17:28:06,470 geoprocessing.(442) INFO 51.3% complete 2019-06-22 17:28:11,505 geoprocessing.(442) INFO 67.9% complete 2019-06-22 17:28:16,530 geoprocessing.(442) INFO 85.5% complete 2019-06-22 17:28:19,569 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:28:19,572 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:28:19,572 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:28:19,572 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:28:21,523 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:28:21,526 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:28:26,555 geoprocessing.(442) INFO 41.4% complete 2019-06-22 17:28:31,556 geoprocessing.(442) INFO 57.3% complete 2019-06-22 17:28:36,591 geoprocessing.(442) INFO 72.3% complete 2019-06-22 17:28:41,609 geoprocessing.(442) INFO 87.0% complete 2019-06-22 17:28:46,427 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:28:46,428 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:28:46,428 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:28:46,430 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:28:55,220 geoprocessing.(918) INFO 87.9% complete 2019-06-22 17:28:57,528 Task._call(1068) INFO 0.0% complete 2019-06-22 17:29:03,132 Task._call(1068) INFO 10.0% complete 2019-06-22 17:29:09,082 Task._call(1068) INFO 13.3% complete 2019-06-22 17:29:15,059 Task._call(1068) INFO 16.7% complete 2019-06-22 17:29:21,243 Task._call(1068) INFO 16.7% complete 2019-06-22 17:29:27,071 Task._call(1068) INFO 20.0% complete 2019-06-22 17:29:33,263 Task._call(1068) INFO 23.3% complete 2019-06-22 17:29:39,164 Task._call(1068) INFO 26.6% complete 2019-06-22 17:29:45,049 Task._call(1068) INFO 26.6% complete 2019-06-22 17:29:51,145 Task._call(1068) INFO 30.0% complete 2019-06-22 17:29:57,059 Task._call(1068) INFO 33.3% complete 2019-06-22 17:30:03,042 Task._call(1068) INFO 36.6% complete 2019-06-22 17:30:09,000 Task._call(1068) INFO 36.6% complete 2019-06-22 17:30:15,003 Task._call(1068) INFO 40.0% complete 2019-06-22 17:30:21,170 Task._call(1068) INFO 43.3% complete 2019-06-22 17:30:27,236 Task._call(1068) INFO 46.6% complete 2019-06-22 17:30:33,032 Task._call(1068) INFO 50.0% complete 2019-06-22 17:30:39,006 Task._call(1068) INFO 50.0% complete 2019-06-22 17:30:45,115 Task._call(1068) INFO 53.3% complete 2019-06-22 17:30:51,141 Task._call(1068) INFO 56.6% complete 2019-06-22 17:30:57,036 Task._call(1068) INFO 59.9% complete 2019-06-22 17:31:03,299 Task._call(1068) INFO 59.9% complete 2019-06-22 17:31:09,082 Task._call(1068) INFO 63.3% complete 2019-06-22 17:31:15,104 Task._call(1068) INFO 66.6% complete 2019-06-22 17:31:21,132 Task._call(1068) INFO 69.9% complete 2019-06-22 17:31:27,164 Task._call(1068) INFO 73.3% complete 2019-06-22 17:31:33,099 Task._call(1068) INFO 76.6% complete 2019-06-22 17:31:39,115 Task._call(1068) INFO 79.9% complete 2019-06-22 17:31:45,157 Task._call(1068) INFO 83.3% complete 2019-06-22 17:31:51,117 Task._call(1068) INFO 86.6% complete 2019-06-22 17:31:57,073 Task._call(1068) INFO 100.0% complete 2019-06-22 17:32:00,569 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:32:00,569 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:32:05,586 geoprocessing.(442) INFO 31.4% complete 2019-06-22 17:32:10,589 geoprocessing.(442) INFO 48.5% complete 2019-06-22 17:32:15,592 geoprocessing.(442) INFO 63.2% complete 2019-06-22 17:32:20,605 geoprocessing.(442) INFO 78.0% complete 2019-06-22 17:32:25,612 geoprocessing.(442) INFO 96.7% complete 2019-06-22 17:32:26,736 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:32:26,737 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:32:26,739 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:32:26,737 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:32:30,617 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:32:30,618 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:32:35,625 geoprocessing.(442) INFO 26.3% complete 2019-06-22 17:32:40,650 geoprocessing.(442) INFO 39.2% complete 2019-06-22 17:32:45,654 geoprocessing.(442) INFO 52.9% complete 2019-06-22 17:32:50,674 geoprocessing.(442) INFO 65.5% complete 2019-06-22 17:32:55,680 geoprocessing.(442) INFO 78.2% complete 2019-06-22 17:33:00,683 geoprocessing.(442) INFO 94.1% complete 2019-06-22 17:33:02,680 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:33:02,681 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:33:02,681 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:33:02,683 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:33:04,874 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:33:04,875 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:33:09,884 geoprocessing.(442) INFO 37.5% complete 2019-06-22 17:33:14,901 geoprocessing.(442) INFO 53.9% complete 2019-06-22 17:33:19,910 geoprocessing.(442) INFO 70.8% complete 2019-06-22 17:33:24,921 geoprocessing.(442) INFO 87.3% complete 2019-06-22 17:33:28,555 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:33:28,556 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:33:28,558 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:33:28,558 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:33:33,651 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-06-22 17:33:33,654 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-06-22 17:33:38,661 geoprocessing.(442) INFO 27.9% complete 2019-06-22 17:33:43,706 geoprocessing.(442) INFO 41.7% complete 2019-06-22 17:33:48,736 geoprocessing.(442) INFO 56.3% complete 2019-06-22 17:33:53,750 geoprocessing.(442) INFO 70.8% complete 2019-06-22 17:33:58,760 geoprocessing.(442) INFO 88.4% complete 2019-06-22 17:34:00,786 geoprocessing.raster_calculator(445) INFO 100.0%% complete 2019-06-22 17:34:00,786 geoprocessing.raster_calculator(448) INFO signaling stats worker to terminate 2019-06-22 17:34:00,786 threading.run(754) DEBUG payload is None, terminating 2019-06-22 17:34:00,786 geoprocessing.raster_calculator(450) INFO Waiting for raster stats worker result. 2019-06-22 17:34:01,812 geoprocessing.zonal_statistics(1152) DEBUG > 2019-06-22 17:34:01,819 geoprocessing.align_and_resize_raster_stack(752) DEBUG n_workers == 1 so a threadpool is sufficient 2019-06-22 17:34:07,801 geoprocessing.logger_callback(3155) INFO Warp 38.0% complete c:\users\crp-ab\appdata\local\temp\clipped_raster_y65kh.tif 2019-06-22 17:34:12,845 geoprocessing.logger_callback(3155) INFO Warp 57.0% complete c:\users\crp-ab\appdata\local\temp\clipped_raster_y65kh.tif 2019-06-22 17:34:19,517 geoprocessing.logger_callback(3155) INFO Warp 82.0% complete c:\users\crp-ab\appdata\local\temp\clipped_raster_y65kh.tif 2019-06-22 17:34:22,483 geoprocessing.logger_callback(3155) INFO Warp 100.0% complete c:\users\crp-ab\appdata\local\temp\clipped_raster_y65kh.tif 2019-06-22 17:34:25,177 geoprocessing.align_and_resize_raster_stack(779) INFO 1 of 1 aligned: clipped_raster_y65kh.tif 2019-06-22 17:34:25,279 geoprocessing.align_and_resize_raster_stack(788) INFO aligned all 1 rasters. 2019-06-22 17:34:25,290 geoprocessing.zonal_statistics(1212) INFO build a lookup of aggregate field value to FID 2019-06-22 17:34:25,292 geoprocessing.zonal_statistics(1219) INFO creating disjoint polygon set 2019-06-22 17:34:25,296 geoprocessing.calculate_disjoint_polygon_set(2048) INFO build shapely polygon list 2019-06-22 17:34:25,302 geoprocessing.calculate_disjoint_polygon_set(2057) INFO build shapely rtree index 2019-06-22 17:34:25,489 geoprocessing.calculate_disjoint_polygon_set(2072) INFO poly feature lookup 100.0% complete on pranhita.shp 2019-06-22 17:34:25,489 geoprocessing.calculate_disjoint_polygon_set(2074) INFO build poly intersection lookup 2019-06-22 17:34:25,490 geoprocessing.calculate_disjoint_polygon_set(2098) INFO poly intersection feature lookup 100.0% complete on pranhita.shp 2019-06-22 17:34:25,490 geoprocessing.calculate_disjoint_polygon_set(2132) INFO maximal subset build 100.0% complete on pranhita.shp 2019-06-22 17:34:25,513 geoprocessing.zonal_statistics(1239) INFO processing 1 disjoint polygon sets 2019-06-22 17:34:25,515 geoprocessing.zonal_statistics(1273) INFO disjoint polygon set 1 of 1 100.0% processed on pranhita.shp 2019-06-22 17:34:27,450 geoprocessing.zonal_statistics(1281) INFO rasterizing disjoint polygon set 1 of 1 pranhita.shp 2019-06-22 17:34:32,799 geoprocessing.logger_callback(3159) INFO p_progress_arg is None df_complete: 1.0, message: rasterizing polygon 1 of 1 set %.1f%% complete 2019-06-22 17:34:34,118 geoprocessing.zonal_statistics(1299) INFO summarizing rasterized disjoint polygon set 1 of 1 pranhita.shp 2019-06-22 17:34:39,078 geoprocessing.zonal_statistics(1343) DEBUG unset_fids: 0 of 1 2019-06-22 17:34:39,079 geoprocessing.zonal_statistics(1346) DEBUG gt [ 1.8229019e+05 3.0740156e+01 0.0000000e+00 2.1957482e+06 0.0000000e+00 -3.0740156e+01] for (u'E:\\InVEST\\SDR\\Pranhita Sub_basin\\Trial Run\\Trial 2\\usle.tif', 1) 2019-06-22 17:34:39,081 geoprocessing.zonal_statistics(1420) DEBUG remaining unset_fids: 0 of 1 2019-06-22 17:34:39,081 geoprocessing.zonal_statistics(1428) INFO all done processing polygon sets for pranhita.shp 2019-06-22 17:34:39,134 geoprocessing.zonal_statistics(1152) DEBUG > 2019-06-22 17:34:39,142 geoprocessing.align_and_resize_raster_stack(752) DEBUG n_workers == 1 so a threadpool is sufficient 2019-06-22 17:34:44,987 geoprocessing.logger_callback(3155) INFO Warp 38.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterfd6wbx.tif 2019-06-22 17:34:50,019 geoprocessing.logger_callback(3155) INFO Warp 59.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterfd6wbx.tif 2019-06-22 17:34:56,796 geoprocessing.logger_callback(3155) INFO Warp 82.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterfd6wbx.tif 2019-06-22 17:34:59,701 geoprocessing.logger_callback(3155) INFO Warp 100.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterfd6wbx.tif 2019-06-22 17:35:02,321 geoprocessing.align_and_resize_raster_stack(779) INFO 1 of 1 aligned: clipped_rasterfd6wbx.tif 2019-06-22 17:35:02,421 geoprocessing.align_and_resize_raster_stack(788) INFO aligned all 1 rasters. 2019-06-22 17:35:02,433 geoprocessing.zonal_statistics(1212) INFO build a lookup of aggregate field value to FID 2019-06-22 17:35:02,434 geoprocessing.zonal_statistics(1219) INFO creating disjoint polygon set 2019-06-22 17:35:02,437 geoprocessing.calculate_disjoint_polygon_set(2048) INFO build shapely polygon list 2019-06-22 17:35:02,441 geoprocessing.calculate_disjoint_polygon_set(2057) INFO build shapely rtree index 2019-06-22 17:35:02,681 geoprocessing.calculate_disjoint_polygon_set(2072) INFO poly feature lookup 100.0% complete on pranhita.shp 2019-06-22 17:35:02,683 geoprocessing.calculate_disjoint_polygon_set(2074) INFO build poly intersection lookup 2019-06-22 17:35:02,684 geoprocessing.calculate_disjoint_polygon_set(2098) INFO poly intersection feature lookup 100.0% complete on pranhita.shp 2019-06-22 17:35:02,684 geoprocessing.calculate_disjoint_polygon_set(2132) INFO maximal subset build 100.0% complete on pranhita.shp 2019-06-22 17:35:02,714 geoprocessing.zonal_statistics(1239) INFO processing 1 disjoint polygon sets 2019-06-22 17:35:02,717 geoprocessing.zonal_statistics(1273) INFO disjoint polygon set 1 of 1 100.0% processed on pranhita.shp 2019-06-22 17:35:04,608 geoprocessing.zonal_statistics(1281) INFO rasterizing disjoint polygon set 1 of 1 pranhita.shp 2019-06-22 17:35:10,164 geoprocessing.logger_callback(3159) INFO p_progress_arg is None df_complete: 1.0, message: rasterizing polygon 1 of 1 set %.1f%% complete 2019-06-22 17:35:11,526 geoprocessing.zonal_statistics(1299) INFO summarizing rasterized disjoint polygon set 1 of 1 pranhita.shp 2019-06-22 17:35:16,571 geoprocessing.zonal_statistics(1343) DEBUG unset_fids: 0 of 1 2019-06-22 17:35:16,572 geoprocessing.zonal_statistics(1346) DEBUG gt [ 1.8229019e+05 3.0740156e+01 0.0000000e+00 2.1957482e+06 0.0000000e+00 -3.0740156e+01] for (u'E:\\InVEST\\SDR\\Pranhita Sub_basin\\Trial Run\\Trial 2\\sed_export.tif', 1) 2019-06-22 17:35:16,572 geoprocessing.zonal_statistics(1420) DEBUG remaining unset_fids: 0 of 1 2019-06-22 17:35:16,572 geoprocessing.zonal_statistics(1428) INFO all done processing polygon sets for pranhita.shp 2019-06-22 17:35:16,625 geoprocessing.zonal_statistics(1152) DEBUG > 2019-06-22 17:35:16,634 geoprocessing.align_and_resize_raster_stack(752) DEBUG n_workers == 1 so a threadpool is sufficient 2019-06-22 17:35:22,624 geoprocessing.logger_callback(3155) INFO Warp 38.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterivy3bt.tif 2019-06-22 17:35:27,736 geoprocessing.logger_callback(3155) INFO Warp 57.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterivy3bt.tif 2019-06-22 17:35:34,500 geoprocessing.logger_callback(3155) INFO Warp 82.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterivy3bt.tif 2019-06-22 17:35:37,489 geoprocessing.logger_callback(3155) INFO Warp 100.0% complete c:\users\crp-ab\appdata\local\temp\clipped_rasterivy3bt.tif 2019-06-22 17:35:40,243 geoprocessing.align_and_resize_raster_stack(779) INFO 1 of 1 aligned: clipped_rasterivy3bt.tif 2019-06-22 17:35:40,345 geoprocessing.align_and_resize_raster_stack(788) INFO aligned all 1 rasters. 2019-06-22 17:35:40,355 geoprocessing.zonal_statistics(1212) INFO build a lookup of aggregate field value to FID 2019-06-22 17:35:40,358 geoprocessing.zonal_statistics(1219) INFO creating disjoint polygon set 2019-06-22 17:35:40,361 geoprocessing.calculate_disjoint_polygon_set(2048) INFO build shapely polygon list 2019-06-22 17:35:40,365 geoprocessing.calculate_disjoint_polygon_set(2057) INFO build shapely rtree index 2019-06-22 17:35:40,601 geoprocessing.calculate_disjoint_polygon_set(2072) INFO poly feature lookup 100.0% complete on pranhita.shp 2019-06-22 17:35:40,601 geoprocessing.calculate_disjoint_polygon_set(2074) INFO build poly intersection lookup 2019-06-22 17:35:40,604 geoprocessing.calculate_disjoint_polygon_set(2098) INFO poly intersection feature lookup 100.0% complete on pranhita.shp 2019-06-22 17:35:40,604 geoprocessing.calculate_disjoint_polygon_set(2132) INFO maximal subset build 100.0% complete on pranhita.shp 2019-06-22 17:35:40,634 geoprocessing.zonal_statistics(1239) INFO processing 1 disjoint polygon sets 2019-06-22 17:35:40,635 geoprocessing.zonal_statistics(1273) INFO disjoint polygon set 1 of 1 100.0% processed on pranhita.shp 2019-06-22 17:35:42,540 geoprocessing.zonal_statistics(1281) INFO rasterizing disjoint polygon set 1 of 1 pranhita.shp 2019-06-22 17:35:48,046 geoprocessing.logger_callback(3159) INFO p_progress_arg is None df_complete: 1.0, message: rasterizing polygon 1 of 1 set %.1f%% complete 2019-06-22 17:35:49,394 geoprocessing.zonal_statistics(1299) INFO summarizing rasterized disjoint polygon set 1 of 1 pranhita.shp 2019-06-22 17:35:54,538 geoprocessing.zonal_statistics(1343) DEBUG unset_fids: 0 of 1 2019-06-22 17:35:54,539 geoprocessing.zonal_statistics(1346) DEBUG gt [ 1.8229019e+05 3.0740156e+01 0.0000000e+00 2.1957482e+06 0.0000000e+00 -3.0740156e+01] for (u'E:\\InVEST\\SDR\\Pranhita Sub_basin\\Trial Run\\Trial 2\\sed_retention.tif', 1) 2019-06-22 17:35:54,539 geoprocessing.zonal_statistics(1420) DEBUG remaining unset_fids: 0 of 1 2019-06-22 17:35:54,539 geoprocessing.zonal_statistics(1428) INFO all done processing polygon sets for pranhita.shp 2019-06-22 17:35:54,732 model._logged_target(1642) INFO Execution finished 2019-06-22 17:35:54,734 utils.prepare_workspace(115) INFO Elapsed time: 47m 46.19s