Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

overlord,usersession: initial notifications of pending refreshes #9446

Merged
merged 29 commits into from Oct 26, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
29 commits
Select commit Hold shift + click to select a range
2de348f
usersession: add pending refresh notice API
zyga Sep 30, 2020
0e7e301
overlord/snapstate: notify about postponed snap refresh
zyga Sep 30, 2020
f0b40bc
usersession: add missing i18n.G of notification text
zyga Oct 1, 2020
e9eb7f1
usersession: remove debug printf
zyga Oct 1, 2020
6066d68
usersession: remove ineffective ExpireTimeout
zyga Oct 1, 2020
1be2b1a
overlord/snapstate: send notifications asynchronously
zyga Oct 1, 2020
6c5ae0c
overlord: store snapInfo in BusySnapError
zyga Oct 12, 2020
65d8eeb
overlord: convert populateRefreshHints to method on BusySnapError
zyga Oct 12, 2020
db810ed
overlord: add TODO about missing tests
zyga Oct 12, 2020
99295dd
overlord: make asyncPendingRefreshNotification mockable
zyga Oct 12, 2020
2a36c49
overlord: test dispatch of desktop notifications
zyga Oct 12, 2020
670b01a
overlord: test non-overdue refresh notification
zyga Oct 12, 2020
b6be078
Merge remote-tracking branch 'origin/master' into feature/notify-on-p…
zyga Oct 12, 2020
24dbf7c
Merge remote-tracking branch 'origin/master' into feature/notify-on-p…
zyga Oct 13, 2020
bf12216
Merge remote-tracking branch 'origin/master' into feature/notify-on-p…
zyga Oct 16, 2020
9981312
usersession: use refreshInfo to refer to PendingSnapRefreshInfo
zyga Oct 22, 2020
59d3475
usersession: add smoke test for PendingRefreshNotification client call
zyga Oct 22, 2020
c9e348d
usersession: use SnapDesktopFilesDir over custom constant
zyga Oct 22, 2020
12434b8
usersession: drop TODO about snap-store
zyga Oct 22, 2020
b2fdb1f
usersession: explain TODO better
zyga Oct 22, 2020
48c80b4
usersession: add tests for /v1/notifications/pending-refresh
zyga Oct 22, 2020
17eb9e7
overlord/snapstate: use test counter, not flag
zyga Oct 22, 2020
f680c1e
overlord/snapstate: explain some test measurements
zyga Oct 22, 2020
31dec23
overlord/snapstate: use osutil.FileExists
zyga Oct 22, 2020
c487d86
usersession: tweak variable declaration
zyga Oct 22, 2020
3d43e83
usersession: do not close shared D-Bus connection
zyga Oct 23, 2020
4e68782
usersession: use io.snapcraft.SessionAgent desktop-entry hint
zyga Oct 23, 2020
268557e
usersession: re-factor i18n handling to avoid repetition
zyga Oct 23, 2020
20f559a
usersession: add TODO for sharing DBus connection
zyga Oct 23, 2020
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
33 changes: 33 additions & 0 deletions overlord/snapstate/autorefresh.go
Expand Up @@ -20,6 +20,7 @@
package snapstate

import (
"context"
"fmt"
"os"
"time"
Expand All @@ -35,6 +36,7 @@ import (
"github.com/snapcore/snapd/strutil"
"github.com/snapcore/snapd/timeutil"
"github.com/snapcore/snapd/timings"
userclient "github.com/snapcore/snapd/usersession/client"
)

// the default refresh pattern
Expand Down Expand Up @@ -531,21 +533,45 @@ func getTime(st *state.State, timeKey string) (time.Time, error) {
return t1, nil
}

// asyncPendingRefreshNotification broadcasts desktop notification in a goroutine.
//
// This allows the, possibly slow, communication with each snapd session agent,
// to be performed without holding the snap state lock.
var asyncPendingRefreshNotification = func(context context.Context, client *userclient.Client, refreshInfo *userclient.PendingSnapRefreshInfo) {
go func() {
if err := client.PendingRefreshNotification(context, refreshInfo); err != nil {
logger.Noticef("Cannot send notification about pending refresh: %v", err)
}
}()
}

// inhibitRefresh returns an error if refresh is inhibited by running apps.
//
// Internally the snap state is updated to remember when the inhibition first
// took place. Apps can inhibit refreshes for up to "maxInhibition", beyond
// that period the refresh will go ahead despite application activity.
func inhibitRefresh(st *state.State, snapst *SnapState, info *snap.Info, checker func(*snap.Info) error) error {
if err := checker(info); err != nil {
refreshInfo := &userclient.PendingSnapRefreshInfo{
InstanceName: info.InstanceName(),
}
if err, ok := err.(*BusySnapError); ok {
refreshInfo = err.PendingSnapRefreshInfo()
}

days := int(maxInhibition.Truncate(time.Hour).Hours() / 24)
now := time.Now()
client := userclient.New()
if snapst.RefreshInhibitedTime == nil {
// Store the instant when the snap was first inhibited.
// This is reset to nil on successful refresh.
snapst.RefreshInhibitedTime = &now
Set(st, info.InstanceName(), snapst)
if _, ok := err.(*BusySnapError); ok {
refreshInfo.TimeRemaining = (maxInhibition - now.Sub(*snapst.RefreshInhibitedTime)).Truncate(time.Second)
// Send the notification asynchronously to avoid holding the state lock.
asyncPendingRefreshNotification(context.TODO(), client, refreshInfo)
// XXX: remove the warning or send it only if no notification was delivered?
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, I think we should remove the warning. Fwiw, I think the warning here is really a bit of a misfeature because we cannot make it go away once the app was refreshed. But it's fine to keep the XXX and do that in a followup. Especially this first warning that just warns for the first time seems a bit unneeded.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree but I'd like to remove them in a follow up.

st.Warnf(i18n.NG(
"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.",
"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),
Expand All @@ -557,9 +583,16 @@ func inhibitRefresh(st *state.State, snapst *SnapState, info *snap.Info, checker
if now.Sub(*snapst.RefreshInhibitedTime) < maxInhibition {
// If we are still in the allowed window then just return
// the error but don't change the snap state again.
refreshInfo.TimeRemaining = (maxInhibition - now.Sub(*snapst.RefreshInhibitedTime)).Truncate(time.Second)
asyncPendingRefreshNotification(context.TODO(), client, refreshInfo)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

(nitpick) we have the notification sending code in very small variations three times here, I wonder if this could be somehow simplified but definitely more a followup.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I will do this with the removal of the warning, in a follow-up.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done (in a follow-up that needs this to land first)

// TODO: as time left shrinks, send additional notifications with
// increasing frequency, allowing the user to understand the
// urgency.
return err
}
if _, ok := err.(*BusySnapError); ok {
asyncPendingRefreshNotification(context.TODO(), client, refreshInfo)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is slightly asymmetric, yes? I mean, we generate a warning here, i.e. the "policy" how strongly we warn is part of "autorefresh.go" here. But for the notifications we just give the "refreshInfo" and leave the "policy" about how strongly it warns to the "client.PendingRefreshNotification".

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are right but I think this resolves itself when the warnings go away.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Warnings are removed in a follow-up

// XXX: remove the warning or send it only if no notification was delivered?
st.Warnf(i18n.NG(
"snap %q has been running for the maximum allowable %d day since its refresh was postponed. It will now be refreshed.",
"snap %q has been running for the maximum allowable %d days since its refresh was postponed. It will now be refreshed.", days),
Expand Down
60 changes: 57 additions & 3 deletions overlord/snapstate/autorefresh_test.go
Expand Up @@ -43,6 +43,7 @@ import (
"github.com/snapcore/snapd/store/storetest"
"github.com/snapcore/snapd/testutil"
"github.com/snapcore/snapd/timeutil"
userclient "github.com/snapcore/snapd/usersession/client"
)

type autoRefreshStore struct {
Expand Down Expand Up @@ -800,30 +801,82 @@ func (s *autoRefreshTestSuite) TestRefreshOnMeteredConnNotMetered(c *C) {
c.Check(s.store.ops, DeepEquals, []string{"list-refresh"})
}

func (s *autoRefreshTestSuite) TestInhibitRefreshWithinInhibitWindow(c *C) {
func (s *autoRefreshTestSuite) TestInitialInhibitRefreshWithinInhibitWindow(c *C) {
s.state.Lock()
defer s.state.Unlock()

notificationCount := 0
restore := snapstate.MockAsyncPendingRefreshNotification(func(ctx context.Context, client *userclient.Client, refreshInfo *userclient.PendingSnapRefreshInfo) {
notificationCount++
c.Check(refreshInfo.InstanceName, Equals, "pkg")
c.Check(refreshInfo.TimeRemaining, Equals, time.Hour*14*24)
})
defer restore()

si := &snap.SideInfo{RealName: "pkg", Revision: snap.R(1)}
info := &snap.Info{SideInfo: *si}
snapst := &snapstate.SnapState{
Sequence: []*snap.SideInfo{si},
Current: si.Revision,
}
err := snapstate.InhibitRefresh(s.state, snapst, info, func(si *snap.Info) error {
return &snapstate.BusySnapError{SnapName: "pkg"}
return &snapstate.BusySnapError{SnapInfo: si}
})
c.Assert(err, ErrorMatches, `snap "pkg" has running apps or hooks`)

pending, _ := s.state.PendingWarnings()
c.Assert(pending, HasLen, 1)
c.Check(pending[0].String(), Equals, `snap "pkg" is currently in use. Its refresh will be postponed for up to 14 days to wait for the snap to no longer be in use.`)
c.Check(notificationCount, Equals, 1)
}

func (s *autoRefreshTestSuite) TestSubsequentInhibitRefreshWithinInhibitWindow(c *C) {
s.state.Lock()
defer s.state.Unlock()

notificationCount := 0
restore := snapstate.MockAsyncPendingRefreshNotification(func(ctx context.Context, client *userclient.Client, refreshInfo *userclient.PendingSnapRefreshInfo) {
notificationCount++
c.Check(refreshInfo.InstanceName, Equals, "pkg")
// XXX: This test measures real time, with second granularity.
// It takes non-zero (hence the subtracted second) to execute the test.
c.Check(refreshInfo.TimeRemaining, Equals, time.Hour*14*24/2-time.Second)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A comment here might be nice, something like: // just below the 14d window that triggers a stricter warning

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I actually explained the XXX aspect of this test. Please see inline.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

so this test is assuming that the test itself will always take less than one second? That seems ... brittle ... given our past experiences with running unit tests on arm* LP builders

})
defer restore()

instant := time.Now()
pastInstant := instant.Add(-snapstate.MaxInhibition / 2) // In the middle of the allowed window

si := &snap.SideInfo{RealName: "pkg", Revision: snap.R(1)}
info := &snap.Info{SideInfo: *si}
snapst := &snapstate.SnapState{
Sequence: []*snap.SideInfo{si},
Current: si.Revision,
RefreshInhibitedTime: &pastInstant,
}

err := snapstate.InhibitRefresh(s.state, snapst, info, func(si *snap.Info) error {
return &snapstate.BusySnapError{SnapInfo: si}
})
c.Assert(err, ErrorMatches, `snap "pkg" has running apps or hooks`)

pending, _ := s.state.PendingWarnings()
c.Assert(pending, HasLen, 0) // This case does not warn
c.Check(notificationCount, Equals, 1)
}

func (s *autoRefreshTestSuite) TestInhibitRefreshWarnsAndRefreshesWhenOverdue(c *C) {
s.state.Lock()
defer s.state.Unlock()

notificationCount := 0
restore := snapstate.MockAsyncPendingRefreshNotification(func(ctx context.Context, client *userclient.Client, refreshInfo *userclient.PendingSnapRefreshInfo) {
notificationCount++
c.Check(refreshInfo.InstanceName, Equals, "pkg")
c.Check(refreshInfo.TimeRemaining, Equals, time.Duration(0))
})
defer restore()

instant := time.Now()
pastInstant := instant.Add(-snapstate.MaxInhibition * 2)

Expand All @@ -835,11 +888,12 @@ func (s *autoRefreshTestSuite) TestInhibitRefreshWarnsAndRefreshesWhenOverdue(c
RefreshInhibitedTime: &pastInstant,
}
err := snapstate.InhibitRefresh(s.state, snapst, info, func(si *snap.Info) error {
return &snapstate.BusySnapError{SnapName: "pkg"}
return &snapstate.BusySnapError{SnapInfo: si}
})
c.Assert(err, IsNil)

pending, _ := s.state.PendingWarnings()
c.Assert(pending, HasLen, 1)
c.Check(pending[0].String(), Equals, `snap "pkg" has been running for the maximum allowable 14 days since its refresh was postponed. It will now be refreshed.`)
c.Check(notificationCount, Equals, 1)
}
18 changes: 18 additions & 0 deletions overlord/snapstate/export_test.go
Expand Up @@ -26,6 +26,7 @@ import (
"github.com/snapcore/snapd/overlord/state"
"github.com/snapcore/snapd/snap"
"github.com/snapcore/snapd/store"
userclient "github.com/snapcore/snapd/usersession/client"
)

type ManagerBackend managerBackend
Expand Down Expand Up @@ -190,6 +191,14 @@ func MockLocalInstallLastCleanup(t time.Time) (restore func()) {
}
}

func MockAsyncPendingRefreshNotification(fn func(context.Context, *userclient.Client, *userclient.PendingSnapRefreshInfo)) (restore func()) {
old := asyncPendingRefreshNotification
asyncPendingRefreshNotification = fn
return func() {
asyncPendingRefreshNotification = old
}
}

// re-refresh related
var (
RefreshedSnaps = refreshedSnaps
Expand Down Expand Up @@ -263,6 +272,15 @@ var (
MaxInhibition = maxInhibition
)

func NewBusySnapError(info *snap.Info, pids []int, busyAppNames, busyHookNames []string) *BusySnapError {
return &BusySnapError{
SnapInfo: info,
pids: pids,
busyAppNames: busyAppNames,
busyHookNames: busyHookNames,
}
}

func MockGenericRefreshCheck(fn func(info *snap.Info, canAppRunDuringRefresh func(app *snap.AppInfo) bool) error) (restore func()) {
old := genericRefreshCheck
genericRefreshCheck = fn
Expand Down
37 changes: 31 additions & 6 deletions overlord/snapstate/refresh.go
Expand Up @@ -21,6 +21,7 @@ package snapstate

import (
"fmt"
"path/filepath"
"sort"
"strings"

Expand All @@ -30,6 +31,7 @@ import (
"github.com/snapcore/snapd/overlord/state"
"github.com/snapcore/snapd/sandbox/cgroup"
"github.com/snapcore/snapd/snap"
userclient "github.com/snapcore/snapd/usersession/client"
)

// pidsOfSnap is a mockable version of PidsOfSnap
Expand Down Expand Up @@ -79,7 +81,7 @@ var genericRefreshCheck = func(info *snap.Info, canAppRunDuringRefresh func(app
sort.Strings(busyHookNames)
sort.Ints(busyPIDs)
return &BusySnapError{
SnapName: info.SnapName(),
SnapInfo: info,
busyAppNames: busyAppNames,
busyHookNames: busyHookNames,
pids: busyPIDs,
Expand Down Expand Up @@ -123,26 +125,49 @@ func HardNothingRunningRefreshCheck(info *snap.Info) error {

// BusySnapError indicates that snap has apps or hooks running and cannot refresh.
type BusySnapError struct {
SnapName string
SnapInfo *snap.Info
pids []int
busyAppNames []string
busyHookNames []string
}

// PendingSnapRefreshInfo computes information necessary to perform user notification
// of postponed refresh of a snap, based on the information about snap "business".
//
// The returned value contains the instance name of the snap as well as, if possible,
// information relevant for desktop notification services, such as application name
// and the snapd-generated desktop file name.
func (err *BusySnapError) PendingSnapRefreshInfo() *userclient.PendingSnapRefreshInfo {
refreshInfo := &userclient.PendingSnapRefreshInfo{
InstanceName: err.SnapInfo.InstanceName(),
}
for _, appName := range err.busyAppNames {
if app, ok := err.SnapInfo.Apps[appName]; ok {
path := app.DesktopFile()
if osutil.FileExists(path) {
refreshInfo.BusyAppName = appName
refreshInfo.BusyAppDesktopEntry = strings.SplitN(filepath.Base(path), ".", 2)[0]
break
}
}
}
return refreshInfo
}

// Error formats an error string describing what is running.
func (err *BusySnapError) Error() string {
switch {
case len(err.busyAppNames) > 0 && len(err.busyHookNames) > 0:
return fmt.Sprintf("snap %q has running apps (%s) and hooks (%s)",
err.SnapName, strings.Join(err.busyAppNames, ", "), strings.Join(err.busyHookNames, ", "))
err.SnapInfo.InstanceName(), strings.Join(err.busyAppNames, ", "), strings.Join(err.busyHookNames, ", "))
case len(err.busyAppNames) > 0:
return fmt.Sprintf("snap %q has running apps (%s)",
err.SnapName, strings.Join(err.busyAppNames, ", "))
err.SnapInfo.InstanceName(), strings.Join(err.busyAppNames, ", "))
case len(err.busyHookNames) > 0:
return fmt.Sprintf("snap %q has running hooks (%s)",
err.SnapName, strings.Join(err.busyHookNames, ", "))
err.SnapInfo.InstanceName(), strings.Join(err.busyHookNames, ", "))
default:
return fmt.Sprintf("snap %q has running apps or hooks", err.SnapName)
return fmt.Sprintf("snap %q has running apps or hooks", err.SnapInfo.InstanceName())
}
}

Expand Down
28 changes: 26 additions & 2 deletions overlord/snapstate/refresh_test.go
Expand Up @@ -20,6 +20,10 @@
package snapstate_test

import (
"io/ioutil"
"os"
"path/filepath"

. "gopkg.in/check.v1"

"github.com/snapcore/snapd/cmd/snaplock/runinhibit"
Expand Down Expand Up @@ -145,6 +149,26 @@ func (s *refreshSuite) TestHardNothingRunningRefreshCheck(c *C) {
c.Check(err.(*snapstate.BusySnapError).Pids(), DeepEquals, []int{105})
}

func (s *refreshSuite) TestPendingSnapRefreshInfo(c *C) {
err := snapstate.NewBusySnapError(s.info, nil, nil, nil)
refreshInfo := err.PendingSnapRefreshInfo()
c.Check(refreshInfo.InstanceName, Equals, s.info.InstanceName())
// The information about a busy app is not populated because
// the original error did not have the corresponding information.
c.Check(refreshInfo.BusyAppName, Equals, "")
c.Check(refreshInfo.BusyAppDesktopEntry, Equals, "")

// If we create a matching desktop entry then relevant meta-data is added.
err = snapstate.NewBusySnapError(s.info, nil, []string{"app"}, nil)
desktopFile := s.info.Apps["app"].DesktopFile()
c.Assert(os.MkdirAll(filepath.Dir(desktopFile), 0755), IsNil)
c.Assert(ioutil.WriteFile(desktopFile, nil, 0644), IsNil)
refreshInfo = err.PendingSnapRefreshInfo()
c.Check(refreshInfo.InstanceName, Equals, s.info.InstanceName())
c.Check(refreshInfo.BusyAppName, Equals, "app")
c.Check(refreshInfo.BusyAppDesktopEntry, Equals, "pkg_app")
}

func (s *refreshSuite) addInstalledSnap(snapst *snapstate.SnapState) (*snapstate.SnapState, *snap.Info) {
snapName := snapst.Sequence[0].RealName
snapstate.Set(s.state, snapName, snapst)
Expand Down Expand Up @@ -194,7 +218,7 @@ func (s *refreshSuite) TestDoSoftRefreshCheckDisallowed(c *C) {

// Pretend that snaps cannot refresh.
restore := snapstate.MockGenericRefreshCheck(func(info *snap.Info, canAppRunDuringRefresh func(app *snap.AppInfo) bool) error {
return &snapstate.BusySnapError{SnapName: info.InstanceName()}
return &snapstate.BusySnapError{SnapInfo: info}
})
defer restore()

Expand Down Expand Up @@ -245,7 +269,7 @@ func (s *refreshSuite) TestDoHardRefreshFlowRefreshDisallowed(c *C) {

// Pretend that snaps cannot refresh.
restore := snapstate.MockGenericRefreshCheck(func(info *snap.Info, canAppRunDuringRefresh func(app *snap.AppInfo) bool) error {
return &snapstate.BusySnapError{SnapName: info.InstanceName()}
return &snapstate.BusySnapError{SnapInfo: info}
})
defer restore()

Expand Down
5 changes: 3 additions & 2 deletions usersession/agent/export_test.go
Expand Up @@ -25,8 +25,9 @@ import (
)

var (
SessionInfoCmd = sessionInfoCmd
ServiceControlCmd = serviceControlCmd
SessionInfoCmd = sessionInfoCmd
ServiceControlCmd = serviceControlCmd
PendingRefreshNotificationCmd = pendingRefreshNotificationCmd
)

func MockStopTimeouts(stop, kill time.Duration) (restore func()) {
Expand Down