Skip to content

Commit

Permalink
Send client logs with the cloud logging library (#474)
Browse files Browse the repository at this point in the history 
* test slog

* test slog

* fix conflicts

* fix lint errors

* remove unused struct

* log latency in seconds

* read uptime from /proc/uptime

* add workload name to latency log

* fix error fmt

* Fit Fprintf lint issues

* Fit lint issue

* Make formatting consistent

* text handler and experiment logging

* fix bugs in main

* Add export comment to Experiments.Log

* adjust logging for token refresh

* rebase and cleanup

* test cloud logger

* test cloud logger

* add cloud logging dependency

* update go.work.sum

* change logging version

* add logging library with cloud logging client

* fix lint issues

* add logging package comment

* fix remaining conflicts

* fix bug where serialconsole file is closed prematurely

* change message label to all caps

* re-add logging to stdout

* add isntance name to resource labels

* add hostname field to logging payload

* correct log name

* fix typo

* re-add os.exit defer

* add tests for logging library

* Avoid using logging client for unit tests

* remove usage of logging.client from tests

* fix lint errors

* review comments

* change read_cloud_logging fields

* fix logging tests

* tweak logging payload keys

* Specify seconds for logging

* revert key changes

* log the attestation token as a single struct

* Remove unused code

* fix logging methods

* fix conflict errors

* separately log workload setup and execution duration

* address comments
  • Loading branch information
@jessieqliu
jessieqliu authored Oct 23, 2024
1 parent 86cd15e commit c891518
Show file tree
Hide file tree
Showing 17 changed files with 731 additions and 130 deletions.
6 changes: 3 additions & 3 deletions cmd/token.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -107,7 +107,7 @@ The OIDC token includes claims regarding the GCE VM, which is verified by Attest
}

cloudLogger = cloudLogClient.Logger(toolName)
fmt.Fprint(debugOutput(), "cloudLogger created for project: "+projectID+"\n")
fmt.Fprintf(debugOutput(), "cloudLogger created for project: %s\n", projectID)
}

key = "gceAK"
Expand Down Expand Up @@ -175,7 +175,7 @@ The OIDC token includes claims regarding the GCE VM, which is verified by Attest
}

if output == "" {
fmt.Fprint(messageOutput(), string(token)+"\n")
fmt.Fprintf(messageOutput(), "%s\n", string(token))
} else {
out := []byte(token)
if _, err := dataOutput().Write(out); err != nil {
Expand All @@ -194,7 +194,7 @@ The OIDC token includes claims regarding the GCE VM, which is verified by Attest
}
}

fmt.Fprint(debugOutput(), string(claimsString)+"\n"+"Note: these Claims are for debugging purpose and not verified"+"\n")
fmt.Fprintf(debugOutput(), "%s\nNote: these Claims are for debugging purpose and not verified\n", string(claimsString))

return nil
},
Expand Down
2 changes: 2 additions & 0 deletions go.work.sum
View file
Original file line number Diff line number Diff line change
Expand Up @@ -488,6 +488,7 @@ cloud.google.com/go/storage v1.30.1/go.mod h1:NfxhC0UJE1aXSx7CIIbCf7y9HKT7Biccwk
cloud.google.com/go/storage v1.39.1/go.mod h1:xK6xZmxZmo+fyP7+DEF6FhNc24/JAe95OLyOHCXFH1o=
cloud.google.com/go/storage v1.40.0/go.mod h1:Rrj7/hKlG87BLqDJYtwR0fbPld8uJPbQ2ucUMY7Ir0g=
cloud.google.com/go/storage v1.41.0/go.mod h1:J1WCa/Z2FcgdEDuPUY8DxT5I+d9mFKsCepp5vR6Sq80=
cloud.google.com/go/storage v1.42.0/go.mod h1:HjMXRFq65pGKFn6hxj6x3HCyR41uSB72Z0SO/Vn6JFQ=
cloud.google.com/go/storagetransfer v1.10.1/go.mod h1:rS7Sy0BtPviWYTTJVWCSV4QrbBitgPeuK4/FKa4IdLs=
cloud.google.com/go/storagetransfer v1.10.4/go.mod h1:vef30rZKu5HSEf/x1tK3WfWrL0XVoUQN/EPDRGPzjZs=
cloud.google.com/go/storagetransfer v1.10.6/go.mod h1:3sAgY1bx1TpIzfSzdvNGHrGYldeCTyGI/Rzk6Lc6A7w=
Expand Down Expand Up @@ -685,6 +686,7 @@ github.com/golang-jwt/jwt/v4 v4.0.0/go.mod h1:/xlHOz8bRuivTWchD4jCa+NbatV+wEUSzw
github.com/golang-jwt/jwt/v4 v4.2.0/go.mod h1:/xlHOz8bRuivTWchD4jCa+NbatV+wEUSzwAxVc6locg=
github.com/golang/glog v1.0.0/go.mod h1:EWib/APOK0SL3dFbYqvxE3UYd8E6s1ouQ7iEp/0LWV4=
github.com/golang/glog v1.1.2/go.mod h1:zR+okUeTbrL6EL3xHUDxZuEtGv04p5shwip1+mL/rLQ=
github.com/golang/glog v1.2.0 h1:uCdmnmatrKCgMBlM4rMuJZWOkPDqdbZPnrMXDY4gI68=
github.com/golang/glog v1.2.0/go.mod h1:6AhwSGph0fcJtXVM/PEHPqZlFeoLxhs7/t5UDAwmO+w=
github.com/golang/protobuf v1.5.3/go.mod h1:XVQd3VNwM+JqD3oG2Ue2ip4fOMUkwXdXDdiuN0vRsmY=
github.com/golang/snappy v0.0.4/go.mod h1:/XxbfmMg8lxefKM7IXC3fBNl/7bRcc72aCRzEWrmP2Q=
Expand Down
18 changes: 9 additions & 9 deletions launcher/agent/agent.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,14 +11,14 @@ import (
"crypto"
"fmt"
"io"
"log"
"net/http"
"sync"
"time"

"github.com/cenkalti/backoff/v4"
"github.com/google/go-tpm-tools/cel"
"github.com/google/go-tpm-tools/client"
"github.com/google/go-tpm-tools/launcher/internal/logging"
"github.com/google/go-tpm-tools/launcher/internal/signaturediscovery"
"github.com/google/go-tpm-tools/launcher/spec"
pb "github.com/google/go-tpm-tools/proto/attest"
Expand Down Expand Up @@ -58,7 +58,7 @@ type agent struct {
sigsFetcher signaturediscovery.Fetcher
cosCel cel.CEL
launchSpec spec.LaunchSpec
logger *log.Logger
logger logging.Logger
sigsCache *sigsCache
}

Expand All @@ -69,7 +69,7 @@ type agent struct {
// - principalFetcher is a func to fetch GCE principal tokens for a given audience.
// - signaturesFetcher is a func to fetch container image signatures associated with the running workload.
// - logger will log any partial errors returned by VerifyAttestation.
func CreateAttestationAgent(tpm io.ReadWriteCloser, akFetcher util.TpmKeyFetcher, verifierClient verifier.Client, principalFetcher principalIDTokenFetcher, sigsFetcher signaturediscovery.Fetcher, launchSpec spec.LaunchSpec, logger *log.Logger) (AttestationAgent, error) {
func CreateAttestationAgent(tpm io.ReadWriteCloser, akFetcher util.TpmKeyFetcher, verifierClient verifier.Client, principalFetcher principalIDTokenFetcher, sigsFetcher signaturediscovery.Fetcher, launchSpec spec.LaunchSpec, logger logging.Logger) (AttestationAgent, error) {
// Fetched the AK and save it, so the agent doesn't need to create a new key everytime
ak, err := akFetcher(tpm)
if err != nil {
Expand Down Expand Up @@ -139,15 +139,15 @@ func (a *agent) Attest(ctx context.Context, opts AttestAgentOpts) ([]byte, error
signatures := a.sigsCache.get()
if len(signatures) > 0 {
req.ContainerImageSignatures = signatures
a.logger.Printf("Found container image signatures: %v\n", signatures)
a.logger.Info("Found container image signatures: %v\n", "signatures", signatures)
}

resp, err := a.client.VerifyAttestation(ctx, req)
if err != nil {
return nil, err
}
if len(resp.PartialErrs) > 0 {
a.logger.Printf("Partial errors from VerifyAttestation: %v", resp.PartialErrs)
a.logger.Error(fmt.Sprintf("Partial errors from VerifyAttestation: %v", resp.PartialErrs))
}
return resp.ClaimsToken, nil
}
Expand All @@ -163,11 +163,11 @@ func (a *agent) attest(nonce []byte, cel []byte) (*pb.Attestation, error) {
func (a *agent) Refresh(ctx context.Context) error {
signatures := fetchContainerImageSignatures(ctx, a.sigsFetcher, a.launchSpec.SignedImageRepos, defaultRetryPolicy, a.logger)
a.sigsCache.set(signatures)
a.logger.Printf("Refreshed container image signature cache: %v\n", signatures)
a.logger.Info("Refreshed container image signature cache", "signatures", signatures)
return nil
}

func fetchContainerImageSignatures(ctx context.Context, fetcher signaturediscovery.Fetcher, targetRepos []string, retry func() backoff.BackOff, logger *log.Logger) []oci.Signature {
func fetchContainerImageSignatures(ctx context.Context, fetcher signaturediscovery.Fetcher, targetRepos []string, retry func() backoff.BackOff, logger logging.Logger) []oci.Signature {
signatures := make([][]oci.Signature, len(targetRepos))

var wg sync.WaitGroup
Expand All @@ -186,10 +186,10 @@ func fetchContainerImageSignatures(ctx context.Context, fetcher signaturediscove
},
retry(),
func(err error, _ time.Duration) {
logger.Printf("Failed to fetch container image signatures from repo %q: %v", targetRepo, err)
logger.Error(fmt.Sprintf("Failed to fetch container image signatures from repo: %v", err.Error()), "repo", targetRepo)
})
if err != nil {
logger.Printf("Failed all attempts to refresh container signatures from repo %q: %v", targetRepo, err)
logger.Error(fmt.Sprintf("Failed all attempts to refresh container signatures from repo: %v", err.Error()), "repo", targetRepo)
} else {
signatures[index] = sigs
}
Expand Down
14 changes: 7 additions & 7 deletions launcher/agent/agent_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,6 @@ import (
"crypto/rsa"
"encoding/base64"
"fmt"
"log"
"math"
"runtime"
"sync"
Expand All @@ -19,6 +18,7 @@ import (
"github.com/google/go-tpm-tools/cel"
"github.com/google/go-tpm-tools/client"
"github.com/google/go-tpm-tools/internal/test"
"github.com/google/go-tpm-tools/launcher/internal/logging"
"github.com/google/go-tpm-tools/launcher/internal/signaturediscovery"
"github.com/google/go-tpm-tools/launcher/spec"
attestpb "github.com/google/go-tpm-tools/proto/attest"
Expand Down Expand Up @@ -59,7 +59,7 @@ func TestAttestRacing(t *testing.T) {
}

verifierClient := fake.NewClient(fakeSigner)
agent, err := CreateAttestationAgent(tpm, client.AttestationKeyECC, verifierClient, placeholderPrincipalFetcher, signaturediscovery.NewFakeClient(), spec.LaunchSpec{}, log.Default())
agent, err := CreateAttestationAgent(tpm, client.AttestationKeyECC, verifierClient, placeholderPrincipalFetcher, signaturediscovery.NewFakeClient(), spec.LaunchSpec{}, logging.SimpleLogger())
if err != nil {
t.Fatal(err)
}
Expand Down Expand Up @@ -111,9 +111,9 @@ func TestAttest(t *testing.T) {

verifierClient := fake.NewClient(fakeSigner)

agent, err := CreateAttestationAgent(tpm, client.AttestationKeyECC, verifierClient, tc.principalIDTokenFetcher, tc.containerSignaturesFetcher, tc.launchSpec, log.Default())
agent, err := CreateAttestationAgent(tpm, client.AttestationKeyECC, verifierClient, tc.principalIDTokenFetcher, tc.containerSignaturesFetcher, tc.launchSpec, logging.SimpleLogger())
if err != nil {
t.Fatalf("falied to create an attestation agent %v", err)
t.Fatalf("failed to create an attestation agent %v", err)
}
err = measureFakeEvents(agent)
if err != nil {
Expand Down Expand Up @@ -291,7 +291,7 @@ func TestFetchContainerImageSignatures(t *testing.T) {
}

sdClient := signaturediscovery.NewFakeClient()
gotSigs := fetchContainerImageSignatures(ctx, sdClient, tc.targetRepos, testRetryPolicy, log.Default())
gotSigs := fetchContainerImageSignatures(ctx, sdClient, tc.targetRepos, testRetryPolicy, logging.SimpleLogger())
if len(gotSigs) != len(tc.wantBase64Sigs) {
t.Errorf("fetchContainerImageSignatures did not return expected signatures for test case %s, got signatures length %d, but want %d", tc.name, len(gotSigs), len(tc.wantBase64Sigs))
}
Expand Down Expand Up @@ -498,7 +498,7 @@ func TestFetchContainerImageSignatures_RetriesOnFailure(t *testing.T) {
}
}

gotSigs := fetchContainerImageSignatures(ctx, sdClient, repos, retryPolicy, log.Default())
gotSigs := fetchContainerImageSignatures(ctx, sdClient, repos, retryPolicy, logging.SimpleLogger())

if len(gotSigs) != len(wantSigs) {
t.Errorf("fetchContainerImageSignatures did not return expected signatures for test case %s, got signatures length %d, but want %d", tc.name, len(gotSigs), len(wantSigs))
Expand Down Expand Up @@ -591,7 +591,7 @@ func TestWithAgent(t *testing.T) {
tpm := test.GetTPM(t)
defer client.CheckedClose(t, tpm)

agent, err := CreateAttestationAgent(tpm, client.AttestationKeyECC, vClient, testPrincipalIDTokenFetcher, signaturediscovery.NewFakeClient(), spec.LaunchSpec{}, log.Default())
agent, err := CreateAttestationAgent(tpm, client.AttestationKeyECC, vClient, testPrincipalIDTokenFetcher, signaturediscovery.NewFakeClient(), spec.LaunchSpec{}, logging.SimpleLogger())
if err != nil {
t.Fatalf("failed to create an attestation agent %v", err)
}
Expand Down
Loading

0 comments on commit c891518

Please sign in to comment.