ipn/ipnlocal: stay out of map poll when down

Fixes #2434

Signed-off-by: Brad Fitzpatrick <bradfitz@tailscale.com>

ipn/ipnlocal/local.go

@@ -214,6 +214,15 @@ func (b *LocalBackend) SetDirectFileRoot(dir string) {
 	b.directFileRoot = dir
 }
 
+// b.mu must be held.
+func (b *LocalBackend) maybePauseControlClientLocked() {
+	if b.cc == nil {
+		return
+	}
+	networkUp := b.prevIfState.AnyInterfaceUp()
+	b.cc.SetPaused((b.state == ipn.Stopped && b.netMap != nil) || !networkUp)
+}
+
 // linkChange is our link monitor callback, called whenever the network changes.
 // major is whether ifst is different than earlier.
 func (b *LocalBackend) linkChange(major bool, ifst *interfaces.State) {
@@ -222,11 +231,7 @@ func (b *LocalBackend) linkChange(major bool, ifst *interfaces.State) {
 
 	hadPAC := b.prevIfState.HasPAC()
 	b.prevIfState = ifst
-
+	b.maybePauseControlClientLocked()
-	networkUp := ifst.AnyInterfaceUp()
-	if b.cc != nil {
-		go b.cc.SetPaused((b.state == ipn.Stopped && b.netMap != nil) || !networkUp)
-	}
 
 	// If the PAC-ness of the network changed, reconfig wireguard+route to
 	// add/remove subnets.
@@ -2173,9 +2178,7 @@ func (b *LocalBackend) enterState(newState ipn.State) {
 	oldState := b.state
 	b.state = newState
 	prefs := b.prefs
-	cc := b.cc
 	netMap := b.netMap
-	networkUp := b.prevIfState.AnyInterfaceUp()
 	activeLogin := b.activeLogin
 	authURL := b.authURL
 	if newState == ipn.Running {
@@ -2185,6 +2188,7 @@ func (b *LocalBackend) enterState(newState ipn.State) {
 		// Transitioning away from running.
 		b.closePeerAPIListenersLocked()
 	}
+	b.maybePauseControlClientLocked()
 	b.mu.Unlock()
 
 	if oldState == newState {
@@ -2195,10 +2199,6 @@ func (b *LocalBackend) enterState(newState ipn.State) {
 	health.SetIPNState(newState.String(), prefs.WantRunning)
 	b.send(ipn.Notify{State: &newState})
 
-	if cc != nil {
-		cc.SetPaused((newState == ipn.Stopped && netMap != nil) || !networkUp)
-	}
-
 	switch newState {
 	case ipn.NeedsLogin:
 		systemd.Status("Needs login: %s", authURL)
@@ -2459,6 +2459,7 @@ func (b *LocalBackend) setNetMapLocked(nm *netmap.NetworkMap) {
 		b.logf("active login: %v", login)
 		b.activeLogin = login
 	}
+	b.maybePauseControlClientLocked()
 
 	// Determine if file sharing is enabled
 	fs := hasCapability(nm, tailcfg.CapabilityFileSharing)

ipn/ipnlocal/state_test.go

@@ -354,7 +354,7 @@ func TestStateMachine(t *testing.T) {
 	c.Assert(b.Start(ipn.Options{StateKey: ipn.GlobalDaemonStateKey}), qt.IsNil)
 	{
 		// BUG: strictly, it should pause, not unpause, here, since !WantRunning.
-		c.Assert([]string{"Shutdown", "New", "unpause"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"Shutdown", "unpause", "New", "unpause"}, qt.DeepEquals, cc.getCalls())
 
 		nn := notifies.drain(2)
 		c.Assert(cc.getCalls(), qt.HasLen, 0)
@@ -389,7 +389,7 @@ func TestStateMachine(t *testing.T) {
 	url1 := "http://localhost:1/1"
 	cc.send(nil, url1, false, nil)
 	{
-		c.Assert(cc.getCalls(), qt.DeepEquals, []string{})
+		c.Assert(cc.getCalls(), qt.DeepEquals, []string{"unpause"})
 
 		// ...but backend eats that notification, because the user
 		// didn't explicitly request interactive login yet, and
@@ -414,7 +414,7 @@ func TestStateMachine(t *testing.T) {
 		// We're still not logged in so there's nothing we can do
 		// with it. (And empirically, it's providing an empty list
 		// of endpoints.)
-		c.Assert([]string{"UpdateEndpoints"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"UpdateEndpoints", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(nn[0].BrowseToURL, qt.Not(qt.IsNil))
 		c.Assert(url1, qt.Equals, *nn[0].BrowseToURL)
 	}
@@ -440,7 +440,7 @@ func TestStateMachine(t *testing.T) {
 	cc.send(nil, url2, false, nil)
 	{
 		// BUG: UpdateEndpoints again, this is getting silly.
-		c.Assert([]string{"UpdateEndpoints"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"UpdateEndpoints", "unpause", "unpause"}, qt.DeepEquals, cc.getCalls())
 
 		// This time, backend should emit it to the UI right away,
 		// because the UI is anxiously awaiting a new URL to visit.
@@ -470,7 +470,7 @@ func TestStateMachine(t *testing.T) {
 		// wait until it gets into Starting.
 		// TODO: (Currently this test doesn't detect that bug, but
 		// it's visible in the logs)
-		c.Assert([]string{"unpause", "UpdateEndpoints"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"unpause", "unpause", "UpdateEndpoints", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(nn[0].LoginFinished, qt.Not(qt.IsNil))
 		c.Assert(nn[1].Prefs, qt.Not(qt.IsNil))
 		c.Assert(nn[2].State, qt.Not(qt.IsNil))
@@ -492,7 +492,7 @@ func TestStateMachine(t *testing.T) {
 	})
 	{
 		nn := notifies.drain(1)
-		c.Assert([]string{"unpause", "UpdateEndpoints"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"unpause", "unpause", "UpdateEndpoints", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(nn[0].State, qt.Not(qt.IsNil))
 		c.Assert(ipn.Starting, qt.Equals, *nn[0].State)
 	}
@@ -534,7 +534,7 @@ func TestStateMachine(t *testing.T) {
 		nn := notifies.drain(2)
 		// BUG: UpdateEndpoints isn't needed here.
 		// BUG: Login isn't needed here. We never logged out.
-		c.Assert([]string{"Login", "unpause", "UpdateEndpoints"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"Login", "unpause", "UpdateEndpoints", "unpause"}, qt.DeepEquals, cc.getCalls())
 		// BUG: I would expect Prefs to change first, and state after.
 		c.Assert(nn[0].State, qt.Not(qt.IsNil))
 		c.Assert(nn[1].Prefs, qt.Not(qt.IsNil))
@@ -570,7 +570,7 @@ func TestStateMachine(t *testing.T) {
 	b.Logout()
 	{
 		nn := notifies.drain(2)
-		c.Assert([]string{"pause", "StartLogout"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"pause", "StartLogout", "pause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(nn[0].State, qt.Not(qt.IsNil))
 		c.Assert(nn[1].Prefs, qt.Not(qt.IsNil))
 		c.Assert(ipn.Stopped, qt.Equals, *nn[0].State)
@@ -587,7 +587,7 @@ func TestStateMachine(t *testing.T) {
 	cc.send(nil, "", false, nil)
 	{
 		nn := notifies.drain(1)
-		c.Assert([]string{"unpause"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"unpause", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(nn[0].State, qt.Not(qt.IsNil))
 		c.Assert(ipn.NeedsLogin, qt.Equals, *nn[0].State)
 		c.Assert(b.Prefs().LoggedOut, qt.IsTrue)
@@ -603,7 +603,7 @@ func TestStateMachine(t *testing.T) {
 		notifies.drain(0)
 		// BUG: the backend has already called StartLogout, and we're
 		// still logged out. So it shouldn't call it again.
-		c.Assert([]string{"StartLogout"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"StartLogout", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(cc.getCalls(), qt.HasLen, 0)
 		c.Assert(b.Prefs().LoggedOut, qt.IsTrue)
 		c.Assert(b.Prefs().WantRunning, qt.IsFalse)
@@ -617,8 +617,7 @@ func TestStateMachine(t *testing.T) {
 	cc.send(nil, "", false, nil)
 	{
 		notifies.drain(0)
-		c.Assert(cc.getCalls(), qt.HasLen, 0)
+		c.Assert(cc.getCalls(), qt.DeepEquals, []string{"unpause", "unpause"})
-		c.Assert(cc.getCalls(), qt.HasLen, 0)
 		c.Assert(b.Prefs().LoggedOut, qt.IsTrue)
 		c.Assert(b.Prefs().WantRunning, qt.IsFalse)
 		c.Assert(ipn.NeedsLogin, qt.Equals, b.State())
@@ -632,7 +631,7 @@ func TestStateMachine(t *testing.T) {
 	// I guess, since that's supposed to be synchronous.
 	{
 		notifies.drain(0)
-		c.Assert([]string{"Logout"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"Logout", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(cc.getCalls(), qt.HasLen, 0)
 		c.Assert(b.Prefs().LoggedOut, qt.IsTrue)
 		c.Assert(b.Prefs().WantRunning, qt.IsFalse)
@@ -646,8 +645,7 @@ func TestStateMachine(t *testing.T) {
 	cc.send(nil, "", false, nil)
 	{
 		notifies.drain(0)
-		c.Assert(cc.getCalls(), qt.HasLen, 0)
+		c.Assert(cc.getCalls(), qt.DeepEquals, []string{"unpause", "unpause"})
-		c.Assert(cc.getCalls(), qt.HasLen, 0)
 		c.Assert(b.Prefs().LoggedOut, qt.IsTrue)
 		c.Assert(b.Prefs().WantRunning, qt.IsFalse)
 		c.Assert(ipn.NeedsLogin, qt.Equals, b.State())
@@ -678,7 +676,7 @@ func TestStateMachine(t *testing.T) {
 		// BUG: We already called Shutdown(), no need to do it again.
 		// BUG: Way too soon for UpdateEndpoints.
 		// BUG: don't unpause because we're not logged in.
-		c.Assert([]string{"Shutdown", "New", "UpdateEndpoints", "unpause"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"Shutdown", "unpause", "New", "UpdateEndpoints", "unpause"}, qt.DeepEquals, cc.getCalls())
 
 		nn := notifies.drain(2)
 		c.Assert(cc.getCalls(), qt.HasLen, 0)
@@ -703,7 +701,7 @@ func TestStateMachine(t *testing.T) {
 	})
 	{
 		nn := notifies.drain(3)
-		c.Assert([]string{"unpause"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"unpause", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(nn[0].LoginFinished, qt.Not(qt.IsNil))
 		c.Assert(nn[1].Prefs, qt.Not(qt.IsNil))
 		c.Assert(nn[2].State, qt.Not(qt.IsNil))
@@ -743,7 +741,7 @@ func TestStateMachine(t *testing.T) {
 		//  on startup, otherwise UIs can't show the node list, login
 		//  name, etc when in state ipn.Stopped.
 		//  Arguably they shouldn't try. But they currently do.
-		c.Assert([]string{"Shutdown", "New", "UpdateEndpoints", "Login", "unpause"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"Shutdown", "unpause", "New", "UpdateEndpoints", "Login", "unpause"}, qt.DeepEquals, cc.getCalls())
 
 		nn := notifies.drain(2)
 		c.Assert(cc.getCalls(), qt.HasLen, 0)
@@ -817,7 +815,7 @@ func TestStateMachine(t *testing.T) {
 	})
 	{
 		nn := notifies.drain(3)
-		c.Assert([]string{"unpause"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"unpause", "unpause"}, qt.DeepEquals, cc.getCalls())
 		c.Assert(nn[0].LoginFinished, qt.Not(qt.IsNil))
 		c.Assert(nn[1].Prefs, qt.Not(qt.IsNil))
 		c.Assert(nn[2].State, qt.Not(qt.IsNil))
@@ -836,7 +834,7 @@ func TestStateMachine(t *testing.T) {
 	{
 		// NOTE: cc.Shutdown() is correct here, since we didn't call
 		// b.Shutdown() ourselves.
-		c.Assert([]string{"Shutdown", "New", "UpdateEndpoints", "Login"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"Shutdown", "unpause", "New", "UpdateEndpoints", "Login", "unpause"}, qt.DeepEquals, cc.getCalls())
 
 		nn := notifies.drain(1)
 		c.Assert(cc.getCalls(), qt.HasLen, 0)
@@ -855,7 +853,7 @@ func TestStateMachine(t *testing.T) {
 	})
 	{
 		nn := notifies.drain(1)
-		c.Assert([]string{"unpause"}, qt.DeepEquals, cc.getCalls())
+		c.Assert([]string{"unpause", "unpause"}, qt.DeepEquals, cc.getCalls())
 		// NOTE: No LoginFinished message since no interactive
 		// login was needed.
 		c.Assert(nn[0].State, qt.Not(qt.IsNil))

tstest/integration/integration.go

@@ -205,6 +205,13 @@ func (lc *LogCatcher) logsString() string {
 	return lc.buf.String()
 }
 
+// Reset clears the buffered logs from memory.
+func (lc *LogCatcher) Reset() {
+	lc.mu.Lock()
+	defer lc.mu.Unlock()
+	lc.buf.Reset()
+}
+
 func (lc *LogCatcher) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	var body io.Reader = r.Body
 	if r.Header.Get("Content-Encoding") == "zstd" {

tstest/integration/integration_test.go

@@ -72,29 +72,9 @@ func TestOneNodeUp_NoAuth(t *testing.T) {
 
 	d1 := n1.StartDaemon(t)
 	defer d1.Kill()
-
+	n1.AwaitResponding(t)
-	n1.AwaitListening(t)
-
-	st := n1.MustStatus(t)
-	t.Logf("Status: %s", st.BackendState)
-
-	if err := tstest.WaitFor(20*time.Second, func() error {
-		const sub = `Program starting: `
-		if !env.LogCatcher.logsContains(mem.S(sub)) {
-			return fmt.Errorf("log catcher didn't see %#q; got %s", sub, env.LogCatcher.logsString())
-		}
-		return nil
-	}); err != nil {
-		t.Error(err)
-	}
-
 	n1.MustUp()
 
-	if d, _ := time.ParseDuration(os.Getenv("TS_POST_UP_SLEEP")); d > 0 {
-		t.Logf("Sleeping for %v to give 'up' time to misbehave (https://github.com/tailscale/tailscale/issues/1840) ...", d)
-		time.Sleep(d)
-	}
-
 	t.Logf("Got IP: %v", n1.AwaitIP(t))
 	n1.AwaitRunning(t)
 
@@ -115,22 +95,7 @@ func TestStateSavedOnStart(t *testing.T) {
 
 	d1 := n1.StartDaemon(t)
 	defer d1.Kill()
-
+	n1.AwaitResponding(t)
-	n1.AwaitListening(t)
-
-	st := n1.MustStatus(t)
-	t.Logf("Status: %s", st.BackendState)
-
-	if err := tstest.WaitFor(20*time.Second, func() error {
-		const sub = `Program starting: `
-		if !env.LogCatcher.logsContains(mem.S(sub)) {
-			return fmt.Errorf("log catcher didn't see %#q; got %s", sub, env.LogCatcher.logsString())
-		}
-		return nil
-	}); err != nil {
-		t.Error(err)
-	}
-
 	n1.MustUp()
 
 	t.Logf("Got IP: %v", n1.AwaitIP(t))
@@ -346,6 +311,53 @@ func TestAddPingRequest(t *testing.T) {
 	t.Error("all ping attempts failed")
 }
 
+// Issue 2434: when "down" (WantRunning false), tailscaled shouldn't
+// be connected to control.
+func TestNoControlConnectionWhenDown(t *testing.T) {
+	t.Parallel()
+	bins := BuildTestBinaries(t)
+
+	env := newTestEnv(t, bins)
+	defer env.Close()
+
+	n1 := newTestNode(t, env)
+
+	d1 := n1.StartDaemon(t)
+	defer d1.Kill()
+	n1.AwaitResponding(t)
+
+	// Come up the first time.
+	n1.MustUp()
+	ip1 := n1.AwaitIP(t)
+	n1.AwaitRunning(t)
+
+	// Then bring it down and stop the daemon.
+	n1.MustDown()
+	d1.MustCleanShutdown(t)
+
+	env.LogCatcher.Reset()
+	d2 := n1.StartDaemon(t)
+	defer d2.Kill()
+	n1.AwaitResponding(t)
+
+	st := n1.MustStatus(t)
+	if got, want := st.BackendState, "Stopped"; got != want {
+		t.Fatalf("after restart, state = %q; want %q", got, want)
+	}
+
+	ip2 := n1.AwaitIP(t)
+	if ip1 != ip2 {
+		t.Errorf("IPs different: %q vs %q", ip1, ip2)
+	}
+
+	// The real test: verify our daemon doesn't have an HTTP request open.:
+	if n := env.Control.InServeMap(); n != 0 {
+		t.Errorf("in serve map = %d; want 0", n)
+	}
+
+	d2.MustCleanShutdown(t)
+}
+
 // testEnv contains the test environment (set of servers) used by one
 // or more nodes.
 type testEnv struct {
@@ -462,6 +474,26 @@ func (n *testNode) diskPrefs(t testing.TB) *ipn.Prefs {
 	return p
 }
 
+// AwaitResponding waits for n's tailscaled to be up enough to be
+// responding, but doesn't wait for any particular state.
+func (n *testNode) AwaitResponding(t testing.TB) {
+	t.Helper()
+	n.AwaitListening(t)
+
+	st := n.MustStatus(t)
+	t.Logf("Status: %s", st.BackendState)
+
+	if err := tstest.WaitFor(20*time.Second, func() error {
+		const sub = `Program starting: `
+		if !n.env.LogCatcher.logsContains(mem.S(sub)) {
+			return fmt.Errorf("log catcher didn't see %#q; got %s", sub, n.env.LogCatcher.logsString())
+		}
+		return nil
+	}); err != nil {
+		t.Fatal(err)
+	}
+}
+
 // addLogLineHook registers a hook f to be called on each tailscaled
 // log line output.
 func (n *testNode) addLogLineHook(f func([]byte)) {
@@ -654,6 +686,7 @@ func (n *testNode) AwaitIP(t testing.TB) netaddr.IP {
 	return ips[0]
 }
 
+// AwaitRunning waits for n to reach the IPN state "Running".
 func (n *testNode) AwaitRunning(t testing.TB) {
 	t.Helper()
 	if err := tstest.WaitFor(20*time.Second, func() error {

tstest/integration/testcontrol/testcontrol.go

@@ -51,6 +51,7 @@ type Server struct {
 	mux         *http.ServeMux
 
 	mu            sync.Mutex
+	inServeMap    int
 	cond          *sync.Cond // lazily initialized by condLocked
 	pubKey        wgkey.Key
 	privKey       wgkey.Private
@@ -509,7 +510,22 @@ func (s *Server) UpdateNode(n *tailcfg.Node) (peersToUpdate []tailcfg.NodeID) {
 	return peersToUpdate
 }
 
+func (s *Server) incrInServeMap(delta int) {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+	s.inServeMap += delta
+}
+
+// InServeMap returns the number of clients currently in a MapRequest HTTP handler.
+func (s *Server) InServeMap() int {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+	return s.inServeMap
+}
+
 func (s *Server) serveMap(w http.ResponseWriter, r *http.Request, mkey tailcfg.MachineKey) {
+	s.incrInServeMap(1)
+	defer s.incrInServeMap(-1)
 	ctx := r.Context()
 
 	req := new(tailcfg.MapRequest)