fix logger for issue #631

mine
derailed 2020-03-24 10:57:15 -06:00
parent e7312d569b
commit 733d8482de
12 changed files with 99 additions and 70 deletions

1
go.mod
View File

@ -45,6 +45,7 @@ require (
github.com/openfaas/faas-provider v0.15.0 github.com/openfaas/faas-provider v0.15.0
github.com/petergtz/pegomock v2.6.0+incompatible github.com/petergtz/pegomock v2.6.0+incompatible
github.com/rakyll/hey v0.1.2 github.com/rakyll/hey v0.1.2
github.com/rivo/tview v0.0.0-20191018115645-bacbf5155bc1
github.com/rs/zerolog v1.18.0 github.com/rs/zerolog v1.18.0
github.com/ryanuber/go-glob v1.0.0 // indirect github.com/ryanuber/go-glob v1.0.0 // indirect
github.com/sahilm/fuzzy v0.1.0 github.com/sahilm/fuzzy v0.1.0

2
go.sum
View File

@ -478,6 +478,7 @@ github.com/quobyte/api v0.1.2/go.mod h1:jL7lIHrmqQ7yh05OJ+eEEdHr0u/kmT1Ff9iHd+4H
github.com/rakyll/hey v0.1.2 h1:XlGaKcBdmXJaPImiTnE+TGLDUWQ2toYuHCwdrylLjmg= github.com/rakyll/hey v0.1.2 h1:XlGaKcBdmXJaPImiTnE+TGLDUWQ2toYuHCwdrylLjmg=
github.com/rakyll/hey v0.1.2/go.mod h1:S5M+++KwbmxA7w68S92B5NdWiCB+cIhITaMUkq9W608= github.com/rakyll/hey v0.1.2/go.mod h1:S5M+++KwbmxA7w68S92B5NdWiCB+cIhITaMUkq9W608=
github.com/remyoudompheng/bigfft v0.0.0-20170806203942-52369c62f446/go.mod h1:uYEyJGbgTkfkS4+E/PavXkNJcbFIpEtjt2B0KDQ5+9M= github.com/remyoudompheng/bigfft v0.0.0-20170806203942-52369c62f446/go.mod h1:uYEyJGbgTkfkS4+E/PavXkNJcbFIpEtjt2B0KDQ5+9M=
github.com/rivo/tview v0.0.0-20191018115645-bacbf5155bc1 h1:s9Lw4phBWkuQJUd+msaBMxP3utLvrFaBQV9jNgG55r0=
github.com/rivo/tview v0.0.0-20191018115645-bacbf5155bc1/go.mod h1:+rKjP5+h9HMwWRpAfhIkkQ9KE3m3Nz5rwn7YtUpwgqk= github.com/rivo/tview v0.0.0-20191018115645-bacbf5155bc1/go.mod h1:+rKjP5+h9HMwWRpAfhIkkQ9KE3m3Nz5rwn7YtUpwgqk=
github.com/rivo/uniseg v0.0.0-20190513083848-b9f5b9457d44/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc= github.com/rivo/uniseg v0.0.0-20190513083848-b9f5b9457d44/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc=
github.com/rivo/uniseg v0.1.0 h1:+2KBaVoUmb9XzDsrx/Ct0W/EYOSFf/nWTauy++DprtY= github.com/rivo/uniseg v0.1.0 h1:+2KBaVoUmb9XzDsrx/Ct0W/EYOSFf/nWTauy++DprtY=
@ -713,6 +714,7 @@ gotest.tools v2.2.0+incompatible/go.mod h1:DsYFclhRJ6vuDpmuTbkuFWG+y2sxOXAzmJt81
gotest.tools/gotestsum v0.3.5/go.mod h1:Mnf3e5FUzXbkCfynWBGOwLssY7gTQgCHObK9tMpAriY= gotest.tools/gotestsum v0.3.5/go.mod h1:Mnf3e5FUzXbkCfynWBGOwLssY7gTQgCHObK9tMpAriY=
helm.sh/helm v1.2.1 h1:Jrn7kKQqQ/hnFWZEX+9pMFvYqFexkzrBnGqYBmIph7c= helm.sh/helm v1.2.1 h1:Jrn7kKQqQ/hnFWZEX+9pMFvYqFexkzrBnGqYBmIph7c=
helm.sh/helm v2.16.3+incompatible h1:a7P7FSGTBdK6ZsAcWWZZQXPIdzkgybD8CWd/Dy+jwf4= helm.sh/helm v2.16.3+incompatible h1:a7P7FSGTBdK6ZsAcWWZZQXPIdzkgybD8CWd/Dy+jwf4=
helm.sh/helm v2.16.4+incompatible h1:3Wb9ZHLFXr+MyeUELIkEkIiyQZg+gZn7m2fRiNtg1Gg=
helm.sh/helm/v3 v3.0.2 h1:BggvLisIMrAc+Is5oAHVrlVxgwOOrMN8nddfQbm5gKo= helm.sh/helm/v3 v3.0.2 h1:BggvLisIMrAc+Is5oAHVrlVxgwOOrMN8nddfQbm5gKo=
helm.sh/helm/v3 v3.0.2/go.mod h1:KBxE6XWO57XSNA1PA9CvVLYRY0zWqYQTad84bNXp1lw= helm.sh/helm/v3 v3.0.2/go.mod h1:KBxE6XWO57XSNA1PA9CvVLYRY0zWqYQTad84bNXp1lw=
honnef.co/go/tools v0.0.0-20180728063816-88497007e858/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= honnef.co/go/tools v0.0.0-20180728063816-88497007e858/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4=

View File

@ -2,6 +2,8 @@ package color
import ( import (
"fmt" "fmt"
"github.com/rs/zerolog/log"
) )
// ColorFmt colorize a string with ansi colors. // ColorFmt colorize a string with ansi colors.
@ -27,6 +29,7 @@ const (
// Colorize returns an ASCII colored string based on given color. // Colorize returns an ASCII colored string based on given color.
func Colorize(s string, c Paint) string { func Colorize(s string, c Paint) string {
log.Debug().Msgf("Painting %#v", c)
if c == 0 { if c == 0 {
return s return s
} }

View File

@ -266,7 +266,7 @@ var expectedConfig = `k9s:
logger: logger:
tail: 500 tail: 500
buffer: 800 buffer: 800
sinceSeconds: 300 sinceSeconds: -1
fullScreenLogs: false fullScreenLogs: false
currentContext: blee currentContext: blee
currentCluster: blee currentCluster: blee
@ -316,7 +316,7 @@ var resetConfig = `k9s:
logger: logger:
tail: 200 tail: 200
buffer: 2000 buffer: 2000
sinceSeconds: 300 sinceSeconds: -1
fullScreenLogs: false fullScreenLogs: false
currentContext: blee currentContext: blee
currentCluster: blee currentCluster: blee

View File

@ -10,7 +10,7 @@ const (
// MaxLogThreshold sets the max value for log size. // MaxLogThreshold sets the max value for log size.
MaxLogThreshold = 5000 MaxLogThreshold = 5000
// DefaultSinceSeconds tracks default log age. // DefaultSinceSeconds tracks default log age.
DefaultSinceSeconds = 5 * 60 // 5mins DefaultSinceSeconds = -1 // all logs
) )
// Logger tracks logger options // Logger tracks logger options

View File

@ -7,6 +7,7 @@ import (
"strings" "strings"
"time" "time"
"github.com/derailed/tview"
"github.com/rs/zerolog/log" "github.com/rs/zerolog/log"
"github.com/sahilm/fuzzy" "github.com/sahilm/fuzzy"
) )
@ -40,32 +41,59 @@ func NewLogItemFromString(s string) *LogItem {
return &l return &l
} }
// ID returns pod and or container based id.
func (l *LogItem) ID() string {
if l.Pod != "" {
return l.Pod
}
return l.Container
}
// Info returns pod and container information.
func (l *LogItem) Info() string {
return fmt.Sprintf("%q::%q", l.Pod, l.Container)
}
// IsEmpty checks if the entry is empty. // IsEmpty checks if the entry is empty.
func (l *LogItem) IsEmpty() bool { func (l *LogItem) IsEmpty() bool {
return len(l.Bytes) == 0 return len(l.Bytes) == 0
} }
const colorFmt = "\033[38;5;%dm%s\033[0m"
// colorize me
func colorize(s string, c int) string {
return fmt.Sprintf(colorFmt, c, s)
}
// Render returns a log line as string. // Render returns a log line as string.
func (l *LogItem) Render(showTime bool) []byte { func (l *LogItem) Render(c int, showTime bool) []byte {
bb := make([]byte, 0, 100+len(l.Bytes)) bb := make([]byte, 0, 30+len(l.Bytes)+len(l.Info()))
if showTime { if showTime {
bb = append(bb, fmt.Sprintf("%-30s ", l.Timestamp)...) bb = append(bb, colorize(fmt.Sprintf("%-30s ", l.Timestamp), 106)...)
} }
if l.Pod != "" { if l.Pod != "" {
bb = append(bb, l.Pod...) bb = append(bb, []byte(colorize(l.Pod, c))...)
bb = append(bb, ':') bb = append(bb, ':')
bb = append(bb, l.Container...) }
bb = append(bb, ' ') if l.Container != "" {
} else if l.Container != "" { bb = append(bb, []byte(colorize(l.Container, c))...)
bb = append(bb, l.Container...)
bb = append(bb, ' ') bb = append(bb, ' ')
} }
bb = append(bb, l.Bytes...) bb = append(bb, []byte(tview.Escape(string(l.Bytes)))...)
return bb return bb
} }
func colorFor(n string) int {
var sum int
for _, r := range n {
sum += int(r)
}
return sum % 256
}
// ---------------------------------------------------------------------------- // ----------------------------------------------------------------------------
// LogItems represents a collection of log items. // LogItems represents a collection of log items.
@ -75,7 +103,7 @@ type LogItems []*LogItem
func (l LogItems) Lines() []string { func (l LogItems) Lines() []string {
ll := make([]string, len(l)) ll := make([]string, len(l))
for i, item := range l { for i, item := range l {
ll[i] = string(item.Render(false)) ll[i] = string(item.Render(0, false))
} }
return ll return ll
@ -83,8 +111,15 @@ func (l LogItems) Lines() []string {
// Render returns logs as a collection of strings. // Render returns logs as a collection of strings.
func (l LogItems) Render(showTime bool, ll [][]byte) { func (l LogItems) Render(showTime bool, ll [][]byte) {
colors := map[string]int{}
for i, item := range l { for i, item := range l {
ll[i] = item.Render(showTime) info := item.ID()
c, ok := colors[item.ID()]
if !ok {
c = colorFor(info)
colors[info] = c
}
ll[i] = item.Render(c, showTime)
} }
} }

View File

@ -92,14 +92,14 @@ func TestLogItemsRender(t *testing.T) {
opts: dao.LogOptions{ opts: dao.LogOptions{
Container: "fred", Container: "fred",
}, },
e: "fred Testing 1,2,3...", e: "\x1b[38;5;161mfred\x1b[0m Testing 1,2,3...",
}, },
"pod": { "pod": {
opts: dao.LogOptions{ opts: dao.LogOptions{
Path: "blee/fred", Path: "blee/fred",
Container: "blee", Container: "blee",
}, },
e: "fred:blee Testing 1,2,3...", e: "\x1b[38;5;161mfred\x1b[0m:\x1b[38;5;161mblee\x1b[0m Testing 1,2,3...",
}, },
"full": { "full": {
opts: dao.LogOptions{ opts: dao.LogOptions{
@ -107,7 +107,7 @@ func TestLogItemsRender(t *testing.T) {
Container: "blee", Container: "blee",
ShowTimestamp: true, ShowTimestamp: true,
}, },
e: "2018-12-14T10:36:43.326972-07:00 fred:blee Testing 1,2,3...", e: "\x1b[38;5;106m2018-12-14T10:36:43.326972-07:00 \x1b[0m\x1b[38;5;161mfred\x1b[0m:\x1b[38;5;161mblee\x1b[0m Testing 1,2,3...",
}, },
} }
@ -156,14 +156,14 @@ func TestLogItemRender(t *testing.T) {
opts: dao.LogOptions{ opts: dao.LogOptions{
Container: "fred", Container: "fred",
}, },
e: "fred Testing 1,2,3...", e: "\x1b[38;5;0mfred\x1b[0m Testing 1,2,3...",
}, },
"pod": { "pod": {
opts: dao.LogOptions{ opts: dao.LogOptions{
Path: "blee/fred", Path: "blee/fred",
Container: "blee", Container: "blee",
}, },
e: "fred:blee Testing 1,2,3...", e: "\x1b[38;5;0mfred\x1b[0m:\x1b[38;5;0mblee\x1b[0m Testing 1,2,3...",
}, },
"full": { "full": {
opts: dao.LogOptions{ opts: dao.LogOptions{
@ -171,7 +171,7 @@ func TestLogItemRender(t *testing.T) {
Container: "blee", Container: "blee",
ShowTimestamp: true, ShowTimestamp: true,
}, },
e: "2018-12-14T10:36:43.326972-07:00 fred:blee Testing 1,2,3...", e: "\x1b[38;5;106m2018-12-14T10:36:43.326972-07:00 \x1b[0m\x1b[38;5;0mfred\x1b[0m:\x1b[38;5;0mblee\x1b[0m Testing 1,2,3...",
}, },
} }
@ -183,7 +183,7 @@ func TestLogItemRender(t *testing.T) {
_, n := client.Namespaced(u.opts.Path) _, n := client.Namespaced(u.opts.Path)
i.Pod, i.Container = n, u.opts.Container i.Pod, i.Container = n, u.opts.Container
assert.Equal(t, u.e, string(i.Render(u.opts.ShowTimestamp))) assert.Equal(t, u.e, string(i.Render(0, u.opts.ShowTimestamp)))
}) })
} }
} }
@ -195,6 +195,6 @@ func BenchmarkLogItemRender(b *testing.B) {
b.ResetTimer() b.ResetTimer()
b.ReportAllocs() b.ReportAllocs()
for n := 0; n < b.N; n++ { for n := 0; n < b.N; n++ {
i.Render(true) i.Render(0, true)
} }
} }

View File

@ -1,6 +1,7 @@
package dao package dao
import ( import (
"fmt"
"strings" "strings"
"time" "time"
@ -23,6 +24,11 @@ type LogOptions struct {
In, Out string In, Out string
} }
// Info returns the option pod and container info.
func (o LogOptions) Info() string {
return fmt.Sprintf("%q::%q", o.Path, o.Container)
}
// HasContainer checks if a container is present. // HasContainer checks if a container is present.
func (o LogOptions) HasContainer() bool { func (o LogOptions) HasContainer() bool {
return o.Container != "" return o.Container != ""
@ -80,9 +86,7 @@ func (o LogOptions) DecorateLog(bytes []byte) *LogItem {
if o.MultiPods { if o.MultiPods {
_, pod := client.Namespaced(o.Path) _, pod := client.Namespaced(o.Path)
item.Pod, item.Container = pod, o.Container item.Pod, item.Container = pod, o.Container
} } else {
if !o.SingleContainer {
item.Container = o.Container item.Container = o.Container
} }

View File

@ -180,30 +180,25 @@ func (p *Pod) TailLogs(ctx context.Context, c LogChan, opts LogOptions) error {
if err != nil { if err != nil {
return err return err
} }
var po v1.Pod var po v1.Pod
if err := runtime.DefaultUnstructuredConverter.FromUnstructured(o.(*unstructured.Unstructured).Object, &po); err != nil { if err := runtime.DefaultUnstructuredConverter.FromUnstructured(o.(*unstructured.Unstructured).Object, &po); err != nil {
return err return err
} }
rcos := loggableContainers(po.Status)
if opts.HasContainer() { if opts.HasContainer() {
opts.SingleContainer = true opts.SingleContainer = true
if !in(rcos, opts.Container) {
return fmt.Errorf("no logs found for container %s on %s", opts.Container, opts.Path)
}
if err := tailLogs(ctx, p, c, opts); err != nil { if err := tailLogs(ctx, p, c, opts); err != nil {
log.Error().Err(err).Msgf("Getting logs for %s failed", opts.Container)
return err return err
} }
return nil return nil
} }
if len(po.Spec.InitContainers)+len(po.Spec.Containers) == 1 { if len(po.Spec.InitContainers)+len(po.Spec.Containers) == 1 {
opts.SingleContainer = true opts.SingleContainer = true
} }
var tailed bool var tailed bool
for _, co := range po.Spec.InitContainers { for _, co := range po.Spec.InitContainers {
log.Debug().Msgf("Tailing INIT-CO %q", co.Name)
opts.Container = co.Name opts.Container = co.Name
if err := p.TailLogs(ctx, c, opts); err != nil { if err := p.TailLogs(ctx, c, opts); err != nil {
return err return err
@ -211,19 +206,26 @@ func (p *Pod) TailLogs(ctx context.Context, c LogChan, opts LogOptions) error {
tailed = true tailed = true
} }
for _, co := range po.Spec.Containers { for _, co := range po.Spec.Containers {
if in(rcos, co.Name) { log.Debug().Msgf("Tailing CO %q", co.Name)
opts.Container = co.Name opts.Container = co.Name
if err := tailLogs(ctx, p, c, opts); err != nil { if err := tailLogs(ctx, p, c, opts); err != nil {
log.Error().Err(err).Msgf("Getting logs for %s failed", co.Name)
return err return err
} }
tailed = true tailed = true
} }
for _, co := range po.Spec.EphemeralContainers {
log.Debug().Msgf("Tailing EPH-CO %q", co.Name)
opts.Container = co.Name
if err := tailLogs(ctx, p, c, opts); err != nil {
return err
}
tailed = true
} }
if !tailed { if !tailed {
return fmt.Errorf("no loggable containers found for pod %s", opts.Path) return fmt.Errorf("no loggable containers found for pod %s", opts.Path)
} }
return nil return nil
} }
@ -249,9 +251,9 @@ func tailLogs(ctx context.Context, logger Logger, c LogChan, opts LogOptions) er
func readLogs(stream io.ReadCloser, c LogChan, opts LogOptions) { func readLogs(stream io.ReadCloser, c LogChan, opts LogOptions) {
defer func() { defer func() {
log.Debug().Msgf(">>> Closing stream `%s", opts.Path) log.Debug().Msgf(">>> Closing stream %s", opts.Info())
if err := stream.Close(); err != nil { if err := stream.Close(); err != nil {
log.Error().Err(err).Msg("Cloing stream") log.Error().Err(err).Msgf("Fail to close stream %s", opts.Info())
} }
}() }()
@ -259,13 +261,12 @@ func readLogs(stream io.ReadCloser, c LogChan, opts LogOptions) {
for { for {
bytes, err := r.ReadBytes('\n') bytes, err := r.ReadBytes('\n')
if err != nil { if err != nil {
log.Warn().Err(err).Msg("Read error")
if err == io.EOF { if err == io.EOF {
log.Warn().Err(err).Msgf("stream closed") log.Warn().Err(err).Msgf("Stream closed for %s", opts.Info())
c <- NewLogItemFromString("<STREAM> closed") c <- NewLogItemFromString("<STREAM> closed")
return return
} }
log.Error().Err(err).Msgf("stream reader failed") log.Warn().Err(err).Msgf("Stream READ error %s", opts.Info())
c <- NewLogItemFromString("<STREAM> failed") c <- NewLogItemFromString("<STREAM> failed")
return return
} }
@ -332,16 +333,6 @@ func extractFQN(o runtime.Object) string {
return FQN(ns, n) return FQN(ns, n)
} }
func loggableContainers(s v1.PodStatus) []string {
var rcos []string
for _, c := range s.ContainerStatuses {
if c.State.Waiting == nil {
rcos = append(rcos, c.Name)
}
}
return rcos
}
// Check if string is in a string list. // Check if string is in a string list.
func in(ll []string, s string) bool { func in(ll []string, s string) bool {
for _, l := range ll { for _, l := range ll {

View File

@ -35,7 +35,6 @@ type Log struct {
cancelFn context.CancelFunc cancelFn context.CancelFunc
mx sync.RWMutex mx sync.RWMutex
filter string filter string
bufferSize int
lastSent int lastSent int
flushTimeout time.Duration flushTimeout time.Duration
} }
@ -70,8 +69,7 @@ func (l *Log) SetLogOptions(opts dao.LogOptions) {
// Configure sets logger configuration. // Configure sets logger configuration.
func (l *Log) Configure(opts *config.Logger) { func (l *Log) Configure(opts *config.Logger) {
l.bufferSize = opts.BufferSize l.logOptions.Lines = int64(opts.BufferSize)
l.logOptions.Lines = int64(opts.TailCount)
l.logOptions.SinceSeconds = opts.SinceSeconds l.logOptions.SinceSeconds = opts.SinceSeconds
} }
@ -231,14 +229,14 @@ func (l *Log) updateLogs(ctx context.Context, c dao.LogChan) {
if !ok { if !ok {
log.Debug().Msgf("Closed channel detected. Bailing out...") log.Debug().Msgf("Closed channel detected. Bailing out...")
l.Append(item) l.Append(item)
l.Notify(false) l.Notify(true)
return return
} }
l.Append(item) l.Append(item)
var overflow bool var overflow bool
l.mx.RLock() l.mx.RLock()
{ {
overflow = len(l.lines)-l.lastSent > l.bufferSize overflow = int64(len(l.lines)-l.lastSent) > l.logOptions.Lines
} }
l.mx.RUnlock() l.mx.RUnlock()
if overflow { if overflow {

View File

@ -1,6 +1,7 @@
package view package view
import ( import (
"bytes"
"context" "context"
"fmt" "fmt"
"io" "io"
@ -109,7 +110,7 @@ func (l *Log) LogFailed(err error) {
if l.logs.GetText(true) == logMessage { if l.logs.GetText(true) == logMessage {
l.logs.Clear() l.logs.Clear()
} }
l.write(color.Colorize(err.Error(), color.Red)) fmt.Fprintln(l.ansiWriter, tview.Escape(color.Colorize(err.Error(), color.Red)))
}) })
} }
@ -237,10 +238,6 @@ func (l *Log) Logs() *Details {
return l.logs return l.logs
} }
func (l *Log) write(lines string) {
fmt.Fprintln(l.ansiWriter, tview.Escape(lines))
}
// Flush write logs to viewer. // Flush write logs to viewer.
func (l *Log) Flush(lines dao.LogItems) { func (l *Log) Flush(lines dao.LogItems) {
defer func(t time.Time) { defer func(t time.Time) {
@ -248,11 +245,9 @@ func (l *Log) Flush(lines dao.LogItems) {
}(time.Now()) }(time.Now())
showTime := l.Indicator().showTime showTime := l.Indicator().showTime
ll := make([]string, len(lines)) ll := make([][]byte, len(lines))
for i, line := range lines { lines.Render(showTime, ll)
ll[i] = string(line.Render(showTime)) fmt.Fprintln(l.ansiWriter, string(bytes.Join(ll, []byte("\n"))))
}
l.write(strings.Join(ll, "\n"))
l.logs.ScrollToEnd() l.logs.ScrollToEnd()
l.indicator.Refresh() l.indicator.Refresh()
} }

View File

@ -103,7 +103,7 @@ func (l *logList) LogChanged(ii dao.LogItems) {
l.change++ l.change++
l.lines = "" l.lines = ""
for _, i := range ii { for _, i := range ii {
l.lines += string(i.Render(false)) l.lines += string(i.Render(0, false))
} }
} }
func (l *logList) LogCleared() { l.clear++ } func (l *logList) LogCleared() { l.clear++ }