Skip to content

Commit 695f58d

Browse files
rodneyosodorodneyosodo
authored
NOISSUE - Use slog for Logging (#52)
* feat(logging): Use slog for logging This commit adds logging functionality to the proxy functions in order to track and log connections. The changes include: - Adding level to be type slog.Leveler - Changing function signatures to accept a slog logger parameter These changes improve the observability and debugging capabilities of the codebase by providing detailed logs for tracking connections handled by the proxy functions. No breaking changes or other significant modifications were made in this commit. Signed-off-by: Rodney Osodo <[email protected]> * Add logging statements for starting proxy servers on different ports Signed-off-by: Rodney Osodo <[email protected]> --------- Signed-off-by: Rodney Osodo <[email protected]>
1 parent 0b102d0 commit 695f58d

File tree

12 files changed

+96
-142
lines changed

12 files changed

+96
-142
lines changed

‎cmd/main.go

Lines changed: 40 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -5,13 +5,13 @@ import (
55
"crypto/tls"
66
"fmt"
77
"log"
8+
"log/slog"
89
"net/http"
910
"os"
1011
"os/signal"
1112
"strconv"
1213
"syscall"
1314

14-
mglog "github.com/absmach/magistrala/logger"
1515
"github.com/absmach/mproxy/examples/simple"
1616
hproxy "github.com/absmach/mproxy/pkg/http"
1717
"github.com/absmach/mproxy/pkg/mqtt"
@@ -104,7 +104,7 @@ type config struct {
104104
wsMQTTConfig WSMQTTConfig
105105
wsConfig WSConfig
106106

107-
logLevel string
107+
logLevel slog.Level
108108
}
109109

110110
type WSConfig struct {
@@ -146,10 +146,10 @@ type HTTPConfig struct {
146146
func main() {
147147
cfg := loadConfig()
148148

149-
logger, err := mglog.New(os.Stdout, cfg.logLevel)
150-
if err != nil {
151-
log.Fatalf(err.Error())
152-
}
149+
logHandler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
150+
Level: cfg.logLevel,
151+
})
152+
logger := slog.New(logHandler)
153153

154154
h := simple.New(logger)
155155

@@ -164,30 +164,30 @@ func main() {
164164
}
165165

166166
// WSS - MQTT
167-
logger.Info(fmt.Sprintf("Starting encrypted WebSocket proxy on port %s ", cfg.wsMQTTConfig.wssPort))
167+
logServerStart(logger, "encrypted WebSocket", cfg.wsMQTTConfig.wssPort, cfg.wsMQTTConfig.targetPort)
168168
go proxyMQTTWSS(cfg, tlsCfg, logger, h, errs)
169169
// MQTTS
170-
logger.Info(fmt.Sprintf("Starting MQTTS proxy on port %s ", cfg.mqttConfig.mqttsPort))
170+
logServerStart(logger, "MQTTS", cfg.mqttConfig.mqttsPort, cfg.mqttConfig.targetPort)
171171
go proxyMQTTS(ctx, cfg.mqttConfig, tlsCfg, logger, h, errs)
172172
// WSS
173-
logger.Info(fmt.Sprintf("Starting WSS proxy on port %s ", cfg.wsConfig.port))
173+
logServerStart(logger, "WSS", cfg.wsConfig.port, cfg.wsConfig.targetPort)
174174
go proxyWSS(ctx, cfg, logger, h, errs)
175175
// HTTPS
176-
logger.Info(fmt.Sprintf("Starting HTTPS proxy on port %s ", cfg.httpConfig.port))
176+
logServerStart(logger, "HTTPS", cfg.httpConfig.port, cfg.httpConfig.targetPort)
177177
go proxyHTTPS(ctx, cfg.httpConfig, logger, h, errs)
178178
} else {
179179
// WS - MQTT
180-
logger.Info(fmt.Sprintf("Starting WebSocket proxy on port %s ", cfg.wsMQTTConfig.port))
180+
logServerStart(logger, "WebSocket", cfg.wsMQTTConfig.port, cfg.wsMQTTConfig.targetPort)
181181
go proxyMQTTWS(cfg.wsMQTTConfig, logger, h, errs)
182182

183183
// MQTT
184-
logger.Info(fmt.Sprintf("Starting MQTT proxy on port %s ", cfg.mqttConfig.port))
184+
logServerStart(logger, "MQTT", cfg.mqttConfig.port, cfg.mqttConfig.targetPort)
185185
go proxyMQTT(ctx, cfg.mqttConfig, logger, h, errs)
186186
// WS
187-
logger.Info(fmt.Sprintf("Starting WS proxy on port %s ", cfg.wsConfig.port))
187+
logServerStart(logger, "WS", cfg.wsConfig.port, cfg.wsConfig.targetPort)
188188
go proxyWS(ctx, cfg.wsConfig, logger, h, errs)
189189
// HTTP
190-
logger.Info(fmt.Sprintf("Starting HTTP proxy on port %s ", cfg.httpConfig.port))
190+
logServerStart(logger, "HTTP", cfg.httpConfig.port, cfg.httpConfig.targetPort)
191191
go proxyHTTP(ctx, cfg.httpConfig, logger, h, errs)
192192
}
193193

@@ -197,7 +197,7 @@ func main() {
197197
errs <- fmt.Errorf("%s", <-c)
198198
}()
199199

200-
err = <-errs
200+
err := <-errs
201201
logger.Error(fmt.Sprintf("mProxy terminated: %s", err))
202202
}
203203

@@ -215,6 +215,11 @@ func loadConfig() config {
215215
log.Fatalf("Invalid value passed for %s\n", envClientTLS)
216216
}
217217

218+
var level slog.Level
219+
if err := level.UnmarshalText([]byte(env(envLogLevel, defLogLevel))); err != nil {
220+
log.Fatalf("Invalid value passed for %s with error: %s\n", envLogLevel, err)
221+
}
222+
218223
return config{
219224
// WS
220225
wsMQTTConfig: WSMQTTConfig{
@@ -261,42 +266,42 @@ func loadConfig() config {
261266
},
262267

263268
// Log
264-
logLevel: env(envLogLevel, defLogLevel),
269+
logLevel: level,
265270
}
266271
}
267272

268-
func proxyMQTTWS(cfg WSMQTTConfig, logger mglog.Logger, handler session.Handler, errs chan error) {
273+
func proxyMQTTWS(cfg WSMQTTConfig, logger *slog.Logger, handler session.Handler, errs chan error) {
269274
target := fmt.Sprintf("%s:%s", cfg.targetHost, cfg.targetPort)
270275
wp := websocket.New(target, cfg.targetPath, cfg.targetScheme, handler, nil, logger)
271276
http.Handle(cfg.path, wp.Handler())
272277

273278
errs <- wp.Listen(cfg.port)
274279
}
275280

276-
func proxyMQTTWSS(cfg config, tlsCfg *tls.Config, logger mglog.Logger, handler session.Handler, errs chan error) {
281+
func proxyMQTTWSS(cfg config, tlsCfg *tls.Config, logger *slog.Logger, handler session.Handler, errs chan error) {
277282
target := fmt.Sprintf("%s:%s", cfg.wsMQTTConfig.targetHost, cfg.wsMQTTConfig.targetPort)
278283
wp := websocket.New(target, cfg.wsMQTTConfig.targetPath, cfg.wsMQTTConfig.targetScheme, handler, nil, logger)
279284
http.Handle(cfg.wsMQTTConfig.wssPath, wp.Handler())
280285
errs <- wp.ListenTLS(tlsCfg, cfg.serverCert, cfg.serverKey, cfg.wsMQTTConfig.wssPort)
281286
}
282287

283-
func proxyMQTT(ctx context.Context, cfg MQTTConfig, logger mglog.Logger, handler session.Handler, errs chan error) {
288+
func proxyMQTT(ctx context.Context, cfg MQTTConfig, logger *slog.Logger, handler session.Handler, errs chan error) {
284289
address := fmt.Sprintf("%s:%s", cfg.host, cfg.port)
285290
target := fmt.Sprintf("%s:%s", cfg.targetHost, cfg.targetPort)
286291
mp := mqtt.New(address, target, handler, nil, logger)
287292

288293
errs <- mp.Listen(ctx)
289294
}
290295

291-
func proxyMQTTS(ctx context.Context, cfg MQTTConfig, tlsCfg *tls.Config, logger mglog.Logger, handler session.Handler, errs chan error) {
296+
func proxyMQTTS(ctx context.Context, cfg MQTTConfig, tlsCfg *tls.Config, logger *slog.Logger, handler session.Handler, errs chan error) {
292297
address := fmt.Sprintf("%s:%s", cfg.host, cfg.mqttsPort)
293298
target := fmt.Sprintf("%s:%s", cfg.targetHost, cfg.targetPort)
294299
mp := mqtt.New(address, target, handler, nil, logger)
295300

296301
errs <- mp.ListenTLS(ctx, tlsCfg)
297302
}
298303

299-
func proxyHTTP(ctx context.Context, cfg HTTPConfig, logger mglog.Logger, handler session.Handler, errs chan error) {
304+
func proxyHTTP(_ context.Context, cfg HTTPConfig, logger *slog.Logger, handler session.Handler, errs chan error) {
300305
address := fmt.Sprintf("%s:%s", cfg.host, cfg.port)
301306
target := fmt.Sprintf("%s:%s", cfg.targetHost, cfg.targetPort)
302307
hp, err := hproxy.NewProxy(address, target, handler, logger)
@@ -308,7 +313,7 @@ func proxyHTTP(ctx context.Context, cfg HTTPConfig, logger mglog.Logger, handler
308313
errs <- hp.Listen()
309314
}
310315

311-
func proxyHTTPS(ctx context.Context, cfg HTTPConfig, logger mglog.Logger, handler session.Handler, errs chan error) {
316+
func proxyHTTPS(_ context.Context, cfg HTTPConfig, logger *slog.Logger, handler session.Handler, errs chan error) {
312317
address := fmt.Sprintf("%s:%s", cfg.host, cfg.port)
313318
target := fmt.Sprintf("%s:%s", cfg.targetHost, cfg.targetPort)
314319
hp, err := hproxy.NewProxy(address, target, handler, logger)
@@ -320,7 +325,7 @@ func proxyHTTPS(ctx context.Context, cfg HTTPConfig, logger mglog.Logger, handle
320325
errs <- hp.ListenTLS(cfg.serverCert, cfg.serverKey)
321326
}
322327

323-
func proxyWS(ctx context.Context, cfg WSConfig, logger mglog.Logger, handler session.Handler, errs chan error) {
328+
func proxyWS(_ context.Context, cfg WSConfig, logger *slog.Logger, handler session.Handler, errs chan error) {
324329
address := fmt.Sprintf("%s:%s", cfg.host, cfg.port)
325330
target := fmt.Sprintf("%s:%s", cfg.targetHost, cfg.targetPort)
326331
wp, err := websockets.NewProxy(address, target, logger, handler)
@@ -330,7 +335,7 @@ func proxyWS(ctx context.Context, cfg WSConfig, logger mglog.Logger, handler ses
330335
errs <- wp.Listen()
331336
}
332337

333-
func proxyWSS(ctx context.Context, cfg config, logger mglog.Logger, handler session.Handler, errs chan error) {
338+
func proxyWSS(_ context.Context, cfg config, logger *slog.Logger, handler session.Handler, errs chan error) {
334339
address := fmt.Sprintf("%s:%s", cfg.wsConfig.host, cfg.wsConfig.port)
335340
target := fmt.Sprintf("%s:%s", cfg.wsConfig.targetHost, cfg.wsConfig.targetPort)
336341
wp, err := websockets.NewProxy(address, target, logger, handler)
@@ -339,3 +344,14 @@ func proxyWSS(ctx context.Context, cfg config, logger mglog.Logger, handler sess
339344
}
340345
errs <- wp.ListenTLS(cfg.serverCert, cfg.serverKey)
341346
}
347+
348+
func logServerStart(logger *slog.Logger, name, port, targetPort string) {
349+
logger.Info("Starting "+name+" proxy",
350+
slog.Group("server",
351+
slog.String("port", port),
352+
),
353+
slog.Group("target",
354+
slog.String("port", targetPort),
355+
),
356+
)
357+
}

‎examples/simple/simple.go

Lines changed: 30 additions & 57 deletions
Original file line numberDiff line numberDiff line change
@@ -3,10 +3,8 @@ package simple
33
import (
44
"context"
55
"errors"
6-
"fmt"
7-
"strings"
6+
"log/slog"
87

9-
"github.com/absmach/magistrala/logger"
108
"github.com/absmach/mproxy/pkg/session"
119
)
1210

@@ -16,11 +14,11 @@ var _ session.Handler = (*Handler)(nil)
1614

1715
// Handler implements mqtt.Handler interface
1816
type Handler struct {
19-
logger logger.Logger
17+
logger *slog.Logger
2018
}
2119

2220
// New creates new Event entity
23-
func New(logger logger.Logger) *Handler {
21+
func New(logger *slog.Logger) *Handler {
2422
return &Handler{
2523
logger: logger,
2624
}
@@ -29,91 +27,66 @@ func New(logger logger.Logger) *Handler {
2927
// AuthConnect is called on device connection,
3028
// prior forwarding to the MQTT broker
3129
func (h *Handler) AuthConnect(ctx context.Context) error {
32-
s, ok := session.FromContext(ctx)
33-
if !ok {
34-
h.logger.Error(errSessionMissing.Error())
35-
return errSessionMissing
36-
}
37-
h.logger.Info(fmt.Sprintf("AuthConnect() - sessionID: %s, username: %s, password: %s, client_CN: %s", s.ID, s.Username, string(s.Password), s.Cert.Subject.CommonName))
38-
return nil
30+
return h.logAction(ctx, "AuthConnect", nil, nil)
3931
}
4032

4133
// AuthPublish is called on device publish,
4234
// prior forwarding to the MQTT broker
4335
func (h *Handler) AuthPublish(ctx context.Context, topic *string, payload *[]byte) error {
44-
s, ok := session.FromContext(ctx)
45-
if !ok {
46-
h.logger.Error(errSessionMissing.Error())
47-
return errSessionMissing
48-
}
49-
h.logger.Info(fmt.Sprintf("AuthPublish() - sessionID: %s, topic: %s, payload: %s", s.ID, *topic, string(*payload)))
50-
51-
return nil
36+
return h.logAction(ctx, "AuthPublish", &[]string{*topic}, payload)
5237
}
5338

5439
// AuthSubscribe is called on device publish,
5540
// prior forwarding to the MQTT broker
5641
func (h *Handler) AuthSubscribe(ctx context.Context, topics *[]string) error {
57-
s, ok := session.FromContext(ctx)
58-
if !ok {
59-
h.logger.Error(errSessionMissing.Error())
60-
return errSessionMissing
61-
}
62-
h.logger.Info(fmt.Sprintf("AuthSubscribe() - sessionID: %s, topics: %s", s.ID, strings.Join(*topics, ",")))
63-
return nil
42+
return h.logAction(ctx, "AuthSubscribe", topics, nil)
6443
}
6544

6645
// Connect - after client successfully connected
6746
func (h *Handler) Connect(ctx context.Context) error {
68-
s, ok := session.FromContext(ctx)
69-
if !ok {
70-
h.logger.Error(errSessionMissing.Error())
71-
return errSessionMissing
72-
}
73-
h.logger.Info(fmt.Sprintf("Connect() - username: %s, sessionID: %s", s.Username, s.ID))
74-
return nil
47+
return h.logAction(ctx, "Connect", nil, nil)
7548
}
7649

7750
// Publish - after client successfully published
7851
func (h *Handler) Publish(ctx context.Context, topic *string, payload *[]byte) error {
79-
s, ok := session.FromContext(ctx)
80-
if !ok {
81-
h.logger.Error(errSessionMissing.Error())
82-
return errSessionMissing
83-
}
84-
h.logger.Info(fmt.Sprintf("Publish() - username: %s, sessionID: %s, topic: %s, payload: %s", s.Username, s.ID, *topic, string(*payload)))
85-
return nil
52+
return h.logAction(ctx, "Publish", &[]string{*topic}, payload)
8653
}
8754

8855
// Subscribe - after client successfully subscribed
8956
func (h *Handler) Subscribe(ctx context.Context, topics *[]string) error {
90-
s, ok := session.FromContext(ctx)
91-
if !ok {
92-
h.logger.Error(errSessionMissing.Error())
93-
return errSessionMissing
94-
}
95-
h.logger.Info(fmt.Sprintf("Subscribe() - username: %s, sessionID: %s, topics: %s", s.Username, s.ID, strings.Join(*topics, ",")))
96-
return nil
57+
return h.logAction(ctx, "Subscribe", topics, nil)
9758
}
9859

9960
// Unsubscribe - after client unsubscribed
10061
func (h *Handler) Unsubscribe(ctx context.Context, topics *[]string) error {
101-
s, ok := session.FromContext(ctx)
102-
if !ok {
103-
h.logger.Error(errSessionMissing.Error())
104-
return errSessionMissing
105-
}
106-
h.logger.Info(fmt.Sprintf("Unsubscribe() - username: %s, sessionID: %s, topics: %s", s.Username, s.ID, strings.Join(*topics, ",")))
107-
return nil
62+
return h.logAction(ctx, "Unsubscribe", topics, nil)
10863
}
10964

11065
// Disconnect on connection lost
11166
func (h *Handler) Disconnect(ctx context.Context) error {
67+
return h.logAction(ctx, "Disconnect", nil, nil)
68+
}
69+
70+
func (h *Handler) logAction(ctx context.Context, action string, topics *[]string, payload *[]byte) error {
11271
s, ok := session.FromContext(ctx)
72+
args := []interface{}{
73+
slog.Group("session", slog.String("id", s.ID), slog.String("username", s.Username)),
74+
}
75+
if s.Cert.Subject.CommonName != "" {
76+
args = append(args, slog.Group("cert", slog.String("cn", s.Cert.Subject.CommonName)))
77+
}
78+
if topics != nil {
79+
args = append(args, slog.Any("topics", *topics))
80+
}
81+
if payload != nil {
82+
args = append(args, slog.Any("payload", *payload))
83+
}
11384
if !ok {
114-
h.logger.Error(errSessionMissing.Error())
85+
args = append(args, slog.Any("error", errSessionMissing))
86+
h.logger.Error(action+"() failed to complete", args...)
11587
return errSessionMissing
11688
}
117-
h.logger.Info(fmt.Sprintf("Disconnect() - client with username: %s and ID: %s disconnected", s.Username, s.ID))
89+
h.logger.Info(action+"() completed successfully", args...)
90+
11891
return nil
11992
}

‎go.mod

Lines changed: 1 addition & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -5,15 +5,10 @@ go 1.21
55
toolchain go1.21.4
66

77
require (
8-
github.com/absmach/magistrala v0.11.1-0.20231220185538-1fe2e74a741f
98
github.com/eclipse/paho.mqtt.golang v1.4.3
109
github.com/google/uuid v1.5.0
1110
github.com/gorilla/websocket v1.5.1
1211
golang.org/x/sync v0.6.0
1312
)
1413

15-
require (
16-
github.com/go-kit/log v0.2.1 // indirect
17-
github.com/go-logfmt/logfmt v0.6.0 // indirect
18-
golang.org/x/net v0.20.0 // indirect
19-
)
14+
require golang.org/x/net v0.20.0 // indirect

‎go.sum

Lines changed: 0 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -1,24 +1,10 @@
1-
github.com/absmach/magistrala v0.11.1-0.20231220185538-1fe2e74a741f h1:QIfX7wem1z6mj3GpkVu7WX3dFXzO8O+Sr+Bffw9YqPw=
2-
github.com/absmach/magistrala v0.11.1-0.20231220185538-1fe2e74a741f/go.mod h1:vnzZ/Y6v0L/14BQTUGR9Na+qRXZ3o4l3yyMD1b5nfjk=
3-
github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc h1:U9qPSI2PIWSS1VwoXQT9A3Wy9MM3WgvqSxFWenqJduM=
4-
github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
51
github.com/eclipse/paho.mqtt.golang v1.4.3 h1:2kwcUGn8seMUfWndX0hGbvH8r7crgcJguQNCyp70xik=
62
github.com/eclipse/paho.mqtt.golang v1.4.3/go.mod h1:CSYvoAlsMkhYOXh/oKyxa8EcBci6dVkLCbo5tTC1RIE=
7-
github.com/go-kit/log v0.2.1 h1:MRVx0/zhvdseW+Gza6N9rVzU/IVzaeE1SFI4raAhmBU=
8-
github.com/go-kit/log v0.2.1/go.mod h1:NwTd00d/i8cPZ3xOwwiv2PO5MOcx78fFErGNcVmBjv0=
9-
github.com/go-logfmt/logfmt v0.6.0 h1:wGYYu3uicYdqXVgoYbvnkrPVXkuLM1p1ifugDMEdRi4=
10-
github.com/go-logfmt/logfmt v0.6.0/go.mod h1:WYhtIu8zTZfxdn5+rREduYbwxfcBr/Vr6KEVveWlfTs=
113
github.com/google/uuid v1.5.0 h1:1p67kYwdtXjb0gL0BPiP1Av9wiZPo5A8z2cWkTZ+eyU=
124
github.com/google/uuid v1.5.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
135
github.com/gorilla/websocket v1.5.1 h1:gmztn0JnHVt9JZquRuzLw3g4wouNVzKL15iLr/zn/QY=
146
github.com/gorilla/websocket v1.5.1/go.mod h1:x3kM2JMyaluk02fnUJpQuwD2dCS5NDG2ZHL0uE0tcaY=
15-
github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 h1:Jamvg5psRIccs7FGNTlIRMkT8wgtp5eCXdBlqhYGL6U=
16-
github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
17-
github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk=
18-
github.com/stretchr/testify v1.8.4/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo=
197
golang.org/x/net v0.20.0 h1:aCL9BSgETF1k+blQaYUBx9hJ9LOGP3gAVemcZlf1Kpo=
208
golang.org/x/net v0.20.0/go.mod h1:z8BVo6PvndSri0LbOE3hAn0apkU+1YvI6E70E9jsnvY=
219
golang.org/x/sync v0.6.0 h1:5BMeUDZ7vkXGfEr1x9B4bRcTH4lpkTkpdh0T/J+qjbQ=
2210
golang.org/x/sync v0.6.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk=
23-
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
24-
gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

0 commit comments

Comments
 (0)