--- a/regress/slog.sh +++ b/regress/slog.sh @@ -1,41 +1,60 @@ tid='structured log' -port="4242" log_prefix="sshd_auth_msg:" -log_keys="server_ip server_port remote_ip remote_port pid session_id method cert_id cert_serial principal user session_state auth_successful _time command end_time duration auth_info client_version" +log_keys="server_ip server_port remote_ip remote_port pid session_id method cert_id cert_serial principal user session_state auth_successful command end_time duration auth_info client_version" do_log_json="yes" -test_config="$OBJ/sshd2_config" -old_config="$OBJ/sshd_config" -PIDFILE=$OBJ/pidfile - -cat << EOF > $test_config - #*: - StrictModes no - Port $port - AddressFamily inet - ListenAddress 127.0.0.1 - #ListenAddress ::1 - PidFile $PIDFILE - AuthorizedKeysFile $OBJ/authorized_keys_%u - LogLevel ERROR - AcceptEnv _XXX_TEST_* - AcceptEnv _XXX_TEST - HostKey $OBJ/host.ssh-ed25519 - LogFormatPrefix $log_prefix - LogFormatJson $do_log_json - LogFormatKeys $log_keys + +AUTH_PRINC_FILE="$OBJ/auth_principals" +CA_FILE="$OBJ/ca-rsa" +IDENTITY_FILE="$OBJ/$USER-rsa" +CERT_ID=$USER + +cat << EOF >> $OBJ/sshd_config +TrustedUserCAKeys $CA_FILE.pub +PubkeyAuthentication yes +AuthenticationMethods publickey +AuthorizedPrincipalsFile $AUTH_PRINC_FILE +LogFormatPrefix $log_prefix +LogFormatJson $do_log_json +LogFormatKeys $log_keys EOF +sed -i 's/DEBUG3/VERBOSE/g' $OBJ/sshd_config -cp $test_config $old_config -start_sshd +cleanup() { + rm -f $CA_FILE{.pub,} + rm -f $IDENTITY_FILE{-cert.pub,.pub,} + rm -f $AUTH_PRINC_FILE + rm -f $TEST_SSHD_LOGFILE +} + +make_keys() { + local keytype=$1 + + rm -f $IDENTITY_FILE{.pub,} + ${SSHKEYGEN} -q -t $keytype -C '' -N '' -f $IDENTITY_FILE || + fatal 'Could not create keypair' + + cat $IDENTITY_FILE.pub > authorized_keys_$USER + ${SSHKEYGEN} -lf $IDENTITY_FILE +} -${SSH} -F $OBJ/ssh_config somehost true -if [ $? -ne 0 ]; then - fail "ssh connect with failed" -fi +make_cert() { + local princs=$1 + local certtype=$2 + local serial=$3 -test_log_counts() { + rm -f $CA_FILE + rm -f "$IDENTITY_FILE-cert.pub" + + ${SSHKEYGEN} -q -t $certtype -C '' -N '' -f $CA_FILE || + fatal 'Could not create CA key' + + ${SSHKEYGEN} -q -s $CA_FILE -I $CERT_ID -n "$princs" -z $serial "$IDENTITY_FILE.pub" || + fatal "Could not create SSH cert" +} + +do_test_log_counts() { cnt=$(grep -c "$log_prefix" "$TEST_SSHD_LOGFILE") if [ $cnt -ne 2 ]; then fail "expected 2 structured logging lines, got $cnt" @@ -43,7 +62,10 @@ test_log_counts() { } test_json_valid() { - which python &>/dev/null || echo 'python not found in path, skipping tests' + if ! $(which python &>/dev/null) ; then + echo 'python not found in path, skipping JSON tests' + return 1 + fi loglines=$(cat "$TEST_SSHD_LOGFILE" | grep "$log_prefix") first=$(echo "$loglines" | head -n1) @@ -55,5 +77,72 @@ test_json_valid() { || fail "invalid json structure $last" } -test_log_counts -test_json_valid +# todo: first/last line +extract_key() { + local key=$1 + loglines=$(cat "$TEST_SSHD_LOGFILE" | grep "$log_prefix") + last=$(echo "$loglines" | tail -n1) + json=${last:$(expr length $log_prefix)} + + val=$(echo $json | python -c "import sys, json; print(json.load(sys.stdin)[\"$key\"])") || + fail "error extracting $key from $json" + echo "$val" +} + +test_basic_logging() { + ${SSH} -F $OBJ/ssh_config -v -i "$IDENTITY_FILE" somehost true || + fatal "SSH failed" + + do_test_log_counts + test_json_valid || return 1 +} + +extract_hash() { + local source=$1 + echo $source | sed "s/.*\(SHA256:[[:print:]]\{43\}\).*$/\1/" +} + +test_auth_info() { + local keyfp=$1 + local keytype=$2 + local princ=$3 + local serial=$4 + + ${SSH} -F $OBJ/ssh_config -v -i "$IDENTITY_FILE" somehost true || + fatal "SSH failed" + + auth_info=$(extract_key 'auth_info') + digest=$(extract_hash "$keyfp") + + [ -z "$keyfp" ] || echo "$auth_info" | grep -q "$digest" || + echo "hash digest not found" + [ -z "$keytype" ] || echo "$auth_info" | grep -q "$keytype" || + echo "keytype not found" + [ -z "$princ" ] || echo "$auth_info" | grep -q "$princ" || + echo "princ not found" + [ -z "$serial" ] || echo "$auth_info" | grep -q "$serial" || + echo "serial not found" +} + +test_cert_serial() { + local serial=$1 + logged_serial=$(extract_key 'cert_serial') + [ $serial = $logged_serial ] || fail 'cert serial mismatch' +} + +start_sshd + +keytype="RSA" +keyfp=$(make_keys $keytype) +test_basic_logging || return +test_auth_info "$keyfp" "$keytype" + +rm authorized_keys_$USER # force cert auth + +princ="$USER" +echo $princ > $AUTH_PRINC_FILE + +serial='42' +make_cert "$princ" "$keytype" "$serial" +test_auth_info "$keyfp" "$keytype" "$princ" "$serial" +test_cert_serial "$serial" --- a/auth.c +++ b/auth.c @@ -351,6 +351,8 @@ auth_log(struct ssh *ssh, int authentica extra != NULL ? ": " : "", extra != NULL ? extra : ""); + if (extra != NULL) + slog_set_auth_info(extra); free(extra); slog_set_auth_data(authenticated, method, authctxt->user); --- a/auth2-pubkey.c +++ b/auth2-pubkey.c @@ -723,7 +723,7 @@ check_authkey_line(struct ssh *ssh, stru (unsigned long long)key->cert->serial, sshkey_type(found), fp, loc); - slog_set_cert_serial(key->cert->serial); + slog_set_cert_serial(key->cert->serial); success: if (finalopts == NULL) fatal_f("internal error: missing options"); @@ -886,6 +886,8 @@ user_cert_trusted_ca(struct ssh *ssh, st final_opts = NULL; } slog_set_cert_id(key->cert->key_id); + slog_set_cert_serial(key->cert->serial); + ret = 1; out: sshauthopt_free(principals_opts);