Solved

Linux "time" command output redirection

Posted on 2016-11-06
16
75 Views
Last Modified: 2016-11-07
Hi Experts,

I'm wanting concise way to get the "real" figure from the output of the "time" command.

Here's what I've tried:

$ time sleep 5
real    0m5.001s           <= This is what I want to extract.
user    0m0.001s
sys     0m0.001s

$ time sleep 5 | grep real
real    0m5.003s
user    0m0.001s
sys     0m0.002s

$ time sleep 5 2>&1 | grep real
real    0m5.002s
user    0m0.002s
sys     0m0.000s

$ time sleep 5 2>/dev/null | grep real
real    0m5.002s
user    0m0.000s
sys     0m0.002s

$ time sleep 5 1>/dev/null | grep real
real    0m5.003s
user    0m0.000s
sys     0m0.003s

$ time sleep 5 3>/dev/null | grep real
real    0m5.004s
user    0m0.000s
sys     0m0.004s

$ man time | grep -iC1 std
       -o FILE, --output=FILE
              Do not send the results to stderr, but overwrite the specified file.

So, it looks as if the output should be going to stderr by default, but as you can see above, it doesn't appear to be.

$ time -o myfile cal
-bash: -o: command not found              # What the???
real    0m0.001s
user    0m0.000s
sys     0m0.000s

$ time --output=myfile sleep 5
-bash: --output=myfile: command not found
real    0m0.001s
user    0m0.000s
sys     0m0.000s


What is going on?

Note: I have removed/inserted some blank lines above for readability.

I think the OS is some kind of Cloud Linux and it's on a shared webhost.

$ uname -a
Linux server...etc... 3.10.0-427.10.1.lve1.4.22.el7.x86_64 #1 SMP Fri Oct 21 09:45:54 EDT 2016 x86_64 x86_64 x86_64 GNU/Linux

Thanks.
tel2
0
Comment
Question by:tel2
  • 5
  • 4
  • 3
  • +2
16 Comments
 
LVL 16

Expert Comment

by:Hanno Schröder
ID: 41877144
Try this to have stderr sent to stdout:
time 2>&1 | grep -i real

Open in new window

0
 
LVL 16

Expert Comment

by:Hanno Schröder
ID: 41877146
e.g.
time [i]sleep 5[/i] 2>&1 | grep -i real

Open in new window

0
 
LVL 16

Expert Comment

by:Hanno Schröder
ID: 41877150
Formatting does not work for code (previous post), therefore:
eg.: time sleep 5  2>&1 | grep -i real
0
 
LVL 61

Assisted Solution

by:gheist
gheist earned 50 total points
ID: 41877589
this time is bash macro
it is better to use /usr/bin/time (command(s) here) 2>&1 | tee outputlog
0
 
LVL 34

Assisted Solution

by:Duncan Roe
Duncan Roe earned 225 total points
ID: 41877906
In brief, this is what you have to do
bash -c "time sleep 5" 2>&1 | grep real

Open in new window

1
 
LVL 34

Assisted Solution

by:Duncan Roe
Duncan Roe earned 225 total points
ID: 41877915
By way of an explanation, first look at the documentation given by the help builtin
08:59:56$ help time
time: time [-p] pipeline
    Report time consumed by pipeline's execution.
    
    Execute PIPELINE and print a summary of the real time, user CPU time,
    and system CPU time spent executing PIPELINE when it terminates.
    
    Options:
      -p        print the timing summary in the portable Posix format
    
    The value of the TIMEFORMAT variable is used as the output format.
    
    Exit Status:
    The return status is the return status of PIPELINE.

Open in new window

From this you can see that bash outputs time statistics after the execution of the pipeline is complete.  So in your original question, you were timing the pipeline sleep 5 2>&1 | grep real. In order to filter the timing statistics, you have to execute bash.
0
 
LVL 16

Expert Comment

by:Hanno Schröder
ID: 41877919
Just to clearify:
the command "time" exists in two variants:
 a) as shell-builtin
 b) as external command
To use your shell's builtin command, just run
time sleep 5  2>&1 | grep -i real

Open in new window

to use the external command run
/usr/bin/time sleep 5  2>&1 | grep -i real

Open in new window

Where "sleep 5" is the command to time.
0
 
LVL 11

Author Comment

by:tel2
ID: 41877943
Hi Hanno,
"time sleep 5  2>&1 | grep -i real"
Did you see the 3rd example in my original post?  I've already tried that command (without the -i switch).  The output can be seen in my original post.  (Also see the 4th example from by original post.)
BTW, grep's '-i' switch is not required since we know the case of "real" in the output of time.
"/usr/bin/time sleep 5  2>&1 | grep -i real"
The output I get from the above command is...nothing.  You'll see why in my response to gheist, below (i.e. /usr/bin/time returns "elapsed" instead of "real").
If the above worked for you, then there may be differences between my OS and yours.  See the bottom of my original post for details on my OS.

Hi gheist,
That's interesting, thank you.
$ /usr/bin/time sleep 5
0.00user 0.00system 0:05.01elapsed 0%CPU (0avgtext+0avgdata 588maxresident)k
56inputs+0outputs (1major+190minor)pagefaults 0swaps
$ /usr/bin/time sleep 5 2>&1 | perl -ne 'print $1 if /(\S+)elapsed/'
0:05.01
That is the figure I'm wanting, so well done, but I'd still like to know what's happening with the command I was running.

I'll try to look at Duncan's posts later.
0
Highfive + Dolby Voice = No More Audio Complaints!

Poor audio quality is one of the top reasons people don’t use video conferencing. Get the crispest, clearest audio powered by Dolby Voice in every meeting. Highfive and Dolby Voice deliver the best video conferencing and audio experience for every meeting and every room.

 
LVL 27

Accepted Solution

by:
serialband earned 225 total points
ID: 41878005
Try it this way:
(time  sleep 5)  2>&1 | grep real

(time  sleep 5)  2>&1 | grep real > time_test.txt

That causes the output of the entire time command to be redirected.  Without the parenthesis, you're just redirecting the output of the sleep command and that outputs nothing, so you have nothing to grep.
1
 
LVL 11

Author Comment

by:tel2
ID: 41878016
That makes sense, serialband.

And it works for me.

Thanks.
0
 
LVL 27

Expert Comment

by:serialband
ID: 41878026
Your real time for the sleep 5 should also be 5.00s now, since you're no longer timing the redirect and grep commands.
0
 
LVL 11

Author Comment

by:tel2
ID: 41878032
Good point.

The following seems to confirm that:

$ time sleep 5
real    0m5.001s
user    0m0.000s
sys     0m0.002s

$ (time sleep 5) 2>&1 | grep real
real    0m5.001s

$ time sleep 5 2>&1 | grep real
real    0m5.002s
user    0m0.001s
sys     0m0.002s

The 0.001 secs (in 5.001s) is presumably the time for "sleep" to load.
0
 
LVL 34

Expert Comment

by:Duncan Roe
ID: 41878041
sleep will never wait less time than you tell it to. time for "sleep" to load is a good guess; but remember that Linux is a multi-process system and your process can only wake up when it is next given a CPU to run on.
the sleep command uses the nanosleep() system call which you can read about by man nanosleep
1
 
LVL 11

Author Comment

by:tel2
ID: 41878046
OK - thanks Duncan.
0
 
LVL 27

Expert Comment

by:serialband
ID: 41878048
There's still a tiny bit of overhead for the whole process and depends on your system.  I get a different result from you and it varies a tiny bit.
(time  sleep 5)  2>&1 | grep real
real      0m5.003s

(time  sleep 5)  2>&1 | grep real
real      0m5.005s


time sleep 5 2>&1 | grep real
   is the same as
(time sleep 5 2>&1 | grep real)

If you want to get the time of that process then you would do the following.
(time sleep 5 2>&1 | grep real) 2>&1|grep real
real      0m5.008s

In that command, the first redirect catches the output of the sleep command, and that greps as null.  The 2nd one catches the output of the time command and the average results of this command are slightly greater than the other one.
0
 
LVL 11

Author Comment

by:tel2
ID: 41878051
Thanks again serialband, and thanks to all who helped me understand what's going on here.

I should be able to sleep easier now, with the restored confidence that Linux is not broken after all.

tel2
0

Featured Post

How to run any project with ease

Manage projects of all sizes how you want. Great for personal to-do lists, project milestones, team priorities and launch plans.
- Combine task lists, docs, spreadsheets, and chat in one
- View and edit from mobile/offline
- Cut down on emails

Join & Write a Comment

Attention: This article will no longer be maintained. If you have any questions, please feel free to mail me. jgh@FreeBSD.org Please see http://www.freebsd.org/doc/en_US.ISO8859-1/articles/freebsd-update-server/ for the updated article. It is avail…
Introduction We as admins face situation where we need to redirect websites to another. This may be required as a part of an upgrade keeping the old URL but website should be served from new URL. This document would brief you on different ways ca…
Learn how to get help with Linux/Unix bash shell commands. Use help to read help documents for built in bash shell commands.: Use man to interface with the online reference manuals for shell commands.: Use man to search man pages for unknown command…
This demo shows you how to set up the containerized NetScaler CPX with NetScaler Management and Analytics System in a non-routable Mesos/Marathon environment for use with Micro-Services applications.

705 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question

Need Help in Real-Time?

Connect with top rated Experts

16 Experts available now in Live!

Get 1:1 Help Now