We're finding that some of our pipelines take longer than we'd like to complete. In the UI we see timelines that look like the attached image. Notably, the gaps between our steps are significantly longer than the steps themselves, so I want to make sure I understand what these visualizations represent. Is it the case that: • green lines are user code • gray lines are user code plus writing artifacts • horizontal gaps between gray lines are things like waiting for a pod, spinning up a pod, pulling the image, etc. Can anyone offer advice on shrinking those gaps? We're using Argo Workflows.

@quiet-afternoon-68940 - kubernetes task startup delays can result from many different variables - 1. Is their enough capacity in your cluster to run the task immediately or is the cluster over-subscribed? 2. Assuming enough capacity, are you seeing any delays with pod placements from the kube-scheduler - it can be quite common if the scheduler hasn't been tuned appropriately for large clusters - (delays with pod assignment, poor packing of pods etc.) 3. Assuming pods are getting launched immediately, are there specific delays that you are able to observe with container spin up times? In our experience, we have seen delays add up across many layers of vanilla kubernetes - do you have any specific customizations in place? Those may or may not alter the latencies.

Thanks. I will look into these questions. So the gaps are all cluster-related delays? Artifact tracking is accounted for in the gray intervals?

Yep - all the gaps that you see between the gray lines should be all cluster related (and some delay attributed to wifi if you are running the workflow locally)

Is it possible to get a sanity check on what a 'reasonable' inter-step delay could/should be? If capacity was ample, scheduling was running smoothly, no massive artifacts to deserialise, what we should expect to see in a timeline? @square-wire-39606

In an ideal scenario, there shouldn’t be much gap between the gray lines if the deployment is properly configured and network bandwidth between local instance and the deployment is not a concern.

Thanks @square-wire-39606. So, say, ~10s gap (between gray lines) is feasible?

It is feasible depending on a multitude of factors, but highly undesirable.

Oh, I was using it as a reasonable best case scenario 😅

Reasonable scenario should be a sub second gap

Wow, okay. Thanks 🙂

Can you verify that your metadata service isn’t leading to any delays?

What's the best way to test that?

One other thing I would add is that we are seeing logs that appear to be inconsistent with the timeline visualization. For instance, we have the timeline says that the start step took 35.1s and the task took 17.6s, whereas the logs span 1m 58s.

when you say that the logs span 1m 58s - how are they getting timed? maybe it's best to jump on a quick call

This is the difference between the timestamp of the first log item (

Setting up task environment.

) and the last log line from user code

that shouldn't be the case - are you able to share the task metadata and the scrubbed loglines?

here's the basic skeleton of what we're seeing

2023-03-23 12:45:03 Setting up task environment.
2023-03-23 12:45:25 Downloading code package...
2023-03-23 12:45:26 Code package downloaded.
2023-03-23 12:45:26 Task is starting.
2023-03-23 12:46:23.395 Executing flow_decorator_1 flow_init() ...
2023-03-23 12:46:23.395 Setting schedule on branch *********** to ***********.
2023-03-23 12:46:23.395 Executing flow_decorator_2 flow_init() ...
2023-03-23 12:46:23.395 current.branch_name==***********, setting ENV_VAR to value.
2023-03-23 12:46:23.396 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:23.396 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:23.397 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:23.397 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:23.397 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:23.397 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:59.838 Executing flow_decorator_1 flow_init() ...
2023-03-23 12:46:59.839 Setting schedule on branch *********** to **********.
2023-03-23 12:46:59.839 Executing flow_decorator_2 flow_init() ...
2023-03-23 12:46:59.839 current.branch_name==***********, setting ENV_VAR to value.
2023-03-23 12:46:59.840 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:59.840 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:59.840 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:59.840 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:59.840 Executing step_decorator_1 step_init() ...
2023-03-23 12:46:59.841 Executing step_decorator_1 step_init() ...

it would be good to understand what's going on in the bigger gaps here: • 124503 to 124525 • 124526 to 124623.395 • 124623.397 to 124659.838 these runs are scheduled with Argo workflows, so I would be surprised if anyone's laptop were the problem.

interesting - do you have a list of all the decorators that are applied to this step?

These are custom decorators, yes (I replaced the real names). We have two decorators on the step, one is

@card

and the other does some exception handling.

what does the other decorator do in

step_init

?

the exception handling one? it just logs that message and assigns the logger to

self.logger

I have to jump into a meeting, but if you are around later in the am - we can nail down the source of delay - once you are in the task - things should be rather quick!

yes, a call would be great. I should be around at least through the end of the business day Eastern US time

invite sent!

(fwiw, we still have multi-minute gaps between step executions on flows that have no flow or step decorators applied)

Yep - that can because of multitude of reasons on the infrastructure side of the house. I can give a deep dive when we meet