diff --git a/ipn/ipnlocal/local.go b/ipn/ipnlocal/local.go index 6b74823d2..7b4217e3b 100644 --- a/ipn/ipnlocal/local.go +++ b/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 - - networkUp := ifst.AnyInterfaceUp() - if b.cc != nil { - go b.cc.SetPaused((b.state == ipn.Stopped && b.netMap != nil) || !networkUp) - } + b.maybePauseControlClientLocked() // 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) diff --git a/ipn/ipnlocal/state_test.go b/ipn/ipnlocal/state_test.go index 56f8d360a..ee0fee7a7 100644 --- a/ipn/ipnlocal/state_test.go +++ b/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.HasLen, 0) + c.Assert(cc.getCalls(), qt.DeepEquals, []string{"unpause", "unpause"}) 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.HasLen, 0) + c.Assert(cc.getCalls(), qt.DeepEquals, []string{"unpause", "unpause"}) 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)) diff --git a/tstest/integration/integration.go b/tstest/integration/integration.go index 23ff9c935..442a0d32e 100644 --- a/tstest/integration/integration.go +++ b/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" { diff --git a/tstest/integration/integration_test.go b/tstest/integration/integration_test.go index 11a2f2b5a..39c391fb4 100644 --- a/tstest/integration/integration_test.go +++ b/tstest/integration/integration_test.go @@ -72,29 +72,9 @@ func TestOneNodeUp_NoAuth(t *testing.T) { d1 := n1.StartDaemon(t) defer d1.Kill() - - 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.AwaitResponding(t) 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.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.AwaitResponding(t) 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 { diff --git a/tstest/integration/testcontrol/testcontrol.go b/tstest/integration/testcontrol/testcontrol.go index f27706b5c..7f6792f3d 100644 --- a/tstest/integration/testcontrol/testcontrol.go +++ b/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)