Merge pull request #101252 from smarterclayton/certificate_logging_upstream

Add type logging to certificate manager
This commit is contained in:
Kubernetes Prow Robot 2021-04-27 08:59:37 -07:00 committed by GitHub
commit 4f36038c0b
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 67 additions and 26 deletions

View File

@ -124,6 +124,14 @@ type Config struct {
// CertifcateRenewFailure will record a metric that keeps track of
// certificate renewal failures.
CertificateRenewFailure Counter
// Name is an optional string that will be used when writing log output
// or returning errors from manager methods. If not set, SignerName will
// be used, if SignerName is not set, if Usages includes client auth the
// name will be "client auth", otherwise the value will be "server".
Name string
// Logf is an optional function that log output will be sent to from the
// certificate manager. If not set it will use klog.V(2)
Logf func(format string, args ...interface{})
}
// Store is responsible for getting and updating the current certificate.
@ -199,6 +207,9 @@ type manager struct {
// Set to time.Now but can be stubbed out for testing
now func() time.Time
name string
logf func(format string, args ...interface{})
}
// NewManager returns a new certificate manager. A certificate manager is
@ -233,6 +244,25 @@ func NewManager(config *Config) (Manager, error) {
now: time.Now,
}
name := config.Name
if len(name) == 0 {
name = m.signerName
}
if len(name) == 0 {
switch {
case hasKeyUsage(config.Usages, certificates.UsageClientAuth):
name = string(certificates.UsageClientAuth)
default:
name = "certificate"
}
}
m.name = name
m.logf = config.Logf
if m.logf == nil {
m.logf = func(format string, args ...interface{}) { klog.V(2).Infof(format, args...) }
}
return &m, nil
}
@ -244,7 +274,7 @@ func (m *manager) Current() *tls.Certificate {
m.certAccessLock.RLock()
defer m.certAccessLock.RUnlock()
if m.cert != nil && m.cert.Leaf != nil && m.now().After(m.cert.Leaf.NotAfter) {
klog.V(2).Infof("Current certificate is expired.")
m.logf("%s: Current certificate is expired", m.name)
return nil
}
return m.cert
@ -275,17 +305,16 @@ func (m *manager) Start() {
// signing API, so don't start the certificate manager if we don't have a
// client.
if m.clientsetFn == nil {
klog.V(2).Infof("Certificate rotation is not enabled, no connection to the apiserver.")
m.logf("%s: Certificate rotation is not enabled, no connection to the apiserver", m.name)
return
}
klog.V(2).Infof("Certificate rotation is enabled.")
m.logf("%s: Certificate rotation is enabled", m.name)
templateChanged := make(chan struct{})
go wait.Until(func() {
deadline := m.nextRotationDeadline()
if sleepInterval := deadline.Sub(m.now()); sleepInterval > 0 {
klog.V(2).Infof("Waiting %v for next certificate rotation", sleepInterval)
m.logf("%s: Waiting %v for next certificate rotation", m.name, sleepInterval)
timer := time.NewTimer(sleepInterval)
defer timer.Stop()
@ -299,7 +328,7 @@ func (m *manager) Start() {
// if the template now matches what we last requested, restart the rotation deadline loop
return
}
klog.V(2).Infof("Certificate template changed, rotating")
m.logf("%s: Certificate template changed, rotating", m.name)
}
}
@ -315,7 +344,7 @@ func (m *manager) Start() {
Steps: 5,
}
if err := wait.ExponentialBackoff(backoff, m.rotateCerts); err != nil {
utilruntime.HandleError(fmt.Errorf("Reached backoff limit, still unable to rotate certs: %v", err))
utilruntime.HandleError(fmt.Errorf("%s: Reached backoff limit, still unable to rotate certs: %v", m.name, err))
wait.PollInfinite(32*time.Second, m.rotateCerts)
}
}, time.Second, m.stopCh)
@ -381,8 +410,6 @@ func getCurrentCertificateOrBootstrap(
if _, err := store.Update(bootstrapCertificatePEM, bootstrapKeyPEM); err != nil {
utilruntime.HandleError(fmt.Errorf("Unable to set the cert/key pair to the bootstrap certificate: %v", err))
} else {
klog.V(4).Infof("Updated the store to contain the initial bootstrap certificate")
}
return &bootstrapCert, true, nil
@ -409,11 +436,11 @@ func (m *manager) RotateCerts() (bool, error) {
// from the server on the various calls it makes.
// TODO: return errors, have callers handle and log them correctly
func (m *manager) rotateCerts() (bool, error) {
klog.V(2).Infof("Rotating certificates")
m.logf("%s: Rotating certificates", m.name)
template, csrPEM, keyPEM, privateKey, err := m.generateCSR()
if err != nil {
utilruntime.HandleError(fmt.Errorf("Unable to generate a certificate signing request: %v", err))
utilruntime.HandleError(fmt.Errorf("%s: Unable to generate a certificate signing request: %v", m.name, err))
if m.certificateRenewFailure != nil {
m.certificateRenewFailure.Inc()
}
@ -423,7 +450,7 @@ func (m *manager) rotateCerts() (bool, error) {
// request the client each time
clientSet, err := m.getClientset()
if err != nil {
utilruntime.HandleError(fmt.Errorf("Unable to load a client to request certificates: %v", err))
utilruntime.HandleError(fmt.Errorf("%s: Unable to load a client to request certificates: %v", m.name, err))
if m.certificateRenewFailure != nil {
m.certificateRenewFailure.Inc()
}
@ -434,7 +461,7 @@ func (m *manager) rotateCerts() (bool, error) {
// new private key.
reqName, reqUID, err := csr.RequestCertificate(clientSet, csrPEM, "", m.signerName, m.usages, privateKey)
if err != nil {
utilruntime.HandleError(fmt.Errorf("Failed while requesting a signed certificate from the master: %v", err))
utilruntime.HandleError(fmt.Errorf("%s: Failed while requesting a signed certificate from the control plane: %v", m.name, err))
if m.certificateRenewFailure != nil {
m.certificateRenewFailure.Inc()
}
@ -451,7 +478,7 @@ func (m *manager) rotateCerts() (bool, error) {
// is a remainder after the old design using raw watch wrapped with backoff.
crtPEM, err := csr.WaitForCertificate(ctx, clientSet, reqName, reqUID)
if err != nil {
utilruntime.HandleError(fmt.Errorf("certificate request was not signed: %v", err))
utilruntime.HandleError(fmt.Errorf("%s: certificate request was not signed: %v", m.name, err))
if m.certificateRenewFailure != nil {
m.certificateRenewFailure.Inc()
}
@ -460,7 +487,7 @@ func (m *manager) rotateCerts() (bool, error) {
cert, err := m.certStore.Update(crtPEM, keyPEM)
if err != nil {
utilruntime.HandleError(fmt.Errorf("Unable to store the new cert/key pair: %v", err))
utilruntime.HandleError(fmt.Errorf("%s: Unable to store the new cert/key pair: %v", m.name, err))
if m.certificateRenewFailure != nil {
m.certificateRenewFailure.Inc()
}
@ -488,7 +515,7 @@ func (m *manager) certSatisfiesTemplateLocked() bool {
if template := m.getTemplate(); template != nil {
if template.Subject.CommonName != m.cert.Leaf.Subject.CommonName {
klog.V(2).Infof("Current certificate CN (%s) does not match requested CN (%s)", m.cert.Leaf.Subject.CommonName, template.Subject.CommonName)
m.logf("%s: Current certificate CN (%s) does not match requested CN (%s)", m.name, m.cert.Leaf.Subject.CommonName, template.Subject.CommonName)
return false
}
@ -496,7 +523,7 @@ func (m *manager) certSatisfiesTemplateLocked() bool {
desiredDNSNames := sets.NewString(template.DNSNames...)
missingDNSNames := desiredDNSNames.Difference(currentDNSNames)
if len(missingDNSNames) > 0 {
klog.V(2).Infof("Current certificate is missing requested DNS names %v", missingDNSNames.List())
m.logf("%s: Current certificate is missing requested DNS names %v", m.name, missingDNSNames.List())
return false
}
@ -510,7 +537,7 @@ func (m *manager) certSatisfiesTemplateLocked() bool {
}
missingIPs := desiredIPs.Difference(currentIPs)
if len(missingIPs) > 0 {
klog.V(2).Infof("Current certificate is missing requested IP addresses %v", missingIPs.List())
m.logf("%s: Current certificate is missing requested IP addresses %v", m.name, missingIPs.List())
return false
}
@ -518,7 +545,7 @@ func (m *manager) certSatisfiesTemplateLocked() bool {
desiredOrgs := sets.NewString(template.Subject.Organization...)
missingOrgs := desiredOrgs.Difference(currentOrgs)
if len(missingOrgs) > 0 {
klog.V(2).Infof("Current certificate is missing requested orgs %v", missingOrgs.List())
m.logf("%s: Current certificate is missing requested orgs %v", m.name, missingOrgs.List())
return false
}
}
@ -553,7 +580,7 @@ func (m *manager) nextRotationDeadline() time.Time {
totalDuration := float64(notAfter.Sub(m.cert.Leaf.NotBefore))
deadline := m.cert.Leaf.NotBefore.Add(jitteryDuration(totalDuration))
klog.V(2).Infof("Certificate expiration is %v, rotation deadline is %v", notAfter, deadline)
m.logf("%s: Certificate expiration is %v, rotation deadline is %v", m.name, notAfter, deadline)
return deadline
}
@ -607,22 +634,22 @@ func (m *manager) generateCSR() (template *x509.CertificateRequest, csrPEM []byt
// Generate a new private key.
privateKey, err := ecdsa.GenerateKey(elliptic.P256(), cryptorand.Reader)
if err != nil {
return nil, nil, nil, nil, fmt.Errorf("unable to generate a new private key: %v", err)
return nil, nil, nil, nil, fmt.Errorf("%s: unable to generate a new private key: %v", m.name, err)
}
der, err := x509.MarshalECPrivateKey(privateKey)
if err != nil {
return nil, nil, nil, nil, fmt.Errorf("unable to marshal the new key to DER: %v", err)
return nil, nil, nil, nil, fmt.Errorf("%s: unable to marshal the new key to DER: %v", m.name, err)
}
keyPEM = pem.EncodeToMemory(&pem.Block{Type: keyutil.ECPrivateKeyBlockType, Bytes: der})
template = m.getTemplate()
if template == nil {
return nil, nil, nil, nil, fmt.Errorf("unable to create a csr, no template available")
return nil, nil, nil, nil, fmt.Errorf("%s: unable to create a csr, no template available", m.name)
}
csrPEM, err = cert.MakeCSRFromTemplate(privateKey, template)
if err != nil {
return nil, nil, nil, nil, fmt.Errorf("unable to create a csr from the private key: %v", err)
return nil, nil, nil, nil, fmt.Errorf("%s: unable to create a csr from the private key: %v", m.name, err)
}
return template, csrPEM, keyPEM, privateKey, nil
}
@ -639,3 +666,12 @@ func (m *manager) setLastRequest(cancel context.CancelFunc, r *x509.CertificateR
m.lastRequestCancel = cancel
m.lastRequest = r
}
func hasKeyUsage(usages []certificates.KeyUsage, usage certificates.KeyUsage) bool {
for _, u := range usages {
if u == usage {
return true
}
}
return false
}

View File

@ -277,6 +277,7 @@ func TestSetRotationDeadline(t *testing.T) {
getTemplate: func() *x509.CertificateRequest { return &x509.CertificateRequest{} },
usages: []certificatesv1.KeyUsage{},
now: func() time.Time { return now },
logf: t.Logf,
}
jitteryDuration = func(float64) time.Duration { return time.Duration(float64(tc.notAfter.Sub(tc.notBefore)) * 0.7) }
lowerBound := tc.notBefore.Add(time.Duration(float64(tc.notAfter.Sub(tc.notBefore)) * 0.7))
@ -449,6 +450,7 @@ func TestCertSatisfiesTemplate(t *testing.T) {
cert: tlsCert,
getTemplate: func() *x509.CertificateRequest { return tc.template },
now: time.Now,
logf: t.Logf,
}
result := m.certSatisfiesTemplate()
@ -473,7 +475,8 @@ func TestRotateCertCreateCSRError(t *testing.T) {
clientsetFn: func(_ *tls.Certificate) (clientset.Interface, error) {
return newClientset(fakeClient{failureType: createError}), nil
},
now: func() time.Time { return now },
now: func() time.Time { return now },
logf: t.Logf,
}
if success, err := m.rotateCerts(); success {
@ -497,7 +500,8 @@ func TestRotateCertWaitingForResultError(t *testing.T) {
clientsetFn: func(_ *tls.Certificate) (clientset.Interface, error) {
return newClientset(fakeClient{failureType: watchError}), nil
},
now: func() time.Time { return now },
now: func() time.Time { return now },
logf: t.Logf,
}
defer func(t time.Duration) { certificateWaitTimeout = t }(certificateWaitTimeout)
@ -1056,6 +1060,7 @@ func TestRotationLogsDuration(t *testing.T) {
},
certificateRotation: &h,
now: func() time.Time { return now },
logf: t.Logf,
}
ok, err := m.rotateCerts()
if err != nil || !ok {