Skip to content

fix: redact home paths in profile runner logs #262

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
chen2021673 wants to merge 1 commit into
base: master
Choose a base branch
from
Open

fix: redact home paths in profile runner logs #262

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
87 changes: 56 additions & 31 deletions scripts/run_models_and_profile.bash
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -66,6 +66,19 @@ read_var() {
jq -r --arg k "$key" '.variables[$k] // empty' "$CONFIG_FILE"
}

# GNU sed supports -u; BSD/macOS sed does not. Buffering is acceptable there
# because callers wait for the filter process to exit before reading logs.
if sed --help 2>&1 | grep -q -- --unbuffered; then
REDACT_SED_BUFFER=(-u)
else
REDACT_SED_BUFFER=()
fi

redact_log_paths() {
sed -E "${REDACT_SED_BUFFER[@]}" \
"s@/(home|Users)/[^/[:space:]\"']+@<home>@g; s@~/@<home>/@g; s@/root([^[:alnum:]_-])@<home>\\1@g; s@/root\$@<home>@g" "$@"
}

BUILD_DIR="$(read_var BUILD_DIR)"; : "${BUILD_DIR:=../build}"
LOG_DIR="$(read_var LOG_DIR)"; : "${LOG_DIR:=logs}"
PROFILE_LOG_DIR="$(read_var PROFILE_LOG_DIR)"; : "${PROFILE_LOG_DIR:=./profile_logs}"
Expand Down Expand Up @@ -125,13 +138,13 @@ RUN_METADATA_FILE="$(realpath "$RUN_METADATA_FILE")"
echo "[GIT_BRANCH] $GIT_BRANCH"
echo "[GIT_COMMIT] $GIT_COMMIT_FULL"
echo "[GIT_COMMIT_SHORT] $GIT_COMMIT_SHORT"
echo "[CONFIG_FILE] $CONFIG_FILE"
echo "[LOG_DIR] $(realpath "$LOG_DIR")"
echo "[PROFILE_LOG_DIR] $(realpath "$PROFILE_LOG_DIR")"
echo "[CONFIG_FILE] $(basename -- "$CONFIG_FILE")"
echo "[LOG_DIR] logs"
echo "[PROFILE_LOG_DIR] profile_logs"
} > "$RUN_METADATA_FILE"
echo -e "\033[1;33mRun metadata:\033[0m $RUN_METADATA_FILE"
echo -e "\033[1;33mRun log dir:\033[0m $(realpath "$LOG_DIR")"
echo -e "\033[1;33mRun profile log dir:\033[0m $(realpath "$PROFILE_LOG_DIR")"
echo -e "\033[1;33mRun metadata:\033[0m $RUN_METADATA_FILE" | redact_log_paths
echo -e "\033[1;33mRun log dir:\033[0m $LOG_DIR" | redact_log_paths
echo -e "\033[1;33mRun profile log dir:\033[0m $PROFILE_LOG_DIR" | redact_log_paths

normalize_tag() {
local raw="$1"
Expand Down Expand Up @@ -181,7 +194,7 @@ fi

# Clean the build directory
clean_build_dir() {
echo -e "\033[1;31m[CLEAN] Removing all contents in: ${BUILD_DIR}\033[0m"
echo -e "\033[1;31m[CLEAN] Removing all contents in: ${BUILD_DIR}\033[0m" | redact_log_paths
mkdir -p "$BUILD_DIR"
rm -rf "${BUILD_DIR:?}/"*
}
Expand All @@ -190,7 +203,7 @@ clean_build_dir() {
clean_checkpoints() {
echo -e "\033[1;31m[CLEAN] Removing checkpoint directories from previous run\033[0m"
if [[ -d "$CKPT_ROOT_DIR" ]]; then
echo -e "\033[1;31m[CLEAN] Removing: ${CKPT_ROOT_DIR}\033[0m"
echo -e "\033[1;31m[CLEAN] Removing: ${CKPT_ROOT_DIR}\033[0m" | redact_log_paths
rm -rf "${CKPT_ROOT_DIR:?}"
fi
}
Expand Down Expand Up @@ -274,23 +287,24 @@ run_and_log() {
local tag_log_dir="${LOG_DIR}/${tag}"
mkdir -p "$tag_log_dir"
local log_path="$(realpath "${tag_log_dir}/${log_name}.log")"
local metadata_log_path="../run_metadata.log"

echo -e "\033[1;32m============================================================\033[0m"
echo -e "\033[1;36m[$timestamp] [Running] ${log_name}\033[0m"

# Print the command being executed
echo -e "\033[1;33mCommand:\033[0m $cmd"
echo -e "\033[1;33mCommand:\033[0m $cmd" | redact_log_paths

# Print the most recent CMake command
if [[ -n "$LAST_CMAKE_CMD" ]]; then
echo -e "\033[1;34mLast CMake Command:\033[0m $LAST_CMAKE_CMD"
echo -e "\033[1;34mLast CMake Command:\033[0m $LAST_CMAKE_CMD" | redact_log_paths
fi

echo -e "\033[1;33mLog file:\033[0m $log_path"
echo -e "\033[1;33mLog file:\033[0m $log_path" | redact_log_paths

# Notify if profiling mode is enabled
if [[ "$is_profile" == "yes" ]]; then
echo -e "\033[1;35m[PROFILE MODE ON] Profiling logs will be saved to: ${PROFILE_LOG_DIR}\033[0m"
echo -e "\033[1;35m[PROFILE MODE ON] Profiling logs will be saved to: ${PROFILE_LOG_DIR}\033[0m" | redact_log_paths
fi

echo -e "\033[1;32m============================================================\033[0m"
Expand All @@ -299,26 +313,37 @@ run_and_log() {

# Write the last cmake command into the log file if available
if [[ -n "$LAST_CMAKE_CMD" ]]; then
echo "[LAST_CMAKE] $LAST_CMAKE_CMD" > "$log_path"
echo "[LAST_CMAKE] $LAST_CMAKE_CMD" | redact_log_paths > "$log_path"
else
# If no cmake command has been run yet, clear the log
> "$log_path"
fi

# Write the current run command to the log
echo "[RUN_METADATA] $RUN_METADATA_FILE" >> "$log_path"
echo "[RUN_METADATA] $metadata_log_path" >> "$log_path"
echo "[RUN_STARTED_AT] $RUN_STARTED_AT" >> "$log_path"
echo "[GIT_BRANCH] $GIT_BRANCH" >> "$log_path"
echo "[GIT_COMMIT] $GIT_COMMIT_FULL" >> "$log_path"
echo "[GIT_COMMIT_SHORT] $GIT_COMMIT_SHORT" >> "$log_path"
local expanded_cmd="${cmd//\$LORA_WEIGHTS_DIR/$LORA_WEIGHTS_DIR}"
echo "[COMMAND] $expanded_cmd" >> "$log_path"

# Run the command and append both stdout and stderr to the log file
if ! eval "$cmd" >> "$log_path" 2>&1; then
echo "[COMMAND] $expanded_cmd" | redact_log_paths >> "$log_path"

# Filter output before writing it, including logs from interrupted commands.
# Keep eval in this shell and wait for the filter to flush before reading logs.
local log_output_fd log_filter_pid exit_code=0
exec {log_output_fd}> >(redact_log_paths >> "$log_path")
log_filter_pid=$!
if eval "$cmd" >&"$log_output_fd" 2>&1; then
exit_code=0
else
exit_code=$?
fi
exec {log_output_fd}>&-
wait "$log_filter_pid"
if [[ "$exit_code" -ne 0 ]]; then
echo -e "\033[1;31m============================================================\033[0m"
echo -e "\033[1;31m[ERROR] Command failed: ${cmd}\033[0m"
echo -e "\033[1;31m[ERROR] See log file for details: ${log_path}\033[0m"
echo -e "\033[1;31m[ERROR] Command failed: ${cmd}\033[0m" | redact_log_paths
echo -e "\033[1;31m[ERROR] See log file for details: ${log_path}\033[0m" | redact_log_paths
echo -e "\033[1;31m============================================================\033[0m"
echo ""
echo "[ERROR] Last 20 lines of log:"
Expand Down Expand Up @@ -348,7 +373,7 @@ move_profile_logs() {
local base_name
base_name=$(basename "$report_file")
mv "$report_file" "${tag_profile_dir}/${prefix}_${base_name}"
echo "Moved $base_name to ${tag_profile_dir}/${prefix}_${base_name}"
echo "Moved $base_name to ${tag_profile_dir}/${prefix}_${base_name}" | redact_log_paths
fi
done

Expand All @@ -358,7 +383,7 @@ move_profile_logs() {
local base_name
base_name=$(basename "$record_file")
mv "$record_file" "${tag_profile_dir}/${prefix}_${base_name}"
echo "Moved $base_name to ${tag_profile_dir}/${prefix}_${base_name}"
echo "Moved $base_name to ${tag_profile_dir}/${prefix}_${base_name}" | redact_log_paths
fi
done
}
Expand Down Expand Up @@ -432,11 +457,11 @@ model_has_selected_group() {
check_model_inputs() {
if model_has_selected_group "$MIXTRAL_TEST_GROUPS"; then
if [[ ! -f "$MIXTRAL_INPUT_BIN" ]]; then
echo "Error: missing MIXTRAL_INPUT_BIN: $MIXTRAL_INPUT_BIN" >&2
echo "Error: missing MIXTRAL_INPUT_BIN: $MIXTRAL_INPUT_BIN" | redact_log_paths >&2
exit 1
fi
if [[ ! -f "$MIXTRAL_LLMC_FILEPATH" ]]; then
echo "Error: missing MIXTRAL_LLMC_FILEPATH: $MIXTRAL_LLMC_FILEPATH" >&2
echo "Error: missing MIXTRAL_LLMC_FILEPATH: $MIXTRAL_LLMC_FILEPATH" | redact_log_paths >&2
exit 1
fi
fi
Expand Down Expand Up @@ -582,32 +607,32 @@ if [[ -n "$COMPARE_LOG_DIR" ]]; then
SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"

echo -e "\n\033[1;36m============================================================\033[0m"
echo -e "\033[1;36m[Comparison] Comparing logs with: ${COMPARE_LOG_DIR}\033[0m"
echo -e "\033[1;36m[Comparison] Comparing logs with: ${COMPARE_LOG_DIR}\033[0m" | redact_log_paths
echo -e "\033[1;36m============================================================\033[0m"

# Run compare_loss.py
echo -e "\n\033[1;33m[Running] compare_loss.py\033[0m"
python3 "${SCRIPT_DIR}/compare_loss.py" "$COMPARE_LOG_DIR" "$LOG_DIR" || true
python3 "${SCRIPT_DIR}/compare_loss.py" "$COMPARE_LOG_DIR" "$LOG_DIR" 2>&1 | redact_log_paths || true

# Run compare_tps.py
echo -e "\n\033[1;33m[Running] compare_tps.py\033[0m"
python3 "${SCRIPT_DIR}/compare_tps.py" "$COMPARE_LOG_DIR" "$LOG_DIR" || true
python3 "${SCRIPT_DIR}/compare_tps.py" "$COMPARE_LOG_DIR" "$LOG_DIR" 2>&1 | redact_log_paths || true

echo -e "\n\033[1;32mComparison completed.\033[0m"
else
echo -e "\n\033[1;33m============================================================\033[0m"
echo -e "\033[1;33m[WARNING] COMPARE_LOG_DIR is not set. Skipping comparison.\033[0m"
echo -e "\033[1;33m To enable comparison, set 'variables.COMPARE_LOG_DIR' in ${CONFIG_FILE}\033[0m"
echo -e "\033[1;33m To enable comparison, set 'variables.COMPARE_LOG_DIR' in $(basename -- "$CONFIG_FILE")\033[0m"
echo -e "\033[1;33m or export COMPARE_LOG_DIR=/path/to/baseline_logs before running.\033[0m"
echo -e "\033[1;33m============================================================\033[0m"

echo -e "\n\033[1;33mRun comparison manually:\033[0m"
echo "python3 compare_loss.py \"/path/to/baseline_logs\" \"$(realpath "$LOG_DIR")\""
echo "python3 compare_tps.py \"/path/to/baseline_logs\" \"$(realpath "$LOG_DIR")\""
echo "python3 compare_loss.py \"/path/to/baseline_logs\" \"$LOG_DIR\"" | redact_log_paths
echo "python3 compare_tps.py \"/path/to/baseline_logs\" \"$LOG_DIR\"" | redact_log_paths
fi

echo -e "\n\033[1;36m[END OF TEST] Cleaning build directory after all tests\033[0m"
clean_build_dir

echo -e "\n\033[1;33mNext step:\033[0m"
echo "python3 write_to_feishu_sheet.py token.json --log-dir \"$(realpath "$RUN_OUTPUT_DIR")\""
echo "python3 write_to_feishu_sheet.py token.json --log-dir \"$RUN_OUTPUT_DIR\"" | redact_log_paths
Loading