error logs when "dog vdi delete" deletes VDI

Bug #1312500 reported by Yuichi Bando
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
sheepdog
New
Undecided
Unassigned

Bug Description

Sheep outputs error logs such "No Object Found" and "remove object <OID> fail" when "dog vdi delete" deletes VDI.
I found this bug in the long-term stability test which repeats snapshot and rollback.

[Possible cause]
When I delete 2 snapshots and original VDI,
sheep attempts to delete a deleted data object.
But the data object has already been deleted in the first "dog vdi delete".

[How to reproduce]
I give 3 scripts for reproduction.
Please execute "108_failed-to-remove-object-log-output.sh"
I confirmed this scripts both in stable-0.7 master and mainline.

################ 108_failed-to-remove-object-log-output.sh ##################
#!/bin/bash

SHDIR=`cd $(dirname $0); pwd`
. ${SHDIR}/common_functions.sh
. ${SHDIR}/assert_functions.sh

echo "### sheep & tgtd restart."
_env_format

_start_sheep 1

tgtd -d 1

echo "### wait startup sheep,tgtd"
_wait_sheep_running_with_format || exit 1
_wait_tgtd_running || exit 1

echo "##### (1) create vdi and target(lu, acl)."
dog vdi create testvdi 1G
sleep 2
tgtadm -m target -o new --tid 1 --targetname iqn.2014-03.powder.osrg.net:testvdi
tgtadm -m logicalunit -o new --tid 1 --lun 1 --backing-store unix:/tmp/sheepdog0/sock:testvdi --bstype sheepdog
sleep 1
tgtadm -m target -o bind --tid 1 --initiator-address ALL
tgtadm -m target -o show
sleep 3

echo "##### (2) initiator login"
iscsiadm -m discovery -t sendtargets -p 127.0.0.1
sleep 2
iscsiadm -m node -T iqn.2014-03.powder.osrg.net:testvdi --login
_wait_exist_symboliclink /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2014-03.powder.osrg.net:testvdi-lun-1

echo "##### (3) disk format"
fdisk /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2014-03.powder.osrg.net:testvdi-lun-1 << EOF
n
p
1

w
EOF
sleep 2
ls -l /dev/disk/by-path/ip-*

mkfs.ext4 /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2014-03.powder.osrg.net:testvdi-lun-1-part1
sleep 3

echo "##### (4) iSCSI disk mount"

mkdir -p /mnt/test

mount /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2014-03.powder.osrg.net:testvdi-lun-1-part1 /mnt/test
sleep 3

echo "##### (5) create file1 to mount disk"

touch /mnt/test/file1
sync

echo "##### (6) create snapshot"

dog vdi snapshot testvdi

echo "##### (7) create file2 to mount disk"

touch /mnt/test/file2
sync

echo "##### (8) create snapshot"

dog vdi snapshot testvdi

echo "##### (9) create file3 to mount disk"

touch /mnt/test/file3
sync

ls -la /mnt/test

echo "##### (10) iSCSI disk umount"

umount /mnt/test

echo "##### (11) initiator logout"

iscsiadm -m node -T iqn.2014-03.powder.osrg.net:testvdi --logout
sleep 3

echo "##### (12) target delete"

tgtadm --lld iscsi --op unbind --mode target --tid 1 -I ALL
tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1
tgtadm --lld iscsi --op delete --mode target --tid 1

echo "##### (13) vdi rollback"

dog vdi rollback -f -s 1 testvdi

echo "##### (14) target recreate"

tgtadm -m target -o new --tid 1 --targetname iqn.2014-03.powder.osrg.net:testvdi
tgtadm -m logicalunit -o new --tid 1 --lun 1 --backing-store unix:/tmp/sheepdog0/sock:testvdi --bstype sheepdog
tgtadm -m target -o bind --tid 1 -I ALL
tgtadm -m target -o show

echo "##### (15) initiator login"
iscsiadm -m node -T iqn.2014-03.powder.osrg.net:testvdi --login
sleep 3

echo "##### (16) iSCSI disk mount"

mount /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2014-03.powder.osrg.net:testvdi-lun-1-part1 /mnt/test
sleep 2

echo "##### (17) check file exist"

ls -la /mnt/test

echo "##### (18) initiator logout"

iscsiadm -m node -T iqn.2014-03.powder.osrg.net:testvdi --logout
sleep 3

echo "##### (19) target delete"

tgtadm --lld iscsi --op unbind --mode target --tid 1 -I ALL
tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1
tgtadm --lld iscsi --op delete --mode target --tid 1

echo "##### (20) vdi(id:0) delete"

VDIID=`dog vdi list -r | grep "testvdi 0" | cut -d' ' -f8`
dog vdi delete testvdi
sleep 2

echo "##### (21) vdi(id:1) delete"

dog vdi delete -s 1 testvdi
sleep 2

echo "##### (22) vdi(id:2) delete"

dog vdi delete -s 2 testvdi
sleep 2

echo "##### (23) assert ERROR message"
MSG=`grep ERROR /tmp/sheepdog0/sheep.log`
_assert_null "${MSG}" "error message output"
if [ $? -ne 0 ]; then
  echo "-------------------"
  echo "$MSG"
  echo "-------------------"
  exit 1
fi

exit 0

################ common_functions.sh ##################
#!/bin/bash

## COMMANDS
DOG='/usr/sbin/dog'
SHEEP='/usr/sbin/sheep'
TGTD='/sbin/tgtd'

## COMMON LIBRARY PARAM
TIMEOUT=60 # sec

## COMMON LIBRARY
function _env_format() {
  umount /mnt/* >/dev/null 2>&1
  iscsiadm -m node --logout >/dev/null 2>&1
  pkill -9 sheep
  pkill -9 tgtd
  pkill -9 iscsid
  rm -rf /tmp/sheepdog*
  rm -rf /var/lib/iscsi
  service corosync restart
}

function _start_sheep() {
  ## param[1]: exec sheep proc num
  test $# != 1 && echo "specific param[1]:exec sheep proc num" && return 1
  for i in `seq 0 $(expr $1 - 1)`; do
    mkdir -p /tmp/sheepdog${i}
    if [ `${SHEEP} -v | cut -d' ' -f4 | grep 0.7 | wc -l` == 1 ]; then
      ${SHEEP} -z ${i} -p 700${i} -l 7 /tmp/sheepdog${i}
    else
      ${SHEEP} -z ${i} -p 700${i} -l level=debug /tmp/sheepdog${i}
    fi
  done
  return 0
}

function _wait_sheep_running() {
  for i in `seq 1 ${TIMEOUT}`; do
    test `${DOG} cluster info | grep "Cluster status" | cut -d, -f1 | cut -d: -f2 | sed "s/ //g"`x == "running"x && return 0
    sleep 1
  done
  echo "[ERROR] sheep start timeout (${TIMEOUT}s)."
  return 1
}

function _wait_sheep_running_with_format() {
  for i in `seq 1 ${TIMEOUT}`; do
    yes yes | ${DOG} cluster format 2>/dev/null
    test `${DOG} cluster info | grep "Cluster status" | cut -d, -f1 | cut -d: -f2 | sed "s/ //g"`x == "running"x && return 0
    sleep 1
  done
  echo "[ERROR] sheep start timeout (${TIMEOUT}s)."
  return 1
}

function _wait_tgtd_running() {
  for i in `seq 1 ${TIMEOUT}`; do
    test `tgtadm -m system -o show | grep State | cut -d: -f2 | sed "s/ //g"`x == "ready"x && return 0
    sleep 1
  done
  echo "[ERROR] tgtd start timeout (${TIMEOUT}s)."
  return 1
}

function _wait_exist_symboliclink() {
  ## param[1]: check syncboliclink path
  test $# != 1 && echo "specific param[1]:check syncboliclink path" && return 1
  for i in `seq 1 ${TIMEOUT}`; do
    test -h $1 && return 0
    sleep 1
  done
  echo "[ERROR] symboliclink exist check timeout (${TIMEOUT}s)."
  return 1

}

################ assert_functions.sh ##################
#!/bin/bash

##
## ASSERT FUNCTIONS
##

#-----------------------------------
# func : _assert_equal
# desc : Asserts that two objects are equal.
# param: $1: inspection
# $2: expect
# $3: output error message
#-----------------------------------
function _assert_equal() {
  if [ "$1"x == "$2"x ]; then
    return 0
  else
    echo "[ERROR] $3, \"$1\" expect equals \"$2\"."
    return 1
  fi
}

#-----------------------------------
# func : _assert_not_equal
# desc : Asserts that two objects does not equal.
# param: $1: inspection
# $2: expect
# $3: output error message
#-----------------------------------
function _assert_not_equal() {
  if [ "$1"x != "$2"x ]; then
    return 0
  else
    echo "[ERROR] $3, \"$1\" expect not equals \"$2\"."
    return 1
  fi
}

#-----------------------------------
# func : _assert_null
# desc : Asserts that an object is null.
# param: $1: inspection
# $2: output error message
#-----------------------------------
function _assert_null() {
  ret=`printf "$1" | wc -c`
  if [ $ret == 0 ]; then
    return 0
  else
    echo "[ERROR] $2, \"$1\" expect equals null."
    return 1
  fi
}

#-----------------------------------
# func : _assert_not_null
# desc : Asserts that an object isn't null.
# param: $1: inspection
# $2: output error message
#-----------------------------------
function _assert_not_null() {
  ret=`printf "$1" | wc -c`
  if [ $ret != 0 ]; then
    return 0
  else
    echo "[ERROR] $2, expect equals not null."
    return 1
  fi
}

#-----------------------------------
# func : _assert_zero
# desc : Asserts that an object is zero(0).
# param: $1: inspection
# $2: output error message
#-----------------------------------
function _assert_zero() {
  if [ "$1"x == "0"x ]; then
    return 0
  else
    echo "[ERROR] $2, \"$1\" expect equals zero."
    return 1
  fi
}

#-----------------------------------
# func : _assert_not_zero
# desc : Asserts that an object isn't zero(0).
# param: $1: inspection
# $2: output error message
#-----------------------------------
function _assert_not_zero() {
  if [ "$1"x != "0"x ]; then
    return 0
  else
    echo "[ERROR] $2, \"$1\" expect not equals zero."
    return 1
  fi
}

#-----------------------------------
# func : _assert_contain
# desc : Asserts that a keyword contain at object.
# param: $1: inspection
# $2: keyword to expect
# $3: output error message
# ($4): if specify "1", don't print a inspection to message.
#-----------------------------------
function _assert_contain() {
  ret=`echo "$1" | grep "$2" | wc -l`
  if [ $ret -ge 1 ]; then
    return 0
  else
    test "$4"x == "1"x && echo "[ERROR] $3, expect contain \"$2\"."
    test "$4"x != "1"x && echo "[ERROR] $3, \"$1\" expect contain \"$2\"."
    return 1
  fi
}

#-----------------------------------
# func : _assert_not_contain
# desc : Asserts that a keyword does not contain at object.
# param: $1: inspection
# $2: keyword not to expect
# $3: output error message
# ($4): if specify "1", don't print a inspection to message.
#-----------------------------------
function _assert_not_contain() {
  ret=`echo "$1" | grep "$2" | wc -l`
  if [ $ret -eq 0 ]; then
    return 0
  else
    test "$4"x == "1"x && echo "[ERROR] $3, expect not contain \"$2\"."
    test "$4"x != "1"x && echo "[ERROR] $3, \"$1\" expect not contain \"$2\"."
    return 1
  fi
}

#-----------------------------------
# func : _assert_file_exist
# desc : Asserts that a file exist.
# param: $1: inspection filepath
# $2: output error message
#-----------------------------------
function _assert_file_exist() {
  if [ -f "$1" ]; then
    return 0
  else
    echo "[ERROR] $2, \"$1\" expect file exist."
    return 1
  fi
}

#-----------------------------------
# func : _assert_file_not_exist
# desc : Asserts that a file does not exist.
# param: $1: inspection filepath
# $2: output error message
#-----------------------------------
function _assert_file_not_exist() {
  if [ ! -f "$1" ]; then
    return 0
  else
    echo "[ERROR] $2, \"$1\" expact file not exist."
    return 1
  fi
}

Thanks
Yuichi Bando

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.