Attestation logging (#275)

* Add section for checking joinservice logs

* Add logging for attestation validation

Signed-off-by: Daniel Weiße <dw@edgeless.systems>
This commit is contained in:
Daniel Weiße 2022-10-14 16:29:21 +02:00 committed by GitHub
parent e7118223fe
commit f068e50dee
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 82 additions and 18 deletions

View File

@ -177,6 +177,9 @@ type warnLogger struct {
cmd *cobra.Command cmd *cobra.Command
} }
// Infof is a no-op since we don't want extra info messages when using the CLI.
func (wl warnLogger) Infof(format string, args ...interface{}) {}
// Warnf prints a formatted warning from the validator. // Warnf prints a formatted warning from the validator.
func (wl warnLogger) Warnf(fmtStr string, args ...interface{}) { func (wl warnLogger) Warnf(fmtStr string, args ...interface{}) {
wl.cmd.PrintErrf("Warning: %s\n", fmt.Sprintf(fmtStr, args...)) wl.cmd.PrintErrf("Warning: %s\n", fmt.Sprintf(fmtStr, args...))

View File

@ -79,7 +79,49 @@ Configure `kubectl` to connect to your local Constellation cluster:
export KUBECONFIG="$PWD/constellation-admin.conf" export KUBECONFIG="$PWD/constellation-admin.conf"
``` ```
It may take a couple of minutes for all cluster resources to be available. Your cluster initially consists of a single control-plane node:
```shell-session
$ kubectl get nodes
NAME STATUS ROLES AGE VERSION
control-plane-0 Ready control-plane 66s v1.24.6
```
A worker node will request to join the cluster shortly.
Before the new worker node is allowed to join the cluster, its state is verified using remote attestation by the [JoinService](../architecture/components.md#joinservice).
If verification passes successfully, the new node receives keys and certificates to join the cluster.
You can follow this process by viewing the logs of the JoinService:
```shell-session
$ kubectl logs -n kube-system daemonsets/join-service -f
{"level":"INFO","ts":"2022-10-14T09:32:20Z","caller":"cmd/main.go:48","msg":"Constellation Node Join Service","version":"2.1.0","cloudProvider":"qemu"}
{"level":"INFO","ts":"2022-10-14T09:32:20Z","logger":"validator","caller":"watcher/validator.go:96","msg":"Updating expected measurements"}
{"level":"INFO","ts":"2022-10-14T09:32:20Z","logger":"server","caller":"server/server.go:73","msg":"Starting join service on [::]:9090"}
{"level":"INFO","ts":"2022-10-14T09:32:20Z","caller":"cmd/main.go:103","msg":"starting file watcher for measurements file /var/config/measurements"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server","caller":"server/server.go:86","msg":"IssueJoinTicket called","peerAddress":"10.42.2.100:59988"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server","caller":"server/server.go:88","msg":"Requesting measurement secret","peerAddress":"10.42.2.100:59988"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kms","caller":"kms/kms.go:41","msg":"Connecting to KMS at kms.kube-system:9000","keyID":"measurementSecret","endpoint":"kms.kube-system:9000"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kms","caller":"kms/kms.go:48","msg":"Requesting data key","keyID":"measurementSecret","endpoint":"kms.kube-system:9000"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kms","caller":"kms/kms.go:61","msg":"Data key request successful","keyID":"measurementSecret","endpoint":"kms.kube-system:9000"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server","caller":"server/server.go:95","msg":"Requesting disk encryption key","peerAddress":"10.42.2.100:59988"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kms","caller":"kms/kms.go:41","msg":"Connecting to KMS at kms.kube-system:9000","keyID":"0f87c61f-31e7-466d-be22-e7300e7d9e76","endpoint":"kms.kube-system:9000"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kms","caller":"kms/kms.go:48","msg":"Requesting data key","keyID":"0f87c61f-31e7-466d-be22-e7300e7d9e76","endpoint":"kms.kube-system:9000"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kms","caller":"kms/kms.go:61","msg":"Data key request successful","keyID":"0f87c61f-31e7-466d-be22-e7300e7d9e76","endpoint":"kms.kube-system:9000"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server","caller":"server/server.go:102","msg":"Creating Kubernetes join token","peerAddress":"10.42.2.100:59988"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kubeadm","caller":"kubeadm/kubeadm.go:63","msg":"Generating new random bootstrap token"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kubeadm","caller":"kubeadm/kubeadm.go:81","msg":"Creating bootstrap token in Kubernetes"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kubeadm","caller":"kubeadm/kubeadm.go:87","msg":"Preparing join token for new node"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"kubeadm","caller":"kubeadm/kubeadm.go:109","msg":"Join token creation successful"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server","caller":"server/server.go:109","msg":"Querying K8sVersion ConfigMap","peerAddress":"10.42.2.100:59988"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server","caller":"server/server.go:115","msg":"Creating signed kubelet certificate","peerAddress":"10.42.2.100:59988"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"certificateAuthority","caller":"kubernetesca/kubernetesca.go:84","msg":"Creating kubelet certificate"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server","caller":"server/server.go:138","msg":"IssueJoinTicket successful","peerAddress":"10.42.2.100:59988"}
{"level":"INFO","ts":"2022-10-14T09:32:21Z","logger":"server.gRPC","caller":"zap/server_interceptors.go:39","msg":"finished unary call with code OK","grpc.start_time":"2022-10-14T09:32:21Z","grpc.request.deadline":"2022-10-14T09:32:51Z","system":"grpc","span.kind":"server","grpc.service":"join.API","grpc.method":"IssueJoinTicket","peer.address":"10.42.2.100:59988","grpc.code":"OK","grpc.time_ms":27.715}
```
Once the worker node has joined your cluster, it may take a couple of minutes for all resources to be available.
You can check on the state of your cluster by running the following: You can check on the state of your cluster by running the following:
```bash ```bash
@ -90,9 +132,9 @@ If your cluster is running as expected the output should look like the following
```shell-session ```shell-session
$ kubectl get nodes $ kubectl get nodes
NAME STATUS ROLES AGE VERSION NAME STATUS ROLES AGE VERSION
control-plane-0 Ready control-plane,master 2m59s v1.23.9 control-plane-0 Ready control-plane 2m59s v1.24.6
worker-0 Ready <none> 32s v1.23.9 worker-0 Ready <none> 32s v1.24.6
``` ```
## Deploy a sample application ## Deploy a sample application

View File

@ -41,7 +41,7 @@ type Validator struct {
} }
// NewValidator initializes a new Azure validator with the provided PCR values. // NewValidator initializes a new Azure validator with the provided PCR values.
func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, idKeyDigest []byte, enforceIDKeyDigest bool, log vtpm.WarnLogger) *Validator { func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, idKeyDigest []byte, enforceIDKeyDigest bool, log vtpm.AttestationLogger) *Validator {
return &Validator{ return &Validator{
Validator: vtpm.NewValidator( Validator: vtpm.NewValidator(
pcrs, pcrs,
@ -76,7 +76,9 @@ func reverseEndian(b []byte) {
// getTrustedKey establishes trust in the given public key. // getTrustedKey establishes trust in the given public key.
// It does so by verifying the SNP attestation statement in instanceInfo. // It does so by verifying the SNP attestation statement in instanceInfo.
func getTrustedKey(hclAk HCLAkValidator, idKeyDigest []byte, enforceIDKeyDigest bool, log vtpm.WarnLogger) func(akPub, instanceInfoRaw []byte) (crypto.PublicKey, error) { func getTrustedKey(
hclAk HCLAkValidator, idKeyDigest []byte, enforceIDKeyDigest bool, log vtpm.AttestationLogger,
) func(akPub, instanceInfoRaw []byte) (crypto.PublicKey, error) {
return func(akPub, instanceInfoRaw []byte) (crypto.PublicKey, error) { return func(akPub, instanceInfoRaw []byte) (crypto.PublicKey, error) {
var instanceInfo azureInstanceInfo var instanceInfo azureInstanceInfo
if err := json.Unmarshal(instanceInfoRaw, &instanceInfo); err != nil { if err := json.Unmarshal(instanceInfoRaw, &instanceInfo); err != nil {
@ -140,7 +142,10 @@ func validateVCEK(vcekRaw []byte, certChain []byte) (*x509.Certificate, error) {
return vcek, nil return vcek, nil
} }
func validateSNPReport(cert *x509.Certificate, expectedIDKeyDigest []byte, enforceIDKeyDigest bool, report snpAttestationReport, log vtpm.WarnLogger) error { func validateSNPReport(
cert *x509.Certificate, expectedIDKeyDigest []byte, enforceIDKeyDigest bool,
report snpAttestationReport, log vtpm.AttestationLogger,
) error {
if report.Policy.Debug() { if report.Policy.Debug() {
return errDebugEnabled return errDebugEnabled
} }

View File

@ -32,7 +32,7 @@ type Validator struct {
} }
// NewValidator initializes a new Azure validator with the provided PCR values. // NewValidator initializes a new Azure validator with the provided PCR values.
func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, log vtpm.WarnLogger) *Validator { func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, log vtpm.AttestationLogger) *Validator {
rootPool := x509.NewCertPool() rootPool := x509.NewCertPool()
rootPool.AddCert(ameRoot) rootPool.AddCert(ameRoot)
v := &Validator{roots: rootPool} v := &Validator{roots: rootPool}

View File

@ -34,7 +34,7 @@ type Validator struct {
} }
// NewValidator initializes a new GCP validator with the provided PCR values. // NewValidator initializes a new GCP validator with the provided PCR values.
func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, log vtpm.WarnLogger) *Validator { func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, log vtpm.AttestationLogger) *Validator {
return &Validator{ return &Validator{
Validator: vtpm.NewValidator( Validator: vtpm.NewValidator(
pcrs, pcrs,

View File

@ -21,7 +21,7 @@ type Validator struct {
} }
// NewValidator initializes a new qemu validator with the provided PCR values. // NewValidator initializes a new qemu validator with the provided PCR values.
func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, log vtpm.WarnLogger) *Validator { func NewValidator(pcrs map[uint32][]byte, enforcedPCRs []uint32, log vtpm.AttestationLogger) *Validator {
return &Validator{ return &Validator{
Validator: vtpm.NewValidator( Validator: vtpm.NewValidator(
pcrs, pcrs,

View File

@ -57,8 +57,9 @@ type (
VerifyUserData func(pub crypto.PublicKey, hash crypto.Hash, hashed, sig []byte) error VerifyUserData func(pub crypto.PublicKey, hash crypto.Hash, hashed, sig []byte) error
) )
// WarnLogger is a logger used to print warnings during attestation validation. // AttestationLogger is a logger used to print warnings and infos during attestation validation.
type WarnLogger interface { type AttestationLogger interface {
Infof(format string, args ...interface{})
Warnf(format string, args ...interface{}) Warnf(format string, args ...interface{})
} }
@ -139,12 +140,12 @@ type Validator struct {
validateCVM ValidateCVM validateCVM ValidateCVM
verifyUserData VerifyUserData verifyUserData VerifyUserData
log WarnLogger log AttestationLogger
} }
// NewValidator returns a new Validator. // NewValidator returns a new Validator.
func NewValidator(expectedPCRs map[uint32][]byte, enforcedPCRs []uint32, func NewValidator(expectedPCRs map[uint32][]byte, enforcedPCRs []uint32, getTrustedKey GetTPMTrustedAttestationPublicKey,
getTrustedKey GetTPMTrustedAttestationPublicKey, validateCVM ValidateCVM, verifyUserData VerifyUserData, log WarnLogger, validateCVM ValidateCVM, verifyUserData VerifyUserData, log AttestationLogger,
) *Validator { ) *Validator {
// Convert the enforced PCR list to a map for convenient and fast lookup // Convert the enforced PCR list to a map for convenient and fast lookup
enforcedMap := make(map[uint32]struct{}) enforcedMap := make(map[uint32]struct{})
@ -164,6 +165,10 @@ func NewValidator(expectedPCRs map[uint32][]byte, enforcedPCRs []uint32,
// Validate a TPM based attestation. // Validate a TPM based attestation.
func (v *Validator) Validate(attDocRaw []byte, nonce []byte) ([]byte, error) { func (v *Validator) Validate(attDocRaw []byte, nonce []byte) ([]byte, error) {
if v.log != nil {
v.log.Infof("Validating attestation document")
}
var attDoc AttestationDocument var attDoc AttestationDocument
if err := json.Unmarshal(attDocRaw, &attDoc); err != nil { if err := json.Unmarshal(attDocRaw, &attDoc); err != nil {
return nil, fmt.Errorf("unmarshaling TPM attestation document: %w", err) return nil, fmt.Errorf("unmarshaling TPM attestation document: %w", err)
@ -213,6 +218,10 @@ func (v *Validator) Validate(attDocRaw []byte, nonce []byte) ([]byte, error) {
if err = v.verifyUserData(aKP, crypto.SHA256, digest[:], attDoc.UserDataSignature); err != nil { if err = v.verifyUserData(aKP, crypto.SHA256, digest[:], attDoc.UserDataSignature); err != nil {
return nil, fmt.Errorf("verifying signed user data: %w", err) return nil, fmt.Errorf("verifying signed user data: %w", err)
} }
if v.log != nil {
v.log.Infof("Successfully validated attestation document")
}
return attDoc.UserData, nil return attDoc.UserData, nil
} }

View File

@ -68,7 +68,7 @@ func TestValidate(t *testing.T) {
0: {0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00}, 0: {0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00},
1: {0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00}, 1: {0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00},
} }
warnLog := &testWarnLog{} warnLog := &testAttestationLogger{}
issuer := NewIssuer(newSimTPMWithEventLog, tpmclient.AttestationKeyRSA, fakeGetInstanceInfo) issuer := NewIssuer(newSimTPMWithEventLog, tpmclient.AttestationKeyRSA, fakeGetInstanceInfo)
validator := NewValidator(testExpectedPCRs, []uint32{0, 1}, fakeGetTrustedKey, fakeValidateCVM, VerifyPKCS1v15, warnLog) validator := NewValidator(testExpectedPCRs, []uint32{0, 1}, fakeGetTrustedKey, fakeValidateCVM, VerifyPKCS1v15, warnLog)
@ -401,10 +401,15 @@ func TestGetSelectedPCRs(t *testing.T) {
} }
} }
type testWarnLog struct { type testAttestationLogger struct {
infos []string
warnings []string warnings []string
} }
func (w *testWarnLog) Warnf(format string, args ...interface{}) { func (w *testAttestationLogger) Infof(format string, args ...interface{}) {
w.infos = append(w.infos, fmt.Sprintf(format, args...))
}
func (w *testAttestationLogger) Warnf(format string, args ...interface{}) {
w.warnings = append(w.warnings, fmt.Sprintf(format, args...)) w.warnings = append(w.warnings, fmt.Sprintf(format, args...))
} }