diff options
author | Martin Polden <mpolden@mpolden.no> | 2021-09-17 11:12:08 +0200 |
---|---|---|
committer | Martin Polden <mpolden@mpolden.no> | 2021-09-17 11:12:08 +0200 |
commit | b5730c4b632161ac42a4c9fca467beff3175fca6 (patch) | |
tree | a7bdd23a5b343b64cbf1f79555557002e45e7fad | |
parent | fb5d4c9b0ac504698f4df52b9b0257170b944450 (diff) |
Print logs while waiting for cloud deployment
-rw-r--r-- | client/go/cmd/deploy.go | 7 | ||||
-rw-r--r-- | client/go/cmd/helpers.go | 2 | ||||
-rw-r--r-- | client/go/vespa/target.go | 93 | ||||
-rw-r--r-- | client/go/vespa/target_test.go | 13 |
4 files changed, 97 insertions, 18 deletions
diff --git a/client/go/cmd/deploy.go b/client/go/cmd/deploy.go index 2789a74d9ac..9bf59187778 100644 --- a/client/go/cmd/deploy.go +++ b/client/go/cmd/deploy.go @@ -13,11 +13,13 @@ import ( ) const ( - zoneFlag = "zone" + zoneFlag = "zone" + logLevelFlag = "log-level" ) var ( - zoneArg string + zoneArg string + logLevelArg string ) func init() { @@ -25,6 +27,7 @@ func init() { rootCmd.AddCommand(prepareCmd) rootCmd.AddCommand(activateCmd) deployCmd.PersistentFlags().StringVarP(&zoneArg, zoneFlag, "z", "dev.aws-us-east-1c", "The zone to use for deployment") + deployCmd.PersistentFlags().StringVarP(&logLevelArg, logLevelFlag, "l", "error", `Log level for Vespa logs. Must be "error", "warning", "info" or "debug"`) } var deployCmd = &cobra.Command{ diff --git a/client/go/cmd/helpers.go b/client/go/cmd/helpers.go index a541f2d363a..3493a4b32a8 100644 --- a/client/go/cmd/helpers.go +++ b/client/go/cmd/helpers.go @@ -147,7 +147,7 @@ func getTarget() vespa.Target { if err != nil { fatalErrHint(err, "Deployment to cloud requires a certificate. Try 'vespa cert'") } - return vespa.CloudTarget(deployment, kp, apiKey) + return vespa.CloudTarget(deployment, kp, apiKey, vespa.LogOptions{Writer: stdout, Level: vespa.LogLevel(logLevelArg)}) } fatalErrHint(fmt.Errorf("Invalid target: %s", targetType), "Valid targets are 'local', 'cloud' or an URL") return nil diff --git a/client/go/vespa/target.go b/client/go/vespa/target.go index ada2b2151b2..065471d2a1e 100644 --- a/client/go/vespa/target.go +++ b/client/go/vespa/target.go @@ -4,9 +4,12 @@ import ( "crypto/tls" "encoding/json" "fmt" + "io" "io/ioutil" "net/http" "net/url" + "sort" + "strconv" "time" "github.com/vespa-engine/vespa/client/go/util" @@ -45,6 +48,12 @@ type Target interface { DiscoverServices(timeout time.Duration, runID int64) error } +// LogOptions configures the log output to produce when waiting for services. +type LogOptions struct { + Writer io.Writer + Level int +} + type customTarget struct { targetType string baseURL string @@ -74,7 +83,7 @@ func (s *Service) Wait(timeout time.Duration) (int, error) { return 0, err } okFunc := func(status int, response []byte) (bool, error) { return status/100 == 2, nil } - return wait(okFunc, req, &s.certificate, timeout) + return wait(okFunc, func() *http.Request { return req }, &s.certificate, timeout) } func (s *Service) Description() string { @@ -145,7 +154,7 @@ func (t *customTarget) DiscoverServices(timeout time.Duration, runID int64) erro converged = resp.Converged return converged, nil } - if _, err := wait(convergedFunc, req, nil, timeout); err != nil { + if _, err := wait(convergedFunc, func() *http.Request { return req }, nil, timeout); err != nil { return err } if !converged { @@ -160,6 +169,7 @@ type cloudTarget struct { deployment Deployment keyPair tls.Certificate apiKey []byte + logOptions LogOptions queryURL string documentURL string @@ -206,8 +216,15 @@ func (t *cloudTarget) waitForRun(signer *RequestSigner, runID int64, timeout tim if err != nil { return err } - if err := signer.SignRequest(req); err != nil { - return err + lastID := int64(-1) + requestFunc := func() *http.Request { + q := req.URL.Query() + q.Set("after", strconv.FormatInt(lastID, 10)) + req.URL.RawQuery = q.Encode() + if err := signer.SignRequest(req); err != nil { + panic(err) + } + return req } jobSuccessFunc := func(status int, response []byte) (bool, error) { if status/100 != 2 { @@ -217,6 +234,9 @@ func (t *cloudTarget) waitForRun(signer *RequestSigner, runID int64, timeout tim if err := json.Unmarshal(response, &resp); err != nil { return false, nil } + if t.logOptions.Writer != nil { + lastID = t.printLog(resp, lastID) + } if resp.Active { return false, nil } @@ -225,10 +245,32 @@ func (t *cloudTarget) waitForRun(signer *RequestSigner, runID int64, timeout tim } return true, nil } - _, err = wait(jobSuccessFunc, req, &t.keyPair, timeout) + _, err = wait(jobSuccessFunc, requestFunc, &t.keyPair, timeout) return err } +func (t *cloudTarget) printLog(response jobResponse, last int64) int64 { + if response.LastID == 0 { + return last + } + var msgs []logMessage + for step, stepMsgs := range response.Log { + for _, msg := range stepMsgs { + if step == "copyVespaLogs" && LogLevel(msg.Type) > t.logOptions.Level { + continue + } + msgs = append(msgs, msg) + } + } + sort.Slice(msgs, func(i, j int) bool { return msgs[i].At < msgs[j].At }) + for _, msg := range msgs { + tm := time.Unix(msg.At/1000, (msg.At%1000)*1000) + fmtTime := tm.Format("15:04:05") + fmt.Fprintf(t.logOptions.Writer, "[%s] %-7s %s\n", fmtTime, msg.Type, msg.Message) + } + return response.LastID +} + func (t *cloudTarget) discoverEndpoints(signer *RequestSigner, timeout time.Duration) error { deploymentURL := fmt.Sprintf("%s/application/v4/tenant/%s/application/%s/instance/%s/environment/%s/region/%s", t.cloudAPI, @@ -256,7 +298,7 @@ func (t *cloudTarget) discoverEndpoints(signer *RequestSigner, timeout time.Dura endpointURL = resp.Endpoints[0].URL return true, nil } - if _, err = wait(endpointFunc, req, &t.keyPair, timeout); err != nil { + if _, err = wait(endpointFunc, func() *http.Request { return req }, &t.keyPair, timeout); err != nil { return err } if endpointURL == "" { @@ -278,13 +320,28 @@ func CustomTarget(baseURL string) Target { } // CloudTarget creates a Target for the Vespa Cloud platform. -func CloudTarget(deployment Deployment, keyPair tls.Certificate, apiKey []byte) Target { +func CloudTarget(deployment Deployment, keyPair tls.Certificate, apiKey []byte, logOptions LogOptions) Target { return &cloudTarget{ cloudAPI: defaultCloudAPI, targetType: cloudTargetType, deployment: deployment, keyPair: keyPair, apiKey: apiKey, + logOptions: logOptions, + } +} + +// LogLevel returns an int representing a named log level. +func LogLevel(name string) int { + switch name { + case "error": + return 0 + case "warning": + return 1 + case "info": + return 2 + default: // everything else, e.g. debug + return 3 } } @@ -296,18 +353,28 @@ type deploymentResponse struct { Endpoints []deploymentEndpoint `json:"endpoints"` } +type serviceConvergeResponse struct { + Converged bool `json:"converged"` +} + type jobResponse struct { - Active bool `json:"active"` - Status string `json:"status"` + Active bool `json:"active"` + Status string `json:"status"` + Log map[string][]logMessage `json:"log"` + LastID int64 `json:"lastId"` } -type serviceConvergeResponse struct { - Converged bool `json:"converged"` +type logMessage struct { + At int64 `json:"at"` + Type string `json:"type"` + Message string `json:"message"` } type responseFunc func(status int, response []byte) (bool, error) -func wait(fn responseFunc, req *http.Request, certificate *tls.Certificate, timeout time.Duration) (int, error) { +type requestFunc func() *http.Request + +func wait(fn responseFunc, reqFn requestFunc, certificate *tls.Certificate, timeout time.Duration) (int, error) { if certificate != nil { util.ActiveHttpClient.UseCertificate(*certificate) } @@ -319,7 +386,7 @@ func wait(fn responseFunc, req *http.Request, certificate *tls.Certificate, time deadline := time.Now().Add(timeout) loopOnce := timeout == 0 for time.Now().Before(deadline) || loopOnce { - response, httpErr = util.HttpDo(req, 10*time.Second, "") + response, httpErr = util.HttpDo(reqFn(), 10*time.Second, "") if httpErr == nil { statusCode = response.StatusCode body, err := ioutil.ReadAll(response.Body) diff --git a/client/go/vespa/target_test.go b/client/go/vespa/target_test.go index 213b2d93cf8..f4875587593 100644 --- a/client/go/vespa/target_test.go +++ b/client/go/vespa/target_test.go @@ -1,6 +1,7 @@ package vespa import ( + "bytes" "crypto/tls" "fmt" "net/http" @@ -28,7 +29,11 @@ func (v *mockVespaApi) mockVespaHandler(w http.ResponseWriter, req *http.Request if v.deploymentConverged { response = `{"active": false, "status": "success"}` } else { - response = `{"active": true, "status": "running"}` + response = `{"active": true, "status": "running", + "lastId": 42, + "log": {"deployReal": [{"at": 1631707708431, + "type": "info", + "message": "Deploying platform version 7.465.17 and application version 1.0.2 ..."}]}}` } w.Write([]byte(response)) case "/application/v2/tenant/default/application/default/environment/prod/region/default/instance/default/serviceconverge": @@ -94,13 +99,15 @@ func TestCloudTargetWait(t *testing.T) { apiKey, err := CreateAPIKey() assert.Nil(t, err) + var logWriter bytes.Buffer target := CloudTarget( Deployment{ Application: ApplicationID{Tenant: "t1", Application: "a1", Instance: "i1"}, Zone: ZoneID{Environment: "dev", Region: "us-north-1"}, }, x509KeyPair, - apiKey) + apiKey, + LogOptions{Writer: &logWriter}) if ct, ok := target.(*cloudTarget); ok { ct.cloudAPI = srv.URL } else { @@ -120,6 +127,8 @@ func TestCloudTargetWait(t *testing.T) { assertServiceWait(t, 500, target, "query") assertServiceWait(t, 500, target, "document") + + assert.Equal(t, "[14:08:28] info Deploying platform version 7.465.17 and application version 1.0.2 ...\n", logWriter.String()) } func assertServiceURL(t *testing.T, url string, target Target, service string) { |