Browse code

Merge "Add total timings"

Jenkins authored on 2016/04/01 10:20:10
Showing 1 changed files
... ...
@@ -2322,8 +2322,9 @@ function sudo_with_proxies {
2322 2322
 # Resolution is only in whole seconds, so should be used for long
2323 2323
 # running activities.
2324 2324
 
2325
-declare -A TOTAL_TIME
2326
-declare -A START_TIME
2325
+declare -A _TIME_TOTAL
2326
+declare -A _TIME_START
2327
+declare -r _TIME_BEGIN=$(date +%s)
2327 2328
 
2328 2329
 # time_start $name
2329 2330
 #
... ...
@@ -2331,11 +2332,11 @@ declare -A START_TIME
2331 2331
 # already started.
2332 2332
 function time_start {
2333 2333
     local name=$1
2334
-    local start_time=${START_TIME[$name]}
2334
+    local start_time=${_TIME_START[$name]}
2335 2335
     if [[ -n "$start_time" ]]; then
2336 2336
         die $LINENO "Trying to start the clock on $name, but it's already been started"
2337 2337
     fi
2338
-    START_TIME[$name]=$(date +%s)
2338
+    _TIME_START[$name]=$(date +%s)
2339 2339
 }
2340 2340
 
2341 2341
 # time_stop $name
... ...
@@ -2351,32 +2352,53 @@ function time_stop {
2351 2351
     local start_time
2352 2352
 
2353 2353
     name=$1
2354
-    start_time=${START_TIME[$name]}
2354
+    start_time=${_TIME_START[$name]}
2355 2355
 
2356 2356
     if [[ -z "$start_time" ]]; then
2357 2357
         die $LINENO "Trying to stop the clock on $name, but it was never started"
2358 2358
     fi
2359 2359
     end_time=$(date +%s)
2360 2360
     elapsed_time=$(($end_time - $start_time))
2361
-    total=${TOTAL_TIME[$name]:-0}
2361
+    total=${_TIME_TOTAL[$name]:-0}
2362 2362
     # reset the clock so we can start it in the future
2363
-    START_TIME[$name]=""
2364
-    TOTAL_TIME[$name]=$(($total + $elapsed_time))
2363
+    _TIME_START[$name]=""
2364
+    _TIME_TOTAL[$name]=$(($total + $elapsed_time))
2365 2365
 }
2366 2366
 
2367 2367
 # time_totals
2368
-#
2369
-# prints out total time
2368
+#  Print out total time summary
2370 2369
 function time_totals {
2370
+    local elapsed_time
2371
+    local end_time
2372
+    local len=15
2373
+    local xtrace
2374
+
2375
+    end_time=$(date +%s)
2376
+    elapsed_time=$(($end_time - $_TIME_BEGIN))
2377
+
2378
+    # pad 1st column this far
2379
+    for t in ${!_TIME_TOTAL[*]}; do
2380
+        if [[ ${#t} -gt $len ]]; then
2381
+            len=${#t}
2382
+        fi
2383
+    done
2384
+
2385
+    xtrace=$(set +o | grep xtrace)
2386
+    set +o xtrace
2387
+
2371 2388
     echo
2372
-    echo "========================"
2373
-    echo "DevStack Components Timed"
2374
-    echo "========================"
2389
+    echo "========================="
2390
+    echo "DevStack Component Timing"
2391
+    echo "========================="
2392
+    printf "%-${len}s %3d\n" "Total runtime" "$elapsed_time"
2375 2393
     echo
2376
-    for t in ${!TOTAL_TIME[*]}; do
2377
-        local v=${TOTAL_TIME[$t]}
2378
-        echo "$t - $v secs"
2394
+    for t in ${!_TIME_TOTAL[*]}; do
2395
+        local v=${_TIME_TOTAL[$t]}
2396
+        printf "%-${len}s %3d\n" "$t" "$v"
2379 2397
     done
2398
+    echo "========================="
2399
+
2400
+    $xtrace
2380 2401
 }
2381 2402
 
2382 2403
 # Restore xtrace