Skip to content
This repository was archived by the owner on Jun 12, 2022. It is now read-only.

Commit ba242e9

Browse files
database64128database64128
committed
⚡ Use zap for structured logging
1 parent 2c88f6d commit ba242e9

File tree

21 files changed

+815
-475
lines changed

21 files changed

+815
-475
lines changed

‎client/client.go‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -201,6 +201,9 @@ func (c *ssClient) ListenUDP(laddr *net.UDPAddr) (ShadowsocksPacketConn, error)
201201
type ShadowsocksPacketConn interface {
202202
net.PacketConn
203203

204+
// RemoteAddr returns the remote proxy's address.
205+
RemoteAddr() net.Addr
206+
204207
// ReadFromZeroCopy eliminates copying by requiring that a big enough buffer is passed for reading.
205208
ReadFromZeroCopy(b []byte) (socksAddrStart, payloadStart, payloadLength int, err error)
206209

@@ -257,6 +260,10 @@ func newPacketConn(proxyConn *net.UDPConn, c *ss.Cipher) (*packetConn, error) {
257260
}, nil
258261
}
259262

263+
func (c *packetConn) RemoteAddr() net.Addr {
264+
return c.UDPConn.RemoteAddr()
265+
}
266+
260267
// WriteTo encrypts `b` and writes to `addr` through the proxy.
261268
func (c *packetConn) WriteTo(b []byte, addr net.Addr) (int, error) {
262269
lazySlice := udpPool.LazySlice()

‎client/logger.go‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,11 @@
1+
package client
2+
3+
import "go.uber.org/zap"
4+
5+
// logger is the shared logger instance used by this package.
6+
// This variable must be assigned before calling any functions in this package.
7+
var logger *zap.Logger
8+
9+
func SetLogger(l *zap.Logger) {
10+
logger = l
11+
}

‎client/nat.go‎

Lines changed: 27 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -2,14 +2,14 @@ package client
22

33
import (
44
"errors"
5-
"log"
65
"net"
76
"os"
87
"sync"
98
"time"
109

1110
onet "github.com/Shadowsocks-NET/outline-ss-server/net"
1211
"github.com/Shadowsocks-NET/outline-ss-server/service"
12+
"go.uber.org/zap"
1313
)
1414

1515
type natconn struct {
@@ -98,6 +98,10 @@ func (c *natconn) LocalAddr() net.Addr {
9898
return c.proxyConn.LocalAddr()
9999
}
100100

101+
func (c *natconn) RemoteAddr() net.Addr {
102+
return c.proxyConn.RemoteAddr()
103+
}
104+
101105
func (c *natconn) Close() error {
102106
return c.proxyConn.Close()
103107
}
@@ -112,19 +116,38 @@ func (c *natconn) timedCopy() {
112116
if errors.Is(err, os.ErrDeadlineExceeded) {
113117
return
114118
}
115-
log.Print(err)
119+
logger.Warn("Failed to read from proxy",
120+
zap.Stringer("listenAddress", c.clientConn.LocalAddr()),
121+
zap.Stringer("clientAddress", c.clientAddr),
122+
zap.Stringer("proxyConnLocalAddress", c.proxyConn.LocalAddr()),
123+
zap.Stringer("proxyConnRemoteAddress", c.proxyConn.RemoteAddr()),
124+
zap.Error(err),
125+
)
116126
continue
117127
}
118128

119129
writeBuf, err := c.packetAdapter.EncapsulatePacket(packetBuf, socksAddrStart, payloadStart, payloadLength)
120130
if err != nil {
121-
log.Print(err)
131+
logger.Warn("Failed to encapsulate decrypted proxy packet for sending on clientConn",
132+
zap.Stringer("listenAddress", c.clientConn.LocalAddr()),
133+
zap.Stringer("clientAddress", c.clientAddr),
134+
zap.Stringer("proxyConnLocalAddress", c.proxyConn.LocalAddr()),
135+
zap.Stringer("proxyConnRemoteAddress", c.proxyConn.RemoteAddr()),
136+
zap.Stringer("packetAdapter", c.packetAdapter),
137+
zap.Error(err),
138+
)
122139
continue
123140
}
124141

125142
_, _, err = c.clientConn.WriteMsgUDP(writeBuf, c.oobCache, c.clientAddr)
126143
if err != nil {
127-
log.Print(err)
144+
logger.Warn("Failed to write to clientConn",
145+
zap.Stringer("listenAddress", c.clientConn.LocalAddr()),
146+
zap.Stringer("clientAddress", c.clientAddr),
147+
zap.Stringer("proxyConnLocalAddress", c.proxyConn.LocalAddr()),
148+
zap.Stringer("proxyConnRemoteAddress", c.proxyConn.RemoteAddr()),
149+
zap.Error(err),
150+
)
128151
}
129152
}
130153
}

‎client/service.go‎

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,14 @@
11
package client
22

3+
// Service defines the management interface for client services.
34
type Service interface {
4-
Name() string
5+
// String returns the service's name.
6+
// This method may be called on a nil pointer.
7+
String() string
8+
9+
// Start starts the service.
510
Start() error
11+
12+
// Stop stops the service.
613
Stop() error
714
}

‎client/tcp.go‎

Lines changed: 100 additions & 53 deletions
Original file line numberDiff line numberDiff line change
@@ -6,12 +6,12 @@ import (
66
"errors"
77
"fmt"
88
"io"
9-
"log"
109
"net"
1110

1211
onet "github.com/Shadowsocks-NET/outline-ss-server/net"
1312
"github.com/Shadowsocks-NET/outline-ss-server/socks"
1413
"github.com/database64128/tfo-go"
14+
"go.uber.org/zap"
1515
)
1616

1717
type TCPTunnel struct {
@@ -24,70 +24,117 @@ type TCPTunnel struct {
2424
handshaker Handshaker
2525
}
2626

27-
func (s *TCPTunnel) Name() string {
28-
return fmt.Sprint("TCP ", s.handshaker.Name(), " relay service")
27+
func (s *TCPTunnel) String() string {
28+
return fmt.Sprint("TCP ", s.handshaker.String(), " relay service")
2929
}
3030

3131
func (s *TCPTunnel) Start() error {
32-
go s.listen()
33-
log.Printf("Started %s listening on %s", s.Name(), s.listenAddress)
34-
return nil
35-
}
36-
37-
func (s *TCPTunnel) listen() {
3832
lc := tfo.ListenConfig{
3933
DisableTFO: !s.listenerTFO,
4034
}
4135
l, err := lc.Listen(context.Background(), "tcp", s.listenAddress)
4236
if err != nil {
43-
log.Print(err)
44-
return
37+
return err
4538
}
46-
defer l.Close()
47-
4839
s.listener = l.(*net.TCPListener)
4940

50-
for {
51-
clientConn, err := l.(*net.TCPListener).AcceptTCP()
52-
if err != nil {
53-
if errors.Is(err, net.ErrClosed) {
54-
return
55-
}
56-
log.Print(err)
57-
continue
58-
}
59-
60-
go func() {
61-
defer clientConn.Close()
41+
go func() {
42+
defer s.listener.Close()
6243

63-
socksaddr, err := s.handshaker.Handshake(clientConn)
44+
for {
45+
clientConn, err := l.(*net.TCPListener).AcceptTCP()
6446
if err != nil {
65-
log.Print(err)
66-
return
67-
}
68-
if socksaddr == nil {
69-
// Keep the connection open until EOF.
70-
// Example use case: SOCKS5 UDP ASSOCIATE command.
71-
b := make([]byte, 1)
72-
_, err = io.ReadFull(clientConn, b)
73-
if err != nil && err != io.ErrUnexpectedEOF {
74-
log.Print(err)
47+
if errors.Is(err, net.ErrClosed) {
48+
return
7549
}
76-
return
50+
logger.Warn("Failed to accept TCP connection",
51+
zap.Stringer("service", s),
52+
zap.String("listenAddress", s.listenAddress),
53+
zap.Error(err),
54+
)
55+
continue
7756
}
7857

79-
proxyConn, err := s.client.DialTCP(nil, socksaddr, s.dialerTFO)
80-
if err != nil {
81-
log.Print(err)
82-
return
83-
}
84-
defer proxyConn.Close()
58+
go s.handleConn(clientConn)
59+
}
60+
}()
61+
logger.Info("Started listener", zap.Stringer("service", s), zap.String("listenAddress", s.listenAddress))
62+
return nil
63+
}
8564

86-
err = relay(clientConn, proxyConn)
87-
if err != nil {
88-
log.Print(err)
89-
}
90-
}()
65+
func (s *TCPTunnel) handleConn(clientConn *net.TCPConn) {
66+
defer clientConn.Close()
67+
68+
socksaddr, err := s.handshaker.Handshake(clientConn)
69+
if err != nil {
70+
logger.Warn("Failed to handshake with client",
71+
zap.Stringer("service", s),
72+
zap.Stringer("clientConnLocalAddress", clientConn.LocalAddr()),
73+
zap.Stringer("clientConnRemoteAddress", clientConn.RemoteAddr()),
74+
zap.Error(err),
75+
)
76+
return
77+
}
78+
if socksaddr == nil {
79+
// Keep the connection open until EOF.
80+
// Example use case: SOCKS5 UDP ASSOCIATE command.
81+
logger.Debug("Keeping TCP connection open for UDP association",
82+
zap.Stringer("service", s),
83+
zap.Stringer("clientConnLocalAddress", clientConn.LocalAddr()),
84+
zap.Stringer("clientConnRemoteAddress", clientConn.RemoteAddr()),
85+
)
86+
87+
b := make([]byte, 1)
88+
_, err = io.ReadFull(clientConn, b)
89+
if err != nil && err != io.ErrUnexpectedEOF {
90+
logger.Warn("TCP connection for UDP association failed",
91+
zap.Stringer("service", s),
92+
zap.Stringer("clientConnLocalAddress", clientConn.LocalAddr()),
93+
zap.Stringer("clientConnRemoteAddress", clientConn.RemoteAddr()),
94+
zap.Error(err),
95+
)
96+
}
97+
return
98+
}
99+
100+
logger.Debug("Dialing target",
101+
zap.Stringer("service", s),
102+
zap.Stringer("clientConnLocalAddress", clientConn.LocalAddr()),
103+
zap.Stringer("clientConnRemoteAddress", clientConn.RemoteAddr()),
104+
zap.Stringer("targetAddress", socksaddr),
105+
zap.Bool("dialerTFO", s.dialerTFO),
106+
)
107+
108+
proxyConn, err := s.client.DialTCP(nil, socksaddr, s.dialerTFO)
109+
if err != nil {
110+
logger.Warn("Failed to dial target via proxy",
111+
zap.Stringer("service", s),
112+
zap.Stringer("clientConnLocalAddress", clientConn.LocalAddr()),
113+
zap.Stringer("clientConnRemoteAddress", clientConn.RemoteAddr()),
114+
zap.Stringer("targetAddress", socksaddr),
115+
zap.Error(err),
116+
)
117+
return
118+
}
119+
defer proxyConn.Close()
120+
121+
logger.Info("Relaying",
122+
zap.Stringer("service", s),
123+
zap.Stringer("clientConnRemoteAddress", clientConn.RemoteAddr()),
124+
zap.Stringer("proxyConnRemoteAddress", proxyConn.RemoteAddr()),
125+
zap.Stringer("targetAddress", socksaddr),
126+
)
127+
128+
err = relay(clientConn, proxyConn)
129+
if err != nil {
130+
logger.Warn("TCP relay failed",
131+
zap.Stringer("service", s),
132+
zap.Stringer("clientConnLocalAddress", clientConn.LocalAddr()),
133+
zap.Stringer("clientConnRemoteAddress", clientConn.RemoteAddr()),
134+
zap.Stringer("proxyConnLocalAddress", proxyConn.LocalAddr()),
135+
zap.Stringer("proxyConnRemoteAddress", proxyConn.RemoteAddr()),
136+
zap.Error(err),
137+
)
91138
}
92139
}
93140

@@ -116,7 +163,7 @@ func relay(leftConn, rightConn onet.DuplexConn) error {
116163

117164
func (s *TCPTunnel) Stop() error {
118165
if s.listener != nil {
119-
s.listener.Close()
166+
return s.listener.Close()
120167
}
121168
return nil
122169
}
@@ -128,7 +175,7 @@ func (s *TCPTunnel) Stop() error {
128175
//
129176
// If both the returned socks address and error are nil, the connection is kept open until EOF.
130177
type Handshaker interface {
131-
Name() string
178+
String() string
132179
Handshake(*net.TCPConn) (socks.Addr, error)
133180
}
134181

@@ -143,7 +190,7 @@ func NewSimpleTunnelHandshaker(remoteSocksAddr socks.Addr) *SimpleTunnelHandshak
143190
}
144191
}
145192

146-
func (h *SimpleTunnelHandshaker) Name() string {
193+
func (h *SimpleTunnelHandshaker) String() string {
147194
return "simple tunnel"
148195
}
149196

@@ -165,7 +212,7 @@ func NewSimpleSocks5Handshaker(enableTCP, enableUDP bool) *SimpleSocks5Handshake
165212
}
166213
}
167214

168-
func (h *SimpleSocks5Handshaker) Name() string {
215+
func (h *SimpleSocks5Handshaker) String() string {
169216
return "simple SOCKS5"
170217
}
171218

@@ -243,7 +290,7 @@ func replyWithStatus(conn *net.TCPConn, socks5err byte) error {
243290
// ShadowsocksNoneHandshaker implements the 'none' mode of Shadowsocks.
244291
type ShadowsocksNoneHandshaker struct{}
245292

246-
func (h *ShadowsocksNoneHandshaker) Name() string {
293+
func (h *ShadowsocksNoneHandshaker) String() string {
247294
return "Shadowsocks none"
248295
}
249296

0 commit comments

Comments
 (0)