Some timestamps need interpretation.
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 ElectricFlow Server is busy and doesn't get to the packet immediately - for example, during java (JRE) garbage collection.
- In ElectricFlow v3.10, the ElectricFlow server was changed to retry steps that open the workspace directory and fail. The retry change affected when the ElectricFlow Server records the step start times.
Use the first step "start" (/myParent/start) property and subtract the job "createTime" (/myJob/createTime) property.
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.
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;
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