Blob Blame History Raw
--- 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);