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