Skip to content

Commit

Permalink
Fixing conflicts
Browse files Browse the repository at this point in the history
  • Loading branch information
@ycombinator
ycombinator committed Oct 10, 2023
1 parent 34370d7 commit c7618c9
Showing 1 changed file with 43 additions and 59 deletions.
102 changes: 43 additions & 59 deletions internal/pkg/agent/application/upgrade/artifact/download/http/downloader_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,17 +6,22 @@ package http

import (
"context"
"fmt"
"io/ioutil"
"net"
"net/http"
"net/http/httptest"
"os"
"regexp"
"strconv"
"sync"
"testing"
"time"

"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest/observer"

"github.com/elastic/elastic-agent/internal/pkg/agent/application/upgrade/artifact"
"github.com/elastic/elastic-agent/pkg/core/logger"

"github.com/docker/go-units"
"github.com/stretchr/testify/assert"
Expand Down Expand Up @@ -57,21 +62,23 @@ func TestDownloadBodyError(t *testing.T) {
Architecture: "64",
}

log := newRecordLogger()
log, obs := logger.NewTesting("downloader")
testClient := NewDownloaderWithClient(log, config, *client)
artifactPath, err := testClient.Download(context.Background(), beatSpec, version)
os.Remove(artifactPath)
if err == nil {
t.Fatal("expected Download to return an error")
}

log.lock.RLock()
defer log.lock.RUnlock()
infoLogs := obs.FilterLevelExact(zapcore.InfoLevel).TakeAll()
warnLogs := obs.FilterLevelExact(zapcore.WarnLevel).TakeAll()

require.GreaterOrEqual(t, len(log.info), 1, "download error not logged at info level")
assert.True(t, containsMessage(log.info, "download from %s failed at %s @ %sps: %s"))
require.GreaterOrEqual(t, len(log.warn), 1, "download error not logged at warn level")
assert.True(t, containsMessage(log.warn, "download from %s failed at %s @ %sps: %s"))
expectedURL := fmt.Sprintf("%s/%s-%s-%s", srv.URL, "beats/filebeat/filebeat", version, "linux-x86_64.tar.gz")
expectedMsg := fmt.Sprintf("download from %s failed at 0B @ NaNBps: unexpected EOF", expectedURL)
require.GreaterOrEqual(t, len(infoLogs), 1, "download error not logged at info level")
assert.True(t, containsMessage(infoLogs, expectedMsg))
require.GreaterOrEqual(t, len(warnLogs), 1, "download error not logged at warn level")
assert.True(t, containsMessage(warnLogs, expectedMsg))
}

func TestDownloadLogProgressWithLength(t *testing.T) {
Expand Down Expand Up @@ -111,16 +118,19 @@ func TestDownloadLogProgressWithLength(t *testing.T) {
},
}

log := newRecordLogger()
log, obs := logger.NewTesting("downloader")
testClient := NewDownloaderWithClient(log, config, *client)
artifactPath, err := testClient.Download(context.Background(), beatSpec, version)
os.Remove(artifactPath)
require.NoError(t, err, "Download should not have errored")

log.lock.RLock()
defer log.lock.RUnlock()

expectedProgressMsg := "download progress from %s is %s/%s (%.2f%% complete) @ %sps"
expectedURL := fmt.Sprintf("%s/%s-%s-%s", srv.URL, "beats/filebeat/filebeat", version, "linux-x86_64.tar.gz")
expectedProgressRegexp := regexp.MustCompile(
`^download progress from ` + expectedURL + `(.sha512)? is \S+/\S+ \(\d+\.\d{2}% complete\) @ \S+$`,
)
expectedCompletedRegexp := regexp.MustCompile(
`^download from ` + expectedURL + `(.sha512)? completed in \d+ \S+ @ \S+$`,
)

// Two files are downloaded. Each file is being downloaded in 100 chunks with a delay of 10ms between chunks. The
// expected time to download is, therefore, 100 * 10ms = 1000ms. In reality, the actual download time will be a bit
Expand All @@ -129,15 +139,15 @@ func TestDownloadLogProgressWithLength(t *testing.T) {
// the actual total download time / 50ms, for each file. That works out to at least 1000ms / 50ms = 20 INFO log
// messages, for each file, about its download progress. Additionally, we should expect 1 INFO log message, for
// each file, about the download completing.
assertLogs(t, log.info, 20, expectedProgressMsg)
assertLogs(t, obs.FilterLevelExact(zapcore.InfoLevel).TakeAll(), 20, expectedProgressRegexp, expectedCompletedRegexp)

// By similar math as above, since the download of each file is expected to take 1000ms, and the progress logger
// starts issuing WARN messages once the download has taken more than 75% of the expected time,
// we should see warning messages for at least the last 250 seconds of the download. Given that
// reporting happens every 50 seconds, we should see at least 250s / 50s = 5 WARN log messages, for each file,
// about its download progress. Additionally, we should expect 1 WARN message, for each file, about the download
// completing.
assertLogs(t, log.warn, 5, expectedProgressMsg)
assertLogs(t, obs.FilterLevelExact(zapcore.WarnLevel).TakeAll(), 5, expectedProgressRegexp, expectedCompletedRegexp)
}

func TestDownloadLogProgressWithoutLength(t *testing.T) {
Expand Down Expand Up @@ -176,16 +186,19 @@ func TestDownloadLogProgressWithoutLength(t *testing.T) {
},
}

log := newRecordLogger()
log, obs := logger.NewTesting("downloader")
testClient := NewDownloaderWithClient(log, config, *client)
artifactPath, err := testClient.Download(context.Background(), beatSpec, version)
os.Remove(artifactPath)
require.NoError(t, err, "Download should not have errored")

log.lock.RLock()
defer log.lock.RUnlock()

expectedProgressMsg := "download progress from %s has fetched %s @ %sps"
expectedURL := fmt.Sprintf("%s/%s-%s-%s", srv.URL, "beats/filebeat/filebeat", version, "linux-x86_64.tar.gz")
expectedProgressRegexp := regexp.MustCompile(
`^download progress from ` + expectedURL + `(.sha512)? has fetched \S+ @ \S+$`,
)
expectedCompletedRegexp := regexp.MustCompile(
`^download from ` + expectedURL + `(.sha512)? completed in \d+ \S+ @ \S+$`,
)

// Two files are downloaded. Each file is being downloaded in 100 chunks with a delay of 10ms between chunks. The
// expected time to download is, therefore, 100 * 10ms = 1000ms. In reality, the actual download time will be a bit
Expand All @@ -194,56 +207,27 @@ func TestDownloadLogProgressWithoutLength(t *testing.T) {
// the actual total download time / 50ms, for each file. That works out to at least 1000ms / 50ms = 20 INFO log
// messages, for each file, about its download progress. Additionally, we should expect 1 INFO log message, for
// each file, about the download completing.
assertLogs(t, log.info, 20, expectedProgressMsg)
assertLogs(t, obs.FilterLevelExact(zapcore.InfoLevel).TakeAll(), 20, expectedProgressRegexp, expectedCompletedRegexp)

// By similar math as above, since the download of each file is expected to take 1000ms, and the progress logger
// starts issuing WARN messages once the download has taken more than 75% of the expected time,
// we should see warning messages for at least the last 250 seconds of the download. Given that
// reporting happens every 50 seconds, we should see at least 250s / 50s = 5 WARN log messages, for each file,
// about its download progress. Additionally, we should expect 1 WARN message, for each file, about the download
// completing.
assertLogs(t, log.warn, 5, expectedProgressMsg)
}

type logMessage struct {
record string
args []interface{}
}

type recordLogger struct {
lock sync.RWMutex
info []logMessage
warn []logMessage
assertLogs(t, obs.FilterLevelExact(zapcore.WarnLevel).TakeAll(), 5, expectedProgressRegexp, expectedCompletedRegexp)
}

func newRecordLogger() *recordLogger {
return &recordLogger{
info: make([]logMessage, 0, 10),
warn: make([]logMessage, 0, 10),
}
}

func (f *recordLogger) Infof(record string, args ...interface{}) {
f.lock.Lock()
defer f.lock.Unlock()
f.info = append(f.info, logMessage{record, args})
}

func (f *recordLogger) Warnf(record string, args ...interface{}) {
f.lock.Lock()
defer f.lock.Unlock()
f.warn = append(f.warn, logMessage{record, args})
}

func containsMessage(logs []logMessage, msg string) bool {
func containsMessage(logs []observer.LoggedEntry, msg string) bool {
for _, item := range logs {
if item.record == msg {
if item.Message == msg {
return true
}
}
return false
}
func assertLogs(t *testing.T, logs []logMessage, minExpectedProgressLogs int, expectedProgressMsg string) {

func assertLogs(t *testing.T, logs []observer.LoggedEntry, minExpectedProgressLogs int, expectedProgressRegexp, expectedCompletedRegexp *regexp.Regexp) {
t.Helper()

// Verify that we've logged at least minExpectedProgressLogs (about download progress) + 1 log
Expand All @@ -253,21 +237,21 @@ func assertLogs(t *testing.T, logs []logMessage, minExpectedProgressLogs int, ex
// Verify that the first minExpectedProgressLogs messages are about the download progress (for the first file).
i := 0
for ; i < minExpectedProgressLogs; i++ {
assert.Equal(t, logs[i].record, expectedProgressMsg)
assert.Regexp(t, expectedProgressRegexp, logs[i].Message)
}

// Find the next message that's about the download being completed (for the first file).
found := false
for ; i < len(logs) && !found; i++ {
found = logs[i].record == "download from %s completed in %s @ %sps"
found = expectedCompletedRegexp.MatchString(logs[i].Message)
}
assert.True(t, found)

// Verify that the next minExpectedProgressLogs messages are about the download progress (for the second file).
for j := 0; j < minExpectedProgressLogs; j++ {
assert.Equal(t, logs[i+j].record, expectedProgressMsg)
assert.Regexp(t, expectedProgressRegexp, logs[i+j].Message)
}

// Verify that the last message is about the download being completed (for the second file).
assert.Equal(t, logs[len(logs)-1].record, "download from %s completed in %s @ %sps")
assert.Regexp(t, expectedCompletedRegexp, logs[len(logs)-1].Message)
}

0 comments on commit c7618c9

Please sign in to comment.