harinirajendran commented on issue #11414:
URL: https://github.com/apache/druid/issues/11414#issuecomment-875601615
> Hi @harinirajendran, thank you for your report. Was it only one task being
paused or all tasks for the same datasource? If it's the first case, then maybe
your guess is correct that there were lots of notices in the queue because the
task who initiated the checkpoint process pauses itself after it sends the
checkpoint request to the supervisor. If it's the second case, it means the
supervisor was already in processing of the checkpoint notice but hadn't
finished it yet. It was probably waiting for all tasks to respond to the pause
request or waiting for tasks to respond to the setEndOffset request (see
`SeekableStreamSupervisor.checkpointTaskGroup()`. One of our customers had a
similar issue at Imply before and the cause was frequent HTTP communication
failures which were retried with backoff.
@jihoonson : This long pause happens whenever a task requests a checkpoint
notice while task roll is happening for the same data source. So it happens
with all tasks requesting checkpoint notice while task roll is going on. In our
case, the tasks roll happens over a span of 5-6 minutes. Also, this ingestion
lag spike consistently only happens around task rolls which makes me think
these aren't because of HTTP communication issues.
Also, the timeline is as follows
time t1: task x pauses itself and initiates a checkpoint
request to the coordinator
time t1: coordinator receives the checkpoint notice and
adds it to the notices queue
time t1+2 minutes: coordinator sends a pause to the task
time t1+2 minutes: coordinator gets response to pause and then calls
setEndOffset(which in turn resumes the task)
So the coordinator processes the checkpoint notice and sends a pause only
after about 2 minutes.
Following is the log sequence for the same
```
Jun 21, 2021 @ 17:34:51.624 Performing action for task[<task_id>]:
CheckPointDataSourceMetadataAction{supervisorId='<supervisor_id>',
taskGroupId='14',
checkpointMetadata=KafkaDataSourceMetadata{SeekableStreamStartSequenceNumbers=SeekableStreamStartSequenceNumbers{stream='<kafka-topic>',
partitionSequenceNumberMap={104=238760642689, 14=337995870870},
exclusivePartitions=[]}}} coordinator-0
Jun 21, 2021 @ 17:34:51.624 Checkpointing
[KafkaDataSourceMetadata{SeekableStreamStartSequenceNumbers=SeekableStreamStartSequenceNumbers{stream='<kafka-topic>',
partitionSequenceNumberMap={104=238760642689, 14=337995870870},
exclusivePartitions=[]}}] for taskGroup [14] coordinator-0
Jun 21, 2021 @ 17:36:27.086 Pause task[<task_id>] coordinator-0
Jun 21, 2021 @ 17:36:27.087 HTTP POST:
http://<MMHost:MMport>/druid/worker/v1/chat/<task_id>/pause coordinator-0
Jun 21, 2021 @ 17:36:27.089 SetEndOffsets task[<task_id>]
endOffsets[{104=238763631003, 14=337998805846}] finalize[false] coordinator-0
Jun 21, 2021 @ 17:36:27.089 Task [<task_id>] paused successfully
coordinator-0
Jun 21, 2021 @ 17:36:27.091 HTTP POST:
http://<MMHost:MMport>/druid/worker/v1/chat/<task_id>/offsets/end?finish=false
coordinator-0
Jun 21, 2021 @ 17:36:27.097 Handled checkpoint notice, new checkpoint is
[{104=238763631003, 14=337998805846}] for taskGroup [14] coordinator-0
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
