Files
heimdal/tests/kdc/check-iprop.in
Nicolas Williams 20df2c8706 Two-phase HDB commit via iprop log, + GC for log
We used to update the iprop log and HDB in different orders depending on
the kadm5 operation, which then led to various race conditions.

The iprop log now functions as a two-phase commit (with roll forward)
log for HDB changes.  The log is auto-truncated, keeping the latest
entries that fit in a configurable maximum number of bytes (defaults to
50MB).  See the log-max-size parameter description in krb5.conf(5).

The iprop log format and the protocol remain backwards-compatible with
earlier versions of Heimdal.  This is NOT a flag-day; there is NO need
to update all the slaves at once with the master, though it is advisable
in general.  Rolling upgrades and downgrades should work.

The sequence of updates is now (with HDB and log open and locked):

a) check that the HDB operation will succeed if attempted,
b) append to iprop log and fsync() it,
c) write to HDB (which should fsync()),
d) mark last log record committed (no fsync in this case).

Every kadm5 write operation recover transactions not yet confirmed as
committed, thus there can be at most one unconfirmed commit on a master
KDC.

Reads via kadm5_get_principal() also attempt to lock the log, and if
successful, recover unconfirmed transactions; readers must have write
access and must win any race to lock the iprop log.

The ipropd-master daemon also attempts to recover unconfirmed
transactions when idle.

The log now starts with a nop record whose payload records the offset of
the logical end of the log: the end of the last confirmed committed
transaction.  This is kown as the "uber record".  Its purpose is
two-fold: act as the confirmation of committed transactions, and provide
an O(1) method of finding the end of the log (i.e., without having to
traverse the entire log front to back).

Two-phase commit makes all kadm5 writes single-operation atomic
transactions (though some kadm5 operations, such as renames of
principals, and changes to principals' aliases, use multiple low-level
HDB write operations, but still all in one transaction).  One can still
hold a lock on the HDB across many operations (e.g., by using the lock
command in a kadmin -l or calling kadm5_lock()) in order to push
multiple transactions in sequence, but this sequence will not be atomic
if the process or host crashes in the middle.

As before, HDB writes which do not go through the kadm5 API are excluded
from all of this, but there should be no such writes.

Lastly, the iprop-log(1) command is enhanced as follows:

 - The dump, last-version, truncate, and replay sub-commands now have an
   option to not lock the log.  This is useful for inspecting a running
   system's log file, especially on slave KDCs.

 - The dump, last-version, truncate, and replay sub-commands now take an
   optional iprop log file positional argument, so that they may be used
   to inspect log files other than the running system's
   configured/default log file.

Extensive code review and some re-writing for clarity by Viktor Dukhovni.
2016-02-26 00:55:33 -06:00

390 lines
13 KiB
Bash

#!/bin/sh
#
# Copyright (c) 2006 - 2007 Kungliga Tekniska Högskolan
# (Royal Institute of Technology, Stockholm, Sweden).
# All rights reserved.
#
# Redistribution and use in source and binary forms, with or without
# modification, are permitted provided that the following conditions
# are met:
#
# 1. Redistributions of source code must retain the above copyright
# notice, this list of conditions and the following disclaimer.
#
# 2. Redistributions in binary form must reproduce the above copyright
# notice, this list of conditions and the following disclaimer in the
# documentation and/or other materials provided with the distribution.
#
# 3. Neither the name of the Institute nor the names of its contributors
# may be used to endorse or promote products derived from this software
# without specific prior written permission.
#
# THIS SOFTWARE IS PROVIDED BY THE INSTITUTE AND CONTRIBUTORS ``AS IS'' AND
# ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
# ARE DISCLAIMED. IN NO EVENT SHALL THE INSTITUTE OR CONTRIBUTORS BE LIABLE
# FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
# DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
# OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
# HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
# LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
# OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
# SUCH DAMAGE.
top_builddir="@top_builddir@"
env_setup="@env_setup@"
objdir="@objdir@"
db_type=@db_type@
. ${env_setup}
# If there is no useful db support compile in, disable test
${have_db} || exit 77
# Dont run this test in AFS, since it lacks support for AF_UNIX
expr "X`/bin/pwd || pwd`" : "X/afs/.*" > /dev/null 2>/dev/null && exit 77
R=TEST.H5L.SE
port=@port@
cache="FILE:${objdir}/cache.krb5"
keytabfile=${objdir}/iprop.keytab
keytab="FILE:${keytabfile}"
kdc="${kdc} --addresses=localhost -P $port"
kadmin="${kadmin} -r $R"
kinit="${kinit} -c $cache ${afs_no_afslog}"
KRB5_CONFIG="${objdir}/krb5.conf"
export KRB5_CONFIG
rm -f ${keytabfile}
rm -f current-db*
rm -f current*.log
rm -f out-*
rm -f mkey.file*
rm -f messages.log
> messages.log
echo Creating database
${kadmin} -l \
init \
--realm-max-ticket-life=1day \
--realm-max-renewable-life=1month \
${R} || exit 1
${kadmin} -l add -p foo --use-defaults user@${R} || exit 1
${kadmin} -l add --random-key --use-defaults iprop/localhost@${R} || exit 1
${kadmin} -l ext -k ${keytab} iprop/localhost@${R} || exit 1
${kadmin} -l add --random-key --use-defaults iprop/slave.test.h5l.se@${R} || exit 1
${kadmin} -l ext -k ${keytab} iprop/slave.test.h5l.se@${R} || exit 1
echo foo > ${objdir}/foopassword
echo "Test log recovery"
${kadmin} -l add --random-key --use-defaults recovtest@${R} || exit 1
# Test theory: save the log, make a change and save the record it
# produced, restore the log, append to it the saved record, then get
# Save the log
cp current.log current.log.tmp
ls -l current.log.tmp | awk '{print $5}' > tmp
read sz < tmp
# Make a change
${kadmin} -l mod -a requires-pre-auth recovtest@${R} || exit 1
${kadmin} -l get recovtest@${R} | grep 'Attributes: requires-pre-auth$' > /dev/null || exit 1
# Save the resulting log record
ls -l current.log | awk '{print $5}' > tmp
read nsz < tmp
rm tmp
dd bs=1 if=current.log skip=$sz of=current.log.tmp.saved-record count=`expr $nsz - $sz` 2>/dev/null
# Undo the change
${kadmin} -l mod -a -requires-pre-auth recovtest@${R} || exit 1
${kadmin} -l get recovtest@${R} | grep 'Attributes:.$' > /dev/null || exit 1
# Restore the log
cp current.log current.log.save
mv current.log.tmp current.log
# Append the saved record
cat current.log.tmp.saved-record >> current.log
rm current.log.tmp.saved-record
# Check that we still see the principal as modified
${kadmin} -l get recovtest@${R} | grep 'Attributes: requires-pre-auth$' > /dev/null || exit 1
# -- foo
ipds=
ipdm=
kdcpid=
> iprop-stats
rm -f iprop-slave-status
ipropd_slave="${ipropd_slave} --status-file=iprop-slave-status"
trap "echo 'killing ipropd s + m + kdc'; kill -9 \${ipdm} \${ipds} \${kdcpid} >/dev/null 2>/dev/null; tail messages.log ; tail iprop-stats; exit 1;" EXIT
echo Starting kdc ; > messages.log
${kdc} &
kdcpid=$!
sh ${wait_kdc} || exit 1
echo "starting master" ; > messages.log
env ${HEIM_MALLOC_DEBUG} \
${ipropd_master} --hostname=localhost -k ${keytab} \
--database=${objdir}/current-db &
ipdm=$!
sh ${wait_kdc} ipropd-master || exit 1
echo "starting slave" ; > messages.log
env ${HEIM_MALLOC_DEBUG} \
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
ipds=$!
sh ${wait_kdc} ipropd-slave messages.log 'slave status change: up-to-date' || exit 1
sleep 1
echo "checking slave is up"
${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave to up to date" ; cat iprop-slave-status ; exit 1; }
# ----------------- checking: pushing lives changes
echo "Add host"
${kadmin} -l add --random-key --use-defaults host/foo@${R} || exit 1
sleep 2
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/foo@${R} > /dev/null || exit 1
echo "Rollover host keys"
${kadmin} -l cpw -r --keepold host/foo@${R} || exit 1
${kadmin} -l cpw -r --keepold host/foo@${R} || exit 1
${kadmin} -l cpw -r --keepold host/foo@${R} || exit 1
sleep 2
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/foo@${R} | \
${EGREP} Keytypes: | cut -d: -f2 | tr ' ' '
' | sed 's/^.*[[]\(.*\)[]].*$/\1/' | grep '[0-9]' | sort -nu | tr -d '
' | ${EGREP} 1234 > /dev/null || exit 1
echo "Delete 3DES keys"
${kadmin} -l del_enctype host/foo@${R} des3-cbc-sha1
sleep 2
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/foo@${R} | \
${EGREP} Keytypes: | cut -d: -f2 | tr ' ' '
' | sed 's/^.*[[]\(.*\)[]].*$/\1/' | grep '[0-9]' | sort -nu | tr -d '
' | ${EGREP} 1234 > /dev/null || exit 1
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/foo@${R} | \
${EGREP} 'Keytypes:.*des3-cbc-sha1' > /dev/null && exit 1
echo "Change policy host"
${kadmin} -l modify --policy=default host/foo@${R} || exit 1
sleep 2
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/foo@${R} > /dev/null 2>/dev/null || exit 1
echo "Rename host"
${kadmin} -l rename host/foo@${R} host/bar@${R} || exit 1
sleep 2
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/foo@${R} > /dev/null 2>/dev/null && exit 1
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/bar@${R} > /dev/null || exit 1
echo "Delete host"
${kadmin} -l delete host/bar@${R} || exit 1
sleep 2
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${kadmin} -l get host/bar@${R} > /dev/null 2>/dev/null && exit 1
# See note below in LMDB sanity checking
echo "Re-add host"
${kadmin} -l add --random-key --use-defaults host/foo@${R} || exit 1
${kadmin} -l add --random-key --use-defaults host/bar@${R} || exit 1
echo "kill slave and remove log and database"
> iprop-stats
sh ${leaks_kill} ipropd-slave $ipds || exit 1
rm -f iprop-slave-status
${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Down' iprop-stats >/dev/null || exit 1
# ----------------- checking: slave is missing changes while down
rm current.slave.log current-db.slave* || exit 1
echo "doing changes while slave is down"
${kadmin} -l cpw --random-password user@${R} > /dev/null || exit 1
${kadmin} -l cpw --random-password user@${R} > /dev/null || exit 1
echo "Makeing a copy of the master log file"
cp ${objdir}/current.log ${objdir}/current.log.tmp
# ----------------- checking: checking that master and slaves resyncs
echo "starting slave again" ; > messages.log
> iprop-stats
env ${HEIM_MALLOC_DEBUG} \
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
ipds=$!
sh ${wait_kdc} ipropd-slave messages.log 'slave status change: up-to-date' || exit 1
sleep 1
echo "checking slave is up again"
${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave not up to date" ; cat iprop-slave-status ; exit 1; }
echo "checking for replay problems"
${EGREP} 'Entry already exists in database' messages.log && exit 1
echo "compare versions on master and slave logs (no lock)"
KRB5_CONFIG=${objdir}/krb5-slave.conf \
${iprop_log} last-version -n > slave-last.tmp
${iprop_log} last-version -n > master-last.tmp
cmp master-last.tmp slave-last.tmp || exit 1
echo "kill slave and remove log and database"
sh ${leaks_kill} ipropd-slave $ipds || exit 1
sleep 2
rm current.slave.log current-db.slave* || exit 1
> iprop-stats
rm -f iprop-slave-status
echo "starting slave" ; > messages.log
env ${HEIM_MALLOC_DEBUG} \
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
ipds=$!
sh ${wait_kdc} ipropd-slave messages.log 'slave status change: up-to-date' || exit 1
sleep 1
echo "checking slave is up again"
${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave not up to date" ; cat iprop-slave-status ; exit 1; }
echo "checking for replay problems"
${EGREP} 'Entry already exists in database' messages.log && exit 1
# ----------------- checking: checking live truncation of master log
${kadmin} -l cpw --random-password user@${R} > /dev/null || exit 1
sleep 2
echo "live truncate on master log"
${iprop_log} truncate -K 5 || exit 1
sleep 2
echo "Killing master and slave"
sh ${leaks_kill} ipropd-master $ipdm || exit 1
sh ${leaks_kill} ipropd-slave $ipds || exit 1
rm -f iprop-slave-status
#sleep 2
#${EGREP} "^master down at " iprop-stats > /dev/null || exit 1
echo "compare versions on master and slave logs"
KRB5_CONFIG=${objdir}/krb5-slave.conf \
${iprop_log} last-version > slave-last.tmp
${iprop_log} last-version > master-last.tmp
cmp master-last.tmp slave-last.tmp || exit 1
# ----------------- checking: master going backward
> iprop-stats
> messages.log
echo "Going back to old version of the master log file"
cp ${objdir}/current.log.tmp ${objdir}/current.log
echo "starting master" ; > messages.log
env ${HEIM_MALLOC_DEBUG} \
${ipropd_master} --hostname=localhost -k ${keytab} \
--database=${objdir}/current-db &
ipdm=$!
sh ${wait_kdc} ipropd-master || exit 1
echo "starting slave" ; > messages.log
env ${HEIM_MALLOC_DEBUG} \
KRB5_CONFIG="${objdir}/krb5-slave.conf" \
${ipropd_slave} --hostname=slave.test.h5l.se -k ${keytab} localhost &
ipds=$!
sh ${wait_kdc} ipropd-slave messages.log 'slave status change: up-to-date' || exit 1
sleep 1
echo "checking slave is up again"
${EGREP} 'iprop/slave.test.h5l.se@TEST.H5L.SE.*Up' iprop-stats >/dev/null || exit 1
${EGREP} 'up-to-date with version' iprop-slave-status >/dev/null || { echo "slave to up to date" ; cat iprop-slave-status ; exit 1; }
echo "checking for replay problems"
${EGREP} 'Entry already exists in database' messages.log && exit 1
echo "pushing one change"
${kadmin} -l cpw --random-password user@${R} > /dev/null || exit 1
sleep 2
echo "Killing master"
sh ${leaks_kill} ipropd-master $ipdm || exit 1
sleep 4
${EGREP} 'disconnected' iprop-slave-status >/dev/null && { echo "slave still think its connected" ; cat iprop-slave-status ; exit 1; }
if ! tail -30 messages.log | grep 'disconnected for server' > /dev/null; then
echo "client didnt disconnect"
exit 1
fi
echo "probing for slave pid"
kill -0 ${ipds} || { echo "slave no longer there"; exit 1; }
> messages.log
echo "Staring master again" ; > messages.log
env ${HEIM_MALLOC_DEBUG} \
${ipropd_master} --hostname=localhost -k ${keytab} \
--database=${objdir}/current-db &
ipdm=$!
sh ${wait_kdc} ipropd-master || exit 1
echo "probing for slave pid"
kill -0 ${ipds} || { echo "slave no longer there"; exit 1; }
sh ${wait_kdc} ipropd-slave messages.log "connection successful to master" || exit 1
sh ${wait_kdc} ipropd-slave messages.log "ipropd-slave started at version" || exit 1
echo "pushing one change"
${kadmin} -l cpw --random-password user@${R} > /dev/null || exit 1
sleep 2
echo "shutting down all services"
trap "" EXIT
sh ${leaks_kill} kdc $kdcpid || exit 1
sh ${leaks_kill} ipropd-master $ipdm || exit 1
sh ${leaks_kill} ipropd-slave $ipds || exit 1
rm -f iprop-slave-status
echo "compare versions on master and slave logs"
KRB5_CONFIG=${objdir}/krb5-slave.conf \
${iprop_log} last-version > slave-last.tmp
${iprop_log} last-version > master-last.tmp
cmp master-last.tmp slave-last.tmp || exit 1
if [ "$db_type" = lmdb ]; then
# Sanity check that we have the same number of principals at the HDB
# and LMDB levels.
#
echo "checking that principals in DB == entries in LMDB"
princs=`${kadmin} -l list '*' | wc -l`
entries=`mdb_stat -n current-db.mdb | grep 'Entries:' | awk '{print $2}'`
[ "`expr 1 + "$princs"`" -eq "$entries" ] || exit 1
fi
exit 0