Linux analysis of execution time with time

On Linux, the time command can be used to measure the execution time for a command line program. This article shows this with the example of the updatedb program.

call

The timecommand is simply given before the program to be executed when calling:

[root @ tpw ~] # time updatedb

real 1m5.682s
user 0m0.543s
sys 0m2.823s
[root @ tpw ~] # 

The program updatedb is a nice example here. It searches the entire file system for all files and writes the information to a small database. With the help of this database you can search for files later with the locate commands. This search is much faster than a normal search with the find command. However, the result does not reflect the current state, but the state of the database (last call of the updatedb command).

Since udpatedb searches the entire file system, resulting in very random I / O accesses, the CPU waits most of the time for I / O when updatingb is executed.

analysis

The individual values have the following meaning:

• real : Elapsed real time – the total actual execution time.
• user : Total number of CPU-seconds that the process spent in user mode – ie the time in which the CPU actually executes the (user) code of the program.
• sys : Total number of CPU-seconds that the process spent in kernel mode – the time when the CPU is busy executing kernel code for the program.

The rest of the time the CPU spends either with other programs or waiting for I / O. This also shows a parallel executed vmstat ,Example: CPU waits for IO :

[user @ tpw ~] $ vmstat 1 10
procs ----------- memory ---------- --- swap-- ----- io ---- --system-- ----- cpu -----
 rb swpd free buff cache si so bi bo in cs us sy id wa st
 3 1 3276 17544 109672 869900 0 0 62 180 812 1340 17 6 ​​75 2 0	
 1 1 3276 17000 110144 869900 0 0 464 76 815 1594 17 5 0 78 0	
 2 1 3276 16556 110552 869892 0 0 408 20 670 1415 2 5 0 93 0	
 0 1 3276 15980 111060 869936 0 0 508 0 844 1775 9 6 0 85 0	
 1 1 3276 15408 111524 869944 0 0 464 0 717 1592 5 4 0 91 0	
 0 1 3276 15000 111904 869976 0 0 372 12 627 1461 2 5 0 93 0	
 0 1 3276 15700 112788 869956 0 0 876 40 960 2177 5 7 0 88 0	
 0 1 3276 14420 113968 870136 0 0 1180 28 850 2020 5 11 0 84 0	
 0 1 3276 14628 115560 868288 0 0 1600 0 1281 2602 3 17 0 80 0	
 0 1 3276 14744 116996 866704 0 0 1696 0 1426 2806 7 19 0 74 0	
[user @ tpw ~] $