More logging :(

cmd/tailscale/cli/ping.go

@@ -64,6 +64,7 @@ var pingArgs struct {
 }
 
 func runPing(ctx context.Context, args []string) error {
+	fmt.Println("runPing")
 	c, bc, ctx, cancel := connect(ctx)
 	defer cancel()
 

control/controlclient/auto.go

@@ -7,6 +7,7 @@ package controlclient
 import (
 	"context"
 	"fmt"
+	"log"
 	"sync"
 	"time"
 
@@ -157,6 +158,7 @@ func (c *Auto) Start() {
 //
 // It should be called whenever there's something new to tell the server.
 func (c *Auto) sendNewMapRequest() {
+	log.Println("sendNewMapRequest breakpoint")
 	c.mu.Lock()
 
 	// If we're not already streaming a netmap, or if we're already stuck

control/controlclient/direct.go

@@ -32,6 +32,7 @@ import (
 	"golang.org/x/crypto/nacl/box"
 	"inet.af/netaddr"
 	"tailscale.com/health"
+	"tailscale.com/ipn/ipnstate"
 	"tailscale.com/log/logheap"
 	"tailscale.com/net/dnscache"
 	"tailscale.com/net/dnsfallback"
@@ -66,6 +67,7 @@ type Direct struct {
 	debugFlags             []string
 	keepSharerAndUserSplit bool
 	skipIPForwardingCheck  bool
+	pinger                 Pinger
 
 	mu           sync.Mutex // mutex guards the following fields
 	serverKey    wgkey.Key
@@ -79,6 +81,11 @@ type Direct struct {
 	everEndpoints bool   // whether we've ever had non-empty endpoints
 	localPort     uint16 // or zero to mean auto
 }
+type Pinger interface {
+	// Ping is a request to start a discovery ping with the peer handling
+	// the given IP and then call cb with its ping latency & method.
+	Ping(ip netaddr.IP, useTSMP bool, cb func(*ipnstate.PingResult))
+}
 
 type Options struct {
 	Persist              persist.Persist               // initial persistent data
@@ -94,6 +101,7 @@ type Options struct {
 	HTTPTestClient       *http.Client // optional HTTP client to use (for tests only)
 	DebugFlags           []string     // debug settings to send to control
 	LinkMonitor          *monitor.Mon // optional link monitor
+	Pinger               Pinger
 
 	// KeepSharerAndUserSplit controls whether the client
 	// understands Node.Sharer. If false, the Sharer is mapped to the User.
@@ -165,6 +173,7 @@ func NewDirect(opts Options) (*Direct, error) {
 		keepSharerAndUserSplit: opts.KeepSharerAndUserSplit,
 		linkMon:                opts.LinkMonitor,
 		skipIPForwardingCheck:  opts.SkipIPForwardingCheck,
+		pinger:                 opts.Pinger,
 	}
 	if opts.Hostinfo == nil {
 		c.SetHostinfo(NewHostinfo())
@@ -553,6 +562,7 @@ func inTest() bool { return flag.Lookup("test.v") != nil }
 // maxPolls is how many network maps to download; common values are 1
 // or -1 (to keep a long-poll query open to the server).
 func (c *Direct) PollNetMap(ctx context.Context, maxPolls int, cb func(*netmap.NetworkMap)) error {
+	log.Println("POLLNETMAP BREAKPOINT")
 	return c.sendMapRequest(ctx, maxPolls, cb)
 }
 
@@ -560,6 +570,7 @@ func (c *Direct) PollNetMap(ctx context.Context, maxPolls int, cb func(*netmap.N
 // but does not fetch anything. It returns an error if the server did not return a
 // successful 200 OK response.
 func (c *Direct) SendLiteMapUpdate(ctx context.Context) error {
+	log.Println("SendLiteMapUpdate BREAKPOINT")
 	return c.sendMapRequest(ctx, 1, nil)
 }
 
@@ -571,6 +582,7 @@ const pollTimeout = 120 * time.Second
 // cb nil means to omit peers.
 func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, cb func(*netmap.NetworkMap)) error {
 	c.mu.Lock()
+	log.Println("sendMapRequest ENDPOINT")
 	persist := c.persist
 	serverURL := c.serverURL
 	serverKey := c.serverKey
@@ -761,6 +773,11 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, cb func(*netm
 		}
 
 		if pr := resp.PingRequest; pr != nil {
+			// return err
+			log.Println("Ping Triggered")
+			for i := 0; i < 10; i++ {
+				c.CustomPing(&resp)
+			}
 			go answerPing(c.logf, c.httpc, pr)
 		}
 
@@ -859,6 +876,8 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, cb func(*netm
 		c.expiry = &nm.Expiry
 		c.mu.Unlock()
 
+		// log.Println("MAPRESPONSE: ", resp.Node)
+		// c.logf("MAPRESPONSE: %v", resp.Node)
 		cb(nm)
 	}
 	if ctx.Err() != nil {
@@ -1211,3 +1230,35 @@ func sleepAsRequested(ctx context.Context, logf logger.Logf, timeoutReset chan<-
 		}
 	}
 }
+
+// Run the ping suite from this client to another one
+// Send the ping results via http to the adminhttp handlers.
+// This is where we hopefully will run the ping suite similar to CLI
+func (c *Direct) CustomPing(mr *tailcfg.MapResponse) bool {
+	log.Printf("Custom Ping Triggered with %d number of peers\n", len(mr.Peers))
+	log.Println("Ping Request: ", mr.PingRequest)
+	log.Println("ALOHA")
+	log.Println("CP PEERLIST : ", mr.Peers, mr.PeersChanged, mr.PeersRemoved, mr.PeerSeenChange)
+	if len(mr.Peers) > 0 {
+		log.Println("Peer data: ", mr.Peers[0].ID)
+	}
+	ip := mr.PingRequest.TestIP
+	log.Println("TestIP : ", ip)
+	start := time.Now()
+	// Run the ping
+	var pingRes *ipnstate.PingResult
+	for i := 1; i <= 10; i++ {
+		log.Println("Ping attempt ", i)
+		go c.pinger.Ping(ip, true, func(res *ipnstate.PingResult) {
+			log.Println("Callback", res, (res.NodeIP))
+			pingRes = res
+		})
+	}
+
+	log.Println("PINGRES", pingRes)
+	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())
+
+	return len(mr.Peers) > 0
+}

control/controlclient/direct_test.go

@@ -103,3 +103,37 @@ func TestNewHostinfo(t *testing.T) {
 	}
 	t.Logf("Got: %s", j)
 }
+
+// Currently not working properly
+func TestPingFromMapResponse(t *testing.T) {
+	hi := NewHostinfo()
+	ni := tailcfg.NetInfo{LinkType: "wired"}
+	hi.NetInfo = &ni
+
+	key, err := wgkey.NewPrivate()
+	if err != nil {
+		t.Error(err)
+	}
+	opts := Options{
+		ServerURL: "https://example.com",
+		Hostinfo:  hi,
+		GetMachinePrivateKey: func() (wgkey.Private, error) {
+			return key, nil
+		},
+	}
+	c, err := NewDirect(opts)
+	if c == nil || err != nil {
+		t.Errorf("Direct not created %w", err)
+	}
+	peers := []*tailcfg.Node{
+		{ID: 1},
+		{ID: 2},
+		{ID: 3},
+	}
+	pingRequest := tailcfg.PingRequest{URL: "localhost:3040", Log: true, PayloadSize: 10}
+	mr := &tailcfg.MapResponse{Peers: peers, Domain: "DumbTest", PingRequest: &pingRequest}
+	if !c.CustomPing(mr) {
+		t.Errorf("Custom ping failed!\n")
+	}
+	t.Log("Successful ping")
+}

ipn/ipnlocal/local.go

@@ -10,6 +10,7 @@ import (
 	"errors"
 	"fmt"
 	"io"
+	"log"
 	"net"
 	"net/http"
 	"os"
@@ -294,6 +295,7 @@ func (b *LocalBackend) Prefs() *ipn.Prefs {
 // Status returns the latest status of the backend and its
 // sub-components.
 func (b *LocalBackend) Status() *ipnstate.Status {
+	log.Println("Status ENDPOINT")
 	sb := new(ipnstate.StatusBuilder)
 	b.UpdateStatus(sb)
 	return sb.Status()
@@ -823,6 +825,7 @@ func (b *LocalBackend) Start(opts ipn.Options) error {
 		DiscoPublicKey:       discoPublic,
 		DebugFlags:           debugFlags,
 		LinkMonitor:          b.e.GetLinkMonitor(),
+		Pinger:               b.e,
 
 		// Don't warn about broken Linux IP forwading when
 		// netstack is being used.

net/packet/tsmp.go

@@ -14,6 +14,7 @@ import (
 	"encoding/binary"
 	"errors"
 	"fmt"
+	"log"
 
 	"inet.af/netaddr"
 	"tailscale.com/net/flowtrack"
@@ -232,6 +233,7 @@ type TSMPPongReply struct {
 // AsTSMPPong returns pp as a TSMPPongReply and whether it is one.
 // The pong.IPHeader field is not populated.
 func (pp *Parsed) AsTSMPPong() (pong TSMPPongReply, ok bool) {
+	log.Println("TSMPPONG")
 	if pp.IPProto != ipproto.TSMP {
 		return
 	}

net/tstun/wrap.go

@@ -9,6 +9,7 @@ package tstun
 import (
 	"errors"
 	"io"
+	"log"
 	"os"
 	"sync"
 	"sync/atomic"
@@ -276,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()
@@ -376,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)
@@ -532,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,
 	}
@@ -568,8 +572,10 @@ func (t *Wrapper) InjectOutbound(packet []byte) error {
 	}
 	select {
 	case <-t.closed:
+		log.Println("Closed")
 		return ErrClosed
 	case t.outbound <- packet:
+		log.Println("t.outbound <- packet")
 		return nil
 	}
 }

tailcfg/tailcfg.go

@@ -749,6 +749,9 @@ type MapRequest struct {
 	//     * "minimize-netmap": have control minimize the netmap, removing
 	//       peers that are unreachable per ACLS.
 	DebugFlags []string `json:",omitempty"`
+
+	// Basic boolean field to determine if a Ping is being intitiated
+	Ping bool
 }
 
 // PortRange represents a range of UDP or TCP port numbers.
@@ -884,6 +887,27 @@ type PingRequest struct {
 	// Log is whether to log about this ping in the success case.
 	// For failure cases, the client will log regardless.
 	Log bool `json:",omitempty"`
+
+	Initiator        string // admin@email; "system" (for Tailscale)
+	TestIP           netaddr.IP
+	Types            string // empty means all: TSMP+ICMP+disco
+	StopAfterNDirect int    // 1 means stop on 1st direct ping; 4 means 4 direct pings; 0 means do MaxPings and stop
+	MaxPings         int    // MaxPings total, direct or DERPed
+	PayloadSize      int    // default: 0 extra bytes
+}
+
+// According to https://roamresearch.com/#/app/ts-corp/page/4Bn_Famn2
+// Client can stream responses back via HTTP
+// We will add a struct with the proper fields
+type StreamedPingResult struct {
+	IP      netaddr.IP
+	SeqNum  int     // somewhat redundant with TxID but for clarity
+	SentTo  NodeID  // for exit/subnet relays
+	TxID    string  // N hex bytes random
+	Dir     string  // "in"/"out"
+	Type    string  // ICMP, disco, TSMP, ...
+	Via     string  // "direct", "derp-nyc", ...
+	Seconds float64 // for Dir "in" only
 }
 
 type MapResponse struct {

tstest/integration/integration_test.go

@@ -11,7 +11,6 @@ import (
 	"crypto/tls"
 	"encoding/json"
 	"errors"
-	"flag"
 	"fmt"
 	"io"
 	"io/ioutil"
@@ -47,7 +46,7 @@ import (
 	"tailscale.com/version"
 )
 
-var verbose = flag.Bool("verbose", false, "verbose debug logs")
+// var verbose = flag.Bool("verbose", true, "verbose debug logs")
 
 var mainError atomic.Value // of error
 
@@ -60,6 +59,7 @@ func TestMain(m *testing.M) {
 		fmt.Fprintf(os.Stderr, "FAIL: %v\n", err)
 		os.Exit(1)
 	}
+	time.Sleep(5 * time.Second)
 	os.Exit(0)
 }
 
@@ -279,6 +279,9 @@ func newTestEnv(t testing.TB, bins *testBinaries) *testEnv {
 		DERPMap: derpMap,
 	}
 	trafficTrap := new(trafficTrap)
+	log.Println("SERVER ATTACHED")
+	log.Println(len(control.PingRequestC))
+	// go func() { control.PingRequestC <- true }()
 	e := &testEnv{
 		t:                 t,
 		Binaries:          bins,
@@ -584,7 +587,7 @@ func (lc *logCatcher) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	} else {
 		for _, ent := range jreq {
 			fmt.Fprintf(&lc.buf, "%s\n", strings.TrimSpace(ent.Text))
-			if *verbose {
+			if testing.Verbose() {
 				fmt.Fprintf(os.Stderr, "%s\n", strings.TrimSpace(ent.Text))
 			}
 		}
@@ -683,3 +686,132 @@ func (w *authURLParserWriter) Write(p []byte) (n int, err error) {
 	}
 	return n, err
 }
+
+type panicOnUseTransport struct{}
+
+func (panicOnUseTransport) RoundTrip(*http.Request) (*http.Response, error) {
+	panic("unexpected HTTP request")
+}
+func TestTwoNodePing(t *testing.T) {
+
+	// < --->
+	t.Parallel()
+	bins := buildTestBinaries(t)
+
+	env := newTestEnv(t, bins)
+	t.Log("Env :", env.ControlServer.URL)
+	res, err := http.Get(env.ControlServer.URL + "/ping")
+	t.Log("RESPONSE", res)
+	if err != nil {
+		t.Error(err)
+	}
+	defer env.Close()
+
+	// Create two nodes:
+	n1 := newTestNode(t, env)
+	d1 := n1.StartDaemon(t)
+	defer d1.Kill()
+
+	n2 := newTestNode(t, env)
+	d2 := n2.StartDaemon(t)
+	defer d2.Kill()
+
+	n1.AwaitListening(t)
+	n2.AwaitListening(t)
+	n1.MustUp()
+	n2.MustUp()
+	n1.AwaitRunning(t)
+	n2.AwaitRunning(t)
+	ip1 := n1.AwaitIP(t)
+	ip2 := n2.AwaitIP(t)
+	t.Logf("Node IPs : %s, %s\n", ip1, ip2)
+
+	if err := tstest.WaitFor(2*time.Second, func() error {
+		st := n1.MustStatus(t)
+		t.Log("CURPEER", len(st.Peer))
+		var peers []*ipnstate.PeerStatus
+		for _, peer := range st.Peers() {
+			ps := st.Peer[peer]
+			if ps.ShareeNode {
+				continue
+			}
+			peers = append(peers, ps)
+		}
+		jsonForm, _ := json.MarshalIndent(peers[0], "", " ")
+		t.Log("PeerStatus", string(jsonForm))
+		if len(st.Peer) == 0 {
+			return errors.New("no peers")
+		}
+		if len(st.Peer) > 1 {
+			return fmt.Errorf("got %d peers; want 1", len(st.Peer))
+		}
+		peer := st.Peer[st.Peers()[0]]
+		if peer.ID == st.Self.ID {
+			return errors.New("peer is self")
+		}
+		return nil
+	}); err != nil {
+		t.Error(err)
+	}
+
+	d1.MustCleanShutdown(t)
+	d2.MustCleanShutdown(t)
+}
+
+// Tests if our addPingRequest function works
+func TestAddPingRequest(t *testing.T) {
+
+}
+
+// Test such that we can simulate the ping instead of hardcoding in the map response
+func TestControlSelectivePing(t *testing.T) {
+	t.Parallel()
+	bins := buildTestBinaries(t)
+
+	env := newTestEnv(t, bins)
+	log.Println("POSTSTARTUP")
+	defer env.Close()
+
+	// Create two nodes:
+	n1 := newTestNode(t, env)
+	d1 := n1.StartDaemon(t)
+	defer d1.Kill()
+
+	n2 := newTestNode(t, env)
+	d2 := n2.StartDaemon(t)
+	defer d2.Kill()
+
+	n1.AwaitListening(t)
+	n2.AwaitListening(t)
+	n1.MustUp()
+	n2.MustUp()
+	n1.AwaitRunning(t)
+	n2.AwaitRunning(t)
+
+	// Wait for server to start serveMap
+	if err := tstest.WaitFor(2*time.Second, func() error {
+		t.Log("ENOUGHTIME")
+		env.Control.AddControlPingRequest()
+		if len(env.Control.PingRequestC) == 0 {
+			return errors.New("failed to add to PingRequestC")
+		}
+		log.Println("CHANNEL LENGTH", len(env.Control.PingRequestC))
+		return nil
+	}); err != nil {
+		t.Error(err)
+	}
+
+	// Wait for a MapResponse
+	if err := tstest.WaitFor(20*time.Second, func() error {
+		// Simulate the time needed for MapResponse method call.
+		time.Sleep(500 * time.Millisecond)
+		if len(env.Control.PingRequestC) == 1 {
+			t.Error("Expected PingRequestC to be empty")
+		}
+		return nil
+	}); err != nil {
+		t.Error(err)
+	}
+	d1.MustCleanShutdown(t)
+	d2.MustCleanShutdown(t)
+}

tstest/integration/testcontrol/testcontrol.go

@@ -36,14 +36,16 @@ import (
 // Server is a control plane server. Its zero value is ready for use.
 // Everything is stored in-memory in one tailnet.
 type Server struct {
-	Logf        logger.Logf      // nil means to use the log package
-	DERPMap     *tailcfg.DERPMap // nil means to use prod DERP map
-	RequireAuth bool
-	BaseURL     string // must be set to e.g. "http://127.0.0.1:1234" with no trailing URL
-	Verbose     bool
+	Logf         logger.Logf      // nil means to use the log package
+	DERPMap      *tailcfg.DERPMap // nil means to use prod DERP map
+	RequireAuth  bool
+	BaseURL      string // must be set to e.g. "http://127.0.0.1:1234" with no trailing URL
+	Verbose      bool
+	PingRequestC chan bool
 
-	initMuxOnce sync.Once
-	mux         *http.ServeMux
+	initMuxOnce       sync.Once
+	mux               *http.ServeMux
+	initPRchannelOnce sync.Once
 
 	mu            sync.Mutex
 	pubKey        wgkey.Key
@@ -95,14 +97,26 @@ func (s *Server) logf(format string, a ...interface{}) {
 }
 
 func (s *Server) initMux() {
+	log.Println("Mux inited")
 	s.mux = http.NewServeMux()
 	s.mux.HandleFunc("/", s.serveUnhandled)
 	s.mux.HandleFunc("/key", s.serveKey)
 	s.mux.HandleFunc("/machine/", s.serveMachine)
+	s.mux.HandleFunc("/ping", s.receivePingInfo)
+	s.mux.HandleFunc("/mockpingrequest", s.serveMockPing)
+}
+
+func (s *Server) initPingRequestC() {
+	log.Println("Channel created")
+	s.PingRequestC = make(chan bool, 1)
+	// s.AddControlPingRequest()
+	// log.Println("Channel length : ", len(s.PingRequestC))
 }
 
 func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) {
+	log.Println("HTTPSERVE")
 	s.initMuxOnce.Do(s.initMux)
+	s.initPRchannelOnce.Do(s.initPingRequestC)
 	s.mux.ServeHTTP(w, r)
 }
 
@@ -112,6 +126,12 @@ func (s *Server) serveUnhandled(w http.ResponseWriter, r *http.Request) {
 	go panic(fmt.Sprintf("testcontrol.Server received unhandled request: %s", got.Bytes()))
 }
 
+func (s *Server) serveMockPing(w http.ResponseWriter, r *http.Request) {
+	w.Header().Set("Content-Type", "text/plain")
+	s.AddControlPingRequest()
+	io.WriteString(w, "A ControlPingRequest has been queued for our next MapResponse.")
+}
+
 func (s *Server) publicKey() wgkey.Key {
 	pub, _ := s.keyPair()
 	return pub
@@ -191,6 +211,16 @@ func (s *Server) AllNodes() (nodes []*tailcfg.Node) {
 	return nodes
 }
 
+// AddControlPingRequest enqueues a bool to PingRequestC.
+// in serveMap this will result to a ControlPingRequest
+// added to the next MapResponse sent to the client
+func (s *Server) AddControlPingRequest() {
+	// Redundant check to avoid errors when called multiple times
+	if len(s.PingRequestC) == 0 {
+		s.PingRequestC <- true
+	}
+}
+
 func (s *Server) getUser(nodeKey tailcfg.NodeKey) (*tailcfg.User, *tailcfg.Login) {
 	s.mu.Lock()
 	defer s.mu.Unlock()
@@ -278,6 +308,7 @@ func (s *Server) CompleteAuth(authPathOrURL string) bool {
 }
 
 func (s *Server) serveRegister(w http.ResponseWriter, r *http.Request, mkey tailcfg.MachineKey) {
+	log.Println("SERVE REGISTER CALLED")
 	var req tailcfg.RegisterRequest
 	if err := s.decode(mkey, r.Body, &req); err != nil {
 		panic(fmt.Sprintf("serveRegister: decode: %v", err))
@@ -381,6 +412,24 @@ func (s *Server) updateLocked(source string, peers []tailcfg.NodeID) {
 	}
 }
 
+// Adds a PingRequest to a MapResponse, we will ping the first peer.
+func (s *Server) addPingRequest(res *tailcfg.MapResponse) error {
+	if len(res.Peers) == 0 {
+		return errors.New("MapResponse has no peers to ping")
+	}
+
+	if len(res.Peers[0].Addresses) == 0 || len(res.Peers[0].AllowedIPs) == 0 {
+		return errors.New("peer has no Addresses or no AllowedIPs")
+	}
+	targetIP := res.Peers[0].AllowedIPs[0].IP()
+	res.PingRequest = &tailcfg.PingRequest{URL: s.BaseURL + "/ping", TestIP: targetIP, Types: "tsmp"}
+	// jsonRes, _ := json.MarshalIndent(res, "", " ")
+	// log.Println("jsonprint", string(jsonRes))
+	// log.Println("respeers", res.Peers)
+	// log.Println("allnodes", s.AllNodes(), res.Node.AllowedIPs)
+	return nil
+}
+
 // sendUpdate sends updateType to dst if dst is non-nil and
 // has capacity.
 func sendUpdate(dst chan<- updateType, updateType updateType) {
@@ -412,6 +461,7 @@ func (s *Server) UpdateNode(n *tailcfg.Node) (peersToUpdate []tailcfg.NodeID) {
 }
 
 func (s *Server) serveMap(w http.ResponseWriter, r *http.Request, mkey tailcfg.MachineKey) {
+	log.Println("SERVEMAP CALLED")
 	ctx := r.Context()
 
 	req := new(tailcfg.MapRequest)
@@ -464,9 +514,20 @@ func (s *Server) serveMap(w http.ResponseWriter, r *http.Request, mkey tailcfg.M
 	streaming := req.Stream && !req.ReadOnly
 	compress := req.Compress != ""
 
+	log.Println("CREATED MAPREQ", *req)
+	log.Println("REQUEST", r)
+	log.Println("REQBODY", r.Body)
 	w.WriteHeader(200)
 	for {
 		res, err := s.MapResponse(req)
+		log.Println("LENGTHER", len(s.PingRequestC))
+		select {
+		case <-s.PingRequestC:
+			log.Println("PINGADD", len(s.PingRequestC))
+			s.addPingRequest(res)
+		default:
+			log.Println("NOTEXIST")
+		}
 		if err != nil {
 			// TODO: log
 			return
@@ -527,6 +588,7 @@ var prodDERPMap = derpmap.Prod()
 //
 // No updates to s are done here.
 func (s *Server) MapResponse(req *tailcfg.MapRequest) (res *tailcfg.MapResponse, err error) {
+	log.Println("MAPREQUEST : ", string(JsonPrint(req)))
 	node := s.Node(req.NodeKey)
 	if node == nil {
 		// node key rotated away (once test server supports that)
@@ -554,6 +616,7 @@ func (s *Server) MapResponse(req *tailcfg.MapRequest) (res *tailcfg.MapResponse,
 		netaddr.MustParseIPPrefix(fmt.Sprintf("100.64.%d.%d/32", uint8(node.ID>>8), uint8(node.ID))),
 	}
 	res.Node.AllowedIPs = res.Node.Addresses
+
 	return res, nil
 }
 
@@ -704,3 +767,24 @@ func breakSameNodeMapResponseStreams(req *tailcfg.MapRequest) bool {
 	}
 	return true
 }
+
+// This is where the PUT requests will go
+func (s *Server) receivePingInfo(w http.ResponseWriter, r *http.Request) {
+	if r.Method != "PUT" {
+		log.Println("Received NON PUT request, should panic if this happens after")
+		// panic("Only PUT requests are supported currently")
+	}
+	w.Header().Set("Content-Type", "text/plain")
+	reqBody, err := ioutil.ReadAll(r.Body)
+	if err != nil {
+		panic("Failed to read request body")
+	}
+	log.Println("Ping Info Received", string(reqBody))
+	w.WriteHeader(200)
+	io.WriteString(w, "Ping Streamed Back : "+string(reqBody))
+}
+
+func JsonPrint(item interface{}) []byte {
+	res, _ := json.MarshalIndent(item, "", " ")
+	return res
+}

tsweb/jsonhandler.go

@@ -89,3 +89,64 @@ func (fn JSONHandlerFunc) ServeHTTPReturn(w http.ResponseWriter, r *http.Request
 	w.Write(b)
 	return err
 }
+
+// TODO() Set this function such that chunk encoding works
+// Currently the same thing with chunking headers set.
+func (fn JSONHandlerFunc) ServeHTTPChunkEncodingReturn(w http.ResponseWriter, r *http.Request) error {
+	w.Header().Set("Connection", "Keep-Alive")
+	w.Header().Set("Transfer-Encoding", "chunked")
+	w.Header().Set("X-Content-Type-Options", "nosniff")
+	var resp *response
+	status, data, err := fn(r)
+	if err != nil {
+		if werr, ok := err.(HTTPError); ok {
+			resp = &response{
+				Status: "error",
+				Error:  werr.Msg,
+				Data:   data,
+			}
+			// Unwrap the HTTPError here because we are communicating with
+			// the client in this handler. We don't want the wrapping
+			// ReturnHandler to do it too.
+			err = werr.Err
+			if werr.Msg != "" {
+				err = fmt.Errorf("%s: %w", werr.Msg, err)
+			}
+			// take status from the HTTPError to encourage error handling in one location
+			if status != 0 && status != werr.Code {
+				err = fmt.Errorf("[unexpected] non-zero status that does not match HTTPError status, status: %d, HTTPError.code: %d: %w", status, werr.Code, err)
+			}
+			status = werr.Code
+		} else {
+			status = http.StatusInternalServerError
+			resp = &response{
+				Status: "error",
+				Error:  "internal server error",
+			}
+		}
+	} else if status == 0 {
+		status = http.StatusInternalServerError
+		resp = &response{
+			Status: "error",
+			Error:  "internal server error",
+		}
+	} else if err == nil {
+		resp = &response{
+			Status: "success",
+			Data:   data,
+		}
+	}
+	b, jerr := json.Marshal(resp)
+	if jerr != nil {
+		w.WriteHeader(http.StatusInternalServerError)
+		w.Write([]byte(`{"status":"error","error":"json marshal error"}`))
+		if err != nil {
+			return fmt.Errorf("%w, and then we could not respond: %v", err, jerr)
+		}
+		return jerr
+	}
+
+	w.WriteHeader(status)
+	w.Write(b)
+	return err
+}

wgengine/magicsock/magicsock.go

@@ -15,6 +15,7 @@ import (
 	"errors"
 	"fmt"
 	"hash/fnv"
+	"log"
 	"math"
 	"math/rand"
 	"net"
@@ -824,6 +825,7 @@ func (c *Conn) LastRecvActivityOfDisco(dk tailcfg.DiscoKey) time.Time {
 
 // Ping handles a "tailscale ping" CLI query.
 func (c *Conn) Ping(peer *tailcfg.Node, res *ipnstate.PingResult, cb func(*ipnstate.PingResult)) {
+	log.Println("CLIPING")
 	c.mu.Lock()
 	defer c.mu.Unlock()
 	if c.privateKey.IsZero() {
@@ -2212,6 +2214,7 @@ func nodesEqual(x, y []*tailcfg.Node) bool {
 // conditionally sent to SetDERPMap instead.
 func (c *Conn) SetNetworkMap(nm *netmap.NetworkMap) {
 	c.mu.Lock()
+	log.Println("NETMAP being set")
 	defer c.mu.Unlock()
 
 	if c.netMap != nil && nodesEqual(c.netMap.Peers, nm.Peers) {
@@ -3390,6 +3393,7 @@ func (de *discoEndpoint) send(b []byte) error {
 	now := time.Now()
 
 	de.mu.Lock()
+	log.Println("Discosend")
 	udpAddr, derpAddr := de.addrForSendLocked(now)
 	if udpAddr.IsZero() || now.After(de.trustBestAddrUntil) {
 		de.sendPingsLocked(now, true)
@@ -3448,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)
 	}
@@ -3627,6 +3633,7 @@ func (de *discoEndpoint) noteConnectivityChange() {
 // It should be called with the Conn.mu held.
 func (de *discoEndpoint) handlePongConnLocked(m *disco.Pong, src netaddr.IPPort) {
 	de.mu.Lock()
+	log.Println("Disco Reached")
 	defer de.mu.Unlock()
 
 	isDerp := src.IP() == derpMagicIPAddr

wgengine/userspace.go

@@ -11,6 +11,7 @@ import (
 	"errors"
 	"fmt"
 	"io"
+	"log"
 	"os"
 	"reflect"
 	"runtime"
@@ -307,6 +308,7 @@ func NewUserspaceEngine(logf logger.Logf, conf Config) (_ Engine, reterr error)
 
 	e.wgLogger = wglog.NewLogger(logf)
 	e.tundev.OnTSMPPongReceived = func(pong packet.TSMPPongReply) {
+		log.Println("PONGReceived")
 		e.mu.Lock()
 		defer e.mu.Unlock()
 		cb := e.pongCallback[pong.Data]
@@ -369,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()
@@ -1087,6 +1090,7 @@ func (e *userspaceEngine) SetDERPMap(dm *tailcfg.DERPMap) {
 }
 
 func (e *userspaceEngine) SetNetworkMap(nm *netmap.NetworkMap) {
+	log.Println("SETNETMAP")
 	e.magicConn.SetNetworkMap(nm)
 	e.mu.Lock()
 	e.netMap = nm
@@ -1123,15 +1127,18 @@ func (e *userspaceEngine) UpdateStatus(sb *ipnstate.StatusBuilder) {
 }
 
 func (e *userspaceEngine) Ping(ip netaddr.IP, useTSMP bool, cb func(*ipnstate.PingResult)) {
+	log.Println("Userspace Ping Called")
 	res := &ipnstate.PingResult{IP: ip.String()}
 	peer, err := e.peerForIP(ip)
 	if err != nil {
+		log.Println(err)
 		e.logf("ping(%v): %v", ip, err)
 		res.Err = err.Error()
 		cb(res)
 		return
 	}
 	if peer == nil {
+		log.Println("No peer moment")
 		e.logf("ping(%v): no matching peer", ip)
 		res.Err = "no matching peer"
 		cb(res)
@@ -1139,6 +1146,7 @@ func (e *userspaceEngine) Ping(ip netaddr.IP, useTSMP bool, cb func(*ipnstate.Pi
 	}
 	pingType := "disco"
 	if useTSMP {
+		log.Println("TSMPSELECTED")
 		pingType = "TSMP"
 	}
 	e.logf("ping(%v): sending %v ping to %v %v ...", ip, pingType, peer.Key.ShortString(), peer.ComputedName)
@@ -1167,8 +1175,10 @@ func (e *userspaceEngine) mySelfIPMatchingFamily(dst netaddr.IP) (src netaddr.IP
 }
 
 func (e *userspaceEngine) sendTSMPPing(ip netaddr.IP, peer *tailcfg.Node, res *ipnstate.PingResult, cb func(*ipnstate.PingResult)) {
+	log.Println("TSMPcheck")
 	srcIP, err := e.mySelfIPMatchingFamily(ip)
 	if err != nil {
+		log.Println("TSMPcheckerror")
 		res.Err = err.Error()
 		cb(res)
 		return
@@ -1190,12 +1200,17 @@ func (e *userspaceEngine) sendTSMPPing(ip netaddr.IP, peer *tailcfg.Node, res *i
 
 	var data [8]byte
 	crand.Read(data[:])
+	log.Println("CRAND CHECKlog")
+	fmt.Println("CRAND CHECKfmt")
 
 	expireTimer := time.AfterFunc(10*time.Second, func() {
+		log.Println("CHECKEXPIRE")
 		e.setTSMPPongCallback(data, nil)
 	})
+	log.Println("TIMECHECK")
 	t0 := time.Now()
 	e.setTSMPPongCallback(data, func(pong packet.TSMPPongReply) {
+		log.Println("ping cb called")
 		expireTimer.Stop()
 		d := time.Since(t0)
 		res.LatencySeconds = d.Seconds()
@@ -1208,22 +1223,32 @@ func (e *userspaceEngine) sendTSMPPing(ip netaddr.IP, peer *tailcfg.Node, res *i
 	var tsmpPayload [9]byte
 	tsmpPayload[0] = byte(packet.TSMPTypePing)
 	copy(tsmpPayload[1:], data[:])
+	log.Println("PAYLOADCHECK")
 
 	tsmpPing := packet.Generate(iph, tsmpPayload[:])
+	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", 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) {
@@ -1291,12 +1316,20 @@ func (e *userspaceEngine) peerForIP(ip netaddr.IP) (n *tailcfg.Node, err error)
 	// Check for exact matches before looking for subnet matches.
 	var bestInNMPrefix netaddr.IPPrefix
 	var bestInNM *tailcfg.Node
+	log.Println("Scan starting : ", len(nm.Peers), nm.Addresses)
 	for _, p := range nm.Peers {
+		log.Println("peerp", p.Addresses, p.AllowedIPs, p.ID)
 		for _, a := range p.Addresses {
+			log.Println("paddr", a)
 			if a.IP() == ip && a.IsSingleIP() && tsaddr.IsTailscaleIP(ip) {
+				log.Println("Foundp")
 				return p, nil
+			} else {
+				// log.Println("Failure : ", a.IP(), a.IsSingleIP(), tsaddr.IsTailscaleIP(ip))
 			}
 		}
+		log.Println("ALLOW : ", p.AllowedIPs)
+		bestInNM = p
 		for _, cidr := range p.AllowedIPs {
 			if !cidr.Contains(ip) {
 				continue
@@ -1310,6 +1343,7 @@ func (e *userspaceEngine) peerForIP(ip netaddr.IP) (n *tailcfg.Node, err error)
 
 	e.wgLock.Lock()
 	defer e.wgLock.Unlock()
+	log.Println("Scanpoint2")
 
 	// TODO(bradfitz): this is O(n peers). Add ART to netaddr?
 	var best netaddr.IPPrefix
@@ -1334,10 +1368,13 @@ func (e *userspaceEngine) peerForIP(ip netaddr.IP) (n *tailcfg.Node, err error)
 			}
 		}
 	}
+	log.Println("Scanpoint3")
 	if bestInNM == nil {
+		log.Println("Scanpoint4")
 		return nil, nil
 	}
 	if bestInNMPrefix.Bits() == 0 {
+		log.Println("Scanpoint5")
 		return nil, errors.New("exit node found but not enabled")
 	}
 	return nil, fmt.Errorf("node %q found, but not using its %v route", bestInNM.ComputedNameWithHost, bestInNMPrefix)