Skip to content

Commit ce8c49b

Browse files
mergify[bot]cmacknz
mergify[bot]
and
cmacknz
authored
Improve logging for agent upgrades. (#1287) (#1310)
(cherry picked from commit 5225e54) Co-authored-by: Craig MacKenzie <craig.mackenzie@elastic.co>
1 parent b168e8e commit ce8c49b

12 files changed

Lines changed: 115 additions & 51 deletions

File tree

‎CHANGELOG.next.asciidoc‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -206,3 +206,4 @@
206206
- Fix incorrectly creating a filebeat redis input when a policy contains a packetbeat redis input. {issue}[427] {pull}[700]
207207
- Add `lumberjack` input type to the Filebeat spec. {pull}[959]
208208
- Add support for hints' based autodiscovery in kubernetes provider. {pull}[698]
209+
- Improve logging during upgrades. {pull}[1287]

‎internal/pkg/agent/application/pipeline/actions/handlers/handler_action_upgrade.go‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -39,6 +39,14 @@ func (h *Upgrade) Handle(ctx context.Context, a fleetapi.Action, acker store.Fle
3939
}
4040

4141
_, err := h.upgrader.Upgrade(ctx, &upgradeAction{action}, true)
42+
if err != nil {
43+
// Always log upgrade failures at the error level. Action errors are logged at debug level
44+
// by default higher up the stack in ActionDispatcher.Dispatch()
45+
h.log.Errorw("Upgrade action failed", "error.message", err,
46+
"action.version", action.Version, "action.source_uri", action.SourceURI, "action.id", action.ActionID,
47+
"action.start_time", action.StartTime, "action.expiration", action.ActionExpiration)
48+
}
49+
4250
return err
4351
}
4452

‎internal/pkg/agent/application/upgrade/cleanup.go‎

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -13,11 +13,15 @@ import (
1313
"github.com/hashicorp/go-multierror"
1414

1515
"github.com/elastic/elastic-agent/internal/pkg/agent/application/paths"
16+
"github.com/elastic/elastic-agent/pkg/core/logger"
1617
)
1718

18-
// preUpgradeCleanup will remove files that do not have the passed version number from the downloads directory.
19-
func preUpgradeCleanup(version string) error {
20-
files, err := os.ReadDir(paths.Downloads())
19+
// cleanNonMatchingVersionsFromDownloads will remove files that do not have the passed version number from the downloads directory.
20+
func cleanNonMatchingVersionsFromDownloads(log *logger.Logger, version string) error {
21+
downloadsPath := paths.Downloads()
22+
log.Debugw("Cleaning up non-matching downloaded versions", "version", version, "downloads.path", downloadsPath)
23+
24+
files, err := os.ReadDir(downloadsPath)
2125
if err != nil {
2226
return fmt.Errorf("unable to read directory %q: %w", paths.Downloads(), err)
2327
}

‎internal/pkg/agent/application/upgrade/cleanup_test.go‎

Lines changed: 15 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,9 @@ import (
99
"path/filepath"
1010
"testing"
1111

12+
"github.com/elastic/elastic-agent-libs/logp"
1213
"github.com/elastic/elastic-agent/internal/pkg/agent/application/paths"
14+
"github.com/elastic/elastic-agent/pkg/core/logger"
1315

1416
"github.com/stretchr/testify/require"
1517
)
@@ -31,7 +33,8 @@ func setupDir(t *testing.T) {
3133

3234
func TestPreUpgradeCleanup(t *testing.T) {
3335
setupDir(t)
34-
err := preUpgradeCleanup("8.4.0")
36+
log := newErrorLogger(t)
37+
err := cleanNonMatchingVersionsFromDownloads(log, "8.4.0")
3538
require.NoError(t, err)
3639

3740
files, err := os.ReadDir(paths.Downloads())
@@ -42,3 +45,14 @@ func TestPreUpgradeCleanup(t *testing.T) {
4245
require.NoError(t, err)
4346
require.Equal(t, []byte("hello, world!"), p)
4447
}
48+
49+
func newErrorLogger(t *testing.T) *logger.Logger {
50+
t.Helper()
51+
52+
loggerCfg := logger.DefaultLoggingConfig()
53+
loggerCfg.Level = logp.ErrorLevel
54+
55+
log, err := logger.NewFromConfig("", loggerCfg, false)
56+
require.NoError(t, err)
57+
return log
58+
}

‎internal/pkg/agent/application/upgrade/rollback.go‎

Lines changed: 13 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -31,33 +31,35 @@ const (
3131
)
3232

3333
// Rollback rollbacks to previous version which was functioning before upgrade.
34-
func Rollback(ctx context.Context, prevHash, currentHash string) error {
34+
func Rollback(ctx context.Context, log *logger.Logger, prevHash string, currentHash string) error {
3535
// change symlink
36-
if err := ChangeSymlink(ctx, prevHash); err != nil {
36+
if err := ChangeSymlink(ctx, log, prevHash); err != nil {
3737
return err
3838
}
3939

4040
// revert active commit
41-
if err := UpdateActiveCommit(prevHash); err != nil {
41+
if err := UpdateActiveCommit(log, prevHash); err != nil {
4242
return err
4343
}
4444

4545
// Restart
46+
log.Info("Restarting the agent after rollback")
4647
if err := restartAgent(ctx); err != nil {
4748
return err
4849
}
4950

5051
// cleanup everything except version we're rolling back into
51-
return Cleanup(prevHash, true)
52+
return Cleanup(log, prevHash, true)
5253
}
5354

5455
// Cleanup removes all artifacts and files related to a specified version.
55-
func Cleanup(currentHash string, removeMarker bool) error {
56+
func Cleanup(log *logger.Logger, currentHash string, removeMarker bool) error {
57+
log.Debugw("Cleaning up upgrade", "hash", currentHash, "remove_marker", removeMarker)
5658
<-time.After(afterRestartDelay)
5759

5860
// remove upgrade marker
5961
if removeMarker {
60-
if err := CleanMarker(); err != nil {
62+
if err := CleanMarker(log); err != nil {
6163
return err
6264
}
6365
}
@@ -74,7 +76,9 @@ func Cleanup(currentHash string, removeMarker bool) error {
7476
}
7577

7678
// remove symlink to avoid upgrade failures, ignore error
77-
_ = os.Remove(prevSymlinkPath())
79+
prevSymlink := prevSymlinkPath()
80+
log.Debugw("Removing previous symlink path", "file.path", prevSymlinkPath())
81+
_ = os.Remove(prevSymlink)
7882

7983
dirPrefix := fmt.Sprintf("%s-", agentName)
8084
currentDir := fmt.Sprintf("%s-%s", agentName, currentHash)
@@ -88,6 +92,7 @@ func Cleanup(currentHash string, removeMarker bool) error {
8892
}
8993

9094
hashedDir := filepath.Join(paths.Data(), dir)
95+
log.Debugw("Removing hashed data directory", "file.path", hashedDir)
9196
if cleanupErr := install.RemovePath(hashedDir); cleanupErr != nil {
9297
err = multierror.Append(err, cleanupErr)
9398
}
@@ -113,6 +118,7 @@ func InvokeWatcher(log *logger.Logger) error {
113118
}
114119
}()
115120

121+
log.Debugw("Starting upgrade watcher", "path", cmd.Path, "args", cmd.Args, "env", cmd.Env, "dir", cmd.Dir)
116122
return cmd.Start()
117123
}
118124

‎internal/pkg/agent/application/upgrade/step_download.go‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,10 @@ func (u *Upgrader) downloadArtifact(ctx context.Context, version, sourceURI stri
4040
}
4141
}
4242

43+
u.log.Debugw("Downloading upgrade artifact", "version", version,
44+
"source_uri", settings.SourceURI, "drop_path", settings.DropPath,
45+
"target_path", settings.TargetDirectory, "install_path", settings.InstallPath)
46+
4347
verifier, err := newVerifier(version, u.log, &settings)
4448
if err != nil {
4549
return "", errors.New(err, "initiating verifier")

‎internal/pkg/agent/application/upgrade/step_mark.go‎

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ import (
1717
"github.com/elastic/elastic-agent/internal/pkg/agent/errors"
1818
"github.com/elastic/elastic-agent/internal/pkg/fleetapi"
1919
"github.com/elastic/elastic-agent/internal/pkg/release"
20+
"github.com/elastic/elastic-agent/pkg/core/logger"
2021
)
2122

2223
const markerFilename = ".update-marker"
@@ -91,7 +92,7 @@ func newMarkerSerializer(m *UpdateMarker) *updateMarkerSerializer {
9192
}
9293

9394
// markUpgrade marks update happened so we can handle grace period
94-
func (u *Upgrader) markUpgrade(_ context.Context, hash string, action Action) error {
95+
func (u *Upgrader) markUpgrade(_ context.Context, log *logger.Logger, hash string, action Action) error {
9596
prevVersion := release.Version()
9697
prevHash := release.Commit()
9798
if len(prevHash) > hashLen {
@@ -112,20 +113,22 @@ func (u *Upgrader) markUpgrade(_ context.Context, hash string, action Action) er
112113
}
113114

114115
markerPath := markerFilePath()
116+
log.Infow("Writing upgrade marker file", "file.path", markerPath, "hash", marker.Hash, "prev_hash", prevHash)
115117
if err := ioutil.WriteFile(markerPath, markerBytes, 0600); err != nil {
116118
return errors.New(err, errors.TypeFilesystem, "failed to create update marker file", errors.M(errors.MetaKeyPath, markerPath))
117119
}
118120

119-
if err := UpdateActiveCommit(hash); err != nil {
121+
if err := UpdateActiveCommit(log, hash); err != nil {
120122
return err
121123
}
122124

123125
return nil
124126
}
125127

126128
// UpdateActiveCommit updates active.commit file to point to active version.
127-
func UpdateActiveCommit(hash string) error {
129+
func UpdateActiveCommit(log *logger.Logger, hash string) error {
128130
activeCommitPath := filepath.Join(paths.Top(), agentCommitFile)
131+
log.Infow("Updating active commit", "file.path", activeCommitPath, "hash", hash)
129132
if err := ioutil.WriteFile(activeCommitPath, []byte(hash), 0600); err != nil {
130133
return errors.New(err, errors.TypeFilesystem, "failed to update active commit", errors.M(errors.MetaKeyPath, activeCommitPath))
131134
}
@@ -134,8 +137,9 @@ func UpdateActiveCommit(hash string) error {
134137
}
135138

136139
// CleanMarker removes a marker from disk.
137-
func CleanMarker() error {
140+
func CleanMarker(log *logger.Logger) error {
138141
markerFile := markerFilePath()
142+
log.Debugw("Removing marker file", "file.path", markerFile)
139143
if err := os.Remove(markerFile); !os.IsNotExist(err) {
140144
return err
141145
}

‎internal/pkg/agent/application/upgrade/step_relink.go‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,10 +14,11 @@ import (
1414
"github.com/elastic/elastic-agent-libs/file"
1515
"github.com/elastic/elastic-agent/internal/pkg/agent/application/paths"
1616
"github.com/elastic/elastic-agent/internal/pkg/agent/errors"
17+
"github.com/elastic/elastic-agent/pkg/core/logger"
1718
)
1819

1920
// ChangeSymlink updates symlink paths to match current version.
20-
func ChangeSymlink(ctx context.Context, targetHash string) error {
21+
func ChangeSymlink(ctx context.Context, log *logger.Logger, targetHash string) error {
2122
// create symlink to elastic-agent-{hash}
2223
hashedDir := fmt.Sprintf("%s-%s", agentName, targetHash)
2324

@@ -31,6 +32,7 @@ func ChangeSymlink(ctx context.Context, targetHash string) error {
3132
}
3233

3334
prevNewPath := prevSymlinkPath()
35+
log.Infow("Changing symlink", "symlink_path", symlinkPath, "new_path", newPath, "prev_path", prevNewPath)
3436

3537
// remove symlink to avoid upgrade failures
3638
if err := os.Remove(prevNewPath); !os.IsNotExist(err) {

‎internal/pkg/agent/application/upgrade/step_unpack.go‎

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ import (
2121

2222
"github.com/elastic/elastic-agent/internal/pkg/agent/application/paths"
2323
"github.com/elastic/elastic-agent/internal/pkg/agent/errors"
24+
"github.com/elastic/elastic-agent/pkg/core/logger"
2425
)
2526

2627
// unpack unpacks archive correctly, skips root (symlink, config...) unpacks data/*
@@ -30,18 +31,21 @@ func (u *Upgrader) unpack(ctx context.Context, version, archivePath string) (str
3031
var hash string
3132
var err error
3233
if runtime.GOOS == "windows" {
33-
hash, err = unzip(version, archivePath)
34+
hash, err = unzip(u.log, version, archivePath)
3435
} else {
35-
hash, err = untar(version, archivePath)
36+
hash, err = untar(u.log, version, archivePath)
3637
}
38+
3739
if err != nil {
40+
u.log.Errorw("Failed to unpack upgrade artifact", "error.message", err, "version", version, "file.path", archivePath, "hash", hash)
3841
return "", err
3942
}
4043

44+
u.log.Infow("Unpacked upgrade artifact", "version", version, "file.path", archivePath, "hash", hash)
4145
return hash, nil
4246
}
4347

44-
func unzip(version, archivePath string) (string, error) {
48+
func unzip(log *logger.Logger, version string, archivePath string) (string, error) {
4549
var hash, rootDir string
4650
r, err := zip.OpenReader(archivePath)
4751
if err != nil {
@@ -82,8 +86,10 @@ func unzip(version, archivePath string) (string, error) {
8286
path := filepath.Join(paths.Data(), strings.TrimPrefix(fileName, "data/"))
8387

8488
if f.FileInfo().IsDir() {
89+
log.Debugw("Unpacking directory", "archive", "zip", "file.path", path)
8590
os.MkdirAll(path, f.Mode())
8691
} else {
92+
log.Debugw("Unpacking file", "archive", "zip", "file.path", path)
8793
os.MkdirAll(filepath.Dir(path), f.Mode())
8894
f, err := os.OpenFile(path, os.O_WRONLY|os.O_CREATE|os.O_TRUNC, f.Mode())
8995
if err != nil {
@@ -119,7 +125,7 @@ func unzip(version, archivePath string) (string, error) {
119125
return hash, nil
120126
}
121127

122-
func untar(version, archivePath string) (string, error) {
128+
func untar(log *logger.Logger, version string, archivePath string) (string, error) {
123129
r, err := os.Open(archivePath)
124130
if err != nil {
125131
return "", errors.New(fmt.Sprintf("artifact for 'elastic-agent' version '%s' could not be found at '%s'", version, archivePath), errors.TypeFilesystem, errors.M(errors.MetaKeyPath, archivePath))
@@ -183,6 +189,7 @@ func untar(version, archivePath string) (string, error) {
183189
mode := fi.Mode()
184190
switch {
185191
case mode.IsRegular():
192+
log.Debugw("Unpacking file", "archive", "tar", "file.path", abs)
186193
// just to be sure, it should already be created by Dir type
187194
if err := os.MkdirAll(filepath.Dir(abs), 0755); err != nil {
188195
return "", errors.New(err, "TarInstaller: creating directory for file "+abs, errors.TypeFilesystem, errors.M(errors.MetaKeyPath, abs))
@@ -201,6 +208,7 @@ func untar(version, archivePath string) (string, error) {
201208
return "", fmt.Errorf("TarInstaller: error writing to %s: %w", abs, err)
202209
}
203210
case mode.IsDir():
211+
log.Debugw("Unpacking directory", "archive", "tar", "file.path", abs)
204212
if err := os.MkdirAll(abs, 0755); err != nil {
205213
return "", errors.New(err, "TarInstaller: creating directory for file "+abs, errors.TypeFilesystem, errors.M(errors.MetaKeyPath, abs))
206214
}

0 commit comments

Comments
 (0)