[Linux Time Command Learning Article] timing statistics command execution times

Note: The command must be followed by a semicolon;

http://codingstandards.iteye.com/blog/798788 Application Notes

The time command is often used to measure the runtime of a command, noting that it is not used to display and modify system time (this is what the Date command did). But today, by looking at the man page of the time command, I found out that it can do more than just measuring the runtime, but it can also measure memory, I/O, and so on, and the manual page says time a simple command or give resource usage, Where time is the term I think it should be measured or measured meaning, and not only refers to the timing. The system resources that a program uses at runtime typically include CPU, memory, and I/O, where CPU resources are counted for real time, User state usage (the process spent in user mode), and kernel State usage time (the Process spent in kernel mode). But the simple use of the time command does not get the statistics of memory and I/O, please look at the following text slowly.

Common parameters

The most common use of the time command is to follow the commands and parameters directly on the subsequent face:

Time <command> [<arguments...>]

After the command execution is complete, the CPU usage is printed:

Real 0m5.064s <== actual use (real time)
User 0m0.020s <== Usage time (the process spent in user mode)
SYS 0m0.040s <== kernel state usage time (the process spent in kernel mode)

The time command, followed by the-p parameter, can print only the number of seconds, not printing units.

Using the example example one statistic run time

[[Email protected] root]# time find. -name "Mysql.sh"
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh

Real 0m14.837s
User 0m0.030s
SYS 0m0.120s
[Email protected] root]#

Note: Real is much larger than user plus sys because find needs to traverse the directories, require a lot of I/O operations, and disk I/O is usually the slowest link, so most of the time the find process waits for disk I/O to complete.

[[Email protected] root]# time find. -name "Mysql.sh"
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh

Real 0m0.230s
User 0m0.040s
SYS 0m0.030s

Note: When running again, it is found that real time is becoming very small and should be the reason why the operating system caches some of the files that have just been manipulated, thus greatly reducing disk I/O.
[[email protected] root]# time-p find. -name "Mysql.sh"
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh
Real 0.15
User 0.04
SYS 0.03

Note: When using the-p parameter, the numeric value of the time required to print directly, in seconds, rather than in a more friendly format, including the display of minutes and seconds.
[Email protected] root]#

Example two Linux systems the time command actually has more than one

Friends who have read the manual page will find that there is an-f parameter to specify the output format of the statistics, so let's try it.

[Email protected] root]# time-f "real%f\nuser%f\nsys%f\n" find. -name "Mysql.sh"
-bash:-f:command not found

Real 0m0.024s
User 0m0.000s
SYS 0m0.000s

Strange, not spiritual. Take a look at it with type-a. Using this shell built-in command often has unexpected discoveries.

[Email protected] root]# type-a time
Time is a shell keyword
Time Is/usr/bin/time

Note: With this command we can find that the time we use is actually a shell keyword, and an external command/usr/bin/time, how is it different?
[Email protected] root]#/usr/bin/time
Usage:/usr/bin/time [-APVV] [-f format] [-o file] [--append] [--verbose]
[--portability] [--format=format] [--output=file] [--version]
[--help] command [arg ...]

Note: External command/usr/bin/time is more powerful, try it out below.

[[email protected] root]#/usr/bin/time find. -name "Mysql.sh"
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh
0.03user 0.04system 0:00.12elapsed 55%cpu (0avgtext+0avgdata 0maxresident) k
0inputs+0outputs (154major+63minor) pagefaults 0swaps

Note: Pay attention to the next two lines, print a lot of information, but see not very clear. It has a parameter-V, which can be printed more clearly.
[[email protected] root]#/usr/bin/time-v find. -name "Mysql.sh"
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh
Command being timed: "Find. -name mysql.sh "
User Time (seconds): 0.03
System Time (seconds): 0.05
Percent of CPU This job got:47%
Elapsed (Wall Clock) time (H:MM:SS or M:SS): 0:00.17
Average shared Text Size (Kbytes): 0
Average unshared Data Size (Kbytes): 0
Average stack size (Kbytes): 0
Average Total size (Kbytes): 0
Maximum resident set Size (Kbytes): 0
Average resident set Size (Kbytes): 0
Major (requiring I/O) page faults:153
Minor (Reclaiming a frame) page faults:64
Voluntary context switches:0
Involuntary context switches:0
swaps:0
File system inputs:0
File system outputs:0
Socket Messages sent:0
Socket Messages received:0
Signals delivered:0
Page size (bytes): 4096
Exit status:0
[Email protected] root]#

After trying to finish this, I looked at the results of Google search, found that a shrimp has already found the secret, see the relevant information "1".

Example three addresses redirection of time command output information

The output information of the time command is printed on the standard error output, and we validate it with a simple attempt.

[[Email protected] root]# time find. -name "mysql.sh" >1.txt

Real 0m0.081s
User 0m0.060s
SYS 0m0.020s
[[Email protected] root]# time find. -name "mysql.sh" 2>2.txt
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh

Real 0m0.068s
User 0m0.040s
SYS 0m0.030s

Through the above attempt, it was found that the output information of time could not be redirected to the file, why? Because time is the shell's keyword, the shell makes a special deal, and it handles the command line as a whole at the back of the command, which, when redirected, is actually directed at the subsequent command, and the output of the command itself is not redirected. So what do we do now? There are two solutions "2,3" available on the web, so let's try one by one.

The first solution is to put the time command and the command line that will be executed in a shell code block, which is a pair of curly braces, and pay attention to the use of spaces and semicolons.
[[email protected] root]# {time find-name "mysql.sh"} 2>2.txt

Seems to have succeeded. Slow down, look right.
[email protected] root]# cat 2.txt
-bash: {Time:command not found

The original bash has {time as a whole to deal with, and before and after the space to try.
[[email protected] root]# {time find-name "mysql.sh"} 2>2.txt
> CTRL + C

This time bash does not think the command is complete, and the semicolon is missing. Because Bash believes that the following} is a parameter to the Find command.
[[email protected] root]# {time find-name "mysql.sh";} 2>2.txt
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh
[email protected] root]# cat 2.txt

Real 0m0.068s
User 0m0.030s
SYS 0m0.040s

The first attempt succeeded, summing up is {time command-line;} 2>file note the use of separators.

Another way is to use the child shell, as follows:

[[Email protected] root]# (Time find-name "mysql.sh") 2>2.txt
./work186/sms/bin/mysql.sh
./work186/sms/src/scripts/mysql.sh
./work186/sms/src/scripts1/mysql.sh
./work186/sms1/bin/mysql.sh
./work186/sms1/src/scripts/mysql.sh
./temp/sms/bin/mysql.sh
./temp/sms/src/scripts/mysql.sh
[email protected] root]# cat 2.txt

Real 0m0.083s
User 0m0.040s
SYS 0m0.020s
[Email protected] root]#

The second way of trying is also successful, summed up is (time command-line) 2>file here time close to the parentheses (also can, command line end does not have to take a semicolon.) Of course, it is best to use the first method, after all, to start a child shell is more resources.

Problem thinking

1. Why do the multiple-time statistics for the find command vary widely, with a real time of 12 seconds and a few less than 1 seconds?

[Linux Time Command Learning Article] timing statistics command execution times