Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Refactor logging #189

Merged
merged 4 commits into from
Feb 3, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions channels.go
Original file line number Diff line number Diff line change
Expand Up @@ -79,14 +79,14 @@ func (s *Session) getChannels(ctx context.Context, chanTypes []string, cb func(t
}
total += len(chans)

s.l().Printf("channels request #%5d, fetched: %4d, total: %8d (speed: %6.2f/sec, avg: %6.2f/sec)\n",
s.log.Printf("channels request #%5d, fetched: %4d, total: %8d (speed: %6.2f/sec, avg: %6.2f/sec)\n",
i, len(chans), total,
float64(len(chans))/float64(time.Since(reqStart).Seconds()),
float64(total)/float64(time.Since(fetchStart).Seconds()),
)

if nextcur == "" {
s.l().Printf("channels fetch complete, total: %d channels", total)
s.log.Printf("channels fetch complete, total: %d channels", total)
break
}

Expand Down
2 changes: 2 additions & 0 deletions channels_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"github.com/slack-go/slack"
"github.com/stretchr/testify/assert"

"github.com/rusq/slackdump/v2/logger"
"github.com/rusq/slackdump/v2/types"
)

Expand Down Expand Up @@ -80,6 +81,7 @@ func TestSession_getChannels(t *testing.T) {
client: mc,
Users: tt.fields.Users,
cfg: tt.fields.options,
log: logger.Silent,
}

if tt.expectFn != nil {
Expand Down
3 changes: 3 additions & 0 deletions cmd/slackdump/internal/cfg/cfg.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import (

"github.com/rusq/slackdump/v2"
"github.com/rusq/slackdump/v2/auth/browser"
"github.com/rusq/slackdump/v2/logger"
)

var (
Expand All @@ -25,6 +26,8 @@ var (
SlackCookie string
Browser browser.Browser
SlackConfig = slackdump.DefOptions

Log logger.Interface
)

type FlagMask int
Expand Down
4 changes: 1 addition & 3 deletions cmd/slackdump/internal/dump/dump.go
Original file line number Diff line number Diff line change
Expand Up @@ -100,9 +100,7 @@ func RunDump(ctx context.Context, cmd *base.Command, args []string) error {
return fmt.Errorf("file template error: %w", err)
}

cfg.SlackConfig.Logger = dlog.FromContext(ctx)

sess, err := slackdump.New(ctx, prov, cfg.SlackConfig)
sess, err := slackdump.New(ctx, prov, cfg.SlackConfig, slackdump.WithLogger(dlog.FromContext(ctx)))
if err != nil {
base.SetExitStatus(base.SApplicationError)
return err
Expand Down
2 changes: 1 addition & 1 deletion cmd/slackdump/internal/v1/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -170,7 +170,7 @@ func run(ctx context.Context, p params) error {
ctx = dlog.NewContext(ctx, lg)

// - setting the logger for the application.
p.appCfg.SlackConfig.Logger = lg
p.appCfg.Log = lg

// - trace init
if traceStopFn, err := initTrace(lg, p.traceFile); err != nil {
Expand Down
3 changes: 1 addition & 2 deletions cmd/slackdump/internal/workspace/list.go
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,6 @@ func printAll(m manager, current string, wsps []string) {
fmt.Fprintln(tw,
"C\tname\tfilename\tmodified\tteam\tuser\terror\n"+
"-\t-------\t------------\t-------------------\t---------\t--------\t-----")
cfg.SlackConfig.Logger = logger.Silent
cfg.SlackConfig.UserCache.Disabled = true
for _, name := range wsps {
curr := ""
Expand All @@ -119,7 +118,7 @@ func userInfo(ctx context.Context, m manager, name string) (*slack.AuthTestRespo
if err != nil {
return nil, err
}
sess, err := slackdump.New(ctx, prov, cfg.SlackConfig)
sess, err := slackdump.New(ctx, prov, cfg.SlackConfig, slackdump.WithLogger(logger.Silent))
if err != nil {
return nil, err
}
Expand Down
2 changes: 1 addition & 1 deletion cmd/slackdump/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -164,7 +164,7 @@ func invoke(cmd *base.Command, args []string) error {
} else {
lg.SetPrefix(cmd.Name() + ": ")
ctx = dlog.NewContext(ctx, lg)
cfg.SlackConfig.Logger = lg
cfg.Log = lg
}

if cmd.RequireAuth {
Expand Down
10 changes: 4 additions & 6 deletions config.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,8 +10,6 @@ import (
ut "github.com/go-playground/universal-translator"
"github.com/go-playground/validator/v10"
translations "github.com/go-playground/validator/v10/translations/en"

"github.com/rusq/slackdump/v2/logger"
)

// Config is the option set for the Session.
Expand All @@ -24,7 +22,7 @@ type Config struct {
UserCache CacheConfig

BaseLocation string // base location for the dump files
Logger logger.Interface
Logfile string
}

// CacheConfig represents the options for the cache.
Expand Down Expand Up @@ -92,9 +90,9 @@ var DefOptions = Config{
},
DumpFiles: false,
UserCache: CacheConfig{Filename: "users.cache", MaxAge: 4 * time.Hour},
CacheDir: "", // default cache dir
Logger: logger.Default, // default logger is the... default logger
BaseLocation: ".", // default location is the current directory
CacheDir: "", // default cache dir
BaseLocation: ".", // default location is the current directory
Logfile: "", // empty, means STDERR
}

var (
Expand Down
8 changes: 4 additions & 4 deletions export/expfmt_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,10 +22,10 @@ func Test_newFileExporter(t *testing.T) {
args args
wantT string
}{
{"unknown is nodownload", args{t: ExportType(255), l: logger.Default, token: "abcd"}, "dl.Nothing"},
{"no", args{t: TNoDownload, l: logger.Default, token: "abcd"}, "dl.Nothing"},
{"standard", args{t: TStandard, fs: fsadapter.NewDirectory("."), cl: &slack.Client{}, l: logger.Default, token: "abcd"}, "*dl.Std"},
{"mattermost", args{t: TMattermost, fs: fsadapter.NewDirectory("."), cl: &slack.Client{}, l: logger.Default, token: "abcd"}, "*dl.Mattermost"},
{"unknown is nodownload", args{t: ExportType(255), l: logger.Silent, token: "abcd"}, "dl.Nothing"},
{"no", args{t: TNoDownload, l: logger.Silent, token: "abcd"}, "dl.Nothing"},
{"standard", args{t: TStandard, fs: fsadapter.NewDirectory("."), cl: &slack.Client{}, l: logger.Silent, token: "abcd"}, "*dl.Std"},
{"mattermost", args{t: TMattermost, fs: fsadapter.NewDirectory("."), cl: &slack.Client{}, l: logger.Silent, token: "abcd"}, "*dl.Mattermost"},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
Expand Down
102 changes: 53 additions & 49 deletions fsadapter/zipfs_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -145,60 +145,64 @@ func TestNewZIP(t *testing.T) {
}

func TestCreateConcurrency(t *testing.T) {
// test for GH issue#90 - race condition in ZIP.Create
const (
numRoutines = 16
testContentsSz = 1 * (1 << 20)
)

var buf bytes.Buffer
var wg sync.WaitGroup

zw := zip.NewWriter(&buf)
defer zw.Close()

fsa := NewZIP(zw)
defer fsa.Close()

// prepare workers
readySteadyGo := make(chan struct{})
panicAttacks := make(chan any, numRoutines)

for i := 0; i < numRoutines; i++ {
wg.Add(1)
go func(n int) {
defer func() {
if r := recover(); r != nil {
panicAttacks <- fmt.Sprintf("ZIP.Create race condition in gr %d: %v", n, r)
t.Parallel()
t.Run("issue#90", func(t *testing.T) {
t.Parallel()
// test for GH issue#90 - race condition in ZIP.Create
const (
numRoutines = 16
testContentsSz = 1 * (1 << 20)
)

var buf bytes.Buffer
var wg sync.WaitGroup

zw := zip.NewWriter(&buf)
defer zw.Close()

fsa := NewZIP(zw)
defer fsa.Close()

// prepare workers
readySteadyGo := make(chan struct{})
panicAttacks := make(chan any, numRoutines)

for i := 0; i < numRoutines; i++ {
wg.Add(1)
go func(n int) {
defer func() {
if r := recover(); r != nil {
panicAttacks <- fmt.Sprintf("ZIP.Create race condition in gr %d: %v", n, r)
}
}()

defer wg.Done()
var contents bytes.Buffer
if _, err := io.CopyN(&contents, rand.Reader, testContentsSz); err != nil {
panic(err)
}
}()

defer wg.Done()
var contents bytes.Buffer
if _, err := io.CopyN(&contents, rand.Reader, testContentsSz); err != nil {
panic(err)
}

<-readySteadyGo
fw, err := fsa.Create(fmt.Sprintf("file%d", n))
if err != nil {
panic(err)
}
defer fw.Close()
<-readySteadyGo
fw, err := fsa.Create(fmt.Sprintf("file%d", n))
if err != nil {
panic(err)
}
defer fw.Close()

if _, err := io.Copy(fw, &contents); err != nil {
panic(err)
if _, err := io.Copy(fw, &contents); err != nil {
panic(err)
}
}(i)
}
close(readySteadyGo)
wg.Wait()
close(panicAttacks)
for r := range panicAttacks {
if r != nil {
t.Error(r)
}
}(i)
}
close(readySteadyGo)
wg.Wait()
close(panicAttacks)
for r := range panicAttacks {
if r != nil {
t.Error(r)
}
}
})
}

func TestZIP_normalizePath(t *testing.T) {
Expand Down
6 changes: 4 additions & 2 deletions internal/app/config/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,8 @@ type Params struct {
Emoji EmojiParams

SlackConfig slackdump.Config

Log logger.Interface
}

type EmojiParams struct {
Expand Down Expand Up @@ -160,8 +162,8 @@ func (in Input) Producer(fn func(string) error) error {
}

func (p *Params) Logger() logger.Interface {
if p.SlackConfig.Logger == nil {
if p.Log == nil {
return logger.Default
}
return p.SlackConfig.Logger
return p.Log
}
9 changes: 6 additions & 3 deletions internal/network/network.go
Original file line number Diff line number Diff line change
Expand Up @@ -83,10 +83,13 @@ func WithRetry(ctx context.Context, l *rate.Limiter, maxAttempts int, fn func()
}

// waitTime returns the amount of time to wait before retrying depending on
// the current attempt. The wait time is calculated as (x+2)^3 seconds, where
// x is the current attempt number. The maximum wait time is capped at 5
// the current attempt. This variable exists to reduce the test time.
var waitTime = cubicWait

// cubicWait is the wait time function. Time is calculated as (x+2)^3 seconds,
// where x is the current attempt number. The maximum wait time is capped at 5
// minutes.
func waitTime(attempt int) time.Duration {
func cubicWait(attempt int) time.Duration {
x := attempt + 2 // this is to ensure that we sleep at least 8 seconds.
delay := time.Duration(x*x*x) * time.Second
if delay > MaxAllowedWaitTime {
Expand Down
10 changes: 6 additions & 4 deletions internal/network/network_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -148,14 +148,16 @@ func Test_withRetry(t *testing.T) {
}

func Test500ErrorHandling(t *testing.T) {
t.Parallel()
waitTime = func(attempt int) time.Duration { return 50 * time.Millisecond }
defer func() {
waitTime = cubicWait
}()

var codes = []int{500, 502, 503, 504, 598}
for _, code := range codes {
var thisCode = code
// This test is to ensure that we handle 500 errors correctly.
t.Run(fmt.Sprintf("%d error", code), func(t *testing.T) {
t.Parallel()

const (
testRetryCount = 1
Expand Down Expand Up @@ -227,7 +229,7 @@ func Test500ErrorHandling(t *testing.T) {
})
}

func Test_waitTime(t *testing.T) {
func Test_cubicWait(t *testing.T) {
type args struct {
attempt int
}
Expand All @@ -245,7 +247,7 @@ func Test_waitTime(t *testing.T) {
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
if got := waitTime(tt.args.attempt); !reflect.DeepEqual(got, tt.want) {
if got := cubicWait(tt.args.attempt); !reflect.DeepEqual(got, tt.want) {
t.Errorf("waitTime() = %v, want %v", got, tt.want)
}
})
Expand Down
20 changes: 16 additions & 4 deletions logger/logger.go
Original file line number Diff line number Diff line change
@@ -1,13 +1,13 @@
package logger

import (
"io"
"log"
"os"

"github.com/rusq/dlog"
)

// Interface is the interface for a logger.
type Interface interface {
Debug(...any)
Debugf(fmt string, a ...any)
Expand All @@ -16,8 +16,20 @@ type Interface interface {
Println(...any)
}

// Default is the default logger. It logs to stderr and debug logging can be
// enabled by setting the DEBUG environment variable to 1. For example:
//
// DEBUG=1 slackdump
var Default = dlog.New(log.Default().Writer(), "", log.LstdFlags, os.Getenv("DEBUG") == "1")

// note: previously ioutil.Discard which is not deprecated in favord of io.Discard
// so this is valid only from go1.16
var Silent = dlog.New(io.Discard, "", log.LstdFlags, false)
// Silent is a logger that does not log anything.
var Silent = silent{}

// Silent is a logger that does not log anything.
type silent struct{}

func (s silent) Debug(...any) {}
func (s silent) Debugf(fmt string, a ...any) {}
func (s silent) Print(...any) {}
func (s silent) Printf(fmt string, a ...any) {}
func (s silent) Println(...any) {}
16 changes: 16 additions & 0 deletions logger/logger_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
package logger

import "testing"

func BenchmarkSlientPrintf(b *testing.B) {
var l = Silent
for i := 0; i < b.N; i++ {
l.Printf("hello world, %s, %d", "foo", i)
}
// This benchmark compares the performance of the Silent logger when
// using io.Discard, and when using a no-op function.
// io.Discard: BenchmarkSlientPrintf-16 93075956 12.92 ns/op 8 B/op 0 allocs/op
// no-op func: BenchmarkSlientPrintf-16 1000000000 0.2364 ns/op 0 B/op 0 allocs/op
//
// Oh, look! We have an WINNER. The no-op function wins, no surprises.
}
Loading