2019-11-12 09:59:39,276 utils.prepare_workspace(109) INFO Writing log messages to C:\ArcGIS\Projects\InVest_Yanan\00\InVEST-Seasonal-Water-Yield-log-2019-11-12--09_59_39.txt 2019-11-12 09:59:39,282 model._logged_target(1633) Level 100 Starting model with parameters: Arguments for InVEST natcap.invest.seasonal_water_yield.seasonal_water_yield 3.7.0: alpha_m 1/12 aoi_path C:/ArcGIS/Projects/InVest_Yanan/Input_data/Yanan_total.shp beta_i 1 biophysical_table_path C:/ArcGIS/Projects/InVest_Yanan/Input_data/biophysical_table.csv dem_raster_path C:/ArcGIS/Projects/InVest_Yanan/Input_data/Yanan_dem.tif et0_dir C:\ArcGIS\Projects\InVest_Yanan\Input_data\PET_00 gamma 1 lulc_raster_path C:/ArcGIS/Projects/InVest_Yanan/Input_data/LUCC/2000.tif monthly_alpha False n_workers -1 precip_dir C:\ArcGIS\Projects\InVest_Yanan\Input_data\P_95 rain_events_table_path C:/ArcGIS/Projects/InVest_Yanan/Input_data/Rainevents00.csv results_suffix soil_group_path C:/ArcGIS/Projects/InVest_Yanan/Input_data/Soilhy.tif threshold_flow_accumulation 1000 user_defined_climate_zones False user_defined_local_recharge False workspace_dir C:\ArcGIS\Projects\InVest_Yanan\00 2019-11-12 09:59:39,312 seasonal_water_yield._execute(184) INFO prepare and test inputs for common errors 2019-11-12 09:59:39,489 seasonal_water_yield._execute(246) INFO Building file registry 2019-11-12 09:59:39,489 seasonal_water_yield._execute(252) INFO Checking that the AOI is not the output aggregate vector 2019-11-12 09:59:39,489 seasonal_water_yield._execute(261) INFO Aligning and clipping dataset list 2019-11-12 09:59:39,632 geoprocessing.align_and_resize_raster_stack(729) INFO n_workers > 1 (4) so starting a processes pool. 2019-11-12 09:59:51,529 geoprocessing.align_and_resize_raster_stack(779) INFO 1 of 27 aligned: prcp_a0.tif 2019-11-12 09:59:53,214 geoprocessing.align_and_resize_raster_stack(779) INFO 2 of 27 aligned: prcp_a1.tif 2019-11-12 09:59:54,645 geoprocessing.align_and_resize_raster_stack(779) INFO 3 of 27 aligned: prcp_a2.tif 2019-11-12 09:59:56,035 geoprocessing.align_and_resize_raster_stack(779) INFO 4 of 27 aligned: prcp_a3.tif 2019-11-12 09:59:57,756 geoprocessing.align_and_resize_raster_stack(779) INFO 5 of 27 aligned: prcp_a4.tif 2019-11-12 09:59:59,551 geoprocessing.align_and_resize_raster_stack(779) INFO 6 of 27 aligned: prcp_a5.tif 2019-11-12 10:00:00,979 geoprocessing.align_and_resize_raster_stack(779) INFO 7 of 27 aligned: prcp_a6.tif 2019-11-12 10:00:02,436 geoprocessing.align_and_resize_raster_stack(779) INFO 8 of 27 aligned: prcp_a7.tif 2019-11-12 10:00:04,256 geoprocessing.align_and_resize_raster_stack(779) INFO 9 of 27 aligned: prcp_a8.tif 2019-11-12 10:00:05,979 geoprocessing.align_and_resize_raster_stack(779) INFO 10 of 27 aligned: prcp_a9.tif 2019-11-12 10:00:07,312 geoprocessing.align_and_resize_raster_stack(779) INFO 11 of 27 aligned: prcp_a10.tif 2019-11-12 10:00:08,996 geoprocessing.align_and_resize_raster_stack(779) INFO 12 of 27 aligned: prcp_a11.tif 2019-11-12 10:00:08,996 geoprocessing.align_and_resize_raster_stack(779) INFO 13 of 27 aligned: soil_group_aligned.tif 2019-11-12 10:00:12,783 geoprocessing.align_and_resize_raster_stack(779) INFO 14 of 27 aligned: et0_a0.tif 2019-11-12 10:00:14,421 geoprocessing.align_and_resize_raster_stack(779) INFO 15 of 27 aligned: et0_a1.tif 2019-11-12 10:00:15,190 geoprocessing.align_and_resize_raster_stack(779) INFO 16 of 27 aligned: et0_a2.tif 2019-11-12 10:00:15,444 geoprocessing.align_and_resize_raster_stack(779) INFO 17 of 27 aligned: et0_a3.tif 2019-11-12 10:00:19,496 geoprocessing.align_and_resize_raster_stack(779) INFO 18 of 27 aligned: et0_a4.tif 2019-11-12 10:00:20,713 geoprocessing.align_and_resize_raster_stack(779) INFO 19 of 27 aligned: et0_a5.tif 2019-11-12 10:00:22,204 geoprocessing.align_and_resize_raster_stack(779) INFO 20 of 27 aligned: et0_a6.tif 2019-11-12 10:00:22,204 geoprocessing.align_and_resize_raster_stack(779) INFO 21 of 27 aligned: et0_a7.tif 2019-11-12 10:00:26,621 geoprocessing.align_and_resize_raster_stack(779) INFO 22 of 27 aligned: et0_a8.tif 2019-11-12 10:00:27,038 geoprocessing.align_and_resize_raster_stack(779) INFO 23 of 27 aligned: et0_a9.tif 2019-11-12 10:00:28,509 geoprocessing.align_and_resize_raster_stack(779) INFO 24 of 27 aligned: et0_a10.tif 2019-11-12 10:00:28,743 geoprocessing.align_and_resize_raster_stack(779) INFO 25 of 27 aligned: et0_a11.tif 2019-11-12 10:00:31,296 geoprocessing.align_and_resize_raster_stack(779) INFO 26 of 27 aligned: lulc_aligned.tif 2019-11-12 10:00:57,061 geoprocessing.align_and_resize_raster_stack(779) INFO 27 of 27 aligned: dem_aligned.tif 2019-11-12 10:00:57,213 geoprocessing.align_and_resize_raster_stack(788) INFO aligned all 27 rasters. 2019-11-12 10:01:26,428 Task._call(1068) INFO 0.0% complete 2019-11-12 10:01:32,213 Task._call(1068) INFO 3.7% complete 2019-11-12 10:01:38,095 Task._call(1068) INFO 3.7% complete 2019-11-12 10:01:44,147 Task._call(1068) INFO 7.3% complete 2019-11-12 10:01:50,282 Task._call(1068) INFO 7.3% complete 2019-11-12 10:01:56,046 Task._call(1068) INFO 11.0% complete 2019-11-12 10:02:02,095 Task._call(1068) INFO 11.0% complete 2019-11-12 10:02:08,030 Task._call(1068) INFO 14.6% complete 2019-11-12 10:02:14,365 Task._call(1068) INFO 18.3% complete 2019-11-12 10:02:20,061 Task._call(1068) INFO 18.3% complete 2019-11-12 10:02:26,200 Task._call(1068) INFO 21.9% complete 2019-11-12 10:02:32,296 Task._call(1068) INFO 21.9% complete 2019-11-12 10:02:38,295 Task._call(1068) INFO 25.6% complete 2019-11-12 10:02:44,010 Task._call(1068) INFO 25.6% complete 2019-11-12 10:02:50,262 Task._call(1068) INFO 29.2% complete 2019-11-12 10:02:56,211 Task._call(1068) INFO 32.9% complete 2019-11-12 10:03:02,013 Task._call(1068) INFO 32.9% complete 2019-11-12 10:03:08,276 Task._call(1068) INFO 36.5% complete 2019-11-12 10:03:14,233 Task._call(1068) INFO 36.5% complete 2019-11-12 10:03:20,012 Task._call(1068) INFO 40.2% complete 2019-11-12 10:03:26,010 Task._call(1068) INFO 43.8% complete 2019-11-12 10:03:32,279 Task._call(1068) INFO 43.8% complete 2019-11-12 10:03:38,457 Task._call(1068) INFO 47.5% complete 2019-11-12 10:03:44,076 Task._call(1068) INFO 51.1% complete 2019-11-12 10:03:50,045 Task._call(1068) INFO 51.1% complete 2019-11-12 10:03:56,016 Task._call(1068) INFO 54.8% complete 2019-11-12 10:04:02,130 Task._call(1068) INFO 54.8% complete 2019-11-12 10:04:08,112 Task._call(1068) INFO 58.4% complete 2019-11-12 10:04:14,112 Task._call(1068) INFO 62.1% complete 2019-11-12 10:04:20,043 Task._call(1068) INFO 62.1% complete 2019-11-12 10:04:26,026 Task._call(1068) INFO 65.7% complete 2019-11-12 10:04:32,206 Task._call(1068) INFO 69.4% complete 2019-11-12 10:04:38,052 Task._call(1068) INFO 69.4% complete 2019-11-12 10:04:44,078 Task._call(1068) INFO 73.0% complete 2019-11-12 10:04:50,015 Task._call(1068) INFO 73.1% complete 2019-11-12 10:04:56,230 Task._call(1068) INFO 76.7% complete 2019-11-12 10:05:02,089 Task._call(1068) INFO 80.3% complete 2019-11-12 10:05:08,112 Task._call(1068) INFO 80.4% complete 2019-11-12 10:05:14,082 Task._call(1068) INFO 84.0% complete 2019-11-12 10:05:20,519 Task._call(1068) INFO 87.6% complete 2019-11-12 10:05:26,447 Task._call(1068) INFO 87.7% complete 2019-11-12 10:05:32,187 Task._call(1068) INFO 91.3% complete 2019-11-12 10:05:38,095 Task._call(1068) INFO 91.3% complete 2019-11-12 10:05:44,230 Task._call(1068) INFO 95.0% complete 2019-11-12 10:05:50,227 Task._call(1068) INFO 95.0% complete 2019-11-12 10:05:56,065 Task._call(1068) INFO 98.6% complete 2019-11-12 10:05:58,142 Task._call(1068) INFO 100.0% complete 2019-11-12 10:06:08,131 Task._call(1068) INFO 0.0% complete 2019-11-12 10:06:14,221 Task._call(1068) INFO 3.7% complete 2019-11-12 10:06:20,117 Task._call(1068) INFO 3.7% complete 2019-11-12 10:06:26,177 Task._call(1068) INFO 7.3% complete 2019-11-12 10:06:32,194 Task._call(1068) INFO 11.0% complete 2019-11-12 10:06:38,088 Task._call(1068) INFO 14.6% complete 2019-11-12 10:06:44,111 Task._call(1068) INFO 14.6% complete 2019-11-12 10:06:50,065 Task._call(1068) INFO 18.3% complete 2019-11-12 10:06:56,296 Task._call(1068) INFO 21.9% complete 2019-11-12 10:07:02,019 Task._call(1068) INFO 25.6% complete 2019-11-12 10:07:08,012 Task._call(1068) INFO 25.6% complete 2019-11-12 10:07:14,279 Task._call(1068) INFO 29.2% complete 2019-11-12 10:07:20,003 Task._call(1068) INFO 32.9% complete 2019-11-12 10:07:26,016 Task._call(1068) INFO 36.5% complete 2019-11-12 10:07:32,013 Task._call(1068) INFO 36.5% complete 2019-11-12 10:07:38,197 Task._call(1068) INFO 40.2% complete 2019-11-12 10:07:44,122 Task._call(1068) INFO 43.8% complete 2019-11-12 10:07:50,105 Task._call(1068) INFO 47.5% complete 2019-11-12 10:07:56,232 Task._call(1068) INFO 51.1% complete 2019-11-12 10:08:02,114 Task._call(1068) INFO 51.1% complete 2019-11-12 10:08:08,040 Task._call(1068) INFO 54.8% complete 2019-11-12 10:08:14,170 Task._call(1068) INFO 58.4% complete 2019-11-12 10:08:20,125 Task._call(1068) INFO 58.4% complete 2019-11-12 10:08:26,130 Task._call(1068) INFO 62.1% complete 2019-11-12 10:08:32,108 Task._call(1068) INFO 65.7% complete 2019-11-12 10:08:38,105 Task._call(1068) INFO 69.4% complete 2019-11-12 10:08:44,138 Task._call(1068) INFO 69.4% complete 2019-11-12 10:08:50,013 Task._call(1068) INFO 73.0% complete 2019-11-12 10:08:56,010 Task._call(1068) INFO 76.7% complete 2019-11-12 10:09:02,012 Task._call(1068) INFO 80.3% complete 2019-11-12 10:09:08,262 Task._call(1068) INFO 84.0% complete 2019-11-12 10:09:14,089 Task._call(1068) INFO 84.0% complete 2019-11-12 10:09:20,071 Task._call(1068) INFO 87.7% complete 2019-11-12 10:09:26,061 Task._call(1068) INFO 91.3% complete 2019-11-12 10:09:32,029 Task._call(1068) INFO 95.0% complete 2019-11-12 10:09:38,095 Task._call(1068) INFO 95.0% complete 2019-11-12 10:09:45,986 Task._call(1068) INFO 100.0% complete 2019-11-12 10:09:52,687 Task._call(1068) INFO 0.0% complete 2019-11-12 10:09:58,017 Task._call(1068) INFO 14.6% complete 2019-11-12 10:10:42,510 Task._call(1068) INFO 80.3% complete 2019-11-12 10:10:58,891 Task._call(1068) INFO 98.6% complete 2019-11-12 10:11:41,378 Task._call(1068) INFO 98.6% complete 2019-11-12 10:11:46,180 Task._call(1068) INFO 100.0% complete 2019-11-12 10:11:53,009 Task._call(1068) INFO 14.6% complete 2019-11-12 10:11:59,017 Task._call(1068) INFO 29.2% complete 2019-11-12 10:12:05,019 Task._call(1068) INFO 43.8% complete 2019-11-12 10:12:11,010 Task._call(1068) INFO 58.4% complete 2019-11-12 10:12:17,000 Task._call(1068) INFO 73.0% complete 2019-11-12 10:12:27,736 Task._call(1068) INFO 76.7% complete 2019-11-12 10:12:33,010 Task._call(1068) INFO 91.3% complete 2019-11-12 10:12:46,463 Task._call(1068) INFO 98.6% complete 2019-11-12 10:12:47,526 Task._call(1068) INFO filter out incomplete divergent streams 2019-11-12 10:12:48,479 Task._call(1068) INFO 100.0% complete 2019-11-12 10:12:48,499 seasonal_water_yield._execute(363) INFO quick flow 2019-11-12 10:12:48,499 seasonal_water_yield._execute(377) INFO loading number of monthly events 2019-11-12 10:13:12,260 geoprocessing.raster_calculator(366) INFO starting stats_worker 2019-11-12 10:13:12,263 geoprocessing.raster_calculator(372) INFO started stats_worker 2019-11-12 10:13:12,278 geoprocessing.raster_calculator(477) INFO Waiting for raster stats worker result. 2019-11-12 10:13:12,278 threading.run(754) DEBUG payload is None, terminating 2019-11-12 10:13:12,278 threading.run(754) WARNING No valid pixels were received, sending None. 2019-11-12 10:13:12,295 Task.add_task(636) ERROR Something went wrong when adding task calculate curve number (14), terminating taskgraph. Traceback (most recent call last): File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 602, in add_task File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 1068, in _call File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\seasonal_water_yield\seasonal_water_yield.py", line 818, in _calculate_curve_number_raster File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\pygeoprocessing\geoprocessing.py", line 415, in raster_calculator File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\seasonal_water_yield\seasonal_water_yield.py", line 810, in cn_op IndexError: index 7 is out of bounds for axis 0 with size 7 2019-11-12 10:13:12,295 model._logged_target(1639) ERROR Exception while executing Traceback (most recent call last): File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\ui\model.py", line 1636, in _logged_target File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\seasonal_water_yield\seasonal_water_yield.py", line 169, in execute File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\seasonal_water_yield\seasonal_water_yield.py", line 429, in _execute File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 602, in add_task File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\taskgraph\Task.py", line 1068, in _call File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\seasonal_water_yield\seasonal_water_yield.py", line 818, in _calculate_curve_number_raster File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\pygeoprocessing\geoprocessing.py", line 415, in raster_calculator File "Z:\opt\atlassian\pipelines\agent\build\env\lib\site-packages\natcap\invest\seasonal_water_yield\seasonal_water_yield.py", line 810, in cn_op IndexError: index 7 is out of bounds for axis 0 with size 7 2019-11-12 10:13:12,295 model._logged_target(1642) INFO Execution finished 2019-11-12 10:13:12,295 utils.prepare_workspace(115) INFO Elapsed time: 13m 33.01s