* [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something
@ 2022-05-25 18:44 Noah Sanci
2022-05-27 16:20 ` Mark Wielaard
0 siblings, 1 reply; 6+ messages in thread
From: Noah Sanci @ 2022-05-25 18:44 UTC (permalink / raw)
To: elfutils-devel
[-- Attachment #1: Type: text/plain, Size: 150 bytes --]
PR28577: Make run-debuginfod-fd-prefetch-caches.sh test
something
Update to the run-debuginfod-fd-prefetch to make the test more sound.
[-- Attachment #2: 0001-PR28577-Make-run-debuginfod-fd-prefetch-caches.sh-te.patch --]
[-- Type: text/x-patch, Size: 7716 bytes --]
From b84dd9b2b36812ea299ff189c7e5557863dd82d2 Mon Sep 17 00:00:00 2001
From: Noah Sanci <nsanci@redhat.com>
Date: Fri, 13 May 2022 14:32:27 -0400
Subject: [PATCH] PR28577: Make run-debuginfod-fd-prefetch-caches.sh test
something
Update to the run-debuginfod-fd-prefetch to make the test more
sound.
---
tests/run-debuginfod-fd-prefetch-caches.sh | 116 +++++++++------------
1 file changed, 48 insertions(+), 68 deletions(-)
diff --git a/tests/run-debuginfod-fd-prefetch-caches.sh b/tests/run-debuginfod-fd-prefetch-caches.sh
index 66a7a083..50ffc4ac 100755
--- a/tests/run-debuginfod-fd-prefetch-caches.sh
+++ b/tests/run-debuginfod-fd-prefetch-caches.sh
@@ -21,22 +21,22 @@
# for test case debugging, uncomment:
set -x
unset VALGRIND_CMD
+mkdir R Z
-mkdir R
-cp -rvp ${abs_srcdir}/debuginfod-rpms R
-if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
- rm -vrf R/debuginfod-rpms/fedora31
-fi
-
-FDCACHE_MBS=$((1/1024/1024))
+FDCACHE_MBS=1
FDCACHE_FDS=1
-PREFETCH_MBS=$((1/1024/1024))
-PREFETCH_FDS=2
+PREFETCH_MBS=1
+PREFETCH_FDS=1
PREFETCH=1
# This variable is essential and ensures no time-race for claiming ports occurs
# set base to a unique multiple of 100 not used in any other 'run-debuginfod-*' test
base=8800
get_ports
+cp -rvp ${abs_srcdir}/debuginfod-rpms R
+if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
+ rm -vrf R/debuginfod-rpms/fedora31
+fi
+cp -rvp ${abs_srcdir}/debuginfod-tars Z
DB=${PWD}/.debuginfod_tmp.sqlite
tempfiles $DB
@@ -47,88 +47,68 @@ export DEBUGINFOD_CACHE_PATH=${PWD}/.client_cache
######
rm -rf $DEBUGINFOD_CACHE_PATH
rm -rf $DB
+
# Set mb values to ensure the caches certainly have enough space
# To store the test files
env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS= ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d $DB \
- --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-fds=$PREFETCH_FDS --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R \
- --fdcache-mbs=50 --fdcache-prefetch-mbs=50 \
- --fdcache-prefetch=$PREFETCH > vlog$PORT1 2>&1 &
+ --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-fds=$PREFETCH_FDS -vvvvv -g 0 -t 0 -R R \
+ -Z .tar.bz2=bzcat Z --fdcache-mbs=50 --fdcache-prefetch-mbs=100 \
+ --fdcache-prefetch=$PREFETCH -F > vlog$PORT1 2>&1 &
PID1=$!
tempfiles vlog$PORT1
errfiles vlog$PORT1
+
# Server must become ready
wait_ready $PORT1 'ready' 1
########################################################################
-cp -rvp ${abs_srcdir}/debuginfod-rpms R
-if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
- rm -vrf R/debuginfod-rpms/fedora31
-fi
kill -USR1 $PID1
wait_ready $PORT1 'thread_work_total{role="traverse"}' 1
+wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
+wait_ready $PORT1 'thread_busy{role="scan"}' 0
# All rpms need to be in the index, except the dummy permission-000 one
rpms=$(find R -name \*rpm | grep -v nothing | wc -l)
wait_ready $PORT1 'scanned_files_total{source=".rpm archive"}' $rpms
-kill -USR1 $PID1 # two hits of SIGUSR1 may be needed to resolve .debug->dwz->srefs
-# Wait till both files are in the index and scan/index fully finished
+kill -USR1 $PID1
wait_ready $PORT1 'thread_work_total{role="traverse"}' 2
-export DEBUGINFOD_URLS="http://127.0.0.1:"$PORT1
+wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
+wait_ready $PORT1 'thread_busy{role="scan"}' 0
-archive_hits=5
-SHA=f4a1a8062be998ae93b8f1cd744a398c6de6dbb1
-for i in $archive_hits
-do
- archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
-done
+export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/
+# load prefetch cache
+testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
metrics=$(curl http://127.0.0.1:$PORT1/metrics)
-regex="fdcache_op_count\{op=\"enqueue\"\} ([0-9]+).*fdcache_op_count\{op=\"evict\"\} ([0-9]+).*"
-enqueue=0
-if [[ $metrics =~ $regex ]]
-then
- enqueue=${BASH_REMATCH[1]}
- evict=${BASH_REMATCH[2]}
+regex="fdcache_prefetch_count ([0-9])+"
+# Check to see if prefetch cache is loaded
+if [[ $metrics =~ $regex ]]; then
+ if [[ ${BASH_REMATCH[1]} -ne 1 ]]; then
+ err
+ fi
else
- err
-fi
-# This is an ad-hoc test than only works when FDCACHE_FDS < "archive_test"s above (5)
-# otherwise there will be no eviction
-if [[ $(( $enqueue-$FDCACHE_FDS )) -ne $evict ]]
-then
- err
-fi
-# Test prefetch cache
-archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
+ err
+fi
+# Ensure that searching for the source prefetched finds it in the prefetch cache
+testrun ${abs_top_builddir}/debuginfod/debuginfod-find source cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb /usr/src/debug/hello.c
metrics=$(curl http://127.0.0.1:$PORT1/metrics)
-regex="fdcache_prefetch_count ([0-9])+"
-pf_count=0
-for i in $FDCACHE_FDS
-do
- if [[ $metrics =~ $regex ]]; then
-
- if [[ $(( $pf_count+$PREFETCH )) -ne ${BASH_REMATCH[1]} ]]; then
- err
- else
- pf_count=${BASH_REMATCH[1]}
- fi
-
- else
+regex="fdcache_op_count\{op=\"prefetch_access\"\} ([0-9])+"
+if [[ $metrics =~ $regex ]]; then
+ if [[ ${BASH_REMATCH[1]} -ne 1 ]]; then
err
fi
-done
+else
+ err
+fi
kill $PID1
wait $PID1
PID1=0
-
#########
-# Test mb limit on fd and prefetch cache
+# Test mb limit on fd cache
#########
-
rm -rf $DEBUGINFOD_CACHE_PATH
rm -rf $DB
env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS= ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d $DB \
- --fdcache-mbs=1 --fdcache-prefetch-mbs=1 --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R \
- > vlog2$PORT1 2>&1 &
+ --fdcache-mbs=$FDCACHE_MBS --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R > vlog2$PORT1 2>&1 &
PID1=$!
tempfiles vlog2$PORT1
errfiles vlog2$PORT1
@@ -139,26 +119,26 @@ wait_ready $PORT1 'thread_work_total{role="traverse"}' 1
# All rpms need to be in the index, except the dummy permission-000 one
rpms=$(find R -name \*rpm | grep -v nothing | wc -l)
wait_ready $PORT1 'scanned_files_total{source=".rpm archive"}' $rpms
-kill -USR1 $PID1 # two hits of SIGUSR1 may be needed to resolve .debug->dwz->srefs
-# Wait till both files are in the index and scan/index fully finished
+kill -USR1 $PID1
wait_ready $PORT1 'thread_work_total{role="traverse"}' 2
+wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
+wait_ready $PORT1 'thread_busy{role="scan"}' 0
-archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
+# This many archives cause the fd cache to be loaded with just over 1mb of
+# files. So we expect the 1mb cap off
+SHA=f4a1a8062be998ae93b8f1cd744a398c6de6dbb1
archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
archive_test 41a236eb667c362a1c4196018cc4581e09722b1b /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
archive_test f0aa15b8aba4f3c28cac3c2a73801fefa644a9f2 /usr/src/debug/hello-1.0/hello.c $SHA
archive_test bbbf92ebee5228310e398609c23c2d7d53f6e2f9 /usr/src/debug/hello-1.0/hello.c $SHA
-archive_test d44d42cbd7d915bc938c81333a21e355a6022fb7 /usr/src/debug/hello-1.0/hello.c $SHA
-
metrics=$(curl http://127.0.0.1:$PORT1/metrics)
-regex="fdcache_bytes ([0-9]+).*fdcache_prefetch_bytes ([0-9]+)"
+regex="fdcache_bytes ([0-9]+)"
mb=$((1024*1024))
if [[ $metrics =~ $regex ]]; then
fdbytes=${BASH_REMATCH[1]}
- pfbytes=${BASH_REMATCH[2]}
- if [ $fdbytes -gt $mb ] || [ $pfbytes -gt $mb ]; then
+ if [ $fdbytes -gt $mb ] ; then
err
fi
else
--
2.36.1
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something
2022-05-25 18:44 [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something Noah Sanci
@ 2022-05-27 16:20 ` Mark Wielaard
[not found] ` <CAJXA7qiYfeEpr5pHY5xPWcmnMoA1csnBvDnAHBoTubTVyBz+4g@mail.gmail.com>
0 siblings, 1 reply; 6+ messages in thread
From: Mark Wielaard @ 2022-05-27 16:20 UTC (permalink / raw)
To: Noah Sanci, elfutils-devel
Hi Noah,
On Wed, 2022-05-25 at 14:44 -0400, Noah Sanci via Elfutils-devel wrote:
> PR28577: Make run-debuginfod-fd-prefetch-caches.sh test
> something
>
> Update to the run-debuginfod-fd-prefetch to make the test more sound.
Thanks. And according to Evgeny this makes the test pass for him:
https://sourceware.org/bugzilla/show_bug.cgi?id=29180#c2
But I find it a little hard to review, it would have been helpful to
get a bit more comments/documentation what exactly is being tested now.
> diff --git a/tests/run-debuginfod-fd-prefetch-caches.sh b/tests/run-
> debuginfod-fd-prefetch-caches.sh
> index 66a7a083..50ffc4ac 100755
> --- a/tests/run-debuginfod-fd-prefetch-caches.sh
> +++ b/tests/run-debuginfod-fd-prefetch-caches.sh
> @@ -21,22 +21,22 @@
> # for test case debugging, uncomment:
> set -x
> unset VALGRIND_CMD
> +mkdir R Z
OK, some boilerplate.
> -mkdir R
> -cp -rvp ${abs_srcdir}/debuginfod-rpms R
> -if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
> - rm -vrf R/debuginfod-rpms/fedora31
> -fi
This gets moved to below.
> -FDCACHE_MBS=$((1/1024/1024))
> +FDCACHE_MBS=1
> FDCACHE_FDS=1
> -PREFETCH_MBS=$((1/1024/1024))
> -PREFETCH_FDS=2
> +PREFETCH_MBS=1
> +PREFETCH_FDS=1
> PREFETCH=1
OK, new presets.
> # This variable is essential and ensures no time-race for claiming
> ports occurs
> # set base to a unique multiple of 100 not used in any other 'run-
> debuginfod-*' test
> base=8800
> get_ports
> +cp -rvp ${abs_srcdir}/debuginfod-rpms R
> +if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
> + rm -vrf R/debuginfod-rpms/fedora31
> +fi
> +cp -rvp ${abs_srcdir}/debuginfod-tars Z
OK, put rpms under R, tars under Z.
> DB=${PWD}/.debuginfod_tmp.sqlite
> tempfiles $DB
> @@ -47,88 +47,68 @@ export DEBUGINFOD_CACHE_PATH=${PWD}/.client_cache
> ######
> rm -rf $DEBUGINFOD_CACHE_PATH
> rm -rf $DB
> +
> # Set mb values to ensure the caches certainly have enough space
> # To store the test files
> env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS= ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d $DB \
> - --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-fds=$PREFETCH_FDS --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R \
> - --fdcache-mbs=50 --fdcache-prefetch-mbs=50 \
> - --fdcache-prefetch=$PREFETCH > vlog$PORT1 2>&1 &
> + --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-fds=$PREFETCH_FDS -vvvvv -g 0 -t 0 -R R \
> + -Z .tar.bz2=bzcat Z --fdcache-mbs=50 --fdcache-prefetch-mbs=100 \
> + --fdcache-prefetch=$PREFETCH -F > vlog$PORT1 2>&1 &
Now run with --fdcache-fds=1 --fdcache-mbs=50 and
-fdcache-prefetch-fds=1 fdcache-prefetch=1 -fdcache-prefetch-mbs=100
It is these last 3 we want to test.
> PID1=$!
> tempfiles vlog$PORT1
> errfiles vlog$PORT1
> +
> # Server must become ready
> wait_ready $PORT1 'ready' 1
> ########################################################################
> -cp -rvp ${abs_srcdir}/debuginfod-rpms R
> -if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
> - rm -vrf R/debuginfod-rpms/fedora31
> -fi
> kill -USR1 $PID1
> wait_ready $PORT1 'thread_work_total{role="traverse"}' 1
> +wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
> +wait_ready $PORT1 'thread_busy{role="scan"}' 0
OK, boilerplate to wait for initial scan.
> # All rpms need to be in the index, except the dummy permission-000 one
> rpms=$(find R -name \*rpm | grep -v nothing | wc -l)
> wait_ready $PORT1 'scanned_files_total{source=".rpm archive"}' $rpms
> -kill -USR1 $PID1 # two hits of SIGUSR1 may be needed to resolve .debug->dwz->srefs
> -# Wait till both files are in the index and scan/index fully finished
> +kill -USR1 $PID1
> wait_ready $PORT1 'thread_work_total{role="traverse"}' 2
> -export DEBUGINFOD_URLS="http://127.0.0.1:"$PORT1
> +wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
> +wait_ready $PORT1 'thread_busy{role="scan"}' 0
Do another scan and wait for it to be ready.
> -archive_hits=5
> -SHA=f4a1a8062be998ae93b8f1cd744a398c6de6dbb1
> -for i in $archive_hits
> -do
> - archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
> -done
> +export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/
> +# load prefetch cache
> +testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
OK, which particular file is this?
> metrics=$(curl http://127.0.0.1:$PORT1/metrics)
> -regex="fdcache_op_count\{op=\"enqueue\"\} ([0-9]+).*fdcache_op_count\{op=\"evict\"\} ([0-9]+).*"
> -enqueue=0
> -if [[ $metrics =~ $regex ]]
> -then
> - enqueue=${BASH_REMATCH[1]}
> - evict=${BASH_REMATCH[2]}
> +regex="fdcache_prefetch_count ([0-9])+"
> +# Check to see if prefetch cache is loaded
> +if [[ $metrics =~ $regex ]]; then
> + if [[ ${BASH_REMATCH[1]} -ne 1 ]]; then
> + err
> + fi
Why the -ne 1 ? What number are we expecting and why?
> else
> - err
> -fi
> -# This is an ad-hoc test than only works when FDCACHE_FDS < "archive_test"s above (5)
> -# otherwise there will be no eviction
> -if [[ $(( $enqueue-$FDCACHE_FDS )) -ne $evict ]]
> -then
> - err
> -fi
> -# Test prefetch cache
> -archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
> + err
> +fi
> +# Ensure that searching for the source prefetched finds it in the prefetch cache
> +testrun ${abs_top_builddir}/debuginfod/debuginfod-find source cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb /usr/src/debug/hello.c
> metrics=$(curl http://127.0.0.1:$PORT1/metrics)
> -regex="fdcache_prefetch_count ([0-9])+"
> -pf_count=0
> -for i in $FDCACHE_FDS
> -do
> - if [[ $metrics =~ $regex ]]; then
> -
> - if [[ $(( $pf_count+$PREFETCH )) -ne ${BASH_REMATCH[1]} ]]; then
> - err
> - else
> - pf_count=${BASH_REMATCH[1]}
> - fi
> -
> - else
> +regex="fdcache_op_count\{op=\"prefetch_access\"\} ([0-9])+"
> +if [[ $metrics =~ $regex ]]; then
> + if [[ ${BASH_REMATCH[1]} -ne 1 ]]; then
> err
> fi
> -done
> +else
> + err
> +fi
Again -ne 1? Shouldn't it be different from the above now?
> kill $PID1
> wait $PID1
> PID1=0
>
> -
> #########
> -# Test mb limit on fd and prefetch cache
> +# Test mb limit on fd cache
> #########
> -
> rm -rf $DEBUGINFOD_CACHE_PATH
> rm -rf $DB
> env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS= ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d $DB \
> - --fdcache-mbs=1 --fdcache-prefetch-mbs=1 --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R \
> - > vlog2$PORT1 2>&1 &
> + --fdcache-mbs=$FDCACHE_MBS --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R > vlog2$PORT1 2>&1 &
> PID1=$!
OK start a fresh debuginfod with -fdcache-mbs=1 --fdcache-mintmp 0
Is the fdcache-mintmp 0 meant to clear the cache immediately?
> tempfiles vlog2$PORT1
> errfiles vlog2$PORT1
> @@ -139,26 +119,26 @@ wait_ready $PORT1 'thread_work_total{role="traverse"}' 1
> # All rpms need to be in the index, except the dummy permission-000 one
> rpms=$(find R -name \*rpm | grep -v nothing | wc -l)
> wait_ready $PORT1 'scanned_files_total{source=".rpm archive"}' $rpms
> -kill -USR1 $PID1 # two hits of SIGUSR1 may be needed to resolve .debug->dwz->srefs
> -# Wait till both files are in the index and scan/index fully finished
> +kill -USR1 $PID1
> wait_ready $PORT1 'thread_work_total{role="traverse"}' 2
> +wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
> +wait_ready $PORT1 'thread_busy{role="scan"}' 0
OK, boilerplate again for triggering and waiting for a new scan to
complete.
> -archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
> +# This many archives cause the fd cache to be loaded with just over 1mb of
> +# files. So we expect the 1mb cap off
> +SHA=f4a1a8062be998ae93b8f1cd744a398c6de6dbb1
> archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
> archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
> archive_test 41a236eb667c362a1c4196018cc4581e09722b1b /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
> archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
> archive_test f0aa15b8aba4f3c28cac3c2a73801fefa644a9f2 /usr/src/debug/hello-1.0/hello.c $SHA
> archive_test bbbf92ebee5228310e398609c23c2d7d53f6e2f9 /usr/src/debug/hello-1.0/hello.c $SHA
> -archive_test d44d42cbd7d915bc938c81333a21e355a6022fb7 /usr/src/debug/hello-1.0/hello.c $SHA
OK, test that the hello.c source file is found in the scanned archives,
that the fdcache is used and that the sha1sum checks out.
> metrics=$(curl http://127.0.0.1:$PORT1/metrics)
> -regex="fdcache_bytes ([0-9]+).*fdcache_prefetch_bytes ([0-9]+)"
> +regex="fdcache_bytes ([0-9]+)"
> mb=$((1024*1024))
> if [[ $metrics =~ $regex ]]; then
> fdbytes=${BASH_REMATCH[1]}
> - pfbytes=${BASH_REMATCH[2]}
> - if [ $fdbytes -gt $mb ] || [ $pfbytes -gt $mb ]; then
> + if [ $fdbytes -gt $mb ] ; then
> err
> fi
OK, check that the prefetch cache isn't bigger than 10MB. Why that
number?
Thanks,
Mark
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something
[not found] ` <CAJXA7qiYfeEpr5pHY5xPWcmnMoA1csnBvDnAHBoTubTVyBz+4g@mail.gmail.com>
@ 2022-05-30 15:36 ` Mark Wielaard
2022-06-03 14:49 ` Mark Wielaard
0 siblings, 1 reply; 6+ messages in thread
From: Mark Wielaard @ 2022-05-30 15:36 UTC (permalink / raw)
To: Noah Sanci; +Cc: elfutils-devel
[-- Attachment #1: Type: text/plain, Size: 8088 bytes --]
Hi Noah,
Hope you don't mind me adding elfutils-devel back to the CC.
On Fri, 2022-05-27 at 15:32 -0400, Noah Sanci wrote:
> On Fri, May 27, 2022 at 12:29 PM Mark Wielaard <mark@klomp.org>
> wrote:
>
> > On Wed, 2022-05-25 at 14:44 -0400, Noah Sanci via Elfutils-devel
> > wrote:
> > > PR28577: Make run-debuginfod-fd-prefetch-caches.sh test
> > > something
> > >
> > > Update to the run-debuginfod-fd-prefetch to make the test more
> > > sound.
> >
> > Thanks. And according to Evgeny this makes the test pass for him:
> > https://sourceware.org/bugzilla/show_bug.cgi?id=29180#c2
>
> Good to hear.
> > But I find it a little hard to review, it would have been helpful
> > to
> > get a bit more comments/documentation what exactly is being tested
> > now.
>
> Fair, I should have made what was being tested/why clearer.
Thanks. I also understand now that I read the test logic the wrong way
around.
> > > diff --git a/tests/run-debuginfod-fd-prefetch-caches.sh
> > > b/tests/run-
> > > debuginfod-fd-prefetch-caches.sh
> > > index 66a7a083..50ffc4ac 100755
> > > --- a/tests/run-debuginfod-fd-prefetch-caches.sh
> > > +++ b/tests/run-debuginfod-fd-prefetch-caches.sh
> > > @@ -21,22 +21,22 @@
> > > # for test case debugging, uncomment:
> > > set -x
> > > unset VALGRIND_CMD
> > > +mkdir R Z
> >
> > OK, some boilerplate.
> > > -mkdir R
> > > -cp -rvp ${abs_srcdir}/debuginfod-rpms R
> > > -if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
> > > - rm -vrf R/debuginfod-rpms/fedora31
> > > -fi
> >
> > This gets moved to below.
>
> The two above changes should look better now
>
> > > DB=${PWD}/.debuginfod_tmp.sqlite
> > > tempfiles $DB
> > > @@ -47,88 +47,68 @@ export
> > > DEBUGINFOD_CACHE_PATH=${PWD}/.client_cache
> > > ######
> > > rm -rf $DEBUGINFOD_CACHE_PATH
> > > rm -rf $DB
> > > +
> > > # Set mb values to ensure the caches certainly have enough space
> > > # To store the test files
> > > env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS=
> > > ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d
> > > $DB \
> > > - --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-
> > > fds=$PREFETCH_FDS --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R \
> > > - --fdcache-mbs=50 --fdcache-prefetch-mbs=50 \
> > > - --fdcache-prefetch=$PREFETCH > vlog$PORT1 2>&1 &
> > > + --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-
> > > fds=$PREFETCH_FDS -vvvvv -g 0 -t 0 -R R \
> > > + -Z .tar.bz2=bzcat Z --fdcache-mbs=50 --fdcache-prefetch-
> > > mbs=100 \
> > > + --fdcache-prefetch=$PREFETCH -F > vlog$PORT1 2>&1 &
> >
> > Now run with --fdcache-fds=1 --fdcache-mbs=50 and
> > -fdcache-prefetch-fds=1 fdcache-prefetch=1 -fdcache-prefetch-
> > mbs=100
> >
> > It is these last 3 we want to test.
>
> This particular instance of debuginfod was intended to test
> fdcache-fds and prefetch-fds.
> The test is just testing prefetch-fds. fdcache-fds was tested in a
> different diff, but because the
> fdcache is just the basic lru the test was removed. Mb values are set
> high enough so that no
> files will be excluded for being too large. Maybe there should be a
> test prior to this for just
> fdcache-prefetch as it determines how much is prefetched.
OK. I think no extra test is needed.
> > > PID1=$!
> > > tempfiles vlog$PORT1
> > > errfiles vlog$PORT1
> > > +
> > > # Server must become ready
> > > wait_ready $PORT1 'ready' 1
> > > ################################################################
> > > ########
> > > -cp -rvp ${abs_srcdir}/debuginfod-rpms R
> > > -if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
> > > - rm -vrf R/debuginfod-rpms/fedora31
> > > -fi
> > > kill -USR1 $PID1
> > > wait_ready $PORT1 'thread_work_total{role="traverse"}' 1
> > > +wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
> > > +wait_ready $PORT1 'thread_busy{role="scan"}' 0
> >
> > OK, boilerplate to wait for initial scan.
>
> Yes, Frank told me that just checking traverse is insufficient to
> conclude a
> scan has completed.
> > > -archive_hits=5
> > > -SHA=f4a1a8062be998ae93b8f1cd744a398c6de6dbb1
> > > -for i in $archive_hits
> > > -do
> > > - archive_test c36708a78618d597dee15d0dc989f093ca5f9120
> > > /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
> > > -done
> > > +export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/
> > > +# load prefetch cache
> > > +testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo
> > > cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
> >
> > OK, which particular file is this?
>
> pk.pkg.tar/usr/src/debug/hello.c, now elaborated in comment
Thanks.
> > > metrics=$(curl http://127.0.0.1:$PORT1/metrics)
> > > -regex="fdcache_op_count\{op=\"enqueue\"\} ([0-
> > > 9]+).*fdcache_op_count\{op=\"evict\"\} ([0-9]+).*"
> > > -enqueue=0
> > > -if [[ $metrics =~ $regex ]]
> > > -then
> > > - enqueue=${BASH_REMATCH[1]}
> > > - evict=${BASH_REMATCH[2]}
> > > +regex="fdcache_prefetch_count ([0-9])+"
> > > +# Check to see if prefetch cache is loaded
> > > +if [[ $metrics =~ $regex ]]; then
> > > + if [[ ${BASH_REMATCH[1]} -ne 1 ]]; then
> > > + err
> > > + fi
> >
> > Why the -ne 1 ? What number are we expecting and why?
>
> Ensuring that prefetch is loaded, but not loaded more than it is
> intended to hold.
> debuginfod will try to load 2 files into prefetch, so check to ensure
> that only 1 is loaded.
> Explained in comment.
Right. I misread the test condition. This makes sense now.
> > > else
> > > - err
> > > -fi
> > > -# This is an ad-hoc test than only works when FDCACHE_FDS <
> > > "archive_test"s above (5)
> > > -# otherwise there will be no eviction
> > > -if [[ $(( $enqueue-$FDCACHE_FDS )) -ne $evict ]]
> > > -then
> > > - err
> > > -fi
> > > -# Test prefetch cache
> > > -archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30
> > > /usr/src/debug/hello-1.0/hello.c $SHA
> > > + err
> > > +fi
> > > +# Ensure that searching for the source prefetched finds it in
> > > the prefetch cache
> > > +testrun ${abs_top_builddir}/debuginfod/debuginfod-find source
> > > cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb /usr/src/debug/hello.c
> > > metrics=$(curl http://127.0.0.1:$PORT1/metrics)
> > > -regex="fdcache_prefetch_count ([0-9])+"
> > > -pf_count=0
> > > -for i in $FDCACHE_FDS
> > > -do
> > > - if [[ $metrics =~ $regex ]]; then
> > > -
> > > - if [[ $(( $pf_count+$PREFETCH )) -ne ${BASH_REMATCH[1]} ]];
> > > then
> > > - err
> > > - else
> > > - pf_count=${BASH_REMATCH[1]}
> > > - fi
> > > -
> > > - else
> > > +regex="fdcache_op_count\{op=\"prefetch_access\"\} ([0-9])+"
> > > +if [[ $metrics =~ $regex ]]; then
> > > + if [[ ${BASH_REMATCH[1]} -ne 1 ]]; then
> > > err
> > > fi
> > > -done
> > > +else
> > > + err
> > > +fi
> >
> > Again -ne 1? Shouldn't it be different from the above now?
>
> Now we're seeing if debuginfod is actually using the prefetch cache
> by checking the access count.
> We're searching for the 1 file we loaded before so we expect 1
> access.
> Explained in comment
Thanks.
> > > metrics=$(curl http://127.0.0.1:$PORT1/metrics)
> > > -regex="fdcache_bytes ([0-9]+).*fdcache_prefetch_bytes ([0-9]+)"
> > > +regex="fdcache_bytes ([0-9]+)"
> > > mb=$((1024*1024))
> > > if [[ $metrics =~ $regex ]]; then
> > > fdbytes=${BASH_REMATCH[1]}
> > > - pfbytes=${BASH_REMATCH[2]}
> > > - if [ $fdbytes -gt $mb ] || [ $pfbytes -gt $mb ]; then
> > > + if [ $fdbytes -gt $mb ] ; then
> > > err
> > > fi
> >
> > OK, check that the prefetch cache isn't bigger than 10MB. Why that
> > number?
>
> mb should equal 1mb in bytes as this is the maximum space allocated
> to both the prefetch and fd cache. and curling metrics returns memory
> used in bytes
Thanks. I was off by a factor 10. Sorry.
> Please find the new patch attached.
Thanks for adding all the comments. Looks good.
Cheers,
Mark
[-- Attachment #2: 0001-PR28577-Make-run-debuginfod-fd-prefetch-caches.sh-te.patch --]
[-- Type: text/x-patch, Size: 7981 bytes --]
From 07cfa0f6698102e8be1cfd710344ef61c9c161f3 Mon Sep 17 00:00:00 2001
From: Noah Sanci <nsanci@redhat.com>
Date: Fri, 13 May 2022 14:32:27 -0400
Subject: [PATCH] PR28577: Make run-debuginfod-fd-prefetch-caches.sh test
something
Update to the run-debuginfod-fd-prefetch to make the test more
sound.
---
tests/run-debuginfod-fd-prefetch-caches.sh | 121 +++++++++------------
1 file changed, 49 insertions(+), 72 deletions(-)
diff --git a/tests/run-debuginfod-fd-prefetch-caches.sh b/tests/run-debuginfod-fd-prefetch-caches.sh
index 66a7a083..8778d3a2 100755
--- a/tests/run-debuginfod-fd-prefetch-caches.sh
+++ b/tests/run-debuginfod-fd-prefetch-caches.sh
@@ -22,17 +22,19 @@
set -x
unset VALGRIND_CMD
-mkdir R
+# Set up archive folders for scanning
+mkdir R Z
+cp -rvp ${abs_srcdir}/debuginfod-tars Z
cp -rvp ${abs_srcdir}/debuginfod-rpms R
if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
rm -vrf R/debuginfod-rpms/fedora31
fi
-FDCACHE_MBS=$((1/1024/1024))
+# Set up maximums. 1 is just a convenient cap to test on.
+FDCACHE_MBS=1
FDCACHE_FDS=1
-PREFETCH_MBS=$((1/1024/1024))
-PREFETCH_FDS=2
-PREFETCH=1
+PREFETCH_FDS=1
+PREFETCH=2
# This variable is essential and ensures no time-race for claiming ports occurs
# set base to a unique multiple of 100 not used in any other 'run-debuginfod-*' test
base=8800
@@ -47,88 +49,61 @@ export DEBUGINFOD_CACHE_PATH=${PWD}/.client_cache
######
rm -rf $DEBUGINFOD_CACHE_PATH
rm -rf $DB
-# Set mb values to ensure the caches certainly have enough space
-# To store the test files
+# Testing prefetch fd maximum (Set mb maximums to be beyond consideration)
env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS= ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d $DB \
- --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-fds=$PREFETCH_FDS --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R \
- --fdcache-mbs=50 --fdcache-prefetch-mbs=50 \
- --fdcache-prefetch=$PREFETCH > vlog$PORT1 2>&1 &
+ --fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-fds=$PREFETCH_FDS -vvvvv -g 0 -t 0 \
+ -Z .tar.bz2=bzcat Z --fdcache-mbs=100 --fdcache-prefetch-mbs=100 \
+ --fdcache-prefetch=$PREFETCH > vlog$PORT1 2>&1 &
PID1=$!
tempfiles vlog$PORT1
errfiles vlog$PORT1
# Server must become ready
wait_ready $PORT1 'ready' 1
########################################################################
-cp -rvp ${abs_srcdir}/debuginfod-rpms R
-if [ "$zstd" = "false" ]; then # nuke the zstd fedora 31 ones
- rm -vrf R/debuginfod-rpms/fedora31
-fi
kill -USR1 $PID1
wait_ready $PORT1 'thread_work_total{role="traverse"}' 1
-# All rpms need to be in the index, except the dummy permission-000 one
-rpms=$(find R -name \*rpm | grep -v nothing | wc -l)
-wait_ready $PORT1 'scanned_files_total{source=".rpm archive"}' $rpms
-kill -USR1 $PID1 # two hits of SIGUSR1 may be needed to resolve .debug->dwz->srefs
-# Wait till both files are in the index and scan/index fully finished
-wait_ready $PORT1 'thread_work_total{role="traverse"}' 2
-export DEBUGINFOD_URLS="http://127.0.0.1:"$PORT1
-
-archive_hits=5
-SHA=f4a1a8062be998ae93b8f1cd744a398c6de6dbb1
-for i in $archive_hits
-do
- archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
-done
-metrics=$(curl http://127.0.0.1:$PORT1/metrics)
-regex="fdcache_op_count\{op=\"enqueue\"\} ([0-9]+).*fdcache_op_count\{op=\"evict\"\} ([0-9]+).*"
-enqueue=0
-if [[ $metrics =~ $regex ]]
-then
- enqueue=${BASH_REMATCH[1]}
- evict=${BASH_REMATCH[2]}
-else
- err
-fi
-# This is an ad-hoc test than only works when FDCACHE_FDS < "archive_test"s above (5)
-# otherwise there will be no eviction
-if [[ $(( $enqueue-$FDCACHE_FDS )) -ne $evict ]]
-then
- err
-fi
-# Test prefetch cache
-archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
+wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
+wait_ready $PORT1 'thread_busy{role="scan"}' 0
+export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/
+# load prefetch cache with debuginfod-tars/usr/src/debug/hello.c
+testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
metrics=$(curl http://127.0.0.1:$PORT1/metrics)
regex="fdcache_prefetch_count ([0-9])+"
-pf_count=0
-for i in $FDCACHE_FDS
-do
- if [[ $metrics =~ $regex ]]; then
-
- if [[ $(( $pf_count+$PREFETCH )) -ne ${BASH_REMATCH[1]} ]]; then
- err
- else
- pf_count=${BASH_REMATCH[1]}
- fi
+# Check to see if prefetch cache is maximally loaded. Note fdcache-prefetch (2) > prefetch-fds (1),
+# so the debuginfod will try to load the prefetch cache with 2 files. We want prefetch-fds to cap that
+# off
+if [[ $metrics =~ $regex ]]; then
+ if [[ ${BASH_REMATCH[1]} -ne $PREFETCH_FDS ]]; then
+ err
+ fi
+else
+ err
+fi
- else
+testrun ${abs_top_builddir}/debuginfod/debuginfod-find source cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb /usr/src/debug/hello.c
+metrics=$(curl http://127.0.0.1:$PORT1/metrics)
+regex="fdcache_op_count\{op=\"prefetch_access\"\} ([0-9])+"
+if [[ $metrics =~ $regex ]]; then
+ # In the test above hello.c should've been loaded into the prefetch cache.
+ # Ensure that searching for hello.c a second time accesses the prefetch cache once
+ if [[ ${BASH_REMATCH[1]} -ne 1 ]]; then
err
fi
-done
+else
+ err
+fi
kill $PID1
wait $PID1
PID1=0
-
#########
-# Test mb limit on fd and prefetch cache
+# Test mb limit on fd cache
#########
-
rm -rf $DEBUGINFOD_CACHE_PATH
rm -rf $DB
env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS= ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d $DB \
- --fdcache-mbs=1 --fdcache-prefetch-mbs=1 --fdcache-mintmp 0 -vvvvv -g 0 -t 0 -R R \
- > vlog2$PORT1 2>&1 &
+ --fdcache-mbs=$FDCACHE_MBS -vvvvv -g 0 -t 0 -R R > vlog2$PORT1 2>&1 &
PID1=$!
tempfiles vlog2$PORT1
errfiles vlog2$PORT1
@@ -139,26 +114,28 @@ wait_ready $PORT1 'thread_work_total{role="traverse"}' 1
# All rpms need to be in the index, except the dummy permission-000 one
rpms=$(find R -name \*rpm | grep -v nothing | wc -l)
wait_ready $PORT1 'scanned_files_total{source=".rpm archive"}' $rpms
-kill -USR1 $PID1 # two hits of SIGUSR1 may be needed to resolve .debug->dwz->srefs
-# Wait till both files are in the index and scan/index fully finished
+kill -USR1 $PID1
wait_ready $PORT1 'thread_work_total{role="traverse"}' 2
+wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
+wait_ready $PORT1 'thread_busy{role="scan"}' 0
-archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
+# This many archives cause the fd cache to be loaded with just over 1mb of
+# files. So we expect the 1mb cap off
+SHA=f4a1a8062be998ae93b8f1cd744a398c6de6dbb1
archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
archive_test c36708a78618d597dee15d0dc989f093ca5f9120 /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
archive_test 41a236eb667c362a1c4196018cc4581e09722b1b /usr/src/debug/hello2-1.0-2.x86_64/hello.c $SHA
archive_test bc1febfd03ca05e030f0d205f7659db29f8a4b30 /usr/src/debug/hello-1.0/hello.c $SHA
archive_test f0aa15b8aba4f3c28cac3c2a73801fefa644a9f2 /usr/src/debug/hello-1.0/hello.c $SHA
archive_test bbbf92ebee5228310e398609c23c2d7d53f6e2f9 /usr/src/debug/hello-1.0/hello.c $SHA
-archive_test d44d42cbd7d915bc938c81333a21e355a6022fb7 /usr/src/debug/hello-1.0/hello.c $SHA
-
metrics=$(curl http://127.0.0.1:$PORT1/metrics)
-regex="fdcache_bytes ([0-9]+).*fdcache_prefetch_bytes ([0-9]+)"
-mb=$((1024*1024))
+regex="fdcache_bytes ([0-9]+)"
+# Since the server metrics report in bytes, $mb is just the total number of bytes allocated
+# to the fd cache. Ensure that this cap isn't crossed
+mb=$(($FDCACHE_MBS*1024*1024))
if [[ $metrics =~ $regex ]]; then
fdbytes=${BASH_REMATCH[1]}
- pfbytes=${BASH_REMATCH[2]}
- if [ $fdbytes -gt $mb ] || [ $pfbytes -gt $mb ]; then
+ if [ $fdbytes -gt $mb ] ; then
err
fi
else
--
2.36.1
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something
2022-05-30 15:36 ` Mark Wielaard
@ 2022-06-03 14:49 ` Mark Wielaard
[not found] ` <CAJXA7qjnhkwRaMWv2C7xnG+ruWFVsPgrvufDG94NUQe2Z067nA@mail.gmail.com>
0 siblings, 1 reply; 6+ messages in thread
From: Mark Wielaard @ 2022-06-03 14:49 UTC (permalink / raw)
To: Noah Sanci; +Cc: elfutils-devel
Hi Noah,
On Mon, 2022-05-30 at 17:36 +0200, Mark Wielaard wrote:
> > Please find the new patch attached.
>
> Thanks for adding all the comments. Looks good.
The only issue is that although it seems to work well on Fedora I am
having problems getting to test to work on an older CentOS 7 install.
It always seems to fail at this point:
export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/
# load prefetch cache with debuginfod-tars/usr/src/debug/hello.c
testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
metrics=$(curl http://127.0.0.1:$PORT1/metrics)
regex="fdcache_prefetch_count ([0-9])+"
# Check to see if prefetch cache is maximally loaded. Note fdcache-prefetch (2) > prefetch-fds (1),
# so the debuginfod will try to load the prefetch cache with 2 files. We want prefetch-fds to cap that
# off
if [[ $metrics =~ $regex ]]; then
if [[ ${BASH_REMATCH[1]} -ne $PREFETCH_FDS ]]; then
err
fi
else
err
fi
Because I am getting:
++ curl http://127.0.0.1:8819/metrics
% Total % Received % Xferd Average
Speed Time Time Time Current
Dload Upload Total Spent Left
Speed
^M 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:
--:-- 0^M100 5793 100 5793 0 0 7532k 0 --:--:-- --
:--:-- --:--:-- 5657k
+ metrics='fdcache_bytes 0
fdcache_count 0
fdcache_op_count{op="emerg-flush"} 3
fdcache_op_count{op="enqueue"} 1
fdcache_op_count{op="evict"} 1
fdcache_op_count{op="prefetch_enqueue"} 1
fdcache_op_count{op="prefetch_evict"} 1
fdcache_op_count{op="probe_miss"} 2
fdcache_prefetch_bytes 0
fdcache_prefetch_count 0
[...]
So no bytes are prefetched at all.
I am not sure why this is happening. Do you see any obvious issue that
would explain this happening on centos7?
Thanks,
Mark
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something
[not found] ` <CAJXA7qjnhkwRaMWv2C7xnG+ruWFVsPgrvufDG94NUQe2Z067nA@mail.gmail.com>
@ 2022-06-03 15:02 ` Mark Wielaard
2022-06-03 16:22 ` Mark Wielaard
0 siblings, 1 reply; 6+ messages in thread
From: Mark Wielaard @ 2022-06-03 15:02 UTC (permalink / raw)
To: Noah Sanci; +Cc: elfutils-devel
[-- Attachment #1: Type: text/plain, Size: 274 bytes --]
Hi Noah,
Adding the mailinglist back to CC so other can jump in if there is
anything obvious from the logs.
On Fri, 2022-06-03 at 10:51 -0400, Noah Sanci wrote:
> Nothing immediately jumps out, would you mind sending the entire log?
Attached.
Cheers,
Mark
[-- Attachment #2: Type: text/x-log, Size: 82099 bytes --]
curl is /usr/bin/curl
rpm2cpio is /usr/bin/rpm2cpio
cpio is /usr/bin/cpio
bzcat is /usr/bin/bzcat
zstd=false bsdtar=bsdtar 3.1.2 - libarchive 3.1.2
+ unset VALGRIND_CMD
+ mkdir R Z
+ cp -rvp /home/mark/src/elfutils/tests/debuginfod-tars Z
'/home/mark/src/elfutils/tests/debuginfod-tars' -> 'Z/debuginfod-tars'
'/home/mark/src/elfutils/tests/debuginfod-tars/hello-1-1-x86_64.pkg.tar.xz' -> 'Z/debuginfod-tars/hello-1-1-x86_64.pkg.tar.xz'
'/home/mark/src/elfutils/tests/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2' -> 'Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2'
'/home/mark/src/elfutils/tests/debuginfod-tars/pacman-sources' -> 'Z/debuginfod-tars/pacman-sources'
'/home/mark/src/elfutils/tests/debuginfod-tars/pacman-sources/PKGBUILD' -> 'Z/debuginfod-tars/pacman-sources/PKGBUILD'
'/home/mark/src/elfutils/tests/debuginfod-tars/pacman-sources/README.md' -> 'Z/debuginfod-tars/pacman-sources/README.md'
'/home/mark/src/elfutils/tests/debuginfod-tars/pacman-sources/hello.c' -> 'Z/debuginfod-tars/pacman-sources/hello.c'
+ cp -rvp /home/mark/src/elfutils/tests/debuginfod-rpms R
'/home/mark/src/elfutils/tests/debuginfod-rpms' -> 'R/debuginfod-rpms'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora30' -> 'R/debuginfod-rpms/fedora30'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora30/hello2-1.0-2.src.rpm' -> 'R/debuginfod-rpms/fedora30/hello2-1.0-2.src.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora30/hello2-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora30/hello2-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora30/hello2-debuginfo-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora30/hello2-debuginfo-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora30/hello2-debugsource-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora30/hello2-debugsource-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora30/hello2-two-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora30/hello2-two-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora30/hello2-two-debuginfo-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora30/hello2-two-debuginfo-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora31' -> 'R/debuginfod-rpms/fedora31'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora31/hello3-1.0-2.src.rpm' -> 'R/debuginfod-rpms/fedora31/hello3-1.0-2.src.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora31/hello3-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora31/hello3-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora31/hello3-debuginfo-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora31/hello3-debuginfo-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora31/hello3-debugsource-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora31/hello3-debugsource-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora31/hello3-two-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora31/hello3-two-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/fedora31/hello3-two-debuginfo-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/fedora31/hello3-two-debuginfo-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/hello2.spec.' -> 'R/debuginfod-rpms/hello2.spec.'
'/home/mark/src/elfutils/tests/debuginfod-rpms/hello3.spec.' -> 'R/debuginfod-rpms/hello3.spec.'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel6' -> 'R/debuginfod-rpms/rhel6'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel6/hello2-1.0-2.i686.rpm' -> 'R/debuginfod-rpms/rhel6/hello2-1.0-2.i686.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel6/hello2-1.0-2.src.rpm' -> 'R/debuginfod-rpms/rhel6/hello2-1.0-2.src.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel6/hello2-debuginfo-1.0-2.i686.rpm' -> 'R/debuginfod-rpms/rhel6/hello2-debuginfo-1.0-2.i686.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel6/hello2-two-1.0-2.i686.rpm' -> 'R/debuginfod-rpms/rhel6/hello2-two-1.0-2.i686.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel7' -> 'R/debuginfod-rpms/rhel7'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel7/hello2-1.0-2.src.rpm' -> 'R/debuginfod-rpms/rhel7/hello2-1.0-2.src.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel7/hello2-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/rhel7/hello2-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel7/hello2-debuginfo-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/rhel7/hello2-debuginfo-1.0-2.x86_64.rpm'
'/home/mark/src/elfutils/tests/debuginfod-rpms/rhel7/hello2-two-1.0-2.x86_64.rpm' -> 'R/debuginfod-rpms/rhel7/hello2-two-1.0-2.x86_64.rpm'
+ '[' false = false ']'
+ rm -vrf R/debuginfod-rpms/fedora31
removed 'R/debuginfod-rpms/fedora31/hello3-1.0-2.src.rpm'
removed 'R/debuginfod-rpms/fedora31/hello3-1.0-2.x86_64.rpm'
removed 'R/debuginfod-rpms/fedora31/hello3-debuginfo-1.0-2.x86_64.rpm'
removed 'R/debuginfod-rpms/fedora31/hello3-debugsource-1.0-2.x86_64.rpm'
removed 'R/debuginfod-rpms/fedora31/hello3-two-1.0-2.x86_64.rpm'
removed 'R/debuginfod-rpms/fedora31/hello3-two-debuginfo-1.0-2.x86_64.rpm'
removed directory: 'R/debuginfod-rpms/fedora31'
+ FDCACHE_MBS=1
+ FDCACHE_FDS=1
+ PREFETCH_FDS=1
+ PREFETCH=2
+ base=8800
+ get_ports
+ true
++ expr '(' 30134 % 50 ')' + 8800
+ PORT1=8834
+ ss -atn
+ fgrep :8834
+ break
+ true
++ expr '(' 31624 % 50 ')' + 8800 + 50
+ PORT2=8874
+ ss -atn
+ fgrep :8874
+ break
+ DB=/home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite
+ tempfiles /home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite
+ remove_files=' /home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite'
+ export DEBUGINFOD_CACHE_PATH=/home/mark/build/elfutils-obj/tests/test-11559/.client_cache
+ DEBUGINFOD_CACHE_PATH=/home/mark/build/elfutils-obj/tests/test-11559/.client_cache
+ rm -rf /home/mark/build/elfutils-obj/tests/test-11559/.client_cache
+ rm -rf /home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite
+ PID1=11584
+ tempfiles vlog8834
+ remove_files=' /home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite vlog8834'
+ errfiles vlog8834
+ errfiles_list=' vlog8834'
+ wait_ready 8834 ready 1
+ port=8834
+ what=ready
+ value=1
+ timeout=20
+ echo 'Wait 20 seconds on 8834 for metric ready to change to 1'
Wait 20 seconds on 8834 for metric ready to change to 1
+ '[' 20 -gt 0 ']'
+ env LD_LIBRARY_PATH=/home/mark/build/elfutils-obj/libdw:/home/mark/build/elfutils-obj/backends:/home/mark/build/elfutils-obj/libelf:/home/mark/build/elfutils-obj/libasm:/home/mark/build/elfutils-obj/debuginfod:/opt/rh/httpd24/root/usr/lib64:/opt/rh/httpd24/root/usr/lib64 DEBUGINFOD_URLS= /home/mark/build/elfutils-obj/tests/../debuginfod/debuginfod -vvv -p 8834 -d /home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite --fdcache-fds=1 --fdcache-prefetch-fds=1 -vvvvv -g 0 -t 0 -Z .tar.bz2=bzcat Z --fdcache-mbs=100 --fdcache-prefetch-mbs=100 --fdcache-prefetch=2
++ curl -s http://127.0.0.1:8834/metrics
++ grep ready
++ awk '{print $NF}'
+ mvalue=
+ '[' -z '' ']'
+ mvalue=0
+ echo 'metric ready: 0'
metric ready: 0
+ '[' 0 -eq 1 ']'
+ sleep 0.5
+ (( timeout-- ))
+ '[' 19 -gt 0 ']'
++ curl -s http://127.0.0.1:8834/metrics
++ grep ready
++ awk '{print $NF}'
+ mvalue=1
+ '[' -z 1 ']'
+ echo 'metric ready: 1'
metric ready: 1
+ '[' 1 -eq 1 ']'
+ break
+ '[' 19 -eq 0 ']'
+ kill -USR1 11584
+ wait_ready 8834 'thread_work_total{role="traverse"}' 1
+ port=8834
+ what='thread_work_total{role="traverse"}'
+ value=1
+ timeout=20
+ echo 'Wait 20 seconds on 8834 for metric thread_work_total{role="traverse"} to change to 1'
Wait 20 seconds on 8834 for metric thread_work_total{role="traverse"} to change to 1
+ '[' 20 -gt 0 ']'
++ curl -s http://127.0.0.1:8834/metrics
++ grep 'thread_work_total{role="traverse"}'
++ awk '{print $NF}'
+ mvalue=
+ '[' -z '' ']'
+ mvalue=0
+ echo 'metric thread_work_total{role="traverse"}: 0'
metric thread_work_total{role="traverse"}: 0
+ '[' 0 -eq 1 ']'
+ sleep 0.5
+ (( timeout-- ))
+ '[' 19 -gt 0 ']'
++ curl -s http://127.0.0.1:8834/metrics
++ grep 'thread_work_total{role="traverse"}'
++ awk '{print $NF}'
+ mvalue=1
+ '[' -z 1 ']'
+ echo 'metric thread_work_total{role="traverse"}: 1'
metric thread_work_total{role="traverse"}: 1
+ '[' 1 -eq 1 ']'
+ break
+ '[' 19 -eq 0 ']'
+ wait_ready 8834 'thread_work_pending{role="scan"}' 0
+ port=8834
+ what='thread_work_pending{role="scan"}'
+ value=0
+ timeout=20
+ echo 'Wait 20 seconds on 8834 for metric thread_work_pending{role="scan"} to change to 0'
Wait 20 seconds on 8834 for metric thread_work_pending{role="scan"} to change to 0
+ '[' 20 -gt 0 ']'
++ curl -s http://127.0.0.1:8834/metrics
++ grep 'thread_work_pending{role="scan"}'
++ awk '{print $NF}'
+ mvalue=0
+ '[' -z 0 ']'
+ echo 'metric thread_work_pending{role="scan"}: 0'
metric thread_work_pending{role="scan"}: 0
+ '[' 0 -eq 0 ']'
+ break
+ '[' 20 -eq 0 ']'
+ wait_ready 8834 'thread_busy{role="scan"}' 0
+ port=8834
+ what='thread_busy{role="scan"}'
+ value=0
+ timeout=20
+ echo 'Wait 20 seconds on 8834 for metric thread_busy{role="scan"} to change to 0'
Wait 20 seconds on 8834 for metric thread_busy{role="scan"} to change to 0
+ '[' 20 -gt 0 ']'
++ curl -s http://127.0.0.1:8834/metrics
++ grep 'thread_busy{role="scan"}'
++ awk '{print $NF}'
+ mvalue=0
+ '[' -z 0 ']'
+ echo 'metric thread_busy{role="scan"}: 0'
metric thread_busy{role="scan"}: 0
+ '[' 0 -eq 0 ']'
+ break
+ '[' 20 -eq 0 ']'
+ export DEBUGINFOD_URLS=http://127.0.0.1:8834/
+ DEBUGINFOD_URLS=http://127.0.0.1:8834/
+ testrun /home/mark/build/elfutils-obj/debuginfod/debuginfod-find debuginfo cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
+ built_testrun /home/mark/build/elfutils-obj/debuginfod/debuginfod-find debuginfo cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
+ LD_LIBRARY_PATH=/home/mark/build/elfutils-obj/libdw:/home/mark/build/elfutils-obj/backends:/home/mark/build/elfutils-obj/libelf:/home/mark/build/elfutils-obj/libasm:/home/mark/build/elfutils-obj/debuginfod:/opt/rh/httpd24/root/usr/lib64:/opt/rh/httpd24/root/usr/lib64
+ /home/mark/build/elfutils-obj/debuginfod/debuginfod-find debuginfo cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
/home/mark/build/elfutils-obj/tests/test-11559/.client_cache/cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb/debuginfo
++ curl http://127.0.0.1:8834/metrics
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0\r100 5785 100 5785 0 0 8344k 0 --:--:-- --:--:-- --:--:-- 5649k
+ metrics='fdcache_bytes 0
fdcache_count 0
fdcache_op_count{op="emerg-flush"} 3
fdcache_op_count{op="enqueue"} 1
fdcache_op_count{op="evict"} 1
fdcache_op_count{op="prefetch_enqueue"} 1
fdcache_op_count{op="prefetch_evict"} 1
fdcache_op_count{op="probe_miss"} 2
fdcache_prefetch_bytes 0
fdcache_prefetch_count 0
filesys_free_ratio{purpose="database"} 0.1539297218490474
filesys_free_ratio{purpose="tmpdir"} 0.08872804205341149
found_debuginfo_total{source=".tar.bz2 archive"} 1
found_executable_total{source=".tar.bz2 archive"} 0
found_sourcerefs_total{source=".tar.bz2 archive"} 9
groom{statistic="archive d/e"} 0
groom{statistic="archive sdef"} 0
groom{statistic="archive sref"} 0
groom{statistic="buildids"} 0
groom{statistic="file d/e"} 0
groom{statistic="file s"} 0
groom{statistic="filenames"} 0
groom{statistic="files scanned (#)"} 0
groom{statistic="files scanned (mb)"} 0
http_requests_total{type="debuginfo"} 1
http_requests_total{type="metrics"} 6
http_responses_after_you_milliseconds_count{code="200",type="debuginfo"} 1
http_responses_after_you_milliseconds_count{code="200",type="metrics"} 5
http_responses_after_you_milliseconds_sum{code="200",type="debuginfo"} 0.005788000000000001
http_responses_after_you_milliseconds_sum{code="200",type="metrics"} 0
http_responses_duration_milliseconds_count{code="200",type="debuginfo"} 1
http_responses_duration_milliseconds_count{code="200",type="metrics"} 5
http_responses_duration_milliseconds_sum{code="200",type="debuginfo"} 4.040639000000001
http_responses_duration_milliseconds_sum{code="200",type="metrics"} 0.288449
http_responses_total{result=".tar.bz2 archive"} 1
http_responses_transfer_bytes_count{code="200",type="debuginfo"} 1
http_responses_transfer_bytes_count{code="200",type="metrics"} 5
http_responses_transfer_bytes_sum{code="200",type="debuginfo"} 7736
http_responses_transfer_bytes_sum{code="200",type="metrics"} 15284
ready 1
scanned_bytes_total{source=".tar.bz2 archive"} 5814
scanned_files_total{source=".tar.bz2 archive"} 1
sqlite3_milliseconds_count{reset="check old files"} 2
sqlite3_milliseconds_count{reset="incremental vacuum"} 1
sqlite3_milliseconds_count{reset="mhd-query-d"} 1
sqlite3_milliseconds_count{reset="nuke orphan buildids"} 1
sqlite3_milliseconds_count{reset="optimize"} 1
sqlite3_milliseconds_count{reset="rpm-buildid-intern"} 1
sqlite3_milliseconds_count{reset="rpm-de-insert"} 1
sqlite3_milliseconds_count{reset="rpm-file-intern"} 15
sqlite3_milliseconds_count{reset="rpm-negativehit-query"} 2
sqlite3_milliseconds_count{reset="rpm-scanned"} 1
sqlite3_milliseconds_count{reset="rpm-sdef-insert"} 4
sqlite3_milliseconds_count{reset="rpm-sref-insert"} 9
sqlite3_milliseconds_count{reset="wal checkpoint"} 1
sqlite3_milliseconds_count{step="check old files"} 1
sqlite3_milliseconds_count{step="database-overview"} 10
sqlite3_milliseconds_count{step="mhd-query-d"} 1
sqlite3_milliseconds_count{step="rpm-negativehit-query"} 1
sqlite3_milliseconds_count{step_done="incremental vacuum"} 1
sqlite3_milliseconds_count{step_done="nuke orphan buildids"} 1
sqlite3_milliseconds_count{step_done="optimize"} 1
sqlite3_milliseconds_count{step_done="rpm-buildid-intern"} 1
sqlite3_milliseconds_count{step_done="rpm-de-insert"} 1
sqlite3_milliseconds_count{step_done="rpm-file-intern"} 15
sqlite3_milliseconds_count{step_done="rpm-scanned"} 1
sqlite3_milliseconds_count{step_done="rpm-sdef-insert"} 4
sqlite3_milliseconds_count{step_done="rpm-sref-insert"} 9
sqlite3_milliseconds_count{step_done="wal checkpoint"} 1
sqlite3_milliseconds_sum{reset="check old files"} 0.002276
sqlite3_milliseconds_sum{reset="incremental vacuum"} 0.000215
sqlite3_milliseconds_sum{reset="mhd-query-d"} 0.00046
sqlite3_milliseconds_sum{reset="nuke orphan buildids"} 0.000434
sqlite3_milliseconds_sum{reset="optimize"} 0.000164
sqlite3_milliseconds_sum{reset="rpm-buildid-intern"} 0.0008309999999999999
sqlite3_milliseconds_sum{reset="rpm-de-insert"} 0.000311
sqlite3_milliseconds_sum{reset="rpm-file-intern"} 0.009559000000000002
sqlite3_milliseconds_sum{reset="rpm-negativehit-query"} 0.002185
sqlite3_milliseconds_sum{reset="rpm-scanned"} 0.000673
sqlite3_milliseconds_sum{reset="rpm-sdef-insert"} 0.00251
sqlite3_milliseconds_sum{reset="rpm-sref-insert"} 0.003144000000000001
sqlite3_milliseconds_sum{reset="wal checkpoint"} 0.000687
sqlite3_milliseconds_sum{step="check old files"} 0.030437
sqlite3_milliseconds_sum{step="database-overview"} 0.051596
sqlite3_milliseconds_sum{step="mhd-query-d"} 0.035134
sqlite3_milliseconds_sum{step="rpm-negativehit-query"} 0.024304
sqlite3_milliseconds_sum{step_done="incremental vacuum"} 0.011465
sqlite3_milliseconds_sum{step_done="nuke orphan buildids"} 0.017668
sqlite3_milliseconds_sum{step_done="optimize"} 0.004877
sqlite3_milliseconds_sum{step_done="rpm-buildid-intern"} 0.040443
sqlite3_milliseconds_sum{step_done="rpm-de-insert"} 0.036597
sqlite3_milliseconds_sum{step_done="rpm-file-intern"} 0.557634
sqlite3_milliseconds_sum{step_done="rpm-scanned"} 0.04808
sqlite3_milliseconds_sum{step_done="rpm-sdef-insert"} 0.122009
sqlite3_milliseconds_sum{step_done="rpm-sref-insert"} 0.239557
sqlite3_milliseconds_sum{step_done="wal checkpoint"} 0.375263
thread_busy{role="groom"} 0
thread_busy{role="http-buildid"} 0
thread_busy{role="http-buildid-after-you"} 0
thread_busy{role="http-metrics"} 1
thread_busy{role="scan"} 0
thread_busy{role="traverse"} 0
thread_count{role="groom"} 1
thread_count{role="scan"} 8
thread_count{role="traverse"} 1
thread_tid{role="groom"} 11591
thread_tid{role="traverse"} 11592
thread_work_pending{role="groom"} 0
thread_work_pending{role="scan"} 0
thread_work_total{role="groom"} 1
thread_work_total{role="scan"} 5
thread_work_total{role="traverse"} 1
traversed_total{type="directory"} 3
traversed_total{type="file"} 5
traversed_total{type="other"} 3'
+ regex='fdcache_prefetch_count ([0-9])+'
+ [[ fdcache_bytes 0
fdcache_count 0
fdcache_op_count{op="emerg-flush"} 3
fdcache_op_count{op="enqueue"} 1
fdcache_op_count{op="evict"} 1
fdcache_op_count{op="prefetch_enqueue"} 1
fdcache_op_count{op="prefetch_evict"} 1
fdcache_op_count{op="probe_miss"} 2
fdcache_prefetch_bytes 0
fdcache_prefetch_count 0
filesys_free_ratio{purpose="database"} 0.1539297218490474
filesys_free_ratio{purpose="tmpdir"} 0.08872804205341149
found_debuginfo_total{source=".tar.bz2 archive"} 1
found_executable_total{source=".tar.bz2 archive"} 0
found_sourcerefs_total{source=".tar.bz2 archive"} 9
groom{statistic="archive d/e"} 0
groom{statistic="archive sdef"} 0
groom{statistic="archive sref"} 0
groom{statistic="buildids"} 0
groom{statistic="file d/e"} 0
groom{statistic="file s"} 0
groom{statistic="filenames"} 0
groom{statistic="files scanned (#)"} 0
groom{statistic="files scanned (mb)"} 0
http_requests_total{type="debuginfo"} 1
http_requests_total{type="metrics"} 6
http_responses_after_you_milliseconds_count{code="200",type="debuginfo"} 1
http_responses_after_you_milliseconds_count{code="200",type="metrics"} 5
http_responses_after_you_milliseconds_sum{code="200",type="debuginfo"} 0.005788000000000001
http_responses_after_you_milliseconds_sum{code="200",type="metrics"} 0
http_responses_duration_milliseconds_count{code="200",type="debuginfo"} 1
http_responses_duration_milliseconds_count{code="200",type="metrics"} 5
http_responses_duration_milliseconds_sum{code="200",type="debuginfo"} 4.040639000000001
http_responses_duration_milliseconds_sum{code="200",type="metrics"} 0.288449
http_responses_total{result=".tar.bz2 archive"} 1
http_responses_transfer_bytes_count{code="200",type="debuginfo"} 1
http_responses_transfer_bytes_count{code="200",type="metrics"} 5
http_responses_transfer_bytes_sum{code="200",type="debuginfo"} 7736
http_responses_transfer_bytes_sum{code="200",type="metrics"} 15284
ready 1
scanned_bytes_total{source=".tar.bz2 archive"} 5814
scanned_files_total{source=".tar.bz2 archive"} 1
sqlite3_milliseconds_count{reset="check old files"} 2
sqlite3_milliseconds_count{reset="incremental vacuum"} 1
sqlite3_milliseconds_count{reset="mhd-query-d"} 1
sqlite3_milliseconds_count{reset="nuke orphan buildids"} 1
sqlite3_milliseconds_count{reset="optimize"} 1
sqlite3_milliseconds_count{reset="rpm-buildid-intern"} 1
sqlite3_milliseconds_count{reset="rpm-de-insert"} 1
sqlite3_milliseconds_count{reset="rpm-file-intern"} 15
sqlite3_milliseconds_count{reset="rpm-negativehit-query"} 2
sqlite3_milliseconds_count{reset="rpm-scanned"} 1
sqlite3_milliseconds_count{reset="rpm-sdef-insert"} 4
sqlite3_milliseconds_count{reset="rpm-sref-insert"} 9
sqlite3_milliseconds_count{reset="wal checkpoint"} 1
sqlite3_milliseconds_count{step="check old files"} 1
sqlite3_milliseconds_count{step="database-overview"} 10
sqlite3_milliseconds_count{step="mhd-query-d"} 1
sqlite3_milliseconds_count{step="rpm-negativehit-query"} 1
sqlite3_milliseconds_count{step_done="incremental vacuum"} 1
sqlite3_milliseconds_count{step_done="nuke orphan buildids"} 1
sqlite3_milliseconds_count{step_done="optimize"} 1
sqlite3_milliseconds_count{step_done="rpm-buildid-intern"} 1
sqlite3_milliseconds_count{step_done="rpm-de-insert"} 1
sqlite3_milliseconds_count{step_done="rpm-file-intern"} 15
sqlite3_milliseconds_count{step_done="rpm-scanned"} 1
sqlite3_milliseconds_count{step_done="rpm-sdef-insert"} 4
sqlite3_milliseconds_count{step_done="rpm-sref-insert"} 9
sqlite3_milliseconds_count{step_done="wal checkpoint"} 1
sqlite3_milliseconds_sum{reset="check old files"} 0.002276
sqlite3_milliseconds_sum{reset="incremental vacuum"} 0.000215
sqlite3_milliseconds_sum{reset="mhd-query-d"} 0.00046
sqlite3_milliseconds_sum{reset="nuke orphan buildids"} 0.000434
sqlite3_milliseconds_sum{reset="optimize"} 0.000164
sqlite3_milliseconds_sum{reset="rpm-buildid-intern"} 0.0008309999999999999
sqlite3_milliseconds_sum{reset="rpm-de-insert"} 0.000311
sqlite3_milliseconds_sum{reset="rpm-file-intern"} 0.009559000000000002
sqlite3_milliseconds_sum{reset="rpm-negativehit-query"} 0.002185
sqlite3_milliseconds_sum{reset="rpm-scanned"} 0.000673
sqlite3_milliseconds_sum{reset="rpm-sdef-insert"} 0.00251
sqlite3_milliseconds_sum{reset="rpm-sref-insert"} 0.003144000000000001
sqlite3_milliseconds_sum{reset="wal checkpoint"} 0.000687
sqlite3_milliseconds_sum{step="check old files"} 0.030437
sqlite3_milliseconds_sum{step="database-overview"} 0.051596
sqlite3_milliseconds_sum{step="mhd-query-d"} 0.035134
sqlite3_milliseconds_sum{step="rpm-negativehit-query"} 0.024304
sqlite3_milliseconds_sum{step_done="incremental vacuum"} 0.011465
sqlite3_milliseconds_sum{step_done="nuke orphan buildids"} 0.017668
sqlite3_milliseconds_sum{step_done="optimize"} 0.004877
sqlite3_milliseconds_sum{step_done="rpm-buildid-intern"} 0.040443
sqlite3_milliseconds_sum{step_done="rpm-de-insert"} 0.036597
sqlite3_milliseconds_sum{step_done="rpm-file-intern"} 0.557634
sqlite3_milliseconds_sum{step_done="rpm-scanned"} 0.04808
sqlite3_milliseconds_sum{step_done="rpm-sdef-insert"} 0.122009
sqlite3_milliseconds_sum{step_done="rpm-sref-insert"} 0.239557
sqlite3_milliseconds_sum{step_done="wal checkpoint"} 0.375263
thread_busy{role="groom"} 0
thread_busy{role="http-buildid"} 0
thread_busy{role="http-buildid-after-you"} 0
thread_busy{role="http-metrics"} 1
thread_busy{role="scan"} 0
thread_busy{role="traverse"} 0
thread_count{role="groom"} 1
thread_count{role="scan"} 8
thread_count{role="traverse"} 1
thread_tid{role="groom"} 11591
thread_tid{role="traverse"} 11592
thread_work_pending{role="groom"} 0
thread_work_pending{role="scan"} 0
thread_work_total{role="groom"} 1
thread_work_total{role="scan"} 5
thread_work_total{role="traverse"} 1
traversed_total{type="directory"} 3
traversed_total{type="file"} 5
traversed_total{type="other"} 3 =~ fdcache_prefetch_count ([0-9])+ ]]
+ [[ 0 -ne 1 ]]
+ err
+ trap - ERR
+ echo ERROR REPORTS
ERROR REPORTS
+ for port in '$PORT1' '$PORT2'
+ echo ERROR REPORT 8834 metrics
ERROR REPORT 8834 metrics
+ curl -s http://127.0.0.1:8834/metrics
fdcache_bytes 0
fdcache_count 0
fdcache_op_count{op="emerg-flush"} 3
fdcache_op_count{op="enqueue"} 1
fdcache_op_count{op="evict"} 1
fdcache_op_count{op="prefetch_enqueue"} 1
fdcache_op_count{op="prefetch_evict"} 1
fdcache_op_count{op="probe_miss"} 2
fdcache_prefetch_bytes 0
fdcache_prefetch_count 0
filesys_free_ratio{purpose="database"} 0.1539297218490474
filesys_free_ratio{purpose="tmpdir"} 0.08872804205341149
found_debuginfo_total{source=".tar.bz2 archive"} 1
found_executable_total{source=".tar.bz2 archive"} 0
found_sourcerefs_total{source=".tar.bz2 archive"} 9
groom{statistic="archive d/e"} 0
groom{statistic="archive sdef"} 0
groom{statistic="archive sref"} 0
groom{statistic="buildids"} 0
groom{statistic="file d/e"} 0
groom{statistic="file s"} 0
groom{statistic="filenames"} 0
groom{statistic="files scanned (#)"} 0
groom{statistic="files scanned (mb)"} 0
http_requests_total{type="debuginfo"} 1
http_requests_total{type="metrics"} 7
http_responses_after_you_milliseconds_count{code="200",type="debuginfo"} 1
http_responses_after_you_milliseconds_count{code="200",type="metrics"} 6
http_responses_after_you_milliseconds_sum{code="200",type="debuginfo"} 0.005788000000000001
http_responses_after_you_milliseconds_sum{code="200",type="metrics"} 0
http_responses_duration_milliseconds_count{code="200",type="debuginfo"} 1
http_responses_duration_milliseconds_count{code="200",type="metrics"} 6
http_responses_duration_milliseconds_sum{code="200",type="debuginfo"} 4.040639000000001
http_responses_duration_milliseconds_sum{code="200",type="metrics"} 0.358968
http_responses_total{result=".tar.bz2 archive"} 1
http_responses_transfer_bytes_count{code="200",type="debuginfo"} 1
http_responses_transfer_bytes_count{code="200",type="metrics"} 6
http_responses_transfer_bytes_sum{code="200",type="debuginfo"} 7736
http_responses_transfer_bytes_sum{code="200",type="metrics"} 21069
ready 1
scanned_bytes_total{source=".tar.bz2 archive"} 5814
scanned_files_total{source=".tar.bz2 archive"} 1
sqlite3_milliseconds_count{reset="check old files"} 2
sqlite3_milliseconds_count{reset="incremental vacuum"} 1
sqlite3_milliseconds_count{reset="mhd-query-d"} 1
sqlite3_milliseconds_count{reset="nuke orphan buildids"} 1
sqlite3_milliseconds_count{reset="optimize"} 1
sqlite3_milliseconds_count{reset="rpm-buildid-intern"} 1
sqlite3_milliseconds_count{reset="rpm-de-insert"} 1
sqlite3_milliseconds_count{reset="rpm-file-intern"} 15
sqlite3_milliseconds_count{reset="rpm-negativehit-query"} 2
sqlite3_milliseconds_count{reset="rpm-scanned"} 1
sqlite3_milliseconds_count{reset="rpm-sdef-insert"} 4
sqlite3_milliseconds_count{reset="rpm-sref-insert"} 9
sqlite3_milliseconds_count{reset="wal checkpoint"} 1
sqlite3_milliseconds_count{step="check old files"} 1
sqlite3_milliseconds_count{step="database-overview"} 10
sqlite3_milliseconds_count{step="mhd-query-d"} 1
sqlite3_milliseconds_count{step="rpm-negativehit-query"} 1
sqlite3_milliseconds_count{step_done="incremental vacuum"} 1
sqlite3_milliseconds_count{step_done="nuke orphan buildids"} 1
sqlite3_milliseconds_count{step_done="optimize"} 1
sqlite3_milliseconds_count{step_done="rpm-buildid-intern"} 1
sqlite3_milliseconds_count{step_done="rpm-de-insert"} 1
sqlite3_milliseconds_count{step_done="rpm-file-intern"} 15
sqlite3_milliseconds_count{step_done="rpm-scanned"} 1
sqlite3_milliseconds_count{step_done="rpm-sdef-insert"} 4
sqlite3_milliseconds_count{step_done="rpm-sref-insert"} 9
sqlite3_milliseconds_count{step_done="wal checkpoint"} 1
sqlite3_milliseconds_sum{reset="check old files"} 0.002276
sqlite3_milliseconds_sum{reset="incremental vacuum"} 0.000215
sqlite3_milliseconds_sum{reset="mhd-query-d"} 0.00046
sqlite3_milliseconds_sum{reset="nuke orphan buildids"} 0.000434
sqlite3_milliseconds_sum{reset="optimize"} 0.000164
sqlite3_milliseconds_sum{reset="rpm-buildid-intern"} 0.0008309999999999999
sqlite3_milliseconds_sum{reset="rpm-de-insert"} 0.000311
sqlite3_milliseconds_sum{reset="rpm-file-intern"} 0.009559000000000002
sqlite3_milliseconds_sum{reset="rpm-negativehit-query"} 0.002185
sqlite3_milliseconds_sum{reset="rpm-scanned"} 0.000673
sqlite3_milliseconds_sum{reset="rpm-sdef-insert"} 0.00251
sqlite3_milliseconds_sum{reset="rpm-sref-insert"} 0.003144000000000001
sqlite3_milliseconds_sum{reset="wal checkpoint"} 0.000687
sqlite3_milliseconds_sum{step="check old files"} 0.030437
sqlite3_milliseconds_sum{step="database-overview"} 0.051596
sqlite3_milliseconds_sum{step="mhd-query-d"} 0.035134
sqlite3_milliseconds_sum{step="rpm-negativehit-query"} 0.024304
sqlite3_milliseconds_sum{step_done="incremental vacuum"} 0.011465
sqlite3_milliseconds_sum{step_done="nuke orphan buildids"} 0.017668
sqlite3_milliseconds_sum{step_done="optimize"} 0.004877
sqlite3_milliseconds_sum{step_done="rpm-buildid-intern"} 0.040443
sqlite3_milliseconds_sum{step_done="rpm-de-insert"} 0.036597
sqlite3_milliseconds_sum{step_done="rpm-file-intern"} 0.557634
sqlite3_milliseconds_sum{step_done="rpm-scanned"} 0.04808
sqlite3_milliseconds_sum{step_done="rpm-sdef-insert"} 0.122009
sqlite3_milliseconds_sum{step_done="rpm-sref-insert"} 0.239557
sqlite3_milliseconds_sum{step_done="wal checkpoint"} 0.375263
thread_busy{role="groom"} 0
thread_busy{role="http-buildid"} 0
thread_busy{role="http-buildid-after-you"} 0
thread_busy{role="http-metrics"} 1
thread_busy{role="scan"} 0
thread_busy{role="traverse"} 0
thread_count{role="groom"} 1
thread_count{role="scan"} 8
thread_count{role="traverse"} 1
thread_tid{role="groom"} 11591
thread_tid{role="traverse"} 11592
thread_work_pending{role="groom"} 0
thread_work_pending{role="scan"} 0
thread_work_total{role="groom"} 1
thread_work_total{role="scan"} 5
thread_work_total{role="traverse"} 1
traversed_total{type="directory"} 3
traversed_total{type="file"} 5
traversed_total{type="other"} 3
+ echo
+ for port in '$PORT1' '$PORT2'
+ echo ERROR REPORT 8874 metrics
ERROR REPORT 8874 metrics
+ curl -s http://127.0.0.1:8874/metrics
+ :
+ echo
+ for x in '$errfiles_list'
+ echo ERROR REPORT vlog8834
ERROR REPORT vlog8834
+ cat vlog8834
[Fri Jun 3 14:58:29 2022] (11584/11584): fdcache limited to maxfds=1 maxmbs=100
[Fri Jun 3 14:58:29 2022] (11584/11584): opened database /home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite rw ro
[Fri Jun 3 14:58:29 2022] (11584/11584): sqlite version 3.7.17
[Fri Jun 3 14:58:29 2022] (11584/11584): service mode active
[Fri Jun 3 14:58:29 2022] (11584/11584): ddl: pragma foreign_keys = on;
pragma synchronous = 0;
pragma journal_mode = wal;
pragma wal_checkpoint = truncate;
pragma journal_size_limit = 0;
pragma auto_vacuum = incremental;
pragma busy_timeout = 1000;
create table if not exists buildids9_files (
id integer primary key not null,
name text unique not null
);
create table if not exists buildids9_buildids (
id integer primary key not null,
hex text unique not null);
create table if not exists buildids9_file_mtime_scanned (
mtime integer not null,
file integer not null,
size integer not null,
sourcetype text(1) not null
check (sourcetype IN ('F', 'R')),
foreign key (file) references buildids9_files(id) on update cascade on delete cascade,
primary key (file, mtime, sourcetype)
) ;
create table if not exists buildids9_f_de (
buildid integer not null,
debuginfo_p integer not null,
executable_p integer not null,
file integer not null,
mtime integer not null,
foreign key (file) references buildids9_files(id) on update cascade on delete cascade,
foreign key (buildid) references buildids9_buildids(id) on update cascade on delete cascade,
primary key (buildid, file, mtime)
) ;
create table if not exists buildids9_f_s (
buildid integer not null,
artifactsrc integer not null,
file integer not null,
mtime integer not null,
foreign key (file) references buildids9_files(id) on update cascade on delete cascade,
foreign key (artifactsrc) references buildids9_files(id) on update cascade on delete cascade,
foreign key (buildid) references buildids9_buildids(id) on update cascade on delete cascade,
primary key (buildid, artifactsrc, file, mtime)
) ;
create table if not exists buildids9_r_de (
buildid integer not null,
debuginfo_p integer not null,
executable_p integer not null,
file integer not null,
mtime integer not null,
content integer not null,
foreign key (file) references buildids9_files(id) on update cascade on delete cascade,
foreign key (content) references buildids9_files(id) on update cascade on delete cascade,
foreign key (buildid) references buildids9_buildids(id) on update cascade on delete cascade,
primary key (buildid, debuginfo_p, executable_p, file, content, mtime)
) ;
create table if not exists buildids9_r_sref (
buildid integer not null,
artifactsrc integer not null,
foreign key (artifactsrc) references buildids9_files(id) on update cascade on delete cascade,
foreign key (buildid) references buildids9_buildids(id) on update cascade on delete cascade,
primary key (buildid, artifactsrc)
) ;
create table if not exists buildids9_r_sdef (
file integer not null,
mtime integer not null,
content integer not null,
foreign key (file) references buildids9_files(id) on update cascade on delete cascade,
foreign key (content) references buildids9_files(id) on update cascade on delete cascade,
primary key (content, file, mtime)
) ;
create view if not exists buildids9_query_d as
select
b.hex as buildid, n.mtime, 'F' as sourcetype, f0.name as source0, n.mtime as mtime, null as source1
from buildids9_buildids b, buildids9_files f0, buildids9_f_de n
where b.id = n.buildid and f0.id = n.file and n.debuginfo_p = 1
union all select
b.hex as buildid, n.mtime, 'R' as sourcetype, f0.name as source0, n.mtime as mtime, f1.name as source1
from buildids9_buildids b, buildids9_files f0, buildids9_files f1, buildids9_r_de n
where b.id = n.buildid and f0.id = n.file and f1.id = n.content and n.debuginfo_p = 1
;create view if not exists buildids9_query_e as
select
b.hex as buildid, n.mtime, 'F' as sourcetype, f0.name as source0, n.mtime as mtime, null as source1
from buildids9_buildids b, buildids9_files f0, buildids9_f_de n
where b.id = n.buildid and f0.id = n.file and n.executable_p = 1
union all select
b.hex as buildid, n.mtime, 'R' as sourcetype, f0.name as source0, n.mtime as mtime, f1.name as source1
from buildids9_buildids b, buildids9_files f0, buildids9_files f1, buildids9_r_de n
where b.id = n.buildid and f0.id = n.file and f1.id = n.content and n.executable_p = 1
;create view if not exists buildids9_query_s as
select
b.hex as buildid, fs.name as artifactsrc, 'F' as sourcetype, f0.name as source0, n.mtime as mtime, null as source1, null as source0ref
from buildids9_buildids b, buildids9_files f0, buildids9_files fs, buildids9_f_s n
where b.id = n.buildid and f0.id = n.file and fs.id = n.artifactsrc
union all select
b.hex as buildid, f1.name as artifactsrc, 'R' as sourcetype, f0.name as source0, sd.mtime as mtime, f1.name as source1, fsref.name as source0ref
from buildids9_buildids b, buildids9_files f0, buildids9_files f1, buildids9_files fsref, buildids9_r_sdef sd, buildids9_r_sref sr, buildids9_r_de sde
where b.id = sr.buildid and f0.id = sd.file and fsref.id = sde.file and f1.id = sd.content
and sr.artifactsrc = sd.content and sde.buildid = sr.buildid
;drop view if exists buildids9_stats;
create view if not exists buildids9_stats as
select 'file d/e' as label,count(*) as quantity from buildids9_f_de
union all select 'file s',count(*) from buildids9_f_s
union all select 'archive d/e',count(*) from buildids9_r_de
union all select 'archive sref',count(*) from buildids9_r_sref
union all select 'archive sdef',count(*) from buildids9_r_sdef
union all select 'buildids',count(*) from buildids9_buildids
union all select 'filenames',count(*) from buildids9_files
union all select 'files scanned (#)',count(*) from buildids9_file_mtime_scanned
union all select 'files scanned (mb)',coalesce(sum(size)/1024/1024,0) from buildids9_file_mtime_scanned
;
drop table if exists buildids8_f_de;
drop table if exists buildids8_f_s;
drop table if exists buildids8_r_de;
drop table if exists buildids8_r_sref;
drop table if exists buildids8_r_sdef;
drop table if exists buildids8_file_mtime_scanned;
drop table if exists buildids8_files;
drop table if exists buildids8_buildids;
drop table if exists buildids7_f_de;
drop table if exists buildids7_f_s;
drop table if exists buildids7_r_de;
drop table if exists buildids7_r_sref;
drop table if exists buildids7_r_sdef;
drop table if exists buildids7_file_mtime_scanned;
drop table if exists buildids7_files;
drop table if exists buildids7_buildids;
drop table if exists buildids6_norm;
drop table if exists buildids6_files;
drop table if exists buildids6_buildids;
drop view if exists buildids6;
drop table if exists buildids5_norm;
drop table if exists buildids5_files;
drop table if exists buildids5_buildids;
drop table if exists buildids5_bolo;
drop table if exists buildids5_rfolo;
drop view if exists buildids5;
drop table if exists buildids4_norm;
drop table if exists buildids4_files;
drop table if exists buildids4_buildids;
drop table if exists buildids4_bolo;
drop table if exists buildids4_rfolo;
drop view if exists buildids4;
drop table if exists buildids3_norm;
drop table if exists buildids3_files;
drop table if exists buildids3_buildids;
drop table if exists buildids3_bolo;
drop view if exists buildids3;
drop table if exists buildids2_norm;
drop table if exists buildids2_files;
drop table if exists buildids2_buildids;
drop view if exists buildids2;
drop table if exists buildids1;
drop table if exists buildids;
[Fri Jun 3 14:58:29 2022] (11584/11584): started http server on IPv4 IPv6 port=8834
[Fri Jun 3 14:58:29 2022] (11584/11584): search concurrency 8
[Fri Jun 3 14:58:29 2022] (11584/11584): webapi connection pool 0 (unlimited)
[Fri Jun 3 14:58:29 2022] (11584/11584): rescan time 0
[Fri Jun 3 14:58:29 2022] (11584/11584): fdcache fds 1
[Fri Jun 3 14:58:29 2022] (11584/11584): fdcache mbs 100
[Fri Jun 3 14:58:29 2022] (11584/11584): fdcache prefetch 2
[Fri Jun 3 14:58:29 2022] (11584/11584): fdcache tmpdir /tmp
[Fri Jun 3 14:58:29 2022] (11584/11584): fdcache tmpdir min% 25
[Fri Jun 3 14:58:29 2022] (11584/11584): groom time 0
[Fri Jun 3 14:58:29 2022] (11584/11584): prefetch fds 1
[Fri Jun 3 14:58:29 2022] (11584/11584): prefetch mbs 100
[Fri Jun 3 14:58:29 2022] (11584/11584): forwarded ttl limit 8
[Fri Jun 3 14:58:29 2022] (11584/11584): accepting archive types .tar.bz2(bzcat)
[Fri Jun 3 14:58:29 2022] (11584/11593): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11593): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11593): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11593): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11593): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11598): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11598): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): file-buildids-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11593): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11598): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): file-files-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11598): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11593): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11595): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11598): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11600): file-de-upsert prep insert or ignore into buildids9_f_de (buildid, debuginfo_p, executable_p, file, mtime) values ((select id from buildids9_buildids where hex = ?), ?,?, (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11594): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11593): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11599): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11596): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11598): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): file-s-upsert prep insert or ignore into buildids9_f_s (buildid, artifactsrc, file, mtime) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?), (select id from buildids9_files where name = ?), ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11597): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11597): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11597): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11599): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11599): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11595): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11598): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): file-negativehit-find prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'F' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11600): file-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('F', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11600): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11597): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11599): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11599): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11599): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11598): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11596): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11600): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11597): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11595): rpm-buildid-intern prep insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11598): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11594): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11598): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11598): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11598): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11600): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11597): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): rpm-file-intern prep insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:29 2022] (11584/11593): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11594): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11596): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11598): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11600): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): rpm-de-insert prep insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11593): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11594): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11596): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11595): rpm-sref-insert prep insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11593): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11594): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11594): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): rpm-sdef-insert prep insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:29 2022] (11584/11595): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11593): rpm-negativehit-query prep select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:29 2022] (11584/11593): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11595): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:29 2022] (11584/11596): rpm-scanned prep insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:30 2022] (11584/11605): 127.0.0.1:43694 UA:curl/7.29.0 XFF: GET /metrics 200 344 0+0ms
[Fri Jun 3 14:58:30 2022] (11584/11610): 127.0.0.1:43696 UA:curl/7.29.0 XFF: GET /metrics 200 767 0+0ms
[Fri Jun 3 14:58:30 2022] (11584/11591): grooming database
[Fri Jun 3 14:58:30 2022] (11584/11591): check old files prep select distinct s.mtime, s.file, f.name from buildids9_file_mtime_scanned s, buildids9_files f where f.id = s.file
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars/hello-1-1-x86_64.pkg.tar.xz
[Fri Jun 3 14:58:30 2022] (11584/11591): check old files step(unknown error) select distinct s.mtime, s.file, f.name from buildids9_file_mtime_scanned s, buildids9_files f where f.id = s.file
[Fri Jun 3 14:58:30 2022] (11584/11591): nuke f_de prep delete from buildids9_f_de where file = ? and mtime = ?
[Fri Jun 3 14:58:30 2022] (11584/11591): nuke r_de prep delete from buildids9_r_de where file = ? and mtime = ?
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars/pacman-sources
[Fri Jun 3 14:58:30 2022] (11584/11591): nuke f_m_s prep delete from buildids9_file_mtime_scanned where file = ? and mtime = ?
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars/pacman-sources/PKGBUILD
[Fri Jun 3 14:58:30 2022] (11584/11591): nuke orphan buildids prep delete from buildids9_buildids where not exists (select 1 from buildids9_f_de d where buildids9_buildids.id = d.buildid) and not exists (select 1 from buildids9_r_de d where buildids9_buildids.id = d.buildid)
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars/pacman-sources/README.md
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars/pacman-sources/hello.c
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars/pacman-sources
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z/debuginfod-tars
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversing Z
[Fri Jun 3 14:58:30 2022] (11584/11592): fts traversed source paths in 0.000247999s, scanned=11, regex-skipped=0
[Fri Jun 3 14:58:30 2022] (11584/11591): nuke orphan buildids step-ok-done(unknown error) delete from buildids9_buildids where not exists (select 1 from buildids9_f_de d where buildids9_buildids.id = d.buildid) and not exists (select 1 from buildids9_r_de d where buildids9_buildids.id = d.buildid)
[Fri Jun 3 14:58:30 2022] (11584/11591): incremental vacuum prep pragma incremental_vacuum
[Fri Jun 3 14:58:30 2022] (11584/11591): incremental vacuum step-ok-done(unknown error) pragma incremental_vacuum
[Fri Jun 3 14:58:30 2022] (11584/11591): optimize prep pragma optimize
[Fri Jun 3 14:58:30 2022] (11584/11591): optimize step-ok-done(unknown error) pragma optimize
[Fri Jun 3 14:58:30 2022] (11584/11591): wal checkpoint prep pragma wal_checkpoint=truncate
[Fri Jun 3 14:58:30 2022] (11584/11591): wal checkpoint step-ok-done(unknown error) pragma wal_checkpoint=truncate
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview prep select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): database record counts:
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): file d/e 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): file s 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): archive d/e 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): archive sref 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): archive sdef 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): buildids 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): filenames 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): files scanned (#) 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): files scanned (mb) 0
[Fri Jun 3 14:58:30 2022] (11584/11591): database-overview step(unknown error) select label,quantity from buildids9_stats
[Fri Jun 3 14:58:30 2022] (11584/11591): fdcache limited to maxfds=0 maxmbs=0
[Fri Jun 3 14:58:30 2022] (11584/11591): fdcache limited to maxfds=1 maxmbs=100
[Fri Jun 3 14:58:30 2022] (11584/11591): groomed database in 0.000990294s
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-negativehit-query bind 1=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-negativehit-query bind 2=1646139216
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-negativehit-query step(unknown error) select 1 from buildids9_file_mtime_scanned where sourcetype = 'R' and file = (select id from buildids9_files where name = ?) and mtime = ?;
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): libarchive scanning /opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): libarchive checking BUILDINFO
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=BUILDINFO
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 1=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 2=1646139216
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 3=BUILDINFO
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): libarchive checking MTREE
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=MTREE
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 1=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 2=1646139216
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 3=MTREE
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): libarchive checking PKGINFO
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=PKGINFO
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 1=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 2=1646139216
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 3=PKGINFO
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): libarchive checking /usr/lib/debug/usr/bin/hello.debug
[Fri Jun 3 14:58:30 2022] (11584/11599): searching for sources for cu=hello.c comp_dir=/usr/src/debug #files=10 #dirs=5
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/src/debug/hello.c new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/include/bits/stdio2.h new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/lib/gcc/x86_64-pc-linux-gnu/9.2.0/include/stddef.h new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/include/bits/types.h new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/include/bits/types/struct_FILE.h new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/include/bits/types/FILE.h new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/include/stdio.h new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/include/bits/sys_errlist.h new
[Fri Jun 3 14:58:30 2022] (11584/11599): /usr/src/debug/<built-in> new
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-buildid-intern bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-buildid-intern step-ok-done(unknown error) insert or ignore into buildids9_buildids VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/lib/debug/usr/bin/hello.debug
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/include/bits/stdio2.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/include/bits/stdio2.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/include/bits/sys_errlist.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/include/bits/sys_errlist.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/include/bits/types.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/include/bits/types.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/include/bits/types/FILE.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/include/bits/types/FILE.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/include/bits/types/struct_FILE.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/include/bits/types/struct_FILE.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/include/stdio.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/include/stdio.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/lib/gcc/x86_64-pc-linux-gnu/9.2.0/include/stddef.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/lib/gcc/x86_64-pc-linux-gnu/9.2.0/include/stddef.h
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/src/debug/<built-in>
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/src/debug/<built-in>
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/src/debug/hello.c
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert bind 2=/usr/src/debug/hello.c
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sref-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sref (buildid, artifactsrc) values ((select id from buildids9_buildids where hex = ?), (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-de-insert bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-de-insert bind 2=1
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-de-insert bind 3=0
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-de-insert bind 4=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-de-insert bind 5=1646139216
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-de-insert bind 6=/usr/lib/debug/usr/bin/hello.debug
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-de-insert step-ok-done(unknown error) insert or ignore into buildids9_r_de (buildid, debuginfo_p, executable_p, file, mtime, content) values ((select id from buildids9_buildids where hex = ?), ?, ?, (select id from buildids9_files where name = ?), ?, (select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): recorded buildid=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb rpm=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 file=/usr/lib/debug/usr/bin/hello.debug mtime=1646139216 atype=D sourcefiles=9
[Fri Jun 3 14:58:30 2022] (11584/11599): libarchive checking /usr/src/debug/hello.c
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern bind 1=/usr/src/debug/hello.c
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-file-intern step-ok-done(unknown error) insert or ignore into buildids9_files VALUES (NULL, ?);
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 1=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 2=1646139216
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert bind 3=/usr/src/debug/hello.c
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-sdef-insert step-ok-done(unknown error) insert or ignore into buildids9_r_sdef (file, mtime, content) values ((select id from buildids9_files where name = ?), ?,(select id from buildids9_files where name = ?));
[Fri Jun 3 14:58:30 2022] (11584/11599): scanned archive=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 mtime=1646139216 executables=0 debuginfos=1 srefs=9 sdefs=4
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-scanned bind 1=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-scanned bind 2=1646139216
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-scanned bind 3=5814
[Fri Jun 3 14:58:30 2022] (11584/11599): rpm-scanned step-ok-done(unknown error) insert or ignore into buildids9_file_mtime_scanned (sourcetype, file, mtime, size)values ('R', (select id from buildids9_files where name = ?), ?, ?);
[Fri Jun 3 14:58:30 2022] (11584/11618): 127.0.0.1:43698 UA:curl/7.29.0 XFF: GET /metrics 200 4724 0+0ms
[Fri Jun 3 14:58:30 2022] (11584/11623): 127.0.0.1:43700 UA:curl/7.29.0 XFF: GET /metrics 200 4724 0+0ms
[Fri Jun 3 14:58:30 2022] (11584/11628): 127.0.0.1:43702 UA:curl/7.29.0 XFF: GET /metrics 200 4725 0+0ms
[Fri Jun 3 14:58:30 2022] (11584/11630): searching for buildid=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb artifacttype=debuginfo suffix=
[Fri Jun 3 14:58:30 2022] (11584/11630): mhd-query-d prep select mtime, sourcetype, source0, source1 from buildids9_query_d where buildid = ? order by mtime desc
[Fri Jun 3 14:58:30 2022] (11584/11630): mhd-query-d bind 1=cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb
[Fri Jun 3 14:58:30 2022] (11584/11630): mhd-query-d step(unknown error) select mtime, sourcetype, source0, source1 from buildids9_query_d where buildid = ? order by mtime desc
[Fri Jun 3 14:58:30 2022] (11584/11630): found mtime=1646139216 stype=R source0=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 source1=/usr/lib/debug/usr/bin/hello.debug
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache emergency flush for filling tmpdir
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache limited to maxfds=0 maxmbs=0
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache interned a=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 b=/usr/lib/debug/usr/bin/hello.debug fd=/tmp/debuginfod.xsYIWV mb=0.0698767 front=1
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache emergency flush for filling tmpdir
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache evicted a=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 b=/usr/lib/debug/usr/bin/hello.debug fd=/tmp/debuginfod.xsYIWV mb=0.0698767
[Fri Jun 3 14:58:30 2022] (11584/11630): serving archive /opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 file /usr/lib/debug/usr/bin/hello.debug
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache interned a=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 b=/usr/src/debug/hello.c fd=/tmp/debuginfod.oghAyX mb=0.0625677 front=0
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache emergency flush for filling tmpdir
[Fri Jun 3 14:58:30 2022] (11584/11630): fdcache evicted from prefetch a=/opt/local/build/elfutils-obj/tests/test-11559/Z/debuginfod-tars/hello-debug-1-1-x86_64.pkg.tar.bz2 b=/usr/src/debug/hello.c fd=/tmp/debuginfod.oghAyX mb=0.0625677
[Fri Jun 3 14:58:30 2022] (11584/11630): 127.0.0.1:43704 UA:elfutils/0.187,Linux/x86_64,rhel/7.9 XFF: GET /buildid/cee13b2ea505a7f37bd20d271c6bc7e5f8d2dfcb/debuginfo 200 7736 0+4ms
[Fri Jun 3 14:58:30 2022] (11584/11633): 127.0.0.1:43706 UA:curl/7.29.0 XFF: GET /metrics 200 5785 0+0ms
[Fri Jun 3 14:58:30 2022] (11584/11635): 127.0.0.1:43708 UA:curl/7.29.0 XFF: GET /metrics 200 5785 0+0ms
+ echo
+ cleanup
+ trap - 0
+ '[' 11584 -ne 0 ']'
+ kill 11584
+ wait 11584
+ '[' 0 -ne 0 ']'
+ rm -rf F R D L Z /home/mark/build/elfutils-obj/tests/test-11559/foobar /home/mark/build/elfutils-obj/tests/test-11559/mocktree /home/mark/build/elfutils-obj/tests/test-11559/.client_cache '/home/mark/build/elfutils-obj/tests/test-11559/tmp*'
+ exit_cleanup
+ rm -f /home/mark/build/elfutils-obj/tests/test-11559/.debuginfod_tmp.sqlite vlog8834
+ cd ..
+ rmdir test-11559
+ false
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something
2022-06-03 15:02 ` Mark Wielaard
@ 2022-06-03 16:22 ` Mark Wielaard
0 siblings, 0 replies; 6+ messages in thread
From: Mark Wielaard @ 2022-06-03 16:22 UTC (permalink / raw)
To: Noah Sanci; +Cc: elfutils-devel
Hi,
On Fri, 2022-06-03 at 17:02 +0200, Mark Wielaard wrote:
> On Fri, 2022-06-03 at 10:51 -0400, Noah Sanci wrote:
> > Nothing immediately jumps out, would you mind sending the entire
> > log?
>
> Attached.
And Noah figured it out. The machine where it failed has /tmp 92% full
and the default mintmp is 25%. Which triggers an fdcache emergency
flush. So with this it PASSes everywhere:
diff --git a/tests/run-debuginfod-fd-prefetch-caches.sh b/tests/run-debuginfod-fd-prefetch-caches.sh
index 8778d3a2..a538cd48 100755
--- a/tests/run-debuginfod-fd-prefetch-caches.sh
+++ b/tests/run-debuginfod-fd-prefetch-caches.sh
@@ -50,10 +50,12 @@ export DEBUGINFOD_CACHE_PATH=${PWD}/.client_cache
rm -rf $DEBUGINFOD_CACHE_PATH
rm -rf $DB
# Testing prefetch fd maximum (Set mb maximums to be beyond consideration)
+# Set --fdcache-mintmp=0 so we don't accidentially trigger an fdcache
+# emergency flush for filling tmpdir
env LD_LIBRARY_PATH=$ldpath DEBUGINFOD_URLS= ${abs_builddir}/../debuginfod/debuginfod $VERBOSE -p $PORT1 -d $DB \
--fdcache-fds=$FDCACHE_FDS --fdcache-prefetch-fds=$PREFETCH_FDS -vvvvv -g 0 -t 0 \
-Z .tar.bz2=bzcat Z --fdcache-mbs=100 --fdcache-prefetch-mbs=100 \
- --fdcache-prefetch=$PREFETCH > vlog$PORT1 2>&1 &
+ --fdcache-mintmp=0 --fdcache-prefetch=$PREFETCH > vlog$PORT1 2>&1 &
PID1=$!
tempfiles vlog$PORT1
errfiles vlog$PORT1
Pushed with that change.
Thanks,
Mark
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2022-06-03 16:22 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-05-25 18:44 [Bug debuginfod/28577] Make run-...-fd-prefetch-caches.sh test something Noah Sanci
2022-05-27 16:20 ` Mark Wielaard
[not found] ` <CAJXA7qiYfeEpr5pHY5xPWcmnMoA1csnBvDnAHBoTubTVyBz+4g@mail.gmail.com>
2022-05-30 15:36 ` Mark Wielaard
2022-06-03 14:49 ` Mark Wielaard
[not found] ` <CAJXA7qjnhkwRaMWv2C7xnG+ruWFVsPgrvufDG94NUQe2Z067nA@mail.gmail.com>
2022-06-03 15:02 ` Mark Wielaard
2022-06-03 16:22 ` Mark Wielaard
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).