++ . /etc/sorcery/compile_config
+++ LOCAL_COMPILE_CONFIG=/etc/sorcery/local/compile_config
+++ CCACHE=off
+++ CCACHE_DIR=/var/cache/compiler
+++ DISTCC_HOSTS=
+++ JOBS_PER_HOST=0
+++ MAKE_NJOBS=1
+++ RUN_COMPILER_DIR=/var/lib/sorcery/build
+++ '[' -x /etc/sorcery/local/compile_config ']'
+++ . /etc/sorcery/local/compile_config
++++ CCACHE=on
++++ DISTCC_HOSTS='omega zeta omikron ksi'
++++ JOBS_PER_HOST=3
++++ MAKE_NJOBS=1
++++ CCACHE_DIR=/home/ruskie/downloads/4/compiler
++ . /etc/sorcery/screen
+++ SCREEN_CAST_WIN=2
+++ SCREEN_SUMMON_WIN=1
+++ SCREEN_MAIN_WIN=0
+++ SCREEN_LAST_FAILED_CAST_WIN=3
+++ SCREEN_DEBUG_WIN=4
+++ SCREENRC=/etc/sorcery/screenrc
+++ SCREEN_ANTI_RACE_SLEEP=0.2
++ '[' -r /etc/sorcery/local/grimoire ']'
++ . /etc/sorcery/local/grimoire
+++ GRIMOIRE_DIR[0]=/var/lib/sorcery/codex/xorg-modular
+++ GRIMOIRE_DIR[1]=/var/lib/sorcery/codex/test
+++ GRIMOIRE_DIR[2]=/var/lib/sorcery/codex/games
+++ GRIMOIRE_DIR[3]=/var/lib/sorcery/codex/arcane
+++ GRIMOIRE_DIR[4]=/var/lib/sorcery/codex/z-rejected
+++ GRIMOIRE_DIR[5]=/var/lib/sorcery/codex/compiz-grimoire
+++ GRIMOIRE_DIR[6]=/var/lib/sorcery/codex/local
++ BUILD_DIRECTORY=/usr/src
++ DOCUMENT_DIRECTORY=/usr/share/doc
++ CONFIG_STAGE_DIRECTORY=/var/state/sorcery/staged_configs
++ INSTALLWATCH_UNSTAGED_PATHS=
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,/var/lib/sorcery,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,/var/lib/sorcery,//var/lib/sorcery,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,/var/lib/sorcery,//var/lib/sorcery,/var/spool/sorcery,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,/var/lib/sorcery,//var/lib/sorcery,/var/spool/sorcery,/etc/sorcery/local,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,/var/lib/sorcery,//var/lib/sorcery,/var/spool/sorcery,/etc/sorcery/local,/var/state/sorcery,
++ for dir in /dev /proc /tmp /var/tmp /sys '${BUILD_DIRECTORY}' '${SGL_LIBRARY}' '${INSTALL_ROOT}/${SGL_LIBRARY}' '${SOURCE_CACHE}' '${CONFIG_CACHE}' '${STATE_DIRECTORY}' '${LOG_DIRECTORY}'
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,/var/lib/sorcery,//var/lib/sorcery,/var/spool/sorcery,/etc/sorcery/local,/var/state/sorcery,/var/log/sorcery,
++ INSTALLWATCH_UNSTAGED_PATHS=/dev,/proc,/tmp,/var/tmp,/sys,/usr/src,/var/lib/sorcery,//var/lib/sorcery,/var/spool/sorcery,/etc/sorcery/local,/var/state/sorcery,/var/log/sorcery
++ INSTALLWATCH_DEBUG_LEVEL=1
++ '[' -z ']'
++ optimize
++ debug libsorcery 'In optimize()'
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libsorcery
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libsorcery(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "In optimize()"'
++ echo
++ true
++ unset CFLAGS CXXFLAGS LDFLAGS CPPFLAGS
++ unset COMBRELOC FAST PRELINK RISKY SMALL SPEEDY STRIP TINY
++ [[ -n '' ]]
++ set_architecture
++ eval local '_stddbg_file=${BASH_SOURCE[0]}' ';' '_stddbg_file=${_stddbg_file##*/};' debug '"${_stddbg_file}"' '"${FUNCNAME[0]}@$LINENO"' '"$@"'
+++ local _stddbg_file=/var/lib/sorcery/modules/libmisc
+++ _stddbg_file=libmisc
+++ debug libmisc set_architecture@1280
+++ [[ -n /dev/null ]]
+++ local debugVar=DEBUG_libmisc
+++ local i
+++ [[ '' != \n\o ]]
+++ echo -n 'libmisc(19116): '
+++ shift
+++ for i in '"$@"'
+++ echo -n ' "set_architecture@1280"'
+++ echo
+++ true
++ local specdir
++ local i j
++ unset SPECFILE
++ local arch=
++ [[ ! -n '' ]]
++ [[ off == on ]]
++ [[ -n '' ]]
++ arch=athlon-xp
++ local find_compat=0
++ find --version
++ grep -q 'version 4\.1\(\.\|$\)'
++ for specdir in '${ARCH_SPECS[@]}'
++ [[ 0 == 1 ]]
+++ find -L /usr/share/archspecs -perm -400 -type f -name athlon-xp -print -quit
++ SPECFILE=/usr/share/archspecs/32/ia32/amd/k7/athlon-xp
++ '[' /usr/share/archspecs/32/ia32/amd/k7/athlon-xp ']'
++ break
++ [[ ! -n /usr/share/archspecs/32/ia32/amd/k7/athlon-xp ]]
++ debug libmisc 'set_architecture: SPECFILE=/usr/share/archspecs/32/ia32/amd/k7/athlon-xp'
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libmisc
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libmisc(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "set_architecture: SPECFILE=/usr/share/archspecs/32/ia32/amd/k7/athlon-xp"'
++ echo
++ true
++ unset SMGL_COMPAT_ARCHS
++ explode 32/ia32/amd/k7/athlon-xp / SMGL_COMPAT_ARCHS
++ [[ -n SMGL_COMPAT_ARCHS ]]
++ local l=32/ia32/amd/k7/athlon-xp
++ local i=0
++ [[ -n 32/ia32/amd/k7/athlon-xp ]]
++ local result=32
++ l=/ia32/amd/k7/athlon-xp
++ l=ia32/amd/k7/athlon-xp
++ eval 'SMGL_COMPAT_ARCHS[0]="32"'
+++ SMGL_COMPAT_ARCHS[0]=32
++ (( i++ ))
++ [[ -n ia32/amd/k7/athlon-xp ]]
++ local result=ia32
++ l=/amd/k7/athlon-xp
++ l=amd/k7/athlon-xp
++ eval 'SMGL_COMPAT_ARCHS[1]="ia32"'
+++ SMGL_COMPAT_ARCHS[1]=ia32
++ (( i++ ))
++ [[ -n amd/k7/athlon-xp ]]
++ local result=amd
++ l=/k7/athlon-xp
++ l=k7/athlon-xp
++ eval 'SMGL_COMPAT_ARCHS[2]="amd"'
+++ SMGL_COMPAT_ARCHS[2]=amd
++ (( i++ ))
++ [[ -n k7/athlon-xp ]]
++ local result=k7
++ l=/athlon-xp
++ l=athlon-xp
++ eval 'SMGL_COMPAT_ARCHS[3]="k7"'
+++ SMGL_COMPAT_ARCHS[3]=k7
++ (( i++ ))
++ [[ -n athlon-xp ]]
++ local result=athlon-xp
++ l=
++ l=
++ eval 'SMGL_COMPAT_ARCHS[4]="athlon-xp"'
+++ SMGL_COMPAT_ARCHS[4]=athlon-xp
++ (( i++ ))
++ [[ -n '' ]]
++ local lc=32/ia32/amd/k7/athlon-xp
++ '[' 32/ia32/amd/k7/athlon-xp = true ']'
++ unset ARCHITECTURE
++ j=0
++ (( i=5-1 ))
++ (( i>=0 ))
++ ARCHITECTURE[j++]=athlon-xp
++ (( i-- ))
++ (( i>=0 ))
++ ARCHITECTURE[j++]=k7
++ (( i-- ))
++ (( i>=0 ))
++ ARCHITECTURE[j++]=amd
++ (( i-- ))
++ (( i>=0 ))
++ ARCHITECTURE[j++]=ia32
++ (( i-- ))
++ (( i>=0 ))
++ ARCHITECTURE[j++]=32
++ (( i-- ))
++ (( i>=0 ))
++ source /usr/share/archspecs/32/ia32/amd/k7/athlon-xp
+++ CPUNAME='AMD Athlon XP'
+++ use_gcc2
+++ use_gcc 2.95.
+++ gcc -dumpversion
++++ esc_str 2.95.
++++ local OUT
++++ [[ 2.95. == .* ]]
+++++ echo 2.95.
+++++ sed -e 's:\.:\\.:g' -e 's:\*:\\*:g'
++++ OUT='2\.95\.'
++++ echo '2\.95\.'
+++ grep -q '2\.95\.'
+++ CFLAGS='-march=athlon-xp -mmmx -msse -m3dnow'
+++ HOST=i686-pc-linux-gnu
+++ FAST=-O3
+++ SMALL=-Os
++ debug 'ARCHITECTURE='\''athlon-xp'\'''
++ [[ -n /dev/null ]]
++ local 'debugVar=DEBUG_ARCHITECTURE='\''athlon-xp'\'''
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'ARCHITECTURE='\''athlon-xp'\''(19116): '
++ shift
++ echo
++ true
++ debug libsorcery 'TARGET='\'''\'''
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libsorcery
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libsorcery(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "TARGET='\'''\''"'
++ echo
++ true
++ debug libsorcery 'OPTIMIZATIONS='\''combreloc prelink speedy '\'''
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libsorcery
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libsorcery(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "OPTIMIZATIONS='\''combreloc prelink speedy '\''"'
++ echo
++ true
++ BUILD=i686-pc-linux-gnu
++ debug libsorcery 'BUILD is i686-pc-linux-gnu, HOST is i686-pc-linux-gnu'
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libsorcery
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libsorcery(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "BUILD is i686-pc-linux-gnu, HOST is i686-pc-linux-gnu"'
++ echo
++ true
++ CFLAGS='-march=athlon-xp -mmmx -msse -m3dnow -pipe'
++ for PARAM in '$OPTIMIZATIONS'
++ case $PARAM in
++ LDFLAGS=' -z combreloc'
++ COMBRELOC=on
++ for PARAM in '$OPTIMIZATIONS'
++ case $PARAM in
++ CFLAGS='-march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC'
++ PRELINK=on
++ for PARAM in '$OPTIMIZATIONS'
++ case $PARAM in
++ CFLAGS='-march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC -O3'
++ SPEEDY=on
+++ echo -march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC -O3 -g
++ export 'CFLAGS=-march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC -O3 -g'
++ CFLAGS='-march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC -O3 -g'
+++ echo -march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC -O3 -g -g
++ export 'CXXFLAGS=-march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC -O3 -g -g'
++ CXXFLAGS='-march=athlon-xp -mmmx -msse -m3dnow -pipe -DPIC -fPIC -O3 -g -g'
+++ echo -z combreloc
++ export 'LDFLAGS=-z combreloc'
++ LDFLAGS='-z combreloc'
+++ echo
++ export CPPFLAGS=
++ CPPFLAGS=
++ umask 0022
++ unset MAKELEVEL
++ unset MAKEFLAGS
+ '[' 0 == 0 ']'
+ [[ +10 != \0 ]]
+ renice +10 -p 19116
+ mk_tmp_dirs summon
+ debug mk_tmp_dirs 'Making tmp dirs for 19116'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_mk_tmp_dirs
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'mk_tmp_dirs(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "Making tmp dirs for 19116"'
+ echo
+ true
+ local SCRIPT_NAME=summon STATS tmp
+ SCRIPT_NAME=summon
+ local BASE_DIR=/tmp/sorcery
+ local SCRIPT_DIR=/tmp/sorcery/summon
+ local FULL_DIR=/tmp/sorcery/summon/19116
++ ls -ld /tmp/sorcery
++ awk '{printf "%s:%s:%s\n" ,$1,$3,$4; }'
+ tmp=drwxr-xr-x:root:root
+ [[ drwxr-xr-x:root:root != \d\r\w\x\r\-\x\r\-\x\:\r\o\o\t\:\r\o\o\t ]]
++ ls -ld /tmp/sorcery
++ awk '{printf "%s:%s:%s\n" ,$1,$3,$4; }'
+ tmp=drwxr-xr-x:root:root
+ [[ drwxr-xr-x:root:root != \d\r\w\x\r\-\x\r\-\x\:\r\o\o\t\:\r\o\o\t ]]
++ ls -ld /tmp/sorcery/summon
++ awk '{printf "%s:%s:%s\n" ,$1,$3,$4; }'
+ tmp=drwxr-xr-x:root:root
+ [[ drwxr-xr-x:root:root != \d\r\w\x\r\-\x\r\-\x\:\r\o\o\t\:\r\o\o\t ]]
++ ls -ld /tmp/sorcery/summon
++ awk '{printf "%s:%s:%s\n" ,$1,$3,$4; }'
+ tmp=drwxr-xr-x:root:root
+ [[ drwxr-xr-x:root:root != \d\r\w\x\r\-\x\r\-\x\:\r\o\o\t\:\r\o\o\t ]]
+ '[' -e /tmp/sorcery/summon/19116 ']'
+ install -d -o root -g root -m 755 /tmp/sorcery/summon/19116
++ ls -ld /tmp/sorcery/summon
++ awk '{printf "%s:%s:%s\n" ,$1,$3,$4; }'
+ tmp=drwxr-xr-x:root:root
+ [[ drwxr-xr-x:root:root != \d\r\w\x\r\-\x\r\-\x\:\r\o\o\t\:\r\o\o\t ]]
+ export TMP_DIR=/tmp/sorcery/summon/19116
+ TMP_DIR=/tmp/sorcery/summon/19116
+ main drm
+ local spells_to_get
+ cd /tmp
+ process_parameters drm
+ '[' '!' -n drm ']'
+ '[' -n drm ']'
+ echo '' drm
+ grep -q '^ -'
+ shift 1
+ '[' -n '' ']'
+ '[' -n '' ']'
+ '[' -n '' ']'
+ '[' -n '' ']'
++ strip_parameters drm
++ '[' -n drm ']'
++ echo '' drm
++ grep -q '^ -'
++ echo drm
++ shift 1
++ '[' -n '' ']'
+ spells_to_get=drm
+ '[' -n '' ']'
+ summon_spells drm
+ local SPELLS=drm
+ local SPELL
+ '[' -z drm ']'
+ for SPELL in '$SPELLS'
+ summon_spell drm
+ eval local '_stddbg_file=${BASH_SOURCE[0]}' ';' '_stddbg_file=${_stddbg_file##*/};' debug '"${_stddbg_file}"' '"${FUNCNAME[0]}@$LINENO"' '"$@"'
++ local _stddbg_file=/var/lib/sorcery/modules/libsummon
++ _stddbg_file=libsummon
++ debug libsummon summon_spell@30 drm
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libsummon
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libsummon(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "summon_spell@30"'
++ for i in '"$@"'
++ echo -n ' "drm"'
++ echo
++ true
+ local SPELL=drm
+ local rc=1
+ '[' -n drm ']'
+ lock_resources summon drm
+ trylock_resources summon drm
+ local lockfile=summon.drm
+ lockfile=/tmp/liblock-0/summon.drm
+ debug trylock_resources lockfile=/tmp/liblock-0/summon.drm
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_trylock_resources
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'trylock_resources(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "lockfile=/tmp/liblock-0/summon.drm"'
+ echo
+ true
+ mkdir -p /tmp/liblock-0
+ mkdir /tmp/liblock-0/summon.drm
+ ln -sf /proc/19116 /tmp/liblock-0/summon.drm/19116
+ return 0
+ local dl_dir=/tmp/sorcery/summon/19116/drm
+ debug libsummon 'dl_dir is /tmp/sorcery/summon/19116/drm'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libsummon
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libsummon(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "dl_dir is /tmp/sorcery/summon/19116/drm"'
+ echo
+ true
+ mkdir -p /tmp/sorcery/summon/19116/drm
+ pushd /tmp/sorcery/summon/19116/drm
+ local rc=1
+ run_details
+ debug libsorcery 'starting run_details for drm'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libsorcery
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libsorcery(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "starting run_details for drm"'
+ echo
+ true
+ codex_set_current_spell_by_name drm
+ debug libcodex 'codex_set_current_spell_by_name -- drm'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libcodex
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libcodex(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "codex_set_current_spell_by_name -- drm"'
+ echo
+ true
++ codex_find_spell_by_name drm
++ debug libcodex 'codex_find_spell_by_name - drm'
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libcodex
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libcodex(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "codex_find_spell_by_name - drm"'
++ echo
++ true
+++ codex_get_all_grimoires
+++ debug libcodex 'codex_get_all_grimoires()'
+++ [[ -n /dev/null ]]
+++ local debugVar=DEBUG_libcodex
+++ local i
+++ [[ '' != \n\o ]]
+++ echo -n 'libcodex(19116): '
+++ shift
+++ for i in '"$@"'
+++ echo -n ' "codex_get_all_grimoires()"'
+++ echo
+++ true
+++ echo '/var/lib/sorcery/codex/xorg-modular /var/lib/sorcery/codex/test /var/lib/sorcery/codex/games /var/lib/sorcery/codex/arcane /var/lib/sorcery/codex/z-rejected /var/lib/sorcery/codex/compiz-grimoire /var/lib/sorcery/codex/local'
+++ tr '[:blank:]' '\n'
+++ return 0
++ codex_cache_spell_lookup drm /var/lib/sorcery/codex/xorg-modular /var/lib/sorcery/codex/test /var/lib/sorcery/codex/games /var/lib/sorcery/codex/arcane /var/lib/sorcery/codex/z-rejected /var/lib/sorcery/codex/compiz-grimoire /var/lib/sorcery/codex/local
++ local SECTION
++ local spell=drm
++ shift
++ '[' 7 -gt 0 ']'
++ debug libcodex 'looking up drm in /var/lib/sorcery/codex/xorg-modular'\''s cache'
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libcodex
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libcodex(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "looking up drm in /var/lib/sorcery/codex/xorg-modular'\''s cache"'
++ echo
++ true
++ codex_check_cache /var/lib/sorcery/codex/xorg-modular
++ codex_is_canonicalized /var/lib/sorcery/codex/xorg-modular
++ '[' / '!=' / ']'
++ '[' -f /var/lib/sorcery/codex/xorg-modular/codex.index ']'
++ '[' -f /var/lib/sorcery/codex/xorg-modular/provides.index ']'
++ '[' -f /var/lib/sorcery/codex/xorg-modular/codex.index ']'
++ '[' -f /var/lib/sorcery/codex/xorg-modular/provides.index ']'
+++ grep -m 1 '^drm ' /var/lib/sorcery/codex/xorg-modular/codex.index
+++ cut '-d ' -f2
++ SECTION=
++ [[ -n '' ]]
++ shift
++ '[' 6 -gt 0 ']'
++ debug libcodex 'looking up drm in /var/lib/sorcery/codex/test'\''s cache'
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libcodex
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libcodex(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "looking up drm in /var/lib/sorcery/codex/test'\''s cache"'
++ echo
++ true
++ codex_check_cache /var/lib/sorcery/codex/test
++ codex_is_canonicalized /var/lib/sorcery/codex/test
++ '[' / '!=' / ']'
++ '[' -f /var/lib/sorcery/codex/test/codex.index ']'
++ '[' -f /var/lib/sorcery/codex/test/provides.index ']'
++ '[' -f /var/lib/sorcery/codex/test/codex.index ']'
++ '[' -f /var/lib/sorcery/codex/test/provides.index ']'
+++ grep -m 1 '^drm ' /var/lib/sorcery/codex/test/codex.index
+++ cut '-d ' -f2
++ SECTION=/var/lib/sorcery/codex/test/kernels
++ [[ -n /var/lib/sorcery/codex/test/kernels ]]
++ echo /var/lib/sorcery/codex/test/kernels/drm
++ return
+ local SPELL_NAME=/var/lib/sorcery/codex/test/kernels/drm
+ debug libcodex /var/lib/sorcery/codex/test/kernels/drm
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libcodex
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libcodex(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "/var/lib/sorcery/codex/test/kernels/drm"'
+ echo
+ true
+ '[' -n /var/lib/sorcery/codex/test/kernels/drm ']'
+ codex_set_current_spell /var/lib/sorcery/codex/test/kernels/drm
+ debug libcodex 'runing codex_set_current_spell'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libcodex
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libcodex(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "runing codex_set_current_spell"'
+ echo
+ true
+ codex_clear_current_spell
+ unset GRIMOIRE SECTION SECTION_DIRECTORY SPELL SPELL_DIRECTORY SCRIPT_DIRECTORY SPELL_DESCRIPTION VERSION SHORT UPDATED SOURCE WEB_SITE ENTERRED MAINTAINER MD5 LICENSE BUILD_API
+ codex_get_spell_paths /var/lib/sorcery/codex/test/kernels/drm
+ SPELL_DIRECTORY=/var/lib/sorcery/codex/test/kernels/drm
+ SCRIPT_DIRECTORY=/var/lib/sorcery/codex/test/kernels/drm
+ test -e /var/lib/sorcery/codex/test/kernels/drm/SCRIBBLED
+ smgl_dirname /var/lib/sorcery/codex/test/kernels/drm SECTION_DIRECTORY
+ local __dir=/var/lib/sorcery/codex/test/kernels/drm
+ local __last_dir __next_dir
+ [[ /var/lib/sorcery/codex/test/kernels/drm != '' ]]
+ __last_dir=/var/lib/sorcery/codex/test/kernels/drm
+ __dir=/var/lib/sorcery/codex/test/kernels/drm
+ [[ /var/lib/sorcery/codex/test/kernels/drm != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s\/\d\r\m ]]
+ __next_dir=/var/lib/sorcery/codex/test/kernels
+ [[ /var/lib/sorcery/codex/test/kernels == \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s\/\d\r\m ]]
+ __dir=/var/lib/sorcery/codex/test/kernels
+ [[ /var/lib/sorcery/codex/test/kernels != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s\/\d\r\m ]]
+ __last_dir=/var/lib/sorcery/codex/test/kernels
+ __dir=/var/lib/sorcery/codex/test/kernels
+ [[ /var/lib/sorcery/codex/test/kernels == \/ ]]
+ [[ /var/lib/sorcery/codex/test/kernels != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s ]]
+ [[ -n SECTION_DIRECTORY ]]
+ upvar SECTION_DIRECTORY /var/lib/sorcery/codex/test/kernels
+ eval 'SECTION_DIRECTORY=$2'
++ SECTION_DIRECTORY=/var/lib/sorcery/codex/test/kernels
+ smgl_basename /var/lib/sorcery/codex/test/kernels SECTION
+ local __base=/var/lib/sorcery/codex/test/kernels
+ local __last_base
+ [[ /var/lib/sorcery/codex/test/kernels != '' ]]
+ __last_base=/var/lib/sorcery/codex/test/kernels
+ __base=/var/lib/sorcery/codex/test/kernels
+ [[ /var/lib/sorcery/codex/test/kernels != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s ]]
+ __base=kernels
+ [[ -n SECTION ]]
+ upvar SECTION kernels
+ eval 'SECTION=$2'
++ SECTION=kernels
+ smgl_dirname /var/lib/sorcery/codex/test/kernels GRIMOIRE
+ local __dir=/var/lib/sorcery/codex/test/kernels
+ local __last_dir __next_dir
+ [[ /var/lib/sorcery/codex/test/kernels != '' ]]
+ __last_dir=/var/lib/sorcery/codex/test/kernels
+ __dir=/var/lib/sorcery/codex/test/kernels
+ [[ /var/lib/sorcery/codex/test/kernels != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s ]]
+ __next_dir=/var/lib/sorcery/codex/test
+ [[ /var/lib/sorcery/codex/test == \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s ]]
+ __dir=/var/lib/sorcery/codex/test
+ [[ /var/lib/sorcery/codex/test != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s ]]
+ __last_dir=/var/lib/sorcery/codex/test
+ __dir=/var/lib/sorcery/codex/test
+ [[ /var/lib/sorcery/codex/test == \/ ]]
+ [[ /var/lib/sorcery/codex/test != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t ]]
+ [[ -n GRIMOIRE ]]
+ upvar GRIMOIRE /var/lib/sorcery/codex/test
+ eval 'GRIMOIRE=$2'
++ GRIMOIRE=/var/lib/sorcery/codex/test
+ smgl_basename /var/lib/sorcery/codex/test GRIMOIRE_NAME
+ local __base=/var/lib/sorcery/codex/test
+ local __last_base
+ [[ /var/lib/sorcery/codex/test != '' ]]
+ __last_base=/var/lib/sorcery/codex/test
+ __base=/var/lib/sorcery/codex/test
+ [[ /var/lib/sorcery/codex/test != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t ]]
+ __base=test
+ [[ -n GRIMOIRE_NAME ]]
+ upvar GRIMOIRE_NAME test
+ eval 'GRIMOIRE_NAME=$2'
++ GRIMOIRE_NAME=test
+ smgl_basename /var/lib/sorcery/codex/test/kernels/drm SPELL
+ local __base=/var/lib/sorcery/codex/test/kernels/drm
+ local __last_base
+ [[ /var/lib/sorcery/codex/test/kernels/drm != '' ]]
+ __last_base=/var/lib/sorcery/codex/test/kernels/drm
+ __base=/var/lib/sorcery/codex/test/kernels/drm
+ [[ /var/lib/sorcery/codex/test/kernels/drm != \/\v\a\r\/\l\i\b\/\s\o\r\c\e\r\y\/\c\o\d\e\x\/\t\e\s\t\/\k\e\r\n\e\l\s\/\d\r\m ]]
+ __base=drm
+ [[ -n SPELL ]]
+ upvar SPELL drm
+ eval 'SPELL=$2'
++ SPELL=drm
+ SPELL_CONFIG=/etc/sorcery/local/depends/drm
+ return 0
+ '[' -f /etc/sorcery/local/depends/drm ']'
+ . /etc/sorcery/local/depends/drm
+ debug libcodex 'looking around for API_VERSION'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libcodex
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libcodex(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "looking around for API_VERSION"'
+ echo
+ true
+ [[ -x /var/lib/sorcery/codex/test/API_VERSION ]]
+ . /var/lib/sorcery/codex/test/API_VERSION
++ BUILD_API=2
+ [[ -x /var/lib/sorcery/codex/test/kernels/API_VERSION ]]
+ debug libcodex 'sourcing DETAILS'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libcodex
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libcodex(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "sourcing DETAILS"'
+ echo
+ true
+ persistent_load
+ debug libapi 'persistent_load - '
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libapi
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libapi(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "persistent_load - "'
+ echo
+ true
+ real_persistent_load
+ local PERSISTENT_LOADING=yes
+ local PERSISTENT_FILE=/etc/sorcery/local/depends/drm.p
+ '[' -f /etc/sorcery/local/depends/drm.p ']'
+ . /etc/sorcery/local/depends/drm.p
++ DRM_AUTOUPDATE=n
+ local line
++ read line
++ echo DRM_AUTOUPDATE
++ read line
+ persistent_add DRM_AUTOUPDATE
+ debug libapi 'persistent_add - DRM_AUTOUPDATE'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libapi
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libapi(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "persistent_add - DRM_AUTOUPDATE"'
+ echo
+ true
+ real_persistent_add DRM_AUTOUPDATE
+ [[ -n '' ]]
+ list_add PERSISTENT_VARIABLES DRM_AUTOUPDATE
+ debug libapi 'list_add - PERSISTENT_VARIABLES DRM_AUTOUPDATE'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libapi
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libapi(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "list_add - PERSISTENT_VARIABLES DRM_AUTOUPDATE"'
+ echo
+ true
+ real_list_add PERSISTENT_VARIABLES DRM_AUTOUPDATE
+ local var=PERSISTENT_VARIABLES
+ shift
+ local i
+ for i in '$@'
+ local found=0
++ eval 'echo $PERSISTENT_VARIABLES'
+++ echo
+ iterate list_add_sub ' ' ''
+ '[' 3 -lt 2 ']'
+ local 'oldIFS= 	
'
+ local token
+ local func=list_add_sub
+ local returnValue=0
+ [[ 3 -gt 2 ]]
+ IFS=' '
+ shift 2
+ IFS=' 	
'
+ returnValue=0
+ [[ -n '' ]]
+ unset BREAK
+ return 0
+ '[' 0 -eq 0 ']'
+ eval 'PERSISTENT_VARIABLES=`echo "$PERSISTENT_VARIABLES DRM_AUTOUPDATE"`'
+++ echo ' DRM_AUTOUPDATE'
++ PERSISTENT_VARIABLES=' DRM_AUTOUPDATE'
+ eval 'PERSISTENT_VARIABLES="${PERSISTENT_VARIABLES/# /}"'
++ PERSISTENT_VARIABLES=DRM_AUTOUPDATE
+ . /var/lib/sorcery/codex/test/kernels/drm/DETAILS
+ persistent_clear
+ debug 'persistent_clear - '
+ [[ -n /dev/null ]]
+ local 'debugVar=DEBUG_persistent_clear - '
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'persistent_clear - (19116): '
+ shift
+ echo
+ true
+ real_persistent_clear
+ local VAR
+ for VAR in '$PERSISTENT_VARIABLES'
+ unset DRM_AUTOUPDATE
+ unset PERSISTENT_VARIABLES
+ STAGE_DIRECTORY=/usr/src/stage-drm-
+ load_libcompat
+ '[' -x /var/lib/sorcery/codex/test/libcompat ']'
+ . /var/lib/sorcery/codex/test/libcompat
++ declare -f sub_depends
++ declare -f force_depends
++ declare -f show_up_depends
++ declare -f suggest_depends
++ declare -f runtime_depends
+ '[' -x /var/lib/sorcery/codex/test/kernels/libcompat ']'
+ return 0
+ [[ -z 2 ]]
+ true
+ run_spell_file DOWNLOAD download
+ local rc=0
+ local spell_file=DOWNLOAD
+ local function_suffix=download
+ local spell_cmd_var=DOWNLOAD_CMD
+ local spell_cmd=
+ local pre_function=
+ eval 'function real_default_download() {
    default_section_download
  }'
+ eval 'function real_default_section_download() {
    private_default_section_generic DOWNLOAD download
  }'
+ eval 'function real_default_grimoire_download() {
    private_default_grimoire_generic DOWNLOAD download
  }'
+ persistent_load
+ debug libapi 'persistent_load - '
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libapi
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libapi(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "persistent_load - "'
+ echo
+ true
+ real_persistent_load
+ local PERSISTENT_LOADING=yes
+ local PERSISTENT_FILE=/etc/sorcery/local/depends/drm.p
+ '[' -f /etc/sorcery/local/depends/drm.p ']'
+ . /etc/sorcery/local/depends/drm.p
++ DRM_AUTOUPDATE=n
+ local line
++ read line
++ echo DRM_AUTOUPDATE
++ read line
+ persistent_add DRM_AUTOUPDATE
+ debug libapi 'persistent_add - DRM_AUTOUPDATE'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libapi
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libapi(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "persistent_add - DRM_AUTOUPDATE"'
+ echo
+ true
+ real_persistent_add DRM_AUTOUPDATE
+ [[ -n '' ]]
+ list_add PERSISTENT_VARIABLES DRM_AUTOUPDATE
+ debug libapi 'list_add - PERSISTENT_VARIABLES DRM_AUTOUPDATE'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libapi
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libapi(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "list_add - PERSISTENT_VARIABLES DRM_AUTOUPDATE"'
+ echo
+ true
+ real_list_add PERSISTENT_VARIABLES DRM_AUTOUPDATE
+ local var=PERSISTENT_VARIABLES
+ shift
+ local i
+ for i in '$@'
+ local found=0
++ eval 'echo $PERSISTENT_VARIABLES'
+++ echo
+ iterate list_add_sub ' ' ''
+ '[' 3 -lt 2 ']'
+ local 'oldIFS= 	
'
+ local token
+ local func=list_add_sub
+ local returnValue=0
+ [[ 3 -gt 2 ]]
+ IFS=' '
+ shift 2
+ IFS=' 	
'
+ returnValue=0
+ [[ -n '' ]]
+ unset BREAK
+ return 0
+ '[' 0 -eq 0 ']'
+ eval 'PERSISTENT_VARIABLES=`echo "$PERSISTENT_VARIABLES DRM_AUTOUPDATE"`'
+++ echo ' DRM_AUTOUPDATE'
++ PERSISTENT_VARIABLES=' DRM_AUTOUPDATE'
+ eval 'PERSISTENT_VARIABLES="${PERSISTENT_VARIABLES/# /}"'
++ PERSISTENT_VARIABLES=DRM_AUTOUPDATE
+ test -x /var/lib/sorcery/codex/test/kernels/drm/DOWNLOAD
+ [[ -n '' ]]
+ default_download
+ real_default_download
+ default_section_download
+ real_default_section_download
+ private_default_section_generic DOWNLOAD download
+ eval 'function real_default_download() {
    default_grimoire_download
  }'
+ test -x /var/lib/sorcery/codex/test/kernels/DOWNLOAD
+ default_grimoire_download
+ real_default_grimoire_download
+ private_default_grimoire_generic DOWNLOAD download
+ eval 'function real_default_download() {
    default_sorcery_download
  }'
+ test -x /var/lib/sorcery/codex/test/DOWNLOAD
+ default_sorcery_download
+ real_default_sorcery_download
+ eval local '_stddbg_file=${BASH_SOURCE[0]}' ';' '_stddbg_file=${_stddbg_file##*/};' debug '"${_stddbg_file}"' '"${FUNCNAME[0]}@$LINENO"' '"$@"'
++ local _stddbg_file=/var/lib/sorcery/modules/libsummon
++ _stddbg_file=libsummon
++ debug libsummon real_default_sorcery_download@86
++ [[ -n /dev/null ]]
++ local debugVar=DEBUG_libsummon
++ local i
++ [[ '' != \n\o ]]
++ echo -n 'libsummon(19116): '
++ shift
++ for i in '"$@"'
++ echo -n ' "real_default_sorcery_download@86"'
++ echo
++ true
+ local SOURCE_NUMBER
++ real_get_source_nums X
++ local foo
++ compgen -v SOURCE
++ grep '^SOURCE[[:digit:]]*$'
++ sort
++ uniq
++ read foo
+ rc=0
+ eval 'function real_default_download() {
    default_grimoire_download
  }'
+ return 0
+ rc=0
+ eval 'function real_default_download() {
    default_section_download
  }'
+ return 0
+ rc=0
+ persistent_save
+ debug libapi 'persistent_save - '
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_libapi
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'libapi(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "persistent_save - "'
+ echo
+ true
+ real_persistent_save
+ local VAR
+ local TMP
+ for VAR in '$PERSISTENT_VARIABLES'
+ config_get_option DRM_AUTOUPDATE TMP
+ [[ -n '' ]]
+ real_list_find DRM_AUTOUPDATE DRM_AUTOUPDATE
+ local i
+ local input=DRM_AUTOUPDATE
+ shift
+ for i in '$@'
+ eval 'echo " DRM_AUTOUPDATE " | grep -q -e "[[:space:]]DRM_AUTOUPDATE[[:space:]]" && return 0'
++ echo ' DRM_AUTOUPDATE '
++ grep -q -e '[[:space:]]DRM_AUTOUPDATE[[:space:]]'
++ return 0
+ [[ -n TMP ]]
+ eval 'TMP="$DRM_AUTOUPDATE"'
++ TMP=n
+ return 0
+ echo 'DRM_AUTOUPDATE="n"'
+ unset DRM_AUTOUPDATE
+ unset PERSISTENT_VARIABLES
+ eval 'function real_default_download() {
    false
  }'
+ eval 'function real_default_section_download() {
    false
  }'
+ eval 'function real_default_grimoire_download() {
    false
  }'
+ return 0
+ rc=0
+ [[ 0 == 0 ]]
+ activity_log summon drm '' success
+ lock_file /var/log/sorcery/activity
+ debug liblock 'lock_file - /var/log/sorcery/activity'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_liblock
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'liblock(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "lock_file - /var/log/sorcery/activity"'
+ echo
+ true
+ local FILE
++ for FILE in '"$@"'
++ echo file /var/log/sorcery/activity
+ lock_resources file /var/log/sorcery/activity
+ trylock_resources file /var/log/sorcery/activity
+ local lockfile=file./var/log/sorcery/activity
+ lockfile='/tmp/liblock-0/file.^var^log^sorcery^activity'
+ debug trylock_resources 'lockfile=/tmp/liblock-0/file.^var^log^sorcery^activity'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_trylock_resources
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'trylock_resources(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "lockfile=/tmp/liblock-0/file.^var^log^sorcery^activity"'
+ echo
+ true
+ mkdir -p /tmp/liblock-0
+ mkdir '/tmp/liblock-0/file.^var^log^sorcery^activity'
+ ln -sf /proc/19116 '/tmp/liblock-0/file.^var^log^sorcery^activity/19116'
+ return 0
++ date -u '+%Y%m%d:%H%M(%z)'
+ DATE='20060913:1729(+0000)'
+ COMMAND=summon
+ SPELL=drm
+ VERSION=
+ OUTCOME=success
+ INFO=
+ echo -e '20060913:1729(+0000)\tsummon\tdrm\t\tsuccess\t'
+ unlock_file /var/log/sorcery/activity
+ debug liblock 'unlock_file - /var/log/sorcery/activity'
+ [[ -n /dev/null ]]
+ local debugVar=DEBUG_liblock
+ local i
+ [[ '' != \n\o ]]
+ echo -n 'liblock(19116): '
+ shift
+ for i in '"$@"'
+ echo -n ' "unlock_file - /var/log/sorcery/activity"'
+ echo
+ true
+ local FILE
++ for FILE in '"$@"'
++ echo file /var/log/sorcery/activity
+ unlock_resources file /var/log/sorcery/activity
+ local lockfile=file./var/log/sorcery/activity
+ lockfile='/tmp/liblock-0/file.^var^log^sorcery^activity'
+ rm '/tmp/liblock-0/file.^var^log^sorcery^activity/19116'
+ rmdir '/tmp/liblock-0/file.^var^log^sorcery^activity'
+ return 0
+ return 0
+ popd
+ rc=0
+ rm -rf /tmp/sorcery/summon/19116/drm
+ unlock_resources summon drm
+ local lockfile=summon.drm
+ lockfile=/tmp/liblock-0/summon.drm
+ rm /tmp/liblock-0/summon.drm/19116
+ rmdir /tmp/liblock-0/summon.drm
+ return 0
+ return 0
+ rc=0
+ cleanup_tmp_dir /tmp/sorcery/summon/19116
+ local TMP_DIR=/tmp/sorcery/summon/19116
+ '[' /tmp/sorcery/ == /tmp/sorcery/ ']'
+ rm -rf /tmp/sorcery/summon/19116
+ exit 0