report on entire peer chain in TLS transaction debug, not just the en…

…d cert

Note that many of the tests have multiple copies of the same cert in their output.  I think this is an issue w/ smtp-server.pl, not swaks.  See #73

Changes

@@ -1024,3 +1024,6 @@
 * 20231126 In prep for handling peer chains properly, change the printing
            of local cert labeling from local/chain to local[i], but
            only if there is more than one local cert.
+* 20231130 Flesh out printing of certs to include notBefore/After,
+           commonName (not as part of the DN), and subjectAltName
+* 20231130 Show debug for entire peer cert chain, not just for the end cert

swaks

@@ -392,15 +392,16 @@ sub xclient_try {
 sub tls_post_start {
 	ptrans(11, "TLS started with cipher $G::link{tls}{cipher_string}");
 	ptrans(11, "TLS client certificate " . ($G::link{tls}{server_requested_cert} ? '' : 'not ') . "requested and " . ($G::link{tls}{client_sent_cert} ? '' : 'not ') . "sent");
-	if (!exists($G::link{tls}{local_cert_subjects}) || !ref($G::link{tls}{local_cert_subjects}) eq 'ARRAY' || !scalar(@{$G::link{tls}{local_cert_subjects}})) {
-		ptrans(11, "TLS no local certificate set");
+	if (!exists($G::link{tls}{local_certs}) || !ref($G::link{tls}{local_certs}) eq 'ARRAY' || !scalar(@{$G::link{tls}{local_certs}})) {
+		ptrans(11, "TLS no client certificate set");
 	} else {
-		for(my $i = 0; $i < scalar(@{$G::link{tls}{local_cert_subjects}}); $i++) {
-			my $string = sprintf('TLS local%s DN="%s"', scalar(@{$G::link{tls}{local_cert_subjects}}) > 1 ? "[$i]" : '', $G::link{tls}{local_cert_subjects}[$i]);
-			ptrans(11, $string);
+		for (my $i = 0; $i < scalar(@{$G::link{tls}{local_certs}}); $i++) {
+			print_cert_info($G::link{tls}{local_certs}, $i, "client");
 		}
 	}
-	ptrans(11, "TLS peer DN=\"$G::link{tls}{cert_subject}\"");
+	for (my $i = 0; $i < scalar(@{$G::link{tls}{server_certs}}); $i++) {
+		print_cert_info($G::link{tls}{server_certs}, $i, "peer");
+	}
 	ptrans(11, sprintf("TLS peer certificate %s CA verification, %s host verification (%s)",
 		$G::link{tls}{server_cert_verified_ca}   ? 'passed' : 'failed',
 		$G::link{tls}{server_cert_verified_host} ? 'passed' : 'failed',
@@ -417,6 +418,87 @@ sub tls_post_start {
 	}
 }
 
+sub print_cert_info {
+	my $list     = shift;
+	my $pos      = shift;
+	my $label    = shift;
+	my $x509     = $list->[$pos];
+	my $indent   = ' ' x 14;
+	my $fmtLabel = sprintf("%s%s", $label, scalar(@$list) > 1 ? "[$pos]" : '');
+
+	ptrans(11, sprintf('TLS %-9s DN="%s"', $fmtLabel, Net::SSLeay::X509_NAME_oneline(Net::SSLeay::X509_get_subject_name($x509))));
+	ptrans(11, sprintf("%snotBefore=%s", $indent, Net::SSLeay::P_ASN1_TIME_get_isotime(Net::SSLeay::X509_get_notBefore($x509))));
+	ptrans(11, sprintf("%snotAfter=%s", $indent, Net::SSLeay::P_ASN1_TIME_get_isotime(Net::SSLeay::X509_get_notAfter($x509))));
+	ptrans(11, sprintf("%ssubjectAltName=%s", $indent, getSanString($x509)));
+	# ptrans(11, Net::SSLeay::X509_NAME_oneline(Net::SSLeay::X509_get_issuer_name($x509)));
+	# ptrans(11, Net::SSLeay::X509_NAME_get_text_by_NID(Net::SSLeay::X509_get_subject_name($x509), "commonName"));
+
+	# this is a useful stanza for finding all objects in the name, but I don't need it for anything specific right now
+	# my $name = Net::SSLeay::X509_get_subject_name($x509);
+	# for (my $i = 0; $i < Net::SSLeay::X509_NAME_entry_count($name); $i++) {
+	# 	my $data = Net::SSLeay::X509_NAME_get_entry($name, $i);
+	# 	ptrans(11, sprintf("    %s) %s=%s", $i,
+	# 		Net::SSLeay::OBJ_obj2txt(Net::SSLeay::X509_NAME_ENTRY_get_object($data)),
+	# 		Net::SSLeay::P_ASN1_STRING_get(Net::SSLeay::X509_NAME_ENTRY_get_data($data))));
+	# }
+
+	my $commonName = '';
+	if (my $obj = Net::SSLeay::OBJ_txt2obj("commonName", 0)) {
+		if (my $nid = Net::SSLeay::OBJ_obj2nid($obj)) {
+			$commonName = Net::SSLeay::X509_NAME_get_text_by_NID(Net::SSLeay::X509_get_subject_name($x509), $nid);
+		}
+	}
+	ptrans(11, sprintf("%scommonName=%s", $indent, $commonName));
+
+}
+
+sub getSanString {
+	my $x509 = shift;
+
+	my @list = Net::SSLeay::X509_get_subjectAltNames($x509);
+
+	if (!scalar(@list)) {
+		return '';
+	}
+
+	# This is designed to closely follow (eg labels, capitalization, etc) openssl-x509 output unless otherwise noted below.
+	# The relevant code is in i2v_GENERAL_NAME in crypto/x509/v3_san.c.
+	my @modList = ();
+	while (scalar(@list)) {
+		my $type  = shift(@list);
+		my $value = shift(@list);
+
+		if ($type == Net::SSLeay::GEN_OTHERNAME()) {
+			# openssl-x509 further decodes this, but I'm defering that until someone actually asks
+			push(@modList, "othername:$value");
+		} elsif ($type == Net::SSLeay::GEN_X400()) {
+			# per Net::SSLeay POD, GEN_X400 is not supported and will never be returned, even if it is present in the cert
+			push(@modList, "X400Name:$value");
+		} elsif ($type == Net::SSLeay::GEN_EDIPARTY()) {
+			# per Net::SSLeay POD, GEN_EDIPARTY is not supported and will never be returned, even if it is present in the cert
+			push(@modList, "EdiPartyName:$value");
+		} elsif ($type == Net::SSLeay::GEN_EMAIL()) {
+			push(@modList, "email:$value");
+		} elsif ($type == Net::SSLeay::GEN_DNS()) {
+			push(@modList, "DNS:$value");
+		} elsif ($type == Net::SSLeay::GEN_URI()) {
+			push(@modList, "URI:$value");
+		} elsif ($type == Net::SSLeay::GEN_DIRNAME()) {
+			push(@modList, "DirName:$value");
+		} elsif ($type == Net::SSLeay::GEN_RID()) {
+			push(@modList, "Registered ID:$value");
+		} elsif ($type == Net::SSLeay::GEN_IPADD()) {
+			# There is a difference here, but I don't care enough to fix it right now.  for a cert with SAN element `::1`,
+			# openssl-x509 prints "IP Address:0:0:0:0:0:0:0:1", this code prints "IP Address:::1"
+			push(@modList, "IP Address:" . Socket::inet_ntop(length($value) == 4 ? Socket::AF_INET() : Socket::AF_INET6(), $value));
+		} else {
+			push(@modList, "$type:$value");
+		}
+	}
+
+	return '[ ' . join(', ', @modList) . ' ]';
+}
+
 sub start_tls {
 	my %t         = (); # This is a convenience var to access $G::link{tls}{...}
 	$G::link{tls} = \%t;
@@ -456,6 +538,7 @@ sub start_tls {
 	$t{server_cert_verification_status} = undef;
 	$t{server_cert_host_target}         = $G::tls_verify_target || $G::link{server};
 	$t{server_cert_error_components}    = {};
+	$t{server_certs}                    = [];
 	# This callback can get called multiple times, once per cert in the chain.  Because of that we have to be careful in how
 	# we design it - CA verification is sticky on failure (any cert failure means the whole thing is a failure) and loose
 	# on hostname verification (any hostname success is a success).  Also, we might generate the same error multiple times,
@@ -465,8 +548,9 @@ sub start_tls {
 		my $x509_ctx     = shift;
 		my @failures     = ();
 
-		# my $x = Net::SSLeay::X509_STORE_CTX_get_current_cert($x509_ctx);
-		# print STDERR "CALLING CTX_set_verify($preverify_ok): " . Net::SSLeay::X509_NAME_oneline(Net::SSLeay::X509_get_subject_name($x)) . "\n";
+		my $x509 = Net::SSLeay::X509_STORE_CTX_get_current_cert($x509_ctx);
+		unshift(@{$t{server_certs}}, $x509);
+		# print STDERR "CALLING CTX_set_verify($preverify_ok): " . Net::SSLeay::X509_NAME_oneline(Net::SSLeay::X509_get_subject_name($x509)) . "\n";
 
 		# we don't have to do the ca verification, that's handled before we get here
 		# we shape it like this because any cert failure fails the whole chain for cert verification
@@ -555,7 +639,7 @@ sub start_tls {
 			}
 			while (my $x509 = Net::SSLeay::PEM_read_bio_X509($bio)) {
 				$fileCertNum++;
-				push(@{$t{local_cert_subjects}}, Net::SSLeay::X509_NAME_oneline(Net::SSLeay::X509_get_subject_name($x509)));
+				push(@{$t{local_certs}}, $x509);
 				if ($sawFirstCert) {
 					if (!Net::SSLeay::CTX_add_extra_chain_cert($t{con}, $x509)) {
 						$t{res} = "Unable to add chain cert $fileCertNum from $file to SSL CTX: " . Net::SSLeay::ERR_error_string(Net::SSLeay::ERR_get_error());

testing/regressions/_exec-transactions/00229.test

@@ -0,0 +1,18 @@
+auto: REMOVE_FILE,CREATE_FILE,MUNGE,COMPARE_FILE %TESTID%.stdout %TESTID%.stderr %TESTID%.exits
+
+
+
+test action: CMD_CAPTURE %SWAKS% --to [email protected] --from [email protected] --helo hserver \
+  --tls \
+  --pipe '%TEST_SERVER% --silent --domain pipe \
+  --cert %CERTDIR%/signed-intermediate-full-chain.pem \
+  --key  %CERTDIR%/signed-intermediate.example.com.key \
+  part-0000-connect-standard.txt \
+  part-0101-ehlo-all.txt \
+  part-0203-starttls-basic-verify.txt \
+  part-0105-ehlo-post-tls-info.txt \
+  part-1000-mail-basic.txt \
+  part-1100-rcpt-basic-accept.txt \
+  part-2500-data-accept-basic.txt \
+  part-3000-shutdown-accept.txt \
+  '

testing/regressions/_exec-transactions/out-ref/00200.stdout

@@ -19,8 +19,22 @@
 <-  220 TLS go ahead
 === TLS started with cipher VERSION:CIPHER:BITS
 === TLS client certificate not requested and not sent
-=== TLS no local certificate set
-=== TLS peer DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+=== TLS no client certificate set
+=== TLS peer[0]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[1]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[2]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
 === TLS peer certificate failed CA verification, failed host verification (no host string available to verify)
  ~> EHLO hserver
 <~  250-SERVER Hello Server [1.1.1.1]

testing/regressions/_exec-transactions/out-ref/00202.stderr

@@ -1,2 +1,2 @@
-*** TLS startup failed (connect(): error:CODE:SSL routines::sslv3 alert handshake failure)
+*** TLS startup failed (connect(): error:CODE:SSL routines::ssl/tls alert handshake failure)
 *** STARTTLS attempted but failed

testing/regressions/_exec-transactions/out-ref/00207.stdout

@@ -2,8 +2,22 @@
 === Connected to %TEST_SERVER% --silent --domain pipe   part-0201-intialize-tls.txt   part-0000-connect-standard.txt   part-0101-ehlo-all.txt   part-1000-mail-basic.txt   part-1100-rcpt-basic-accept.txt   part-2500-data-accept-basic.txt   part-3000-shutdown-accept.txt   .
 === TLS started with cipher VERSION:CIPHER:BITS
 === TLS client certificate not requested and not sent
-=== TLS no local certificate set
-=== TLS peer DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+=== TLS no client certificate set
+=== TLS peer[0]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[1]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[2]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
 === TLS peer certificate failed CA verification, failed host verification (no host string available to verify)
 <~  220 SERVER ESMTP ready
  ~> EHLO hserver

testing/regressions/_exec-transactions/out-ref/00208.stderr

@@ -1 +1 @@
-*** TLS startup failed (connect(): error:CODE:SSL routines::sslv3 alert handshake failure)
+*** TLS startup failed (connect(): error:CODE:SSL routines::ssl/tls alert handshake failure)

testing/regressions/_exec-transactions/out-ref/00210.stdout

@@ -19,8 +19,26 @@
 <-  220 TLS go ahead
 === TLS started with cipher VERSION:CIPHER:BITS
 === TLS client certificate requested and sent
-=== TLS local DN="/C=US/ST=Indiana/O=Swaks Development (unsigned.example.com, with-SAN)/CN=unsigned.example.com/[email protected]"
-=== TLS peer DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+=== TLS client    DN="/C=US/ST=Indiana/O=Swaks Development (unsigned.example.com, with-SAN)/CN=unsigned.example.com/[email protected]"
+===               notBefore=2023-11-03T14:51:48Z
+===               notAfter=2033-09-11T14:51:48Z
+===               subjectAltName=[ DNS:unsigned.example.com ]
+===               commonName=unsigned.example.com
+=== TLS peer[0]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[1]   DN="/C=US/ST=Indiana/O=Swaks Development/CN=Swaks Root CA/[email protected]"
+===               notBefore=2020-12-13T15:28:17Z
+===               notAfter=2030-12-11T15:28:17Z
+===               subjectAltName=
+===               commonName=Swaks Root CA
+=== TLS peer[2]   DN="/C=US/ST=Indiana/O=Swaks Development/CN=Swaks Root CA/[email protected]"
+===               notBefore=2020-12-13T15:28:17Z
+===               notAfter=2030-12-11T15:28:17Z
+===               subjectAltName=
+===               commonName=Swaks Root CA
 === TLS peer certificate failed CA verification, failed host verification (no host string available to verify)
  ~> EHLO hserver
 <~  250-SERVER Hello Server [1.1.1.1]

testing/regressions/_exec-transactions/out-ref/00211.stdout

@@ -19,8 +19,17 @@
 <-  220 TLS go ahead
 === TLS started with cipher VERSION:CIPHER:BITS
 === TLS client certificate not requested and not sent
-=== TLS no local certificate set
-=== TLS peer DN="/C=US/ST=Indiana/O=Swaks Development (signed.example.com, with-SAN)/CN=signed.example.com/[email protected]"
+=== TLS no client certificate set
+=== TLS peer[0]   DN="/C=US/ST=Indiana/O=Swaks Development (signed.example.com, with-SAN)/CN=signed.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:47Z
+===               notAfter=2033-09-11T14:50:47Z
+===               subjectAltName=[ DNS:signed.example.com ]
+===               commonName=signed.example.com
+=== TLS peer[1]   DN="/C=US/ST=Indiana/O=Swaks Development/CN=Swaks Root CA/[email protected]"
+===               notBefore=2020-12-13T15:28:17Z
+===               notAfter=2030-12-11T15:28:17Z
+===               subjectAltName=
+===               commonName=Swaks Root CA
 === TLS peer certificate passed CA verification, failed host verification (no host string available to verify)
  ~> QUIT
 <~  221 SERVER closing connection

testing/regressions/_exec-transactions/out-ref/00212.stdout

@@ -19,8 +19,17 @@
 <-  220 TLS go ahead
 === TLS started with cipher VERSION:CIPHER:BITS
 === TLS client certificate not requested and not sent
-=== TLS no local certificate set
-=== TLS peer DN="/C=US/ST=Indiana/O=Swaks Development (signed.example.com, with-SAN)/CN=signed.example.com/[email protected]"
+=== TLS no client certificate set
+=== TLS peer[0]   DN="/C=US/ST=Indiana/O=Swaks Development (signed.example.com, with-SAN)/CN=signed.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:47Z
+===               notAfter=2033-09-11T14:50:47Z
+===               subjectAltName=[ DNS:signed.example.com ]
+===               commonName=signed.example.com
+=== TLS peer[1]   DN="/C=US/ST=Indiana/O=Swaks Development/CN=Swaks Root CA/[email protected]"
+===               notBefore=2020-12-13T15:28:17Z
+===               notAfter=2030-12-11T15:28:17Z
+===               subjectAltName=
+===               commonName=Swaks Root CA
 === TLS peer certificate passed CA verification, failed host verification (no host string available to verify)
  ~> QUIT
 <~  221 SERVER closing connection

testing/regressions/_exec-transactions/out-ref/00213.stdout

@@ -19,8 +19,22 @@
 <-  220 TLS go ahead
 === TLS started with cipher VERSION:CIPHER:BITS
 === TLS client certificate not requested and not sent
-=== TLS no local certificate set
-=== TLS peer DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+=== TLS no client certificate set
+=== TLS peer[0]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[1]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[2]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
 === TLS peer certificate failed CA verification, failed host verification (no host string available to verify)
 === -----BEGIN CERTIFICATE-----
 === MIIEGjCCAwKgAwIBAgIUFQU5NT2EO9gtC5YP96Fa9d8vFVkwDQYJKoZIhvcNAQEL

testing/regressions/_exec-transactions/out-ref/00214.stdout

@@ -19,8 +19,22 @@
 <-  220 TLS go ahead
 === TLS started with cipher VERSION:CIPHER:BITS
 === TLS client certificate not requested and not sent
-=== TLS no local certificate set
-=== TLS peer DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+=== TLS no client certificate set
+=== TLS peer[0]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[1]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
+=== TLS peer[2]   DN="/C=US/ST=Indiana/O=Swaks Development (node.example.com, with-SAN)/CN=node.example.com/[email protected]"
+===               notBefore=2023-11-03T14:50:10Z
+===               notAfter=2033-09-11T14:50:10Z
+===               subjectAltName=[ DNS:node.example.com ]
+===               commonName=node.example.com
 === TLS peer certificate failed CA verification, failed host verification (no host string available to verify)
  ~> EHLO hserver
 <~  250-SERVER Hello Server [1.1.1.1]