I m trying to setup Pinot with a custom PinotFS for deep sto Apache Pinot #troubleshooting

I’m trying to setup Pinot with a custom PinotFS fo...

Gerrit van Doorn

07/25/2022, 4:54 AM

I’m trying to setup Pinot with a custom PinotFS for deep store usage. It’s currently unimplemented and just logs the params to see what happens. I’m trying to configure Pinot to decouple the controller from the data path. For testing purposes I have set the

realtime.segment.flush.threshold.rows

to a low value. My assumption was that a server would try to copy data to the deep-store once a segment is completed. However, I’m not seeing the custom PinotFS being used in the server, other than init(..) being called. I do see it being called in the controller once I hit

realtime.segment.flush.threshold.rows

. Shouldn’t I see the server doing this instead of the controller?

Mayank

07/25/2022, 4:57 AM

https://docs.pinot.apache.org/operators/operating-pinot/decoupling-controller-from-the-data-path

Gerrit van Doorn

07/25/2022, 4:57 AM

NOTE: I’m just using a single controller, server, broker setup. The configs look like: controller.cfg:

Copy code

controller.helix.cluster.name=PinotCluster
controller.port=9000
controller.vip.host=manual-pinot-controller
controller.vip.port=9000
pinot.set.instance.id.to.hostname=true
controller.zk.str=manual-pinot-zookeeper:2181


controller.data.dir=<os://FOO_BAR/data>
controller.local.temp.dir=/tmp/data/controller/temp
controller.enable.split.commit=true
pinot.controller.storage.factory.class.os=foo.bar.CustomStorePinotFS
pinot.controller.segment.fetcher.protocols=file,http,s3,os
controller.allow.hlc.tables=false
controller.enable.split.commit=true
controller.realtime.segment.deepStoreUploadRetryEnabled=true

server.cfg:

Copy code

pinot.cluster.name=PinotCluster
pinot.server.instance.realtime.alloc.offheap=true
pinot.set.instance.id.to.hostname=true
pinot.zk.server=manual-pinot-zookeeper:2181
pinot.server.netty.port=7000
pinot.server.adminapi.port=7500
pinot.server.instance.dataDir=/tmp/data/pinotServerData
pinot.server.instance.segmentTarDir=/var/pinot/pinotSegments
pinot.server.segment.fetcher.protocols=file,http,s3,os
pinot.server.instance.segment.store.uri=<os://FOO_BAR/data>
pinot.server.segment.fetcher.os.class=org.apache.pinot.common.utils.fetcher.PinotFSSegmentFetcher
pinot.server.instance.enable.split.commit=true
pinot.server.storage.factory.class.os=foo.bar.CustomStorePinotFS

Gerrit van Doorn

07/25/2022, 4:58 AM

Thanks. I’m familiar with that doc

Mayank

07/25/2022, 4:59 AM

I think that feature needs to be on for the server to directly copy data to deepstore. Without that, server uploads to controller, that copies to deepstore.

Mayank

07/25/2022, 5:01 AM

IIRC, we were discussing to decouple the two (peer download, and removing controller from the data path.

Gerrit van Doorn

07/25/2022, 5:04 AM

The behavior I’m seeing is that the controller checks if the directory exists on the deep store, if not, it uses copyFromLocalFile to copy the segment data. I was expecting something like that to show up in the server log instead, but maybe I’m misunderstanding the expected behavior

Gerrit van Doorn

07/25/2022, 5:09 AM

I base that on reading “When this is enabled, the Pinot servers will attempt to upload the completed segment to the segment store directly, thus by-passing the controller. Once this is finished, it will update the controller with the corresponding segment metadata.” I’m just wondering if I’m missing some configuration option(s)

Mayank

07/25/2022, 5:10 AM

What do you see in the server log (server startup) for how PinotFs was initialized?

Gerrit van Doorn

07/25/2022, 5:13 AM

Copy code

$ less logs/pinot-server.log | grep PinotFS
2022/07/25 04:41:37.254 INFO [DefaultHelixStarterServerConfig] [Start a Pinot [SERVER]] External config key: pinot.server.storage.factory.class.os, value: foo.bar.CustomStorePinotFS
2022/07/25 04:41:37.255 INFO [DefaultHelixStarterServerConfig] [Start a Pinot [SERVER]] External config key: pinot.server.segment.fetcher.os.class, value: org.apache.pinot.common.utils.fetcher.PinotFSSegmentFetcher
2022/07/25 04:41:38.535 INFO [PinotFSFactory] [Start a Pinot [SERVER]] Did not find any fs classes in the configuration
2022/07/25 04:41:38.536 INFO [PinotFSFactory] [Start a Pinot [SERVER]] Got scheme os, initializing class foo.bar.CustomStorePinotFS
2022/07/25 04:41:38.536 INFO [PinotFSFactory] [Start a Pinot [SERVER]] Initializing PinotFS for scheme os, classname foo.bar.CustomStorePinotFS
2022/07/25 04:41:38.541 INFO [CustomStorePinotFS] [Start a Pinot [SERVER]] INIT Configuration: {"empty":true,"keys":[]}
2022/07/25 04:41:39.048 INFO [PinotFSSegmentFetcher] [Start a Pinot [SERVER]] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5
2022/07/25 04:41:39.049 INFO [PinotFSSegmentFetcher] [Start a Pinot [SERVER]] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5
2022/07/25 04:41:39.053 INFO [PinotFSSegmentFetcher] [Start a Pinot [SERVER]] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5
2022/07/25 04:41:39.055 INFO [SegmentFetcherFactory] [Start a Pinot [SERVER]] Creating segment fetcher for protocol: os with class: org.apache.pinot.common.utils.fetcher.PinotFSSegmentFetcher
2022/07/25 04:41:39.056 INFO [PinotFSSegmentFetcher] [Start a Pinot [SERVER]] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5

Gerrit van Doorn

07/25/2022, 5:20 AM

controller log looks like:

Copy code

$ less logs/pinot-controller.log | grep PinotFS
2022/07/25 04:41:38.804 INFO [BaseControllerStarter] [main] Initializing PinotFSFactory
2022/07/25 04:41:38.805 INFO [PinotFSFactory] [main] Did not find any fs classes in the configuration
2022/07/25 04:41:38.805 INFO [PinotFSFactory] [main] Got scheme os, initializing class foo.bar.CustomStorePinotFS
2022/07/25 04:41:38.805 INFO [PinotFSFactory] [main] Initializing PinotFS for scheme os, classname foo.bar.CustomStorePinotFS
2022/07/25 04:41:38.806 INFO [CustomStorePinotFS] [main] INIT Configuration: {"empty":false,"keys":["someconfigparam"]}
2022/07/25 04:41:39.274 INFO [CustomStorePinotFS] [main] EXISTS: <os://FOO_BAR/data>
2022/07/25 04:41:39.274 INFO [CustomStorePinotFS] [main] MKDIR: <os://FOO_BAR/data>
2022/07/25 04:41:39.671 INFO [PinotFSSegmentFetcher] [main] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5
2022/07/25 04:41:39.672 INFO [PinotFSSegmentFetcher] [main] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5
2022/07/25 04:41:39.674 INFO [PinotFSSegmentFetcher] [main] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5
2022/07/25 04:41:39.674 INFO [PinotFSSegmentFetcher] [main] Initialized with retryCount: 3, retryWaitMs: 100, retryDelayScaleFactor: 5
2022/07/25 04:44:08.745 INFO [CustomStorePinotFS] [pool-7-thread-3] EXISTS: <os://FOO_BAR/data/Deleted_Segments>
2022/07/25 04:45:30.402 INFO [CustomStorePinotFS] [grizzly-http-server-7] EXISTS: <os://FOO_BAR/data/event/event__0__0__20220725T0443Z>
2022/07/25 04:45:30.402 INFO [CustomStorePinotFS] [grizzly-http-server-7] COPY_FROM_LOCAL_FILE: /tmp/data/controller/temp/fileUploadTemp/event__0__0__20220725T0443Z.88d75c1d-312a-4659-83b3-997c093273fe => <os://FOO_BAR/data/event/event__0__0__20220725T0443Z>

saurabh dubey

07/25/2022, 5:40 AM

@Gerrit van Doorn Just checking if you've set

peerSegmentDownloadScheme

in your realtime table config? https://docs.pinot.apache.org/operators/operating-pinot/decoupling-controller-from-the-data-path#table-config

Gerrit van Doorn

07/25/2022, 5:56 AM

I did, segment config looks as follows:

Copy code

"segmentsConfig": {
    "schemaName": "event",
    "timeColumnName": "timestamp_nsec",
    "timeType": "NANOSECONDS",
    "segmentPushType": "APPEND",
    "segmentPushFrequency": "hourly",
    "segmentAssignmentStrategy": "BalanceNumSegmentAssignmentStrategy",
    "peerSegmentDownloadScheme": "http",
    "replication": "1",
    "replicasPerPartition": "1",
    "retentionTimeUnit": "DAYS",
    "retentionTimeValue": "90"
  },

Mayank

07/25/2022, 1:18 PM

Seems like server is initialized correctly. In your case did the server actually flush a segment yet?

Gerrit van Doorn

07/25/2022, 2:31 PM

It has one segment marked as "online" and I can see it on disk

Mayank

07/25/2022, 5:57 PM

Do you see it on deep-store? If so, check server log with the segment name to see if server pushed it to deep-store or controller.

Gerrit van Doorn

07/25/2022, 6:01 PM

The deep store PinotFS implementation is currently just a placeholder with log statements. On the server I only see the .init(..) method being logged. However, on the controller I see the following log statements from that placeholder once a segment is created:

Copy code

2022/07/25 17:59:47.614 INFO [ObjectStorePinotFS] [grizzly-http-server-15] EXISTS: <os://FOO_BAR/poc/data/event/event__0__4__20220725T1655Z>
2022/07/25 17:59:47.614 INFO [ObjectStorePinotFS] [grizzly-http-server-15] COPY_FROM_LOCAL_FILE: /tmp/data/controller/temp/fileUploadTemp/event__0__4__20220725T1655Z.5ede3bf1-d2e2-4c97-82a8-26543272d9eb => <os://FOO_BAR/poc/data/event/event__0__4__20220725T1655Z>

Which seems to indicate that it’s going through the controller

Gerrit van Doorn

07/25/2022, 6:04 PM

On the server side I see:

Copy code

2022/07/25 17:59:47.586 INFO [LLRealtimeSegmentDataManager_event__0__4__20220725T1655Z] [event__0__4__20220725T1655Z] Successfully built segment in 453 ms, after lockWaitTime 0 ms
2022/07/25 17:59:47.666 INFO [FileUploadDownloadClient] [event__0__4__20220725T1655Z] Sending request: <http://7a2ea5c28b93:9000/segmentCommit?segmentSizeBytes=98319&buildTimeMillis=453&streamPartitionMsgOffset=21&instance=Server_19a4597cd85c_7000&offset=-1&name=event__0__4__20220725T1655Z&rowCount=5&memoryUsedBytes=33668> to controller: 7a2ea5c28b93, version: Unknown
2022/07/25 17:59:47.666 INFO [ServerSegmentCompletionProtocolHandler] [event__0__4__20220725T1655Z] Controller response {"offset":-1,"streamPartitionMsgOffset":null,"buildTimeSec":-1,"isSplitCommitType":false,"status":"COMMIT_SUCCESS"} for <http://7a2ea5c28b93:9000/segmentCommit?segmentSizeBytes=98319&buildTimeMillis=453&streamPartitionMsgOffset=21&instance=Server_19a4597cd85c_7000&offset=-1&name=event__0__4__20220725T1655Z&rowCount=5&memoryUsedBytes=33668>

Jackie

07/25/2022, 10:08 PM

"isSplitCommitType":false

seems split commit is somehow not enabled

Jackie

07/25/2022, 10:08 PM

What's the pinot version that you are running?

Gerrit van Doorn

07/25/2022, 10:09 PM

ooh right, interesting, totally read over that. I’m using 0.10.0

Jackie

07/25/2022, 10:20 PM

I don't know if it has any side effect, but

controller.enable.split.commit=true

is configured twice in the controller config

Gerrit van Doorn

07/25/2022, 10:23 PM

😮 that fixed it!

Jackie

07/25/2022, 10:24 PM

Really?!

Gerrit van Doorn

07/25/2022, 10:24 PM

thanks for suggesting that. I would not have thought that would be the issue

Gerrit van Doorn

07/25/2022, 10:25 PM

yeah, removed from config, restarted both controller and server and seeing the server trying to copy now.

Jackie

07/25/2022, 10:33 PM

I think I know the reason. Configuring the same fields twice will be treated as multiple values, and then pinot will try to parse it as

controller.enable.split.commit=true,true

, which returns

false

😅

Mayank

07/25/2022, 10:44 PM

Could we file an issue to address this @Jackie?

👍 1

Jackie

07/25/2022, 10:56 PM

https://github.com/apache/pinot/issues/9102

🙏 2

Open in Slack

Previous Next