snapd/tests/lib/tools/journal-state

#!/bin/bash

# This file contains all the cursors used for the different tests
JOURNALCTL_CURSOR_FILE="$TESTSTMP"/runtime-state/journalctl_cursor

show_help() {
    echo "usage: journal-state start-new-log"
    echo "       journal-state check-log-started"
    echo "       journal-state get-last-cursor"
    echo "       journal-state get-test-cursor"
    echo "       journal-state match-log <EXPRESSION> [--attempts|-n PARAM] [--wait PARAM] [--unit|-u PARAM] [-b]"
    echo "       journal-state get-log"
    echo "       journal-state get-log-from-cursor"
}

get_last_cursor(){
    journalctl --output=export -n1 | grep --binary-files=text -o '__CURSOR=.*' | sed -e 's/^__CURSOR=//'
}

start_new_log(){
    _sync_log
    echo "New test starts here - $SPREAD_JOB" | systemd-cat -t snapd-test
    cursor=$(get_last_cursor)
    if [ -z "$cursor" ]; then
        echo "Empty journalctl cursor, exiting..."
        exit 1
    else
        echo "$SPREAD_JOB " >> "$JOURNALCTL_CURSOR_FILE"
        echo "$cursor" >> "$JOURNALCTL_CURSOR_FILE"
    fi
}

get_test_cursor(){
    cursor="$(tail -n 1 "$JOURNALCTL_CURSOR_FILE")"
    if [ -z "$cursor" ]; then
        echo "Cursor for test not found"
        exit 1
    fi
    echo "$cursor"
}

check_log_started(){
    marker="test-${RANDOM}${RANDOM}"
    echo "Running test: $marker" | systemd-cat -t snapd-test
    if match_log "$marker"; then
        return 0
    fi
    echo "Test id not found in journalctl, exiting..."
    exit 1
}

match_log(){
    local wait=1
    local attempts=10
    local params=""
    local expression

    while [ $# -gt 0 ]; do
        case "$1" in
            --wait)
                wait=$2
                shift 2
                ;;
            -n|--attempts)
                attempts=$2
                shift 2
                ;;
            -u|--unit)
                params="$params -u $2"
                shift 2
                ;;
            -b)
                params="$params -b"
                shift
                ;;
            *)
                expression=$1
                shift
                ;;
        esac
    done

    for _ in $(seq "$attempts"); do
        # forcibly silence this particular bit because it produces GOBS of 
        # output and we really don't need to see all the output when we are 
        # checking the output for an expression, as if it is missing we want to 
        # check the journal once at the end of this loop, likely in the debug 
        # section
        set +x
        local log
        if [ -z "$params" ]; then
            log="$(get_log)"
        else
            #shellcheck disable=SC2086
            log="$(get_log $params)"
        fi
        if echo "$log" | grep -q -E "$expression"; then
            return 0
        fi
        set -x
        echo "Match for \"$expression\" failed, retrying"
        sleep "$wait"
    done
    return 1
}

get_log(){
    cursor=""
    if [ -f "$JOURNALCTL_CURSOR_FILE" ]; then
        cursor=$(tail -n1 "$JOURNALCTL_CURSOR_FILE")
    fi
    _sync_log
    get_log_from_cursor "$cursor" "$@"
}

get_log_from_cursor(){
    cursor=$1
    shift
    if [ -z "$cursor" ]; then
        journalctl "$@"
    else
        journalctl "$@" --cursor "$cursor"
    fi
}

_sync_log(){
    journalctl --flush || true
    journalctl --sync || true
}

main() {
    if [ $# -eq 0 ]; then
        show_help
        exit 0
    fi

    subcommand=$1
    action=
    while [ $# -gt 0 ]; do
        case "$1" in
            -h|--help)
                show_help
                exit 0
                ;;
            *)
                action=$(echo "$subcommand" | tr '-' '_')
                shift
                break
                ;;
        esac
    done

    if [ -z "$(declare -f "$action")" ]; then
        echo "journal-state: no such command $subcommand" >&2
        show_help
        exit 1
    fi

    "$action" "$@"
}

main "$@"