[ARVADOS] updated: c8c2068cdb980ef8a1c6a791f6caf6a4bd4b4415

Git user git at public.curoverse.com
Tue Jul 26 11:29:05 EDT 2016


Summary of changes:
 services/keepstore/s3_volume.go      | 23 +++++++--
 services/keepstore/s3_volume_test.go | 90 ++++++++++++++++++++++--------------
 2 files changed, 73 insertions(+), 40 deletions(-)

       via  c8c2068cdb980ef8a1c6a791f6caf6a4bd4b4415 (commit)
       via  99aa0762069ab4fbda4482a20c7bddedbaa0eb93 (commit)
       via  0978e69febabc403866f2ecf303c195a84d83364 (commit)
       via  e59a5d4e33a4e3208b6f19e91fee37905fe5ca7a (commit)
      from  4aedb9bcb7c14de1ad1cd330dd48d6f7671cfff5 (commit)

Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.


commit c8c2068cdb980ef8a1c6a791f6caf6a4bd4b4415
Author: Tom Clegg <tom at curoverse.com>
Date:   Tue Jul 26 11:07:46 2016 -0400

    8555: Untrash to repair inconsistent state (trash/X without recentX).

diff --git a/services/keepstore/s3_volume.go b/services/keepstore/s3_volume.go
index 0cfaaaf..d520d71 100644
--- a/services/keepstore/s3_volume.go
+++ b/services/keepstore/s3_volume.go
@@ -575,8 +575,12 @@ func (v *S3Volume) EmptyTrash() {
 			continue
 		}
 		recent, err := v.Bucket.Head("recent/"+loc, nil)
-		if err != nil {
-			log.Printf("warning: %s: EmptyTrash: cannot delete trash %q with no corresponding recent/* marker", v, trash.Key)
+		if err != nil && os.IsNotExist(v.translateError(err)) {
+			log.Printf("warning: %s: EmptyTrash: found trash marker %q but no %q (%s); calling Untrash", v, trash.Key, "recent/"+loc, err)
+			v.Untrash(loc)
+			continue
+		} else if err != nil {
+			log.Printf("warning: %s: EmptyTrash: HEAD %q: %s", v, "recent/"+loc, err)
 			continue
 		}
 		recentT, err := v.lastModified(recent)
diff --git a/services/keepstore/s3_volume_test.go b/services/keepstore/s3_volume_test.go
index 8a06f19..e41e04b 100644
--- a/services/keepstore/s3_volume_test.go
+++ b/services/keepstore/s3_volume_test.go
@@ -223,6 +223,11 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 			none, t0.Add(-90 * time.Minute), t0.Add(-89 * time.Minute),
 			true, false, true, true, true, false,
 		},
+		{
+			"Trashed copy exists with no recent/* marker (cause unknown); repair by untrashing",
+			none, none, t0.Add(-time.Minute),
+			false, false, false, true, true, true,
+		},
 	} {
 		c.Log("Scenario: ", scenario.label)
 

commit 99aa0762069ab4fbda4482a20c7bddedbaa0eb93
Author: Tom Clegg <tom at curoverse.com>
Date:   Tue Jul 26 09:44:56 2016 -0400

    8555: Log statistics in EmptyTrash.

diff --git a/services/keepstore/s3_volume.go b/services/keepstore/s3_volume.go
index be4da4d..0cfaaaf 100644
--- a/services/keepstore/s3_volume.go
+++ b/services/keepstore/s3_volume.go
@@ -551,6 +551,8 @@ func (v *S3Volume) translateError(err error) error {
 // EmptyTrash looks for trashed blocks that exceeded trashLifetime
 // and deletes them from the volume.
 func (v *S3Volume) EmptyTrash() {
+	var bytesInTrash, blocksInTrash, bytesDeleted, blocksDeleted int64
+
 	// Use a merge sort to find matching sets of trash/X and recent/X.
 	trashL := s3Lister{
 		Bucket:   v.Bucket,
@@ -564,6 +566,9 @@ func (v *S3Volume) EmptyTrash() {
 		if !v.isKeepBlock(loc) {
 			continue
 		}
+		bytesInTrash += trash.Size
+		blocksInTrash++
+
 		trashT, err := time.Parse(time.RFC3339, trash.LastModified)
 		if err != nil {
 			log.Printf("warning: %s: EmptyTrash: %q: parse %q: %s", v, trash.Key, trash.LastModified, err)
@@ -610,6 +615,9 @@ func (v *S3Volume) EmptyTrash() {
 			log.Printf("warning: %s: EmptyTrash: deleting %q: %s", v, trash.Key, err)
 			continue
 		}
+		bytesDeleted += trash.Size
+		blocksDeleted++
+
 		_, err = v.Bucket.Head(loc, nil)
 		if os.IsNotExist(err) {
 			err = v.Bucket.Del("recent/" + loc)
@@ -623,6 +631,7 @@ func (v *S3Volume) EmptyTrash() {
 	if err := trashL.Error(); err != nil {
 		log.Printf("error: %s: EmptyTrash: lister: %s", v, err)
 	}
+	log.Printf("EmptyTrash stats for %v: Deleted %v bytes in %v blocks. Remaining in trash: %v bytes in %v blocks.", v.String(), bytesDeleted, blocksDeleted, bytesInTrash-bytesDeleted, blocksInTrash-blocksDeleted)
 }
 
 type s3Lister struct {

commit 0978e69febabc403866f2ecf303c195a84d83364
Author: Tom Clegg <tom at curoverse.com>
Date:   Tue Jul 26 09:38:07 2016 -0400

    8555: Improve variable names and comments.

diff --git a/services/keepstore/s3_volume.go b/services/keepstore/s3_volume.go
index 8ded160..be4da4d 100644
--- a/services/keepstore/s3_volume.go
+++ b/services/keepstore/s3_volume.go
@@ -558,7 +558,7 @@ func (v *S3Volume) EmptyTrash() {
 		PageSize: v.indexPageSize,
 	}
 	// Define "ready to delete" as "...when EmptyTrash started".
-	now := time.Now()
+	startT := time.Now()
 	for trash := trashL.First(); trash != nil; trash = trashL.Next() {
 		loc := trash.Key[6:]
 		if !v.isKeepBlock(loc) {
@@ -580,7 +580,7 @@ func (v *S3Volume) EmptyTrash() {
 			continue
 		}
 		if trashT.Sub(recentT) < blobSignatureTTL {
-			if age := now.Sub(recentT); age >= blobSignatureTTL - v.raceWindow {
+			if age := startT.Sub(recentT); age >= blobSignatureTTL - v.raceWindow {
 				// recent/loc is too old to protect
 				// loc from being Trashed again during
 				// the raceWindow that starts if we
@@ -602,7 +602,7 @@ func (v *S3Volume) EmptyTrash() {
 				continue
 			}
 		}
-		if now.Sub(trashT) < trashLifetime {
+		if startT.Sub(trashT) < trashLifetime {
 			continue
 		}
 		err = v.Bucket.Del(trash.Key)
diff --git a/services/keepstore/s3_volume_test.go b/services/keepstore/s3_volume_test.go
index 0bb818c..8a06f19 100644
--- a/services/keepstore/s3_volume_test.go
+++ b/services/keepstore/s3_volume_test.go
@@ -122,7 +122,7 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 	v := NewTestableS3Volume(c, 5*time.Minute, false, 2)
 	var none time.Time
 
-	stubKey := func(t time.Time, key string, data []byte) {
+	putS3Obj := func(t time.Time, key string, data []byte) {
 		if t == none {
 			return
 		}
@@ -134,9 +134,9 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 	nextKey := 0
 	for _, scenario := range []struct {
 		label               string
-		data                time.Time
-		recent              time.Time
-		trash               time.Time
+		dataT               time.Time
+		recentT             time.Time
+		trashT              time.Time
 		canGet              bool
 		canTrash            bool
 		canGetAfterTrash    bool
@@ -159,42 +159,42 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 			true, true, true, false, false, false,
 		},
 		{
-			"Not trash; old enough to trash",
+			"Not trash, but old enough to be eligible for trash",
 			t0.Add(-24 * time.Hour), t0.Add(-2 * time.Hour), none,
 			true, true, false, false, false, false,
 		},
 		{
-			"Not trash; not old enough to trash",
+			"Not trash, and not old enough to be eligible for trash",
 			t0.Add(-24 * time.Hour), t0.Add(-30 * time.Minute), none,
 			true, true, true, false, false, false,
 		},
 		{
-			"Trash + not-trash: recent race between Trash and Put",
+			"Trashed + untrashed copies exist, due to recent race between Trash and Put",
 			t0.Add(-24 * time.Hour), t0.Add(-3 * time.Minute), t0.Add(-2 * time.Minute),
 			true, true, true, true, true, false,
 		},
 		{
-			"Trash + not-trash, nearly eligible for deletion, prone to Trash race",
+			"Trashed + untrashed copies exist, trash nearly eligible for deletion: prone to Trash race",
 			t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour), t0.Add(-59 * time.Minute),
 			true, false, true, true, true, false,
 		},
 		{
-			"Trash + not-trash, eligible for deletion, prone to Trash race",
+			"Trashed + untrashed copies exist, trash is eligible for deletion: prone to Trash race",
 			t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour), t0.Add(-61 * time.Minute),
 			true, false, true, true, false, false,
 		},
 		{
-			"Trash + not-trash, unsafe to empty; old race between Put and unfinished Trash",
+			"Trashed + untrashed copies exist, due to old race between Put and unfinished Trash: emptying trash is unsafe",
 			t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour), t0.Add(-12 * time.Hour),
 			true, false, true, true, true, true,
 		},
 		{
-			"Trash + not-trash, was unsafe to empty, but since made safe by fixRace+Touch",
+			"Trashed + untrashed copies exist, used to be unsafe to empty, but since made safe by fixRace+Touch",
 			t0.Add(-time.Second), t0.Add(-time.Second), t0.Add(-12 * time.Hour),
 			true, true, true, true, false, false,
 		},
 		{
-			"Trash operation was interrupted",
+			"Trashed + untrashed copies exist because Trash operation was interrupted (no race)",
 			t0.Add(-24 * time.Hour), t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour),
 			true, false, true, true, false, false,
 		},
@@ -233,19 +233,19 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 		// locator to prevent interference from previous
 		// tests.
 
-		setup := func() (string, []byte) {
+		setupScenario := func() (string, []byte) {
 			nextKey++
 			blk := []byte(fmt.Sprintf("%d", nextKey))
 			loc := fmt.Sprintf("%x", md5.Sum(blk))
 			c.Log("\t", loc)
-			stubKey(scenario.data, loc, blk)
-			stubKey(scenario.recent, "recent/"+loc, nil)
-			stubKey(scenario.trash, "trash/"+loc, blk)
+			putS3Obj(scenario.dataT, loc, blk)
+			putS3Obj(scenario.recentT, "recent/"+loc, nil)
+			putS3Obj(scenario.trashT, "trash/"+loc, blk)
 			v.serverClock.now = &t0
 			return loc, blk
 		}
 
-		loc, blk := setup()
+		loc, blk := setupScenario()
 		buf := make([]byte, len(blk))
 		_, err := v.Get(loc, buf)
 		c.Check(err == nil, check.Equals, scenario.canGet)
@@ -253,7 +253,7 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 			c.Check(os.IsNotExist(err), check.Equals, true)
 		}
 
-		loc, blk = setup()
+		loc, blk = setupScenario()
 		err = v.Trash(loc)
 		c.Check(err == nil, check.Equals, scenario.canTrash)
 		_, err = v.Get(loc, buf)
@@ -262,11 +262,11 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 			c.Check(os.IsNotExist(err), check.Equals, true)
 		}
 
-		loc, blk = setup()
+		loc, blk = setupScenario()
 		err = v.Untrash(loc)
 		c.Check(err == nil, check.Equals, scenario.canUntrash)
 
-		loc, blk = setup()
+		loc, blk = setupScenario()
 		v.EmptyTrash()
 		_, err = v.Bucket.Head("trash/"+loc, nil)
 		c.Check(err == nil, check.Equals, scenario.haveTrashAfterEmpty)

commit e59a5d4e33a4e3208b6f19e91fee37905fe5ca7a
Author: Tom Clegg <tom at curoverse.com>
Date:   Tue Jul 26 09:19:30 2016 -0400

    8555: Reformat test cases.

diff --git a/services/keepstore/s3_volume_test.go b/services/keepstore/s3_volume_test.go
index fb0bea2..0bb818c 100644
--- a/services/keepstore/s3_volume_test.go
+++ b/services/keepstore/s3_volume_test.go
@@ -147,7 +147,8 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 		{
 			"No related objects",
 			none, none, none,
-			false, false, false, false, false, false},
+			false, false, false, false, false, false,
+		},
 		{
 			// Stored by older version, or there was a
 			// race between EmptyTrash and Put: Trash is a
@@ -155,59 +156,73 @@ func (s *StubbedS3Suite) TestBackendStates(c *check.C) {
 			// old
 			"No recent/X",
 			t0.Add(-48 * time.Hour), none, none,
-			true, true, true, false, false, false},
+			true, true, true, false, false, false,
+		},
 		{
 			"Not trash; old enough to trash",
 			t0.Add(-24 * time.Hour), t0.Add(-2 * time.Hour), none,
-			true, true, false, false, false, false},
+			true, true, false, false, false, false,
+		},
 		{
 			"Not trash; not old enough to trash",
 			t0.Add(-24 * time.Hour), t0.Add(-30 * time.Minute), none,
-			true, true, true, false, false, false},
+			true, true, true, false, false, false,
+		},
 		{
 			"Trash + not-trash: recent race between Trash and Put",
 			t0.Add(-24 * time.Hour), t0.Add(-3 * time.Minute), t0.Add(-2 * time.Minute),
-			true, true, true, true, true, false},
+			true, true, true, true, true, false,
+		},
 		{
 			"Trash + not-trash, nearly eligible for deletion, prone to Trash race",
 			t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour), t0.Add(-59 * time.Minute),
-			true, false, true, true, true, false},
+			true, false, true, true, true, false,
+		},
 		{
 			"Trash + not-trash, eligible for deletion, prone to Trash race",
 			t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour), t0.Add(-61 * time.Minute),
-			true, false, true, true, false, false},
+			true, false, true, true, false, false,
+		},
 		{
 			"Trash + not-trash, unsafe to empty; old race between Put and unfinished Trash",
 			t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour), t0.Add(-12 * time.Hour),
-			true, false, true, true, true, true},
+			true, false, true, true, true, true,
+		},
 		{
 			"Trash + not-trash, was unsafe to empty, but since made safe by fixRace+Touch",
 			t0.Add(-time.Second), t0.Add(-time.Second), t0.Add(-12 * time.Hour),
-			true, true, true, true, false, false},
+			true, true, true, true, false, false,
+		},
 		{
 			"Trash operation was interrupted",
 			t0.Add(-24 * time.Hour), t0.Add(-24 * time.Hour), t0.Add(-12 * time.Hour),
-			true, false, true, true, false, false},
+			true, false, true, true, false, false,
+		},
 		{
 			"Trash, not yet eligible for deletion",
 			none, t0.Add(-12 * time.Hour), t0.Add(-time.Minute),
-			false, false, false, true, true, false},
+			false, false, false, true, true, false,
+		},
 		{
 			"Trash, not yet eligible for deletion, prone to races",
 			none, t0.Add(-12 * time.Hour), t0.Add(-59 * time.Minute),
-			false, false, false, true, true, false},
+			false, false, false, true, true, false,
+		},
 		{
 			"Trash, eligible for deletion",
 			none, t0.Add(-12 * time.Hour), t0.Add(-2 * time.Hour),
-			false, false, false, true, false, false},
+			false, false, false, true, false, false,
+		},
 		{
 			"Erroneously trashed during a race, detected before trashLifetime",
 			none, t0.Add(-30 * time.Minute), t0.Add(-29 * time.Minute),
-			true, false, true, true, true, false},
+			true, false, true, true, true, false,
+		},
 		{
 			"Erroneously trashed during a race, rescue during EmptyTrash despite reaching trashLifetime",
 			none, t0.Add(-90 * time.Minute), t0.Add(-89 * time.Minute),
-			true, false, true, true, true, false},
+			true, false, true, true, true, false,
+		},
 	} {
 		c.Log("Scenario: ", scenario.label)
 

-----------------------------------------------------------------------


hooks/post-receive
-- 




More information about the arvados-commits mailing list