Skip to content

Commit

Permalink
Fix t3c report mode to be less spammy (#6220)
Browse files Browse the repository at this point in the history 
* Fix t3c report mode to be less spammy

Fixes #6201

* Fix t3c sub-app logs.

Fixes t3c sub-app logging to conform to the logger format,
so all lines are prefixed, to prevent breaking
people's log parsing.

(cherry picked from commit f394887)
  • Loading branch information
@rob05c @zrhoffman
rob05c authored and zrhoffman committed Sep 29, 2021
1 parent a8e0c29 commit 5a2eea2
Show file tree
Hide file tree
Showing 8 changed files with 159 additions and 99 deletions.
23 changes: 21 additions & 2 deletions cache-config/t3c-apply/config/config.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -239,7 +239,8 @@ func GetCfg() (Cfg, error) {
defaultClientTLSVersions := getopt.StringLong("default-client-tls-versions", 'V', "", "Comma-delimited list of default TLS versions for Delivery Services with no Parameter, e.g. --default-tls-versions='1.1,1.2,1.3'. If omitted, all versions are enabled.")
maxmindLocationPtr := getopt.StringLong("maxmind-location", 'M', "", "URL of a maxmind gzipped database file, to be installed into the trafficserver etc directory.")
verbosePtr := getopt.CounterLong("verbose", 'v', `Log verbosity. Logging is output to stderr. By default, errors are logged. To log warnings, pass '-v'. To log info, pass '-vv'. To omit error logging, see '-s'`)
silentPtr := getopt.BoolLong("silent", 's', `Silent. Errors are not logged, and the 'verbose' flag is ignored. If a fatal error occurs, the return code will be non-zero but no text will be output to stderr`)
const silentFlagName = "silent"
silentPtr := getopt.BoolLong(silentFlagName, 's', `Silent. Errors are not logged, and the 'verbose' flag is ignored. If a fatal error occurs, the return code will be non-zero but no text will be output to stderr`)

const waitForParentsFlagName = "wait-for-parents"
waitForParentsPtr := getopt.BoolLong(waitForParentsFlagName, 'W', "[true | false] do not update if parent_pending = 1 in the update json. Default is false")
Expand Down Expand Up @@ -282,6 +283,8 @@ badass sets --install-packages=true
--ignore-update-flag=true
--update-ipallow=true
report sets --report-only=true
--no-unset-update-flag=true
--silent
Note the 'syncds' settings are all the flag defaults. Hence, if no mode is set, the default is effectively 'syncds'.
Expand Down Expand Up @@ -332,6 +335,14 @@ If any of the related flags are also set, they override the mode's default behav
modeLogStrs = append(modeLogStrs, runMode.String()+" setting --"+reportOnlyFlagName+"="+"true")
*reportOnlyPtr = true
}
if !getopt.IsSet(ignoreUpdateFlagName) {
modeLogStrs = append(modeLogStrs, runMode.String()+" setting --"+ignoreUpdateFlagName+"="+"true")
*ignoreUpdateFlagPtr = true
}
if !getopt.IsSet(silentFlagName) {
modeLogStrs = append(modeLogStrs, runMode.String()+" setting --"+silentFlagName+"="+"true")
*silentPtr = true
}
}
}

Expand Down Expand Up @@ -511,9 +522,17 @@ If any of the related flags are also set, they override the mode's default behav
}

for _, str := range modeLogStrs {
str = strings.TrimSpace(str)
if str == "" {
continue
}
log.Infoln(str)
}
for msg := range toInfoLog {
for _, msg := range toInfoLog {
msg = strings.TrimSpace(msg)
if msg == "" {
continue
}
log.Infoln(msg)
}

Expand Down
8 changes: 2 additions & 6 deletions cache-config/t3c-apply/t3c-apply.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -110,7 +110,7 @@ func main() {
}
}

log.Infoln(time.Now().Format(time.UnixDate))
log.Infoln(time.Now().Format(time.RFC3339))

if !util.CheckUser(cfg) {
lock.UnlockAndExit(UserCheckError)
Expand Down Expand Up @@ -231,12 +231,8 @@ func main() {
runSysctl(cfg)
}

// update Traffic Ops
result, err := trops.UpdateTrafficOps(&syncdsUpdate)
if err != nil {
if err := trops.UpdateTrafficOps(&syncdsUpdate); err != nil {
log.Errorf("failed to update Traffic Ops: %s\n", err.Error())
} else if result {
log.Infoln("Traffic Ops has been updated.")
}

GitCommitAndExit(Success, cfg)
Expand Down
140 changes: 84 additions & 56 deletions cache-config/t3c-apply/torequest/cmd.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ import (
"errors"
"fmt"
"io/ioutil"
golog "log"
"os"
"os/exec"
"strconv"
Expand Down Expand Up @@ -81,12 +82,11 @@ func generate(cfg config.Cfg) ([]t3cutil.ATSConfigFile, error) {

generatedFiles, stdErr, code := t3cutil.DoInput(configData, config.GenerateCmd, args...)
if code != 0 {
return nil, fmt.Errorf("t3c-generate returned non-zero exit code %v stdout '%v' stderr '%v'", code, string(generatedFiles), string(stdErr))
}
if len(bytes.TrimSpace(stdErr)) > 0 {
log.Warnln(`t3c-generate stderr start` + "\n" + string(stdErr))
log.Warnln(`t3c-generate stderr end`)
logSubAppErr(`t3c-generate stdout`, generatedFiles)
logSubAppErr(`t3c-generate stderr`, stdErr)
return nil, fmt.Errorf("t3c-generate returned non-zero exit code %v, see log for output", code)
}
logSubApp(`t3c-generate`, stdErr)

preprocessedBytes, err := preprocess(cfg, configData, generatedFiles)
if err != nil {
Expand Down Expand Up @@ -156,11 +156,11 @@ func preprocess(cfg config.Cfg, configData []byte, generatedFiles []byte) ([]byt
stdOut := outbuf.Bytes()
stdErr := errbuf.Bytes()
if code != 0 {
return nil, fmt.Errorf("t3c-preprocess returned non-zero exit code %v stdout '%v' stderr '%v'", code, string(stdOut), string(stdErr))
}
if len(bytes.TrimSpace(stdErr)) > 0 {
log.Warnf("t3c-preprocess returned code 0 but stderr '%v'", string(stdErr)) // usually warnings
logSubAppErr(`t3c-preprocess stdout`, stdOut)
logSubAppErr(`t3c-preprocess stderr`, stdErr)
return nil, fmt.Errorf("t3c-preprocess returned non-zero exit code %v, see log for output", code)
}
logSubApp(`t3c-preprocess`, stdErr)
return stdOut, nil
}

Expand Down Expand Up @@ -245,39 +245,56 @@ func sendUpdate(cfg config.Cfg, updateStatus bool, revalStatus bool) error {
}
stdOut, stdErr, code := t3cutil.Do(`t3c-update`, args...)
if code != 0 {
return fmt.Errorf("t3c-update returned non-zero exit code %v stdout '%v' stderr '%v'", code, string(stdOut), string(stdErr))
}
if len(bytes.TrimSpace(stdErr)) > 0 {
log.Warnf("t3c-update returned code 0 but stderr '%v'", string(stdErr)) // usually warnings
logSubAppErr(`t3c-update stdout`, stdOut)
logSubAppErr(`t3c-update stderr`, stdErr)
return fmt.Errorf("t3c-update returned non-zero exit code %v, see log for output", code)
}
logSubApp(`t3c-update`, stdErr)
log.Infoln("t3c-update succeeded")
return nil
}

// diff calls t3c-diff to diff the given new file and the file on disk. Returns whether they're different.
// Logs the difference.
// If the file on disk doesn't exist, returns true and logs the entire file as a diff.
func diff(cfg config.Cfg, newFile []byte, fileLocation string) (bool, error) {
func diff(cfg config.Cfg, newFile []byte, fileLocation string, reportOnly bool) (bool, error) {
diffMsg := ""

stdOut, stdErr, code := t3cutil.DoInput(newFile, `t3c-diff`, `stdin`, fileLocation)
if code > 1 {
return false, fmt.Errorf("t3c-diff returned error code %v stdout '%v' stderr '%v'", code, string(stdOut), string(stdErr))
}
if len(bytes.TrimSpace(stdErr)) > 0 {
log.Warnf("t3c-diff returned non-error code %v but stderr '%v'", code, string(stdErr))
}
logSubApp(`t3c-diff`, stdErr)

if code == 0 {
log.Infof("All lines match TrOps for config file: %s\n", fileLocation)
diffMsg += fmt.Sprintf("All lines match TrOps for config file: %s\n", fileLocation)
return false, nil // 0 is only returned if there's no diff
}
// code 1 means a diff, difference text will be on stdout

stdOut = bytes.TrimSpace(stdOut) // the shell output includes a trailing newline that isn't part of the diff; remove it
lines := strings.Split(string(stdOut), "\n")
log.Infoln("file '" + fileLocation + "' changes begin")
diffMsg += "file '" + fileLocation + "' changes begin\n"
for _, line := range lines {
log.Infoln("diff: " + line)
diffMsg += "diff: " + line + "\n"
}
diffMsg += "file '" + fileLocation + "' changes end" // no trailing newline, becuase we're using log*ln, the last line will get a newline appropriately

if reportOnly {
// Create our own info logger, to log the diff.
// We can't use the logger initialized in the config package because
// we don't want to log all the other Info logs.
// But we want the standard log.Info prefix, timestamp, etc.
reportLocation := os.Stdout
goLogger := golog.New(reportLocation, log.InfoPrefix, log.InfoFlags)
for _, line := range strings.Split(diffMsg, "\n") {
log.Logln(goLogger, line)
}
} else {
for _, line := range strings.Split(diffMsg, "\n") {
log.Infoln(line)
}
}
log.Infoln("file '" + fileLocation + "' changes end")

return true, nil
}
Expand All @@ -302,22 +319,12 @@ func checkRefs(cfg config.Cfg, cfgFile []byte, filesAdding []string) error {
stdOut, stdErr, code := t3cutil.DoInput(cfgFile, `t3c`, args...)

if code != 0 {
log.Errorf(`check-refs errors start
` + string(stdOut))
log.Errorf(`check-refs errors end`)
if strings.TrimSpace(string(stdErr)) != "" {
log.Errorf(`check-refs output start
` + string(stdErr))
log.Errorf(`check-refs output end`)
}
logSubAppErr(`t3c-check-refs stdout`, stdOut)
logSubAppErr(`t3c-check-refs stderr`, stdErr)
return fmt.Errorf("%d plugins failed to verify. See log for details.", code)
}
if len(bytes.TrimSpace(stdErr)) > 0 {
log.Warnf("t3c-check-refs returned non-error code %v but stderr '%v'", code, string(stdErr))
}
if len(bytes.TrimSpace(stdOut)) > 0 {
log.Warnf("t3c-check-refs returned non-error code %v but output '%v'", code, string(stdOut))
}
logSubApp(`t3c-check-refs stdout`, stdOut)
logSubApp(`t3c-check-refs stderr`, stdErr)
return nil
}

Expand All @@ -331,21 +338,13 @@ func checkReload(pluginPackagesInstalled []string, changedConfigFiles []string)
)

if code != 0 {
log.Errorf(`t3c-check-reload errors start
` + string(stdErr))
log.Errorf(`t3c-check-reload errors end`)
if strings.TrimSpace(string(stdErr)) != "" {
log.Errorf(`t3c-check-reload output start
` + string(stdOut))
log.Errorf(`t3c-check-reload output end`)
}
logSubAppErr(`t3c-check-reload stdout`, stdOut)
logSubAppErr(`t3c-check-reload stderr`, stdErr)
return t3cutil.ServiceNeedsInvalid, fmt.Errorf("t3c-check-reload returned error code %d - see log for details.", code)
} else if strings.TrimSpace(string(stdErr)) != "" {
log.Errorf(`t3c-check-reload returned success code but nonempty stderr. determine-restart errors start
` + string(stdErr))
log.Errorf(`t3c-check-reload errors end`)

}

logSubApp(`t3c-check-reload`, stdErr)

needs := t3cutil.StrToServiceNeeds(strings.TrimSpace(string(stdOut)))
if needs == t3cutil.ServiceNeedsInvalid {
return t3cutil.ServiceNeedsInvalid, errors.New("t3c-check-reload returned unknown string '" + string(stdOut) + "'")
Expand Down Expand Up @@ -395,11 +394,13 @@ func request(cfg config.Cfg, command string) ([]byte, error) {
}
stdOut, stdErr, code := t3cutil.Do(`t3c-request`, args...)
if code != 0 {
return nil, fmt.Errorf("t3c-request returned non-zero exit code %v stdout '%v' stderr '%v'", code, string(stdOut), string(stdErr))
}
if len(bytes.TrimSpace(stdErr)) > 0 {
log.Warnf("t3c-request returned code 0 but stderr '%v'", string(stdErr)) // usually warnings
logSubAppErr(`t3c-request stdout`, stdOut)
logSubAppErr(`t3c-request stderr`, stdErr)
return nil, fmt.Errorf("t3c-request returned non-zero exit code %v, see log for output", code)
}

logSubApp(`t3c-request`, stdErr)

return stdOut, nil
}

Expand Down Expand Up @@ -459,11 +460,11 @@ func requestConfig(cfg config.Cfg) ([]byte, error) {
stdOut, stdErr, code = t3cutil.Do(`t3c`, args...)
}
if code != 0 {
return nil, fmt.Errorf("t3c-request returned non-zero exit code %v stdout '%v' stderr '%v'", code, string(stdOut), string(stdErr))
}
if len(bytes.TrimSpace(stdErr)) > 0 {
log.Warnf("t3c-request returned code 0 but stderr '%v'", string(stdErr)) // usually warnings
logSubAppErr(`t3c-request stdout`, stdOut)
logSubAppErr(`t3c-request stderr`, stdErr)
return nil, fmt.Errorf("t3c-request returned non-zero exit code %v, see log for details", code)
}
logSubApp(`t3c-request`, stdErr)

if err := ioutil.WriteFile(t3cutil.ApplyCachePath, stdOut, 0600); err != nil {
log.Errorln("writing config data to cache failed: " + err.Error())
Expand All @@ -472,6 +473,33 @@ func requestConfig(cfg config.Cfg) ([]byte, error) {
return stdOut, nil
}

func logSubApp(appName string, stdErr []byte) { logSubAppWarnOrErr(appName, stdErr, false) }
func logSubAppErr(appName string, stdErr []byte) { logSubAppWarnOrErr(appName, stdErr, true) }
func logSubAppWarnOrErr(appName string, stdErr []byte, isErr bool) {
stdErr = bytes.TrimSpace(stdErr)
if len(stdErr) == 0 {
return
}

logF := log.Warnln
logger := log.Warning
if isErr {
logF = log.Errorln
logger = log.Error
}

if logger == nil {
return
}

logF(appName + ` start`)
// write directly to the underlying logger, to avoid duplicating the prefix
for _, msg := range bytes.Split(stdErr, []byte{'\n'}) {
logger.Writer().Write([]byte(string(msg) + "\n"))
}
logF(appName + ` end`)
}

// outToErr returns stderr if logLocation is stdout, otherwise returns logLocation unchanged.
// This is a helper to avoid logging to stdout for commands whose output is on stdout.
func outToErr(logLocation string) string {
Expand Down
30 changes: 13 additions & 17 deletions cache-config/t3c-apply/torequest/torequest.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -217,7 +217,7 @@ func (r *TrafficOpsReq) checkConfigFile(cfg *ConfigFile, filesAdding []string) e
log.Infoln("Successfully verified plugins used by '" + cfg.Name + "'")
}

changeNeeded, err := diff(r.Cfg, cfg.Body, cfg.Path)
changeNeeded, err := diff(r.Cfg, cfg.Body, cfg.Path, r.Cfg.ReportOnly)
if err != nil {
return errors.New("getting diff: " + err.Error())
}
Expand Down Expand Up @@ -1012,9 +1012,7 @@ func (r *TrafficOpsReq) RevalidateWhileSleeping() (UpdateStatus, error) {
return updateStatus, errors.New("failed to start services: " + err.Error())
}

// update Traffic Ops
_, err = r.UpdateTrafficOps(&updateStatus)
if err != nil {
if err := r.UpdateTrafficOps(&updateStatus); err != nil {
log.Errorf("failed to update Traffic Ops: %s\n", err.Error())
}

Expand Down Expand Up @@ -1117,34 +1115,34 @@ func (r *TrafficOpsReq) getPluginPackagesInstalled() []string {
return installedPluginPkgs
}

func (r *TrafficOpsReq) UpdateTrafficOps(syncdsUpdate *UpdateStatus) (bool, error) {
func (r *TrafficOpsReq) UpdateTrafficOps(syncdsUpdate *UpdateStatus) error {
var updateResult bool

serverStatus, err := getUpdateStatus(r.Cfg)
if err != nil {
return false, errors.New("failed to update Traffic Ops: " + err.Error())
return errors.New("failed to update Traffic Ops: " + err.Error())
}

if *syncdsUpdate == UpdateTropsNotNeeded && (serverStatus.UpdatePending == true || serverStatus.RevalPending == true) {
updateResult = true
log.Errorln("Traffic Ops is signaling that an update is ready to be applied but, none was found! Clearing update state in Traffic Ops anyway.")
} else if *syncdsUpdate == UpdateTropsNotNeeded {
log.Errorln("Traffic Ops does not require an update at this time")
return true, nil
return nil
} else if *syncdsUpdate == UpdateTropsFailed {
log.Errorln("Traffic Ops requires an update but, applying the update locally failed. Traffic Ops is not being updated.")
return true, nil
return nil
} else if *syncdsUpdate == UpdateTropsSuccessful {
updateResult = true
log.Errorln("Traffic Ops requires an update and it was applied successfully. Clearing update state in Traffic Ops.")
}

if !updateResult {
return true, nil
return nil
}
if r.Cfg.ReportOnly {
log.Errorln("In Report mode and Traffic Ops needs updated you should probably do that manually.")
return true, nil
return nil
}

if !r.Cfg.ReportOnly && !r.Cfg.NoUnsetUpdateFlag {
Expand All @@ -1161,12 +1159,10 @@ func (r *TrafficOpsReq) UpdateTrafficOps(syncdsUpdate *UpdateStatus) (bool, erro
err = sendUpdate(r.Cfg, false, false)
}
}
if err != nil {
return errors.New("Traffic Ops Update failed: " + err.Error())
}
log.Infoln("Traffic Ops has been updated.")
}

if err != nil {
return false, errors.New("Traffic Ops Update failed: " + err.Error())
}

log.Errorln("Traffic Ops has been updated.")
return true, nil
return nil
}
1 change: 1 addition & 0 deletions cache-config/t3c-apply/util/gitutil.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -140,6 +140,7 @@ func MakeGitCommitAll(cfg config.Cfg, self bool, success bool) error {
cmd := exec.Command("git", "status", "--porcelain")
cmd.Dir = cfg.TsConfigDir
output, err := cmd.CombinedOutput()
output = bytes.TrimSpace(output)
if err != nil {
return fmt.Errorf("git status error: in config dir '%v' returned err %v msg '%v'", cfg.TsConfigDir, err, string(output))
}
Expand Down
Loading

0 comments on commit 5a2eea2

Please sign in to comment.