Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Improve SVID signing logs with more context #2678

Merged
merged 5 commits into from
Jan 14, 2022
Merged

Improve SVID signing logs with more context #2678

Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
e5d4c43
Improve SVID signing logs with more context
Jan 12, 2022
e2f989e
Remove expires_at field from MintX509SVID method
Jan 13, 2022
368434f
Merge branch 'main' into improve-svid-signing-logs
Jan 13, 2022
5c45902
Merge branch 'main' into improve-svid-signing-logs
azdagron Jan 14, 2022
f585e3b
Merge branch 'main' into improve-svid-signing-logs
azdagron Jan 14, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
30 changes: 26 additions & 4 deletions pkg/server/api/svid/v1/service.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -112,13 +112,22 @@ func (s *Service) MintX509SVID(ctx context.Context, req *svidv1.MintX509SVIDRequ
if err != nil {
return nil, api.MakeErr(log, codes.Internal, "failed to sign X509-SVID", err)
}
rpccontext.AuditRPCWithFields(ctx, logrus.Fields{
telemetry.SPIFFEID: id.String(),
telemetry.DNSName: strings.Join(csr.DNSNames, ","),
telemetry.Subject: csr.Subject,

commonX509SVIDLogFields := logrus.Fields{
telemetry.SPIFFEID: id.String(),
telemetry.DNSName: strings.Join(csr.DNSNames, ","),
telemetry.Subject: csr.Subject,
}

rpccontext.AddRPCAuditFields(ctx, logrus.Fields{
telemetry.ExpiresAt: x509SVID[0].NotAfter.Unix(),
})

rpccontext.AuditRPCWithFields(ctx, commonX509SVIDLogFields)
log.WithField(telemetry.Expiration, x509SVID[0].NotAfter.Format(time.RFC3339)).
rturner3 marked this conversation as resolved.
Show resolved Hide resolved
WithFields(commonX509SVIDLogFields).
Debug("Signed X509 SVID")

return &svidv1.MintX509SVIDResponse{
Svid: &types.X509SVID{
Id: api.ProtoFromID(id),
Expand Down Expand Up @@ -258,6 +267,9 @@ func (s *Service) newX509SVID(ctx context.Context, param *svidv1.NewX509SVIDPara
}
}

log.WithField(telemetry.Expiration, x509Svid[0].NotAfter.Format(time.RFC3339)).
Debug("Signed X509 SVID")

return &svidv1.BatchNewX509SVIDResponse_Result{
Svid: &types.X509SVID{
Id: entry.SpiffeId,
Expand Down Expand Up @@ -300,6 +312,11 @@ func (s *Service) mintJWTSVID(ctx context.Context, protoID *types.SPIFFEID, audi
return nil, api.MakeErr(log, codes.Internal, "failed to get JWT-SVID expiry", err)
}

log.WithFields(logrus.Fields{
telemetry.Audience: audience,
telemetry.Expiration: expiresAt.Format(time.RFC3339),
}).Debug("Server CA successfully signed JWT SVID")
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Wonder if we shouldn't take this opportunity to change this log line to be consistent with the others?

Suggested change
}).Debug("Server CA successfully signed JWT SVID")
}).Debug("Signed JWT SVID")

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I guess I feel inclined to keep the message the same as it is today since the proposed change in wording is semantically equivalent. I would prefer to err on the side of preserving the existing message text that users are already familiar with to prevent potentially breaking any log-based alerting.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair 'nough!


return &types.JWTSVID{
Token: token,
Id: api.ProtoFromID(id),
Expand Down Expand Up @@ -375,6 +392,11 @@ func (s *Service) NewDownstreamX509CA(ctx context.Context, req *svidv1.NewDownst
return nil, api.MakeErr(log, codes.Internal, "failed to sign downstream X.509 CA", err)
}

log.WithFields(logrus.Fields{
telemetry.SPIFFEID: x509CASvid[0].URIs[0].String(),
telemetry.Expiration: x509CASvid[0].NotAfter.Format(time.RFC3339),
}).Debug("Signed X509 CA SVID")

bundle, err := s.ds.FetchBundle(ctx, s.td.IDString())
if err != nil {
return nil, api.MakeErr(log, codes.Internal, "failed to fetch bundle", err)
Expand Down
22 changes: 0 additions & 22 deletions pkg/server/ca/ca.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -199,15 +199,6 @@ func (ca *CA) SignX509SVID(ctx context.Context, params X509SVIDParams) ([]*x509.
return nil, err
}

spiffeID := x509SVID[0].URIs[0].String()

if !health.IsCheck(ctx) {
ca.c.Log.WithFields(logrus.Fields{
telemetry.SPIFFEID: spiffeID,
telemetry.Expiration: x509SVID[0].NotAfter.Format(time.RFC3339),
}).Debug("Signed X509 SVID")
}

telemetry_server.IncrServerCASignX509Counter(ca.c.Metrics)
return x509SVID, nil
}
Expand Down Expand Up @@ -248,13 +239,6 @@ func (ca *CA) SignX509CASVID(ctx context.Context, params X509CASVIDParams) ([]*x
return nil, errs.New("unable to create X509 CA SVID: %v", err)
}

spiffeID := cert.URIs[0].String()

ca.c.Log.WithFields(logrus.Fields{
telemetry.SPIFFEID: spiffeID,
telemetry.Expiration: cert.NotAfter.Format(time.RFC3339),
}).Debug("Signed X509 CA SVID")

telemetry_server.IncrServerCASignX509CACounter(ca.c.Metrics)

return makeSVIDCertChain(x509CA, cert), nil
Expand Down Expand Up @@ -282,12 +266,6 @@ func (ca *CA) SignJWTSVID(ctx context.Context, params JWTSVIDParams) (string, er
}

telemetry_server.IncrServerCASignJWTSVIDCounter(ca.c.Metrics)
ca.c.Log.WithFields(logrus.Fields{
telemetry.Audience: params.Audience,
telemetry.Expiration: expiresAt.Format(time.RFC3339),
telemetry.SPIFFEID: params.SpiffeID,
}).Debug("Server CA successfully signed JWT SVID")

return token, nil
}

Expand Down
1 change: 0 additions & 1 deletion pkg/server/server.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -250,7 +250,6 @@ func (s *Server) loadCatalog(ctx context.Context, metrics telemetry.Metrics, ide

func (s *Server) newCA(metrics telemetry.Metrics, healthChecker health.Checker) *ca.CA {
return ca.NewCA(ca.Config{
Log: s.config.Log.WithField(telemetry.SubsystemName, telemetry.CA),
Metrics: metrics,
X509SVIDTTL: s.config.SVIDTTL,
JWTIssuer: s.config.JWTIssuer,
Expand Down
7 changes: 7 additions & 0 deletions pkg/server/svid/rotator.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,9 @@ import (
"time"

"github.com/imkira/go-observer"
"github.com/sirupsen/logrus"
"github.com/spiffe/spire/pkg/common/idutil"
"github.com/spiffe/spire/pkg/common/telemetry"
telemetry_server "github.com/spiffe/spire/pkg/common/telemetry/server"
"github.com/spiffe/spire/pkg/server/ca"
)
Expand Down Expand Up @@ -94,6 +96,11 @@ func (r *Rotator) rotateSVID(ctx context.Context) (err error) {
return err
}

r.c.Log.WithFields(logrus.Fields{
telemetry.SPIFFEID: svid[0].URIs[0].String(),
telemetry.Expiration: svid[0].NotAfter.Format(time.RFC3339),
}).Debug("Signed X509 SVID")

r.state.Update(State{
SVID: svid,
Key: signer,
Expand Down