HBASE-25380 [create-release] Add timestamping to log output (#2758)

Added logging of timestamp so we can tell where we are spending time.
Added context to the README copied from head of entrance script.

Signed-off-by: Andrew Purtell <apurtell@apache.org>

dev-support/create-release/README.txt

@@ -1,7 +1,31 @@
-Entrance script is _do-release-docker.sh_. Requires a local docker;
+Creates a HBase release candidate. The script will update versions, tag the branch,
-for example, on mac os x, Docker for Desktop installed and running.
+build HBase binary packages and documentation, and upload maven artifacts to a staging
+repository. There is also a dry run mode where only local builds are performed, and
+nothing is uploaded to the ASF repos.
 
-For usage, pass '-h':
+Run with "-h" for options. For example, running below will do all
+steps above using the 'rm' dir under Downloads as workspace:
+
+ $ ./do-release-docker.sh  -d ~/Downloads/rm
+
+The scripts in this directory came originally from spark
+(https://github.com/apache/spark/tree/master/dev/create-release). They were then
+modified to suite the hbase context. These scripts supercedes the old
+../make_rc.sh script for making release candidates because what is here is more
+comprehensive doing more steps of the RM process as well as running in a
+container so the RM build environment can be a constant.
+
+It:
+
+ * Tags release
+ * Sets version to the release version
+ * Sets version to next SNAPSHOT version.
+ * Builds, signs, and hashes all artifacts.
+ * Pushes release tgzs to the dev dir in a apache dist.
+ * Pushes to repository.apache.org staging.
+
+The entry point is here, in the do-release-docker.sh script. Requires a local
+docker; for example, on mac os x, Docker for Desktop installed and running.
 
  $ ./do-release-docker.sh -h
 

dev-support/create-release/do-release-docker.sh

@@ -76,7 +76,7 @@ Options:
   -s [step]    runs a single step of the process; valid steps are: tag|publish-dist|publish-release.
                If none specified, runs tag, then publish-dist, and then publish-release.
                'publish-snapshot' is also an allowed, less used, option.
-  -x           debug. do less clean up. (env file, gpg forwarding on mac)
+  -x           debug. Does less clean up (env file, gpg forwarding on mac)
 EOF
   exit 1
 }
@@ -147,7 +147,7 @@ done
 
 # We need to import that public key in the container in order to use the private key via the agent.
 GPG_KEY_FILE="$WORKDIR/gpg.key.public"
-echo "Exporting public key for ${GPG_KEY}"
+log "Exporting public key for ${GPG_KEY}"
 fcreate_secure "$GPG_KEY_FILE"
 $GPG "${GPG_ARGS[@]}" --export "${GPG_KEY}" > "${GPG_KEY_FILE}"
 
@@ -155,10 +155,10 @@ function cleanup {
   local id
   banner "Release Cleanup"
   if is_debug; then
-    echo "skipping due to debug run"
+    log "skipping due to debug run"
     return 0
   fi
-  echo "details in cleanup.log"
+  log "details in cleanup.log"
   if [ -f "${ENVFILE}" ]; then
     rm -f "$ENVFILE"
   fi
@@ -186,7 +186,7 @@ function cleanup {
 
 trap cleanup EXIT
 
-echo "Host OS: ${HOST_OS}"
+log "Host OS: ${HOST_OS}"
 if [ "${HOST_OS}" == "DARWIN" ]; then
   run_silent "Building gpg-agent-proxy image with tag ${IMGTAG}..." "docker-proxy-build.log" \
     docker build --build-arg "UID=${UID}" --build-arg "RM_USER=${USER}" \
@@ -198,7 +198,7 @@ run_silent "Building hbase-rm image with tag $IMGTAG..." "docker-build.log" \
       --build-arg "RM_USER=${USER}" "$SELF/hbase-rm"
 
 banner "Final prep for container launch."
-echo "Writing out environment for container."
+log "Writing out environment for container."
 # Write the release information to a file with environment variables to be used when running the
 # image.
 ENVFILE="$WORKDIR/env.list"
@@ -244,7 +244,7 @@ if [ -n "${GIT_REPO}" ]; then
       ;;
     # on the host but normally git wouldn't use the local optimization
     file://*)
-      echo "[INFO] converted file:// git repo to a local path, which changes git to assume --local."
+      log "Converted file:// git repo to a local path, which changes git to assume --local."
       GIT_REPO_MOUNT=(--mount "type=bind,src=${GIT_REPO#file://},dst=/opt/hbase-repo,consistency=delegated")
       echo "HOST_GIT_REPO=${GIT_REPO}" >> "${ENVFILE}"
       GIT_REPO="/opt/hbase-repo"
@@ -286,8 +286,8 @@ fi
 GPG_PROXY_MOUNT=()
 if [ "${HOST_OS}" == "DARWIN" ]; then
   GPG_PROXY_MOUNT=(--mount "type=volume,src=gpgagent,dst=/home/${USER}/.gnupg/")
-  echo "Setting up GPG agent proxy container needed on OS X."
+  log "Setting up GPG agent proxy container needed on OS X."
-  echo "    we should clean this up for you. If that fails the container ID is below and in " \
+  log "    we should clean this up for you. If that fails the container ID is below and in " \
       "gpg-proxy.cid"
   #TODO the key pair used should be configurable
   docker run --rm -p 62222:22 \
@@ -301,8 +301,8 @@ if [ "${HOST_OS}" == "DARWIN" ]; then
   sort "${HOME}/.ssh/known_hosts" | comm -1 -3 - "${WORKDIR}/gpg-agent-proxy.ssh-keyscan" \
       > "${WORKDIR}/gpg-agent-proxy.known_hosts"
   if [ -s "${WORKDIR}/gpg-agent-proxy.known_hosts" ]; then
-    echo "Your ssh known_hosts does not include the entries for the gpg-agent proxy container."
+    log "Your ssh known_hosts does not include the entries for the gpg-agent proxy container."
-    echo "The following entry(ies) are missing:"
+    log "The following entry(ies) are missing:"
     sed -e 's/^/    /' "${WORKDIR}/gpg-agent-proxy.known_hosts"
     read -r -p "Okay to add these entries to ${HOME}/.ssh/known_hosts? [y/n] " ANSWER
     if [ "$ANSWER" != "y" ]; then
@@ -310,8 +310,8 @@ if [ "${HOST_OS}" == "DARWIN" ]; then
     fi
     cat "${WORKDIR}/gpg-agent-proxy.known_hosts" >> "${HOME}/.ssh/known_hosts"
   fi
-  echo "Launching ssh reverse tunnel from the container to gpg agent."
+  log "Launching ssh reverse tunnel from the container to gpg agent."
-  echo "    we should clean this up for you. If that fails the PID is in gpg-proxy.ssh.pid"
+  log "    we should clean this up for you. If that fails the PID is in gpg-proxy.ssh.pid"
   ssh -p 62222 -R "/home/${USER}/.gnupg/S.gpg-agent:$(gpgconf --list-dir agent-extra-socket)" \
       -i "${HOME}/.ssh/id_rsa" -N -n localhost >gpg-proxy.ssh.log 2>&1 &
   echo $! > "${WORKDIR}/gpg-proxy.ssh.pid"
@@ -326,10 +326,10 @@ else
 fi
 
 banner "Building $RELEASE_TAG; output will be at $WORKDIR/output"
-echo "We should clean the container up when we are done. If that fails then the container ID " \
+log "We should clean the container up when we are done. If that fails then the container ID " \
     "is in release.cid"
 echo
-# Where possible we specifcy "consistency=delegated" when we do not need host access during the
+# Where possible we specify "consistency=delegated" when we do not need host access during the
 # build run. On Mac OS X specifically this gets us a big perf improvement.
 cmd=(docker run --rm -ti \
   --env-file "$ENVFILE" \

dev-support/create-release/release-build.sh

@@ -81,7 +81,7 @@ set -e
 function cleanup {
   # If REPO was set, then leave things be. Otherwise if we defined a repo clean it out.
   if [[ -z "${REPO}" ]] && [[ -n "${MAVEN_LOCAL_REPO}" ]]; then
-    echo "Cleaning up temp repo in '${MAVEN_LOCAL_REPO}'. Set REPO to reuse downloads." >&2
+    log "Cleaning up temp repo in '${MAVEN_LOCAL_REPO}'. Set REPO to reuse downloads." >&2
     rm -f "${MAVEN_SETTINGS_FILE}" &> /dev/null || true
     rm -rf "${MAVEN_LOCAL_REPO}" &> /dev/null || true
   fi
@@ -142,7 +142,7 @@ if [[ "$1" == "tag" ]]; then
   git add RELEASENOTES.md CHANGES.md
 
   git commit -a -m "Preparing ${PROJECT} release $RELEASE_TAG; tagging and updates to CHANGES.md and RELEASENOTES.md"
-  echo "Creating tag $RELEASE_TAG at the head of $GIT_BRANCH"
+  log "Creating tag $RELEASE_TAG at the head of $GIT_BRANCH"
   git tag "$RELEASE_TAG"
 
   # Create next version
@@ -159,7 +159,7 @@ if [[ "$1" == "tag" ]]; then
   else
     cd ..
     mv "${PROJECT}" "${PROJECT}.tag"
-    echo "Dry run: Clone with version changes and tag available as ${PROJECT}.tag in the output directory."
+    log "Dry run: Clone with version changes and tag available as ${PROJECT}.tag in the output directory."
   fi
   exit 0
 fi
@@ -186,7 +186,7 @@ fi
 cd "${PROJECT}"
 git checkout "$GIT_REF"
 git_hash="$(git rev-parse --short HEAD)"
-echo "Checked out ${PROJECT} at ${GIT_REF} commit $git_hash"
+log "Checked out ${PROJECT} at ${GIT_REF} commit $git_hash"
 
 if [ -z "${RELEASE_VERSION}" ]; then
   RELEASE_VERSION="$(maven_get_version)"
@@ -210,7 +210,7 @@ cd ..
 
 if [[ "$1" == "publish-dist" ]]; then
   # Source and binary tarballs
-  echo "Packaging release source tarballs"
+  log "Packaging release source tarballs"
   make_src_release "${PROJECT}" "${RELEASE_VERSION}"
 
   # we do not have binary tarballs for hbase-thirdparty
@@ -228,7 +228,7 @@ if [[ "$1" == "publish-dist" ]]; then
   rm -rf "${svn_target:?}/${DEST_DIR_NAME}"
   mkdir -p "$svn_target/${DEST_DIR_NAME}"
 
-  echo "Copying release tarballs"
+  log "Copying release tarballs"
   cp "${PROJECT}"-*.tar.* "$svn_target/${DEST_DIR_NAME}/"
   cp "${PROJECT}/CHANGES.md" "$svn_target/${DEST_DIR_NAME}/"
   cp "${PROJECT}/RELEASENOTES.md" "$svn_target/${DEST_DIR_NAME}/"
@@ -241,6 +241,7 @@ if [[ "$1" == "publish-dist" ]]; then
   fi
   shopt -u nocasematch
 
+  log "svn add"
   svn add "$svn_target/${DEST_DIR_NAME}"
 
   if ! is_dry_run; then
@@ -250,9 +251,10 @@ if [[ "$1" == "publish-dist" ]]; then
     rm -rf "$svn_target"
   else
     mv "$svn_target/${DEST_DIR_NAME}" "${svn_target}_${DEST_DIR_NAME}.dist"
-    echo "Dry run: svn-managed 'dist' directory with release tarballs, CHANGES.md and RELEASENOTES.md available as $(pwd)/${svn_target}_${DEST_DIR_NAME}.dist"
+    log "Dry run: svn-managed 'dist' directory with release tarballs, CHANGES.md and RELEASENOTES.md available as $(pwd)/${svn_target}_${DEST_DIR_NAME}.dist"
     rm -rf "$svn_target"
   fi
+  log "svn ci done"
 
   exit 0
 fi
@@ -261,13 +263,13 @@ if [[ "$1" == "publish-snapshot" ]]; then
   (
   cd "${PROJECT}"
   mvn_log="${BASE_DIR}/mvn_deploy_snapshot.log"
-  echo "Publishing snapshot to nexus"
+  log "Publishing snapshot to nexus"
   maven_deploy snapshot "$mvn_log"
   if ! is_dry_run; then
-    echo "Snapshot artifacts successfully published to repo."
+    log "Snapshot artifacts successfully published to repo."
     rm "$mvn_log"
   else
-    echo "Dry run: Snapshot artifacts successfully built, but not published due to dry run."
+    log "Dry run: Snapshot artifacts successfully built, but not published due to dry run."
   fi
   )
   exit $?
@@ -277,16 +279,16 @@ if [[ "$1" == "publish-release" ]]; then
   (
   cd "${PROJECT}"
   mvn_log="${BASE_DIR}/mvn_deploy_release.log"
-  echo "Staging release in nexus"
+  log "Staging release in nexus"
   maven_deploy release "$mvn_log"
   declare staged_repo_id="dryrun-no-repo"
   if ! is_dry_run; then
     staged_repo_id=$(grep -o "Closing staging repository with ID .*" "$mvn_log" \
         | sed -e 's/Closing staging repository with ID "\([^"]*\)"./\1/')
-    echo "Release artifacts successfully published to repo ${staged_repo_id}"
+    log "Release artifacts successfully published to repo ${staged_repo_id}"
     rm "$mvn_log"
   else
-    echo "Dry run: Release artifacts successfully built, but not published due to dry run."
+    log "Dry run: Release artifacts successfully built, but not published due to dry run."
   fi
   # Dump out email to send. Where we find vote.tmpl depends
   # on where this script is run from
@@ -300,5 +302,5 @@ fi
 set +x  # done with detailed logging
 cd ..
 rm -rf "${PROJECT}"
-echo "ERROR: expects to be called with 'tag', 'publish-dist', 'publish-release', or 'publish-snapshot'" >&2
+log "ERROR: expects to be called with 'tag', 'publish-dist', 'publish-release', or 'publish-snapshot'" >&2
 exit_with_usage

dev-support/create-release/release-util.sh

@@ -29,7 +29,7 @@ PUBLISH_PROFILES=("-P" "apache-release,release")
 set -e
 
 function error {
-  echo "Error: $*" >&2
+  log "Error: $*" >&2
   exit 1
 }
 
@@ -54,10 +54,14 @@ function parse_version {
 function banner {
   local msg="$1"
   echo "========================"
-  echo "=== ${msg}"
+  log "${msg}"
   echo
 }
 
+function log {
+  echo "$(date -u +"%Y-%m-%dT%H:%M:%SZ") ${1}"
+}
+
 # current number of seconds since epoch
 function get_ctime {
   date +"%s"
@@ -71,17 +75,17 @@ function run_silent {
   local -i stop_time
 
   banner "${BANNER}"
-  echo "Command: $*"
+  log "Command: $*"
-  echo "Log file: $LOG_FILE"
+  log "Log file: $LOG_FILE"
   start_time="$(get_ctime)"
 
   if ! "$@" 1>"$LOG_FILE" 2>&1; then
-    echo "Command FAILED. Check full logs for details."
+    log "Command FAILED. Check full logs for details."
     tail "$LOG_FILE"
     exit 1
   fi
   stop_time="$(get_ctime)"
-  echo "=== SUCCESS ($((stop_time - start_time)) seconds)"
+  log "SUCCESS ($((stop_time - start_time)) seconds)"
 }
 
 function fcreate_secure {
@@ -147,7 +151,7 @@ function get_release_info {
   local version
   version="$(curl -s "$ASF_REPO_WEBUI;a=blob_plain;f=pom.xml;hb=refs/heads/$GIT_BRANCH" |
     parse_version)"
-  echo "Current branch VERSION is $version."
+  log "Current branch VERSION is $version."
 
   NEXT_VERSION="$version"
   RELEASE_VERSION=""
@@ -199,7 +203,7 @@ function get_release_info {
   if git ls-remote --tags "$ASF_REPO" "$RELEASE_TAG" | grep -q "refs/tags/${RELEASE_TAG}$" ; then
     read -r -p "$RELEASE_TAG already exists. Continue anyway [y/n]? " ANSWER
     if [ "$ANSWER" != "y" ]; then
-      echo "Exiting."
+      log "Exiting."
       exit 1
     fi
     SKIP_TAG=1
@@ -209,7 +213,7 @@ function get_release_info {
 
   GIT_REF="$RELEASE_TAG"
   if is_dry_run; then
-    echo "This is a dry run. If tag does not actually exist, please confirm the ref that will be built for testing."
+    log "This is a dry run. If tag does not actually exist, please confirm the ref that will be built for testing."
     GIT_REF="$(read_config "GIT_REF" "$GIT_REF")"
   fi
   export GIT_REF
@@ -252,7 +256,7 @@ EOF
 
   read -r -p "Is this info correct [y/n]? " ANSWER
   if [ "$ANSWER" != "y" ]; then
-    echo "Exiting."
+    log "Exiting."
     exit 1
   fi
   GPG_ARGS=("${GPG_ARGS[@]}" --local-user "${GPG_KEY}")
@@ -279,7 +283,7 @@ function is_debug {
 function check_get_passwords {
   for env in "$@"; do
     if [ -z "${!env}" ]; then
-      echo "The environment variable $env is not set. Please enter the password or passphrase."
+      log "The environment variable $env is not set. Please enter the password or passphrase."
       echo
       # shellcheck disable=SC2229
       stty -echo && printf "%s : " "$env" && read -r "$env" && printf '\n' && stty echo
@@ -293,7 +297,7 @@ function check_needed_vars {
   local missing=0
   for env in "$@"; do
     if [ -z "${!env}" ]; then
-      echo "$env must be set to run this script"
+      log "$env must be set to run this script"
       (( missing++ ))
     else
       # shellcheck disable=SC2163
@@ -322,7 +326,7 @@ function init_java {
     error "JAVA_HOME is not set."
   fi
   JAVA_VERSION=$("${JAVA_HOME}"/bin/javac -version 2>&1 | cut -d " " -f 2)
-  echo "java version: $JAVA_VERSION"
+  log "java version: $JAVA_VERSION"
   export JAVA_VERSION
 }
 
@@ -330,7 +334,7 @@ function init_python {
   if ! [ -x "$(command -v python2)"  ]; then
     error 'python2 needed by yetus. Install or add link? E.g: sudo ln -sf /usr/bin/python2.7 /usr/local/bin/python2'
   fi
-  echo "python version: $(python2 --version)"
+  log "python version: $(python2 --version)"
 }
 
 # Set MVN
@@ -357,7 +361,7 @@ function init_yetus {
   fi
   # Work around yetus bug by asking test-patch for the version instead of rdm.
   YETUS_VERSION=$("${YETUS_HOME}/bin/test-patch" --version)
-  echo "Apache Yetus version ${YETUS_VERSION}"
+  log "Apache Yetus version ${YETUS_VERSION}"
 }
 
 function configure_maven {
@@ -409,7 +413,7 @@ function git_clone_overwrite {
 
   if [[ -z "${GIT_REPO}" ]]; then
     asf_repo="gitbox.apache.org/repos/asf/${PROJECT}.git"
-    echo "[INFO] clone will be of the gitbox repo for ${PROJECT}."
+    log "Clone will be of the gitbox repo for ${PROJECT}."
     if [ -n "${ASF_USERNAME}" ] && [ -n "${ASF_PASSWORD}" ]; then
       # Ugly!
       encoded_username=$(python -c "import urllib; print urllib.quote('''$ASF_USERNAME''', '')")
@@ -419,7 +423,7 @@ function git_clone_overwrite {
       GIT_REPO="https://${asf_repo}"
     fi
   else
-    echo "[INFO] clone will be of provided git repo."
+    log "Clone will be of provided git repo."
   fi
   # N.B. we use the shared flag because the clone is short lived and if a local repo repo was
   #      given this will let us refer to objects there directly instead of hardlinks or copying.
@@ -440,7 +444,7 @@ function start_step {
   if [ -z "${name}" ]; then
     name="${FUNCNAME[1]}"
   fi
-  echo "$(date -u +'%Y-%m-%dT%H:%M:%SZ') ${name} start" >&2
+  log "${name} start" >&2
   get_ctime
 }
 
@@ -452,7 +456,7 @@ function stop_step {
     name="${FUNCNAME[1]}"
   fi
   stop_time="$(get_ctime)"
-  echo "$(date -u +'%Y-%m-%dT%H:%M:%SZ') ${name} stop ($((stop_time - start_time)) seconds)"
+  log "${name} stop ($((stop_time - start_time)) seconds)"
 }
 
 # Writes report into cwd!
@@ -488,7 +492,7 @@ function get_jira_name {
   if [[ -z "$jira_name" ]]; then
     error "Sorry, can't determine the Jira name for project $project"
   fi
-  echo "$jira_name"
+  log "$jira_name"
 }
 
 # Update the CHANGES.md
@@ -625,7 +629,7 @@ make_binary_release() {
     done
   else
     cd .. || exit
-    echo "No ${f_bin_prefix}*-bin.tar.gz product; expected?"
+    log "No ${f_bin_prefix}*-bin.tar.gz product; expected?"
   fi
 
   stop_step "${timing_token}"
@@ -648,7 +652,7 @@ function kick_gpg_agent {
 # Do maven command to set version into local pom
 function maven_set_version { #input: <version_to_set>
   local this_version="$1"
-  echo "${MVN[@]}" versions:set -DnewVersion="$this_version"
+  log "${MVN[@]}" versions:set -DnewVersion="$this_version"
   "${MVN[@]}" versions:set -DnewVersion="$this_version" | grep -v "no value" # silence logs
 }
 
@@ -679,8 +683,8 @@ function maven_deploy { #inputs: <snapshot|release> <log_file_path>
   fi
   # Publish ${PROJECT} to Maven repo
   # shellcheck disable=SC2154
-  echo "Publishing ${PROJECT} checkout at '$GIT_REF' ($git_hash)"
+  log "Publishing ${PROJECT} checkout at '$GIT_REF' ($git_hash)"
-  echo "Publish version is $RELEASE_VERSION"
+  log "Publish version is $RELEASE_VERSION"
   # Coerce the requested version
   maven_set_version "$RELEASE_VERSION"
   # Prepare for signing
@@ -689,9 +693,8 @@ function maven_deploy { #inputs: <snapshot|release> <log_file_path>
   if ! is_dry_run; then
     mvn_goals=("${mvn_goals[@]}" deploy)
   fi
-  echo "${MVN[@]}" -DskipTests -Dcheckstyle.skip=true "${PUBLISH_PROFILES[@]}" \
+  log "${MVN[@]}" -DskipTests -Dcheckstyle.skip=true "${PUBLISH_PROFILES[@]}" "${mvn_goals[@]}"
-      "${mvn_goals[@]}"
+  log "Logging to ${mvn_log_file}.  This will take a while..."
-  echo "Logging to ${mvn_log_file}.  This will take a while..."
   rm -f "$mvn_log_file"
   # The tortuous redirect in the next command allows mvn's stdout and stderr to go to mvn_log_file,
   # while also sending stderr back to the caller.
@@ -700,7 +703,7 @@ function maven_deploy { #inputs: <snapshot|release> <log_file_path>
       "${mvn_goals[@]}" 1>> "$mvn_log_file" 2> >( tee -a "$mvn_log_file" >&2 ); then
     error "Deploy build failed, for details see log at '$mvn_log_file'."
   fi
-  echo "BUILD SUCCESS."
+  log "BUILD SUCCESS."
   stop_step "${timing_token}"
   return 0
 }