Search code examples
bashshelltimevagrantprovisioning

Bash Time Wrong


I'm currently provisioning Vagrant boxes with shell scripts and I'd like to give people an idea of how much time they have left before the provision is complete. But when running the script, the time remaining doesn't match with how much time is passed. I've denoted the differences in the code output below. What is the issue? Thanks!

My script runs as follows

  1. Get the current time from the Unix epoch and set time remaining start=$(date +%s) ; remaining=1200
  2. Print the time remaining echo start=$(date +%s)
  3. Echo the current step and run the step's scripts echo "Moving .ssh" ; ./move_ssh.sh
  4. Recalculate the time remaining by subtracting the new time and adding the start time

    a. This is the same as getting the difference between the start time and the current time from the epoch and subtracting it from the previous time remaining. (a - (b - c) = a - b + c)

    remaining=`expr $remaining - $(date +%s) + $start`
    

Provision script

start=$(date +%s) ; remaining=1200
echo "Time Remaing: $remaining ($(date "+%T"))"
echo "Moving .ssh" ; ./move_ssh.sh
...
remaining=`expr $remaining - $(date +%s) + $start` ; echo "Time Remaing: $remaining ($(date "+%T"))"
...

Vagrant output

==> default: Time Remaing: 1200 (00:43:58)
==> default: Moving .ssh
==> default: Time Remaing: 1200 (00:43:58)
==> default: Installing git
==> default: Time Remaing: 1190 (00:44:08)
==> default: Installing mongodb
==> default: Time Remaing: 1140 (00:44:48) (1190 to 1140 is 50 but 44:08 to 44:48 is 40)
==> default: Installing redis-server
==> default: Time Remaing: 1082 (00:44:56) (1140 to 1082 is 68 but 44:48 to 44:56 is 8)
==> default: Installing python-pip
==> default: Time Remaing: 1001 (00:45:19) (1082 to 1001 is 81 but 44:56 to 45:19 is 23)
==> default: Installing python-dev
==> default: Time Remaing: 887 (00:45:52) (1001 to 887 is 114 but 45:19 to 45:52 is 33)
==> default: Installing mysql-server-5.5
==> default: Time Remaing: 713 (00:46:52) (887 to 713 is 174 but 45:52 to 46:52 is 60)

Solution

  • The following has the expected behavior I created another variable $_remaining:

    start=$(date +%s) ; remaining=1200
    _remaining=$( expr $remaining - $(date +%s) + $start ) ; echo "Time Remaing: $_remaining ($(date "+%T"))"
    

    Debugging with set -x the original shows the issue:

    bob@crunchbang:~/documents/scraping/txt$ set -x
    bob@crunchbang:~/documents/scraping/txt$ start=$(date +%s) ; remaining=1200
    ++ date +%s
    + start=1417917612
    + remaining=1200
    bob@crunchbang:~/documents/scraping/txt$ remaining=$( expr $remaining - $(date +%s) + $start ) ; echo "Time Remaing: $remaining ($(date "+%T"))"
    +++ date +%s
    ++ expr 1200 - 1417917626 + 1417917612
    + remaining=1186
    ++ date +%T
    + echo 'Time Remaing: 1186 (21:00:26)'
    Time Remaing: 1186 (21:00:26)
    bob@crunchbang:~/documents/scraping/txt$ remaining=$( expr $remaining - $(date +%s) + $start ) ; echo "Time Remaing: $remaining ($(date "+%T"))"
    +++ date +%s
    ++ expr 1186 - 1417917634 + 1417917612
    + remaining=1164
    ++ date +%T
    + echo 'Time Remaing: 1164 (21:00:34)'
    Time Remaing: 1164 (21:00:34)
    bob@crunchbang:~/documents/scraping/txt$ remaining=$( expr $remaining - $(date +%s) + $start ) ; echo "Time Remaing: $remaining ($(date "+%T"))"
    +++ date +%s
    ++ expr 1164 - 1417917652 + 1417917612
    + remaining=1124
    ++ date +%T
    + echo 'Time Remaing: 1124 (21:00:52)'
    Time Remaing: 1124 (21:00:52)
    bob@crunchbang:~/documents/scraping/txt$ remaining=$( expr $remaining - $(date +%s) + $start ) ; echo "Time Remaing: $remaining ($(date "+%T"))"
    +++ date +%s
    ++ expr 1124 - 1417917656 + 1417917612
    + remaining=1080
    ++ date +%T
    + echo 'Time Remaing: 1080 (21:00:57)'
    Time Remaing: 1080 (21:00:57)
    

    You can turn off debugging by set +x