Description
Some timestamps need interpretation.
Step start time
The start time of the step is the server time when the server reads the packet from the agent saying the step has started - not the time the Server asks the agent to start the step nor the agent time when it starts the step.
Knowing this information, there are several reasons the agent step could be running before the step start time is recorded.
-
The agent thread doesn’t get time immediately to send the network message because of a busy agent.
-
Delays in network packets
-
The CloudBees CD (CloudBees Flow) Server is busy and doesn’t get to the packet immediately - for example, during java (JRE) garbage collection.
-
In CloudBees CD (CloudBees Flow) v3.10, the CloudBees CD (CloudBees Flow) server was changed to retry steps that open the workspace directory and fail. The retry change affected when the CloudBees CD (CloudBees Flow) Server records the step start times.
Calculating time it takes to start a job
Use the first step "start" (/myParent/start) property and subtract the job "createTime" (/myJob/createTime) property.
Job Total Wait time is the sum of Resource and Workspace wait time for all steps
The total job wait time, totalWaitTime, is a sum of each of the step wait times.
If you drill down, you’ll see the "true" wait times for individual steps.
There are two parts of a step wait time, the resource wait and the workspace wait.
When you run parallel steps, their wait times are be summarized as well.
Job step duration and wait time trend report in SQL
Here is a SQL query (for Mysql) that will give the number of jobs, job steps, duration of job steps, and job step wait time by month.
First, it goes through the whole job step table and rolls up all the job step data by job ID. This is necessary for accurate counting because job steps and/or jobs may cross a month boundary and we don’t want to count them in more than one month. Then its just a matter of rolling all that job-level data by month.
SELECT job_step_start_year_month AS job_step_start_year_month, COUNT(job_id) AS num_jobs, SUM(num_job_steps) AS num_job_steps, SUM(job_step_duration_millis) AS job_step_duration_millis, SUM(job_step_wait_millis) AS job_step_wait_millisFROM(SELECT job_id, MIN(EXTRACT(YEAR_MONTH FROM start_time)) AS job_step_start_year_month, MIN(start_time) AS job_step_start_time, MAX(finish_time) AS job_step_finish_time, COUNT(0) AS num_job_steps, SUM(finish_millis-start_millis) AS job_step_duration_millis, SUM(start_millis-runnable_millis) AS job_step_wait_millis FROM ec_job_step WHERE parent_id IS NOT NULL GROUP BY job_id) job_stepsWHERE job_step_start_time BETWEEN '2009-01-01' AND '2009-12-31'GROUP BY job_step_start_year_monthORDER BY job_step_start_year_month;
Sample results
job_step_start_year_month num_jobs num_job_steps job_step_duration_millis job_step_wait_millis200910 48 48 905255 208722200911 47 47 4068123 49971200912 17 46 281313 460393