Skip to content

Commit 0d5ea79

Browse files
iapershiniapershin
committed
feat(client): add debug struct logging
Signed-off-by: Yaroslav Pershin <62902094+iapershin@users.noreply.github.com>
1 parent d117ce2 commit 0d5ea79

File tree

5 files changed

+148
-89
lines changed

5 files changed

+148
-89
lines changed

‎client/cmd/trdl/main.go‎

Lines changed: 14 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -3,15 +3,16 @@ package main
33
import (
44
"fmt"
55
"os"
6-
"time"
76

87
"github.com/gookit/color"
98
"github.com/spf13/cobra"
109

1110
"github.com/werf/trdl/client/cmd/trdl/command"
11+
"github.com/werf/trdl/client/internal/logger"
1212
)
1313

1414
var homeDir string
15+
var debug bool
1516

1617
func main() {
1718
if err := rootCmd().Execute(); err != nil {
@@ -27,6 +28,16 @@ func rootCmd() *cobra.Command {
2728
Long: "The universal package manager for delivering your software updates securely from a TUF repository (more details on https://trdl.dev)",
2829
SilenceUsage: true,
2930
SilenceErrors: true,
31+
PersistentPreRun: func(cmd *cobra.Command, args []string) {
32+
logLevel := "info"
33+
if debug {
34+
logLevel = "debug"
35+
}
36+
logger.GlobalLogger = logger.SetupGlobalLogger(logger.LoggerOptions{
37+
Level: logLevel,
38+
LogFormat: "text",
39+
})
40+
},
3041
CompletionOptions: cobra.CompletionOptions{
3142
DisableDefaultCmd: true,
3243
},
@@ -35,6 +46,8 @@ func rootCmd() *cobra.Command {
3546
rootCmd.SetHelpCommand(&cobra.Command{Hidden: true})
3647
SetupHomeDir(rootCmd)
3748

49+
rootCmd.PersistentFlags().BoolVarP(&debug, "debug", "d", false, "Enable debug output")
50+
3851
groups := &command.Groups{}
3952
*groups = append(*groups, command.Groups{
4053
{
@@ -67,26 +80,6 @@ func rootCmd() *cobra.Command {
6780
groups.Add(rootCmd)
6881

6982
command.ActsAsRootCommand(rootCmd, *groups...)
70-
71-
for _, cmd := range rootCmd.Commands() {
72-
copyCmdRunE := cmd.RunE
73-
cmd.RunE = func(cmd *cobra.Command, args []string) error {
74-
startTime := time.Now()
75-
76-
log := func(event, format string, args ...interface{}) {
77-
fmt.Printf("[%s] [%.2fs] %s: %s\n",
78-
time.Now().Format("15:04:05.000"), time.Since(startTime).Seconds(), event, fmt.Sprintf(format, args...))
79-
}
80-
81-
log("COMMAND_STARTED", cmd.Name())
82-
83-
err := copyCmdRunE(cmd, args)
84-
85-
log("COMMAND_DONE", "(Total: %.2fs)", time.Since(startTime).Seconds())
86-
87-
return err
88-
}
89-
}
9083

9184
return rootCmd
9285
}

‎client/internal/logger/log.go‎

Lines changed: 102 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,102 @@
1+
package logger
2+
3+
import (
4+
"log/slog"
5+
"os"
6+
)
7+
8+
var GlobalLogger *Logger
9+
10+
type LoggerInterface interface {
11+
Debug(msg string, args ...any)
12+
Error(msg string, args ...any)
13+
Info(msg string, args ...any)
14+
Warn(msg string, args ...any)
15+
With(args ...any) LoggerInterface
16+
}
17+
18+
type Logger struct {
19+
LoggerInterface
20+
}
21+
22+
type LoggerOptions struct {
23+
Level string
24+
LogFormat string
25+
}
26+
27+
func SetupGlobalLogger(opts LoggerOptions) *Logger {
28+
return NewLogger(&SlogWrapper{
29+
logger: NewSlogLogger(SlogOptions{
30+
Handler: slogHandler(opts.LogFormat, slogLevel(opts.Level)),
31+
}),
32+
})
33+
}
34+
35+
func NewLogger(l LoggerInterface) *Logger {
36+
return &Logger{LoggerInterface: l}
37+
}
38+
39+
type SlogOptions struct {
40+
Handler slog.Handler
41+
}
42+
43+
func NewSlogLogger(opts SlogOptions) *slog.Logger {
44+
return slog.New(opts.Handler)
45+
}
46+
47+
type SlogWrapper struct {
48+
logger *slog.Logger
49+
}
50+
51+
func (s *SlogWrapper) Debug(msg string, args ...any) {
52+
s.logger.Debug(msg, args...)
53+
}
54+
55+
func (s *SlogWrapper) Error(msg string, args ...any) {
56+
s.logger.Error(msg, args...)
57+
}
58+
59+
func (s *SlogWrapper) Info(msg string, args ...any) {
60+
s.logger.Info(msg, args...)
61+
}
62+
63+
func (s *SlogWrapper) Warn(msg string, args ...any) {
64+
s.logger.Warn(msg, args...)
65+
}
66+
67+
func (s *SlogWrapper) With(args ...any) LoggerInterface {
68+
return &SlogWrapper{
69+
logger: s.logger.With(args...),
70+
}
71+
}
72+
73+
func (l *Logger) With(args ...any) *Logger {
74+
return &Logger{LoggerInterface: l.LoggerInterface.With(args...)}
75+
}
76+
77+
func slogLevel(l string) slog.Level {
78+
switch l {
79+
case "debug":
80+
return slog.LevelDebug
81+
case "info":
82+
return slog.LevelInfo
83+
case "warn":
84+
return slog.LevelWarn
85+
case "error":
86+
return slog.LevelError
87+
default:
88+
return slog.LevelInfo
89+
}
90+
}
91+
92+
func slogHandler(format string, level slog.Level) slog.Handler {
93+
options := &slog.HandlerOptions{
94+
Level: level,
95+
}
96+
switch format {
97+
case "json":
98+
return slog.NewJSONHandler(os.Stdout, options)
99+
default:
100+
return slog.NewTextHandler(os.Stdout, options)
101+
}
102+
}

‎client/pkg/tuf/client.go‎

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

1313
"github.com/werf/lockgate"
1414
"github.com/werf/lockgate/pkg/file_locker"
15+
"github.com/werf/trdl/client/internal/logger"
1516
"github.com/werf/trdl/client/pkg/util"
1617
)
1718

@@ -87,13 +88,11 @@ func (c *Client) initTufClient() error {
8788
}
8889

8990
var remote tufClient.RemoteStore
90-
var httpClient *http.Client
91-
if os.Getenv("TRDL_TUF_REMOTE_CLIENT_TRACE") == "1" {
92-
httpClient = &http.Client{
93-
Transport: &TracingTransport{
94-
Transport: http.DefaultTransport,
95-
},
96-
}
91+
httpClient := &http.Client{
92+
Transport: &TracingTransport{
93+
Transport: http.DefaultTransport,
94+
Logger: *logger.GlobalLogger,
95+
},
9796
}
9897
remote, err = tufClient.HTTPRemoteStore(c.repoUrl, nil, httpClient)
9998
if err != nil {

‎client/pkg/tuf/trace.go‎

Lines changed: 24 additions & 59 deletions
Original file line numberDiff line numberDiff line change
@@ -1,93 +1,58 @@
11
package tuf
22

33
import (
4-
"crypto/tls"
5-
"fmt"
64
"net/http"
75
"net/http/httptrace"
8-
"strings"
96
"time"
10-
)
117

12-
const (
13-
eventStart = "START"
14-
eventDNSStart = "DNS_START"
15-
eventDNSDone = "DNS_DONE"
16-
eventConnectStart = "CONNECT_START"
17-
eventConnectDone = "CONNECT_DONE"
18-
eventConnectError = "CONNECT_ERROR"
19-
eventTLSStart = "TLS_START"
20-
eventTLSDone = "TLS_DONE"
21-
eventTLSError = "TLS_ERROR"
22-
eventResponseFirstByte = "RESPONSE_FIRST_BYTE"
23-
eventRequestError = "REQUEST_ERROR"
24-
eventRequestDone = "REQUEST_DONE"
8+
"github.com/werf/trdl/client/internal/logger"
259
)
2610

2711
type TracingTransport struct {
2812
Transport http.RoundTripper
13+
Logger logger.Logger
2914
}
3015

3116
func (t *TracingTransport) RoundTrip(req *http.Request) (*http.Response, error) {
17+
log := t.Logger.With("sorce", "tuf-client")
3218
startTime := time.Now()
3319

34-
logBase := func(indent int, event, format string, args ...interface{}) {
35-
indentStr := strings.Repeat(" ", 2 * indent)
36-
fmt.Printf("%s [%.2fs] %s: %s\n",
37-
indentStr, time.Since(startTime).Seconds(), event, fmt.Sprintf(format, args...))
38-
}
39-
40-
logMain := func(event, format string, args ...interface{}) {
41-
logBase(1, event, format, args...)
42-
}
43-
44-
logStep := func(event, format string, args ...interface{}) {
45-
logBase(2, event, format, args...)
46-
}
47-
48-
logMain(eventStart, "Request to %s %s", req.Method, req.URL.String())
20+
log.Debug("Request started",
21+
"method", req.Method,
22+
"url", req.URL.String(),
23+
)
4924

5025
trace := &httptrace.ClientTrace{
51-
DNSStart: func(info httptrace.DNSStartInfo) {
52-
logStep(eventDNSStart, "Lookup %s", info.Host)
53-
},
5426
DNSDone: func(info httptrace.DNSDoneInfo) {
55-
logStep(eventDNSDone, "Resolved %+v", info.Addrs)
56-
},
57-
ConnectStart: func(network, addr string) {
58-
logStep(eventConnectStart, "Connecting to %s (%s)", addr, network)
27+
log.Debug("DNS lookup done", "host", info.Addrs)
5928
},
6029
ConnectDone: func(network, addr string, err error) {
6130
if err != nil {
62-
logStep(eventConnectError, "Failed to %s: %v", addr, err)
63-
} else {
64-
logStep(eventConnectDone, "Connected to %s", addr)
31+
log.Debug("Failed to connect",
32+
"host", addr,
33+
"error", err,
34+
)
35+
return
6536
}
66-
},
67-
TLSHandshakeStart: func() {
68-
logStep(eventTLSStart, "Starting handshake")
69-
},
70-
TLSHandshakeDone: func(state tls.ConnectionState, err error) {
71-
if err != nil {
72-
logStep(eventTLSError, "Handshake failed: %v", err)
73-
} else {
74-
logStep(eventTLSDone, "Handshake completed")
75-
}
76-
},
77-
GotFirstResponseByte: func() {
78-
logStep(eventResponseFirstByte, "Received first byte")
37+
log.Debug("Connected", "address", addr)
7938
},
8039
}
8140

8241
req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))
8342

8443
resp, err := t.Transport.RoundTrip(req)
8544
if err != nil {
86-
logMain(eventRequestError, "Request failed: %v", err)
45+
log.Debug("Failed to send request",
46+
"url", req.URL.String(),
47+
"error", err,
48+
)
8749
return nil, err
8850
}
8951

90-
logMain(eventRequestDone, "Completed with status %s (Total: %.2fs)", resp.Status, time.Since(startTime).Seconds())
91-
52+
log.Debug("Request completed",
53+
"status", resp.Status,
54+
"duration", time.Since(startTime).Seconds(),
55+
)
56+
9257
return resp, nil
93-
}
58+
}

‎e2e/tests/client/basic_test.go‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,7 @@ var _ = Describe("Basic", func() {
1717
It("add", func() {
1818
testutil.RunSucceedCommand(
1919
"",
20-
trdlBinPath,
20+
trdlBinPath, "--debug",
2121
"add", testRepoName, validRepoUrl, validRootVersion, validRootSHA512,
2222
)
2323

@@ -28,7 +28,7 @@ var _ = Describe("Basic", func() {
2828
BeforeEach(func() {
2929
testutil.RunSucceedCommand(
3030
"",
31-
trdlBinPath,
31+
trdlBinPath, "--debug",
3232
"add", testRepoName, validRepoUrl, validRootVersion, validRootSHA512,
3333
)
3434
})

0 commit comments

Comments
 (0)