1

I need to use sleep in a shell script, so I tried it out in a terminal, but the delays it produces are inconsistent and very inaccurate. For example sleep 3 produces a delay close to 20 seconds. These delays can also fluctuate when the same time is specified. In general the delay seems to increase exponentially with higher values.

Tried both on a Ubuntu and a Debian VM with similarly poor results. I do not think the VM component is in play (running a timeout 10 on a Windows VM is fine).

By timing each command the system clock thinks it's running okay but in reality it's not. See a few examples below.


Time in brackets is the actual time elapsed (approximate):

$ time sleep 1        (7 secs)

real    0m1.040s
user    0m0.003s
sys     0m0.016s
$ time sleep 1        (5 secs)

real    0m1.028s      
user    0m0.009s
sys     0m0.013s
$ time sleep 1        (5 secs)

real    0m1.027s
user    0m0.013s
sys     0m0.007s
$ time sleep 1        (5 secs)

real    0m1.029s
user    0m0.007s
sys     0m0.016s
$ time sleep 3       (17 secs)

real    0m3.036s
user    0m0.000s
sys     0m0.021s
$ time sleep 5       (29.5 secs)

real    0m5.026s
user    0m0.007s
sys     0m0.013s

The default is obviously in seconds but adding an s to the time doesn't make any difference.

Nothing else is running on the host machine that might hog disk or CPU.

Rebooting the VM seems to improve the situation for the first few tries but, after that, accuracy gets increasingly worse.

Any idea as to what the issue might be?

EDIT:

  • running declare -p PS1 returns

    declare -- PS1="\${debian_chroot:+(\$debian_chroot)}\\u@\\h:\\w\\\$ "
    
  • running command -V sleep returns

    sleep is hashed (/usr/bin/sleep)
    
  • running declare -p PATH returns

    declare -x PATH="/home/debwp/mycmds:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games"
    
  • Results from Paul_Pedant's post:

    ~$ date '+%T.%N'; time sleep 5; date '+%T.%N'
    22:47:49.679497552
    ^[[A
    ^[[A
    ^[[A
    ^[[A
    
    real  0m5.033s
    user  0m0.005s
    sys   0m0.014s
    22:47:54.788302324
    ~$ date '+%T.%N'; time sleep 5; date '+%T.%N'
    22:47:54.830674809
    
    real  0m5.043s
    user  0m0.008s
    sys   0m0.012s
    22:47:59.934542825
    ~$ date '+%T.%N'; time sleep 5; date '+%T.%N'
    22:47:59.994006022
    
    real  0m5.057s
    user  0m0.004s
    sys   0m0.018s
    22:48:05.159303996
    ~$ date '+%T.%N'; time sleep 5; date '+%T.%N'
    22:48:05.241043114
    
    real  0m5.099s
    user  0m0.004s
    sys   0m0.021s
    22:48:10.383158635
    ~$ date '+%T.%N'; time sleep 5; date '+%T.%N'
    22:48:10.435520982
    
    real  0m5.028s
    user  0m0.004s
    sys   0m0.012s
    22:48:15.497877219
    ~$
    
  • entering date at the terminal at the rate of ~ once per second results in

    $ date
    Mon 31 Aug 20:42:25 CEST 2020
    $ date
    Mon 31 Aug 20:42:25 CEST 2020
    $ date
    Mon 31 Aug 20:42:25 CEST 2020
    $ date
    Mon 31 Aug 20:42:26 CEST 2020
    
  • 2
    The only things running are the sleep command (which the shell keyword time is accurately reporting), and your prompt refresh. Can you run declare -p PS1 and edit the output into your question? Also command -V sleep in case it has been aliased or you have a duplicate. And declare -p PATH in case that is searching a huge directory. – Paul_Pedant Aug 31 at 17:22
  • @Paul_Pedant thx, added the results to the question. – Dave White Aug 31 at 17:43
  • 1
    Thanks. As /usr/bin/sleep is cached, the path should not be searched again so should not matter. The prompt runs debian_chroot, as mine does. I don't know what that is for, or whether VirtualBox would affect timings. – Paul_Pedant Aug 31 at 18:25
  • 1
    Slightly missed the point. Wrapping date x 2 around thetime sleep 5 omly confirms the output of the time command. The format '+%T.%N' shows nanoseconds (first 3 digits only should be accurate). I want to show the delay in bash between the end of executing one command line and the execution of the next: I think the lost time is in bash reading the next command, not the sleep. So multiple date commands should be entered even before the sleep ends. – Paul_Pedant Aug 31 at 20:43
  • What takes 34 seconds? When you enter the 3 commands on one line, how long between output for each of: the first timestamp, the real time report, the second timestamp, the prompt, and the third timestamp? – Paul_Pedant Aug 31 at 20:48
3

The behaviour is certainly related to your hypervisor.

time(7) says:

Real time is defined as time measured from some fixed point, either from a standard point in the past (see the description of the Epoch and calendar time below), or from some point (e.g., the start) in the life of a process (elapsed time).

Process time is defined as the amount of CPU time used by a process. This is sometimes divided into user and system components. User CPU time is the time spent executing code in user mode. System CPU time is the time spent by the kernel executing in system mode on behalf of the process (e.g., executing system calls). The time(1) command can be used to determine the amount of CPU time consumed during the execution of a program.

Based on this, we can conclude that when we write:

$ time sleep 1

real    0m1.002s
user    0m0.002s
sys     0m0.000s

real is the real time, meaning the actual time (sometimes called wall clock time) spent in the process. user is the CPU time (CPU cycles * frequency) spent executing code in user mode and sys is the CPU time (CPU cycles * frequency) spent by the kernel executing in system mode on behalf of the process.

To paraphrase your problem:

Why doesn't real time reported by time(1) match my watch?

When you run an OS on bare metal, you'll usually have a battery-powered crystal oscillator which runs at a constant frequency. This-hardware clock will keep track of the time since the epoch. The number of oscillations per second can be tuned to correct for drift (see hwclock(8)).

time(7) also says:

The accuracy of various system calls that set timeouts, (e.g., select(2), sigtimedwait(2)) and measure CPU time (e.g., getrusage(2)) is limited by the resolution of the software clock, a clock maintained by the kernel which measures time in jiffies. The size of a jiffy is determined by the value of the kernel constant HZ.

The hardware clock is used to initialize the system clock (which would otherwise only know the time since boot). I suspect your hypervisor (virtualbox) uses some hwclock to initialize the time. After that, the software clock takes over.

rtc(4) says:

[hardware clocks] should not be confused with the system clock, which is a software clock maintained by the kernel and used to implement gettimeofday(2) and time(2), as well as setting timestamps on files, and so on.

What we just learned here is that time(2) (which is the library calls used by the utility time(1)) actually gets info from the system clock, not the hardware clock.

The software clock is maintained by the kernel which measures time in jiffies. This is a unit of time determined by a kernel constant. As far as I understand it, a certain number of CPU cycles will increment one jiffie. So if the OS thinks the CPU is running at 2.0 GHz, but the CPU is actually running at 1.0GHz, then one jiffie would actually take 2ms when compared to a wall clock instead of the expected 1ms.

When running with physical hardware, we tell the CPU how fast we want it to run (slower for power-saving, faster for performance), then we assume that the hardware does what it promised because physical hardware does do that. The trick is that when the "hardware" is virtual, then the hypervisor decides how to control the virtual CPU, not the laws of physics.

A hypervisor running in userspace (like virtual-box) will be at the mercy of the host kernel to give it the cycles it needs. If the host system is running 1000 virtual machines, you can imagine that each guest VM will only get a portion of the CPU cycles it was expecting, causing the guess system clocks to increment at a slower rate. Even if a hypervisor gets all of the resources it needs, it can also choose to throttle the resources as it sees fit, leaving the guest-OS to run slower than it expects without understanding why.

| improve this answer | |
  • Thx Stewart, I solved it, it had to do with a setting in the Virtualbox Manager. – Dave White Aug 31 at 21:44
1

Found this answer in Clock drift in a VirtualBox guest:

In Virtualbox Manager, changing the Paravirtualization value (System settings --> Acceleration tab) from Default to Minimal corrected the problem.

| improve this answer | |

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.