merge with current dev.

Merge remote-tracking branch 'origin/dev' into dev-heal-bridges
NOAA-OWP · Jul 24, 2024 · 3d37017 · 3d37017
2 parents 4d835c8 + 25135e0
commit 3d37017
Show file tree

Hide file tree

Showing 4 changed files with 127 additions and 42 deletions.
diff --git 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.
+
+<br/><br/>
+
+
 ## 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
@@ -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
@@ -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,24 +84,29 @@ 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() {
     if [ "$SUCCESS" = true ]; then
         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,36 +256,39 @@ 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 \
     -o $outputDestDir/crosswalk_table.csv
 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
@@ -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,25 +49,43 @@ 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`
 
     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(){