☠ Buildbot (Wildebeest Builder): elfutils - failed test (failure) (master)

☠ Buildbot (Wildebeest Builder): elfutils - failed test (failure) (master)

[buildbot]

A new failure has been detected on builder elfutils-centos-x86_64 while building elfutils.

Full details are available at:
    https://builder.wildebeest.org/buildbot/#builders/1/builds/932

Build state: failed test (failure)
Revision: 399b55a75830f1854c8da9f29282810e82f270b6
Worker: centos-x86_64
Build Reason: (unknown)
Blamelist: Mark Wielaard <mark@klomp.org>

Steps:

- 0: worker_preparation ( success )

- 1: set package name ( success )

- 2: git checkout ( success )
    Logs:
        - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/2/logs/stdio

- 3: autoreconf ( success )
    Logs:
        - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/3/logs/stdio

- 4: configure ( success )
    Logs:
        - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/4/logs/stdio

- 5: get version ( success )
    Logs:
        - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/5/logs/stdio
        - property changes: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/5/logs/property_changes

- 6: shell ( success )
    Logs:
        - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/6/logs/stdio

- 7: make ( warnings )
    Logs:
        - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/7/logs/stdio
        - warnings (2): https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/7/logs/warnings__2_

- 8: make check ( failure )
    Logs:
        - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/8/logs/stdio
        - test-suite.log: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/8/logs/test-suite_log

Re: ☠ Buildbot (Wildebeest Builder): elfutils - failed test (failure) (master)

[Mark Wielaard]

Hi,

On Wed, Apr 13, 2022 at 05:21:03PM +0000, buildbot@builder.wildebeest.org wrote:
> A new failure has been detected on builder elfutils-centos-x86_64 while building elfutils.
> 
> Full details are available at:
>     https://builder.wildebeest.org/buildbot/#builders/1/builds/932
> 
> Build state: failed test (failure)
> Revision: 399b55a75830f1854c8da9f29282810e82f270b6
> Worker: centos-x86_64
> Build Reason: (unknown)
> Blamelist: Mark Wielaard <mark@klomp.org>
> 
> Steps:
> [...] 
> - 8: make check ( failure )
>     Logs:
>         - stdio: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/8/logs/stdio
>         - test-suite.log: https://builder.wildebeest.org/buildbot/#builders/1/builds/932/steps/8/logs/test-suite_log

Hmmm, this seems a little random. The change was just adding some
(unused) constants to dwarf.h. The log says:

command timed out: 1200 seconds without output running ['make', 'check', '-j4'], attempting to kill
process killed by signal 9
program finished with exit code -1
elapsedTime=1925.591587

It looks like run-debuginfod-federation-sqlite.sh is missing.

Looking at the buildbot worker the end of run-debuginfod-federation-sqlite.sh.log is:

+ mvalue=2
+ '[' -z 2 ']'
+ echo 'metric thread_work_total{role="groom"}: 2'
metric thread_work_total{role="groom"}: 2
+ '[' 2 -eq 2 ']'
+ break
+ '[' 18 -eq 0 ']'
+ curl -s http://127.0.0.1:9112/buildid/beefbeefbeefd00dd00d/debuginfo
+ curl -s http://127.0.0.1:9112/metrics
+ grep 'error_count.*sqlite'
error_count{sqlite3="database disk image is malformed"} 6
error_count{sqlite3="file is encrypted or is not a database"} 1
+ kill -INT 28184 28371
+ wait 28184 28371

Which seems to correspond to this part in run-debuginfod-federation-sqlite.sh

########################################################################
# Corrupt the sqlite database and get debuginfod to trip across its errors
curl -s http://127.0.0.1:$PORT1/metrics | grep 'sqlite3.*reset'
dd if=/dev/zero of=$DB bs=1 count=1

# trigger some random activity that's Sure to get sqlite3 upset
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
kill -USR2 $PID1
wait_ready $PORT1 'thread_work_total{role="groom"}' 2
curl -s http://127.0.0.1:$PORT1/buildid/beefbeefbeefd00dd00d/debuginfo > /dev/null || true
curl -s http://127.0.0.1:$PORT1/metrics | grep 'error_count.*sqlite'
# Run the tests again without the servers running. The target file should
# be found in the cache.

kill -INT $PID1 $PID2
wait $PID1 $PID2

So maybe corruptin the sqlite database prevents a proper shutdown of
the debuginfod process?

Cheers,

Mark

Re: ☠ Buildbot (Wildebeest Builder): elfutils - failed test (failure) (master)

[Frank Ch. Eigler]

Hi -

> So maybe corruptin the sqlite database prevents a proper shutdown of
> the debuginfod process?

Yeah, that test is a bit blunt and unpredictable.  (We're literally
overwriting a piece of the database file that the process has open and
has random parts in cache.)  I'm thinking this is not worth testing.

- FChE

Re: ☠ Buildbot (Wildebeest Builder): elfutils - failed test (failure) (master)

[Mark Wielaard]

[-- Attachment #1: Type: text/plain, Size: 446 bytes --]

Hi Frank,

On Wed, 2022-04-13 at 15:09 -0400, Frank Ch. Eigler wrote:
> > So maybe corruptin the sqlite database prevents a proper shutdown
> > of the debuginfod process?
> 
> Yeah, that test is a bit blunt and unpredictable.  (We're literally
> overwriting a piece of the database file that the process has open and
> has random parts in cache.)  I'm thinking this is not worth testing.

Does the attached look OK?

Thanks,

Mark

[-- Attachment #2: 0001-tests-Don-t-try-to-corrupt-sqlite-database-during-te.patch --]
[-- Type: text/x-patch, Size: 2973 bytes --]

From 46e4d78de4a51b6e7ea2a2dba150ac9599c29c2f Mon Sep 17 00:00:00 2001
From: Mark Wielaard <mark@klomp.org>
Date: Thu, 14 Apr 2022 13:26:57 +0200
Subject: [PATCH] tests: Don't try to corrupt sqlite database during test.

In run-debuginfod-federation-sqlite.sh we used to try to corrupt
the sqlite database while the debuginfod server was running and
check it detected errors, but that was unreliably and slightly
dangerous since part of the database was already mapped into memory.
Instead trigger some some random activity, then trigger a shutdown.

Signed-off-by: Mark Wielaard <mark@klomp.org>
---
 tests/ChangeLog                           |  5 +++++
 tests/run-debuginfod-federation-sqlite.sh | 17 +++++++++--------
 2 files changed, 14 insertions(+), 8 deletions(-)

diff --git a/tests/ChangeLog b/tests/ChangeLog
index 6cb0d649..e49bff05 100644
--- a/tests/ChangeLog
+++ b/tests/ChangeLog
@@ -1,3 +1,8 @@
+2022-04-14  Mark Wielaard  <mark@klomp.org>
+
+	* run-debuginfod-federation-sqlite.sh: Don't try to corrupt
+	sqlite database.
+
 2022-04-13  Aaron Merey  <amerey@redhat.com>
 
 	* Makefile.am (TESTS): Remove run-debuginfod-000-permission.sh
diff --git a/tests/run-debuginfod-federation-sqlite.sh b/tests/run-debuginfod-federation-sqlite.sh
index bb3cda12..d9321526 100755
--- a/tests/run-debuginfod-federation-sqlite.sh
+++ b/tests/run-debuginfod-federation-sqlite.sh
@@ -167,11 +167,11 @@ curl -s http://127.0.0.1:$PORT1/metrics | grep 'http_responses_after_you.*'
 # waiting.  A few hundred ms is typical on this developer's workstation.
 
 ########################################################################
-# Corrupt the sqlite database and get debuginfod to trip across its errors
-curl -s http://127.0.0.1:$PORT1/metrics | grep 'sqlite3.*reset'
-dd if=/dev/zero of=$DB bs=1 count=1
-
-# trigger some random activity that's Sure to get sqlite3 upset
+# Trigger some some random activity, then trigger a clean shutdown.
+# We used to try to corrupt the database while the debuginfod server
+# was running and check it detected errors, but that was unreliably
+# and slightly dangerous since part of the database was already mapped
+# into memory.
 kill -USR1 $PID1
 wait_ready $PORT1 'thread_work_total{role="traverse"}' 2
 wait_ready $PORT1 'thread_work_pending{role="scan"}' 0
@@ -179,14 +179,15 @@ wait_ready $PORT1 'thread_busy{role="scan"}' 0
 kill -USR2 $PID1
 wait_ready $PORT1 'thread_work_total{role="groom"}' 2
 curl -s http://127.0.0.1:$PORT1/buildid/beefbeefbeefd00dd00d/debuginfo > /dev/null || true
-curl -s http://127.0.0.1:$PORT1/metrics | grep 'error_count.*sqlite'
-# Run the tests again without the servers running. The target file should
-# be found in the cache.
 
 kill -INT $PID1 $PID2
 wait $PID1 $PID2
 PID1=0
 PID2=0
+
+# Run the tests again without the servers running. The target file should
+# be found in the cache.
+
 tempfiles .debuginfod_*
 
 testrun ${abs_builddir}/debuginfod_build_id_find -e F/prog 1
-- 
2.18.4