refactor to use 'log' function rather than using 'echo' directly.

First cut into doing this, hopefully we're not breaking anything.

15 files changed, 170 insertions, 126 deletions

diff --git a/debuild-pbuilder b/debuild-pbuilder
index 64b58a0..e80a081 100644
--- a/debuild-pbuilder
+++ b/debuild-pbuilder
@@ -6,7 +6,7 @@ while ! test -d ./debian -o "$(pwd)" = "/" ; do
 done
 
 if test ! -d ./debian; then
-    echo "Cannot find ./debian dir"
+    echo "E: Cannot find ./debian dir" >&2
     exit 1
 fi;
 
diff --git a/pbuilder b/pbuilder
index ed35fb4..1a7d525 100755
--- a/pbuilder
+++ b/pbuilder
@@ -42,11 +42,11 @@ case "$1" in
 	shift;
 	. /usr/lib/pbuilder/pbuilder-checkparams
 	if [ -n "$BASEBUILDPLACE" ]; then 
-	    echo "Cleaning [$BASEBUILDPLACE]"
+	    log "I: Cleaning [$BASEBUILDPLACE]"
 	    clean_subdirectories "$BASEBUILDPLACE" || true
 	fi
 	if [ -n "$APTCACHE" ]; then
-	    echo "Cleaning [$APTCACHE]"
+	    log "I: Cleaning [$APTCACHE]"
 	    rm "$APTCACHE"/* || true
 	fi
 	;;
@@ -61,9 +61,9 @@ case "$1" in
 	trap saveaptcache_umountproc_cleanbuildplace_trap exit sighup
 
 	if [ "${INTERNAL_BUILD_UML}" = "yes" ]; then
-	    echo " -> entering the shell"
+	    log "I: entering the shell"
 	else
-	    echo " -> entering the shell
+	    log "I: entering the shell
 File extracted to: $BUILDPLACE
 "
 	fi
@@ -78,10 +78,10 @@ File extracted to: $BUILDPLACE
 	# saving the place afterwards
 	if [ "${SAVE_AFTER_LOGIN}" = "yes" ]; then
 	    if [ "${INTERNAL_BUILD_UML}" = "yes" ]; then
-		echo "E: Invalid combination of internal-build-uml and save-after-login flags" >&2
+		log "E: Invalid combination of internal-build-uml and save-after-login flags"
 		exit 1
 	    else
-		echo " -> Saving the results, modifications to this session will persist"
+		log "I: Saving the results, modifications to this session will persist"
 		unloadhooks
 		umountproc
 		trap cleanbuildplace_trap exit sighup
@@ -104,7 +104,7 @@ File extracted to: $BUILDPLACE
 	EXECPROGRAM="$1"
 	shift
 	if [ ! -f "${EXECPROGRAM}" ]; then
-	    echo "Command line parameter [$EXECPROGRAM] does not exist" >&2
+	    log "E: Command line parameter [$EXECPROGRAM] does not exist"
 	    exit 1;
 	fi;
 	extractbuildplace
@@ -129,9 +129,9 @@ File extracted to: $BUILDPLACE
 	# saving the place afterwards
 	if [ "${SAVE_AFTER_LOGIN}" = "yes" ]; then
 	    if [ "${INTERNAL_BUILD_UML}" = "yes" ]; then
-		echo "E: Invalid combination of internal-build-uml and save-after-login flags" >&2 
+		log "E: Invalid combination of internal-build-uml and save-after-login flags"
 	    else
-		echo " -> Saving the results, modifications to this session will persist"
+		log "I: Saving the results, modifications to this session will persist"
 		unloadhooks
 		umountproc
 		trap cleanbuildplace_trap exit sighup
@@ -154,12 +154,12 @@ File extracted to: $BUILDPLACE
 	trap umountproc_cleanbuildplace_trap exit sighup
 	loadhooks
 	executehooks "F"
-	echo " -> start dump config"
-	echo "  -> set"
+	log "I: start dump config"
+	log "I: set"
 	set;
-	echo "  -> env"
+	log "I: env"
 	env;
-	echo " -> end dump config"
+	log "I: end dump config"
 	;;
     --debuild|debuild)
 	shift
diff --git a/pbuilder-buildpackage b/pbuilder-buildpackage
index 18c781a..02d4b49 100755
--- a/pbuilder-buildpackage
+++ b/pbuilder-buildpackage
@@ -27,7 +27,7 @@ set -e
 
 PACKAGENAME="$1"
 if [ ! -f "$PACKAGENAME" ]; then
-    echo "Command line parameter [$PACKAGENAME] is not a valid .dsc file name" >&2
+    log "E: Command line parameter [$PACKAGENAME] is not a valid .dsc file name"
     exit 1;
 fi;
 
@@ -35,7 +35,7 @@ if [ -n "$BUILDUSERNAME" -a -n "$BUILDUSERID" ]; then
     SUTOUSER="env LOGNAME=$BUILDUSERNAME su -p $BUILDUSERNAME"
     DEBBUILDOPTS="$DEBBUILDOPTS -rfakeroot"
     EXTRAPACKAGES="${EXTRAPACKAGES} fakeroot"
-    echo "I: using fakeroot in build."
+    log "I: using fakeroot in build."
 else
     # run the build in root
     SUTOUSER="su -p "
@@ -60,9 +60,9 @@ if [ ! -d "${BUILDRESULT}" ]; then
 	mkdir -p "${BUILDRESULT}"
     fi
     if [ -d "${BUILDRESULT}" ]; then
-	echo " -> created buildresult dir: ${BUILDRESULT}"
+	log "I: created buildresult dir: ${BUILDRESULT}"
     else
-	echo "E: failed creating buildresult dir: ${BUILDRESULT}" >&2 
+	log "E: failed creating buildresult dir: ${BUILDRESULT}"
 	exit 1
     fi
 fi
@@ -73,7 +73,7 @@ if [ -z "${PBUILDER_BUILD_LOGFILE}" ]; then
 	exec > >(tee "${PBUILDER_BUILD_LOGFILE}")
 	exec 2>&1
 	PBUILDER_BUILD_LOGFILE=$(readlink -f "${PBUILDER_BUILD_LOGFILE}")
-	echo "I: Using pkgname logfile"
+	log "I: Using pkgname logfile"
 	echobacktime
     fi
 fi
@@ -87,31 +87,31 @@ fi
 
 recover_aptcache
 createbuilduser
-echo "Installing the build-deps"
+log "I: Installing the build-deps"
 executehooks "D"
 trap saveaptcache_umountproc_cleanbuildplace_trap exit sighup
 checkbuilddep "$PACKAGENAME"
 save_aptcache
 trap umountproc_cleanbuildplace_trap exit sighup
 
-echo "Copying source file"
+log "I: Copying source file"
 copydsc "$PACKAGENAME" "$BUILDPLACE/tmp/buildd"
 
-echo "Extracting source"
+log "I: Extracting source"
 if echo "chown $BUILDUSERNAME:$BUILDUSERNAME /tmp/buildd /tmp/buildd/*" | $CHROOTEXEC /bin/bash; then
     : # success
 else
-    echo "E: pbuilder: Failed chowning to $BUILDUSERNAME:$BUILDUSERNAME" >&2 
+    log "E: pbuilder: Failed chowning to $BUILDUSERNAME:$BUILDUSERNAME"
     exit 1;
 fi
 if echo "( cd tmp/buildd; /usr/bin/dpkg-source -x $(basename $PACKAGENAME) )" | $CHROOTEXEC $SUTOUSER ; then
     : # success
 else
-    echo "pbuilder: Failed extracting the source" >&2 
+    log "E: pbuilder: Failed extracting the source"
     exit 1;
 fi
 
-echo " -> Building the package"
+log "I: Building the package"
 
 executehooks "A"
 
@@ -130,10 +130,10 @@ if [ -n "${TIMEOUT_TIME}" ]; then
     ( 
 	: Timeout process
 	sleep "${TIMEOUT_TIME}"
-	echo " -> Terminating build process due to timeout "
+	log "I: Terminating build process due to timeout "
 	kill ${BUILD_PID} || true
     ) & # timeout process
-    KILL_WAIT_PID="kill "$!" || true; echo \"  -> Terminate timeout process\"; "
+    KILL_WAIT_PID="kill "$!" || true; echo \"I: Terminate timeout process\"; "
 else
     KILL_WAIT_PID=""
 fi
@@ -141,7 +141,7 @@ fi
 if ! wait ${BUILD_PID}; then
     trap umountproc_cleanbuildplace_trap exit sighup
     eval "${KILL_WAIT_PID}"
-    echo "pbuilder: Failed autobuilding of package" >&2
+    log "E: Failed autobuilding of package"
     executehooks "C"
     exit 1;
 else
@@ -161,7 +161,7 @@ if [ -d "${BUILDRESULT}" ]; then
     chgrp "${BUILDRESULTGID}" "${BUILDPLACE}"/tmp/buildd/*
     cp -p "${BUILDPLACE}"/tmp/buildd/* "${BUILDRESULT}" 2>/dev/null || true
 else
-    echo "E: BUILDRESULT=[$BUILDRESULT] is not a directory." >&2
+    log "E: BUILDRESULT=[$BUILDRESULT] is not a directory."
 fi
 
 :
diff --git a/pbuilder-buildpackage-funcs b/pbuilder-buildpackage-funcs
index 5cdbe40..370c799 100644
--- a/pbuilder-buildpackage-funcs
+++ b/pbuilder-buildpackage-funcs
@@ -25,7 +25,7 @@ function copydsc () {
       "$DSCFILE" \
 	$(cat "$DSCFILE" | \
 	awk 'BEGIN{p=0} /^$/ {p=0} /^.*:/ {p=0} {if (p){print "'$(dirname "$DSCFILE")'/" $3}} /^Files:/{p=1}' ) ; do
-	echo "    -> copying [$FILE]"
+	log "I: copying [$FILE]"
         cp -p "$FILE" "$TARGET" 
     done
 }
@@ -45,7 +45,7 @@ function checkbuilddep () {
 	if [ $? -eq 2 -a "${PRESERVE_BUILDPLACE}" = "yes" ]; then
 	    trap umountproc_trap exit sighup
 	fi
-	echo "E: pbuilder-satisfydepends failed." >&2
+	log "E: pbuilder-satisfydepends failed."
 	exit 2
     fi
     # install extra packages to the chroot
@@ -55,15 +55,14 @@ function checkbuilddep () {
 }
 
 function echobacktime () {
-    echo "Current time: $(date)"
-    echo "pbuilder-time-stamp: $(date +%s)"
+    log "I: Current time: $(date)"
+    log "I: pbuilder-time-stamp: $(date +%s)"
 }
 
 function showbuildbanner () {
     # show some banners for building
-    echo "pbuilder-buildpackage/"$(dpkg --print-architecture) 
-    echo "$1"
-    echo
+    log "I: pbuilder-buildpackage/"$(dpkg --print-architecture) 
+    log "I: $1"
 }
 
 function cowprotect () {
diff --git a/pbuilder-checkparams b/pbuilder-checkparams
index 47e4613..523e21e 100755
--- a/pbuilder-checkparams
+++ b/pbuilder-checkparams
@@ -47,7 +47,7 @@ while [ -n "$1" ]; do
 		    touch "$2";;
 	    esac
 	    if [ ! -f "$2" ]; then
-		echo "E: File $2 does not exist" >&2 
+		log "E: File $2 does not exist"
 		exit 1
 	    fi
 	    BASETGZ=$(readlink -f "$2");
@@ -55,7 +55,7 @@ while [ -n "$1" ]; do
 	    ;;
 	--buildplace)
 	    if [ ! -d "$2" ] ; then
-		echo "E: Directory $2 does not exist" >&2 
+		log "E: Directory $2 does not exist"
 		exit 1
 	    fi
 	    BUILDPLACE=$(readlink -f "$2");
@@ -91,7 +91,7 @@ while [ -n "$1" ]; do
 		    BUILDRESULT=$(readlink -f "$2");
 		else
 		    BUILDRESULT="$2"
-		    echo "W: Build-result Directory $2 does not exist" >&2 
+		    log "W: Build-result Directory $2 does not exist"
 		    # warn, but make it progress.
 		fi
 	    else
@@ -104,7 +104,7 @@ while [ -n "$1" ]; do
 		if [ -d "$2" ]; then
 		    APTCACHE=$(readlink -f "$2");
 		else
-		    echo "E: Directory $2 does not exist" >&2 
+		    log "E: Directory $2 does not exist"
 		    exit 1
 		fi
 	    else
@@ -122,7 +122,7 @@ while [ -n "$1" ]; do
 	    ;;
 	--configfile)
 	    if [ ! -f "$2" ]; then
-		echo "E: Config file $2 does not exist" >&2
+		log "E: Config file $2 does not exist"
 		exit 1
 	    fi
 	    . "$2";
@@ -146,7 +146,7 @@ while [ -n "$1" ]; do
 	    shift; shift;
 	    ;;
 	--logfile)
-	    echo "  -> Logging to $2"
+	    log "I: Logging to $2"
 	    exec > >(tee "$2");
 	    exec 2>&1
 	    PBUILDER_BUILD_LOGFILE=$(readlink -f "$2")
@@ -211,13 +211,13 @@ while [ -n "$1" ]; do
 	    ;;
 	--no-targz)
 	    # specify this option if I am running in no-targz mode
-	    echo " -> Running in no-targz mode"
+	    log "I: Running in no-targz mode"
 	    INTERNAL_BUILD_UML="yes"
 	    shift; 
 	    ;;
 	--internal-build-uml)
 	    # specify this option if I am running inside UML.
-	    echo " -> Running in pbuilder-user-mode-linux mode"
+	    log "I: Running in pbuilder-user-mode-linux mode"
 	    INTERNAL_BUILD_UML="yes"
 	    IGNORE_UMOUNT="no"
 	    shift; 
@@ -227,7 +227,7 @@ while [ -n "$1" ]; do
 	    break;
 	    ;;
 	--*)
-	    echo "Error: Unknown option [$1] was specified " >&2 
+	    log "E: Unknown option [$1] was specified "
 	    exit 1;
 	    ;;
 	*)
diff --git a/pbuilder-createbuildenv b/pbuilder-createbuildenv
index 770fe60..d304f17 100755
--- a/pbuilder-createbuildenv
+++ b/pbuilder-createbuildenv
@@ -26,7 +26,7 @@ set -e
 if [ -z "$DISTRIBUTION" ]; then
     DISTRIBUTION=sid
 fi
-echo "Distribution is $DISTRIBUTION."
+log "I: Distribution is $DISTRIBUTION."
 
 if [ "${PBUILDER_DEBUGMODE}" = "yes" ]; then
     TRAP="echo ignoring trap "
@@ -37,37 +37,37 @@ fi
 # first clean it.
 cleanbuildplace
 
-echo "Building the build environment"
+log "I: Building the build environment"
 mkdir -p "$BUILDPLACE"
 if [ ! -d "$BUILDPLACE" ]; then
-    echo "E: Could not make directory [$BUILDPLACE]" >&2
+    log "E: Could not make directory [$BUILDPLACE]"
     exit 1
 fi
 
 $TRAP cleanbuildplace exit
 
-echo " -> running $DEBOOTSTRAP"
+log "I: running $DEBOOTSTRAP"
 unset DEBOOTSTRAPSCRIPT
 if [ -n "$HOOKDIR" ]; then
     if [ -f "$HOOKDIR/$DISTRIBUTION" ]; then
 	DEBOOTSTRAPSCRIPT=$(readlink -f "$HOOKDIR")"/$DISTRIBUTION"
-	echo "  -> Applying user distribution dist build script $DEBOOTSTRAPSCRIPT"
+	log "I: Applying user distribution dist build script $DEBOOTSTRAPSCRIPT"
     fi
 fi
 
 if which "${DEBOOTSTRAP}"; then
     : # debootstrap exists
 else
-    echo "E: ${DEBOOTSTRAP} does not exist, install or change DEBOOTSTRAP option" >&2
+    log "E: ${DEBOOTSTRAP} does not exist, install or change DEBOOTSTRAP option"
     exit 1
 fi
 
 if ! ( cd "$BUILDPLACE" && "${DEBOOTSTRAP}" "${DEBOOTSTRAPOPTS[@]}" "$DISTRIBUTION" . "$MIRRORSITE" $DEBOOTSTRAPSCRIPT ) ; then
-    echo "pbuilder: $DEBOOTSTRAP failed" >&2
+    log "E: $DEBOOTSTRAP failed"
     exit 1
 fi
 
-echo " -> debootstrap finished"
+log "I: debootstrap finished"
 loadhooks
 
 
@@ -78,8 +78,8 @@ installaptlines
 
 executehooks "G"
 
-echo "Refreshing the base.tgz "
-echo " -> upgrading packages"
+log "I: Refreshing the base.tgz "
+log "I: upgrading packages"
 mountproc
 $TRAP umountproc_cleanbuildplace_trap exit sighup
 $CHROOTEXEC /usr/bin/apt-get update
diff --git a/pbuilder-loadconfig b/pbuilder-loadconfig
index 8367143..2c00871 100644
--- a/pbuilder-loadconfig
+++ b/pbuilder-loadconfig
@@ -21,6 +21,7 @@ for RCFILE in /usr/share/pbuilder/pbuilderrc /etc/pbuilderrc ${HOME}/.pbuilderrc
     if [ -f "$RCFILE" ]; then 
 	. "$RCFILE"
     else
+	# log() is not available
 	echo "W: $RCFILE does not exist" >&2
     fi
 done
diff --git a/pbuilder-modules b/pbuilder-modules
index 74210b7..12e4da7 100644
--- a/pbuilder-modules
+++ b/pbuilder-modules
@@ -88,6 +88,29 @@ EOF
     exit 1
 }
 
+# Log a message
+# message is of a format
+#  E: error message
+#  W: warning message
+#  I: informational message
+function log() {
+    case "$*" in
+	"E: "*) 
+	    echo "$*" >&2
+	    ;;
+ 	"W: "*) 
+	    echo "$*" >&2
+	    ;;
+ 	"I: "*) 
+	    echo "$*"
+	    ;;
+	*)
+	    echo "malformed log message: $*"
+	    exit 1
+	    ;;
+    esac
+}
+
 # test whether a directory is empty
 # fails if "$*" exists but isn't a directory
 # fails and outputs garbage if "$*" doesn't actually exist
@@ -101,23 +124,23 @@ function seems_truly_unmounted() {
     local mountpoint
     mountpoint="$1"
     if ! [ -e "$BUILDPLACE/$mountpoint" ]; then
-        echo "W: $mountpoint doesn't exist" >&2 
+        log "W: $mountpoint doesn't exist"
         return 1
     fi
     if ! [ -d "$BUILDPLACE/$mountpoint" ]; then
-        echo "W: $mountpoint isn't a directory" >&2 
+        log "W: $mountpoint isn't a directory"
         return 1
     fi
     if [ -r "$BUILDPLACE/proc/mounts" ] && grep -q "^[^ ]* $mountpoint " "$BUILDPLACE/proc/mounts"; then
-        echo "W: $mountpoint is mounted according to build place's /proc/mounts" >&2 
+        log "W: $mountpoint is mounted according to build place's /proc/mounts"
         return 1
     fi
     if [ -r "/proc/mounts" ] && grep -q "^[^ ]* $BUILDPLACE/$mountpoint " "/proc/mounts"; then
-        echo "W: $mountpoint is mounted according to system's /proc/mounts" >&2 
+        log "W: $mountpoint is mounted according to system's /proc/mounts"
         return 1
     fi
     if ! is_empty_dir "$BUILDPLACE/$mountpoint"; then
-        echo "W: $mountpoint not empty" >&2 
+        log "W: $mountpoint not empty"
         return 1
     fi
     return 0
@@ -126,13 +149,13 @@ function seems_truly_unmounted() {
 function umount_one () {
     if [ "${IGNORE_UMOUNT}" = "yes" ]; then
 	# support ignore umount option.
-	echo " -> ignoring umount of $1 filesystem"
+	log "I: ignoring umount of $1 filesystem"
 	return
     fi
-    echo " -> unmounting $1 filesystem"
+    log "I: unmounting $1 filesystem"
     local UMOUNT_OUTPUT
     if ! UMOUNT_OUTPUT="$(LC_ALL=C umount "$BUILDPLACE/$1" 2>&1)"; then
-        echo "W: Could not unmount $1: $UMOUNT_OUTPUT" >&2 
+        log "W: Could not unmount $1: $UMOUNT_OUTPUT"
         local ignore_umount_error="no"
         case $UMOUNT_OUTPUT in
           "umount: "*": not found"|"umount:"*": not mounted")
@@ -140,7 +163,7 @@ function umount_one () {
             if seems_truly_unmounted "$1"; then
                 ignore_umount_error="yes"
             else
-                echo "W: Tried ignoring error in unmount, but sanity check failed: $1 might still be mounted" >&2 
+                log "W: Tried ignoring error in unmount, but sanity check failed: $1 might still be mounted"
             fi
             ;;
           *)
@@ -148,7 +171,7 @@ function umount_one () {
             ;;
         esac
         if [ "$ignore_umount_error" != "yes" ]; then
-	    echo "W: Retrying to unmount $1 in 5s" >&2 
+	    log "W: Retrying to unmount $1 in 5s"
 	    sleep 5s
 	    while ! umount "$BUILDPLACE/$1"; do
 		sleep 5s
@@ -167,7 +190,7 @@ EOF
 		chroot "$BUILDPLACE" bin/sh
 	    done
         else
-            echo "W: Ignored error in unmount" >&2 
+            log "W: Ignored error in unmount"
         fi
     fi
 }
@@ -204,18 +227,18 @@ function umountproc () {
 # Also create a policy-rc.d script if it doesn't already exist.
 function mountproc () {
     if [ "$USEPROC" = "yes" ]; then
-	echo " -> mounting /proc filesystem"
+	log "I: mounting /proc filesystem"
 	mkdir -p $BUILDPLACE/proc
 	mount -t proc /proc "$BUILDPLACE/proc"
 	ln -s ../proc/mounts $BUILDPLACE/etc/mtab 2> /dev/null || true
     fi
     if [ "$USEDEVFS" = "yes" ]; then
-	echo " -> mounting /dev filesystem"
+	log "I: mounting /dev filesystem"x
 	mkdir -p $BUILDPLACE/dev || true
 	mount -t devfs /dev "$BUILDPLACE/dev" 
     fi
     if [ "$USEDEVPTS" = "yes" ]; then
-	echo " -> mounting /dev/pts filesystem"
+	log "I: mounting /dev/pts filesystem"
 	mkdir -p $BUILDPLACE/dev/pts || true
 	TTYGRP=5
 	TTYMODE=620
@@ -223,13 +246,13 @@ function mountproc () {
 	mount -t devpts /dev/pts "$BUILDPLACE/dev/pts" -onoexec,nosuid,gid=$TTYGRP,mode=$TTYMODE
     fi
     if [ -x /usr/sbin/selinuxenabled ] && /usr/sbin/selinuxenabled; then
-	echo " -> mounting selinux filesystem"
+	log "I: mounting selinux filesystem"
 	mkdir -p $BUILDPLACE/selinux
 	mount -t selinuxfs /selinux "$BUILDPLACE/selinux"
     fi    
     local -a mounted
     for mnt in $BINDMOUNTS; do
-	echo "-> Mounting $mnt"
+	log "I: Mounting $mnt"
 	if mkdir -p "$BUILDPLACE/$mnt" && 
 	    mount -obind "$mnt" "$BUILDPLACE/$mnt"; then
 	    # successful.
@@ -237,9 +260,9 @@ function mountproc () {
 	else
 	    # when unsuccessful, backtrack / umount and abort.
 	    if [ -n "${mounted[*]}" ]; then
-		echo "-> error recovery: umount successfully mounted bind-mounts: ${mounted[@]}"
+		log "I: error recovery: umount successfully mounted bind-mounts: ${mounted[@]}"
 		for umnt in "${mounted[@]}"; do
-		    echo "-> umounting $umnt"
+		    log "I: umounting $umnt"
 		    umount "$umnt"
 		done
 	    fi
@@ -247,9 +270,9 @@ function mountproc () {
 	fi
     done
     if [ -f "$BUILDPLACE/usr/sbin/policy-rc.d" ]; then
-	echo " -> policy-rc.d already exists"
+	log "I: policy-rc.d already exists"
     else
-	echo " -> installing dummy policy-rc.d"
+	log "I: installing dummy policy-rc.d"
 	echo "\
 #!/bin/sh
 
@@ -270,14 +293,14 @@ done
 ## function to clean subdirs, use instead of rm -r
 function clean_subdirectories () {
   if [ -z "$1" ]; then
-      echo "Fatal internal error in clean_subdirectories"
+      log "E: Fatal internal error in clean_subdirectories"
       exit 1;
   fi
   if [ ! -d "$1" ]; then
-      echo "Warning: directory $1 does not exist in clean_subdirectories"
+      log "W: directory $1 does not exist in clean_subdirectories"
       return;
   fi
-  echo "    -> removing directory $1 and its subdirectories"
+  log "I: removing directory $1 and its subdirectories"
   find "$1" -xdev \( \! -type d \) -print0 |xargs -0 rm -f
   find "$1" -xdev -depth -type d -print0 | \
       (xargs -0 rmdir || true)
@@ -285,11 +308,11 @@ function clean_subdirectories () {
 
 function cleanbuildplace () {
     if [ "$?" -ne 0 ]; then
-	echo " -> Aborting with an error";
+	log "W: Aborting with an error";
     fi
     if [ "${INTERNAL_BUILD_UML}" != "yes" ]; then
 	if [ -d "$BUILDPLACE" ]; then 
-	    echo " -> cleaning the build env "
+	    log "I: cleaning the build env "
 	    clean_subdirectories "$BUILDPLACE"
 	fi;
     fi
@@ -298,7 +321,7 @@ function cleanbuildplace () {
 function umountproc_cleanbuildplace () {
     # rolling back to abort.
     if [ "$?" -ne 0 ]; then
-	echo " -> Aborting with an error";
+	log "W: Aborting with an error";
     fi
     umountproc
     cleanbuildplace
@@ -311,10 +334,10 @@ function saveaptcache_umountproc_cleanbuildplace () {
 }
 
 function installaptlines (){
-    echo "  -> Installing apt-lines"
+    log "I: Installing apt-lines"
     rm -f "$BUILDPLACE"/etc/apt/sources.list
     if [ -z "$DISTRIBUTION" ]; then
-	echo "Distribution not specified, please specify" >&2
+	log "E: Distribution not specified, please specify"
 	exit 1
     fi
     if [ -z "$COMPONENTS" ] ; then
@@ -330,12 +353,12 @@ deb $MIRRORSITE $DISTRIBUTION $COMPONENTS
 EOF
     fi
     if [ -n "$APTCONFDIR" ]; then
-	echo "  -> Copy " "$APTCONFDIR"/* " to chroot"
+	log "I: Copy " "$APTCONFDIR"/* " to chroot"
 	cp -a "$APTCONFDIR/"* "$BUILDPLACE"/etc/apt
     fi
 
     if [ ! -d "$BUILDPLACE"/etc/apt/apt.conf.d ]; then
-	echo "  -> Create /etc/apt/apt.conf.d/ inside chroot"
+	log "I: Create /etc/apt/apt.conf.d/ inside chroot"
 	mkdir "$BUILDPLACE"/etc/apt/apt.conf.d
     fi
 
@@ -344,7 +367,7 @@ EOF
 APT::Install-Recommends "false";
 EOF
     if [ -n "$EXPERIMENTAL" ]; then
-	echo "  -> Installing apt-lines and pinning for experimental"
+	log "I: Installing apt-lines and pinning for experimental"
 	if [ -n "$MIRRORSITE" ] ; then
 	    echo "deb $MIRRORSITE experimental main" >> "$BUILDPLACE"/etc/apt/sources.list
 	    echo "#deb-src $MIRRORSITE experimental main" >> "$BUILDPLACE"/etc/apt/sources.list
@@ -356,13 +379,13 @@ EOF
 }
 
 function copy_local_configuration () {
-    echo " -> copying local configuration"
+    log "I: copying local configuration"
     for a in hosts hostname resolv.conf; do 
 	if [ -f "/etc/$a" ]; then
 		rm -f "$BUILDPLACE/etc/$a"
 		cp $( readlink -f "/etc/$a" ) "$BUILDPLACE/etc/$a";
 	else
-		echo "W: No local /etc/$a to copy, relying on $BUILDPLACE/etc/$a to be correct" >&2
+		log "W: No local /etc/$a to copy, relying on $BUILDPLACE/etc/$a to be correct"
  	fi
     done
 }
@@ -373,21 +396,21 @@ function extractbuildplace () {
 
     if [ "${INTERNAL_BUILD_UML}" != "yes" -a ! \( "${PRESERVE_BUILDPLACE}" = "yes" -a -d "$BUILDPLACE" \) ]; then
 	cleanbuildplace
-	echo "Building the build Environment"
+	log "I: Building the build Environment"
 	if ! mkdir -p "$BUILDPLACE"; then
-	    echo "E: failed to build the directory to chroot" >&2
+	    log "E: failed to build the directory to chroot"
 	    exit 1
 	fi
-	echo " -> extracting base tarball [${BASETGZ}]"
+	log "I: extracting base tarball [${BASETGZ}]"
 	if [ ! -f "$BASETGZ" ]; then
-	    echo "E: failed to find $BASETGZ, have you done <pbuilder create> to create your base tarball yet?" >&2
+	    log "E: failed to find $BASETGZ, have you done <pbuilder create> to create your base tarball yet?"
 	    exit 1
 	fi
 	if ! (cd "$BUILDPLACE" && tar xfzp "$BASETGZ"); then
-	    echo "E: failed to extract $BASETGZ to $BUILDPLACE" >&2 
+	    log "E: failed to extract $BASETGZ to $BUILDPLACE"
 	    exit 1
 	fi
-	echo " -> creating local configuration"
+	log "I: creating local configuration"
 	hostname -f > "$BUILDPLACE/etc/mailname"
     fi
     copy_local_configuration
@@ -397,7 +420,7 @@ function extractbuildplace () {
 	installaptlines
     else # Warn if override config is not set
 	if [ "$OVERRIDE_APTLINES_WARN" = "yes" ]; then
-	    echo "W: --override-config is not set; not updating apt.conf Read the manpage for details."
+	    log "W: --override-config is not set; not updating apt.conf Read the manpage for details."
 	fi
     fi
 
@@ -415,7 +438,7 @@ function recover_aptcache() {
 	else
 	    doit=cp
 	fi
-	echo "Obtaining the cached apt archive contents"
+	log "I: Obtaining the cached apt archive contents"
 	find "$APTCACHE" -maxdepth 1 -name \*.deb | \
 	    while read A ; do
 	    $doit "$A" "$BUILDPLACE/var/cache/apt/archives/" || true
@@ -428,7 +451,7 @@ function save_aptcache() {
     # it is safe to call this function several times.
     local doit
     if [ -n "$APTCACHE" ]; then
-	echo "Copying back the cached apt archive contents"
+	log "I: Copying back the cached apt archive contents"
 	mkdir -p "$APTCACHE" ;
 	if [ "$APTCACHEHARDLINK" = "yes" ]; then
 	    doit=ln
@@ -438,7 +461,7 @@ function save_aptcache() {
 	find "$BUILDPLACE/var/cache/apt/archives/" -maxdepth 1 -name \*.deb | \
 	    while read A ;do
 	    if [ ! -f "$APTCACHE/"$(basename "$A") -a -f "$A" ]; then
-		echo " -> new cache content "$(basename "$A")" added"
+		log "I: new cache content "$(basename "$A")" added"
 		$doit "$A" "$APTCACHE/" || true
 	    fi
 	done
@@ -449,16 +472,16 @@ function create_basetgz() {
     # create base.tgz
     ( 
 	if ! cd "$BUILDPLACE"; then
-	    echo "Error: unexpected error in chdir to $BUILDPLACE" >&2
+	    log "E: unexpected error in chdir to $BUILDPLACE"
 	    exit 1;
 	fi
 	while test -f "${BASETGZ}.tmp"; do
-	    echo "  -> Someone else has lock over ${BASETGZ}.tmp, waiting"
+	    log "I: Someone else has lock over ${BASETGZ}.tmp, waiting"
 	    sleep 10s
 	done
-	echo " -> creating base tarball [${BASETGZ}]"
+	log "I: creating base tarball [${BASETGZ}]"
 	if ! tar cfz "${BASETGZ}.tmp" * ; then
-	    echo " -> failed building base tarball"
+	    log "E: failed building base tarball"
 	    rm -f "${BASETGZ}.tmp"
 	    exit 1;
 	fi
diff --git a/pbuilder-runhooks b/pbuilder-runhooks
index ac500a2..9d26e83 100644
--- a/pbuilder-runhooks
+++ b/pbuilder-runhooks
@@ -38,7 +38,7 @@ function loadhooks () {
     if [ -d "$HOOKDIR" ]; then
 	mkdir -p "$BUILDPLACE/$hooks"
 	if ! cp -aL "$HOOKDIR/"* "$BUILDPLACE/$hooks"; then
-	    echo "W: no hooks found in the hookdir '$HOOKDIR'" >&2 
+	    log "W: no hooks found in the hookdir '$HOOKDIR'"
 	fi
     fi
 }
@@ -54,7 +54,7 @@ function unloadhooks () {
     if [ -d "$BUILDPLACE/$hooks" ]; then
 	rm -rf "$BUILDPLACE/$hooks"
     else
-	echo "E: Logic failure." >&2 
+	log "E: Logic failure."
     fi
 }
 
@@ -77,25 +77,26 @@ function executehooks () {
     for fn in "$BUILDPLACE/$hooks/$prefix"[0-9][0-9]* ; do
 	case "$fn" in
 	    "$BUILDPLACE/$hooks/$prefix"'[0-9][0-9]*')
-		echo "W: no hooks of type ${prefix} found -- ignoring" >&2 
+		log "W: no hooks of type ${prefix} found -- ignoring"
 		;;
 	    *~)
-		echo "W: skipping an editor backup file $fn" >&2 
+		log "W: skipping an editor backup file $fn"
 		;;
 	    *.bak)
-		echo "W: skipping a backup file $fn" >&2 
+		log "W: skipping a backup file $fn"
 		;;
 	    *)	
 		if [ -x "$fn" ]; then
+		    log "I: user script $fn starting"
 		    $CHROOTEXEC "$hooks/"$(basename "$fn")
-		    echo " -> user script $fn finished"
+		    log "I: user script $fn finished"
 		else
 		    if [ -f "$fn" ]; then
 			filetype=$(basename "$fn" ) 
-			echo "W: execute priv not set on file $filetype, not executing." >&2 
+			log "W: execute priv not set on file $filetype, not executing."
 		    else
 			# Should it reach here ? This case should be caught in the above case.
-			echo "W: no hooks of type ${prefix} found -- internal error in logic" >&2 
+			log "W: no hooks of type ${prefix} found -- internal error in logic"
 		    fi
 		fi  
 	        ;;	
diff --git a/pbuilder-updatebuildenv b/pbuilder-updatebuildenv
index 8b76da8..97eb466 100755
--- a/pbuilder-updatebuildenv
+++ b/pbuilder-updatebuildenv
@@ -23,7 +23,7 @@ set -e
 
 
 if [ -n "$DISTRIBUTION" ] && [ "$OVERRIDE_APTLINES" = "yes" ]; then
-    echo "Upgrading for distribution $DISTRIBUTION" 
+    log "I: Upgrading for distribution $DISTRIBUTION" 
 fi
 if [ "${PBUILDER_DEBUGMODE}" = "yes" ]; then
     TRAP="echo ignoring trap "
@@ -35,8 +35,8 @@ extractbuildplace
 $TRAP umountproc_cleanbuildplace_trap exit sighup
 
 loadhooks
-echo "Refreshing the base.tgz "
-echo " -> upgrading packages"
+log "I: Refreshing the base.tgz "
+log "I: upgrading packages"
 $CHROOTEXEC /usr/bin/apt-get update
 if [ -n "$REMOVEPACKAGES" ]; then
     $CHROOTEXEC /usr/bin/dpkg --purge $REMOVEPACKAGES
@@ -50,13 +50,13 @@ save_aptcache
 
 # optionally auto-clean apt-cache
 if [ "${AUTOCLEANAPTCACHE}" = "yes" -a -n "$APTCACHE" ]; then
-    echo " -> Cleaning the cached apt archive"
+    log "I: Cleaning the cached apt archive"
     $CHROOTEXEC /usr/bin/apt-get autoclean || true
     find "$APTCACHE/" -maxdepth 1 -name \*.deb | \
 	while read A; do
 	    if [ ! -f "$BUILDPLACE/var/cache/apt/archives/"$(basename "$A") -a \
 		-f "$A" ]; then
-		echo " -> obsolete cache content "$(basename "$A")" removed"
+		log "I: obsolete cache content "$(basename "$A")" removed"
 		rm -f "$A" || true
 	    fi
     done
diff --git a/pbuilder-user-mode-linux b/pbuilder-user-mode-linux
index 485b1a8..48ce023 100755
--- a/pbuilder-user-mode-linux
+++ b/pbuilder-user-mode-linux
@@ -36,7 +36,7 @@ function usecow () {
     PBUILDER_COWFILENAME="${BUILDPLACE}/$$.cow"
     PBUILDER_COW="${PBUILDER_COWFILENAME},"
     if ! touch "${PBUILDER_COWFILENAME}"; then
-	echo "E: Cannot write-access to the COW file, check buildplace" >&2 
+	log "E: Cannot write-access to the COW file, check buildplace"
 	exit 1;
     fi
     rm -f "${PBUILDER_COWFILENAME}"
diff --git a/pdebuild b/pdebuild
index 4609431..3c3454b 100644
--- a/pdebuild
+++ b/pdebuild
@@ -25,7 +25,7 @@ while ! test -d ./debian -o "$(pwd)" = "/" ; do
 done
 
 if test ! -d ./debian; then
-    echo "E: Cannot find ./debian dir" >&2
+    log "E: Cannot find ./debian dir"
     exit 1
 fi;
 
@@ -52,12 +52,12 @@ if [ "${USE_PDEBUILD_INTERNAL}" = 'yes' ]; then
 	done
 	cp -a ../${CHANGES} "${BUILDRESULT}"
     else
-	echo "E: BUILDRESULT=[$BUILDRESULT] is not a directory." >&2
+	log "E: BUILDRESULT=[$BUILDRESULT] is not a directory."
 	exit 1
     fi
 else
     if ! dpkg-checkbuilddeps -B ; then
-	echo "W: Unmet build-dependency in source" >&2
+	log "W: Unmet build-dependency in source"
     fi
     echo "dpkg-buildpackage -S -us -uc -r${BUILDSOURCEROOTCMD} $DEBBUILDOPTS" | perl -pe 's/(^|\s)-[bB](\s|$)/$1$2/g' | /bin/bash
     ${PBUILDERROOTCMD} ${PDEBUILD_PBUILDER} --build ${EXTRA_CONFIGFILE[@]/#/--configfile } --buildresult "${BUILDRESULT}"  --debbuildopts "${DEBBUILDOPTS}" "$@"  ../"${PKG_SOURCENAME}_${PKG_VERSION}".dsc
diff --git a/pdebuild-checkparams b/pdebuild-checkparams
index 2c003d0..e9a59af 100644
--- a/pdebuild-checkparams
+++ b/pdebuild-checkparams
@@ -33,7 +33,7 @@ while [ -n "$1" ]; do
 		    BUILDRESULT=$(readlink -f "$2");
 		else
 		    BUILDRESULT="$2"
-		    echo "W: Build-result Directory $2 does not exist" >&2 
+		    log "W: Build-result Directory $2 does not exist"
 		    # warn, but make it progress.
 		fi
 	    else
@@ -47,7 +47,7 @@ while [ -n "$1" ]; do
 	    ;;
 	--configfile)
 	    if [ ! -f "$2" ]; then
-		echo "E: Config file $2 does not exist" >&2
+		log "E: Config file $2 does not exist"
 		exit 1
 	    fi
 	    . "$2";
@@ -85,14 +85,14 @@ while [ -n "$1" ]; do
 	    shift;
 	    ;;
 	--logfile)
-	    echo "  -> Logging to $2"
+	    log "I: Logging to $2"
 	    PBUILDER_BUILD_LOGFILE=$(readlink -f $2)
 	    exec > >(tee "$2");
 	    exec 2>&1
 	    shift; shift;
 	    ;;
 	--pbuilder)
-	    echo "  -> using $2 as pbuilder"
+	    log "I: using $2 as pbuilder"
 	    PDEBUILD_PBUILDER="$2"
 	    shift; shift;
 	    ;;
@@ -104,7 +104,7 @@ while [ -n "$1" ]; do
 	    break;
 	    ;;
 	--*)
-	    echo "Error: Unknown option [$1] was specified " >&2 
+	    log "E: Unknown option [$1] was specified "
 	    exit 1;
 	    ;;
 	*)
diff --git a/pdebuild-internal b/pdebuild-internal
index 2d42145..ce624b2 100644
--- a/pdebuild-internal
+++ b/pdebuild-internal
@@ -38,10 +38,15 @@ export LOGNAME=root
 cd "$1"
 shift;
 
+# dummy function that does enough, real one is defined elsewhere.
+function log() {
+    echo "$*"
+}
+
 while [ -n "$1" ]; do 
     case "$1" in 
 	--debbuildopts)
-	    echo "Setting DEBBUILDOPTS=$2"
+	    log "I: Setting DEBBUILDOPTS=$2"
 	    DEBBUILDOPTS="$2"
 	    shift; shift;
 	    ;;
@@ -63,7 +68,7 @@ while [ -n "$1" ]; do
 	    shift;
 	    ;;
 	--*)
-	    echo "Error: Unknown option [$1] was specified " >&2 
+	    log "E: Unknown option [$1] was specified "
 	    exit 1;
 	    ;;
 	*)
diff --git a/test_pbuilder-modules b/test_pbuilder-modules
new file mode 100755
index 0000000..402c424
--- /dev/null
+++ b/test_pbuilder-modules
@@ -0,0 +1,15 @@
+#!/bin/bash
+
+. ./testlib.sh
+. ./pbuilder-modules
+
+function test_information() {
+    log "I: test"
+    log "W: warning"
+    log "E: error"
+}
+expect_output "I: test
+W: warning
+E: error" test_information
+
+testlib_summary