Merge lp:~nikwen/account-polld/authentication-penalty-count into lp:~ubuntu-push-hackers/account-polld/trunk

Proposed by Niklas Wenzel
Status: Merged
Approved by: Jonas G. Drange
Approved revision: 159
Merged at revision: 140
Proposed branch: lp:~nikwen/account-polld/authentication-penalty-count
Merge into: lp:~ubuntu-push-hackers/account-polld/trunk
Diff against target: 147 lines (+48/-35)
2 files modified
cmd/account-polld/account_manager.go (+47/-24)
cmd/account-polld/main.go (+1/-11)
To merge this branch: bzr merge lp:~nikwen/account-polld/authentication-penalty-count
Reviewer Review Type Date Requested Status
Jonas G. Drange (community) Approve
PS Jenkins bot continuous-integration Pending
Alberto Mardegan Pending
Review via email: mp+272031@code.launchpad.net

Commit message

When authentification of an account fails continuously, we should wait a bit before trying again (part of the issue experienced in LP: #1496773)

Description of the change

When authentification of an account fails continuously, we should wait a bit before trying again. Part of the issue experienced in LP: #1496773.

To post a comment you must log in.
Revision history for this message
Niklas Wenzel (nikwen) wrote :

This also fixes the example case provided in the description of LP: #1383298. However, it does fix the "Connection errors should not increase the penalty count" part.

Revision history for this message
Niklas Wenzel (nikwen) wrote :

I tested this now and found that this does not work yet. I'll fix it though. ;)

Revision history for this message
Niklas Wenzel (nikwen) wrote :

After better understanding the account-polld code, I now think that we can solve the "reauthentication" (aka retrying to poll the account with a previous auth failure as that results in reauthentication in case of token expiry and in ignoring temporary network issues) in a better way.

Yet, merging this one will fix the problem experienced with the current implementation, so I vote for doing so right now, but I will still prepare a better version based on this one as soon as possible that is tackling only the "reauthentication in case of token expiry and ignoring temporary issues" part instead of all auth errors.

Revision history for this message
Niklas Wenzel (nikwen) wrote :

Ok, given that the auth errors are passed from C instead of being native Go errors, I think that this will be harder than I though. Partly revising my previous statement, I'll have to see how easy the "ignoring only temporary issues" part is going to be.

That confirms me in my suggestion to get this preliminary (but working!) solution in for now.

147. By Niklas Wenzel

Logic fix

Revision history for this message
Niklas Wenzel (nikwen) wrote :

One idea would be to manually select those that we want/don't want from libsignon-glib's signon-errors.h.

148. By Niklas Wenzel

Fix possible race condition

Revision history for this message
Niklas Wenzel (nikwen) wrote :

The last commit should fix a race condition I found while testing. I'll report back tomorrow if it is gone now.

Revision history for this message
Niklas Wenzel (nikwen) wrote :

Tested it for a day and it seems to work fine now. :)

Revision history for this message
Jonas G. Drange (jonas-drange) wrote :

Do you have a way for me to confirm the fix, i.e. a way to trigger the aggressive polld behaviour?

review: Needs Information
Revision history for this message
Niklas Wenzel (nikwen) wrote :

That's actually a very good question.

I often get an auth failure after rebooting my phone because it tries to authenticate before the phone establishes a network connection. You could try that and set down the authTriesUntilPenalty to 1.
Otherwise, you could try letting it run in the background for some time and your Gmail tokens will at some point have to be refreshed. However, this is always just one auth failure instead of the many from the bug report. As I noted over there, I currently don't have any idea how to reproduce that kind of behaviour. Maybe changing your Gmail account password might work... (The real password without updating it on the phone.)

What I *can* confirm though is that this doesn't break anything. I've been running it for more than a week now and I've got notifications just fine and the logs look good when a token expires. ;)

Revision history for this message
Jonas G. Drange (jonas-drange) wrote :

I can confirm that it doesn't break anything, but from using the new steps to reproduce (which I hope replicates the bug accurately), it doesn't fix the issue either. :|

Maybe your fix fixes an authentication failure, but not a token expiry (which _easily_ causes endless loops, and is seen all over the logs attached in bug 1496773)

review: Needs Fixing
149. By Niklas Wenzel

Treat token expiry the same as auth errors

150. By Niklas Wenzel

Prevent endless refreshes on password changes

151. By Niklas Wenzel

Reset failedAuthenticationTries counter properly in token expiry cases

152. By Niklas Wenzel

Try to fix immediate reauth issue

153. By Niklas Wenzel

Fix minor issue

154. By Niklas Wenzel

Add log output

155. By Niklas Wenzel

Minor changes

156. By Niklas Wenzel

Refactoring

157. By Niklas Wenzel

Comment fixes

158. By Niklas Wenzel

Comment changes

159. By Niklas Wenzel

Remove remaining TODO comment

Revision history for this message
Jonas G. Drange (jonas-drange) wrote :

Looks good, works well!

review: Approve
Revision history for this message
Niklas Wenzel (nikwen) wrote :

Thanks for approving! :)

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'cmd/account-polld/account_manager.go'
2--- cmd/account-polld/account_manager.go 2015-03-20 17:51:02 +0000
3+++ cmd/account-polld/account_manager.go 2015-10-15 15:16:07 +0000
4@@ -28,20 +28,23 @@
5 )
6
7 type AccountManager struct {
8- watcher *accounts.Watcher
9- authData accounts.AuthData
10- plugin plugins.Plugin
11- interval time.Duration
12- postWatch chan *PostWatch
13- authChan chan accounts.AuthData
14- doneChan chan error
15- penaltyCount int
16+ watcher *accounts.Watcher
17+ authData accounts.AuthData
18+ plugin plugins.Plugin
19+ interval time.Duration
20+ postWatch chan *PostWatch
21+ authChan chan accounts.AuthData
22+ doneChan chan error
23+ penaltyCount int
24+ authFailureCount int
25 }
26
27 var (
28- pollTimeout = time.Duration(30 * time.Second)
29- bootstrapPollTimeout = time.Duration(4 * time.Minute)
30- maxCounter = 4
31+ pollTimeout = time.Duration(30 * time.Second)
32+ bootstrapPollTimeout = time.Duration(4 * time.Minute)
33+ maxCounter = 4
34+ authTriesUntilPenalty = 3
35+ authFailurePenalty = 10
36 )
37
38 var (
39@@ -67,9 +70,9 @@
40 }
41
42 func (a *AccountManager) Poll(bootstrap bool) {
43+ gotNewAuthData := false
44 if !a.authData.Enabled {
45- var ok bool
46- if a.authData, ok = <-a.authChan; !ok {
47+ if a.authData, gotNewAuthData = <-a.authChan; !gotNewAuthData {
48 log.Println("Account", a.authData.AccountId, "no longer enabled")
49 return
50 }
51@@ -81,10 +84,15 @@
52 }
53
54 if a.penaltyCount > 0 {
55- log.Printf("Leaving poll for account %d as penaly count is %d", a.authData.AccountId, a.penaltyCount)
56+ log.Printf("Leaving poll for account %d as penalty count is %d", a.authData.AccountId, a.penaltyCount)
57 a.penaltyCount--
58 return
59+ } else if !gotNewAuthData && a.authData.Error != nil {
60+ // Retry to poll the account with a previous auth failure as that results in reauthentication in case of token expiry and in ignoring temporary network issues
61+ log.Println("Retrying to poll account with previous auth failure and id", a.authData.AccountId, "(results in reauthentication in case of token expiry and in ignoring temporary network issues)")
62+ a.authData.Error = nil
63 }
64+
65 timeout := pollTimeout
66 if bootstrap {
67 timeout = bootstrapPollTimeout
68@@ -100,12 +108,36 @@
69 case err := <-a.doneChan:
70 if err == nil {
71 log.Println("Poll for account", a.authData.AccountId, "was successful")
72+ a.authFailureCount = 0
73 a.penaltyCount = 0
74 } else {
75 if err != clickNotInstalledError && err != authError { // Do not log the error twice
76 log.Println("Poll for account", a.authData.AccountId, "has failed:", err)
77 }
78- if a.penaltyCount < maxCounter {
79+ if err == authError || err == plugins.ErrTokenExpired {
80+ // Increase the authFailureCount counter, except for when we did a poll which
81+ // raised a token expiry error when we did not get any new auth data this time.
82+ if err != plugins.ErrTokenExpired || gotNewAuthData {
83+ log.Println("Increasing the auth failure counter for account", a.authData.AccountId)
84+ a.authFailureCount++
85+ } else {
86+ log.Println("Not increasing the auth failure counter for account", a.authData.AccountId, "as we do not have new auth data")
87+ }
88+ if a.authFailureCount >= authTriesUntilPenalty {
89+ a.penaltyCount = authFailurePenalty
90+ a.authFailureCount = 0
91+ log.Println(authTriesUntilPenalty, "auth failures in a row for account", a.authData.AccountId, "-> skipping it for the next", a.penaltyCount, "poll cycles")
92+ } else if err == plugins.ErrTokenExpired && !gotNewAuthData {
93+ // If the error indicates that the authentication token has expired, request reauthentication
94+ // and mark the data as disabled.
95+ // Do not refresh immediately when we just got new (faulty) auth data as immediately trying
96+ // again is probably not going to help. Instead, we wait for the next poll cycle.
97+ a.watcher.Refresh(a.authData.AccountId)
98+ a.authData.Enabled = false
99+ a.authData.Error = err
100+ }
101+ } else if a.penaltyCount < maxCounter {
102+ a.authFailureCount = 0
103 a.penaltyCount++
104 }
105 }
106@@ -131,15 +163,6 @@
107
108 if bs, err := a.plugin.Poll(&a.authData); err != nil {
109 log.Print("Error while polling ", a.authData.AccountId, ": ", err)
110-
111- // If the error indicates that the authentication
112- // token has expired, request reauthentication and
113- // mark data as disabled.
114- if err == plugins.ErrTokenExpired {
115- a.watcher.Refresh(a.authData.AccountId)
116- a.authData.Enabled = false
117- a.authData.Error = err
118- }
119 a.doneChan <- err
120 } else {
121 for _, b := range bs {
122
123=== modified file 'cmd/account-polld/main.go'
124--- cmd/account-polld/main.go 2015-03-20 17:51:02 +0000
125+++ cmd/account-polld/main.go 2015-10-15 15:16:07 +0000
126@@ -138,20 +138,10 @@
127 case <-pollBus.PollChan:
128 var wg sync.WaitGroup
129 for _, v := range mgr {
130- if v.authData.Error != plugins.ErrTokenExpired { // Do not poll if the new token
131- // hasn't been loaded yet
132+ if v.authData.Error != plugins.ErrTokenExpired { // Do not poll if the new token hasn't been loaded yet
133 wg.Add(1)
134 go func(accountManager *AccountManager) {
135 defer wg.Done()
136-
137- if accountManager.authData.Error != nil {
138- // Make the account try to authenticate again in Poll()
139- log.Println("Retrying to authenticate existing account with id",
140- accountManager.authData.AccountId)
141- accountManager.penaltyCount = 0
142- accountManager.authData.Error = nil
143- }
144-
145 accountManager.Poll(false)
146 }(v)
147 } else {

Subscribers

People subscribed via source and target branches