Merge pull request #607 from nrb/restore-metrics

Restore metrics
This commit is contained in:
Steve Kriss
2018-07-27 12:25:56 -07:00
committed by GitHub
6 changed files with 173 additions and 28 deletions
+7
View File
@@ -85,6 +85,10 @@ const (
// RestorePhaseCompleted means the restore has finished executing.
// Any relevant warnings or errors will be captured in the Status.
RestorePhaseCompleted RestorePhase = "Completed"
// RestorePhaseFailed means the restore was unable to execute.
// The failing error is recorded in status.FailureReason.
RestorePhaseFailed RestorePhase = "Failed"
)
// RestoreStatus captures the current status of an Ark restore
@@ -103,6 +107,9 @@ type RestoreStatus struct {
// Errors is a count of all error messages that were generated during
// execution of the restore. The actual errors are stored in object storage.
Errors int `json:"errors"`
// FailureReason is an error that caused the entire restore to fail.
FailureReason string `json:"failureReason"`
}
// RestoreResult is a collection of messages that were generated
+1
View File
@@ -726,6 +726,7 @@ func (s *server) runControllers(config *api.Config) error {
s.snapshotService != nil,
s.logger,
s.pluginManager,
s.metrics,
)
wg.Add(1)
go func() {
+40 -9
View File
@@ -45,6 +45,7 @@ import (
arkv1client "github.com/heptio/ark/pkg/generated/clientset/versioned/typed/ark/v1"
informers "github.com/heptio/ark/pkg/generated/informers/externalversions/ark/v1"
listers "github.com/heptio/ark/pkg/generated/listers/ark/v1"
"github.com/heptio/ark/pkg/metrics"
"github.com/heptio/ark/pkg/plugin"
"github.com/heptio/ark/pkg/restore"
"github.com/heptio/ark/pkg/util/boolptr"
@@ -84,6 +85,7 @@ type restoreController struct {
queue workqueue.RateLimitingInterface
logger logrus.FieldLogger
pluginManager plugin.Manager
metrics *metrics.ServerMetrics
}
func NewRestoreController(
@@ -98,6 +100,7 @@ func NewRestoreController(
pvProviderExists bool,
logger logrus.FieldLogger,
pluginManager plugin.Manager,
metrics *metrics.ServerMetrics,
) Interface {
c := &restoreController{
namespace: namespace,
@@ -114,6 +117,7 @@ func NewRestoreController(
queue: workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), "restore"),
logger: logger,
pluginManager: pluginManager,
metrics: metrics,
}
c.syncHandler = c.processRestore
@@ -255,13 +259,17 @@ func (c *restoreController) processRestore(key string) error {
// don't modify items in the cache
restore = restore.DeepCopy()
// complete & validate restore
// validation
if restore.Status.ValidationErrors = c.completeAndValidate(restore); len(restore.Status.ValidationErrors) > 0 {
restore.Status.Phase = api.RestorePhaseFailedValidation
} else {
restore.Status.Phase = api.RestorePhaseInProgress
}
backupScheduleName := restore.Spec.ScheduleName
// Register attempts after validation so we don't have to fetch the backup multiple times
c.metrics.RegisterRestoreAttempt(backupScheduleName)
// update status
updatedRestore, err := patchRestore(original, restore, c.restoreClient)
if err != nil {
@@ -272,12 +280,12 @@ func (c *restoreController) processRestore(key string) error {
restore = updatedRestore.DeepCopy()
if restore.Status.Phase == api.RestorePhaseFailedValidation {
c.metrics.RegisterRestoreValidationFailed(backupScheduleName)
return nil
}
logContext.Debug("Running restore")
// execution & upload of restore
restoreWarnings, restoreErrors := c.runRestore(restore, c.bucket)
restoreWarnings, restoreErrors, restoreFailure := c.runRestore(restore, c.bucket)
restore.Status.Warnings = len(restoreWarnings.Ark) + len(restoreWarnings.Cluster)
for _, w := range restoreWarnings.Namespaces {
@@ -289,8 +297,17 @@ func (c *restoreController) processRestore(key string) error {
restore.Status.Errors += len(e)
}
logContext.Debug("restore completed")
restore.Status.Phase = api.RestorePhaseCompleted
if restoreFailure != nil {
logContext.Debug("restore failed")
restore.Status.Phase = api.RestorePhaseFailed
restore.Status.FailureReason = restoreFailure.Error()
c.metrics.RegisterRestoreFailed(backupScheduleName)
} else {
logContext.Debug("restore completed")
// We got through the restore process without failing validation or restore execution
restore.Status.Phase = api.RestorePhaseCompleted
c.metrics.RegisterRestoreSuccess(backupScheduleName)
}
logContext.Debug("Updating Restore final status")
if _, err = patchRestore(original, restore, c.restoreClient); err != nil {
@@ -308,7 +325,6 @@ func (c *restoreController) completeAndValidate(restore *api.Restore) []string {
restore.Spec.ExcludedResources = append(restore.Spec.ExcludedResources, nonrestorable)
}
}
var validationErrors []string
// validate that included resources don't contain any non-restorable resources
@@ -361,11 +377,19 @@ func (c *restoreController) completeAndValidate(restore *api.Restore) []string {
}
}
// validate that we can fetch the source backup
if _, err := c.fetchBackup(c.bucket, restore.Spec.BackupName); err != nil {
var (
backup *api.Backup
err error
)
if backup, err = c.fetchBackup(c.bucket, restore.Spec.BackupName); err != nil {
return append(validationErrors, fmt.Sprintf("Error retrieving backup: %v", err))
}
// Fill in the ScheduleName so it's easier to consume for metrics.
if restore.Spec.ScheduleName == "" {
restore.Spec.ScheduleName = backup.GetLabels()["ark-schedule"]
}
return validationErrors
}
@@ -433,7 +457,7 @@ func (c *restoreController) fetchBackup(bucket, name string) (*api.Backup, error
return backup, nil
}
func (c *restoreController) runRestore(restore *api.Restore, bucket string) (restoreWarnings, restoreErrors api.RestoreResult) {
func (c *restoreController) runRestore(restore *api.Restore, bucket string) (restoreWarnings, restoreErrors api.RestoreResult, restoreFailure error) {
logContext := c.logger.WithFields(
logrus.Fields{
"restore": kubeutil.NamespaceAndName(restore),
@@ -453,6 +477,7 @@ func (c *restoreController) runRestore(restore *api.Restore, bucket string) (res
if err != nil {
logContext.WithError(err).Error("Error downloading backup")
restoreErrors.Ark = append(restoreErrors.Ark, err.Error())
restoreFailure = err
return
}
tempFiles = append(tempFiles, backupFile)
@@ -461,6 +486,7 @@ func (c *restoreController) runRestore(restore *api.Restore, bucket string) (res
if err != nil {
logContext.WithError(errors.WithStack(err)).Error("Error creating log temp file")
restoreErrors.Ark = append(restoreErrors.Ark, err.Error())
restoreFailure = err
return
}
tempFiles = append(tempFiles, logFile)
@@ -469,6 +495,7 @@ func (c *restoreController) runRestore(restore *api.Restore, bucket string) (res
if err != nil {
logContext.WithError(errors.WithStack(err)).Error("Error creating results temp file")
restoreErrors.Ark = append(restoreErrors.Ark, err.Error())
restoreFailure = err
return
}
tempFiles = append(tempFiles, resultsFile)
@@ -477,10 +504,12 @@ func (c *restoreController) runRestore(restore *api.Restore, bucket string) (res
for _, file := range tempFiles {
if err := file.Close(); err != nil {
logContext.WithError(errors.WithStack(err)).WithField("file", file.Name()).Error("Error closing file")
restoreFailure = err
}
if err := os.Remove(file.Name()); err != nil {
logContext.WithError(errors.WithStack(err)).WithField("file", file.Name()).Error("Error removing file")
restoreFailure = err
}
}
}()
@@ -492,6 +521,8 @@ func (c *restoreController) runRestore(restore *api.Restore, bucket string) (res
}
defer c.pluginManager.CloseRestoreItemActions(restore.Name)
// Any return statement above this line means a total restore failure
// Some failures after this line *may* be a total restore failure
logContext.Info("starting restore")
restoreWarnings, restoreErrors = c.restorer.Restore(restore, backup, backupFile, logFile, actions)
logContext.Info("restore completed")
+40 -14
View File
@@ -37,6 +37,7 @@ import (
api "github.com/heptio/ark/pkg/apis/ark/v1"
"github.com/heptio/ark/pkg/generated/clientset/versioned/fake"
informers "github.com/heptio/ark/pkg/generated/informers/externalversions"
"github.com/heptio/ark/pkg/metrics"
"github.com/heptio/ark/pkg/restore"
"github.com/heptio/ark/pkg/util/collections"
arktest "github.com/heptio/ark/pkg/util/test"
@@ -95,6 +96,7 @@ func TestFetchBackup(t *testing.T) {
false,
logger,
pluginManager,
metrics.NewServerMetrics(),
).(*restoreController)
for _, itm := range test.informerBackups {
@@ -118,19 +120,21 @@ func TestFetchBackup(t *testing.T) {
func TestProcessRestore(t *testing.T) {
tests := []struct {
name string
restoreKey string
restore *api.Restore
backup *api.Backup
restorerError error
allowRestoreSnapshots bool
expectedErr bool
expectedPhase string
expectedValidationErrors []string
expectedRestoreErrors int
expectedRestorerCall *api.Restore
backupServiceGetBackupError error
uploadLogError error
name string
restoreKey string
restore *api.Restore
backup *api.Backup
restorerError error
allowRestoreSnapshots bool
expectedErr bool
expectedPhase string
expectedValidationErrors []string
expectedRestoreErrors int
expectedRestorerCall *api.Restore
backupServiceGetBackupError error
uploadLogError error
backupServiceDownloadBackupError error
expectedFinalPhase string
}{
{
name: "invalid key returns error",
@@ -298,6 +302,14 @@ func TestProcessRestore(t *testing.T) {
"Invalid included/excluded resource lists: excludes list cannot contain an item in the includes list: restores.ark.heptio.com",
},
},
{
name: "backup download error results in failed restore",
restore: NewRestore("foo", "bar", "backup-1", "ns-1", "", api.RestorePhaseNew).Restore,
expectedPhase: string(api.RestorePhaseInProgress),
expectedFinalPhase: string(api.RestorePhaseFailed),
backupServiceDownloadBackupError: errors.New("Couldn't download backup"),
backup: arktest.NewTestBackup().WithName("backup-1").Backup,
},
}
for _, test := range tests {
@@ -326,6 +338,7 @@ func TestProcessRestore(t *testing.T) {
test.allowRestoreSnapshots,
logger,
pluginManager,
metrics.NewServerMetrics(),
).(*restoreController)
if test.restore != nil {
@@ -400,6 +413,10 @@ func TestProcessRestore(t *testing.T) {
backupSvc.On("GetBackup", "bucket", mock.Anything).Return(nil, test.backupServiceGetBackupError)
}
if test.backupServiceDownloadBackupError != nil {
backupSvc.On("DownloadBackup", "bucket", test.restore.Spec.BackupName).Return(nil, test.backupServiceDownloadBackupError)
}
if test.restore != nil {
pluginManager.On("GetRestoreItemActions", test.restore.Name).Return(nil, nil)
pluginManager.On("CloseRestoreItemActions", test.restore.Name).Return(nil)
@@ -410,7 +427,6 @@ func TestProcessRestore(t *testing.T) {
restorer.AssertExpectations(t)
assert.Equal(t, test.expectedErr, err != nil, "got error %v", err)
actions := client.Actions()
if test.expectedPhase == "" {
@@ -475,6 +491,15 @@ func TestProcessRestore(t *testing.T) {
Errors: test.expectedRestoreErrors,
},
}
// Override our default expectations if the case requires it
if test.expectedFinalPhase != "" {
expected = Patch{
Status: StatusPatch{
Phase: api.RestorePhaseCompleted,
Errors: test.expectedRestoreErrors,
},
}
}
arktest.ValidatePatch(t, actions[1], expected, decode)
@@ -505,6 +530,7 @@ func TestCompleteAndValidateWhenScheduleNameSpecified(t *testing.T) {
false,
logger,
nil,
nil,
).(*restoreController)
restore := &api.Restore{
+83 -5
View File
@@ -30,12 +30,18 @@ type ServerMetrics struct {
const (
metricNamespace = "ark"
backupTarballSizeBytesGauge = "backup_tarball_size_bytes"
backupAttemptCount = "backup_attempt_total"
backupSuccessCount = "backup_success_total"
backupFailureCount = "backup_failure_total"
backupDurationSeconds = "backup_duration_seconds"
// TODO: Rename the Count variables to match their strings
backupAttemptCount = "backup_attempt_total"
backupSuccessCount = "backup_success_total"
backupFailureCount = "backup_failure_total"
backupDurationSeconds = "backup_duration_seconds"
restoreAttemptTotal = "restore_attempt_total"
restoreValidationFailedTotal = "restore_validation_failed_total"
restoreSuccessTotal = "restore_success_total"
restoreFailedTotal = "restore_failed_total"
scheduleLabel = "schedule"
scheduleLabel = "schedule"
backupNameLabel = "backupName"
secondsInMinute = 60.0
)
@@ -95,6 +101,38 @@ func NewServerMetrics() *ServerMetrics {
},
[]string{scheduleLabel},
),
restoreAttemptTotal: prometheus.NewCounterVec(
prometheus.CounterOpts{
Namespace: metricNamespace,
Name: restoreAttemptTotal,
Help: "Total number of attempted restores",
},
[]string{scheduleLabel},
),
restoreSuccessTotal: prometheus.NewCounterVec(
prometheus.CounterOpts{
Namespace: metricNamespace,
Name: restoreSuccessTotal,
Help: "Total number of successful restores",
},
[]string{scheduleLabel},
),
restoreFailedTotal: prometheus.NewCounterVec(
prometheus.CounterOpts{
Namespace: metricNamespace,
Name: restoreFailedTotal,
Help: "Total number of failed restores",
},
[]string{scheduleLabel},
),
restoreValidationFailedTotal: prometheus.NewCounterVec(
prometheus.CounterOpts{
Namespace: metricNamespace,
Name: restoreValidationFailedTotal,
Help: "Total number of failed restores failing validations",
},
[]string{scheduleLabel},
),
},
}
}
@@ -116,6 +154,18 @@ func (m *ServerMetrics) InitSchedule(scheduleName string) {
if c, ok := m.metrics[backupFailureCount].(*prometheus.CounterVec); ok {
c.WithLabelValues(scheduleName).Set(0)
}
if c, ok := m.metrics[restoreAttemptTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(scheduleName).Set(0)
}
if c, ok := m.metrics[restoreFailedTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(scheduleName).Set(0)
}
if c, ok := m.metrics[restoreSuccessTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(scheduleName).Set(0)
}
if c, ok := m.metrics[restoreValidationFailedTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(scheduleName).Set(0)
}
}
// SetBackupTarballSizeBytesGauge records the size, in bytes, of a backup tarball.
@@ -158,3 +208,31 @@ func (m *ServerMetrics) RegisterBackupDuration(backupSchedule string, seconds fl
func toSeconds(d time.Duration) float64 {
return float64(d / time.Second)
}
// RegisterRestoreAttempt records an attempt to restore a backup.
func (m *ServerMetrics) RegisterRestoreAttempt(backupSchedule string) {
if c, ok := m.metrics[restoreAttemptTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(backupSchedule).Inc()
}
}
// RegisterRestoreSuccess records a successful (maybe partial) completion of a restore.
func (m *ServerMetrics) RegisterRestoreSuccess(backupSchedule string) {
if c, ok := m.metrics[restoreSuccessTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(backupSchedule).Inc()
}
}
// RegisterRestoreFailed records a restore that failed.
func (m *ServerMetrics) RegisterRestoreFailed(backupSchedule string) {
if c, ok := m.metrics[restoreFailedTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(backupSchedule).Inc()
}
}
// RegisterRestoreValidationFailed records a restore that failed validation.
func (m *ServerMetrics) RegisterRestoreValidationFailed(backupSchedule string) {
if c, ok := m.metrics[restoreValidationFailedTotal].(*prometheus.CounterVec); ok {
c.WithLabelValues(backupSchedule).Inc()
}
}
+2
View File
@@ -103,6 +103,8 @@ func AssertDeepEqual(t *testing.T, expected, actual interface{}) bool {
}
if !equality.Semantic.DeepEqual(expected, actual) {
fmt.Printf("expected = %+v\n", expected)
fmt.Printf("actual = %+v\n", actual)
return assert.Fail(t, fmt.Sprintf("Objects not equal"))
}