diff --git a/docs/CHANGELOG.md b/docs/CHANGELOG.md
index 262db016..40ed96be 100644
--- a/docs/CHANGELOG.md
+++ b/docs/CHANGELOG.md
@@ -8,6 +8,20 @@ Removes warning when running `heal_bridges_osm.py` by not saving the empty DataF
### Changes
- `src/heal_bridges_osm.py`
+## v4.5.2.11 - 2024-07-19 - [PR#1222](https://github.com/NOAA-OWP/inundation-mapping/pull/1222)
+
+We are having problems with post processing overall duration taking a long time. This new system captures duration times for each module/section inside fim_post_processing.sh and records it to a file on the output directory. It records it as it progress and will also help us learn if fim_post_processing.sh stopped along the way.
+
+Note: When used in code, we call `Set_log_file_path` shell variable with a file name and path (no validation done at this time). The each time a person wants to print to screen and console, use the `l_echo` command instead of the native `echo` command. If the log file has not been set, the output will continue to go to screen, just not the log file.
+
+### Changes
+- `fim_pipeline.sh`: A couple of minor text output changes.
+- `fim_post_processing.sh`: As described above.
+- `src\bash_functions.env`: New functions and adjustments to support the new log system.
+
+
+
+
## v4.5.2.10 - 2024-07-19 - [PR#1224](https://github.com/NOAA-OWP/inundation-mapping/pull/1224)
Addresses warnings to reduce output messages.
diff --git a/fim_pipeline.sh b/fim_pipeline.sh
index 8fc4ae9d..16139fdc 100755
--- a/fim_pipeline.sh
+++ b/fim_pipeline.sh
@@ -116,6 +116,7 @@ echo
echo "---- Unit (HUC) processing is complete"
date -u
Calc_Duration $pipeline_start_time
+echo "---------------------------------------------------"
## POST PROCESSING
@@ -126,8 +127,10 @@ rm -d $workDir/$runName
. $projectDir/fim_post_processing.sh -n $runName -j $jobMaxLimit
echo
-echo "======================== End of fim_pipeline.sh =========================="
+
+echo "======================== End of fim_pipeline for $runName =========="
date -u
+echo "Total Duration is ..."
Calc_Duration $pipeline_start_time
echo
diff --git a/fim_post_processing.sh b/fim_post_processing.sh
index 5d0385c5..e17850cb 100755
--- a/fim_post_processing.sh
+++ b/fim_post_processing.sh
@@ -73,6 +73,7 @@ if [ "$jobLimit" = "" ]; then jobLimit=1; fi
rm -rdf $outputDestDir/logs/src_optimization
rm -f $outputDestDir/logs/log_bankfull_indentify.log
rm -f $outputDestDir/logs/subdiv_src_.log
+rm -f $log_file_name
# load up enviromental information
args_file=$outputDestDir/runtime_args.env
@@ -83,16 +84,21 @@ source $outputDestDir/params.env
source $srcDir/bash_functions.env
source $srcDir/bash_variables.env
-echo
+# Tell the system the name and location of the post processing log
+log_file_name=$outputDestDir/post_proc.log
+Set_log_file_path $log_file_name
+
+l_echo ""
echo "++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++"
-echo "---- Start of fim_post_processing"
-echo "---- Started: `date -u`"
+l_echo "---- Start of fim_post_processing"
+l_echo "---- Started: `date -u`"
T_total_start
post_proc_start_time=`date +%s`
## RUN UPDATE HYDROTABLE AND SRC ##
# Define the counter file
+Tstart
COUNTER_FILE="${outputDestDir}/post_processing_attempt.txt"
# Function to clean up
cleanup() {
@@ -100,7 +106,7 @@ cleanup() {
if [ -f "$COUNTER_FILE" ]; then
COUNTER=$(cat "$COUNTER_FILE")
if [ "$COUNTER" -eq 1 ]; then
- echo "Counter is 1. Removing the counter file."
+ l_echo "Counter is 1. Removing the counter file."
rm "$COUNTER_FILE"
fi
fi
@@ -121,36 +127,42 @@ COUNTER=$(cat "$COUNTER_FILE")
COUNTER=$((COUNTER + 1))
# Save the new counter value
-echo "$COUNTER" > "$COUNTER_FILE"
+l_echo "$COUNTER" > "$COUNTER_FILE"
# Check if the counter is greater than one
if [ "$COUNTER" -gt 1 ]; then
# Execute the Python file
- echo "Updating hydroTable & scr_full_crosswalked for branches"
+ l_echo "Updating hydroTable & scr_full_crosswalked for branches"
python3 $srcDir/update_htable_src.py -d $outputDestDir
else
- echo "Execution count is $COUNTER, not executing the update_htable_src.py file."
+ l_echo "Execution count is $COUNTER, not executing the update_htable_src.py file."
fi
+Tcount
+
## AGGREGATE BRANCH LISTS INTO ONE ##
-echo -e $startDiv"Start branch aggregation"
+l_echo $startDiv"Start branch aggregation"
+Tstart
python3 $srcDir/aggregate_branch_lists.py -d $outputDestDir -f "branch_ids.csv" -o $fim_inputs
+Tcount
## GET NON ZERO EXIT CODES FOR BRANCHES ##
-echo -e $startDiv"Start non-zero exit code checking"
+l_echo $startDiv"Start non-zero exit code checking"
find $outputDestDir/logs/branch -name "*_branch_*.log" -type f | \
xargs grep -E "Exit status: ([1-9][0-9]{0,2})" > \
"$outputDestDir/branch_errors/non_zero_exit_codes.log" &
## RUN AGGREGATE BRANCH ELEV TABLES ##
-echo "Processing usgs & ras2fim elev table aggregation"
+l_echo $startDiv"Processing usgs & ras2fim elev table aggregation"
+Tstart
python3 $srcDir/aggregate_by_huc.py -fim $outputDestDir -i $fim_inputs -elev -ras -j $jobLimit
+Tcount
## RUN BATHYMETRY ADJUSTMENT ROUTINE ##
if [ "$bathymetry_adjust" = "True" ]; then
- echo -e $startDiv"Performing Bathymetry Adjustment routine"
- # Run bathymetry adjustment routine
+ l_echo $startDiv"Performing Bathymetry Adjustment routine"
Tstart
+ # Run bathymetry adjustment routine
python3 $srcDir/bathymetric_adjustment.py \
-fim_dir $outputDestDir \
-bathy $bathymetry_file \
@@ -162,9 +174,9 @@ fi
## RUN SYNTHETIC RATING CURVE BANKFULL ESTIMATION ROUTINE ##
if [ "$src_bankfull_toggle" = "True" ]; then
- echo -e $startDiv"Estimating bankfull stage in SRCs"
- # Run SRC bankfull estimation routine routine
+ l_echo $startDiv"Estimating bankfull stage in SRCs"
Tstart
+ # Run SRC bankfull estimation routine routine
python3 $srcDir/identify_src_bankfull.py \
-fim_dir $outputDestDir \
-flows $bankfull_flows_file \
@@ -174,7 +186,7 @@ fi
## RUN SYNTHETIC RATING SUBDIVISION ROUTINE ##
if [ "$src_subdiv_toggle" = "True" ] && [ "$src_bankfull_toggle" = "True" ]; then
- echo -e $startDiv"Performing SRC channel/overbank subdivision routine"
+ l_echo $startDiv"Performing SRC channel/overbank subdivision routine"
# Run SRC Subdivision & Variable Roughness routine
Tstart
python3 $srcDir/subdiv_chan_obank_src.py \
@@ -187,8 +199,7 @@ fi
## RUN SYNTHETIC RATING CURVE CALIBRATION W/ USGS GAGE RATING CURVES ##
if [ "$src_adjust_usgs" = "True" ] && [ "$src_subdiv_toggle" = "True" ] && [ "$skipcal" = "0" ]; then
Tstart
- echo
- echo -e $startDiv"Performing SRC adjustments using USGS rating curve database"
+ l_echo $startDiv"Performing SRC adjustments using USGS rating curve database"
# Run SRC Optimization routine using USGS rating curve data (WSE and flow @ NWM recur flow values)
python3 $srcDir/src_adjust_usgs_rating_trace.py \
-run_dir $outputDestDir \
@@ -202,8 +213,7 @@ fi
## RUN SYNTHETIC RATING CURVE CALIBRATION W/ RAS2FIM CROSS SECTION RATING CURVES ##
if [ "$src_adjust_ras2fim" = "True" ] && [ "$src_subdiv_toggle" = "True" ] && [ "$skipcal" = "0" ]; then
Tstart
- echo
- echo -e $startDiv"Performing SRC adjustments using ras2fim rating curve database"
+ l_echo $startDiv"Performing SRC adjustments using ras2fim rating curve database"
# Run SRC Optimization routine using ras2fim rating curve data (WSE and flow @ NWM recur flow values)
python3 $srcDir/src_adjust_ras2fim_rating.py \
-run_dir $outputDestDir \
@@ -217,16 +227,14 @@ fi
## RUN SYNTHETIC RATING CURVE CALIBRATION W/ BENCHMARK POINTS (.parquet files) ##
if [ "$src_adjust_spatial" = "True" ] && [ "$src_subdiv_toggle" = "True" ] && [ "$skipcal" = "0" ]; then
Tstart
- echo
- echo -e $startDiv"Performing SRC adjustments using benchmark point .parquet files"
+ l_echo $startDiv"Performing SRC adjustments using benchmark point .parquet files"
python3 $srcDir/src_adjust_spatial_obs.py -fim_dir $outputDestDir -j $jobLimit
Tcount
date -u
fi
## AGGREGATE BRANCH TABLES ##
-echo
-echo -e $startDiv"Aggregating branch hydrotables"
+l_echo $startDiv"Aggregating branch hydrotables"
Tstart
python3 $srcDir/aggregate_by_huc.py \
-fim $outputDestDir \
@@ -239,8 +247,7 @@ date -u
## PERFORM MANUAL CALIBRATION
if [ "$manual_calb_toggle" = "True" ] && [ -f $man_calb_file ]; then
- echo
- echo -e $startDiv"Performing manual calibration"
+ l_echo $startDiv"Performing manual calibration"
Tstart
python3 $srcDir/src_manual_calibration.py \
-fim_dir $outputDestDir \
@@ -249,9 +256,8 @@ if [ "$manual_calb_toggle" = "True" ] && [ -f $man_calb_file ]; then
date -u
fi
-echo
-echo -e $startDiv"Combining crosswalk tables"
-# aggregate outputs
+
+l_echo $startDiv"Combining crosswalk tables"
Tstart
python3 $toolsDir/combine_crosswalk_tables.py \
-d $outputDestDir \
@@ -259,26 +265,30 @@ python3 $toolsDir/combine_crosswalk_tables.py \
Tcount
date -u
-echo -e $startDiv"Resetting Permissions"
+
+l_echo $startDiv"Resetting Permissions"
Tstart
find $outputDestDir -type d -exec chmod -R 777 {} +
find $outputDestDir -type f -exec chmod 777 {} + # just root level files
Tcount
-date -u
-echo
-echo -e $startDiv"Scanning logs for errors. Results be saved in root not inside the log folder."
+
+l_echo $startDiv"Scanning logs for errors and warnings. This can take quite a few minutes so stand by."
+echo "Results will be saved in root not inside the log folder."
Tstart
# grep -H -r -i -n "error" $outputDestDir/logs/ > $outputDestDir/all_errors_from_logs.log
- find $outputDestDir -type f | grep -H -r -i -n "error" $outputDestDir/logs/ > $outputDestDir/all_errors_from_logs.log
-Tcount
-date -u
+ find $outputDestDir -type f | grep -H -r -i -n "error" $outputDestDir/logs/ > \
+ $outputDestDir/all_errors_from_logs.log &
+ l_echo "error scan done, now on to warnings scan"
+ find $outputDestDir -type f | grep -H -r -i -n "warning" $outputDestDir/logs/ > \
+ $outputDestDir/all_warnings_from_logs.log &
+ l_echo "warning scan done"
+Tcount
echo
-echo "++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++"
-echo "---- End of fim_post_processing"
-echo "---- Ended: `date -u`"
+l_echo "++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++"
+l_echo "---- End of fim_post_processing"
+l_echo "---- Ended: `date -u`"
Calc_Duration $post_proc_start_time
echo
-SUCCESS=true
diff --git a/src/bash_functions.env b/src/bash_functions.env
index 72a33f45..e8452003 100644
--- a/src/bash_functions.env
+++ b/src/bash_functions.env
@@ -1,5 +1,44 @@
#!/bin/bash
+
+## Simple logging system
+
+# If this value -nq "", then functions in this file will be printed to
+# console and log file.
+log_file_path=""
+
+# If this is set, all functions will set to a file as well as screen
+# Yes. it needs some validation that the log_file_path is a valid
+# file name and path.
+Set_log_file_path () {
+ log_file_path=$1
+
+ if [ ! -f $log_file_path ]; then
+ touch $log_file_path
+ else
+ rm -f $log_file_path
+ fi
+}
+
+# to stop other calls to make log calls to this all
+Clear_log_file_path () {
+
+ log_file_path=""
+}
+
+
+# if the log_file_path has been set, this will print to screen and add to log file
+l_echo () {
+ local msg=$1
+
+ if [[ $log_file_path != "" ]]; then
+ echo -e $msg ; echo -e $msg >> $log_file_path
+ else
+ echo -e $msg
+ fi
+}
+
+
## Timing functions
T_total_start () {
@@ -10,15 +49,25 @@ Tstart () {
t1=`date +%s`
}
+# This one is based on the value of t1 created earlier, and end is now
Tcount () {
t2=`date +%s`
local total_sec=$(( $t2 - $t1))
local dur_min=$((total_sec / 60))
local dur_remainder_sec=$((total_sec % 60))
- echo "Cumulative Time = $dur_min min(s) and $dur_remainder_sec sec"
+
+ local msg="Duration = $dur_min min(s) and $dur_remainder_sec sec"
+ # if an arg comes in and is a file path, we can display and record to a file
+ if [[ $log_file_path != "" ]]; then
+ echo -e $msg ; echo -e $msg >> $log_file_path
+ else
+ echo -e $msg
+ fi
+
}
+# This expects a start time submitted as an arg and assumes the end time as now
Calc_Duration() {
local start_time=$1
local end_time=`date +%s`
@@ -26,9 +75,17 @@ Calc_Duration() {
local total_sec=$(( $end_time - $start_time ))
local dur_min=$((total_sec / 60))
local dur_remainder_sec=$((total_sec % 60))
- echo "Duration = $dur_min min(s) and $dur_remainder_sec sec"
+
+ local msg="Duration : $dur_min min(s) and $dur_remainder_sec sec"
+ # if an arg comes in and is a file path, we can display and record to a file
+ if [[ $log_file_path != "" ]]; then
+ echo -e $msg ; echo -e $msg >> $log_file_path
+ else
+ echo -e $msg
+ fi
}
+
Calc_Time() {
local start_time=$1
local end_time=`date +%s`
@@ -41,6 +98,7 @@ Calc_Time() {
else
echo "$dur_min:$dur_remainder_sec"
fi
+
}
Calc_Time_Minutes_in_Percent(){