|
| 1 | +package app |
| 2 | + |
| 3 | +import ( |
| 4 | + "context" |
| 5 | + "fmt" |
| 6 | + "os/exec" |
| 7 | + "strconv" |
| 8 | + "time" |
| 9 | + |
| 10 | + "github.com/yandex/mysync/internal/dcs" |
| 11 | + "github.com/yandex/mysync/internal/util" |
| 12 | +) |
| 13 | + |
| 14 | +// names of tracked timings |
| 15 | +const ( |
| 16 | + timingDowntime = "downtime" |
| 17 | + timingFailover = "failover" |
| 18 | + timingSwitchover = "switchover" |
| 19 | +) |
| 20 | + |
| 21 | +func (app *App) timingPath(name string) string { |
| 22 | + return dcs.JoinPath(pathTimings, name) |
| 23 | +} |
| 24 | + |
| 25 | +// getTimingStart returns stored start time and whether it exists |
| 26 | +func (app *App) getTimingStart(name string) (time.Time, bool) { |
| 27 | + var ts time.Time |
| 28 | + if err := app.dcs.Get(app.timingPath(name), &ts); err != nil { |
| 29 | + return time.Time{}, false |
| 30 | + } |
| 31 | + return ts, true |
| 32 | +} |
| 33 | + |
| 34 | +// startTiming stores timing start in dcs (zero ts means now) |
| 35 | +func (app *App) startTiming(name string, ts time.Time) { |
| 36 | + if ts.IsZero() { |
| 37 | + ts = time.Now() |
| 38 | + } |
| 39 | + if err := app.dcs.Set(app.timingPath(name), ts); err != nil { |
| 40 | + app.logger.Warn().Err(err).Msgf("failed to start timing %s", name) |
| 41 | + } |
| 42 | +} |
| 43 | + |
| 44 | +func (app *App) clearTiming(name string) { |
| 45 | + if err := app.dcs.Delete(app.timingPath(name)); err != nil { |
| 46 | + app.logger.Warn().Err(err).Msgf("failed to clear timing %s", name) |
| 47 | + } |
| 48 | +} |
| 49 | + |
| 50 | +// stopTiming logs elapsed time since start and clears it |
| 51 | +func (app *App) stopTiming(name string) { |
| 52 | + now := time.Now() |
| 53 | + start, ok := app.getTimingStart(name) |
| 54 | + if !ok { |
| 55 | + return |
| 56 | + } |
| 57 | + app.clearTiming(name) |
| 58 | + app.logTiming(name, now.Sub(start)) |
| 59 | +} |
| 60 | + |
| 61 | +// logSwitchoverFailure records time spent on a failed switchover as a negative value. |
| 62 | +// Marker-guarded so it is logged once, and only when the switchover actually started. |
| 63 | +func (app *App) logSwitchoverFailure(sw *Switchover) { |
| 64 | + now := time.Now() |
| 65 | + if sw.MasterTransition != SwitchoverTransition { |
| 66 | + return |
| 67 | + } |
| 68 | + start, ok := app.getTimingStart(timingSwitchover) |
| 69 | + if !ok { |
| 70 | + return |
| 71 | + } |
| 72 | + app.clearTiming(timingSwitchover) |
| 73 | + app.clearTiming(timingDowntime) |
| 74 | + since := sw.InitiatedAt |
| 75 | + if since.IsZero() { |
| 76 | + since = start |
| 77 | + } |
| 78 | + app.logTiming(timingSwitchover+"_failure", -now.Sub(since)) |
| 79 | +} |
| 80 | + |
| 81 | +// logTiming runs the configured log_timing command with name and elapsed seconds |
| 82 | +func (app *App) logTiming(name string, d time.Duration) { |
| 83 | + command, ok := app.config.Commands["log_timing"] |
| 84 | + if !ok || command == "" { |
| 85 | + return |
| 86 | + } |
| 87 | + command = fmt.Sprintf(command, name, strconv.FormatFloat(d.Seconds(), 'f', 3, 64)) |
| 88 | + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) |
| 89 | + defer cancel() |
| 90 | + shell := util.GetEnvVariable("SHELL", "sh") |
| 91 | + if err := exec.CommandContext(ctx, shell, "-c", command).Run(); err != nil { |
| 92 | + app.logger.Warn().Err(err).Msgf("failed to execute log_timing command for %s", name) |
| 93 | + } |
| 94 | +} |
0 commit comments