From f4ac37e82e2173ed0d71504dfac93139ef6b6545 Mon Sep 17 00:00:00 2001 From: Simon Ott Date: Tue, 19 Dec 2023 13:11:06 +0000 Subject: [PATCH] treewide: better log messages and fixes Signed-off-by: Simon Ott --- attestationreport/tpm.go | 7 +++++++ attestedtls/attestation.go | 15 +++++---------- testtool/internal.go | 18 ++++++++++-------- tpmdriver/bioseventlog.go | 6 +++--- 4 files changed, 25 insertions(+), 21 deletions(-) diff --git a/attestationreport/tpm.go b/attestationreport/tpm.go index d78a3205..39f558ac 100644 --- a/attestationreport/tpm.go +++ b/attestationreport/tpm.go @@ -183,6 +183,8 @@ func recalculatePcrs(tpmM *TpmMeasurement, referenceValues []ReferenceValue) (ma } } if !found { + log.Warnf("Failed to find reference value %v in measurements", + hex.EncodeToString(ref.Sha256)) ok = false refResult.Success = false refResult.Type = "Reference Value" @@ -226,6 +228,8 @@ func recalculatePcrs(tpmM *TpmMeasurement, referenceValues []ReferenceValue) (ma Type: "Measurement", } artifacts = append(artifacts, measResult) + log.Warnf("Failed to find measurement %v in reference values", + hex.EncodeToString(sha256)) ok = false } } @@ -237,6 +241,8 @@ func recalculatePcrs(tpmM *TpmMeasurement, referenceValues []ReferenceValue) (ma pcrRes.Success = true pcrRes.Calculated = hex.EncodeToString(measurement) } else { + log.Warnf("PCR%v mismatch: measured: %v, calculated: %v", pcrNum, + hex.EncodeToString(measurement), hex.EncodeToString(calculatedHash)) pcrRes.Success = false pcrRes.Calculated = hex.EncodeToString(calculatedHash) pcrRes.Measured = hex.EncodeToString(measurement) @@ -262,6 +268,7 @@ func recalculatePcrs(tpmM *TpmMeasurement, referenceValues []ReferenceValue) (ma artifacts[i].Success = false } } + log.Warnf("Measurement did not contain PCR%v", pcrNum) ok = false } } diff --git a/attestedtls/attestation.go b/attestedtls/attestation.go index 148eb952..392a67c4 100644 --- a/attestedtls/attestation.go +++ b/attestedtls/attestation.go @@ -51,8 +51,7 @@ func attestDialer(conn *tls.Conn, chbindings []byte, cc cmcConfig) error { if err != nil { return fmt.Errorf("failed to send skip client Attestation: %w", err) } - log.Debug("Sent skip response") - log.Debug("Skipping, Server only attestation: client side attestation only") + log.Debug("Skipping client-side attestation") } readvalue, err := readValue(conn, cc.attest, true) @@ -62,8 +61,6 @@ func attestDialer(conn *tls.Conn, chbindings []byte, cc cmcConfig) error { //optional: Wait for attestation report from Server if cc.attest == Attest_Mutual || cc.attest == Attest_Server { - log.Trace("Attesting the Server") - report := readvalue // Verify AR from listener with own channel bindings log.Trace("Verifying attestation report from listener") @@ -72,7 +69,7 @@ func attestDialer(conn *tls.Conn, chbindings []byte, cc cmcConfig) error { return err } } else { - log.Debug("Skipping, Client only attestation: client side attestation only") + log.Debug("Skipping client-side verification") } log.Trace("Attestation successful") @@ -102,8 +99,7 @@ func attestListener(conn *tls.Conn, chbindings []byte, cc cmcConfig) error { if err != nil { return fmt.Errorf("failed to send skip client Attestation: %w", err) } - log.Debug("Sent skip response") - log.Debug("Skipping, Client only attestation: client side attestation only") + log.Debug("Skipping server-side attestation") } readValue, err := readValue(conn, cc.attest, false) @@ -113,7 +109,6 @@ func attestListener(conn *tls.Conn, chbindings []byte, cc cmcConfig) error { // optional: Wait for attestation report from client if cc.attest == Attest_Mutual || cc.attest == Attest_Client { - log.Debug("Attesting the Client") report := readValue // Verify AR from dialer with own channel bindings log.Trace("Verifying attestation report from dialer...") @@ -122,7 +117,7 @@ func attestListener(conn *tls.Conn, chbindings []byte, cc cmcConfig) error { return err } } else { - log.Debug("Skipping, Server only attestation: server side attestation only") + log.Debug("Skipping server-side verification") } log.Trace("Attestation successful") @@ -143,7 +138,7 @@ func readValue(conn *tls.Conn, selection AttestSelect, dialer bool) ([]byte, err // the first byte should always be the attestation mode if readvalue[0] == byte(selection) { - log.Debug("Matching attestation mode, both are set to:", selectionStr) + log.Debugf("Matching attestation mode: [%v]", selectionStr) } else { reportByte := readvalue[0] reportStr, errS1 := selectionString(reportByte) diff --git a/testtool/internal.go b/testtool/internal.go index eb90875f..ad855d7e 100644 --- a/testtool/internal.go +++ b/testtool/internal.go @@ -55,13 +55,15 @@ func dialInternalAddr(c *config, api atls.CmcApiSelect, addr string, tlsConf *tl atls.WithResult(verificationResult), atls.WithCmc(cmc)) // Publish the attestation result asynchronously if publishing address was specified and - // the result is present - wg := new(sync.WaitGroup) - wg.Add(1) - defer wg.Wait() - go publishResultAsync(c.Publish, verificationResult, wg) - if err != nil { - return fmt.Errorf("failed to dial server: %v", err) + // and attestation was performed + if c.Publish != "" && (c.Attest == "mutual" || c.Attest == "server") { + wg := new(sync.WaitGroup) + wg.Add(1) + defer wg.Wait() + go publishResultAsync(c.Publish, verificationResult, wg) + if err != nil { + return fmt.Errorf("failed to dial server: %v", err) + } } defer conn.Close() _ = conn.SetReadDeadline(time.Now().Add(timeoutSec * time.Second)) @@ -230,7 +232,7 @@ func listenInternal(c *config, api atls.CmcApiSelect, cmc *cmc.Cmc) { // Handle established connections go handleConnection(conn) - if c.Mtls { + if c.Publish != "" && (c.Attest == "mutual" || c.Attest == "client") { // Publish the attestation result if publishing address was specified // and result is not empty go publishResult(c.Publish, verificationResult) diff --git a/tpmdriver/bioseventlog.go b/tpmdriver/bioseventlog.go index 8a7a1de9..36a43f44 100644 --- a/tpmdriver/bioseventlog.go +++ b/tpmdriver/bioseventlog.go @@ -20,7 +20,7 @@ import ( "encoding/binary" "errors" "fmt" - "io/ioutil" + "os" ar "github.com/Fraunhofer-AISEC/cmc/attestationreport" ) @@ -110,9 +110,9 @@ type TPMT_HA struct { // measurements (usually /sys/kernel/security/tpm0/binary_bios_measurements) // must be specified func GetBiosMeasurements(file string) ([]ar.ReferenceValue, error) { - data, err := ioutil.ReadFile(file) + data, err := os.ReadFile(file) if err != nil { - return nil, fmt.Errorf("failed to load IMA runtime measurements from %v: %w", file, err) + return nil, fmt.Errorf("failed to read %v: %w", file, err) } digests, err := parseBiosMeasurements(data)