Skip to content

Commit 51877c3

Browse files
committed
mailbox: use prefixed logger
1 parent 9a2c5ac commit 51877c3

File tree

5 files changed

+109
-55
lines changed

5 files changed

+109
-55
lines changed

mailbox/client.go

Lines changed: 9 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ import (
77
"net"
88
"sync"
99

10+
"github.com/btcsuite/btclog"
1011
"github.com/lightninglabs/lightning-node-connect/hashmailrpc"
1112
"google.golang.org/grpc"
1213
)
@@ -38,6 +39,8 @@ type Client struct {
3839
sid [64]byte
3940

4041
ctx context.Context //nolint:containedctx
42+
43+
log btclog.Logger
4144
}
4245

4346
// NewClient creates a new Client object which will handle the mailbox
@@ -56,6 +59,7 @@ func NewClient(ctx context.Context, serverHost string, connData *ConnData,
5659
connData: connData,
5760
status: ClientStatusNotConnected,
5861
sid: sid,
62+
log: newPrefixedLogger(false),
5963
}
6064

6165
// Apply functional options.
@@ -98,12 +102,12 @@ func (c *Client) Dial(_ context.Context, _ string) (net.Conn, error) {
98102
// If there is currently an active connection, block here until the
99103
// previous connection as been closed.
100104
if c.mailboxConn != nil {
101-
log.Debugf("Dial: have existing mailbox connection, waiting")
105+
c.log.Debugf("Dial: have existing mailbox connection, waiting")
102106
<-c.mailboxConn.Done()
103-
log.Debugf("Dial: done with existing conn")
107+
c.log.Debugf("Dial: done with existing conn")
104108
}
105109

106-
log.Debugf("Client: Dialing...")
110+
c.log.Debugf("Dialing...")
107111

108112
sid, err := c.connData.SID()
109113
if err != nil {
@@ -115,7 +119,7 @@ func (c *Client) Dial(_ context.Context, _ string) (net.Conn, error) {
115119
if !bytes.Equal(c.sid[:], sid[:]) && c.mailboxConn != nil {
116120
err := c.mailboxConn.Close()
117121
if err != nil {
118-
log.Errorf("could not close mailbox conn: %v", err)
122+
c.log.Errorf("Could not close mailbox conn: %v", err)
119123
}
120124

121125
c.mailboxConn = nil
@@ -126,7 +130,7 @@ func (c *Client) Dial(_ context.Context, _ string) (net.Conn, error) {
126130
if c.mailboxConn == nil {
127131
mailboxConn, err := NewClientConn(
128132
c.ctx, c.sid, c.serverHost, c.grpcClient,
129-
func(status ClientStatus) {
133+
c.log, func(status ClientStatus) {
130134
c.statusMu.Lock()
131135
c.status = status
132136
c.statusMu.Unlock()

mailbox/client_conn.go

Lines changed: 30 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88
"sync"
99
"time"
1010

11+
"github.com/btcsuite/btclog"
1112
"github.com/grpc-ecosystem/grpc-gateway/v2/runtime"
1213
"github.com/lightninglabs/lightning-node-connect/gbn"
1314
"github.com/lightninglabs/lightning-node-connect/hashmailrpc"
@@ -124,13 +125,15 @@ type ClientConn struct {
124125
quit chan struct{}
125126
cancel func()
126127
closeOnce sync.Once
128+
129+
log btclog.Logger
127130
}
128131

129132
// NewClientConn creates a new client connection with the given receive and send
130133
// session identifiers. The context given as the first parameter will be used
131134
// throughout the connection lifetime.
132135
func NewClientConn(ctx context.Context, sid [64]byte, serverHost string,
133-
client hashmailrpc.HashMailClient,
136+
client hashmailrpc.HashMailClient, logger btclog.Logger,
134137
onNewStatus func(status ClientStatus)) (*ClientConn, error) {
135138

136139
receiveSID := GetSID(sid, true)
@@ -141,7 +144,7 @@ func NewClientConn(ctx context.Context, sid [64]byte, serverHost string,
141144
sendSID: sendSID[:],
142145
}
143146

144-
log.Debugf("New client conn, read_stream=%x, write_stream=%x",
147+
logger.Debugf("New client conn, read_stream=%x, write_stream=%x",
145148
receiveSID[:], sendSID[:])
146149

147150
ctxc, cancel := context.WithCancel(ctx)
@@ -166,6 +169,7 @@ func NewClientConn(ctx context.Context, sid [64]byte, serverHost string,
166169
onNewStatus: onNewStatus,
167170
quit: make(chan struct{}),
168171
cancel: cancel,
172+
log: logger,
169173
}
170174
c.connKit = &connKit{
171175
ctx: ctxc,
@@ -201,10 +205,11 @@ func RefreshClientConn(ctx context.Context, c *ClientConn) (*ClientConn,
201205
c.statusMu.Lock()
202206
defer c.statusMu.Unlock()
203207

204-
log.Debugf("Refreshing client conn, read_stream=%x, write_stream=%x",
208+
c.log.Debugf("Refreshing client conn, read_stream=%x, write_stream=%x",
205209
c.receiveSID[:], c.sendSID[:])
206210

207211
cc := &ClientConn{
212+
log: c.log,
208213
transport: c.transport.Refresh(),
209214
status: ClientStatusNotConnected,
210215
onNewStatus: c.onNewStatus,
@@ -299,7 +304,7 @@ func (c *ClientConn) recv(ctx context.Context) ([]byte, error) {
299304
return nil, err
300305
}
301306

302-
log.Debugf("Client: got failure on receive "+
307+
c.log.Debugf("Client: got failure on receive "+
303308
"socket/stream, re-trying: %v", err)
304309

305310
c.setStatus(errStatus)
@@ -343,8 +348,8 @@ func (c *ClientConn) send(ctx context.Context, payload []byte) error {
343348
return err
344349
}
345350

346-
log.Debugf("Client: got failure on send "+
347-
"socket/stream, re-trying: %v", err)
351+
c.log.Debugf("Got failure on send socket/stream, "+
352+
"re-trying: %v", err)
348353

349354
c.setStatus(errStatus)
350355
c.createSendMailBox(ctx, retryWait)
@@ -377,13 +382,14 @@ func (c *ClientConn) createReceiveMailBox(ctx context.Context,
377382
waiter.Wait()
378383

379384
if err := c.transport.ConnectReceive(ctx); err != nil {
380-
log.Errorf("Client: error connecting to receive "+
385+
c.log.Errorf("Error connecting to receive "+
381386
"socket/stream: %v", err)
382387

383388
continue
384389
}
385390

386-
log.Debugf("Client: receive mailbox initialized")
391+
c.log.Debugf("Receive mailbox initialized")
392+
387393
return
388394
}
389395
}
@@ -406,14 +412,17 @@ func (c *ClientConn) createSendMailBox(ctx context.Context,
406412

407413
waiter.Wait()
408414

409-
log.Debugf("Client: Attempting to create send socket/stream")
415+
c.log.Debugf("Attempting to create send socket/stream")
416+
410417
if err := c.transport.ConnectSend(ctx); err != nil {
411-
log.Debugf("Client: error connecting to send "+
418+
c.log.Debugf("Error connecting to send "+
412419
"stream/socket %v", err)
420+
413421
continue
414422
}
415423

416-
log.Debugf("Client: Connected to send socket/stream")
424+
c.log.Debugf("Connected to send socket/stream")
425+
417426
return
418427
}
419428
}
@@ -460,29 +469,33 @@ func (c *ClientConn) SetSendTimeout(timeout time.Duration) {
460469
func (c *ClientConn) Close() error {
461470
var returnErr error
462471
c.closeOnce.Do(func() {
463-
log.Debugf("Closing client connection")
472+
c.log.Debugf("Closing connection")
464473

465474
if c.gbnConn != nil {
466475
if err := c.gbnConn.Close(); err != nil {
467-
log.Debugf("Error closing gbn connection: %v",
476+
c.log.Debugf("Error closing gbn connection: %v",
468477
err)
469478

470479
returnErr = err
471480
}
472481
}
473482

474483
c.receiveMu.Lock()
475-
log.Debugf("closing receive stream/socket")
484+
c.log.Debugf("Closing receive stream/socket")
476485
if err := c.transport.CloseReceive(); err != nil {
477-
log.Errorf("Error closing receive stream/socket: %v", err)
486+
c.log.Errorf("Error closing receive stream/socket: %v",
487+
err)
488+
478489
returnErr = err
479490
}
480491
c.receiveMu.Unlock()
481492

482493
c.sendMu.Lock()
483-
log.Debugf("closing send stream/socket")
494+
c.log.Debugf("Closing send stream/socket")
484495
if err := c.transport.CloseSend(); err != nil {
485-
log.Errorf("Error closing send stream/socket: %v", err)
496+
c.log.Errorf("Error closing send stream/socket: %v",
497+
err)
498+
486499
returnErr = err
487500
}
488501
c.sendMu.Unlock()

mailbox/log.go

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,8 @@
11
package mailbox
22

33
import (
4+
"fmt"
5+
46
"github.com/btcsuite/btclog"
57
"github.com/lightningnetwork/lnd/build"
68
"google.golang.org/grpc/grpclog"
@@ -29,6 +31,17 @@ func UseLogger(logger btclog.Logger) {
2931
log = logger
3032
}
3133

34+
// nePrefixedLogger constructs a new prefixed logger.
35+
func newPrefixedLogger(isServer bool) *build.PrefixLog {
36+
identifier := "client"
37+
if isServer {
38+
identifier = "server"
39+
}
40+
prefix := fmt.Sprintf("(%s)", identifier)
41+
42+
return build.NewPrefixLog(prefix, log)
43+
}
44+
3245
// GrpcLogLogger is a wrapper around a btclog logger to make it compatible with
3346
// the grpclog logger package. By default we downgrade the info level to debug
3447
// to reduce the verbosity of the logger.

mailbox/server.go

Lines changed: 13 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ import (
77
"io"
88
"net"
99

10+
"github.com/btcsuite/btclog"
1011
"github.com/lightninglabs/lightning-node-connect/hashmailrpc"
1112
"google.golang.org/grpc"
1213
)
@@ -30,6 +31,8 @@ type Server struct {
3031

3132
quit chan struct{}
3233
cancel func()
34+
35+
log btclog.Logger
3336
}
3437

3538
func NewServer(serverHost string, connData *ConnData,
@@ -55,6 +58,7 @@ func NewServer(serverHost string, connData *ConnData,
5558
connData: connData,
5659
sid: sid,
5760
onNewStatus: onNewStatus,
61+
log: newPrefixedLogger(true),
5862
quit: make(chan struct{}),
5963
}
6064

@@ -79,12 +83,14 @@ func (s *Server) Accept() (net.Conn, error) {
7983
// If there is currently an active connection, block here until the
8084
// previous connection as been closed.
8185
if s.mailboxConn != nil {
82-
log.Debugf("Accept: have existing mailbox connection, waiting")
86+
s.log.Debugf("Accept: have existing mailbox connection, " +
87+
"waiting")
88+
8389
select {
8490
case <-s.quit:
8591
return nil, io.EOF
8692
case <-s.mailboxConn.Done():
87-
log.Debugf("Accept: done with existing conn")
93+
s.log.Debugf("Accept: done with existing conn")
8894
}
8995
}
9096

@@ -98,7 +104,7 @@ func (s *Server) Accept() (net.Conn, error) {
98104
if !bytes.Equal(s.sid[:], sid[:]) && s.mailboxConn != nil {
99105
err := s.mailboxConn.Stop()
100106
if err != nil {
101-
log.Errorf("could not close mailbox conn: %v", err)
107+
s.log.Errorf("Could not close mailbox conn: %v", err)
102108
}
103109

104110
s.mailboxConn = nil
@@ -110,7 +116,8 @@ func (s *Server) Accept() (net.Conn, error) {
110116
// otherwise, we just refresh the ServerConn.
111117
if s.mailboxConn == nil {
112118
mailboxConn, err := NewServerConn(
113-
s.ctx, s.serverHost, s.client, sid, s.onNewStatus,
119+
s.ctx, s.serverHost, s.client, sid, s.log,
120+
s.onNewStatus,
114121
)
115122
if err != nil {
116123
return nil, &temporaryError{err}
@@ -143,13 +150,13 @@ func (e *temporaryError) Temporary() bool {
143150
}
144151

145152
func (s *Server) Close() error {
146-
log.Debugf("conn being closed")
153+
s.log.Debugf("Conn being closed")
147154

148155
close(s.quit)
149156

150157
if s.mailboxConn != nil {
151158
if err := s.mailboxConn.Stop(); err != nil {
152-
log.Errorf("error closing mailboxConn %v", err)
159+
s.log.Errorf("Error closing mailboxConn %v", err)
153160
}
154161
}
155162
s.cancel()

0 commit comments

Comments
 (0)