From b3486fc32be21b4403707f618c47ca82d6daf2f0 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Wei=C3=9Fe?=
 <66256922+daniel-weisse@users.noreply.github.com>
Date: Tue, 28 Feb 2023 16:34:18 +0100
Subject: [PATCH] intenal: add logging to attestation issuer (#1264)
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Signed-off-by: Daniel Weiße <dw@edgeless.systems>
---
 bootstrapper/cmd/bootstrapper/main.go         | 10 +++---
 disk-mapper/cmd/main.go                       |  8 ++---
 internal/attestation/aws/issuer.go            |  3 +-
 internal/attestation/azure/azure.go           |  6 ++--
 internal/attestation/azure/snp/issuer.go      |  3 +-
 .../attestation/azure/trustedlaunch/issuer.go |  3 +-
 .../azure/trustedlaunch/trustedlaunch_test.go |  3 +-
 internal/attestation/gcp/issuer.go            |  3 +-
 internal/attestation/qemu/issuer.go           |  3 +-
 internal/attestation/vtpm/attestation.go      | 32 ++++++++++++++++---
 internal/attestation/vtpm/attestation_test.go |  9 +++++-
 verify/cmd/main.go                            |  8 ++---
 12 files changed, 63 insertions(+), 28 deletions(-)

diff --git a/bootstrapper/cmd/bootstrapper/main.go b/bootstrapper/cmd/bootstrapper/main.go
index 2894579d9..ebae1ec8e 100644
--- a/bootstrapper/cmd/bootstrapper/main.go
+++ b/bootstrapper/cmd/bootstrapper/main.go
@@ -82,7 +82,7 @@ func main() {
 			log.With(zap.Error(err)).Fatalf("Failed to get selected PCRs")
 		}
 
-		issuer = aws.NewIssuer()
+		issuer = aws.NewIssuer(log)
 
 		metadata, err := awscloud.New(ctx)
 		if err != nil {
@@ -108,7 +108,7 @@ func main() {
 			log.With(zap.Error(err)).Fatalf("Failed to get selected PCRs")
 		}
 
-		issuer = gcp.NewIssuer()
+		issuer = gcp.NewIssuer(log)
 
 		metadata, err := gcpcloud.New(ctx)
 		if err != nil {
@@ -137,10 +137,10 @@ func main() {
 		}
 
 		if _, err := snp.GetIDKeyDigest(vtpm.OpenVTPM); err == nil {
-			issuer = snp.NewIssuer()
+			issuer = snp.NewIssuer(log)
 		} else {
 			// assume we are running in a trusted-launch VM
-			issuer = trustedlaunch.NewIssuer()
+			issuer = trustedlaunch.NewIssuer(log)
 		}
 
 		metadata, err := azurecloud.New(ctx)
@@ -166,7 +166,7 @@ func main() {
 			log.With(zap.Error(err)).Fatalf("Failed to get selected PCRs")
 		}
 
-		issuer = qemu.NewIssuer()
+		issuer = qemu.NewIssuer(log)
 
 		cloudLogger = qemucloud.NewLogger()
 		metadata := qemucloud.New()
diff --git a/disk-mapper/cmd/main.go b/disk-mapper/cmd/main.go
index 34b827239..51970f040 100644
--- a/disk-mapper/cmd/main.go
+++ b/disk-mapper/cmd/main.go
@@ -79,7 +79,7 @@ func main() {
 			log.With(zap.Error(err)).Fatalf("Failed to set up AWS metadata API")
 		}
 
-		issuer = aws.NewIssuer()
+		issuer = aws.NewIssuer(log)
 
 	case cloudprovider.Azure:
 		diskPath, err = filepath.EvalSymlinks(azureStateDiskPath)
@@ -92,7 +92,7 @@ func main() {
 			log.With(zap.Error).Fatalf("Failed to set up Azure metadata API")
 		}
 
-		issuer = azure.NewIssuer()
+		issuer = azure.NewIssuer(log)
 
 	case cloudprovider.GCP:
 		diskPath, err = filepath.EvalSymlinks(gcpStateDiskPath)
@@ -100,7 +100,7 @@ func main() {
 			_ = exportPCRs()
 			log.With(zap.Error(err)).Fatalf("Unable to resolve GCP state disk path")
 		}
-		issuer = gcp.NewIssuer()
+		issuer = gcp.NewIssuer(log)
 		gcpMeta, err := gcpcloud.New(context.Background())
 		if err != nil {
 			log.With(zap.Error).Fatalf("Failed to create GCP client")
@@ -116,7 +116,7 @@ func main() {
 
 	case cloudprovider.QEMU:
 		diskPath = qemuStateDiskPath
-		issuer = qemu.NewIssuer()
+		issuer = qemu.NewIssuer(log)
 		metadataAPI = qemucloud.New()
 		_ = exportPCRs()
 
diff --git a/internal/attestation/aws/issuer.go b/internal/attestation/aws/issuer.go
index 659886b82..3a02363b8 100644
--- a/internal/attestation/aws/issuer.go
+++ b/internal/attestation/aws/issuer.go
@@ -28,12 +28,13 @@ type Issuer struct {
 }
 
 // NewIssuer creates a new OpenVTPM based issuer for AWS.
-func NewIssuer() *Issuer {
+func NewIssuer(log vtpm.AttestationLogger) *Issuer {
 	return &Issuer{
 		Issuer: vtpm.NewIssuer(
 			vtpm.OpenVTPM,
 			getAttestationKey,
 			getInstanceInfo(imds.New(imds.Options{})),
+			log,
 		),
 	}
 }
diff --git a/internal/attestation/azure/azure.go b/internal/attestation/azure/azure.go
index 21cf5981c..abac62368 100644
--- a/internal/attestation/azure/azure.go
+++ b/internal/attestation/azure/azure.go
@@ -28,9 +28,9 @@ import (
 
 // NewIssuer returns an SNP issuer if it can successfully read the idkeydigest from the TPM.
 // Otherwise returns a Trusted Launch issuer.
-func NewIssuer() atls.Issuer {
+func NewIssuer(log vtpm.AttestationLogger) atls.Issuer {
 	if _, err := snp.GetIDKeyDigest(vtpm.OpenVTPM); err == nil {
-		return snp.NewIssuer()
+		return snp.NewIssuer(log)
 	}
-	return trustedlaunch.NewIssuer()
+	return trustedlaunch.NewIssuer(log)
 }
diff --git a/internal/attestation/azure/snp/issuer.go b/internal/attestation/azure/snp/issuer.go
index 3bd8f9bc0..cc08f89be 100644
--- a/internal/attestation/azure/snp/issuer.go
+++ b/internal/attestation/azure/snp/issuer.go
@@ -56,7 +56,7 @@ type Issuer struct {
 }
 
 // NewIssuer initializes a new Azure Issuer.
-func NewIssuer() *Issuer {
+func NewIssuer(log vtpm.AttestationLogger) *Issuer {
 	imdsAPI := imdsClient{
 		client: &http.Client{Transport: &http.Transport{Proxy: nil}},
 	}
@@ -66,6 +66,7 @@ func NewIssuer() *Issuer {
 			vtpm.OpenVTPM,
 			getAttestationKey,
 			getInstanceInfo(&tpmReport{}, imdsAPI),
+			log,
 		),
 	}
 }
diff --git a/internal/attestation/azure/trustedlaunch/issuer.go b/internal/attestation/azure/trustedlaunch/issuer.go
index 1d3d954ff..c8dd4d38e 100644
--- a/internal/attestation/azure/trustedlaunch/issuer.go
+++ b/internal/attestation/azure/trustedlaunch/issuer.go
@@ -35,7 +35,7 @@ type Issuer struct {
 }
 
 // NewIssuer initializes a new Azure Issuer.
-func NewIssuer() *Issuer {
+func NewIssuer(log vtpm.AttestationLogger) *Issuer {
 	i := &Issuer{
 		hClient: &http.Client{},
 	}
@@ -43,6 +43,7 @@ func NewIssuer() *Issuer {
 		vtpm.OpenVTPM,
 		getAttestationKey,
 		i.getAttestationCert,
+		log,
 	)
 	return i
 }
diff --git a/internal/attestation/azure/trustedlaunch/trustedlaunch_test.go b/internal/attestation/azure/trustedlaunch/trustedlaunch_test.go
index c6426523f..d71cc33cc 100644
--- a/internal/attestation/azure/trustedlaunch/trustedlaunch_test.go
+++ b/internal/attestation/azure/trustedlaunch/trustedlaunch_test.go
@@ -20,6 +20,7 @@ import (
 	"github.com/edgelesssys/constellation/v2/internal/attestation/measurements"
 	"github.com/edgelesssys/constellation/v2/internal/attestation/simulator"
 	"github.com/edgelesssys/constellation/v2/internal/crypto"
+	"github.com/edgelesssys/constellation/v2/internal/logger"
 	tpmclient "github.com/google/go-tpm-tools/client"
 	"github.com/google/go-tpm/tpm2"
 	"github.com/stretchr/testify/assert"
@@ -179,7 +180,7 @@ func TestGetAttestationCert(t *testing.T) {
 			))
 			require.NoError(tpm2.NVWrite(tpm, tpm2.HandleOwner, tpmAkCertIdx, "", akCert, 0))
 
-			issuer := NewIssuer()
+			issuer := NewIssuer(logger.NewTest(t))
 			issuer.hClient = newTestClient(tc.crlServer)
 
 			certs, err := issuer.getAttestationCert(tpm)
diff --git a/internal/attestation/gcp/issuer.go b/internal/attestation/gcp/issuer.go
index 74360c192..dd1f67d42 100644
--- a/internal/attestation/gcp/issuer.go
+++ b/internal/attestation/gcp/issuer.go
@@ -25,12 +25,13 @@ type Issuer struct {
 }
 
 // NewIssuer initializes a new GCP Issuer.
-func NewIssuer() *Issuer {
+func NewIssuer(log vtpm.AttestationLogger) *Issuer {
 	return &Issuer{
 		Issuer: vtpm.NewIssuer(
 			vtpm.OpenVTPM,
 			tpmclient.GceAttestationKeyRSA,
 			getGCEInstanceInfo(metadataClient{}),
+			log,
 		),
 	}
 }
diff --git a/internal/attestation/qemu/issuer.go b/internal/attestation/qemu/issuer.go
index d28486df4..860529b50 100644
--- a/internal/attestation/qemu/issuer.go
+++ b/internal/attestation/qemu/issuer.go
@@ -21,12 +21,13 @@ type Issuer struct {
 }
 
 // NewIssuer initializes a new QEMU Issuer.
-func NewIssuer() *Issuer {
+func NewIssuer(log vtpm.AttestationLogger) *Issuer {
 	return &Issuer{
 		Issuer: vtpm.NewIssuer(
 			vtpm.OpenVTPM,
 			tpmclient.AttestationKeyRSA,
 			func(tpm io.ReadWriteCloser) ([]byte, error) { return nil, nil },
+			log,
 		),
 	}
 }
diff --git a/internal/attestation/vtpm/attestation.go b/internal/attestation/vtpm/attestation.go
index 4bbd4763e..2315212d1 100644
--- a/internal/attestation/vtpm/attestation.go
+++ b/internal/attestation/vtpm/attestation.go
@@ -85,19 +85,34 @@ type Issuer struct {
 	openTPM           TPMOpenFunc
 	getAttestationKey GetTPMAttestationKey
 	getInstanceInfo   GetInstanceInfo
+	log               AttestationLogger
 }
 
 // NewIssuer returns a new Issuer.
-func NewIssuer(openTPM TPMOpenFunc, getAttestationKey GetTPMAttestationKey, getInstanceInfo GetInstanceInfo) *Issuer {
+func NewIssuer(
+	openTPM TPMOpenFunc, getAttestationKey GetTPMAttestationKey,
+	getInstanceInfo GetInstanceInfo, log AttestationLogger,
+) *Issuer {
+	if log == nil {
+		log = &nopAttestationLogger{}
+	}
 	return &Issuer{
 		openTPM:           openTPM,
 		getAttestationKey: getAttestationKey,
 		getInstanceInfo:   getInstanceInfo,
+		log:               log,
 	}
 }
 
 // Issue generates an attestation document using a TPM.
-func (i *Issuer) Issue(userData []byte, nonce []byte) ([]byte, error) {
+func (i *Issuer) Issue(userData []byte, nonce []byte) (res []byte, err error) {
+	i.log.Infof("Issuing attestation statement")
+	defer func() {
+		if err != nil {
+			i.log.Warnf("Failed to issue attestation statement: %s", err)
+		}
+	}()
+
 	tpm, err := i.openTPM()
 	if err != nil {
 		return nil, fmt.Errorf("opening TPM: %w", err)
@@ -113,7 +128,7 @@ func (i *Issuer) Issue(userData []byte, nonce []byte) ([]byte, error) {
 
 	// Create an attestation using the loaded key
 	extraData := makeExtraData(userData, nonce)
-	attestation, err := aK.Attest(tpmClient.AttestOpts{Nonce: extraData})
+	tpmAttestation, err := aK.Attest(tpmClient.AttestOpts{Nonce: extraData})
 	if err != nil {
 		return nil, fmt.Errorf("creating attestation: %w", err)
 	}
@@ -125,11 +140,18 @@ func (i *Issuer) Issue(userData []byte, nonce []byte) ([]byte, error) {
 	}
 
 	attDoc := AttestationDocument{
-		Attestation:  attestation,
+		Attestation:  tpmAttestation,
 		InstanceInfo: instanceInfo,
 		UserData:     userData,
 	}
-	return json.Marshal(attDoc)
+
+	rawAttDoc, err := json.Marshal(attDoc)
+	if err != nil {
+		return nil, fmt.Errorf("marshaling attestation document: %w", err)
+	}
+
+	i.log.Infof("Successfully issued attestation statement")
+	return rawAttDoc, nil
 }
 
 // Validator handles validation of TPM based attestation.
diff --git a/internal/attestation/vtpm/attestation_test.go b/internal/attestation/vtpm/attestation_test.go
index 53718f033..f89945dda 100644
--- a/internal/attestation/vtpm/attestation_test.go
+++ b/internal/attestation/vtpm/attestation_test.go
@@ -16,6 +16,7 @@ import (
 
 	"github.com/edgelesssys/constellation/v2/internal/attestation/measurements"
 	tpmsim "github.com/edgelesssys/constellation/v2/internal/attestation/simulator"
+	"github.com/edgelesssys/constellation/v2/internal/logger"
 	tpmclient "github.com/google/go-tpm-tools/client"
 	"github.com/google/go-tpm-tools/proto/attest"
 	"github.com/google/go-tpm-tools/proto/tpm"
@@ -75,7 +76,7 @@ func TestValidate(t *testing.T) {
 	tpmOpen, tpmCloser := tpmsim.NewSimulatedTPMOpenFunc()
 	defer tpmCloser.Close()
 
-	issuer := NewIssuer(tpmOpen, tpmclient.AttestationKeyRSA, fakeGetInstanceInfo)
+	issuer := NewIssuer(tpmOpen, tpmclient.AttestationKeyRSA, fakeGetInstanceInfo, logger.NewTest(t))
 	validator := NewValidator(testExpectedPCRs, fakeGetTrustedKey, fakeValidateCVM, nil)
 
 	nonce := []byte{1, 2, 3, 4}
@@ -266,6 +267,7 @@ func TestFailIssuer(t *testing.T) {
 				},
 				tpmclient.AttestationKeyRSA,
 				fakeGetInstanceInfo,
+				nil,
 			),
 			userData: []byte("Constellation"),
 			nonce:    []byte{1, 2, 3, 4},
@@ -277,6 +279,7 @@ func TestFailIssuer(t *testing.T) {
 					return nil, errors.New("failure")
 				},
 				fakeGetInstanceInfo,
+				nil,
 			),
 			userData: []byte("Constellation"),
 			nonce:    []byte{1, 2, 3, 4},
@@ -288,6 +291,7 @@ func TestFailIssuer(t *testing.T) {
 					return &tpmclient.Key{}, nil
 				},
 				fakeGetInstanceInfo,
+				nil,
 			),
 			userData: []byte("Constellation"),
 			nonce:    []byte{1, 2, 3, 4},
@@ -297,6 +301,7 @@ func TestFailIssuer(t *testing.T) {
 				newSimTPMWithEventLog,
 				tpmclient.AttestationKeyRSA,
 				func(io.ReadWriteCloser) ([]byte, error) { return nil, errors.New("failure") },
+				nil,
 			),
 			userData: []byte("Constellation"),
 			nonce:    []byte{1, 2, 3, 4},
@@ -307,6 +312,8 @@ func TestFailIssuer(t *testing.T) {
 		t.Run(name, func(t *testing.T) {
 			assert := assert.New(t)
 
+			tc.issuer.log = logger.NewTest(t)
+
 			_, err := tc.issuer.Issue(tc.userData, tc.nonce)
 			assert.Error(err)
 		})
diff --git a/verify/cmd/main.go b/verify/cmd/main.go
index 84a3fe518..18683d484 100644
--- a/verify/cmd/main.go
+++ b/verify/cmd/main.go
@@ -35,13 +35,13 @@ func main() {
 	var issuer server.AttestationIssuer
 	switch cloudprovider.FromString(*provider) {
 	case cloudprovider.AWS:
-		issuer = aws.NewIssuer()
+		issuer = aws.NewIssuer(log)
 	case cloudprovider.GCP:
-		issuer = gcp.NewIssuer()
+		issuer = gcp.NewIssuer(log)
 	case cloudprovider.Azure:
-		issuer = azure.NewIssuer()
+		issuer = azure.NewIssuer(log)
 	case cloudprovider.QEMU:
-		issuer = qemu.NewIssuer()
+		issuer = qemu.NewIssuer(log)
 	default:
 		log.With(zap.String("cloudProvider", *provider)).Fatalf("Unknown cloud provider")
 	}