github.com/hugh712/snapd@v0.0.0-20200910133618-1a99902bd583/overlord/snapstate/autorefresh.go (about)

     1  // -*- Mode: Go; indent-tabs-mode: t -*-
     2  
     3  /*
     4   * Copyright (C) 2017-2020 Canonical Ltd
     5   *
     6   * This program is free software: you can redistribute it and/or modify
     7   * it under the terms of the GNU General Public License version 3 as
     8   * published by the Free Software Foundation.
     9   *
    10   * This program is distributed in the hope that it will be useful,
    11   * but WITHOUT ANY WARRANTY; without even the implied warranty of
    12   * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
    13   * GNU General Public License for more details.
    14   *
    15   * You should have received a copy of the GNU General Public License
    16   * along with this program.  If not, see <http://www.gnu.org/licenses/>.
    17   *
    18   */
    19  
    20  package snapstate
    21  
    22  import (
    23  	"fmt"
    24  	"os"
    25  	"time"
    26  
    27  	"github.com/snapcore/snapd/httputil"
    28  	"github.com/snapcore/snapd/i18n"
    29  	"github.com/snapcore/snapd/logger"
    30  	"github.com/snapcore/snapd/overlord/auth"
    31  	"github.com/snapcore/snapd/overlord/configstate/config"
    32  	"github.com/snapcore/snapd/overlord/state"
    33  	"github.com/snapcore/snapd/release"
    34  	"github.com/snapcore/snapd/snap"
    35  	"github.com/snapcore/snapd/strutil"
    36  	"github.com/snapcore/snapd/timeutil"
    37  	"github.com/snapcore/snapd/timings"
    38  )
    39  
    40  // the default refresh pattern
    41  const defaultRefreshSchedule = "00:00~24:00/4"
    42  
    43  // cannot keep without refreshing for more than maxPostponement
    44  const maxPostponement = 60 * 24 * time.Hour
    45  
    46  // cannot inhibit refreshes for more than maxInhibition
    47  const maxInhibition = 7 * 24 * time.Hour
    48  
    49  // hooks setup by devicestate
    50  var (
    51  	CanAutoRefresh        func(st *state.State) (bool, error)
    52  	CanManageRefreshes    func(st *state.State) bool
    53  	IsOnMeteredConnection func() (bool, error)
    54  )
    55  
    56  // refreshRetryDelay specified the minimum time to retry failed refreshes
    57  var refreshRetryDelay = 20 * time.Minute
    58  
    59  // autoRefresh will ensure that snaps are refreshed automatically
    60  // according to the refresh schedule.
    61  type autoRefresh struct {
    62  	state *state.State
    63  
    64  	lastRefreshSchedule string
    65  	nextRefresh         time.Time
    66  	lastRefreshAttempt  time.Time
    67  	managedDeniedLogged bool
    68  }
    69  
    70  func newAutoRefresh(st *state.State) *autoRefresh {
    71  	return &autoRefresh{
    72  		state: st,
    73  	}
    74  }
    75  
    76  // RefreshSchedule will return a user visible string with the current schedule
    77  // for the automatic refreshes and a flag indicating whether the schedule is a
    78  // legacy one.
    79  func (m *autoRefresh) RefreshSchedule() (schedule string, legacy bool, err error) {
    80  	_, schedule, legacy, err = m.refreshScheduleWithDefaultsFallback()
    81  	return schedule, legacy, err
    82  }
    83  
    84  // NextRefresh returns when the next automatic refresh will happen.
    85  func (m *autoRefresh) NextRefresh() time.Time {
    86  	return m.nextRefresh
    87  }
    88  
    89  // LastRefresh returns when the last refresh happened.
    90  func (m *autoRefresh) LastRefresh() (time.Time, error) {
    91  	return getTime(m.state, "last-refresh")
    92  }
    93  
    94  // EffectiveRefreshHold returns the time until to which refreshes are
    95  // held if refresh.hold configuration is set and accounting for the
    96  // max postponement since the last refresh.
    97  func (m *autoRefresh) EffectiveRefreshHold() (time.Time, error) {
    98  	var holdTime time.Time
    99  
   100  	tr := config.NewTransaction(m.state)
   101  	err := tr.Get("core", "refresh.hold", &holdTime)
   102  	if err != nil && !config.IsNoOption(err) {
   103  		return time.Time{}, err
   104  	}
   105  
   106  	// cannot hold beyond last-refresh + max-postponement
   107  	lastRefresh, err := m.LastRefresh()
   108  	if err != nil {
   109  		return time.Time{}, err
   110  	}
   111  	if lastRefresh.IsZero() {
   112  		seedTime, err := getTime(m.state, "seed-time")
   113  		if err != nil {
   114  			return time.Time{}, err
   115  		}
   116  		if seedTime.IsZero() {
   117  			// no reference to know whether holding is reasonable
   118  			return time.Time{}, nil
   119  		}
   120  		lastRefresh = seedTime
   121  	}
   122  
   123  	limitTime := lastRefresh.Add(maxPostponement)
   124  	if holdTime.After(limitTime) {
   125  		return limitTime, nil
   126  	}
   127  
   128  	return holdTime, nil
   129  }
   130  
   131  // clearRefreshHold clears refresh.hold configuration.
   132  func (m *autoRefresh) clearRefreshHold() {
   133  	tr := config.NewTransaction(m.state)
   134  	tr.Set("core", "refresh.hold", nil)
   135  	tr.Commit()
   136  }
   137  
   138  // AtSeed configures refresh policies at end of seeding.
   139  func (m *autoRefresh) AtSeed() error {
   140  	// on classic hold refreshes for 2h after seeding
   141  	if release.OnClassic {
   142  		var t1 time.Time
   143  		tr := config.NewTransaction(m.state)
   144  		err := tr.Get("core", "refresh.hold", &t1)
   145  		if !config.IsNoOption(err) {
   146  			// already set or error
   147  			return err
   148  		}
   149  		// TODO: have a policy that if the snapd exe itself
   150  		// is older than X weeks/months we skip the holding?
   151  		now := time.Now().UTC()
   152  		tr.Set("core", "refresh.hold", now.Add(2*time.Hour))
   153  		tr.Commit()
   154  		m.nextRefresh = now
   155  	}
   156  	return nil
   157  }
   158  
   159  func canRefreshOnMeteredConnection(st *state.State) (bool, error) {
   160  	tr := config.NewTransaction(st)
   161  	var onMetered string
   162  	err := tr.GetMaybe("core", "refresh.metered", &onMetered)
   163  	if err != nil && err != state.ErrNoState {
   164  		return false, err
   165  	}
   166  
   167  	return onMetered != "hold", nil
   168  }
   169  
   170  func (m *autoRefresh) canRefreshRespectingMetered(now, lastRefresh time.Time) (can bool, err error) {
   171  	can, err = canRefreshOnMeteredConnection(m.state)
   172  	if err != nil {
   173  		return false, err
   174  	}
   175  	if can {
   176  		return true, nil
   177  	}
   178  
   179  	// ignore any errors that occurred while checking if we are on a metered
   180  	// connection
   181  	metered, _ := IsOnMeteredConnection()
   182  	if !metered {
   183  		return true, nil
   184  	}
   185  
   186  	if now.Sub(lastRefresh) >= maxPostponement {
   187  		// TODO use warnings when the infra becomes available
   188  		logger.Noticef("Auto refresh disabled while on metered connections, but pending for too long (%d days). Trying to refresh now.", int(maxPostponement.Hours()/24))
   189  		return true, nil
   190  	}
   191  
   192  	logger.Debugf("Auto refresh disabled on metered connections")
   193  
   194  	return false, nil
   195  }
   196  
   197  // Ensure ensures that we refresh all installed snaps periodically
   198  func (m *autoRefresh) Ensure() error {
   199  	m.state.Lock()
   200  	defer m.state.Unlock()
   201  
   202  	// see if it even makes sense to try to refresh
   203  	if CanAutoRefresh == nil {
   204  		return nil
   205  	}
   206  	if ok, err := CanAutoRefresh(m.state); err != nil || !ok {
   207  		return err
   208  	}
   209  
   210  	// get lastRefresh and schedule
   211  	lastRefresh, err := m.LastRefresh()
   212  	if err != nil {
   213  		return err
   214  	}
   215  
   216  	refreshSchedule, refreshScheduleStr, _, err := m.refreshScheduleWithDefaultsFallback()
   217  	if err != nil {
   218  		return err
   219  	}
   220  	if len(refreshSchedule) == 0 {
   221  		m.nextRefresh = time.Time{}
   222  		return nil
   223  	}
   224  	// we already have a refresh time, check if we got a new config
   225  	if !m.nextRefresh.IsZero() {
   226  		if m.lastRefreshSchedule != refreshScheduleStr {
   227  			// the refresh schedule has changed
   228  			logger.Debugf("Refresh timer changed.")
   229  			m.nextRefresh = time.Time{}
   230  		}
   231  	}
   232  	m.lastRefreshSchedule = refreshScheduleStr
   233  
   234  	// ensure nothing is in flight already
   235  	if autoRefreshInFlight(m.state) {
   236  		return nil
   237  	}
   238  
   239  	now := time.Now()
   240  	// compute next refresh attempt time (if needed)
   241  	if m.nextRefresh.IsZero() {
   242  		// store attempts in memory so that we can backoff
   243  		if !lastRefresh.IsZero() {
   244  			delta := timeutil.Next(refreshSchedule, lastRefresh, maxPostponement)
   245  			now = time.Now()
   246  			m.nextRefresh = now.Add(delta)
   247  		} else {
   248  			// make sure either seed-time or last-refresh
   249  			// are set for hold code below
   250  			m.ensureLastRefreshAnchor()
   251  			// immediate
   252  			m.nextRefresh = now
   253  		}
   254  		logger.Debugf("Next refresh scheduled for %s.", m.nextRefresh.Format(time.RFC3339))
   255  	}
   256  
   257  	// should we hold back refreshes?
   258  	holdTime, err := m.EffectiveRefreshHold()
   259  	if err != nil {
   260  		return err
   261  	}
   262  	if holdTime.After(now) {
   263  		return nil
   264  	}
   265  	if !holdTime.IsZero() {
   266  		// expired hold case
   267  		m.clearRefreshHold()
   268  		if m.nextRefresh.Before(holdTime) {
   269  			// next refresh is obsolete, compute the next one
   270  			delta := timeutil.Next(refreshSchedule, holdTime, maxPostponement)
   271  			now = time.Now()
   272  			m.nextRefresh = now.Add(delta)
   273  		}
   274  	}
   275  
   276  	// do refresh attempt (if needed)
   277  	if !m.nextRefresh.After(now) {
   278  		var can bool
   279  		can, err = m.canRefreshRespectingMetered(now, lastRefresh)
   280  		if err != nil {
   281  			return err
   282  		}
   283  		if !can {
   284  			// clear nextRefresh so that another refresh time is calculated
   285  			m.nextRefresh = time.Time{}
   286  			return nil
   287  		}
   288  
   289  		// Check that we have reasonable delays between attempts.
   290  		// If the store is under stress we need to make sure we do not
   291  		// hammer it too often
   292  		if !m.lastRefreshAttempt.IsZero() && m.lastRefreshAttempt.Add(refreshRetryDelay).After(time.Now()) {
   293  			return nil
   294  		}
   295  
   296  		err = m.launchAutoRefresh()
   297  		if _, ok := err.(*httputil.PerstistentNetworkError); !ok {
   298  			m.nextRefresh = time.Time{}
   299  		} // else - refresh will be retried after refreshRetryDelay
   300  	}
   301  
   302  	return err
   303  }
   304  
   305  func (m *autoRefresh) ensureLastRefreshAnchor() {
   306  	seedTime, _ := getTime(m.state, "seed-time")
   307  	if !seedTime.IsZero() {
   308  		return
   309  	}
   310  
   311  	// last core refresh
   312  	coreRefreshDate := snap.InstallDate("core")
   313  	if !coreRefreshDate.IsZero() {
   314  		m.state.Set("last-refresh", coreRefreshDate)
   315  		return
   316  	}
   317  
   318  	// fallback to executable time
   319  	st, err := os.Stat("/proc/self/exe")
   320  	if err == nil {
   321  		m.state.Set("last-refresh", st.ModTime())
   322  		return
   323  	}
   324  }
   325  
   326  // refreshScheduleWithDefaultsFallback returns the current refresh schedule
   327  // and refresh string. When an invalid refresh schedule is set by the user
   328  // the refresh schedule is automatically reset to the default.
   329  //
   330  // TODO: we can remove the refreshSchedule reset because we have validation
   331  //       of the schedule now.
   332  func (m *autoRefresh) refreshScheduleWithDefaultsFallback() (ts []*timeutil.Schedule, scheduleAsStr string, legacy bool, err error) {
   333  	managed, requested, legacy := refreshScheduleManaged(m.state)
   334  	if managed {
   335  		if m.lastRefreshSchedule != "managed" {
   336  			logger.Noticef("refresh is managed via the snapd-control interface")
   337  			m.lastRefreshSchedule = "managed"
   338  		}
   339  		m.managedDeniedLogged = false
   340  		return nil, "managed", legacy, nil
   341  	} else if requested {
   342  		// managed refresh schedule was denied
   343  		if !m.managedDeniedLogged {
   344  			logger.Noticef("managed refresh schedule denied, no properly configured snapd-control")
   345  			m.managedDeniedLogged = true
   346  		}
   347  		// fallback to default schedule
   348  		return refreshScheduleDefault()
   349  	} else {
   350  		m.managedDeniedLogged = false
   351  	}
   352  
   353  	tr := config.NewTransaction(m.state)
   354  	// try the new refresh.timer config option first
   355  	err = tr.Get("core", "refresh.timer", &scheduleAsStr)
   356  	if err != nil && !config.IsNoOption(err) {
   357  		return nil, "", false, err
   358  	}
   359  	if scheduleAsStr != "" {
   360  		ts, err = timeutil.ParseSchedule(scheduleAsStr)
   361  		if err != nil {
   362  			logger.Noticef("cannot use refresh.timer configuration: %s", err)
   363  			return refreshScheduleDefault()
   364  		}
   365  		return ts, scheduleAsStr, false, nil
   366  	}
   367  
   368  	// fallback to legacy refresh.schedule setting when the new
   369  	// config option is not set
   370  	err = tr.Get("core", "refresh.schedule", &scheduleAsStr)
   371  	if err != nil && !config.IsNoOption(err) {
   372  		return nil, "", false, err
   373  	}
   374  	if scheduleAsStr != "" {
   375  		ts, err = timeutil.ParseLegacySchedule(scheduleAsStr)
   376  		if err != nil {
   377  			logger.Noticef("cannot use refresh.schedule configuration: %s", err)
   378  			return refreshScheduleDefault()
   379  		}
   380  		return ts, scheduleAsStr, true, nil
   381  	}
   382  
   383  	return refreshScheduleDefault()
   384  }
   385  
   386  // launchAutoRefresh creates the auto-refresh taskset and a change for it.
   387  func (m *autoRefresh) launchAutoRefresh() error {
   388  	perfTimings := timings.New(map[string]string{"ensure": "auto-refresh"})
   389  	tm := perfTimings.StartSpan("auto-refresh", "query store and setup auto-refresh change")
   390  	defer func() {
   391  		tm.Stop()
   392  		perfTimings.Save(m.state)
   393  	}()
   394  
   395  	m.lastRefreshAttempt = time.Now()
   396  	updated, tasksets, err := AutoRefresh(auth.EnsureContextTODO(), m.state)
   397  	if _, ok := err.(*httputil.PerstistentNetworkError); ok {
   398  		logger.Noticef("Cannot prepare auto-refresh change due to a permanent network error: %s", err)
   399  		return err
   400  	}
   401  	m.state.Set("last-refresh", time.Now())
   402  	if err != nil {
   403  		logger.Noticef("Cannot prepare auto-refresh change: %s", err)
   404  		return err
   405  	}
   406  
   407  	var msg string
   408  	switch len(updated) {
   409  	case 0:
   410  		logger.Noticef(i18n.G("auto-refresh: all snaps are up-to-date"))
   411  		return nil
   412  	case 1:
   413  		msg = fmt.Sprintf(i18n.G("Auto-refresh snap %q"), updated[0])
   414  	case 2, 3:
   415  		quoted := strutil.Quoted(updated)
   416  		// TRANSLATORS: the %s is a comma-separated list of quoted snap names
   417  		msg = fmt.Sprintf(i18n.G("Auto-refresh snaps %s"), quoted)
   418  	default:
   419  		msg = fmt.Sprintf(i18n.G("Auto-refresh %d snaps"), len(updated))
   420  	}
   421  
   422  	chg := m.state.NewChange("auto-refresh", msg)
   423  	for _, ts := range tasksets {
   424  		chg.AddAll(ts)
   425  	}
   426  	chg.Set("snap-names", updated)
   427  	chg.Set("api-data", map[string]interface{}{"snap-names": updated})
   428  	state.TagTimingsWithChange(perfTimings, chg)
   429  
   430  	return nil
   431  }
   432  
   433  func refreshScheduleDefault() (ts []*timeutil.Schedule, scheduleStr string, legacy bool, err error) {
   434  	refreshSchedule, err := timeutil.ParseSchedule(defaultRefreshSchedule)
   435  	if err != nil {
   436  		panic(fmt.Sprintf("defaultRefreshSchedule cannot be parsed: %s", err))
   437  	}
   438  
   439  	return refreshSchedule, defaultRefreshSchedule, false, nil
   440  }
   441  
   442  func autoRefreshInFlight(st *state.State) bool {
   443  	for _, chg := range st.Changes() {
   444  		if chg.Kind() == "auto-refresh" && !chg.Status().Ready() {
   445  			return true
   446  		}
   447  	}
   448  	return false
   449  }
   450  
   451  // refreshScheduleManaged returns true if the refresh schedule of the
   452  // device is managed by an external snap
   453  func refreshScheduleManaged(st *state.State) (managed, requested, legacy bool) {
   454  	var confStr string
   455  
   456  	// this will only be "nil" if running in tests
   457  	if CanManageRefreshes == nil {
   458  		return false, false, legacy
   459  	}
   460  
   461  	// check new style timer first
   462  	tr := config.NewTransaction(st)
   463  	err := tr.Get("core", "refresh.timer", &confStr)
   464  	if err != nil && !config.IsNoOption(err) {
   465  		return false, false, legacy
   466  	}
   467  	// if not set, fallback to refresh.schedule
   468  	if confStr == "" {
   469  		if err := tr.Get("core", "refresh.schedule", &confStr); err != nil {
   470  			return false, false, legacy
   471  		}
   472  		legacy = true
   473  	}
   474  
   475  	if confStr != "managed" {
   476  		return false, false, legacy
   477  	}
   478  
   479  	return CanManageRefreshes(st), true, legacy
   480  }
   481  
   482  // getTime retrieves a time from a state value.
   483  func getTime(st *state.State, timeKey string) (time.Time, error) {
   484  	var t1 time.Time
   485  	err := st.Get(timeKey, &t1)
   486  	if err != nil && err != state.ErrNoState {
   487  		return time.Time{}, err
   488  	}
   489  	return t1, nil
   490  }
   491  
   492  // inhibitRefresh returns an error if refresh is inhibited by running apps.
   493  //
   494  // Internally the snap state is updated to remember when the inhibition first
   495  // took place. Apps can inhibit refreshes for up to "maxInhibition", beyond
   496  // that period the refresh will go ahead despite application activity.
   497  func inhibitRefresh(st *state.State, snapst *SnapState, info *snap.Info, checker func(*snap.Info) error) error {
   498  	if err := checker(info); err != nil {
   499  		days := int(maxInhibition.Truncate(time.Hour).Hours() / 24)
   500  		now := time.Now()
   501  		if snapst.RefreshInhibitedTime == nil {
   502  			// Store the instant when the snap was first inhibited.
   503  			// This is reset to nil on successful refresh.
   504  			snapst.RefreshInhibitedTime = &now
   505  			Set(st, info.InstanceName(), snapst)
   506  			if _, ok := err.(*BusySnapError); ok {
   507  				st.Warnf(i18n.NG(
   508  					"snap %q is currently in use. Its refresh will be postponed for up to %d day to wait for the snap to no longer be in use.",
   509  					"snap %q is currently in use. Its refresh will be postponed for up to %d days to wait for the snap to no longer be in use.", days),
   510  					info.SnapName(), days)
   511  			}
   512  			return err
   513  		}
   514  
   515  		if now.Sub(*snapst.RefreshInhibitedTime) < maxInhibition {
   516  			// If we are still in the allowed window then just return
   517  			// the error but don't change the snap state again.
   518  			return err
   519  		}
   520  		if _, ok := err.(*BusySnapError); ok {
   521  			st.Warnf(i18n.NG(
   522  				"snap %q has been running for the maximum allowable %d day since its refresh was postponed. It will now be refreshed.",
   523  				"snap %q has been running for the maximum allowable %d days since its refresh was postponed. It will now be refreshed.", days),
   524  				info.SnapName(), days)
   525  		}
   526  	}
   527  	return nil
   528  }