Merge ~cjwatson/launchpad:librarian-gc-delete-tolerate-404 into launchpad:master

Proposed by Colin Watson
Status: Merged
Approved by: Colin Watson
Approved revision: 6239cad5bf1ee47f8f8ba0cb4cc951a98ad04d1f
Merge reported by: Otto Co-Pilot
Merged at revision: not available
Proposed branch: ~cjwatson/launchpad:librarian-gc-delete-tolerate-404
Merge into: launchpad:master
Diff against target: 142 lines (+81/-6)
3 files modified
lib/lp/services/librarianserver/librariangc.py (+5/-1)
lib/lp/services/librarianserver/tests/test_gc.py (+60/-0)
lib/lp/testing/swift/fakeswift.py (+16/-5)
Reviewer Review Type Date Requested Status
Tom Wardill (community) Approve
Review via email: mp+389749@code.launchpad.net

Commit message

Ignore 404 when deleting unwanted Swift files

Description of the change

librarian-gc has been consistently failing for some time with the following pattern:

  2020-08-19 03:22:44 DEBUG http://10.34.0.139:8080 "GET /v1/AUTH_xxx/librarian_6539?format=json&marker=3269994338 HTTP/1.1" 200 552359
  2020-08-19 03:22:44 DEBUG http://10.34.0.139:8080 "GET /v1/AUTH_xxx/librarian_6539?format=json&marker=3269999999 HTTP/1.1" 200 2
  2020-08-19 03:22:45 DEBUG http://10.34.0.139:8080 "DELETE /v1/AUTH_xxx/librarian_6539/3269500785 HTTP/1.1" 401 131
  2020-08-19 03:22:46 DEBUG http://10.34.0.136:5000 "POST /v2.0/tokens HTTP/1.1" 200 3410
  2020-08-19 03:22:46 DEBUG http://10.34.0.139:8080 "DELETE /v1/AUTH_xxx/librarian_6539/3269500785 HTTP/1.1" 404 70

The DELETE may happen in a different swiftclient.client.Connection instance from the GETs, and the sequence of GETs to enumerate all the files in Swift up to that point takes almost two hours on production at the moment which is longer than Keystone's default token expiry time of one hour, so it makes sense that the first DELETE might return 401. However, it's not at all clear why the retried DELETE of the same object gets 404 (nothing else in librarian-gc seems to have deleted that object). Although I'm concerned about this odd pattern, I've been unable to reproduce this with the same version of Swift, so perhaps it's best to just ignore it (since DELETE returning 404 still at least indicates that the object is no longer present) and allow librarian-gc to run to completion.

To post a comment you must log in.
Revision history for this message
Tom Wardill (twom) :
review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
diff --git a/lib/lp/services/librarianserver/librariangc.py b/lib/lp/services/librarianserver/librariangc.py
index 88c9af9..a16e769 100644
--- a/lib/lp/services/librarianserver/librariangc.py
+++ b/lib/lp/services/librarianserver/librariangc.py
@@ -832,7 +832,11 @@ def delete_unwanted_swift_files(con):
832 "File %d not removed - created too recently", content_id)832 "File %d not removed - created too recently", content_id)
833 else:833 else:
834 with swift.connection() as swift_connection:834 with swift.connection() as swift_connection:
835 swift_connection.delete_object(container, name)835 try:
836 swift_connection.delete_object(container, name)
837 except swiftclient.ClientException as e:
838 if e.http_status != 404:
839 raise
836 log.debug3(840 log.debug3(
837 'Deleted ({0}, {1}) from Swift'.format(container, name))841 'Deleted ({0}, {1}) from Swift'.format(container, name))
838 removed_count += 1842 removed_count += 1
diff --git a/lib/lp/services/librarianserver/tests/test_gc.py b/lib/lp/services/librarianserver/tests/test_gc.py
index d59dde0..71fb0c4 100644
--- a/lib/lp/services/librarianserver/tests/test_gc.py
+++ b/lib/lp/services/librarianserver/tests/test_gc.py
@@ -25,6 +25,8 @@ import tempfile
2525
26from fixtures import MockPatchObject26from fixtures import MockPatchObject
27import pytz27import pytz
28import requests
29from six.moves.urllib.parse import urljoin
28from sqlobject import SQLObjectNotFound30from sqlobject import SQLObjectNotFound
29from storm.store import Store31from storm.store import Store
30from swiftclient import client as swiftclient32from swiftclient import client as swiftclient
@@ -855,6 +857,64 @@ class TestSwiftLibrarianGarbageCollection(
855 self.assertFalse(self.file_exists(f1_id))857 self.assertFalse(self.file_exists(f1_id))
856 self.assertTrue(self.file_exists(f2_id))858 self.assertTrue(self.file_exists(f2_id))
857859
860 def test_delete_unwanted_files_handles_missing(self):
861 # GC tolerates a file being already missing from Swift when it tries
862 # to delete it. It's not clear why this happens in practice.
863 switch_dbuser('testadmin')
864 content = b'uploading to swift'
865 f1_lfa = LibraryFileAlias.get(self.client.addFile(
866 'foo.txt', len(content), io.BytesIO(content), 'text/plain'))
867 f1_id = f1_lfa.contentID
868
869 f2_lfa = LibraryFileAlias.get(self.client.addFile(
870 'bar.txt', len(content), io.BytesIO(content), 'text/plain'))
871 f2_id = f2_lfa.contentID
872 transaction.commit()
873
874 for lfc_id in (f1_id, f2_id):
875 # Make the files old so they don't look in-progress.
876 os.utime(swift.filesystem_path(lfc_id), (0, 0))
877
878 switch_dbuser(config.librarian_gc.dbuser)
879
880 swift.to_swift(BufferLogger(), remove_func=os.unlink)
881
882 # Both files exist in Swift.
883 self.assertTrue(self.file_exists(f1_id))
884 self.assertTrue(self.file_exists(f2_id))
885
886 # Remove the first file from the DB.
887 content = f1_lfa.content
888 Store.of(f1_lfa).remove(f1_lfa)
889 Store.of(content).remove(content)
890 transaction.commit()
891
892 # In production, we see a sequence of DELETE 401 / authenticate /
893 # DELETE 404. Since it isn't clear why this happens, we don't know
894 # exactly how to simulate it here, but do our best by deleting the
895 # object and forcibly expiring the client's token just before the
896 # first expected DELETE.
897 real_delete_object = swiftclient.Connection.delete_object
898
899 def fake_delete_object(connection, *args, **kwargs):
900 real_delete_object(connection, *args, **kwargs)
901 self.assertIsNotNone(connection.token)
902 requests.delete(urljoin(
903 config.librarian_server.os_auth_url,
904 'tokens/%s' % connection.token))
905 return real_delete_object(connection, *args, **kwargs)
906
907 self.patch(
908 swiftclient.Connection, 'delete_object', fake_delete_object)
909
910 # delete_unwanted_files completes successfully, and the second file
911 # is intact.
912 with self.librariangc_thinking_it_is_tomorrow():
913 swift.quiet_swiftclient(
914 librariangc.delete_unwanted_files, self.con)
915 self.assertFalse(self.file_exists(f1_id))
916 self.assertTrue(self.file_exists(f2_id))
917
858918
859class TestBlobCollection(TestCase):919class TestBlobCollection(TestCase):
860 layer = LaunchpadZopelessLayer920 layer = LaunchpadZopelessLayer
diff --git a/lib/lp/testing/swift/fakeswift.py b/lib/lp/testing/swift/fakeswift.py
index 86716cd..3536326 100644
--- a/lib/lp/testing/swift/fakeswift.py
+++ b/lib/lp/testing/swift/fakeswift.py
@@ -74,8 +74,8 @@ class FakeKeystone(resource.Resource):
74 def getValidToken(self, tenant_name, expected_token=None):74 def getValidToken(self, tenant_name, expected_token=None):
75 """Get a valid token for the given tenant name."""75 """Get a valid token for the given tenant name."""
76 if expected_token is not None:76 if expected_token is not None:
77 token = self.tokens[expected_token]77 token = self.tokens.get(expected_token)
78 if self._isValidToken(token, tenant_name):78 if token is not None and self._isValidToken(token, tenant_name):
79 return token79 return token
80 else:80 else:
81 for id, token in six.iteritems(self.tokens):81 for id, token in six.iteritems(self.tokens):
@@ -100,10 +100,21 @@ class FakeKeystone(resource.Resource):
100 valid_token = self.getValidToken(tenant_name, token)100 valid_token = self.getValidToken(tenant_name, token)
101 return valid_token is not None101 return valid_token is not None
102102
103 def getChild(self, path, request):103 def getChild(self, name, request):
104 """See `twisted.web.resource.Resource.getChild`."""104 """See `twisted.web.resource.Resource.getChild`."""
105 if path in (b"v2.0", b"tokens"):105 if name in (b"v2.0", b"tokens"):
106 return self106 return self
107
108 token = self.tokens.get(name, None)
109
110 if request.method == b"DELETE":
111 if not self.validateToken(request, token["tenant"]["name"]):
112 return EmptyPage(http.UNAUTHORIZED)
113 if token is None: # delete unknown token
114 return EmptyPage(http.NOT_FOUND)
115 del self.tokens[name]
116 return EmptyPage(http.NO_CONTENT)
117
107 return resource.NoResource("Not a valid keystone URL.")118 return resource.NoResource("Not a valid keystone URL.")
108119
109 def render_POST(self, request):120 def render_POST(self, request):
@@ -531,7 +542,7 @@ class FakeSwift(resource.Resource):
531 return resource542 return resource
532543
533 if not self.root.keystone.validateToken(request, tenant_name):544 if not self.root.keystone.validateToken(request, tenant_name):
534 return EmptyPage(http.FORBIDDEN)545 return EmptyPage(http.UNAUTHORIZED)
535546
536 return resource547 return resource
537548

Subscribers

People subscribed via source and target branches

to status/vote changes: