Shell Scripts hangs when running through ProcessBuilder

Question

I have a Java program where I am triggering a shell scripts. Java Code Sample is :

 ProcessBuilder pb = new ProcessBuilder(cmdList);
        p = pb.start();
        p.waitFor();

Where cmdList contains all required necessary input argument to execute the shell. This shell script is having a for loop inside and executing some DB scripts in that loop and printing result info & error logs in a file.

Below is sample shell script code :

#!/bin/bash

export PATH=/apps/PostgresPlus/as9.6/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin

set -eE

#################################################### START

TIME_ELAPSED="" TIME_ELAPSED_IN_HOURS="" SCRIPT_START_TIME_FORMATTED=date '+%F %T' SCRIPT_START_TIME_IN_SEC=date +%s

PROCESS_LOG_BASE_PATH="/data/logs/purge_log/" PROCESS_LOG="$PROCESS_LOG_BASE_PATH/purge.log"

trap 'err=$?; logError 2>&1 "Error occurred during purging. Exiting with status $err at line $LINENO: ${BASH_COMMAND}. Please check logs for more info." >>$PROCESS_LOG' ERR trap 'logError 2>&1 "Error occurred during purging. Exiting shell script execution as an external interrupt was received. Please check logs for more info." >>$PROCESS_LOG; trap ERR' INT

banner() { echo "+------------------------------------------------------------------------------------------------+" printf "|tput bold[ %-40s tput sgr0|\n" "$1 ] tput setaf 2 $2" echo "+------------------------------------------------------------------------------------------------+" }

logError() { printf "[ProcessId- $$] [date "+%Y-%m-%d %H:%M:%S"] tput setaf 1 tput bold [ERROR] tput setaf 1 %-40s tput sgr0\n" "$@" }

logInfo(){ printf "[ProcessId- $$] [date "+%Y-%m-%d %H:%M:%S"] tput setaf 6 bold [INFO] %-40s tput sgr0\n" "$@" } logWarn(){ printf "[ProcessId- $$] [date "+%Y-%m-%d %H:%M:%S"] tput setaf 3 tput bold [WARNING] %-40s tput sgr0\n" "$@" }

logHint(){ printf "[ProcessId- $$] [date "+%Y-%m-%d %H:%M:%S"] tput setaf 5 tput sitm %-40s tput sgr0\n" "$@" }

main() {
banner "$SCRIPT_START_TIME_FORMATTED" "Started processing" | tee -a $PROCESS_LOG logInfo "Started execution at $SCRIPT_START_TIME_FORMATTED" | tee -a $PROCESS_LOG

set PGPASSWORD=$DB_PASSWORD
export PGPASSWORD=$DB_PASSWORD

# Call DB function for audit and category wise data purging, population of schema names
SCHEMA_NAMES_RESULT=$(psql -h $HOST_NAME -d $DB_NAME -U $DB_USER -p $DB_PORT -At -c "SELECT $COMMON_SCHEMA_NAME.purge_audit_and_populate_schema_names('$COMMON_SCHEMA_NAME', $PURGE_DATA_INTERVAL_IN_DAYS,'$SCHEMA_NAMES',$NUM_TOP_CONTRIBUTING_TENANTS)")

SCHEMA_NAMES_RESULT=$(echo "$SCHEMA_NAMES_RESULT" | sed 's/{//g; s/}//g; s/"//g' )

SCHEMA_NAMES=$(echo $SCHEMA_NAMES_RESULT | rev | cut -d"," -f2-  | rev)

#Convert comma separated string of tenants to array
SCHEMA_NAMES=($(echo "$SCHEMA_NAMES" | tr ',' '\n'))

# loop for multi schema
for element in "${SCHEMA_NAMES[@]}"
do
    logInfo "Effective tenant - $element, Script start time - $SCRIPT_START_TIME_FORMATTED" | tee -a $PROCESS_LOG

    # PGSQL call to DB function to execute purging

    logInfo "Time elapsed since script execution started - $TIME_ELAPSED" | tee -a $PROCESS_LOG
done

#logInfo "Purge completed!" | tee -a $PROCESS_LOG
logInfo "Purge execution completed successfully at `date '+%F %T'`" | tee -a $PROCESS_LOG
exit 0

}

mkdir -p $PROCESS_LOG_BASE_PATH main "$@"

#################################################### END

Following is my observation with this program.

1. When running shell script directly on putty it executes properly without any error.

2. When triggering shell script through above java program the following behavior I observed.

   a. It hangs after a certain iteration in for loop.

   b. As I reduce the number of logs entries from shell scripts, iteration (for loop) numbers keeps on increasing.

   c. When I removed all info logs and keeps on printing only error log then it completed successfully.

Can someone please help in identifying the reason behind this behavior.

For now, I put check on the number of iteration in for loop but that problem can occur any time when I will start receiving multiple error log.

Regards

Kushagra

Answer 1

You have to consume the process streams or map err and out to file so the native buffers don't fill up. It works better if you create threads to consume each stream. The hacky single thread version is something like this:

ProcessBuilder pb = new ProcessBuilder(cmdList);
p = pb.start();
try (InputStream in = p.getInputStream();
            InputStream err = p.getErrorStream();
            OutputStream closeOnly = p.getOutputStream()) {
    while (p.isAlive()) {                
        long skipped = 0L;
        try {
            skipped = in.skip(in.available()) 
                     + err.skip(err.available());
        } catch (IOException jdk8155808) {
           byte[] b = new byte[2048];
           int read = in.read(b, 0, Math.min(b.length, in.available());
           if (read > 0) {
               skipped += read;
           }

           read = err.read(b, 0, Math.min(b.length, err.available());
           if (read > 0) {
               skipped += read;
           }
        }

        if(skipped == 0L) {
           p.waitFor(5L, TimeUnit.MILLISECONDS);
        }
    }
} finally {
   p.destroy();
}

The thread way works like this:

public void foo() {
    class DevNull implements Runnable {
        
        private final InputStream is;
        DevNull(final InputStream is) {
            is = Objects.requireNonNull(is);
        }
        
        public void run() {
            byte[] b = new byte[64];
            try {
                while (is.read(b) >= 0);
            } catch(IOException ignore) {
            }
        }
    }

    ExecutorService e = Executors.newCachedThreadPool();
    ProcessBuilder pb = new ProcessBuilder(cmdList);
    Process p = pb.start();
    try (InputStream in = p.getInputStream();
            InputStream err = p.getErrorStream();
            OutputStream closeOnly = p.getOutputStream()) {
        e.execute(new DevNull(in));
        e.execute(new DevNull(err));
        p.waitFor();
    } finally {
        p.destroy();
        e.shutdown();
    }
}