Log AMI publish step timings

publish-ami.sh

@@ -7,6 +7,7 @@ builder_instance_type=""
 name="nixos-zfs-ec2"
 keep_builder=false
 extra_tofu_args=()
+script_start_epoch="$(date +%s)"
 
 usage() {
   cat >&2 <<'EOF'
@@ -87,6 +88,31 @@ require() {
   fi
 }
 
+elapsed() {
+  local start="$1"
+  local end
+  end="$(date +%s)"
+  printf '%ss' "$((end - start))"
+}
+
+total_elapsed() {
+  elapsed "$script_start_epoch"
+}
+
+log() {
+  printf '[%s] %s\n' "$(date -Is)" "$*" >&2
+}
+
+step() {
+  local label="$1"
+  shift
+  local start
+  start="$(date +%s)"
+  log "starting: ${label}"
+  "$@"
+  log "finished: ${label} ($(elapsed "$start"), total $(total_elapsed))"
+}
+
 require aws
 require git
 require jq
@@ -117,8 +143,8 @@ if [ -n "$builder_instance_type" ]; then
   common_tofu_vars+=(-var "builder_instance_type=$builder_instance_type")
 fi
 
-tofu init
+step "tofu init" tofu init
-tofu apply \
+step "tofu apply builder resources" tofu apply \
   -auto-approve \
   "${common_tofu_vars[@]}" \
   "${extra_tofu_args[@]}"
@@ -128,9 +154,10 @@ nix_volume_id="$(tofu output -raw nix_volume_id)"
 nix_device_name="$(tofu output -raw nix_device_name)"
 nix_pool="$(tofu output -raw nix_pool)"
 
-echo "Waiting for builder instance to stop: $builder_instance_id" >&2
+log "waiting for builder instance to stop: $builder_instance_id"
-aws ec2 wait instance-stopped --region "$aws_region" --instance-ids "$builder_instance_id"
+step "wait for builder instance stop" aws ec2 wait instance-stopped --region "$aws_region" --instance-ids "$builder_instance_id"
 
+log "creating capture image from stopped builder"
 capture_image_id="$(
   aws ec2 create-image \
     --region "$aws_region" \
@@ -142,8 +169,9 @@ capture_image_id="$(
     --query ImageId \
     --output text
 )"
+log "capture image: $capture_image_id"
 
-aws ec2 wait image-available --region "$aws_region" --image-ids "$capture_image_id"
+step "wait for capture image" aws ec2 wait image-available --region "$aws_region" --image-ids "$capture_image_id"
 
 capture_image_json="$(aws ec2 describe-images --region "$aws_region" --image-ids "$capture_image_id")"
 root_snapshot_id="$(
@@ -222,6 +250,7 @@ block_device_mappings="$(
     ]'
 )"
 
+log "registering final AMI"
 image_id="$(
   aws ec2 register-image \
     --region "$aws_region" \
@@ -235,10 +264,11 @@ image_id="$(
     --query ImageId \
     --output text
 )"
+log "final AMI: $image_id"
 
-aws ec2 wait image-available --region "$aws_region" --image-ids "$image_id"
+step "wait for final AMI" aws ec2 wait image-available --region "$aws_region" --image-ids "$image_id"
 
-aws ec2 create-tags \
+step "tag root snapshot" aws ec2 create-tags \
   --region "$aws_region" \
   --resources "$root_snapshot_id" \
   --tags \
@@ -250,7 +280,7 @@ aws ec2 create-tags \
     "Key=BuilderGitRev,Value=${builder_git_rev}" \
     "Key=FlakeLockRev,Value=${flake_lock_rev}"
 
-aws ec2 create-tags \
+step "tag nix snapshot and volume" aws ec2 create-tags \
   --region "$aws_region" \
   --resources "$nix_snapshot_id" "$nix_volume_id" \
   --tags \
@@ -263,7 +293,7 @@ aws ec2 create-tags \
     "Key=FlakeLockRev,Value=${flake_lock_rev}" \
     "Key=NixPool,Value=${nix_pool}"
 
-aws ec2 create-tags \
+step "tag final AMI" aws ec2 create-tags \
   --region "$aws_region" \
   --resources "$image_id" \
   --tags \
@@ -285,7 +315,7 @@ for ssm_ami_parameter_name in \
   "${ssm_ami_prefix}/by-builder-rev/${builder_git_rev}" \
   "${ssm_ami_prefix}/by-input-hash/${input_hash}"
 do
-  aws ssm put-parameter \
+  step "publish SSM ${ssm_ami_parameter_name}" aws ssm put-parameter \
     --region "$aws_region" \
     --name "$ssm_ami_parameter_name" \
     --type String \
@@ -293,7 +323,7 @@ do
     --overwrite >/dev/null
 done
 
-aws ec2 deregister-image --region "$aws_region" --image-id "$capture_image_id" >/dev/null
+step "deregister capture image" aws ec2 deregister-image --region "$aws_region" --image-id "$capture_image_id" >/dev/null
 
 jq -n \
   --arg architecture "$architecture" \
@@ -324,7 +354,7 @@ jq -n \
   }' > artifact.json
 
 if [ "$keep_builder" = false ]; then
-  tofu destroy \
+  step "tofu destroy builder resources" tofu destroy \
     -auto-approve \
     "${common_tofu_vars[@]}" \
     "${extra_tofu_args[@]}"
@@ -332,3 +362,4 @@ fi
 
 echo "Published AMI: $image_id"
 echo "Published SSM parameter: ${ssm_ami_prefix}/recommended"
+log "total elapsed: $(total_elapsed)"