Order Run Timings

Automation provides time result data for three use cases:

• Order run process timings.
• Node execution timings.
• Graphical process times for a recipe variation within a specific kitchen.

Note

Resume function creates a new order run. When a stopped or failed order run is resumed, the system puts the initial run into a Resumed state and starts a new order run to process the remaining nodes of the recipe variation. Note that the two order runs record separate timings and test results, and the initial run retains the Resumed status permanently.

View order run process time

The timings for an individual order run are accessible from the Order Run Details page in both graphical and text formats.

1. Navigate to the Order Run Details page.
2. For a graphical summary, click Timings Graph in the order run toolbar.
   • Note that the chart sorts nodes by start time. Parallel nodes sort by run duration, shortest first.
   • Hover your cursor over bars in the graph for more details.
3. For a text summary, click Show Details in the order run toolbar and expand the Timings section.

You can also find the order run start time and duration listed on the Orders page.

Visual example in Automation

Order run process time in the command line

Timings for an individual order run can be viewed via the orderrun-info command with the --timing option.

~ $ dk orderun-info --kitchen eric_dev -order_run_id 802213bc-3662-11e9-9f7b-0ad19868a29a --timing
Current context is: default
YYYY-MM-DD HH:MM:SS - Display Order-Run details from kitchen eric_dev

TIMING RESULTS

  DKRecipe timing (test_sources_sinks), status = DKNodeStatus_completed_production
   total recipe execution time|0:00:12.205
   Node (redshift_source_test), status = DKNodeStatus_completed_production, timing is||0:00:02.345
    (redshift_source_test) Data Source(redshift_datasource) timing is||0:00:01.312
     (redshift_source_test) Notebook elapsed time is|None
   Node (s3_source_test), status = DKNodeStatus_completed_production, timing is||0:00:03.922
    (s3_source_test) Data Source(s3_datasource) timing is||0:00:02.891
     (s3_source_test) Notebook elapsed time is|None
   Node (node_with_downstream_test), status = DKNodeStatus_completed_production, timing is||0:00:01.439
    (node_with_downstream_test) Data Source(redshift_datasource) timing is||0:00:00.411
     (node_with_downstream_test) Notebook elapsed time is|None

View node execution time

The Order Run Details page includes timing data in the Node Details for each graph node.

Select any node in the graph, then expand the Timings section.

View order run timings over time

Timing data is found as a tab of the Variation Metrics page.

Get graphical views of process timings over time and across multiple order runs and orders for a given kitchen-recipe-variation combination. This data is helpful for identifying outlier runs for further investigation.

1. Use one of the following to navigate to the Variation Metrics page:
   1. On the Orders page, click a Recipe/Variation link.
   2. On the Order Run Details page, click Variation Metrics over Time.
2. Select the Timings tab.

From the Timings tab, click an order run in the bar chart to see a breakdown of node durations in either bar or Gantt chart visualization.

Tip

Critical Path Identifies Bottlenecks: The Gantt chart view of node duration shows the longest path through graph processing as the "critical path." By highlighting the longest-running nodes at each level of a variation graph, the chart can help pinpoint processing problems.

Visual example in Automation