[test] print log files
[doctor.git] / tests / run.sh
index b6bfc0b..37dbaf4 100755 (executable)
@@ -8,6 +8,8 @@
 # http://www.apache.org/licenses/LICENSE-2.0
 ##############################################################################
 
+# Configuration
+
 [[ "${CI_DEBUG:-true}" == [Tt]rue ]] && set -x
 
 IMAGE_URL=https://launchpad.net/cirros/trunk/0.3.0/+download/cirros-0.3.0-x86_64-disk.img
@@ -15,9 +17,11 @@ IMAGE_URL=https://launchpad.net/cirros/trunk/0.3.0/+download/cirros-0.3.0-x86_64
 IMAGE_NAME=${IMAGE_NAME:-cirros}
 IMAGE_FILE="${IMAGE_NAME}.img"
 IMAGE_FORMAT=qcow2
-VM_NAME=doctor_vm1
+VM_BASENAME=doctor_vm
 VM_FLAVOR=m1.tiny
-ALARM_NAME=doctor_alarm1
+#if VM_COUNT set, use that instead
+VM_COUNT=${VM_COUNT:-1}
+ALARM_BASENAME=doctor_alarm
 INSPECTOR_PORT=12345
 CONSUMER_PORT=12346
 DOCTOR_USER=doctor
@@ -25,188 +29,25 @@ DOCTOR_PW=doctor
 DOCTOR_PROJECT=doctor
 #TODO: change back to `_member_` when JIRA DOCTOR-55 is done
 DOCTOR_ROLE=admin
+PROFILER_TYPE=${PROFILER_TYPE:-none}
 
-SUPPORTED_INSTALLER_TYPES="apex fuel local"
-INSTALLER_TYPE=${INSTALLER_TYPE:-local}
-INSTALLER_IP=${INSTALLER_IP:-none}
-
-SUPPORTED_INSPECTOR_TYPES="sample congress"
-INSPECTOR_TYPE=${INSPECTOR_TYPE:-sample}
 TOP_DIR=$(cd $(dirname "$0") && pwd)
 
-ssh_opts="-o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no"
 as_doctor_user="--os-username $DOCTOR_USER --os-password $DOCTOR_PW
                 --os-tenant-name $DOCTOR_PROJECT"
 
-if [[ ! "$SUPPORTED_INSTALLER_TYPES" =~ "$INSTALLER_TYPE" ]] ; then
-    echo "ERROR: INSTALLER_TYPE=$INSTALLER_TYPE is not supported."
-    exit 1
-fi
-
-if [[ ! "$SUPPORTED_INSPECTOR_TYPES" =~ "$INSPECTOR_TYPE" ]] ; then
-    echo "ERROR: INSPECTOR_TYPE=$INSPECTOR_TYPE is not supported."
-    exit 1
-fi
-
-get_installer_ip() {
-    if [[ "$INSTALLER_TYPE" == "apex" ]] ; then
-        if [[ "$INSTALLER_IP" == "none" ]] ; then
-            instack_mac=$(sudo virsh domiflist instack | awk '/default/{print $5}')
-            INSTALLER_IP=$(/usr/sbin/arp -e | grep ${instack_mac} | awk '{print $1}')
-        fi
-    elif [[ "$INSTALLER_TYPE" == "fuel" ]] ; then
-        if [[ "$INSTALLER_IP" == "none" ]] ; then
-            instack_mac=$(sudo virsh domiflist fuel-opnfv | awk '/pxebr/{print $5}')
-            INSTALLER_IP=$(/usr/sbin/arp -e | grep ${instack_mac} | awk '{print $1}')
-        fi
-    fi
-
-    if [[ "$INSTALLER_TYPE" != "local" ]] ; then
-        die_if_not_set $LINENO INSTALLER_IP "No installer IP"
-    fi
-}
-
-prepare_ssh_to_cloud() {
-    ssh_opts_cpu="$ssh_opts"
-
-    # get ssh key from installer node
-    if [[ "$INSTALLER_TYPE" == "apex" ]] ; then
-        sudo scp $ssh_opts root@"$INSTALLER_IP":/home/stack/.ssh/id_rsa instack_key
-        sudo chown $(whoami):$(whoami) instack_key
-        chmod 400 instack_key
-        ssh_opts_cpu+=" -i instack_key"
-    elif [[ "$INSTALLER_TYPE" == "fuel" ]] ; then
-        sshpass -p r00tme scp $ssh_opts root@${INSTALLER_IP}:.ssh/id_rsa instack_key
-        sudo chown $(whoami):$(whoami) instack_key
-        chmod 400 instack_key
-        ssh_opts_cpu+=" -i instack_key"
-    elif [[ "$INSTALLER_TYPE" == "local" ]] ; then
-        echo "INSTALLER_TYPE set to 'local'. Assuming SSH keys already exchanged with $COMPUTE_HOST"
-    fi
-}
-
-prepare_test_env() {
-    #TODO delete it when fuel support the configuration
-    if [[ "$INSTALLER_TYPE" == "fuel" ]] ; then
-        echo "modify the configuration..."
-        cat > set_conf.sh << 'END_TXT'
-#!/bin/bash
-if [ -e /etc/ceilometer/event_pipeline.yaml ]; then
-    if ! grep -q '^ *- notifier://?topic=alarm.all$' /etc/ceilometer/event_pipeline.yaml; then
-        sed -i 's|- notifier://|- notifier://?topic=alarm.all|' /etc/ceilometer/event_pipeline.yaml
-        echo "modify the ceilometer config"
-        service ceilometer-agent-notification restart
-    fi
-else
-    echo "ceilometer event_pipeline.yaml file does not exist"
-    exit 1
-fi
-if [ -e /etc/nova/nova.conf ]; then
-    if ! grep -q '^notification_driver=messaging$' /etc/nova/nova.conf; then
-        sed -i -r 's/notification_driver=/notification_driver=messaging/g' /etc/nova/nova.conf
-        echo "modify nova config"
-        service nova-api restart
-    fi
-else
-    echo "nova.conf file does not exist"
-    exit 1
-fi
-exit 0
-END_TXT
-        chmod +x set_conf.sh
-        CONTROLLER_IP=$(sshpass -p r00tme ssh 2>/dev/null $ssh_opts root@${INSTALLER_IP} \
-             "fuel node | grep controller | cut -d '|' -f 5|xargs")
-        for node in $CONTROLLER_IP;do
-            scp $ssh_opts_cpu set_conf.sh "root@$node:"
-            ssh $ssh_opts_cpu "root@$node" './set_conf.sh > set_conf.log 2>&1 &'
-            sleep 1
-            scp $ssh_opts_cpu "root@$node:set_conf.log" set_conf_$node.log
-        done
-
-        if grep -q "modify the ceilometer config" set_conf_*.log ; then
-            NEED_TO_RESTORE_CEILOMETER=true
-        fi
-        if grep -q "modify nova config" set_conf_*.log ; then
-            NEED_TO_RESTORE_NOVA=true
-        fi
-
-        echo "waiting service restart..."
-        sleep 60
-    fi
-}
-
-restore_test_env() {
-    #TODO delete it when fuel support the configuration
-    if [[ "$INSTALLER_TYPE" == "fuel" ]] ; then
-        if ! ($NEED_TO_RESTORE_CEILOMETER || $NEED_TO_RESTORE_NOVA) ; then
-            echo "Don't need to restore config"
-            exit 0
-        fi
-
-        echo "restore the configuration..."
-        cat > restore_conf.sh << 'END_TXT'
-#!/bin/bash
-if @NEED_TO_RESTORE_CEILOMETER@ ; then
-    if [ -e /etc/ceilometer/event_pipeline.yaml ]; then
-        if grep -q '^ *- notifier://?topic=alarm.all$' /etc/ceilometer/event_pipeline.yaml; then
-            sed -i 's|- notifier://?topic=alarm.all|- notifier://|' /etc/ceilometer/event_pipeline.yaml
-            service ceilometer-agent-notification restart
-        fi
-    else
-        echo "ceilometer event_pipeline.yaml file does not exist"
-        exit 1
-    fi
-fi
-if @NEED_TO_RESTORE_NOVA@ ; then
-    if [ -e /etc/nova/nova.conf ]; then
-        if grep -q '^notification_driver=messaging$' /etc/nova/nova.conf; then
-            sed -i -r 's/notification_driver=messaging/notification_driver=/g' /etc/nova/nova.conf
-            service nova-api restart
-        fi
-    else
-        echo "nova.conf file does not exist"
-        exit 1
-    fi
-fi
-exit 0
-END_TXT
-        sed -i -e "s/@NEED_TO_RESTORE_CEILOMETER@/$NEED_TO_RESTORE_CEILOMETER/" restore_conf.sh
-        sed -i -e "s/@NEED_TO_RESTORE_NOVA@/$NEED_TO_RESTORE_NOVA/" restore_conf.sh
-        chmod +x restore_conf.sh
-        for node in $CONTROLLER_IP;do
-            scp $ssh_opts_cpu restore_conf.sh "root@$node:"
-            ssh $ssh_opts_cpu "root@$node" './restore_conf.sh > restore_conf.log 2>&1 &'
-        done
 
-        echo "waiting service restart..."
-        sleep 60
-    fi
-}
+# Functions
 
 get_compute_host_info() {
-    # get computer host info which VM boot in
-    COMPUTE_HOST=$(openstack $as_doctor_user server show $VM_NAME |
+    # get computer host info which first VM boot in
+    COMPUTE_HOST=$(openstack $as_doctor_user server show ${VM_BASENAME}1 |
                    grep "OS-EXT-SRV-ATTR:host" | awk '{ print $4 }')
     compute_host_in_undercloud=${COMPUTE_HOST%%.*}
     die_if_not_set $LINENO COMPUTE_HOST "Failed to get compute hostname"
 
-    if [[ "$INSTALLER_TYPE" == "apex" ]] ; then
-        COMPUTE_USER=${COMPUTE_USER:-heat-admin}
-        COMPUTE_IP=$(sudo ssh $ssh_opts $INSTALLER_IP \
-             "source stackrc; \
-             nova show $compute_host_in_undercloud \
-             | awk '/ ctlplane network /{print \$5}'")
-    elif [[ "$INSTALLER_TYPE" == "fuel" ]] ; then
-        COMPUTE_USER=${COMPUTE_USER:-root}
-        node_id=$(echo $compute_host_in_undercloud | cut -d "-" -f 2)
-        COMPUTE_IP=$(sshpass -p r00tme ssh 2>/dev/null $ssh_opts root@${INSTALLER_IP} \
-             "fuel node|awk -F '|' -v id=$node_id '{if (\$1 == id) print \$5}' |xargs")
-    elif [[ "$INSTALLER_TYPE" == "local" ]] ; then
-        COMPUTE_USER=${COMPUTE_USER:-$(whoami)}
-        COMPUTE_IP=$(getent hosts "$COMPUTE_HOST" | awk '{ print $1 }')
-    fi
+    get_compute_ip_from_hostname $COMPUTE_HOST
 
-    die_if_not_set $LINENO COMPUTE_IP "Could not resolve $COMPUTE_HOST. Either manually set COMPUTE_IP or enable DNS resolution."
     echo "COMPUTE_HOST=$COMPUTE_HOST"
     echo "COMPUTE_IP=$COMPUTE_IP"
 
@@ -223,15 +64,17 @@ get_compute_host_info() {
     fi
 }
 
-get_consumer_ip() {
+# TODO(r-mibu): update this function to support consumer instance
+#               and migrate this function into installer lib
+get_consumer_ip___to_be_removed() {
     local get_consumer_command="ip route get $COMPUTE_IP | awk '/ src /{print \$NF}'"
-    if [[ "$INSTALLER_TYPE" == "apex" ]] ; then
+    if is_installer apex; then
         CONSUMER_IP=$(sudo ssh $ssh_opts root@$INSTALLER_IP \
                       "$get_consumer_command")
-    elif [[ "$INSTALLER_TYPE" == "fuel" ]] ; then
+    elif is_installer fuel; then
         CONSUMER_IP=$(sudo sshpass -p r00tme ssh $ssh_opts root@${INSTALLER_IP} \
                       "$get_consumer_command")
-    elif [[ "$INSTALLER_TYPE" == "local" ]] ; then
+    elif is_installer local; then
         CONSUMER_IP=`$get_consumer_command`
     fi
     echo "CONSUMER_IP=$CONSUMER_IP"
@@ -272,31 +115,60 @@ create_test_user() {
         openstack role add "$DOCTOR_ROLE" --user "$DOCTOR_USER" \
                            --project "$DOCTOR_PROJECT"
     }
+    # tojuvone: openstack quota show is broken and have to use nova
+    # https://bugs.launchpad.net/manila/+bug/1652118
+    # Note! while it is encouraged to use openstack client it has proven
+    # quite buggy.
+    # QUOTA=$(openstack quota show $DOCTOR_PROJECT)
+    DOCTOR_QUOTA=$(nova quota-show --tenant DOCTOR_PROJECT)
+    # We make sure that quota allows number of instances and cores
+    OLD_INSTANCE_QUOTA=$(echo "${DOCTOR_QUOTA}" | grep " instances " | \
+                         awk '{print $4}')
+    if [ $OLD_INSTANCE_QUOTA -lt $VM_COUNT ]; then
+        openstack quota set --instances $VM_COUNT \
+                  $DOCTOR_USER
+    fi
+    OLD_CORES_QUOTA=$(echo "${DOCTOR_QUOTA}" | grep " cores " | \
+                      awk '{print $4}')
+    if [ $OLD_CORES_QUOTA -lt $VM_COUNT ]; then
+        openstack quota set --cores $VM_COUNT \
+                  $DOCTOR_USER
+    fi
 }
 
 boot_vm() {
     # test VM done with test user, so can test non-admin
-    openstack $as_doctor_user server list | grep -q " $VM_NAME " && return 0
-    openstack $as_doctor_user server create --flavor "$VM_FLAVOR" \
+    servers=$(openstack $as_doctor_user server list)
+    for i in `seq $VM_COUNT`; do
+        echo "${servers}" | grep -q " $VM_BASENAME$i " && continue
+        openstack $as_doctor_user server create --flavor "$VM_FLAVOR" \
                             --image "$IMAGE_NAME" \
-                            "$VM_NAME"
+                            "$VM_BASENAME$i"
+    done
     sleep 1
 }
 
 create_alarm() {
     # get vm_id as test user
-    ceilometer $as_doctor_user alarm-list | grep -q " $ALARM_NAME " && return 0
-    vm_id=$(openstack $as_doctor_user server list | grep " $VM_NAME " | awk '{print $2}')
-    # TODO(r-mibu): change notification endpoint from localhost to the consumer
-    # IP address (functest container).
-    ceilometer $as_doctor_user alarm-event-create --name "$ALARM_NAME" \
-        --alarm-action "http://localhost:$CONSUMER_PORT/failure" \
-        --description "VM failure" \
-        --enabled True \
-        --repeat-actions False \
-        --severity "moderate" \
-        --event-type compute.instance.update \
-        -q "traits.state=string::error; traits.instance_id=string::$vm_id"
+    alarm_list=$(ceilometer $as_doctor_user alarm-list)
+    vms=$(openstack $as_doctor_user server list)
+    for i in `seq $VM_COUNT`; do
+        echo "${alarm_list}" | grep -q " $ALARM_BASENAME$i " || {
+            vm_id=$(echo "${vms}" | grep " $VM_BASENAME$i " | awk '{print $2}')
+            # TODO(r-mibu): change notification endpoint from localhost to the
+            # consumer. IP address (functest container).
+            ceilometer $as_doctor_user alarm-event-create \
+                       --name "$ALARM_BASENAME$i" \
+                       --alarm-action "http://localhost:$CONSUMER_PORT/failure" \
+                       --description "VM failure" \
+                       --enabled True \
+                       --repeat-actions False \
+                       --severity "moderate" \
+                       --event-type compute.instance.update \
+                       -q "traits.state=string::error; \
+                       traits.instance_id=string::$vm_id"
+            }
+     done
 }
 
 start_monitor() {
@@ -310,78 +182,6 @@ stop_monitor() {
     sudo kill $(pgrep -f "python monitor.py")
 }
 
-congress_add_rule() {
-    name=$1
-    policy=$2
-    rule=$3
-
-    if ! openstack congress policy rule list $policy | grep -q -e "// Name: $name$" ; then
-        openstack congress policy rule create --name $name $policy "$rule"
-    fi
-}
-
-congress_del_rule() {
-    name=$1
-    policy=$2
-
-    if openstack congress policy rule list $policy | grep -q -e "^// Name: $name$" ; then
-        openstack congress policy rule delete $policy $name
-    fi
-}
-
-congress_setup_rules() {
-    congress_add_rule host_down classification \
-        'host_down(host) :-
-            doctor:events(hostname=host, type="compute.host.down", status="down")'
-
-    congress_add_rule active_instance_in_host classification \
-        'active_instance_in_host(vmid, host) :-
-            nova:servers(id=vmid, host_name=host, status="ACTIVE")'
-
-    congress_add_rule host_force_down classification \
-        'execute[nova:services.force_down(host, "nova-compute", "True")] :-
-            host_down(host)'
-
-    congress_add_rule error_vm_states classification \
-        'execute[nova:servers.reset_state(vmid, "error")] :-
-            host_down(host),
-            active_instance_in_host(vmid, host)'
-}
-
-start_inspector() {
-    if [[ "$INSPECTOR_TYPE" == "sample" ]] ; then
-        pgrep -f "python inspector.py" && return 0
-        python inspector.py "$INSPECTOR_PORT" > inspector.log 2>&1 &
-    elif [[ "$INSPECTOR_TYPE" == "congress" ]] ; then
-        nova_api_min_version="2.11"
-        nova_api_version=$(openstack congress datasource list | \
-                           grep nova | grep -Po "(?<='api_version': ')[^']*")
-        if ! is_set nova_api_version; then
-            nova_api_version="2.0"
-        fi
-        if [[ "$nova_api_version" < "$nova_api_min_version" ]]; then
-            die $LINENO "Congress Nova datasource API version < $nova_api_min_version ($nova_api_version)"
-        fi
-        openstack congress driver list | grep -q " doctor "
-        openstack congress datasource list | grep -q " doctor " || {
-            openstack congress datasource create doctor doctor
-        }
-        congress_setup_rules
-    fi
-}
-
-stop_inspector() {
-    if [[ "$INSPECTOR_TYPE" == "sample" ]] ; then
-        pgrep -f "python inspector.py" || return 0
-        kill $(pgrep -f "python inspector.py")
-    elif [[ "$INSPECTOR_TYPE" == "congress" ]] ; then
-        congress_del_rule host_force_down classification
-        congress_del_rule error_vm_states classification
-        congress_del_rule active_instance_in_host classification
-        congress_del_rule host_down classification
-    fi
-}
-
 start_consumer() {
     pgrep -f "python consumer.py" && return 0
     python consumer.py "$CONSUMER_PORT" > consumer.log 2>&1 &
@@ -389,18 +189,7 @@ start_consumer() {
     # NOTE(r-mibu): create tunnel to the controller nodes, so that we can
     # avoid some network problems dpends on infra and installers.
     # This tunnel will be terminated by stop_consumer() or after 10 mins passed.
-    if [[ "$INSTALLER_TYPE" != "local" ]] ; then
-        if [[ "$INSTALLER_TYPE" == "apex" ]] ; then
-            CONTROLLER_IPS=$(sudo ssh $ssh_opts $INSTALLER_IP \
-                             "source stackrc; \
-                             nova list | grep ' overcloud-controller-[0-9] ' \
-                             | sed -e 's/^.*ctlplane=//' -e 's/ *|\$//'")
-        elif [[ "$INSTALLER_TYPE" == "fuel" ]] ; then
-            CONTROLLER_IPS=$(sshpass -p r00tme ssh 2>/dev/null $ssh_opts root@${INSTALLER_IP} \
-                            "fuel node | grep controller | cut -d '|' -f 5|xargs")
-        fi
-
-        die_if_not_set $LINENO CONTROLLER_IPS "Could not get CONTROLLER_IPS."
+    if ! is_installer local; then
         for ip in $CONTROLLER_IPS
         do
             forward_rule="-R $CONSUMER_PORT:localhost:$CONSUMER_PORT"
@@ -415,7 +204,7 @@ stop_consumer() {
     kill $(pgrep -f "python consumer.py")
 
     # NOTE(r-mibu): terminate tunnels to the controller nodes
-    if [[ "$INSTALLER_TYPE" != "local" ]] ; then
+    if ! is_installer local; then
         for ip in $CONTROLLER_IPS
         do
             forward_rule="-R $CONSUMER_PORT:localhost:$CONSUMER_PORT"
@@ -431,18 +220,31 @@ wait_for_vm_launch() {
     count=0
     while [[ ${count} -lt 60 ]]
     do
-        state=$(openstack $as_doctor_user server list | grep " $VM_NAME " | awk '{print $6}')
-        if [[ "$state" == "ACTIVE" ]]; then
-            # NOTE(cgoncalves): sleeping for a bit to stabilize
-            # See python-openstackclient/functional/tests/compute/v2/test_server.py:wait_for_status
-            sleep 5
+        active_count=0
+        vms=$(openstack $as_doctor_user server list)
+        for i in `seq $VM_COUNT`; do
+            state=$(echo "${vms}" | grep " $VM_BASENAME$i " | awk '{print $6}')
+            if [[ "$state" == "ACTIVE" ]]; then
+                active_count=$(($active_count+1))
+            elif [[ "$state" == "ERROR" ]]; then
+                die $LINENO "vm state $VM_BASENAME$i is ERROR"
+            else
+                #This VM not yet active
+                count=$(($count+1))
+                sleep 5
+                continue
+            fi
+        done
+        [[ $active_count -eq $VM_COUNT ]] && {
+            echo "get computer host info..."
+            get_compute_host_info
+            VMS_ON_FAILED_HOST=$(openstack $as_doctor_user server list --host \
+                         $COMPUTE_HOST | grep " ${VM_BASENAME}" |  wc -l)
             return 0
-        fi
-        if [[ "$state" == "ERROR" ]]; then
-            die $LINENO "vm state is ERROR"
-        fi
+        }
+        #Not all VMs active
         count=$(($count+1))
-        sleep 1
+        sleep 5
     done
     die $LINENO "Time out while waiting for VM launch"
 }
@@ -452,8 +254,10 @@ inject_failure() {
     cat > disable_network.sh << 'END_TXT'
 #!/bin/bash -x
 dev=$(sudo ip a | awk '/ @COMPUTE_IP@\//{print $7}')
+[[ -n "$dev" ]] || dev=$(sudo ip a | awk '/ @COMPUTE_IP@\//{print $5}')
 sleep 1
 sudo ip link set $dev down
+echo "doctor set link down at" $(date "+%s.%N")
 sleep 180
 sudo ip link set $dev up
 sleep 1
@@ -462,14 +266,32 @@ END_TXT
     chmod +x disable_network.sh
     scp $ssh_opts_cpu disable_network.sh "$COMPUTE_USER@$COMPUTE_IP:"
     ssh $ssh_opts_cpu "$COMPUTE_USER@$COMPUTE_IP" 'nohup ./disable_network.sh > disable_network.log 2>&1 &'
+    # use host time to get rid of potential time sync deviation between nodes
+    triggered=$(date "+%s.%N")
+}
+
+wait_consumer() {
+    local interval=1
+    local rounds=$(($1 / $interval))
+    for i in `seq $rounds`; do
+        notified_count=$(grep "doctor consumer notified at" consumer.log | wc -l)
+        if [[ $notified_count -eq  $VMS_ON_FAILED_HOST ]]; then
+            return 0
+        fi
+        sleep $interval
+    done
+    die $LINENO "Consumer hasn't received fault notification."
 }
 
 calculate_notification_time() {
-    detected=$(grep "doctor monitor detected at" monitor.log | awk '{print $10}')
-    notified=$(grep "doctor consumer notified at" consumer.log | awk '{print $10}')
-    if ! grep -q "doctor consumer notified at" consumer.log ; then
-        die $LINENO "Consumer hasn't received fault notification."
-    fi
+    wait_consumer 60
+    #keep 'at' as the last keyword just before the value, and
+    #use regex to get value instead of the fixed column
+    detected=$(grep "doctor monitor detected at" monitor.log |\
+               sed -e "s/^.* at //")
+    notified=$(grep "doctor consumer notified at" consumer.log |\
+               sed -e "s/^.* at //" | tail -1)
+
     echo "$notified $detected" | \
         awk '{
             d = $1 - $2;
@@ -478,17 +300,93 @@ calculate_notification_time() {
         }'
 }
 
+wait_ping() {
+    local interval=5
+    local rounds=$(($1 / $interval))
+    for i in `seq $rounds`; do
+        ping -c 1 "$COMPUTE_IP"
+        if [[ $? -ne 0 ]] ; then
+            sleep $interval
+            continue
+        fi
+        return 0
+    done
+}
+
 check_host_status() {
+    # Check host related to first Doctor VM is in wanted state
+    # $1    Expected state
+    # $2    Seconds to wait to have wanted state
     expected_state=$1
-
-    host_status_line=$(openstack $as_doctor_user --os-compute-api-version 2.16 \
-                       server show $VM_NAME | grep "host_status")
-    host_status=$(echo $host_status_line | awk '{print $4}')
-    die_if_not_set $LINENO host_status "host_status not reported by: nova show $VM_NAME"
+    local interval=5
+    local rounds=$(($2 / $interval))
+    for i in `seq $rounds`; do
+        host_status_line=$(openstack $as_doctor_user --os-compute-api-version \
+                           2.16 server show ${VM_BASENAME}1 | grep "host_status")
+        host_status=$(echo $host_status_line | awk '{print $4}')
+        die_if_not_set $LINENO host_status "host_status not reported by: nova show ${VM_BASENAME}1"
+        if [[ "$expected_state" =~ "$host_status" ]] ; then
+            echo "${VM_BASENAME}1 showing host_status: $host_status"
+            return 0
+        else
+            sleep $interval
+        fi
+    done
     if [[ "$expected_state" =~ "$host_status" ]] ; then
-        echo "$VM_NAME showing host_status: $host_status"
+        echo "${VM_BASENAME}1 showing host_status: $host_status"
     else
-        die $LINENO "host_status:$host_status not equal to expected_state: $expected_state"
+        die $LINENO  "host_status:$host_status not equal to expected_state: $expected_state"
+    fi
+}
+
+unset_forced_down_hosts() {
+    for host in $(openstack compute service list --service nova-compute \
+                  -f value -c Host -c State | sed -n -e '/down$/s/ *down$//p')
+    do
+        # TODO (r-mibu): make sample inspector use keystone v3 api
+        OS_AUTH_URL=${OS_AUTH_URL/v3/v2.0} \
+        python ./nova_force_down.py $host --unset
+    done
+
+    echo "waiting disabled compute host back to be enabled..."
+    wait_until 'openstack compute service list --service nova-compute
+                -f value -c State | grep -q down' 240 5
+}
+
+collect_logs() {
+    unset_forced_down_hosts
+    # TODO: We need to make sure the target compute host is back to IP
+    #       reachable. wait_ping() will be added by tojuvone .
+    sleep 110
+    scp $ssh_opts_cpu "$COMPUTE_USER@$COMPUTE_IP:disable_network.log" .
+
+    # TODO(yujunz) collect other logs, e.g. nova, aodh
+}
+
+run_profiler() {
+    if [[ "$PROFILER_TYPE" == "poc" ]]; then
+        linkdown=$(grep "doctor set link down at " disable_network.log |\
+                  sed -e "s/^.* at //")
+        vmdown=$(grep "doctor mark vm.* error at" inspector.log |tail -n 1 |\
+                 sed -e "s/^.* at //")
+        hostdown=$(grep "doctor mark host.* down at" inspector.log |\
+                 sed -e "s/^.* at //")
+
+        # TODO(yujunz) check the actual delay to verify time sync status
+        # expected ~1s delay from $trigger to $linkdown
+        relative_start=${linkdown}
+        export DOCTOR_PROFILER_T00=$(python -c \
+          "print(int(($linkdown-$relative_start)*1000))")
+        export DOCTOR_PROFILER_T01=$(python -c \
+          "print(int(($detected-$relative_start)*1000))")
+        export DOCTOR_PROFILER_T03=$(python -c \
+          "print(int(($vmdown-$relative_start)*1000))")
+        export DOCTOR_PROFILER_T04=$(python -c \
+          "print(int(($hostdown-$relative_start)*1000))")
+        export DOCTOR_PROFILER_T09=$(python -c \
+          "print(int(($notified-$relative_start)*1000))")
+
+        python profiler-poc.py >doctor_profiler.log 2>&1
     fi
 }
 
@@ -499,17 +397,24 @@ cleanup() {
     stop_inspector
     stop_consumer
 
-    echo "waiting disabled compute host back to be enabled..."
-    python ./nova_force_down.py "$COMPUTE_HOST" --unset
-    sleep 240
-    check_host_status "UP"
-    scp $ssh_opts_cpu "$COMPUTE_USER@$COMPUTE_IP:disable_network.log" .
+    unset_forced_down_hosts
 
-    openstack $as_doctor_user server list | grep -q " $VM_NAME " && openstack $as_doctor_user server delete "$VM_NAME"
-    sleep 1
-    alarm_id=$(ceilometer $as_doctor_user alarm-list | grep " $ALARM_NAME " | awk '{print $2}')
-    sleep 1
-    [ -n "$alarm_id" ] && ceilometer $as_doctor_user alarm-delete "$alarm_id"
+    wait_ping 120
+
+    scp $ssh_opts_cpu "$COMPUTE_USER@$COMPUTE_IP:disable_network.log" .
+    vms=$(openstack $as_doctor_user server list)
+    vmstodel=""
+    for i in `seq $VM_COUNT`; do
+        $(echo "${vms}" | grep -q " $VM_BASENAME$i ") &&
+        vmstodel+=" $VM_BASENAME$i"
+    done
+    [[ $vmstodel ]] && openstack $as_doctor_user server delete $vmstodel
+    alarm_list=$(ceilometer $as_doctor_user alarm-list)
+    for i in `seq $VM_COUNT`; do
+        alarm_id=$(echo "${alarm_list}" | grep " $ALARM_BASENAME$i " |
+                   awk '{print $2}')
+        [ -n "$alarm_id" ] && ceilometer $as_doctor_user alarm-delete "$alarm_id"
+    done
     sleep 1
 
     image_id=$(openstack image list | grep " $IMAGE_NAME " | awk '{print $2}')
@@ -523,20 +428,31 @@ cleanup() {
     openstack project delete "$DOCTOR_PROJECT"
     openstack user delete "$DOCTOR_USER"
 
-    restore_test_env
+    cleanup_installer
+    cleanup_inspector
+
+    # NOTE: Temporal log printer.
+    for f in $(find . -name '*.log')
+    do
+        echo
+        echo "[$f]"
+        sed -e 's/^/ | /' $f
+        echo
+    done
 }
 
+# Main process
 
 echo "Note: doctor/tests/run.sh has been executed."
+git log --oneline -1 || true   # ignore even you don't have git installed
 
 trap cleanup EXIT
 
 source $TOP_DIR/functions-common
+source $TOP_DIR/lib/installer
+source $TOP_DIR/lib/inspector
 
-echo "preparing test env..."
-get_installer_ip
-prepare_ssh_to_cloud
-prepare_test_env
+setup_installer
 
 echo "preparing VM image..."
 download_image
@@ -549,9 +465,6 @@ echo "creating VM..."
 boot_vm
 wait_for_vm_launch
 
-echo "get computer host info..."
-get_compute_host_info
-
 echo "creating alarm..."
 #TODO: change back to use, network problems depends on infra and installers
 #get_consumer_ip
@@ -565,9 +478,10 @@ start_consumer
 sleep 60
 echo "injecting host failure..."
 inject_failure
-sleep 60
 
-check_host_status "(DOWN|UNKNOWN)"
+check_host_status "(DOWN|UNKNOWN)" 60
 calculate_notification_time
+collect_logs
+run_profiler
 
 echo "done"