From 6a0f119fc22080548a26e067c1ec49f0c5a5bcfb Mon Sep 17 00:00:00 2001 From: Mike Bland Date: Wed, 13 May 2015 17:30:19 -0400 Subject: [PATCH 1/3] Provide graceful shutdown of file watcher in tests This test failure from #92 inspired this change: https://travis-ci.org/bitly/google_auth_proxy/jobs/62425336 2015/05/13 16:27:33 using authenticated emails file /tmp/test_auth_emails_952353477 2015/05/13 16:27:33 watching /tmp/test_auth_emails_952353477 for updates 2015/05/13 16:27:33 validating: is xyzzy@example.com valid? true 2015/05/13 16:27:33 watching interrupted on event: "/tmp/test_auth_emails_952353477": CHMOD 2015/05/13 16:27:33 watching resumed for /tmp/test_auth_emails_952353477 2015/05/13 16:27:33 reloading after event: "/tmp/test_auth_emails_952353477": CHMOD 2015/05/13 16:27:33 watching interrupted on event: "/tmp/test_auth_emails_952353477": REMOVE 2015/05/13 16:27:33 validating: is xyzzy@example.com valid? false 2015/05/13 16:27:33 watching resumed for /tmp/test_auth_emails_952353477 2015/05/13 16:27:33 reloading after event: "/tmp/test_auth_emails_952353477": REMOVE 2015/05/13 16:27:33 failed opening authenticated-emails-file="/tmp/test_auth_emails_952353477", open /tmp/test_auth_emails_952353477: no such file or directory I believe that what happened was that the call to reload the file after the second "reloading after event" lost the race when the test shut down and the file was removed. This change introduces a `done` channel that ensures outstanding actions complete and the watcher exits before the test removes the file. --- validator.go | 10 +++++----- validator_test.go | 19 ++++++++++++++----- validator_watcher_copy_test.go | 3 +-- validator_watcher_test.go | 6 ++---- watcher.go | 6 +++++- 5 files changed, 27 insertions(+), 17 deletions(-) diff --git a/validator.go b/validator.go index 8c3e985..3e0373a 100644 --- a/validator.go +++ b/validator.go @@ -15,13 +15,13 @@ type UserMap struct { m unsafe.Pointer } -func NewUserMap(usersFile string, onUpdate func()) *UserMap { +func NewUserMap(usersFile string, done <-chan bool, onUpdate func()) *UserMap { um := &UserMap{usersFile: usersFile} m := make(map[string]bool) atomic.StorePointer(&um.m, unsafe.Pointer(&m)) if usersFile != "" { log.Printf("using authenticated emails file %s", usersFile) - started := WatchForUpdates(usersFile, func() { + started := WatchForUpdates(usersFile, done, func() { um.LoadAuthenticatedEmailsFile() onUpdate() }) @@ -62,8 +62,8 @@ func (um *UserMap) LoadAuthenticatedEmailsFile() { } func newValidatorImpl(domains []string, usersFile string, - onUpdate func()) func(string) bool { - validUsers := NewUserMap(usersFile, onUpdate) + done <-chan bool, onUpdate func()) func(string) bool { + validUsers := NewUserMap(usersFile, done, onUpdate) for i, domain := range domains { domains[i] = fmt.Sprintf("@%s", strings.ToLower(domain)) @@ -85,5 +85,5 @@ func newValidatorImpl(domains []string, usersFile string, } func NewValidator(domains []string, usersFile string) func(string) bool { - return newValidatorImpl(domains, usersFile, func() {}) + return newValidatorImpl(domains, usersFile, nil, func() {}) } diff --git a/validator_test.go b/validator_test.go index 0912b36..1047258 100644 --- a/validator_test.go +++ b/validator_test.go @@ -9,6 +9,7 @@ import ( type ValidatorTest struct { auth_email_file *os.File + done chan bool } func NewValidatorTest(t *testing.T) *ValidatorTest { @@ -18,13 +19,21 @@ func NewValidatorTest(t *testing.T) *ValidatorTest { if err != nil { t.Fatal("failed to create temp file: " + err.Error()) } + vt.done = make(chan bool) return vt } func (vt *ValidatorTest) TearDown() { + vt.done <- true os.Remove(vt.auth_email_file.Name()) } +func (vt *ValidatorTest) NewValidator(domains []string, + updated chan<- bool) func(string) bool { + return newValidatorImpl(domains, vt.auth_email_file.Name(), + vt.done, func() { updated <- true }) +} + // This will close vt.auth_email_file. func (vt *ValidatorTest) WriteEmails(t *testing.T, emails []string) { defer vt.auth_email_file.Close() @@ -41,7 +50,7 @@ func TestValidatorEmpty(t *testing.T) { vt.WriteEmails(t, []string(nil)) domains := []string(nil) - validator := NewValidator(domains, vt.auth_email_file.Name()) + validator := vt.NewValidator(domains, nil) if validator("foo.bar@example.com") { t.Error("nothing should validate when the email and " + @@ -55,7 +64,7 @@ func TestValidatorSingleEmail(t *testing.T) { vt.WriteEmails(t, []string{"foo.bar@example.com"}) domains := []string(nil) - validator := NewValidator(domains, vt.auth_email_file.Name()) + validator := vt.NewValidator(domains, nil) if !validator("foo.bar@example.com") { t.Error("email should validate") @@ -72,7 +81,7 @@ func TestValidatorSingleDomain(t *testing.T) { vt.WriteEmails(t, []string(nil)) domains := []string{"example.com"} - validator := NewValidator(domains, vt.auth_email_file.Name()) + validator := vt.NewValidator(domains, nil) if !validator("foo.bar@example.com") { t.Error("email should validate") @@ -91,7 +100,7 @@ func TestValidatorMultipleEmailsMultipleDomains(t *testing.T) { "plugh@example.com", }) domains := []string{"example0.com", "example1.com"} - validator := NewValidator(domains, vt.auth_email_file.Name()) + validator := vt.NewValidator(domains, nil) if !validator("foo.bar@example0.com") { t.Error("email from first domain should validate") @@ -117,7 +126,7 @@ func TestValidatorComparisonsAreCaseInsensitive(t *testing.T) { vt.WriteEmails(t, []string{"Foo.Bar@Example.Com"}) domains := []string{"Frobozz.Com"} - validator := NewValidator(domains, vt.auth_email_file.Name()) + validator := vt.NewValidator(domains, nil) if !validator("foo.bar@example.com") { t.Error("loaded email addresses are not lower-cased") diff --git a/validator_watcher_copy_test.go b/validator_watcher_copy_test.go index 35bed3a..fa04cb9 100644 --- a/validator_watcher_copy_test.go +++ b/validator_watcher_copy_test.go @@ -34,8 +34,7 @@ func TestValidatorOverwriteEmailListViaCopyingOver(t *testing.T) { vt.WriteEmails(t, []string{"xyzzy@example.com"}) domains := []string(nil) updated := make(chan bool) - validator := newValidatorImpl(domains, vt.auth_email_file.Name(), - func() { updated <- true }) + validator := vt.NewValidator(domains, updated) if !validator("xyzzy@example.com") { t.Error("email in list should validate") diff --git a/validator_watcher_test.go b/validator_watcher_test.go index 691644f..f220ea2 100644 --- a/validator_watcher_test.go +++ b/validator_watcher_test.go @@ -51,8 +51,7 @@ func TestValidatorOverwriteEmailListDirectly(t *testing.T) { }) domains := []string(nil) updated := make(chan bool) - validator := newValidatorImpl(domains, vt.auth_email_file.Name(), - func() { updated <- true }) + validator := vt.NewValidator(domains, updated) if !validator("xyzzy@example.com") { t.Error("first email in list should validate") @@ -89,8 +88,7 @@ func TestValidatorOverwriteEmailListViaRenameAndReplace(t *testing.T) { vt.WriteEmails(t, []string{"xyzzy@example.com"}) domains := []string(nil) updated := make(chan bool) - validator := newValidatorImpl(domains, vt.auth_email_file.Name(), - func() { updated <- true }) + validator := vt.NewValidator(domains, updated) if !validator("xyzzy@example.com") { t.Error("email in list should validate") diff --git a/watcher.go b/watcher.go index 32c91f2..4573ddc 100644 --- a/watcher.go +++ b/watcher.go @@ -30,7 +30,7 @@ func WaitForReplacement(event fsnotify.Event, watcher *fsnotify.Watcher) { } } -func WatchForUpdates(filename string, action func()) bool { +func WatchForUpdates(filename string, done <-chan bool, action func()) bool { filename = filepath.Clean(filename) watcher, err := fsnotify.NewWatcher() if err != nil { @@ -40,6 +40,10 @@ func WatchForUpdates(filename string, action func()) bool { defer watcher.Close() for { select { + case _ = <-done: + log.Printf("Shutting down watcher for: %s", + filename) + return case event := <-watcher.Events: // On Arch Linux, it appears Chmod events precede Remove events, // which causes a race between action() and the coming Remove event. From 5f2df7167a90fe9c8734a0c12407f53f4f824cd9 Mon Sep 17 00:00:00 2001 From: Mike Bland Date: Wed, 13 May 2015 18:30:22 -0400 Subject: [PATCH 2/3] Ensure watcher tests don't block during shutdown MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit These test failures from #93 inspired this change: https://travis-ci.org/bitly/google_auth_proxy/jobs/62474406 https://travis-ci.org/bitly/google_auth_proxy/jobs/62474407 Both tests exhibited this pattern: 2015/05/13 22:10:54 validating: is xyzzy@example.com valid? false 2015/05/13 22:10:54 watching interrupted on event: "/tmp/test_auth_emails_300880185": CHMOD 2015/05/13 22:10:54 watching resumed for /tmp/test_auth_emails_300880185 2015/05/13 22:10:54 reloading after event: "/tmp/test_auth_emails_300880185": CHMOD panic: test timed out after 1m0s [snip] goroutine 175 [chan send]: github.com/bitly/google_auth_proxy.(*ValidatorTest).TearDown(0xc2080bc330) /home/travis/gopath/src/github.com/bitly/google_auth_proxy/validator_test.go:27 +0x43 github.com/bitly/google_auth_proxy.TestValidatorOverwriteEmailListViaRenameAndReplace(0xc2080f2480) /home/travis/gopath/src/github.com/bitly/google_auth_proxy/validator_watcher_test.go:103 +0x3b9 [snip] goroutine 177 [chan send]: github.com/bitly/google_auth_proxy.func·017() /home/travis/gopath/src/github.com/bitly/google_auth_proxy/validator_test.go:34 +0x41 I realized that the spurious CHMOD events were causing calls to `func() { updated <- true }` (from validator_test.go:34), which caused the goroutine running the watcher to block. At the same time, ValidatorTest.TearDown was blocked by trying to send into the `done` channel. The solution was to create a flag that ensured only one value was ever sent into the update channel. --- validator_test.go | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/validator_test.go b/validator_test.go index 1047258..0bf0a08 100644 --- a/validator_test.go +++ b/validator_test.go @@ -10,6 +10,7 @@ import ( type ValidatorTest struct { auth_email_file *os.File done chan bool + update_seen bool } func NewValidatorTest(t *testing.T) *ValidatorTest { @@ -31,7 +32,12 @@ func (vt *ValidatorTest) TearDown() { func (vt *ValidatorTest) NewValidator(domains []string, updated chan<- bool) func(string) bool { return newValidatorImpl(domains, vt.auth_email_file.Name(), - vt.done, func() { updated <- true }) + vt.done, func() { + if vt.update_seen == false { + updated <- true + vt.update_seen = true + } + }) } // This will close vt.auth_email_file. From 020a35e85fa52767e0caea28d7707d273329bbaa Mon Sep 17 00:00:00 2001 From: Mike Bland Date: Thu, 14 May 2015 07:57:30 -0400 Subject: [PATCH 3/3] Remove file watch upon interruption TestValidatorOverwriteEmailListViaRenameAndReplace was deadlocking on Windows because, on Windows, fsnotify.Watcher will continue to watch a renamed file using its new name. On other systems, it appears the watch on a file is removed after a rename. The fix is to explicitly remove the watch to ensure the watch is resumed under the original name. --- watcher.go | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/watcher.go b/watcher.go index 4573ddc..d8e073f 100644 --- a/watcher.go +++ b/watcher.go @@ -12,17 +12,18 @@ import ( "gopkg.in/fsnotify.v1" ) -func WaitForReplacement(event fsnotify.Event, watcher *fsnotify.Watcher) { +func WaitForReplacement(filename string, op fsnotify.Op, + watcher *fsnotify.Watcher) { const sleep_interval = 50 * time.Millisecond // Avoid a race when fsnofity.Remove is preceded by fsnotify.Chmod. - if event.Op&fsnotify.Chmod != 0 { + if op&fsnotify.Chmod != 0 { time.Sleep(sleep_interval) } for { - if _, err := os.Stat(event.Name); err == nil { - if err := watcher.Add(event.Name); err == nil { - log.Printf("watching resumed for %s", event.Name) + if _, err := os.Stat(filename); err == nil { + if err := watcher.Add(filename); err == nil { + log.Printf("watching resumed for %s", filename) return } } @@ -52,7 +53,8 @@ func WatchForUpdates(filename string, done <-chan bool, action func()) bool { // can't be opened. if event.Op&(fsnotify.Remove|fsnotify.Rename|fsnotify.Chmod) != 0 { log.Printf("watching interrupted on event: %s", event) - WaitForReplacement(event, watcher) + watcher.Remove(filename) + WaitForReplacement(filename, event.Op, watcher) } log.Printf("reloading after event: %s", event) action()