tests: Use '--no-wait' to reduce clear/test_ust runtime
[lttng-tools.git] / tests / regression / tools / clear / test_ust
index dcfc0ee0c855a413a6cf9211472dde90d4256a33..104753b98474ea57bf5a32538daee9f0bb5143b5 100755 (executable)
@@ -1,6 +1,6 @@
 #!/bin/bash
 #
-# Copyright (C) 2019 Jonathan Rajotte-Julien <jonathan.rajotte-julien@efficios.com>
+# Copyright (C) 2019 Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
 #
 # SPDX-License-Identifier: LGPL-2.1-only
 
@@ -9,17 +9,21 @@ TEST_DESC="Clear - UST tracing"
 CURDIR=$(dirname $0)/
 TESTDIR=$CURDIR/../../..
 EVENT_NAME="tp:tptest"
+EVENT_STATE_DUMP_START="lttng_ust_statedump:start"
+EVENT_STATE_DUMP_END="lttng_ust_statedump:end"
 SESSION_NAME=""
 TESTAPP_PATH="$TESTDIR/utils/testapp"
 TESTAPP_NAME="gen-ust-events"
 TESTAPP_BIN="$TESTAPP_PATH/$TESTAPP_NAME/$TESTAPP_NAME"
 
-NUM_TESTS=1683
-
+NUM_TESTS=2071
+DELAYUS=500000
+LIVEVIEWER_TIMEOUT=10  # Timeout in seconds
 PAGE_SIZE=$(getconf PAGE_SIZE)
-TRACE_PATH=$(mktemp -d)
+TRACE_PATH=$(mktemp -d -t tmp.test_clear_ust_trace_path.XXXXXX)
 
-source $TESTDIR/utils/utils.sh
+# shellcheck source=../utils/utils.sh
+source "$TESTDIR/utils/utils.sh"
 
 if [ ! -x "$TESTAPP_BIN" ]; then
        BAIL_OUT "No UST events binary detected."
@@ -29,7 +33,7 @@ function clean_path ()
 {
        local trace_path=$1
        set -u
-       rm -rf $trace_path/*
+       rm -rf $trace_path
        set +u
 }
 
@@ -110,7 +114,32 @@ function test_ust_streaming ()
                fi
        fi
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
+}
+
+function test_ust_streaming_no_event ()
+{
+       local tracing_active=$1
+       local clear_twice=$2
+       #local rotate_before=$3 ignored
+       #local rotate_after=$4
+       local buffer_type=uid
+       local local_path="${TRACE_PATH}/${HOSTNAME}/${SESSION_NAME}*"
+       local channel_name="chan"
+
+       diag "Test ust streaming clear no event"
+       diag "Parameters: tracing_active=$tracing_active, clear_twice=$clear_twice, rotate_before=$rotate_before, rotate_after=$rotate_after, buffer_type=$buffer_type"
+       create_lttng_session_uri $SESSION_NAME net://localhost
+       enable_ust_lttng_channel_ok $SESSION_NAME $channel_name --buffers-$buffer_type
+       enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME $channel_name
+       start_lttng_tracing_ok $SESSION_NAME
+
+       do_clear_session $SESSION_NAME "$tracing_active" "$clear_twice" "$rotate_before" "$rotate_after"
+       stop_lttng_tracing_ok $SESSION_NAME
+
+       validate_directory_empty "$local_path"
+
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function test_ust_streaming_rotate_clear ()
@@ -143,7 +172,7 @@ function test_ust_streaming_rotate_clear ()
        fi
        validate_trace_count $EVENT_NAME $local_path $expect_count
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function test_ust_streaming_clear_rotate ()
@@ -176,7 +205,7 @@ function test_ust_streaming_clear_rotate ()
        fi
        validate_trace_count $EVENT_NAME $local_path $expect_count
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function test_ust_streaming_live ()
@@ -190,7 +219,7 @@ function test_ust_streaming_live ()
 
        diag "Test ust streaming live clear"
        diag "Parameters: tracing_active=$tracing_active, clear_twice=$clear_twice, buffer_type=$buffer_type"
-       create_lttng_session_uri $SESSION_NAME net://localhost "--live"
+       create_lttng_session_uri $SESSION_NAME net://localhost "--live=${DELAYUS}"
        enable_ust_lttng_channel_ok $SESSION_NAME $channel_name --buffers-$buffer_type
        enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME $channel_name
        start_lttng_tracing_ok $SESSION_NAME
@@ -198,9 +227,13 @@ function test_ust_streaming_live ()
        do_clear_session $SESSION_NAME $tracing_active $clear_twice 0 0
        stop_lttng_tracing_ok $SESSION_NAME
 
-       validate_directory_empty $local_path
+       if [[ "$buffer_type" == "uid" ]]; then
+               validate_trace_empty $local_path
+       else    # pid
+               validate_directory_empty $local_path
+       fi
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 #no clear
@@ -213,12 +246,13 @@ function test_ust_basic_streaming_live_viewer ()
        local local_path="${TRACE_PATH}/${HOSTNAME}/${SESSION_NAME}*"
        local remote_trace_path="${HOSTNAME}/${SESSION_NAME}"
        local channel_name="chan"
-       local bt_output_path=$(mktemp -u)
-       local file_sync_before_exit=$(mktemp -u)
+       local bt_output_path=$(mktemp -u -t tmp.test_${FUNCNAME[0]}_bt_output_path.XXXXXX)
+       local bt_error_path=$(mktemp -t "tmp.${FUNCNAME[0]}_bt_error.XXXXXX")
+       local file_sync_before_exit=$(mktemp -u -t tmp.test_${FUNCNAME[0]}_sync_before_exit.XXXXXX)
 
        diag "Test ust basic streaming live with viewer"
        diag "Parameters: tracing_active=$tracing_active, clear_twice=$clear_twice, buffer_type=$buffer_type"
-       create_lttng_session_uri $SESSION_NAME net://localhost "--live"
+       create_lttng_session_uri $SESSION_NAME net://localhost "--live=${DELAYUS}"
        enable_ust_lttng_channel_ok $SESSION_NAME $channel_name --buffers-$buffer_type
        enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME $channel_name
        start_lttng_tracing_ok $SESSION_NAME
@@ -226,8 +260,9 @@ function test_ust_basic_streaming_live_viewer ()
        wait_live_trace_ready net://localhost
 
        # Connect a live viewer
-       $BABELTRACE_BIN -i lttng-live net://localhost/host/$remote_trace_path > $bt_output_path &
+       $BABELTRACE_BIN -i lttng-live net://localhost/host/$remote_trace_path --params=session-not-found-action=end 1> $bt_output_path 2> "${bt_error_path}" &
        local viewer_pid=$!
+       local viewer_iter=0
 
        wait_live_viewer_connect net://localhost
 
@@ -238,13 +273,17 @@ function test_ust_basic_streaming_live_viewer ()
        local evcount=0
        while [ $evcount -ne 10 ]; do
                evcount=$(cat $bt_output_path | wc -l)
-               sleep 0.5
+               sleep 0.1
+               viewer_iter=$((viewer_iter + 1))
+               if [ "${viewer_iter}" -gt $((LIVEVIEWER_TIMEOUT * 10)) ] ; then
+                       break;
+               fi
        done
-       pass "Live viewer read $evcount events, expect 10"
+       is "${evcount}" 10 "Live viewer read $evcount events, expect 10"
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
        touch $file_sync_before_exit
-       diag "Wait for application to exit"
+       diag "Waiting for application to exit"
        wait $app_pid
        pass "Wait for application to exit"
        diag "Wait for viewer to exit"
@@ -253,6 +292,7 @@ function test_ust_basic_streaming_live_viewer ()
        pass "Wait for viewer to exit"
 
        rm -f $bt_output_path
+       clean_path "${bt_error_path}"
        rm -f $file_sync_before_exit
 }
 
@@ -265,11 +305,12 @@ function test_ust_streaming_live_viewer ()
        local local_path="${TRACE_PATH}/${HOSTNAME}/${SESSION_NAME}*"
        local remote_trace_path="${HOSTNAME}/${SESSION_NAME}"
        local channel_name="chan"
-       local bt_output_path=$(mktemp -d)/bt-output.txt
+       local bt_output_path=$(mktemp -u -t tmp.test_${FUNCNAME[0]}_bt_output_path.XXXXXX)
+       local bt_error_path=$(mktemp -t "tmp.${FUNCNAME[0]}_bt_error.XXXXXX")
 
        diag "Test ust streaming live clear with viewer"
        diag "Parameters: tracing_active=$tracing_active, clear_twice=$clear_twice, buffer_type=$buffer_type"
-       create_lttng_session_uri $SESSION_NAME net://localhost "--live"
+       create_lttng_session_uri $SESSION_NAME net://localhost "--live=${DELAYUS}"
        enable_ust_lttng_channel_ok $SESSION_NAME $channel_name --buffers-$buffer_type
        enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME $channel_name
        start_lttng_tracing_ok $SESSION_NAME
@@ -277,7 +318,7 @@ function test_ust_streaming_live_viewer ()
        wait_live_trace_ready net://localhost
 
        # Connect a live viewer
-       $BABELTRACE_BIN -i lttng-live net://localhost/host/$remote_trace_path > $bt_output_path &
+       $BABELTRACE_BIN -i lttng-live net://localhost/host/$remote_trace_path --params=session-not-found-action=end 1> $bt_output_path 2> "${bt_error_path}" &
        local viewer_pid=$!
 
        wait_live_viewer_connect net://localhost
@@ -286,13 +327,109 @@ function test_ust_streaming_live_viewer ()
        do_clear_session $SESSION_NAME $tracing_active $clear_twice 0 0
        stop_lttng_tracing_ok $SESSION_NAME
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
        diag "Wait for viewer to exit"
        wait $viewer_pid
        ok $? "Babeltrace succeeds"
        pass "Wait for viewer to exit"
 
        clean_path $bt_output_path
+       clean_path "${bt_error_path}"
+}
+
+function test_ust_streaming_live_viewer_new_metadata_after_clear ()
+{
+       local tracing_active=$1
+       local clear_twice=$2
+       # 3, 4 unused
+       local buffer_type=$5
+       local local_path="${TRACE_PATH}/${HOSTNAME}/${SESSION_NAME}*"
+       local remote_trace_path="${HOSTNAME}/${SESSION_NAME}"
+       local channel_name="chan"
+
+       local bt_output_path=$(mktemp -t "tmp.${FUNCNAME[0]}_bt_output.XXXXXX")
+       local bt_error_path=$(mktemp -t "tmp.${FUNCNAME[0]}_bt_error.XXXXXX")
+       local file_sync_before_exit=$(mktemp -u -t "tmp.${FUNCNAME[0]}_sync_before_exit.XXXXXX")
+
+       diag "Test ust streaming live clear with viewer with new metadata after clear"
+       diag "Parameters: tracing_active=$tracing_active, clear_twice=$clear_twice, buffer_type=$buffer_type"
+       create_lttng_session_uri "$SESSION_NAME" net://localhost "--live=${DELAYUS}"
+       enable_ust_lttng_channel_ok "$SESSION_NAME" $channel_name "--buffers-$buffer_type"
+
+       # The vpid context is added to filter events based on the vpid of the
+       # test application as state dump events are used. Regenerating a
+       # state dump will cause other instrumented application on the system
+       # to trigger a state dump which would throw off checks that rely on an
+       # event count.
+       add_context_ust_ok "$SESSION_NAME" $channel_name "vpid"
+       enable_ust_lttng_event_ok "$SESSION_NAME" $EVENT_NAME $channel_name
+       start_lttng_tracing_ok "$SESSION_NAME"
+
+       wait_live_trace_ready net://localhost
+
+       # Connect a live viewer
+       $BABELTRACE_BIN -i lttng-live "net://localhost/host/$remote_trace_path" --params=session-not-found-action=end 1> "$bt_output_path" 2> "$bt_error_path" &
+       local viewer_pid=$!
+       local viewer_iter=0
+
+       wait_live_viewer_connect net://localhost
+
+       $TESTAPP_BIN -i 10 --sync-before-exit "$file_sync_before_exit" &
+       local app_pid=$!
+
+       diag "Wait until viewer sees all 10 expected events"
+       local evcount=0
+       while [ $evcount -ne 10 ]; do
+               evcount=$(wc -l < "$bt_output_path")
+               sleep 0.1
+               viewer_iter=$((viewer_iter + 1))
+               if [ "${viewer_iter}" -gt $((LIVEVIEWER_TIMEOUT * 10)) ] ; then
+                       break
+               fi
+       done
+       is "${evcount}" 10 "Live viewer read $evcount events, expect 10"
+
+       do_clear_session "$SESSION_NAME" "$tracing_active" "$clear_twice" 0 0
+
+       # Enable new events which will add their descriptions to the metadata
+       # file. This validates that, following a clear, the relay daemon rotates
+       # the metadata viewer stream to the new metadata file.
+       enable_ust_lttng_event_filter "$SESSION_NAME" $EVENT_STATE_DUMP_START "\$ctx.vpid == $app_pid" $channel_name
+       enable_ust_lttng_event_filter "$SESSION_NAME" $EVENT_STATE_DUMP_END "\$ctx.vpid == $app_pid" $channel_name
+
+       # Forcing a state dump to produce the two events enabled above
+       regenerate_statedump_ok "$SESSION_NAME"
+
+       diag "Wait until viewer sees all 12 expected events"
+       local evcount=0
+       local viewer_iter=0
+       while [ $evcount -ne 12 ]; do
+               evcount=$(wc -l < "$bt_output_path")
+               sleep 0.1
+               viewer_iter=$((viewer_iter + 1))
+               if [ "${viewer_iter}" -gt $((LIVEVIEWER_TIMEOUT * 10)) ]; then
+                       break
+               fi
+       done
+       is "${evcount}" 12 "Live viewer read $evcount events, expect 12"
+
+       stop_lttng_tracing_ok "$SESSION_NAME"
+
+       destroy_lttng_session_ok "$SESSION_NAME" --no-wait
+
+       touch "$file_sync_before_exit"
+       diag "Waiting for application to exit"
+       wait $app_pid
+       pass "Wait for application to exit"
+
+       diag "Wait for viewer to exit"
+       wait $viewer_pid
+       ok $? "Babeltrace succeeds"
+       pass "Wait for viewer to exit"
+
+       clean_path "$bt_output_path"
+       clean_path "$bt_error_path"
+       rm -f "$file_sync_before_exit"
 }
 
 function test_ust_local ()
@@ -320,11 +457,38 @@ function test_ust_local ()
                if [[ "$buffer_type" == "uid" ]]; then
                        validate_trace_empty $TRACE_PATH
                else    # pid
-                       validate_directory_empty $TRACE_PATH
+
+                       # The sessiond always created a `ust/ directory
+                       # whenever the UST domain is active
+                       validate_directory_empty $TRACE_PATH/ust/
                fi
        fi
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
+}
+
+function test_ust_local_no_event ()
+{
+       local tracing_active=$1
+       local clear_twice=$2
+       #local rotate_before=$3 ignored
+       #local rotate_after=$4 ignored
+       local buffer_type=$5
+       local channel_name="chan"
+
+       diag "Test ust local no event"
+       diag "Parameters: tracing_active=$tracing_active, clear_twice=$clear_twice, rotate_before=$rotate_before, rotate_after=$rotate_after, buffer_type=$buffer_type"
+       create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"
+       enable_ust_lttng_channel_ok $SESSION_NAME $channel_name "--buffers-$buffer_type"
+       enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME $channel_name
+       start_lttng_tracing_ok $SESSION_NAME
+
+       do_clear_session $SESSION_NAME "$tracing_active" "$clear_twice" "$rotate_before" "$rotate_after"
+       stop_lttng_tracing_ok $SESSION_NAME
+
+       validate_directory_empty "$TRACE_PATH"
+
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function test_ust_local_rotate_clear ()
@@ -356,7 +520,7 @@ function test_ust_local_rotate_clear ()
        fi
        validate_trace_count $EVENT_NAME $TRACE_PATH $expect_count
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function test_ust_local_clear_rotate ()
@@ -388,7 +552,7 @@ function test_ust_local_clear_rotate ()
        fi
        validate_trace_count $EVENT_NAME $TRACE_PATH $expect_count
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function do_ust_snapshot ()
@@ -447,7 +611,7 @@ function test_ust_streaming_snapshot ()
 
        create_lttng_session_uri $SESSION_NAME net://localhost "--snapshot"
        do_ust_snapshot $SESSION_NAME $TRACE_PATH $tracing_active $clear_twice $buffer_type
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function test_ust_local_snapshot ()
@@ -462,7 +626,7 @@ function test_ust_local_snapshot ()
 
        create_lttng_session_ok $SESSION_NAME $TRACE_PATH "--snapshot"
        do_ust_snapshot $SESSION_NAME $TRACE_PATH $tracing_active $clear_twice $buffer_type
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 # snapshot for per-pid is tested independently of the "buffer type" parameter
@@ -474,10 +638,10 @@ function test_ust_local_snapshot_per_pid ()
        # 3, 4 unused.
        local buffer_type=$5
        local channel_name="channel0"
-       local file_sync_before_last=$(mktemp -u)
-       local file_sync_before_last_touch=$(mktemp -u)
-       local file_sync_before_exit=$(mktemp -u)
-       local file_sync_before_exit_touch=$(mktemp -u)
+       local file_sync_before_last=$(mktemp -u -t "tmp.${FUNCNAME[0]}_sync_before_last.XXXXXX")
+       local file_sync_before_last_touch=$(mktemp -u -t "tmp.${FUNCNAME[0]}_sync_before_last_touch.XXXXXX")
+       local file_sync_before_exit=$(mktemp -u -t "tmp.${FUNCNAME[0]}_sync_before_exit.XXXXXX")
+       local file_sync_before_exit_touch=$(mktemp -u -t "tmp.${FUNCNAME[0]}_sync_before_exit_touch.XXXXXX")
 
        diag "Test ust local snapshot clear per pid"
        diag "Parameters: tracing_active=$tracing_active, clear_twice=$clear_twice, buffer_type=$buffer_type"
@@ -493,10 +657,11 @@ function test_ust_local_snapshot_per_pid ()
                --sync-before-last-event-touch ${file_sync_before_last_touch} \
                --sync-before-exit ${file_sync_before_exit} \
                --sync-before-exit-touch ${file_sync_before_exit_touch} >/dev/null 2>&1 &
+       local app_pid="${!}"
 
        # Continue only when there is only the last event remaining.
        while [ ! -f "${file_sync_before_last_touch}" ]; do
-               sleep 0.5
+               sleep 0.1
        done
 
        # Take a first snapshot and validate that the events are present.
@@ -526,7 +691,7 @@ function test_ust_local_snapshot_per_pid ()
        # Wait for the before exit sync point. This ensure that we went over the
        # last tracepoint.
        while [ ! -f "${file_sync_before_exit_touch}" ]; do
-               sleep 0.5
+               sleep 0.1
        done
 
        # Make sure the snapshot contains the last event.
@@ -536,8 +701,8 @@ function test_ust_local_snapshot_per_pid ()
 
        # Release the application.
        touch ${file_sync_before_exit}
-       wait
-       destroy_lttng_session_ok $SESSION_NAME
+       wait "${app_pid}"
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 
        rm -f ${file_sync_before_last}
        rm -f ${file_sync_before_last_touch}
@@ -586,7 +751,7 @@ function test_ust_streaming_tracefile_rotation ()
                validate_trace_count $EVENT_NAME $local_path 20
        fi
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 # With 1 byte per event (as strict minimum), generating 200000 events
@@ -609,7 +774,7 @@ function test_ust_streaming_tracefile_rotation_overwrite_files ()
                --tracefile-size=$PAGE_SIZE --tracefile-count=2 --buffers-$buffer_type
        enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME $channel_name
        start_lttng_tracing_ok $SESSION_NAME
-       taskset -c 0 $TESTAPP_BIN -i 200000
+       taskset -c "$(get_any_available_cpu)" $TESTAPP_BIN -i 200000
        do_clear_session $SESSION_NAME $tracing_active $clear_twice $rotate_before $rotate_after
        stop_lttng_tracing_ok $SESSION_NAME
 
@@ -624,7 +789,7 @@ function test_ust_streaming_tracefile_rotation_overwrite_files ()
        fi
 
        start_lttng_tracing_ok $SESSION_NAME
-       taskset -c 0 $TESTAPP_BIN -i 400000
+       taskset -c "$(get_any_available_cpu)" $TESTAPP_BIN -i 400000
        stop_lttng_tracing_ok
 
        if [[ $rotate_before -eq 1 ]]; then
@@ -633,7 +798,7 @@ function test_ust_streaming_tracefile_rotation_overwrite_files ()
                validate_trace_count_range_incl_min_excl_max $EVENT_NAME $local_path 1 200000
        fi
 
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 }
 
 function test_ust_disallow_clear ()
@@ -649,7 +814,7 @@ function test_ust_disallow_clear ()
        enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME
        start_lttng_tracing_ok $SESSION_NAME
        lttng_clear_session_fail $SESSION_NAME
-       destroy_lttng_session_ok $SESSION_NAME
+       destroy_lttng_session_ok $SESSION_NAME --no-wait
 
        stop_lttng_sessiond
        stop_lttng_relayd
@@ -660,21 +825,26 @@ plan_tests $NUM_TESTS
 
 print_test_banner "$TEST_DESC"
 
+bail_out_if_no_babeltrace
+
 streaming_tests=(test_ust_streaming
        test_ust_streaming_rotate_clear
        test_ust_streaming_clear_rotate
        test_ust_streaming_tracefile_rotation
        test_ust_streaming_tracefile_rotation_overwrite_files
+       test_ust_streaming_no_event
 )
 
 live_tests=(test_ust_streaming_live
        test_ust_basic_streaming_live_viewer
        test_ust_streaming_live_viewer
+       test_ust_streaming_live_viewer_new_metadata_after_clear
 )
 
 local_tests=(test_ust_local
        test_ust_local_rotate_clear
        test_ust_local_clear_rotate
+       test_ust_local_no_event
 )
 
 snapshot_uid_tests=(test_ust_streaming_snapshot
@@ -791,3 +961,5 @@ stop_lttng_sessiond
 stop_lttng_relayd
 
 test_ust_disallow_clear
+
+rm -rf "$TRACE_PATH"
This page took 0.040462 seconds and 4 git commands to generate.