Historical node not able to download the segment from DeepStorage AWS S3

I’m using tranquility kafka, able to run the indexing task. But all the tasks are waiting to handoff the segment.

Historical node log:

2017-01-10T17:38:07,520 INFO [ZkCoordinator-0] io.druid.server.coordination.ZkCoordinator - zNode[/druid/loadQueue/10.2.1.42:8083/vnk-clst_2017-01-10T13:00:00.000Z_2017-01-10T14:00:00.000Z_2017-01-10T13:00:26.778Z] was removed

2017-01-10T17:38:37,370 INFO [ZkCoordinator-0] io.druid.server.coordination.ZkCoordinator - New request[LOAD: vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z] with zNode[/druid/loadQueue/10.2.1.42:8083/vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z].

2017-01-10T17:38:37,370 INFO [ZkCoordinator-0] io.druid.server.coordination.ZkCoordinator - Loading segment vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z

2017-01-10T17:38:37,390 INFO [ZkCoordinator-0] io.druid.storage.s3.S3DataSegmentPuller - Pulling index at path[s3://common-druid/staging/segments/vnk-clst/2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z/2017-01-10T16:00:19.742Z/0/index.zip] to outDir[var/druid/segment-cache/vnk-clst/2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z/2017-01-10T16:00:19.742Z/0]

2017-01-10T17:38:37,445 WARN [ZkCoordinator-0] io.druid.server.coordination.BatchDataSegmentAnnouncer - No path to unannounce segment[vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z]

2017-01-10T17:38:37,445 INFO [ZkCoordinator-0] io.druid.server.coordination.ZkCoordinator - Completely removing [vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z] in [30,000] millis

2017-01-10T17:38:37,446 INFO [ZkCoordinator-0] io.druid.server.coordination.ZkCoordinator - Completed request [LOAD: vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z]

2017-01-10T17:38:37,447 ERROR [ZkCoordinator-0] io.druid.server.coordination.ZkCoordinator - Failed to load segment for dataSource: {class=io.druid.server.coordination.ZkCoordinator, exceptionType=class io.druid.segment.loading.SegmentLoadingException, exceptionMessage=Exception loading segment[vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z], segment=DataSegment{size=25872160, shardSpec=LinearShardSpec{partitionNum=0}, metrics=[count, session_count, hyper_user_id], dimensions=[event_type, user_id, advertiser_id, session_id, version_name, os_name, os_version, device_brand, device_manufacturer, device_model, carrier, language, platform, sequence_number, lat, lng, country, city, region, device_id, gps_enabled, email, event_id, event_source, product_category, tinder_action, product_id, seller, Brand, isCouponAvailable, product_size, payment_status, vendor_order_id, seller_rating, like_status, payment_mode, product_images, line_items, order_id, refund_through, search_term, otp_confirmed_for, profile_menu, payment_method, quantity, revenue], version=‘2017-01-10T16:00:19.742Z’, loadSpec={type=s3_zip, bucket=common-druid, key=staging/segments/vnk-clst/2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z/2017-01-10T16:00:19.742Z/0/index.zip}, interval=2017-01-10T16:00:00.000Z/2017-01-10T17:00:00.000Z, dataSource=‘vnk-clst’, binaryVersion=‘9’}}

io.druid.segment.loading.SegmentLoadingException: Exception loading segment[vnk-clst_2017-01-10T16:00:00.000Z_2017-01-10T17:00:00.000Z_2017-01-10T16:00:19.742Z]

at io.druid.server.coordination.ZkCoordinator.loadSegment(ZkCoordinator.java:310) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ZkCoordinator.addSegment(ZkCoordinator.java:351) [druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.SegmentChangeRequestLoad.go(SegmentChangeRequestLoad.java:44) [druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ZkCoordinator$1.childEvent(ZkCoordinator.java:153) [druid-server-0.9.2.jar:0.9.2]

at org.apache.curator.framework.recipes.cache.PathChildrenCache$5.apply(PathChildrenCache.java:522) [curator-recipes-2.11.0.jar:?]

at org.apache.curator.framework.recipes.cache.PathChildrenCache$5.apply(PathChildrenCache.java:516) [curator-recipes-2.11.0.jar:?]

at org.apache.curator.framework.listen.ListenerContainer$1.run(ListenerContainer.java:93) [curator-framework-2.11.0.jar:?]

at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:297) [guava-16.0.1.jar:?]

at org.apache.curator.framework.listen.ListenerContainer.forEach(ListenerContainer.java:84) [curator-framework-2.11.0.jar:?]

at org.apache.curator.framework.recipes.cache.PathChildrenCache.callListeners(PathChildrenCache.java:513) [curator-recipes-2.11.0.jar:?]

at org.apache.curator.framework.recipes.cache.EventOperation.invoke(EventOperation.java:35) [curator-recipes-2.11.0.jar:?]

at org.apache.curator.framework.recipes.cache.PathChildrenCache$9.run(PathChildrenCache.java:773) [curator-recipes-2.11.0.jar:?]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_111]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_111]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_111]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_111]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_111]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_111]

at java.lang.Thread.run(Thread.java:745) [?:1.8.0_111]

Caused by: java.lang.RuntimeException: org.jets3t.service.ServiceException: Request Error. – ResponseCode: 403, ResponseStatus: Forbidden, RequestId: 36577DA5877CE531, HostId: 1LwbUy8khcqAiRZyDZ4aq7qUZSNKS0kNPApQOCBgQUBU/vKe5sPNvm2r+5U9wz6eB/fbNUrAhZA=

at com.google.common.base.Throwables.propagate(Throwables.java:160) ~[guava-16.0.1.jar:?]

at io.druid.storage.s3.S3DataSegmentPuller.isObjectInBucket(S3DataSegmentPuller.java:341) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller.getSegmentFiles(S3DataSegmentPuller.java:174) ~[?:?]

at io.druid.storage.s3.S3LoadSpec.loadSegment(S3LoadSpec.java:62) ~[?:?]

at io.druid.segment.loading.SegmentLoaderLocalCacheManager.getSegmentFiles(SegmentLoaderLocalCacheManager.java:143) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.segment.loading.SegmentLoaderLocalCacheManager.getSegment(SegmentLoaderLocalCacheManager.java:95) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ServerManager.loadSegment(ServerManager.java:152) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ZkCoordinator.loadSegment(ZkCoordinator.java:306) ~[druid-server-0.9.2.jar:0.9.2]

… 18 more

Caused by: org.jets3t.service.ServiceException: Request Error.

at org.jets3t.service.impl.rest.httpclient.RestStorageService.performRequest(RestStorageService.java:426) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.performRequest(RestStorageService.java:279) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.performRestHead(RestStorageService.java:1052) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.getObjectImpl(RestStorageService.java:2264) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.getObjectDetailsImpl(RestStorageService.java:2193) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.StorageService.getObjectDetails(StorageService.java:1120) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.StorageService.getObjectDetails(StorageService.java:575) ~[jets3t-0.9.4.jar:0.9.4]

at io.druid.storage.s3.S3Utils.isObjectInBucket(S3Utils.java:92) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller$4.call(S3DataSegmentPuller.java:332) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller$4.call(S3DataSegmentPuller.java:328) ~[?:?]

at com.metamx.common.RetryUtils.retry(RetryUtils.java:60) ~[java-util-0.27.10.jar:?]

at com.metamx.common.RetryUtils.retry(RetryUtils.java:78) ~[java-util-0.27.10.jar:?]

at io.druid.storage.s3.S3Utils.retryS3Operation(S3Utils.java:85) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller.isObjectInBucket(S3DataSegmentPuller.java:326) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller.getSegmentFiles(S3DataSegmentPuller.java:174) ~[?:?]

at io.druid.storage.s3.S3LoadSpec.loadSegment(S3LoadSpec.java:62) ~[?:?]

at io.druid.segment.loading.SegmentLoaderLocalCacheManager.getSegmentFiles(SegmentLoaderLocalCacheManager.java:143) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.segment.loading.SegmentLoaderLocalCacheManager.getSegment(SegmentLoaderLocalCacheManager.java:95) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ServerManager.loadSegment(ServerManager.java:152) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ZkCoordinator.loadSegment(ZkCoordinator.java:306) ~[druid-server-0.9.2.jar:0.9.2]

… 18 more

Caused by: org.jets3t.service.impl.rest.HttpException: 403 Forbidden

at org.jets3t.service.impl.rest.httpclient.RestStorageService.performRequest(RestStorageService.java:425) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.performRequest(RestStorageService.java:279) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.performRestHead(RestStorageService.java:1052) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.getObjectImpl(RestStorageService.java:2264) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.impl.rest.httpclient.RestStorageService.getObjectDetailsImpl(RestStorageService.java:2193) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.StorageService.getObjectDetails(StorageService.java:1120) ~[jets3t-0.9.4.jar:0.9.4]

at org.jets3t.service.StorageService.getObjectDetails(StorageService.java:575) ~[jets3t-0.9.4.jar:0.9.4]

at io.druid.storage.s3.S3Utils.isObjectInBucket(S3Utils.java:92) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller$4.call(S3DataSegmentPuller.java:332) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller$4.call(S3DataSegmentPuller.java:328) ~[?:?]

at com.metamx.common.RetryUtils.retry(RetryUtils.java:60) ~[java-util-0.27.10.jar:?]

at com.metamx.common.RetryUtils.retry(RetryUtils.java:78) ~[java-util-0.27.10.jar:?]

at io.druid.storage.s3.S3Utils.retryS3Operation(S3Utils.java:85) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller.isObjectInBucket(S3DataSegmentPuller.java:326) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller.getSegmentFiles(S3DataSegmentPuller.java:174) ~[?:?]

at io.druid.storage.s3.S3LoadSpec.loadSegment(S3LoadSpec.java:62) ~[?:?]

at io.druid.segment.loading.SegmentLoaderLocalCacheManager.getSegmentFiles(SegmentLoaderLocalCacheManager.java:143) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.segment.loading.SegmentLoaderLocalCacheManager.getSegment(SegmentLoaderLocalCacheManager.java:95) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ServerManager.loadSegment(ServerManager.java:152) ~[druid-server-0.9.2.jar:0.9.2]

at io.druid.server.coordination.ZkCoordinator.loadSegment(ZkCoordinator.java:306) ~[druid-server-0.9.2.jar:0.9.2]

… 18 more

Seems there it is a problem with s3 deep storage. Indexing tasks able to upload the data. I can see the segments in s3. Any help?

+1

I am still seeing this issue with Druid-0.10.0-rc2. Anyone able to find a fix for this?

I see the segments in deep storage but they aren’t being downloaded by the historical (same error as posted above).

Thanks,

Niketh

This bit over here looks like an error from the S3 API:

Caused by: java.lang.RuntimeException: org.jets3t.service.ServiceException: Request Error. – ResponseCode: 403, ResponseStatus: Forbidden, RequestId: 36577DA5877CE531, HostId: 1LwbUy8khcqAiRZyDZ4aq7qUZSNKS0kNPApQOCBgQUBU/vKe5sPNvm2r+5U9wz6eB/fbNUrAhZA=

I would say double check that all the S3 credentials are set up properly.

Gian,

I have double checked the configs, they seem to be correct. Here is the error again:

Caused by: java.lang.RuntimeException: org.jets3t.service.ServiceException: Request Error. – ResponseCode: 400, ResponseStatus: Bad Request, RequestId: 4FA73A0DD812C180, HostId: wSAz0GDSUAqQ6YfeQt4Sdz4HCKmGVuCWz51PlxuI78T732DpiwZYYSkm1o9AozIBZHgbIOcfyzg=

at com.google.common.base.Throwables.propagate(Throwables.java:160) ~[guava-16.0.1.jar:?]

at io.druid.storage.s3.S3DataSegmentPuller.isObjectInBucket(S3DataSegmentPuller.java:335) ~[?:?]

at io.druid.storage.s3.S3DataSegmentPuller.getSegmentFiles(S3DataSegmentPuller.java:175) ~[?:?]

at io.druid.storage.s3.S3LoadSpec.loadSegment(S3LoadSpec.java:60) ~[?:?]

at io.druid.segment.loading.SegmentLoaderLocalCacheManager.loadInLocation(SegmentLoaderLocalCacheManager.java:206) ~[druid-server-0.10.0-rc2.jar:0.10.0-rc2]

Thanks,

Niketh

I think if you turn on debug, or maybe trace logging, you’ll be able to see the request/response to S3 and that will help figure out what’s going on.

Also, Druid 0.10.0 final is out, so I would suggest using that instead of an RC. Not much has changed, but just for good form.