You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-issues@jackrabbit.apache.org by "Wim Symons (JIRA)" <ji...@apache.org> on 2018/11/06 12:50:00 UTC
[jira] [Commented] (OAK-7859) S3 Bucket iterator stops too early
[ https://issues.apache.org/jira/browse/OAK-7859?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16676717#comment-16676717 ]
Wim Symons commented on OAK-7859:
---------------------------------
Hi Amit,
We made the change to run collectGarbage(false, false), but the DSGC has significantly degraded in performance.
It now takes 3.5 hours instead of 1.5 minutes on our development instance.
Here is the output of the data of the BlobGarbageCollection MBean for that environment:
|GlobalMarkStats|
|org.apache.jackrabbit.oak.plugins.blob.BlobGC|
|markEndTime|markStartTime|numReferences|referenceFileSizeBytes|referencesFileSize|repositoryId|
|Tue Nov 06 12:00:36 UTC 2018|Tue Nov 06 12:00:35 UTC 2018|29040|2039209|2.0 MB|f1945c73-291f-4edd-81db-6f62f9830e9a *|
|Tue Nov 06 12:00:31 UTC 2018|Tue Nov 06 12:00:29 UTC 2018|24192|1692187|1.7 MB|fb62b285-8e18-4175-a032-eb2e8280f4e1|
|
During the first (false, false) run, it logged about 1.5 million errors like this:
{code:java}
05.11.2018 15:29:24.096 *WARN* [sling-oak-observation-1023] org.apache.jackrabbit.oak.plugins.blob.MarkSweepGarbageCollector Error occurred while deleting blob with id [ffff2233170c4a5055874998e065ab0996100ebe057244dbe86e984d3695290a#38263]
org.apache.jackrabbit.core.data.DataStoreException: com.amazonaws.services.s3.model.AmazonS3Exception: Not Found (Service: Amazon S3; Status Code: 404; Error Code: 404 Not Found; Request ID: 10F4F1117A8EFD06), S3 Extended Request ID: OaIZl7m5oh3Onzm7fqILYz3qwIv4ZRfkFFOuMUb2I+tSbGexRiEH10dEBdjayIiEb1Y/377NSyU=
at org.apache.jackrabbit.oak.blob.cloud.s3.S3Backend.getRecord(S3Backend.java:515)
at org.apache.jackrabbit.oak.plugins.blob.AbstractSharedCachingDataStore.getRecordForId(AbstractSharedCachingDataStore.java:435)
at org.apache.jackrabbit.oak.plugins.blob.datastore.DataStoreBlobStore.getRecordForId(DataStoreBlobStore.java:519)
at org.apache.jackrabbit.oak.plugins.blob.datastore.DataStoreBlobStore.countDeleteChunks(DataStoreBlobStore.java:425)
at org.apache.jackrabbit.oak.plugins.blob.MarkSweepGarbageCollector$BlobCollectionType$1.sweepInternal(MarkSweepGarbageCollector.java:736)
at org.apache.jackrabbit.oak.plugins.blob.MarkSweepGarbageCollector.sweep(MarkSweepGarbageCollector.java:400)
at org.apache.jackrabbit.oak.plugins.blob.MarkSweepGarbageCollector.markAndSweep(MarkSweepGarbageCollector.java:266)
at org.apache.jackrabbit.oak.plugins.blob.MarkSweepGarbageCollector.collectGarbage(MarkSweepGarbageCollector.java:178)
at org.apache.jackrabbit.oak.plugins.blob.BlobGC$2.call(BlobGC.java:103)
at org.apache.jackrabbit.oak.plugins.blob.BlobGC$2.call(BlobGC.java:99)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.amazonaws.services.s3.model.AmazonS3Exception: Not Found (Service: Amazon S3; Status Code: 404; Error Code: 404 Not Found; Request ID: 10F4F1117A8EFD06)
at com.amazonaws.http.AmazonHttpClient.handleErrorResponse(AmazonHttpClient.java:1389)
at com.amazonaws.http.AmazonHttpClient.executeOneRequest(AmazonHttpClient.java:902)
at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:607)
at com.amazonaws.http.AmazonHttpClient.doExecute(AmazonHttpClient.java:376)
at com.amazonaws.http.AmazonHttpClient.executeWithTimer(AmazonHttpClient.java:338)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:287)
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:3826)
at com.amazonaws.services.s3.AmazonS3Client.getObjectMetadata(AmazonS3Client.java:1015)
at com.amazonaws.services.s3.AmazonS3Client.getObjectMetadata(AmazonS3Client.java:991)
at org.apache.jackrabbit.oak.blob.cloud.s3.S3Backend.getRecord(S3Backend.java:502)
... 13 common frames omitted
{code}
I thought this would only happen during the first run, but the second run is doing exactly the same.
When I check the META folder of our datastore, it contains this:
!Screenshot 2018-11-06 at 13.44.15.png!
Any clue why this happens?
> S3 Bucket iterator stops too early
> ----------------------------------
>
> Key: OAK-7859
> URL: https://issues.apache.org/jira/browse/OAK-7859
> Project: Jackrabbit Oak
> Issue Type: Bug
> Components: blob-cloud
> Affects Versions: 1.6.6
> Reporter: Wim Symons
> Assignee: Amit Jain
> Priority: Critical
> Labels: newbie, pull-request-available
> Attachments: META-ids.txt, Screenshot 2018-11-06 at 13.44.15.png, dsgc-bis.zip, dsgc.log, meta-info.txt
>
>
> Fixed a major bug in the S3 bucket iterator.
> When the returned queue of records is empty due to the fact that we get a full page of records starting with the META/ key, the iterator stops while there is still data available in the bucket.
> This causes problems with datastore GC, and datastore consistency checks (both online and offline), and possibly even more.
> A little explainer. But based on a batch size of 2 instead of 1000.
> Suppose your list of S3 keys looks as follows:
> * 1
> * 2
> * 3
> * 4
> * META/1
> * META/2
> * 5
> * 6
> loadBatch would first load [1, 2], filter out no META/ keys and pass [1, 2] to the caller.
> Next time, loadBatch would load [3, 4], filter out no META/ keys and pass [3, 4] to the caller.
> Than, loadBatch would load [META/1, META/2], filter out the META/ keys and pass [] to the caller.
> When that happens, traversing the bucket would stop, because the returned list is empty, even if there are many more batches to load.
> The fix checks if the returned list is empty and there are more batches available, it would load (a) new batch(es) until there is data in the batch or there is no more batch available.
> We are currently running Oak 1.6.6 on AEM 6.3.1.2, but as the bug is still in trunk, all previous versions of Oak are affected as well.
> I provided 2 pull requests: one for trunk ([https://github.com/apache/jackrabbit-oak/pull/103)] and one for the 1.6 branch ([https://github.com/apache/jackrabbit-oak/pull/104).]
> CI failed on [https://github.com/apache/jackrabbit-oak/pull/103,] but I don't think it's related to my changes.
> For the record, the patch works as I was able to successfully test this on our production repository using oak-run --id. With version 1.6.6 it reported 800k items, with my patched version, it reported 1.8m items. (As our META/ nodes are listed somewhere half-way through.)
>
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)