diff --git a/docs/DEVELOPMENT.md b/docs/DEVELOPMENT.md index a6eb90d..3a7a024 100644 --- a/docs/DEVELOPMENT.md +++ b/docs/DEVELOPMENT.md @@ -14,6 +14,9 @@ ptc-cli-bash/ │ ├── test-runner.sh # Main test runner (CLI invocation tests) │ ├── test-status-handling.sh # Status parsing, polling and preflight │ ├── test-init.sh # `ptc init` detect_config scaffolder +│ ├── test-exit-codes.sh # Exit codes the CLI reports to CI +│ ├── test-error-shapes.sh # Both shapes of a rejected API response +│ ├── test-rate-limit.sh # 429 backoff and failure descriptions │ └── fixtures/ # Test data (created automatically) └── docs/ # Documentation └── DEVELOPMENT.md # This guide @@ -55,10 +58,16 @@ chmod +x tests/test-status-handling.sh ### Running Tests ```bash -# Run all tests +# Run all tests — each file is its own suite, none of them runs the others +for suite in tests/test-*.sh; do echo "== $suite"; bash "$suite" || break; done + +# Or one at a time ./tests/test-runner.sh ./tests/test-status-handling.sh ./tests/test-init.sh +./tests/test-exit-codes.sh +./tests/test-error-shapes.sh +./tests/test-rate-limit.sh # Test specific functionality ./ptc-cli.sh -s en -p '{lang}-copy.json' --dry-run --verbose diff --git a/ptc-cli.sh b/ptc-cli.sh index 33beb31..52a295d 100755 --- a/ptc-cli.sh +++ b/ptc-cli.sh @@ -66,7 +66,82 @@ log_debug() { # User-Agent (ptc-cli/). It forwards to the real curl - which the test # suites stub - so the header rides along as an ordinary -H the stubs already skip. ptc_curl() { - curl -H "User-Agent: $PTC_USER_AGENT" "$@" + # PTC_HEADER_DUMP lets a caller read response headers without every call + # site having to thread a -D through its own curl invocation. Only the + # rate-limit retry sets it; everything else runs exactly as before. + if [[ -n "${PTC_HEADER_DUMP:-}" ]]; then + curl -H "User-Agent: $PTC_USER_AGENT" -D "$PTC_HEADER_DUMP" "$@" + else + curl -H "User-Agent: $PTC_USER_AGENT" "$@" + fi +} + +# --- rate limiting ----------------------------------------------------------- +# create + process + bulk share ONE bucket of PTC_RATE_LIMIT_HINT requests per +# minute, and a run spends two of them per file, so any project past a handful +# of files meets a 429 partway through. Failing there is the worst outcome +# available: the files uploaded before it are already registered and the words +# may already be paid for, so the run must wait rather than abort. +readonly PTC_RATE_LIMIT_MAX_RETRIES=5 +readonly PTC_RATE_LIMIT_BASE_DELAY=15 +readonly PTC_RATE_LIMIT_MAX_DELAY=60 +# Internal signal between a request function and the retry wrapper. It never +# reaches the shell: the wrapper turns it into 0 (recovered) or 1 (gave up). +readonly PTC_RATE_LIMITED=8 + +# Seconds to wait before attempt N. Honours Retry-After when the server sends +# one; PTC does not today (checked 2026-08-04), so the fallback walks towards +# the one-minute window the limit is measured over. +rate_limit_delay() { + local attempt="$1" header_file="${2:-}" + local retry_after="" + + if [[ -n "$header_file" && -f "$header_file" ]]; then + retry_after=$(grep -i '^retry-after:' "$header_file" 2>/dev/null \ + | tail -n 1 | tr -d '\r' \ + | sed -E 's/^[Rr]etry-[Aa]fter:[[:space:]]*//') + fi + + if [[ "$retry_after" =~ ^[0-9]+$ ]] && (( retry_after > 0 )); then + (( retry_after > 300 )) && retry_after=300 # a bad header must not hang the job + printf '%s' "$retry_after" + return 0 + fi + + local delay=$(( PTC_RATE_LIMIT_BASE_DELAY * attempt )) + (( delay > PTC_RATE_LIMIT_MAX_DELAY )) && delay=$PTC_RATE_LIMIT_MAX_DELAY + printf '%s' "$delay" +} + +# Runs a request function, waiting out HTTP 429 instead of failing on it. +# The function must return PTC_RATE_LIMITED to ask for a retry; any other exit +# status is passed straight through, so non-429 failures still fail fast. +call_with_rate_limit_retry() { + local attempt=1 delay rc header_dump="" + + header_dump=$(mktemp "${TMPDIR:-/tmp}/ptc-headers.XXXXXX" 2>/dev/null) || header_dump="" + + while :; do + PTC_HEADER_DUMP="$header_dump" "$@" + rc=$? + + if (( rc != PTC_RATE_LIMITED )); then + [[ -n "$header_dump" ]] && rm -f "$header_dump" + return $rc + fi + + if (( attempt > PTC_RATE_LIMIT_MAX_RETRIES )); then + [[ -n "$header_dump" ]] && rm -f "$header_dump" + log_error "PTC is still rate limiting after $PTC_RATE_LIMIT_MAX_RETRIES retries; giving up." + log_info "The limit is per organization, so another job or a teammate may be sending requests too." + return 1 + fi + + delay=$(rate_limit_delay "$attempt" "$header_dump") + log_warning "PTC rate limit reached (HTTP 429). Waiting ${delay}s, then retry ${attempt} of ${PTC_RATE_LIMIT_MAX_RETRIES}." + sleep "$delay" + attempt=$(( attempt + 1 )) + done } # JSON field readers. The API returns compact JSON today, but these tolerate @@ -154,15 +229,26 @@ response_indicates_failure() { # than dropping it. describe_api_failure() { local http_code="$1" body="${2:-}" - local message codes + local message error codes message=$(json_string_field "$body" "message") + # Several endpoints answer with a plain {"error": "..."} instead of the + # {"message", "errors"} envelope - source_files#create and #process among + # them. Reading only "message" turned those into a bare "HTTP 422" in the + # CI log, which is the one place the reason was needed. + error=$(json_string_field "$body" "error") codes=$(printf '%s' "$body" | tr '\n' ' ' \ | grep -Eo '"errors"[[:space:]]*:[[:space:]]*\[[^]]*\]' \ | head -n 1 | sed -E 's/^"errors"[[:space:]]*:[[:space:]]*//') || true local description="HTTP $http_code" - [[ -n "$message" ]] && description="$description: $message" + if [[ -n "$message" ]]; then + description="$description: $message" + # Both keys present and different: keep each, they say different things. + [[ -n "$error" && "$error" != "$message" ]] && description="$description ($error)" + elif [[ -n "$error" ]]; then + description="$description: $error" + fi [[ -n "$codes" ]] && description="$description (error codes: $codes)" printf '%s' "$description" } @@ -870,7 +956,7 @@ perform_upload_action() { additional_files_json=$(extract_additional_files "$PTC_CONFIG_FILE" "$relative_file_path") fi - if make_ptc_api_call "$file" "$relative_file_path" "$output_file_path" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then + if call_with_rate_limit_retry make_ptc_api_call "$file" "$relative_file_path" "$output_file_path" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then uploaded_files+=("$file") log_success "Upload completed: $relative_file_path" else @@ -929,7 +1015,7 @@ perform_upload_action_with_config() { local additional_files_json="" additional_files_json=$(extract_additional_files "$PTC_CONFIG_FILE" "$relative_file_path") - if make_ptc_api_call "$file" "$relative_file_path" "$output_pattern" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then + if call_with_rate_limit_retry make_ptc_api_call "$file" "$relative_file_path" "$output_pattern" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then uploaded_files+=("$file") log_success "Upload completed: $relative_file_path" else @@ -1107,7 +1193,7 @@ process_files_in_steps() { additional_files_json=$(extract_additional_files "$PTC_CONFIG_FILE" "$relative_file_path") fi - if make_ptc_api_call "$file" "$relative_file_path" "$output_file_path" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then + if call_with_rate_limit_retry make_ptc_api_call "$file" "$relative_file_path" "$output_file_path" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then uploaded_files+=("$file") log_success "Upload completed: $relative_file_path" else @@ -1134,7 +1220,7 @@ process_files_in_steps() { else log_info "Starting processing: $relative_file_path" - if start_processing "$file" "$relative_file_path" "$PTC_FILE_TAG_NAME"; then + if call_with_rate_limit_retry start_processing "$file" "$relative_file_path" "$PTC_FILE_TAG_NAME"; then processed_files+=("$file") log_success "Processing started: $relative_file_path" else @@ -1351,7 +1437,7 @@ process_files_in_steps_with_config() { local additional_files_json="" additional_files_json=$(extract_additional_files "$PTC_CONFIG_FILE" "$relative_file_path") - if make_ptc_api_call "$file" "$relative_file_path" "$output_pattern" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then + if call_with_rate_limit_retry make_ptc_api_call "$file" "$relative_file_path" "$output_pattern" "$PTC_FILE_TAG_NAME" "$additional_files_json"; then uploaded_files+=("$file") log_success "Upload completed: $relative_file_path" else @@ -1378,7 +1464,7 @@ process_files_in_steps_with_config() { else log_info "Starting processing: $relative_file_path" - if start_processing "$file" "$relative_file_path" "$PTC_FILE_TAG_NAME"; then + if call_with_rate_limit_retry start_processing "$file" "$relative_file_path" "$PTC_FILE_TAG_NAME"; then processed_files+=("$file") log_success "Processing started: $relative_file_path" else @@ -1834,6 +1920,12 @@ EOF local http_code="${response: -3}" local response_body="${response%???}" + # Ask the caller to wait and try again rather than reporting a failed + # upload: nothing was uploaded, so this file is still worth retrying. + if [[ "$http_code" == "429" ]]; then + return $PTC_RATE_LIMITED + fi + # A 201 that still carries "success": false is a rejected upload dressed as # a created one - the content-validation path answers that way (ci18-7342). if [[ "$http_code" == "201" ]] && ! response_indicates_failure "$http_code" "$response_body"; then @@ -1897,6 +1989,12 @@ start_processing() { local http_code="${response: -3}" local response_body="${response%???}" + # Same bucket as the upload above, so the same treatment: the file is + # uploaded but not yet processing, and only a retry can finish the job. + if [[ "$http_code" == "429" ]]; then + return $PTC_RATE_LIMITED + fi + if response_indicates_failure "$http_code" "$response_body"; then log_error "Failed to start file processing: $relative_file_path ($(describe_api_failure "$http_code" "$response_body"))" log_debug "Process API response: $response_body" diff --git a/tests/test-rate-limit.sh b/tests/test-rate-limit.sh new file mode 100755 index 0000000..c2ccb86 --- /dev/null +++ b/tests/test-rate-limit.sh @@ -0,0 +1,206 @@ +#!/bin/bash + +# Tests for the 429 handling. +# +# create + process + bulk share one bucket of 10 requests per minute, and a run +# spends two of them per file. Every project past five files therefore meets a +# 429 partway through, and before this the CLI reported it as a failed upload +# and moved on: the run ended green-ish, with some files registered, some not, +# and "HTTP 429" as the only clue in the log. +# +# The regressions guarded here: not retrying at all, retrying forever, treating +# a non-429 failure as retryable, and losing the reason text on the {"error"} +# response shape that source_files#create and #process actually use. + +set -uo pipefail + +readonly TEST_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +readonly CLI_UNDER_TEST="$(dirname "$TEST_DIR")/ptc-cli.sh" + +# shellcheck disable=SC1090 +source "$CLI_UNDER_TEST" # main() is guarded by a BASH_SOURCE check + +set +e + +test_count=0 +passed_count=0 +failed_count=0 + +pass() { echo -e "${GREEN}[PASS]${NC} $*"; passed_count=$((passed_count + 1)); test_count=$((test_count + 1)); } +fail() { echo -e "${RED}[FAIL]${NC} $*"; failed_count=$((failed_count + 1)); test_count=$((test_count + 1)); } + +assert_eq() { + local desc="$1" got="$2" want="$3" + if [[ "$got" == "$want" ]]; then + pass "$desc" + else + fail "$desc (got '$got', want '$want')" + fi +} + +assert_contains() { + local desc="$1" haystack="$2" needle="$3" + if [[ "$haystack" == *"$needle"* ]]; then + pass "$desc" + else + fail "$desc (got '$haystack', wanted it to contain '$needle')" + fi +} + +# Never actually wait: record what the retry asked for instead. A test that +# sleeps for real would take minutes and would be the first thing anyone skips. +SLEPT=() +sleep() { SLEPT+=("$1"); } + +header_file_with() { + local file + file=$(mktemp "${TMPDIR:-/tmp}/ptc-test-headers.XXXXXX") + printf '%s\n' "$@" > "$file" + printf '%s' "$file" +} + +echo "=== rate_limit_delay: backoff when the server sends no Retry-After ===" + +assert_eq "attempt 1 waits the base delay" "$(rate_limit_delay 1)" "15" +assert_eq "attempt 2 doubles it" "$(rate_limit_delay 2)" "30" +assert_eq "attempt 3 keeps climbing" "$(rate_limit_delay 3)" "45" +assert_eq "attempt 4 reaches the window length" "$(rate_limit_delay 4)" "60" +assert_eq "attempt 9 is capped at the window" "$(rate_limit_delay 9)" "60" + +echo +echo "=== rate_limit_delay: honouring Retry-After ===" + +hf=$(header_file_with 'HTTP/1.1 429 Too Many Requests' 'Retry-After: 7') +assert_eq "a Retry-After header wins over the backoff" "$(rate_limit_delay 3 "$hf")" "7" +rm -f "$hf" + +hf=$(header_file_with 'HTTP/1.1 429 Too Many Requests' 'retry-after: 12') +assert_eq "the header name is matched case-insensitively" "$(rate_limit_delay 1 "$hf")" "12" +rm -f "$hf" + +# Servers behind a proxy emit CRLF; a stray \r turns the value into a +# non-number and would silently drop us back to the backoff. +crlf=$(mktemp "${TMPDIR:-/tmp}/ptc-crlf.XXXXXX") +printf 'HTTP/1.1 429\r\nRetry-After: 9\r\n' > "$crlf" +assert_eq "CRLF line endings do not break the value" "$(rate_limit_delay 2 "$crlf")" "9" +rm -f "$crlf" + +hf=$(header_file_with 'Retry-After: Wed, 21 Oct 2026 07:28:00 GMT') +assert_eq "an HTTP-date Retry-After falls back to the backoff" "$(rate_limit_delay 2 "$hf")" "30" +rm -f "$hf" + +hf=$(header_file_with 'Retry-After: 0') +assert_eq "a zero Retry-After falls back to the backoff" "$(rate_limit_delay 1 "$hf")" "15" +rm -f "$hf" + +hf=$(header_file_with 'Retry-After: 99999') +assert_eq "an absurd Retry-After is capped, not obeyed" "$(rate_limit_delay 1 "$hf")" "300" +rm -f "$hf" + +assert_eq "a missing header file is not an error" "$(rate_limit_delay 2 /nonexistent/headers)" "30" + +echo +echo "=== call_with_rate_limit_retry ===" + +CALLS=0 +succeeds_immediately() { CALLS=$((CALLS + 1)); return 0; } +call_with_rate_limit_retry succeeds_immediately +assert_eq "a request that works is called once" "$CALLS" "1" +assert_eq "and nothing was waited on" "${#SLEPT[@]}" "0" + +CALLS=0 +SLEPT=() +rate_limited_twice() { + CALLS=$((CALLS + 1)) + (( CALLS <= 2 )) && return "$PTC_RATE_LIMITED" + return 0 +} +call_with_rate_limit_retry rate_limited_twice +rc=$? +assert_eq "a 429 twice then success exits 0" "$rc" "0" +assert_eq "which took three calls" "$CALLS" "3" +assert_eq "and waited twice" "${#SLEPT[@]}" "2" +assert_eq "with a growing delay" "${SLEPT[0]}-${SLEPT[1]}" "15-30" + +CALLS=0 +SLEPT=() +always_rate_limited() { CALLS=$((CALLS + 1)); return "$PTC_RATE_LIMITED"; } +call_with_rate_limit_retry always_rate_limited >/dev/null 2>&1 +rc=$? +assert_eq "a permanent 429 eventually gives up with 1" "$rc" "1" +assert_eq "after the configured number of retries" "$CALLS" "$((PTC_RATE_LIMIT_MAX_RETRIES + 1))" +assert_eq "never returning the internal signal to the shell" "$([[ $rc -ne $PTC_RATE_LIMITED ]] && echo ok)" "ok" + +CALLS=0 +SLEPT=() +fails_for_another_reason() { CALLS=$((CALLS + 1)); return 3; } +call_with_rate_limit_retry fails_for_another_reason +rc=$? +assert_eq "a non-429 failure is passed straight through" "$rc" "3" +assert_eq "without retrying it" "$CALLS" "1" +assert_eq "and without waiting" "${#SLEPT[@]}" "0" + +SLEPT=() +sees_header_dump() { [[ -n "${PTC_HEADER_DUMP:-}" ]] && return 0; return 3; } +call_with_rate_limit_retry sees_header_dump +assert_eq "the wrapper exposes a header dump to the request" "$?" "0" + +echo +echo "=== describe_api_failure: the {\"error\"} shape ===" + +assert_contains "a plain {\"error\"} body is reported" \ + "$(describe_api_failure 422 '{"error":"Failed to replace source file"}')" \ + "Failed to replace source file" + +assert_contains "so is the {\"success\":false,\"error\"} variant" \ + "$(describe_api_failure 422 '{"success":false,"error":"Failed to create source file"}')" \ + "Failed to create source file" + +assert_contains "the rate-limit body says why" \ + "$(describe_api_failure 429 '{"error":"Rate limit exceeded"}')" \ + "Rate limit exceeded" + +assert_eq "the envelope shape still reads the same as before" \ + "$(describe_api_failure 422 '{"success":false,"message":"Unprocessable Entity","code":422,"errors":[9001]}')" \ + "HTTP 422: Unprocessable Entity (error codes: [9001])" + +assert_contains "both keys present keeps both" \ + "$(describe_api_failure 402 '{"error":"TRIAL_EXPIRED","message":"Your trial has ended"}')" \ + "Your trial has ended" +assert_contains "including the machine-readable one" \ + "$(describe_api_failure 402 '{"error":"TRIAL_EXPIRED","message":"Your trial has ended"}')" \ + "TRIAL_EXPIRED" + +assert_eq "an empty body still names the status" \ + "$(describe_api_failure 401 '')" \ + "HTTP 401" + +echo +echo "=== make_ptc_api_call / start_processing signal a 429 rather than failing ===" + +work_dir=$(mktemp -d "${TMPDIR:-/tmp}/ptc-rl.XXXXXX") +printf '{"hello":"world"}' > "$work_dir/en.json" +PTC_API_URL="https://example.invalid/api/v1/" +PTC_API_TOKEN="test-token" +PTC_VERBOSE="false" + +ptc_curl() { printf '%s%s' '{"error":"Rate limit exceeded"}' '429'; } +make_ptc_api_call "$work_dir/en.json" "en.json" "{{lang}}.json" "main" "" >/dev/null 2>&1 +assert_eq "an upload that hits 429 asks for a retry" "$?" "$PTC_RATE_LIMITED" + +start_processing "$work_dir/en.json" "en.json" "main" >/dev/null 2>&1 +assert_eq "so does starting processing" "$?" "$PTC_RATE_LIMITED" + +ptc_curl() { printf '%s%s' '{"success":false,"error":"File format is invalid"}' '422'; } +make_ptc_api_call "$work_dir/en.json" "en.json" "{{lang}}.json" "main" "" >/dev/null 2>&1 +assert_eq "a real rejection is still a plain failure" "$?" "1" + +rm -rf "$work_dir" + +echo +echo "==========================================" +echo "Total tests: $test_count" +echo -e "Passed: ${GREEN}${passed_count}${NC}" +echo -e "Failed: ${RED}${failed_count}${NC}" +[[ $failed_count -eq 0 ]] && echo -e "${GREEN}All tests passed successfully!${NC}" +exit $(( failed_count > 0 ? 1 : 0 ))