Skip to content

Commit e653741

Browse files
chungthuangchungthuang
committed
TUN-8158: Add logging to confirm when ICMP reply is returned to the edge
1 parent e5ae80a commit e653741

File tree

5 files changed

+55
-31
lines changed

5 files changed

+55
-31
lines changed

‎ingress/icmp_darwin.go‎

Lines changed: 7 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -131,18 +131,16 @@ func newICMPProxy(listenIP netip.Addr, zone string, logger *zerolog.Logger, idle
131131
}
132132

133133
func (ip *icmpProxy) Request(ctx context.Context, pk *packet.ICMP, responder *packetResponder) error {
134-
ctx, span := responder.requestSpan(ctx, pk)
134+
_, span := responder.requestSpan(ctx, pk)
135135
defer responder.exportSpan()
136136

137137
originalEcho, err := getICMPEcho(pk.Message)
138138
if err != nil {
139139
tracing.EndWithErrorStatus(span, err)
140140
return err
141141
}
142-
span.SetAttributes(
143-
attribute.Int("originalEchoID", originalEcho.ID),
144-
attribute.Int("seq", originalEcho.Seq),
145-
)
142+
observeICMPRequest(ip.logger, span, pk.Src.String(), pk.Dst.String(), originalEcho.ID, originalEcho.Seq)
143+
146144
echoIDTrackerKey := flow3Tuple{
147145
srcIP: pk.Src,
148146
dstIP: pk.Dst,
@@ -189,6 +187,7 @@ func (ip *icmpProxy) Request(ctx context.Context, pk *packet.ICMP, responder *pa
189187
tracing.EndWithErrorStatus(span, err)
190188
return err
191189
}
190+
192191
err = icmpFlow.sendToDst(pk.Dst, pk.Message)
193192
if err != nil {
194193
tracing.EndWithErrorStatus(span, err)
@@ -269,15 +268,12 @@ func (ip *icmpProxy) sendReply(ctx context.Context, reply *echoReply) error {
269268
_, span := icmpFlow.responder.replySpan(ctx, ip.logger)
270269
defer icmpFlow.responder.exportSpan()
271270

272-
span.SetAttributes(
273-
attribute.String("dst", reply.from.String()),
274-
attribute.Int("echoID", reply.echo.ID),
275-
attribute.Int("seq", reply.echo.Seq),
276-
attribute.Int("originalEchoID", icmpFlow.originalEchoID),
277-
)
278271
if err := icmpFlow.returnToSrc(reply); err != nil {
279272
tracing.EndWithErrorStatus(span, err)
273+
return err
280274
}
275+
observeICMPReply(ip.logger, span, reply.from.String(), reply.echo.ID, reply.echo.Seq)
276+
span.SetAttributes(attribute.Int("originalEchoID", icmpFlow.originalEchoID))
281277
tracing.End(span)
282278
return nil
283279
}

‎ingress/icmp_linux.go‎

Lines changed: 9 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -107,10 +107,7 @@ func (ip *icmpProxy) Request(ctx context.Context, pk *packet.ICMP, responder *pa
107107
tracing.EndWithErrorStatus(span, err)
108108
return err
109109
}
110-
span.SetAttributes(
111-
attribute.Int("originalEchoID", originalEcho.ID),
112-
attribute.Int("seq", originalEcho.Seq),
113-
)
110+
observeICMPRequest(ip.logger, span, pk.Src.String(), pk.Dst.String(), originalEcho.ID, originalEcho.Seq)
114111

115112
shouldReplaceFunnelFunc := createShouldReplaceFunnelFunc(ip.logger, responder.datagramMuxer, pk, originalEcho.ID)
116113
newFunnelFunc := func() (packet.Funnel, error) {
@@ -199,6 +196,10 @@ func (ip *icmpProxy) handleResponse(ctx context.Context, flow *icmpEchoFlow, buf
199196

200197
n, from, err := flow.originConn.ReadFrom(buf)
201198
if err != nil {
199+
if flow.IsClosed() {
200+
tracing.EndWithErrorStatus(span, fmt.Errorf("flow was closed"))
201+
return false, nil
202+
}
202203
tracing.EndWithErrorStatus(span, err)
203204
return false, err
204205
}
@@ -214,16 +215,14 @@ func (ip *icmpProxy) handleResponse(ctx context.Context, flow *icmpEchoFlow, buf
214215
tracing.EndWithErrorStatus(span, err)
215216
return true, err
216217
}
217-
span.SetAttributes(
218-
attribute.String("dst", reply.from.String()),
219-
attribute.Int("echoID", reply.echo.ID),
220-
attribute.Int("seq", reply.echo.Seq),
221-
)
218+
222219
if err := flow.returnToSrc(reply); err != nil {
223-
ip.logger.Debug().Err(err).Str("dst", from.String()).Msg("Failed to send ICMP reply")
220+
ip.logger.Error().Err(err).Str("dst", from.String()).Msg("Failed to send ICMP reply")
224221
tracing.EndWithErrorStatus(span, err)
225222
return true, err
226223
}
224+
225+
observeICMPReply(ip.logger, span, from.String(), reply.echo.ID, reply.echo.Seq)
227226
tracing.End(span)
228227
return true, nil
229228
}

‎ingress/icmp_posix.go‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88
"fmt"
99
"net"
1010
"net/netip"
11+
"sync/atomic"
1112

1213
"github.com/google/gopacket/layers"
1314
"github.com/rs/zerolog"
@@ -46,6 +47,7 @@ type flow3Tuple struct {
4647
type icmpEchoFlow struct {
4748
*packet.ActivityTracker
4849
closeCallback func() error
50+
closed *atomic.Bool
4951
src netip.Addr
5052
originConn *icmp.PacketConn
5153
responder *packetResponder
@@ -59,6 +61,7 @@ func newICMPEchoFlow(src netip.Addr, closeCallback func() error, originConn *icm
5961
return &icmpEchoFlow{
6062
ActivityTracker: packet.NewActivityTracker(),
6163
closeCallback: closeCallback,
64+
closed: &atomic.Bool{},
6265
src: src,
6366
originConn: originConn,
6467
responder: responder,
@@ -86,9 +89,14 @@ func (ief *icmpEchoFlow) Equal(other packet.Funnel) bool {
8689
}
8790

8891
func (ief *icmpEchoFlow) Close() error {
92+
ief.closed.Store(true)
8993
return ief.closeCallback()
9094
}
9195

96+
func (ief *icmpEchoFlow) IsClosed() bool {
97+
return ief.closed.Load()
98+
}
99+
92100
// sendToDst rewrites the echo ID to the one assigned to this flow
93101
func (ief *icmpEchoFlow) sendToDst(dst netip.Addr, msg *icmp.Message) error {
94102
ief.UpdateLastActive()

‎ingress/icmp_windows.go‎

Lines changed: 7 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -281,10 +281,7 @@ func (ip *icmpProxy) Request(ctx context.Context, pk *packet.ICMP, responder *pa
281281
if err != nil {
282282
return err
283283
}
284-
requestSpan.SetAttributes(
285-
attribute.Int("originalEchoID", echo.ID),
286-
attribute.Int("seq", echo.Seq),
287-
)
284+
observeICMPRequest(ip.logger, requestSpan, pk.Src.String(), pk.Dst.String(), echo.ID, echo.Seq)
288285

289286
resp, err := ip.icmpEchoRoundtrip(pk.Dst, echo)
290287
if err != nil {
@@ -296,17 +293,17 @@ func (ip *icmpProxy) Request(ctx context.Context, pk *packet.ICMP, responder *pa
296293
responder.exportSpan()
297294

298295
_, replySpan := responder.replySpan(ctx, ip.logger)
299-
replySpan.SetAttributes(
300-
attribute.Int("originalEchoID", echo.ID),
301-
attribute.Int("seq", echo.Seq),
302-
attribute.Int64("rtt", int64(resp.rtt())),
303-
attribute.String("status", resp.status().String()),
304-
)
305296
err = ip.handleEchoReply(pk, echo, resp, responder)
306297
if err != nil {
298+
ip.logger.Err(err).Msg("Failed to send ICMP reply")
307299
tracing.EndWithErrorStatus(replySpan, err)
308300
return errors.Wrap(err, "failed to handle ICMP echo reply")
309301
}
302+
observeICMPReply(ip.logger, replySpan, pk.Dst.String(), echo.ID, echo.Seq)
303+
replySpan.SetAttributes(
304+
attribute.Int64("rtt", int64(resp.rtt())),
305+
attribute.String("status", resp.status().String()),
306+
)
310307
tracing.End(replySpan)
311308
return nil
312309
}

‎ingress/origin_icmp_proxy.go‎

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,8 @@ import (
77
"time"
88

99
"github.com/rs/zerolog"
10+
"go.opentelemetry.io/otel/attribute"
11+
"go.opentelemetry.io/otel/trace"
1012
"golang.org/x/net/icmp"
1113
"golang.org/x/net/ipv4"
1214
"golang.org/x/net/ipv6"
@@ -102,3 +104,25 @@ func getICMPEcho(msg *icmp.Message) (*icmp.Echo, error) {
102104
func isEchoReply(msg *icmp.Message) bool {
103105
return msg.Type == ipv4.ICMPTypeEchoReply || msg.Type == ipv6.ICMPTypeEchoReply
104106
}
107+
108+
func observeICMPRequest(logger *zerolog.Logger, span trace.Span, src string, dst string, echoID int, seq int) {
109+
logger.Debug().
110+
Str("src", src).
111+
Str("dst", dst).
112+
Int("originalEchoID", echoID).
113+
Int("originalEchoSeq", seq).
114+
Msg("Received ICMP request")
115+
span.SetAttributes(
116+
attribute.Int("originalEchoID", echoID),
117+
attribute.Int("seq", seq),
118+
)
119+
}
120+
121+
func observeICMPReply(logger *zerolog.Logger, span trace.Span, dst string, echoID int, seq int) {
122+
logger.Debug().Str("dst", dst).Int("echoID", echoID).Int("seq", seq).Msg("Sent ICMP reply to edge")
123+
span.SetAttributes(
124+
attribute.String("dst", dst),
125+
attribute.Int("echoID", echoID),
126+
attribute.Int("seq", seq),
127+
)
128+
}

0 commit comments

Comments
 (0)