From 5bbc159df9d3d34f38b7c8ed75c6b5160395e836 Mon Sep 17 00:00:00 2001 From: derailed Date: Fri, 19 Jun 2020 16:15:48 -0600 Subject: [PATCH] fix #776 --- .gitignore | 1 + internal/dao/log_item.go | 18 +++---- internal/model/cluster_info_test.go | 5 ++ internal/model/log.go | 22 ++++---- internal/model/log_int_test.go | 79 +++++++++++++++++++++++++++++ internal/model/log_test.go | 12 ++--- internal/view/log.go | 10 ++-- internal/view/log_int_test.go | 4 +- 8 files changed, 120 insertions(+), 31 deletions(-) create mode 100644 internal/model/log_int_test.go diff --git a/.gitignore b/.gitignore index 07fa4689..301be356 100644 --- a/.gitignore +++ b/.gitignore @@ -1,4 +1,5 @@ .vscode +*.out .idea .envrc cov.out diff --git a/internal/dao/log_item.go b/internal/dao/log_item.go index a1401e81..d1212ade 100644 --- a/internal/dao/log_item.go +++ b/internal/dao/log_item.go @@ -38,10 +38,10 @@ func NewLogItem(b []byte) *LogItem { // NewLogItemFromString returns a new item. func NewLogItemFromString(s string) *LogItem { - l := LogItem{Bytes: []byte(s)} - l.Timestamp = time.Now().String() - - return &l + return &LogItem{ + Bytes: []byte(s), + Timestamp: time.Now().String(), + } } // ID returns pod and or container based id. @@ -125,15 +125,15 @@ func (l LogItems) Lines() []string { // Render returns logs as a collection of strings. func (l LogItems) Render(showTime bool, ll [][]byte) { - colors := map[string]int{} + colors := make(map[string]int, len(l)) for i, item := range l { info := item.ID() - c, ok := colors[item.ID()] + color, ok := colors[info] if !ok { - c = colorFor(info) - colors[info] = c + color = colorFor(info) + colors[info] = color } - ll[i] = item.Render(c, showTime) + ll[i] = item.Render(color, showTime) } } diff --git a/internal/model/cluster_info_test.go b/internal/model/cluster_info_test.go index 7fabb932..84155a65 100644 --- a/internal/model/cluster_info_test.go +++ b/internal/model/cluster_info_test.go @@ -4,9 +4,14 @@ import ( "testing" "github.com/derailed/k9s/internal/model" + "github.com/rs/zerolog" "github.com/stretchr/testify/assert" ) +func init() { + zerolog.SetGlobalLevel(zerolog.FatalLevel) +} + func TestClusterMetaDelta(t *testing.T) { uu := map[string]struct { o, n model.ClusterMeta diff --git a/internal/model/log.go b/internal/model/log.go index 28264bf6..7bfcf680 100644 --- a/internal/model/log.go +++ b/internal/model/log.go @@ -233,11 +233,11 @@ func (l *Log) Append(line *dao.LogItem) { } // Notify fires of notifications to the listeners. -func (l *Log) Notify(timedOut bool) { +func (l *Log) Notify() { l.mx.Lock() defer l.mx.Unlock() - if timedOut && l.lastSent < len(l.lines) { + if l.lastSent < len(l.lines) { l.fireLogBuffChanged(l.lines[l.lastSent:]) l.lastSent = len(l.lines) } @@ -253,7 +253,7 @@ func (l *Log) updateLogs(ctx context.Context, c dao.LogChan) { if !ok { log.Debug().Msgf("Closed channel detected. Bailing out...") l.Append(item) - l.Notify(true) + l.Notify() return } l.Append(item) @@ -264,10 +264,10 @@ func (l *Log) updateLogs(ctx context.Context, c dao.LogChan) { } l.mx.RUnlock() if overflow { - l.Notify(true) + l.Notify() } case <-time.After(l.flushTimeout): - l.Notify(true) + l.Notify() case <-ctx.Done(): return } @@ -322,10 +322,14 @@ func applyFilter(q string, lines dao.LogItems) (dao.LogItems, error) { } func (l *Log) fireLogBuffChanged(lines dao.LogItems) { - filtered, err := applyFilter(l.filter, lines) - if err != nil { - l.fireLogError(err) - return + filtered := lines + if l.filter != "" { + var err error + filtered, err = applyFilter(l.filter, lines) + if err != nil { + l.fireLogError(err) + return + } } if len(filtered) > 0 { l.fireLogChanged(filtered) diff --git a/internal/model/log_int_test.go b/internal/model/log_int_test.go new file mode 100644 index 00000000..936c749d --- /dev/null +++ b/internal/model/log_int_test.go @@ -0,0 +1,79 @@ +package model + +import ( + "context" + "strconv" + "testing" + "time" + + "github.com/derailed/k9s/internal/client" + "github.com/derailed/k9s/internal/dao" + "github.com/stretchr/testify/assert" +) + +func TestUpdateLogs(t *testing.T) { + size := 100 + m := NewLog(client.NewGVR("fred"), makeLogOpts(size), 10*time.Millisecond) + m.Init(makeFactory()) + + v := newMockLogView() + m.AddListener(v) + + c := make(dao.LogChan) + go func() { + m.updateLogs(context.Background(), c) + }() + + for i := 0; i < 2*size; i++ { + c <- dao.NewLogItemFromString("line" + strconv.Itoa(i)) + } + close(c) + + time.Sleep(2 * time.Second) + assert.Equal(t, size, v.count) +} + +func BenchmarkUpdateLogs(b *testing.B) { + size := 100 + m := NewLog(client.NewGVR("fred"), makeLogOpts(size), 10*time.Millisecond) + m.Init(makeFactory()) + + v := newMockLogView() + m.AddListener(v) + + c := make(dao.LogChan) + go func() { + m.updateLogs(context.Background(), c) + }() + + b.ReportAllocs() + b.ResetTimer() + for n := 0; n < b.N; n++ { + c <- dao.NewLogItemFromString("line" + strconv.Itoa(n)) + } + close(c) +} + +// Helpers... + +func makeLogOpts(count int) dao.LogOptions { + return dao.LogOptions{ + Path: "fred", + Container: "blee", + Lines: int64(count), + } +} + +type mockLogView struct { + count int +} + +func newMockLogView() *mockLogView { + return &mockLogView{} +} + +func (t *mockLogView) LogChanged(d dao.LogItems) { + t.count += len(d.Lines()) +} +func (t *mockLogView) LogCleared() {} +func (t *mockLogView) LogFailed(err error) {} diff --git a/internal/model/log_test.go b/internal/model/log_test.go index 15664a6a..3f3f1704 100644 --- a/internal/model/log_test.go +++ b/internal/model/log_test.go @@ -29,7 +29,7 @@ func TestLogFullBuffer(t *testing.T) { data = append(data, dao.NewLogItemFromString("line"+strconv.Itoa(i))) m.Append(data[i]) } - m.Notify(true) + m.Notify() assert.Equal(t, 1, v.dataCalled) assert.Equal(t, 1, v.clearCalled) @@ -73,7 +73,7 @@ func TestLogFilter(t *testing.T) { m.Append(data[i]) } - m.Notify(true) + m.Notify() assert.Equal(t, 1, v.dataCalled) assert.Equal(t, 1, v.clearCalled) assert.Equal(t, 0, v.errCalled) @@ -100,7 +100,7 @@ func TestLogStartStop(t *testing.T) { for _, d := range data { m.Append(d) } - m.Notify(true) + m.Notify() m.Stop() assert.Equal(t, 1, v.dataCalled) @@ -122,7 +122,7 @@ func TestLogClear(t *testing.T) { for _, d := range data { m.Append(d) } - m.Notify(true) + m.Notify() m.Clear() assert.Equal(t, 1, v.dataCalled) @@ -167,7 +167,7 @@ func TestLogAppend(t *testing.T) { assert.Equal(t, 1, v.dataCalled) assert.Equal(t, items, v.data) - m.Notify(true) + m.Notify() assert.Equal(t, 2, v.dataCalled) assert.Equal(t, 1, v.clearCalled) assert.Equal(t, 0, v.errCalled) @@ -191,7 +191,7 @@ func TestLogTimedout(t *testing.T) { for _, d := range data { m.Append(d) } - m.Notify(true) + m.Notify() assert.Equal(t, 1, v.dataCalled) assert.Equal(t, 1, v.clearCalled) assert.Equal(t, 0, v.errCalled) diff --git a/internal/view/log.go b/internal/view/log.go index a06e040c..ac5107fe 100644 --- a/internal/view/log.go +++ b/internal/view/log.go @@ -235,16 +235,16 @@ func (l *Log) Logs() *Details { return l.logs } +var EOL = []byte("\n") + // Flush write logs to viewer. func (l *Log) Flush(lines dao.LogItems) { - defer func(t time.Time) { - log.Debug().Msgf("FLUSH %d--%v", len(lines), time.Since(t)) - }(time.Now()) - showTime := l.Indicator().showTime ll := make([][]byte, len(lines)) lines.Render(showTime, ll) - fmt.Fprintln(l.ansiWriter, string(bytes.Join(ll, []byte("\n")))) + if _, err := l.ansiWriter.Write(bytes.Join(ll, EOL)); err != nil { + log.Error().Err(err).Msgf("write log failed") + } l.logs.ScrollToEnd() l.indicator.Refresh() } diff --git a/internal/view/log_int_test.go b/internal/view/log_int_test.go index d6d8542d..80cef2f6 100644 --- a/internal/view/log_int_test.go +++ b/internal/view/log_int_test.go @@ -14,7 +14,7 @@ func TestLogAutoScroll(t *testing.T) { v := NewLog(client.NewGVR("v1/pods"), "fred/p1", "blee", false) v.Init(makeContext()) v.GetModel().Set(dao.LogItems{dao.NewLogItemFromString("blee"), dao.NewLogItemFromString("bozo")}) - v.GetModel().Notify(true) + v.GetModel().Notify() assert.Equal(t, 14, len(v.Hints())) @@ -66,7 +66,7 @@ func TestLogTimestamp(t *testing.T) { l.Logs().Clear() l.Flush(buff) - assert.Equal(t, fmt.Sprintf("%-30s %s", "ttt", "fred/blee:c1 Testing 1, 2, 3\n"), l.Logs().GetText(true)) + assert.Equal(t, fmt.Sprintf("%-30s %s", "ttt", "fred/blee:c1 Testing 1, 2, 3"), l.Logs().GetText(true)) assert.Equal(t, 2, list.change) assert.Equal(t, 2, list.clear) assert.Equal(t, 0, list.fail)