log times taken for steps in teh bash runner script

1 files changed, 48 insertions, 22 deletions

diff --git a/cbt b/cbt
index d93ab6a..907a219 100755
--- a/cbt
+++ b/cbt
@@ -1,5 +1,4 @@
 #!/usr/bin/env bash
-#gdate +"%T.%N"
 # Launcher bash script that bootstraps CBT from source.
 # (Some of the code for reporting missing dependencies and waiting for nailgun to come up is a bit weird.)
 # This is inentionally kept as small as posible.
@@ -9,6 +8,29 @@
 # - reduction of dependencies
 # - performance improvements
 
+# utility function to log message to stderr with stating the time
+log () {
+	msg=$1
+	enabled=0
+	while test $# -gt 0; do
+	    case "$1" in
+	    	"-Dlog=time") enabled=1 ;;
+	    	"-Dlog=all") enabled=1 ;;
+	    esac
+	    shift
+	done
+	if [ $enabled -eq 1 ]; then
+		which gdate 2>&1 > /dev/null
+		gdate_installed=$?
+		if [ $gdate_installed -eq 0 ]; then
+			i=`gdate +"%S.%N"`
+			echo "[$i] $msg" 1>&2
+		fi
+	fi
+}
+
+log "Checking for dependencies" $*
+
 which javac 2>&1 > /dev/null
 javac_installed=$?
 if [ ! $javac_installed -eq 0 ]; then
@@ -51,10 +73,11 @@ NG="ng --nailgun-port $NAILGUN_PORT"
 
 CWD=$(pwd)
 _DIR=$(dirname $(readlink "$0") 2>/dev/null || dirname "$0" 2>/dev/null )
-# find out real path. Build realpath if needed.
+
+log "Find out real path. Build realpath if needed." $*
+
 export CBT_HOME=$(dirname $($_DIR/realpath/realpath.sh $0))
 
-#gdate +"%T.%N"
 export SCALA_VERSION="2.11.7"
 export NAILGUN=$CBT_HOME/nailgun_launcher/
 export STAGE1=$CBT_HOME/stage1/
@@ -66,6 +89,8 @@ mkdir -p $STAGE1$TARGET
 which nc 2>&1 > /dev/null
 nc_installed=$?
 
+log "Check for running nailgun with nc." $*
+
 server_up=1
 if [ $nc_installed -eq 0 ]; then
 	nc -z -n -w 1 127.0.0.1 $NAILGUN_PORT > /dev/null 2>&1
@@ -75,12 +100,12 @@ else
 fi
 
 if [ ! $nc_installed -eq 0 ] || [ ! $server_up -eq 0 ]; then
-	echo "Starting up nailgun" 1>&2
+	log "Starting up nailgun server." $*
 	# try to start nailgun-server, just in case it's not up
 	ng-server 127.0.0.1:$NAILGUN_PORT >> $NAILGUN/target/nailgun.stdout.log 2>> $NAILGUN/target/nailgun.stderr.log & 
 fi
 
-#gdate +"%T.%N"
+log "Grabbing Scala classpath..." $*
 # fetch / find scala jars
 export SCALA_CLASSPATH=`$CBT_HOME/bootstrap_scala/bootstrap_scala $SCALA_VERSION`
 if [ ! $? -eq 0 ]; then echo "Problem with bootstrap_scala" 1>&2; exit 1; fi
@@ -98,6 +123,7 @@ done
 compiles1=0
 compiles2=0
 
+log "Checking for source changes in CBT and maybe compiling." $*
 # recompile CBT itself if needed
 if [ ! $changed -eq 0 ]
 then
@@ -129,33 +155,32 @@ build ()
 	CP=$STAGE1$TARGET:$SCALA_CLASSPATH
 	if [ $nailgun_installed -eq 1 ] || [ "$1" = "publishSigned" ] || [ "$2" = "publishSigned" ] || [ "$1" = "direct" ] || [ "$2" = "direct" ]
 	then
-		#echo "Running jvm directly" 1>&2
+		log "Running JVM directly" $*
 		# -Xrunjdwp:transport=dt_socket,server=y,suspend=y,address=localhost:5005
 		java -cp $NAILGUN$TARGET cbt.NailgunLauncher $mainClass $CP "$CWD" $*
 	else
-		#echo "Running via nailgun" 1>&2
-		#gdate +"%T.%N"
-		$NG ng-cp $NAILGUN$TARGET >> $NAILGUN/target/nailgun.stdout.log 2>> $NAILGUN/target/nailgun.stderr.log
-		#gdate +"%T.%N"
-		$NG cbt.NailgunLauncher cbt.CheckAlive $CP "$CWD" $* >> $NAILGUN/target/nailgun.stdout.log 2>> $NAILGUN/target/nailgun.stderr.log
-		#gdate +"%T.%N"
-		alive=$?
-		while [[ $alive -ne 33 ]]
-		do
+		log "Running via nailgun." $*
+		while true; do
 			echo "Waiting for nailgun to start..." 1>&2
-			sleep 1
+			log "Adding classpath." $*
 			$NG ng-cp $NAILGUN$TARGET >> $NAILGUN/target/nailgun.stdout.log 2>> $NAILGUN/target/nailgun.stderr.log
+			log "Checking if nailgun is up yet." $*
 			$NG cbt.NailgunLauncher cbt.CheckAlive $CP "$CWD" $* >> $NAILGUN/target/nailgun.stdout.log 2>> $NAILGUN/target/nailgun.stderr.log
 			alive=$?
+			if [[ $alive -eq 33 ]]; then
+				break
+			else
+				log "Nope. Sleeping for 1 second" $*
+				sleep 1
+			fi
 		done
-		#gdate +"%T.%N"
+		log "Running $mainClass via Nailgun." $*
 		$NG cbt.NailgunLauncher $mainClass $CP "$CWD" $*
-		#gdate +"%T.%N"
-
 	fi
+	log "Done running $mainClass." $*
 } 
-#gdate +"%T.%N"
-# run CBT and loop if desired. This allows recompiling CBT itself as part of compile looping.
+
+log "run CBT and loop if desired. This allows recompiling CBT itself as part of compile looping." $*
 if [ $compiles1 -eq 0 ] && [ $compiles2 -eq 0 ]
 then
 	if [ "$1" = "admin" ]; then
@@ -172,4 +197,5 @@ then
 		done
 	fi
 fi
-#gdate +"%T.%N"
\ No newline at end of file
+
+log "Exiting CBT" $*