Add debug logging to diagnose empty log output #6
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| name: Worker Build Logs | |
| on: | |
| push: | |
| branches: ["**"] | |
| jobs: | |
| build-logs: | |
| name: Cloudflare Worker Build | |
| runs-on: ubuntu-latest | |
| steps: | |
| - name: Stream Worker Build Logs | |
| env: | |
| CF_API_TOKEN: ${{ secrets.CF_BUILDS_API_TOKEN }} | |
| CF_ACCOUNT_ID: ${{ secrets.CF_ACCOUNT_ID }} | |
| CF_WORKER_TAG: ${{ secrets.CF_WORKER_TAG }} | |
| COMMIT_SHA: ${{ github.sha }} | |
| run: | | |
| set -euo pipefail | |
| API_BASE="https://api.cloudflare.com/client/v4/accounts/${CF_ACCOUNT_ID}" | |
| AUTH_HEADER="Authorization: Bearer ${CF_API_TOKEN}" | |
| MAX_WAIT=300 # Max seconds to wait for a build to appear | |
| POLL_INTERVAL=10 # Seconds between polls | |
| LOG_INTERVAL=5 # Seconds between log fetches | |
| # ── Step 1: Wait for a build matching this commit ── | |
| echo "Waiting for Worker Build matching commit ${COMMIT_SHA:0:7}..." | |
| elapsed=0 | |
| build_uuid="" | |
| while [ -z "$build_uuid" ]; do | |
| if [ "$elapsed" -ge "$MAX_WAIT" ]; then | |
| echo "::error::Timed out after ${MAX_WAIT}s waiting for a Worker Build to start for commit ${COMMIT_SHA:0:7}." | |
| echo "" | |
| echo "This usually means Worker Builds did not trigger for this push. Check that:" | |
| echo " 1. 'Builds for non-production branches' is enabled in your Worker's" | |
| echo " Settings > Build > Branch control (if this is not the production branch)" | |
| echo " 2. The branch is not excluded by branch include/exclude filters" | |
| echo " 3. Build watch paths (if configured) match the changed files" | |
| echo " 4. The CF_WORKER_TAG secret matches the correct Worker" | |
| exit 1 | |
| fi | |
| # List recent builds for this worker | |
| response=$(curl -sf \ | |
| "${API_BASE}/builds/workers/${CF_WORKER_TAG}/builds" \ | |
| -H "$AUTH_HEADER" \ | |
| ) || { | |
| echo "::warning::Failed to fetch builds list, retrying in ${POLL_INTERVAL}s..." | |
| sleep "$POLL_INTERVAL" | |
| elapsed=$((elapsed + POLL_INTERVAL)) | |
| continue | |
| } | |
| # Find a build matching our commit SHA | |
| build_uuid=$(echo "$response" | jq -r \ | |
| --arg sha "$COMMIT_SHA" \ | |
| '.result[] | select(.build_trigger_metadata.commit_hash == $sha) | .build_uuid' \ | |
| | head -n1 | |
| ) | |
| if [ -z "$build_uuid" ] || [ "$build_uuid" = "null" ]; then | |
| build_uuid="" | |
| echo " No build found yet... (${elapsed}s elapsed)" | |
| sleep "$POLL_INTERVAL" | |
| elapsed=$((elapsed + POLL_INTERVAL)) | |
| fi | |
| done | |
| echo "Found build: ${build_uuid}" | |
| echo "" | |
| # ── Helper: fetch and print new log lines ── | |
| last_line_count=0 | |
| print_new_logs() { | |
| local json="$1" | |
| echo "[DEBUG] print_new_logs called, json length: ${#json}" | |
| if [ -z "$json" ]; then | |
| echo "[DEBUG] json is empty, returning" | |
| return | |
| fi | |
| # Check if .lines exists | |
| has_lines=$(echo "$json" | jq 'has("lines")' 2>/dev/null || echo "false") | |
| echo "[DEBUG] has .lines key: $has_lines" | |
| # Check top-level keys | |
| echo "[DEBUG] top-level keys: $(echo "$json" | jq -r 'keys | join(", ")' 2>/dev/null || echo "PARSE ERROR")" | |
| total_lines=$(echo "$json" | jq '.lines | length' 2>/dev/null || echo "0") | |
| echo "[DEBUG] total_lines=$total_lines last_line_count=$last_line_count" | |
| if [ "$total_lines" -gt "$last_line_count" ]; then | |
| echo "[DEBUG] printing lines from $last_line_count to $total_lines" | |
| # Print first line raw for debugging | |
| echo "[DEBUG] first new line raw: $(echo "$json" | jq --argjson skip "$last_line_count" '.lines[$skip:][0]' 2>/dev/null)" | |
| echo "$json" | jq -r \ | |
| --argjson skip "$last_line_count" \ | |
| '.lines[$skip:][] | .[1]' | |
| jq_exit=$? | |
| echo "[DEBUG] jq exit code: $jq_exit" | |
| last_line_count=$total_lines | |
| else | |
| echo "[DEBUG] no new lines to print" | |
| fi | |
| } | |
| print_build_phases() { | |
| local json="$1" | |
| if [ -z "$json" ]; then return; fi | |
| events_count=$(echo "$json" | jq '.events | length' 2>/dev/null || echo "0") | |
| if [ "$events_count" -gt 0 ]; then | |
| echo "" | |
| echo "── Build Phases ──" | |
| echo "$json" | jq -r ' | |
| .events[] | | |
| .type as $type | | |
| (.started_on // null) as $start | | |
| (.ended_on // null) as $end | | |
| if $start != null and $end != null then | |
| (($end | sub("\\.[0-9]+Z$"; "Z") | fromdateiso8601) - | |
| ($start | sub("\\.[0-9]+Z$"; "Z") | fromdateiso8601)) as $dur | | |
| " \($type): \($dur)s" | |
| elif $start != null then | |
| " \($type): (no end time)" | |
| else | |
| " \($type)" | |
| end | |
| ' | |
| fi | |
| } | |
| # ── Step 2: Stream logs until the build completes ── | |
| while true; do | |
| # Fetch build status | |
| build_response=$(curl -sf \ | |
| "${API_BASE}/builds/workers/${CF_WORKER_TAG}/builds" \ | |
| -H "$AUTH_HEADER" \ | |
| ) || { | |
| echo "::warning::Failed to fetch build status, retrying..." | |
| sleep "$LOG_INTERVAL" | |
| continue | |
| } | |
| build_data=$(echo "$build_response" | jq -r \ | |
| --arg uuid "$build_uuid" \ | |
| '.result[] | select(.build_uuid == $uuid)') | |
| status=$(echo "$build_data" | jq -r '.status') | |
| outcome=$(echo "$build_data" | jq -r '.build_outcome // empty') | |
| # Fetch and print new log lines | |
| echo "[DEBUG] Fetching logs for build ${build_uuid}..." | |
| logs_json=$(curl -s \ | |
| "${API_BASE}/builds/builds/${build_uuid}/logs" \ | |
| -H "$AUTH_HEADER" \ | |
| ) 2>/dev/null || logs_json="" | |
| logs_curl_exit=$? | |
| echo "[DEBUG] logs curl exit code: $logs_curl_exit, response length: ${#logs_json}" | |
| echo "[DEBUG] logs first 500 chars: ${logs_json:0:500}" | |
| print_new_logs "$logs_json" | |
| # When a build finishes, status becomes "stopped" and the | |
| # result is in build_outcome (success, fail, skipped, cancelled, terminated). | |
| if [ "$status" = "stopped" ]; then | |
| echo "[DEBUG] Build is stopped, outcome=$outcome" | |
| # Do a final log fetch to make sure we got everything | |
| sleep 2 | |
| echo "[DEBUG] Doing final log fetch..." | |
| final_logs=$(curl -s \ | |
| "${API_BASE}/builds/builds/${build_uuid}/logs" \ | |
| -H "$AUTH_HEADER" \ | |
| ) 2>/dev/null || final_logs="" | |
| echo "[DEBUG] final_logs length: ${#final_logs}" | |
| echo "[DEBUG] final_logs first 500 chars: ${final_logs:0:500}" | |
| if [ -n "$final_logs" ]; then | |
| print_new_logs "$final_logs" | |
| print_build_phases "$final_logs" | |
| else | |
| echo "[DEBUG] final_logs is empty!" | |
| fi | |
| echo "" | |
| case "$outcome" in | |
| success) | |
| echo "Build completed successfully." | |
| exit 0 | |
| ;; | |
| fail) | |
| echo "::error::Build failed." | |
| exit 1 | |
| ;; | |
| cancelled) | |
| echo "::warning::Build was cancelled." | |
| exit 1 | |
| ;; | |
| skipped) | |
| echo "Build was skipped." | |
| exit 0 | |
| ;; | |
| terminated) | |
| echo "::error::Build was terminated." | |
| exit 1 | |
| ;; | |
| *) | |
| echo "::error::Build stopped with unknown outcome: ${outcome}" | |
| exit 1 | |
| ;; | |
| esac | |
| fi | |
| sleep "$LOG_INTERVAL" | |
| done |