From 682bebd16593bc9ef1ed41a6d0fc6511d3689819 Mon Sep 17 00:00:00 2001 From: Andrew Lytvynov Date: Fri, 8 Sep 2023 14:26:55 -0700 Subject: [PATCH] ipn/ipnlocal: add logging and locking to c2n /update (#9290) Log some progress info to make updates more debuggable. Also, track whether an active update is already started and return an error if a concurrent update is attempted. Some planned future PRs: * add JSON output to `tailscale update` * use JSON output from `tailscale update` to provide a more detailed status of in-progress update (stage, download progress, etc) Updates #6907 Signed-off-by: Andrew Lytvynov Signed-off-by: Alex Paguis --- clientupdate/clientupdate.go | 4 +- ipn/ipnlocal/c2n.go | 118 +++++++++++++++++++++++++---------- ipn/ipnlocal/local.go | 6 ++ tailcfg/c2ntypes.go | 2 +- 4 files changed, 95 insertions(+), 35 deletions(-) diff --git a/clientupdate/clientupdate.go b/clientupdate/clientupdate.go index a6dc731c74f57..9d3e14326a173 100644 --- a/clientupdate/clientupdate.go +++ b/clientupdate/clientupdate.go @@ -128,8 +128,8 @@ func NewUpdater(args Arguments) (*Updater, error) { return nil, err } } - if args.PkgsAddr == "" { - args.PkgsAddr = "https://pkgs.tailscale.com" + if up.Arguments.PkgsAddr == "" { + up.Arguments.PkgsAddr = "https://pkgs.tailscale.com" } return &up, nil } diff --git a/ipn/ipnlocal/c2n.go b/ipn/ipnlocal/c2n.go index 4408f4316eba7..cae75df963827 100644 --- a/ipn/ipnlocal/c2n.go +++ b/ipn/ipnlocal/c2n.go @@ -4,6 +4,7 @@ package ipnlocal import ( + "bytes" "encoding/json" "errors" "fmt" @@ -14,6 +15,7 @@ import ( "path/filepath" "runtime" "strconv" + "strings" "time" "tailscale.com/clientupdate" @@ -38,7 +40,15 @@ func (b *LocalBackend) handleC2N(w http.ResponseWriter, r *http.Request) { body, _ := io.ReadAll(r.Body) w.Write(body) case "/update": - b.handleC2NUpdate(w, r) + switch r.Method { + case http.MethodGet: + b.handleC2NUpdateGet(w, r) + case http.MethodPost: + b.handleC2NUpdatePost(w, r) + default: + http.Error(w, "bad method", http.StatusMethodNotAllowed) + return + } case "/logtail/flush": if r.Method != "POST" { http.Error(w, "bad method", http.StatusMethodNotAllowed) @@ -111,37 +121,27 @@ func (b *LocalBackend) handleC2N(w http.ResponseWriter, r *http.Request) { } } -func (b *LocalBackend) handleC2NUpdate(w http.ResponseWriter, r *http.Request) { - // TODO(bradfitz): add some sort of semaphore that prevents two concurrent - // updates, or if one happened in the past 5 minutes, or something. +func (b *LocalBackend) handleC2NUpdateGet(w http.ResponseWriter, r *http.Request) { + b.logf("c2n: GET /update received") - // GET returns the current status, and POST actually begins an update. - if r.Method != "GET" && r.Method != "POST" { - http.Error(w, "bad method", http.StatusMethodNotAllowed) - return - } + res := b.newC2NUpdateResponse() + res.Started = b.c2nUpdateStarted() - // If NewUpdater does not return an error, we can update the installation. - // Exception: When version.IsMacSysExt returns true, we don't support that - // yet. TODO(cpalmer, #6995): Implement it. - // - // Note that we create the Updater solely to check for errors; we do not - // invoke it here. For this purpose, it is ok to pass it a zero Arguments. - prefs := b.Prefs().AutoUpdate() - _, err := clientupdate.NewUpdater(clientupdate.Arguments{}) - res := tailcfg.C2NUpdateResponse{ - Enabled: envknob.AllowsRemoteUpdate() || prefs.Apply, - Supported: err == nil && !version.IsMacSysExt(), - } + w.Header().Set("Content-Type", "application/json") + json.NewEncoder(w).Encode(res) +} +func (b *LocalBackend) handleC2NUpdatePost(w http.ResponseWriter, r *http.Request) { + b.logf("c2n: POST /update received") + res := b.newC2NUpdateResponse() defer func() { + if res.Err != "" { + b.logf("c2n: POST /update failed: %s", res.Err) + } w.Header().Set("Content-Type", "application/json") json.NewEncoder(w).Encode(res) }() - if r.Method == "GET" { - return - } if !res.Enabled { res.Err = "not enabled" return @@ -151,6 +151,18 @@ func (b *LocalBackend) handleC2NUpdate(w http.ResponseWriter, r *http.Request) { return } + // Check if update was already started, and mark as started. + if !b.trySetC2NUpdateStarted() { + res.Err = "update already started" + return + } + defer func() { + // Clear the started flag if something failed. + if res.Err != "" { + b.setC2NUpdateStarted(false) + } + }() + cmdTS, err := findCmdTailscale() if err != nil { res.Err = fmt.Sprintf("failed to find cmd/tailscale binary: %v", err) @@ -172,22 +184,64 @@ func (b *LocalBackend) handleC2NUpdate(w http.ResponseWriter, r *http.Request) { res.Err = "cmd/tailscale version mismatch" return } + cmd := exec.Command(cmdTS, "update", "--yes") + buf := new(bytes.Buffer) + cmd.Stdout = buf + cmd.Stderr = buf + b.logf("c2n: running %q", strings.Join(cmd.Args, " ")) if err := cmd.Start(); err != nil { res.Err = fmt.Sprintf("failed to start cmd/tailscale update: %v", err) return } res.Started = true - // TODO(bradfitz,andrew): There might be a race condition here on Windows: - // * We start the update process. - // * tailscale.exe copies itself and kicks off the update process - // * msiexec stops this process during the update before the selfCopy exits(?) - // * This doesn't return because the process is dead. + // Run update asynchronously and respond that it started. + go func() { + if err := cmd.Wait(); err != nil { + b.logf("c2n: update command failed: %v, output: %s", err, buf) + } else { + b.logf("c2n: update complete") + } + b.setC2NUpdateStarted(false) + }() +} + +func (b *LocalBackend) newC2NUpdateResponse() tailcfg.C2NUpdateResponse { + // If NewUpdater does not return an error, we can update the installation. + // Exception: When version.IsMacSysExt returns true, we don't support that + // yet. TODO(cpalmer, #6995): Implement it. // - // This seems fairly unlikely, but worth checking. - defer cmd.Wait() - return + // Note that we create the Updater solely to check for errors; we do not + // invoke it here. For this purpose, it is ok to pass it a zero Arguments. + prefs := b.Prefs().AutoUpdate() + _, err := clientupdate.NewUpdater(clientupdate.Arguments{}) + return tailcfg.C2NUpdateResponse{ + Enabled: envknob.AllowsRemoteUpdate() || prefs.Apply, + Supported: err == nil && !version.IsMacSysExt(), + } +} + +func (b *LocalBackend) c2nUpdateStarted() bool { + b.mu.Lock() + defer b.mu.Unlock() + return b.c2nUpdateStatus.started +} + +func (b *LocalBackend) setC2NUpdateStarted(v bool) { + b.mu.Lock() + defer b.mu.Unlock() + b.c2nUpdateStatus.started = v +} + +func (b *LocalBackend) trySetC2NUpdateStarted() bool { + b.mu.Lock() + defer b.mu.Unlock() + if b.c2nUpdateStatus.started { + return false + } + b.c2nUpdateStatus.started = true + return true } // findCmdTailscale looks for the cmd/tailscale that corresponds to the diff --git a/ipn/ipnlocal/local.go b/ipn/ipnlocal/local.go index 65a167f2ce8fa..13f88db04d17a 100644 --- a/ipn/ipnlocal/local.go +++ b/ipn/ipnlocal/local.go @@ -240,6 +240,8 @@ type LocalBackend struct { directFileRoot string directFileDoFinalRename bool // false on macOS, true on several NAS platforms componentLogUntil map[string]componentLogState + // c2nUpdateStatus is the status of c2n-triggered client update. + c2nUpdateStatus updateStatus // ServeConfig fields. (also guarded by mu) lastServeConfJSON mem.RO // last JSON that was parsed into serveConfig @@ -268,6 +270,10 @@ type LocalBackend struct { clock tstime.Clock } +type updateStatus struct { + started bool +} + // clientGen is a func that creates a control plane client. // It's the type used by LocalBackend.SetControlClientGetterForTesting. type clientGen func(controlclient.Options) (controlclient.Client, error) diff --git a/tailcfg/c2ntypes.go b/tailcfg/c2ntypes.go index 1083973786e30..44f3ac70c085c 100644 --- a/tailcfg/c2ntypes.go +++ b/tailcfg/c2ntypes.go @@ -39,7 +39,7 @@ type C2NSSHUsernamesResponse struct { // its Tailscale installation. type C2NUpdateResponse struct { // Err is the error message, if any. - Err string + Err string `json:",omitempty"` // Enabled indicates whether the user has opted in to updates triggered from // control.