Time Taken by 'Less' Command to Show Output

Time taken by `less` command to show output

Your script is communicating with less via a pipe. Pipe is an in-memory stream of bytes that connects two endpoints: your script and the less program, the former writing output to it, the latter reading from it.

As pipes are in-memory, it would be not pleasant if they grew arbitrarily large. So, by default, there's a limit of data that can be inside the pipe (written, but not yet read) at any given moment. By default it's 64k on Linux. If the pipe is full, and your script tries to write to it, the write blocks. So your script isn't actually working, it stopped at some point when doing a write() call.

How to overcome this? Adjusting defaults is a bad option; what is used instead is allocating a buffer in the reader, so that it reads into the buffer, freeing the pipe and thus letting the writing program work, but shows to you (or handles) only a part of the output. less has such a buffer, and, by default, expands it automatically, However, it doesn't fill it in the background, it only fills it as you read the input.

So what would solve your problem is reading the file until the end (like you would normally press G), and then going back to the beginning (like you would normally press g). The thing is that you may specify these commands via command line like this:

./script | less +Gg

You should note, however, that you will have to wait until the whole script's output loads into memory, so you won't be able to view it at once. less is insufficiently sophisticated for that. But if that's what you really need (browsing the beginning of the output while the ./script is still computing its end), you might want to use a temporary file:

 ./script >x & less x ; rm x

How to redirect the output of the time command to a file in Linux?

Try

{ time sleep 1 ; } 2> time.txt

which combines the STDERR of "time" and your command into time.txt

Or use

{ time sleep 1 2> sleep.stderr ; } 2> time.txt

which puts STDERR from "sleep" into the file "sleep.stderr" and only STDERR from "time" goes into "time.txt"

How to understand the output of time command?

From: http://zch051383471952.blogspot.com/2010/01/different-of-real-user-sys-time.html

Real refers to actual elapsed time;
User and Sys refer to CPU time used
only by the process.

• Real is wall clock time - time from start to finish of the call. This is
  all elapsed time including time slices
  used by other processes and time the
  process spends blocked (for example if
  it is waiting for I/O to complete).
• User is the amount of CPU time spent in user-mode code (outside the
  kernel) within the process. This is
  only actual CPU time used in executing
  the process. Other processes and time
  the process spends blocked do not
  count towards this figure.
• Sys is the amount of CPU time spent in the kernel within the process. This
  means executing CPU time spent in
  system calls within the kernel, as
  opposed to library code, which is
  still running in user-space. Like
  'user', this is only CPU time used by
  the process.

linux time command resulting real is less than user

The script could have used more than 1 core.

Comparing output of time command in shell to a constant

With bash, if you just need the duration in seconds, use the builtin SECONDS variable:

SECONDS=0
some long running process here
duration=$SECONDS

if ((duration > 10)); then
    echo "it took a long time"
fi

Print execution time of a shell command

Don't forget that there is a difference between bash's builtin time (which should be called by default when you do time command) and /usr/bin/time (which should require you to call it by its full path).

The builtin time always prints to stderr, but /usr/bin/time will allow you to send time's output to a specific file, so you do not interfere with the executed command's stderr stream. Also, /usr/bin/time's format is configurable on the command line or by the environment variable TIME, whereas bash's builtin time format is only configured by the TIMEFORMAT environment variable.

$ time factor 1234567889234567891 # builtin
1234567889234567891: 142662263 8653780357

real    0m3.194s
user    0m1.596s
sys 0m0.004s
$ /usr/bin/time factor 1234567889234567891
1234567889234567891: 142662263 8653780357
1.54user 0.00system 0:02.69elapsed 57%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (0major+215minor)pagefaults 0swaps
$ /usr/bin/time -o timed factor 1234567889234567891 # log to file `timed`
1234567889234567891: 142662263 8653780357
$ cat timed
1.56user 0.02system 0:02.49elapsed 63%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (0major+217minor)pagefaults 0swaps

What do 'real', 'user' and 'sys' mean in the output of time(1)?

Real, User and Sys process time statistics

One of these things is not like the other. Real refers to actual elapsed time; User and Sys refer to CPU time used only by the process.

• Real is wall clock time - time from start to finish of the call. This is all elapsed time including time slices used by other processes and time the process spends blocked (for example if it is waiting for I/O to complete).

• User is the amount of CPU time spent in user-mode code (outside the kernel) within the process. This is only actual CPU time used in executing the process. Other processes and time the process spends blocked do not count towards this figure.

• Sys is the amount of CPU time spent in the kernel within the process. This means executing CPU time spent in system calls within the kernel, as opposed to library code, which is still running in user-space. Like 'user', this is only CPU time used by the process. See below for a brief description of kernel mode (also known as 'supervisor' mode) and the system call mechanism.

User+Sys will tell you how much actual CPU time your process used. Note that this is across all CPUs, so if the process has multiple threads (and this process is running on a computer with more than one processor) it could potentially exceed the wall clock time reported by Real (which usually occurs). Note that in the output these figures include the User and Sys time of all child processes (and their descendants) as well when they could have been collected, e.g. by wait(2) or waitpid(2), although the underlying system calls return the statistics for the process and its children separately.

Origins of the statistics reported by time (1)

The statistics reported by time are gathered from various system calls. 'User' and 'Sys' come from wait (2) (POSIX) or times (2) (POSIX), depending on the particular system. 'Real' is calculated from a start and end time gathered from the gettimeofday (2) call. Depending on the version of the system, various other statistics such as the number of context switches may also be gathered by time.

On a multi-processor machine, a multi-threaded process or a process forking children could have an elapsed time smaller than the total CPU time - as different threads or processes may run in parallel. Also, the time statistics reported come from different origins, so times recorded for very short running tasks may be subject to rounding errors, as the example given by the original poster shows.

A brief primer on Kernel vs. User mode

On Unix, or any protected-memory operating system, 'Kernel' or 'Supervisor' mode refers to a privileged mode that the CPU can operate in. Certain privileged actions that could affect security or stability can only be done when the CPU is operating in this mode; these actions are not available to application code. An example of such an action might be manipulation of the MMU to gain access to the address space of another process. Normally, user-mode code cannot do this (with good reason), although it can request shared memory from the kernel, which could be read or written by more than one process. In this case, the shared memory is explicitly requested from the kernel through a secure mechanism and both processes have to explicitly attach to it in order to use it.

The privileged mode is usually referred to as 'kernel' mode because the kernel is executed by the CPU running in this mode. In order to switch to kernel mode you have to issue a specific instruction (often called a trap) that switches the CPU to running in kernel mode and runs code from a specific location held in a jump table. For security reasons, you cannot switch to kernel mode and execute arbitrary code - the traps are managed through a table of addresses that cannot be written to unless the CPU is running in supervisor mode. You trap with an explicit trap number and the address is looked up in the jump table; the kernel has a finite number of controlled entry points.

The 'system' calls in the C library (particularly those described in Section 2 of the man pages) have a user-mode component, which is what you actually call from your C program. Behind the scenes, they may issue one or more system calls to the kernel to do specific services such as I/O, but they still also have code running in user-mode. It is also quite possible to directly issue a trap to kernel mode from any user space code if desired, although you may need to write a snippet of assembly language to set up the registers correctly for the call.

More about 'sys'

There are things that your code cannot do from user mode - things like allocating memory or accessing hardware (HDD, network, etc.). These are under the supervision of the kernel, and it alone can do them. Some operations like malloc orfread/fwrite will invoke these kernel functions and that then will count as 'sys' time. Unfortunately it's not as simple as "every call to malloc will be counted in 'sys' time". The call to malloc will do some processing of its own (still counted in 'user' time) and then somewhere along the way it may call the function in kernel (counted in 'sys' time). After returning from the kernel call, there will be some more time in 'user' and then malloc will return to your code. As for when the switch happens, and how much of it is spent in kernel mode... you cannot say. It depends on the implementation of the library. Also, other seemingly innocent functions might also use malloc and the like in the background, which will again have some time in 'sys' then.

How do I measure request and response times at once using cURL?

From this brilliant blog post... https://blog.josephscott.org/2011/10/14/timing-details-with-curl/

cURL supports formatted output for the details of the request (see the cURL manpage for details, under -w, –write-out <format>). For our purposes we’ll focus just on the timing details that are provided. Times below are in seconds.

1. Create a new file, curl-format.txt, and paste in:

        time_namelookup:  %{time_namelookup}s\n
           time_connect:  %{time_connect}s\n
        time_appconnect:  %{time_appconnect}s\n
       time_pretransfer:  %{time_pretransfer}s\n
          time_redirect:  %{time_redirect}s\n
     time_starttransfer:  %{time_starttransfer}s\n
                        ----------\n
             time_total:  %{time_total}s\n
   

2. Make a request:

    curl -w "@curl-format.txt" -o /dev/null -s "http://wordpress.com/"
   

   Or on Windows, it's...

    curl -w "@curl-format.txt" -o NUL -s "http://wordpress.com/"
   

What this does:

-w "@curl-format.txt" tells cURL to use our format file

-o /dev/null redirects the output of the request to /dev/null

-s
tells cURL not to show a progress meter

"http://wordpress.com/" is
the URL we are requesting. Use quotes particularly if your URL has "&" query string parameters

And here is what you get back:

   time_namelookup:  0.001s
      time_connect:  0.037s
   time_appconnect:  0.000s
  time_pretransfer:  0.037s
     time_redirect:  0.000s
time_starttransfer:  0.092s
                   ----------
        time_total:  0.164s

I have not yet seen an option to output the results in microseconds, but if you're aware of one, post in the comments below.

Make a Linux/Mac shortcut (alias)

alias curltime="curl -w \"@$HOME/.curl-format.txt\" -o /dev/null -s "

Then you can simply call...

curltime wordpress.org

Thanks to commenter Pete Doyle!

Make a Linux/Mac stand-alone script

This script does not require a separate .txt file to contain the formatting.

Create a new file, curltime, somewhere in your executable path, and paste in:

#!/bin/bash

curl -w @- -o /dev/null -s "$@" <<'EOF'
    time_namelookup:  %{time_namelookup}\n
       time_connect:  %{time_connect}\n
    time_appconnect:  %{time_appconnect}\n
   time_pretransfer:  %{time_pretransfer}\n
      time_redirect:  %{time_redirect}\n
 time_starttransfer:  %{time_starttransfer}\n
                    ----------\n
         time_total:  %{time_total}\n
EOF

Then call it the same way as the alias:

curltime wordpress.org

Make a Windows shortcut (aka BAT file)

Create a new text file called curltime.bat in the same folder as curl.exe and curl-format.txt, and paste in the following line:

curl -w "@%~dp0curl-format.txt" -o NUL -s %*

Then from the command line you can simply call:

curltime wordpress.org

(Make sure the folder is listed in your Windows PATH variable to be able to use the command from any folder.)

/usr/bin/time --format output elapsed time in milliseconds

One possibility is to use the date command:

ts=$(date +%s%N) ; my_command ; tt=$((($(date +%s%N) - $ts)/1000000)) ; echo "Time taken: $tt milliseconds"

%N should return nanoseconds, and 1 millisecond is 1000000 nanosecond, hence by division would return the time taken to execute my_command in milliseconds.

NOTE that the %N is not supported on all systems, but most of them.

---

Related Topics