From 11a1a9096dc93b57889a46cf7a04498d8d44105a Mon Sep 17 00:00:00 2001 From: Simeng He Date: Fri, 28 May 2021 16:58:15 -0400 Subject: [PATCH] More logging :( --- control/controlclient/direct.go | 15 +++------------ net/tstun/wrap.go | 3 +++ wgengine/magicsock/magicsock.go | 2 ++ wgengine/userspace.go | 11 ++++++++--- 4 files changed, 16 insertions(+), 15 deletions(-) diff --git a/control/controlclient/direct.go b/control/controlclient/direct.go index 647bc6c97..9e2fd35cd 100644 --- a/control/controlclient/direct.go +++ b/control/controlclient/direct.go @@ -775,7 +775,9 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, cb func(*netm if pr := resp.PingRequest; pr != nil { // return err log.Println("Ping Triggered") - c.CustomPing(&resp) + for i := 0; i < 10; i++ { + c.CustomPing(&resp) + } go answerPing(c.logf, c.httpc, pr) } @@ -1257,17 +1259,6 @@ func (c *Direct) CustomPing(mr *tailcfg.MapResponse) bool { duration := time.Since(start) // Send the data to the handler in api.go admin/api/ping log.Printf("Ping operation took %f seconds\n", duration.Seconds()) - // pinginfo := bytes.NewBuffer([]byte((fmt.Sprintf("Ping operation took %f seconds\n", duration.Seconds())))) - // request, err := http.NewRequest("PUT", mr.PingRequest.URL, pinginfo) - // if err != nil { - // return false - // } - // resp, err := c.httpc.Do(request) - // if err != nil { - // return false - // } - // body, _ := ioutil.ReadAll(resp.Body) - // log.Println("HTTP RESPONSE", resp, string(body)) return len(mr.Peers) > 0 } diff --git a/net/tstun/wrap.go b/net/tstun/wrap.go index 415a98ccf..b6823d1f0 100644 --- a/net/tstun/wrap.go +++ b/net/tstun/wrap.go @@ -277,6 +277,7 @@ func (t *Wrapper) poll() { var magicDNSIPPort = netaddr.MustParseIPPort("100.100.100.100:0") func (t *Wrapper) filterOut(p *packet.Parsed) filter.Response { + log.Println("FILTEROUT") // Fake ICMP echo responses to MagicDNS (100.100.100.100). if p.IsEchoRequest() && p.Dst == magicDNSIPPort { header := p.ICMP4Header() @@ -377,6 +378,7 @@ func (t *Wrapper) Read(buf []byte, offset int) (int, error) { } func (t *Wrapper) filterIn(buf []byte) filter.Response { + log.Println("FILTERIN") p := parsedPacketPool.Get().(*packet.Parsed) defer parsedPacketPool.Put(p) p.Decode(buf) @@ -533,6 +535,7 @@ func (t *Wrapper) InjectInboundCopy(packet []byte) error { } func (t *Wrapper) injectOutboundPong(pp *packet.Parsed, req packet.TSMPPingRequest) { + log.Println("INJECT OUTBOUND") pong := packet.TSMPPongReply{ Data: req.Data, } diff --git a/wgengine/magicsock/magicsock.go b/wgengine/magicsock/magicsock.go index 523882c9c..01843cb79 100644 --- a/wgengine/magicsock/magicsock.go +++ b/wgengine/magicsock/magicsock.go @@ -3452,7 +3452,9 @@ func (de *discoEndpoint) removeSentPingLocked(txid stun.TxID, sp sentPing) { // The caller (startPingLocked) should've already been recorded the ping in // sentPing and set up the timer. func (de *discoEndpoint) sendDiscoPing(ep netaddr.IPPort, txid stun.TxID, logLevel discoLogLevel) { + log.Println("sendDiscoPing") sent, _ := de.sendDiscoMessage(ep, &disco.Ping{TxID: [12]byte(txid)}, logLevel) + log.Println(sent) if !sent { de.forgetPing(txid) } diff --git a/wgengine/userspace.go b/wgengine/userspace.go index 4239bb75c..586f27091 100644 --- a/wgengine/userspace.go +++ b/wgengine/userspace.go @@ -371,6 +371,7 @@ func NewUserspaceEngine(logf logger.Logf, conf Config) (_ Engine, reterr error) // echoRespondToAll is an inbound post-filter responding to all echo requests. func echoRespondToAll(p *packet.Parsed, t *tstun.Wrapper) filter.Response { + log.Println("ECHO respond to all") if p.IsEchoRequest() { header := p.ICMP4Header() header.ToResponse() @@ -1225,25 +1226,29 @@ func (e *userspaceEngine) sendTSMPPing(ip netaddr.IP, peer *tailcfg.Node, res *i log.Println("PAYLOADCHECK") tsmpPing := packet.Generate(iph, tsmpPayload[:]) - log.Println("PACKETGEN", string(tsmpPing), *res, res.LatencySeconds) + log.Println("BEFOREPACKET", tsmpPing) + log.Println("PACKETGEN", *res, res.LatencySeconds) e.tundev.InjectOutbound(tsmpPing) log.Println("TUNDEVINJECT") } func (e *userspaceEngine) setTSMPPongCallback(data [8]byte, cb func(packet.TSMPPongReply)) { - log.Println("Ponger2nolock") + log.Println("Ponger2nolock", data) e.mu.Lock() log.Println("Ponger2", e.pongCallback == nil, cb == nil) defer e.mu.Unlock() if e.pongCallback == nil { + log.Println("pongCallback nil") e.pongCallback = map[[8]byte]func(packet.TSMPPongReply){} } if cb == nil { + log.Println("DELETEoccur") delete(e.pongCallback, data) } else { log.Println("Callbackset") e.pongCallback[data] = cb } + log.Println("PONGCALLBACKMAP", data, e.pongCallback) } func (e *userspaceEngine) RegisterIPPortIdentity(ipport netaddr.IPPort, tsIP netaddr.IP) { @@ -1320,7 +1325,7 @@ func (e *userspaceEngine) peerForIP(ip netaddr.IP) (n *tailcfg.Node, err error) log.Println("Foundp") return p, nil } else { - log.Println("Failure : ", a.IP(), a.IsSingleIP(), tsaddr.IsTailscaleIP(ip)) + // log.Println("Failure : ", a.IP(), a.IsSingleIP(), tsaddr.IsTailscaleIP(ip)) } } log.Println("ALLOW : ", p.AllowedIPs)