dnstap unit test fails on native pkcs11 with softhsm
Summary
dnstap unit test fails on native pkcs11 with softhsm
BIND version used
(Paste the output of named -V.)
BIND 9.11.6-RedHat-9.11.6-1.fc31 (Extended Support Version) <id:f4bd4ca>
running on Linux x86_64 4.20.13-200.fc29.x86_64 #1 SMP Wed Feb 27 19:42:55 UTC 2019
built by make with '--build=x86_64-redhat-linux-gnu' '--host=x86_64-redhat-linux-gnu' '--program-prefix=' '--disable-dependency-tracking' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin' '--sbindir=/usr/sbin' '--sysconfdir=/etc' '--datadir=/usr/share' '--includedir=/usr/include' '--libdir=/usr/lib64' '--libexecdir=/usr/libexec' '--sharedstatedir=/var/lib' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--with-python=/usr/bin/python3' '--with-libtool' '--localstatedir=/var' '--enable-threads' '--enable-ipv6' '--enable-filter-aaaa' '--with-pic' '--disable-static' '--includedir=/usr/include/bind9' '--with-tuning=large' '--with-geoip' '--with-libidn2' '--enable-openssl-hash' '--enable-native-pkcs11' '--with-pkcs11=/usr/lib64/pkcs11/libsofthsm2.so' '--with-dlopen=yes' '--with-dlz-ldap=yes' '--with-dlz-postgres=yes' '--with-dlz-mysql=yes' '--with-dlz-filesystem=yes' '--with-dlz-bdb=yes' '--with-gssapi=yes' '--disable-isc-spnego' '--with-lmdb=yes' '--with-libjson' '--enable-dnstap' '--with-cmocka' '--enable-fixed-rrset' '--with-docbook-xsl=/usr/share/sgml/docbook/xsl-stylesheets' '--enable-full-report' 'build_alias=x86_64-redhat-linux-gnu' 'host_alias=x86_64-redhat-linux-gnu' 'CFLAGS= -O2 -g -pipe -Wall -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -Wp,-D_GLIBCXX_ASSERTIONS -fexceptions -fstack-protector-strong -grecord-gcc-switches -specs=/usr/lib/rpm/redhat/redhat-hardened-cc1 -specs=/usr/lib/rpm/redhat/redhat-annobin-cc1 -m64 -mtune=generic -fasynchronous-unwind-tables -fstack-clash-protection -fcf-protection' 'LDFLAGS=-Wl,-z,relro -Wl,-z,now -specs=/usr/lib/rpm/redhat/redhat-hardened-ld' 'CPPFLAGS= -DDIG_SIGCHASE' 'PKG_CONFIG_PATH=:/usr/lib64/pkgconfig:/usr/share/pkgconfig'
compiled by GCC 8.3.1 20190223 (Red Hat 8.3.1-2)
compiled with OpenSSL version: OpenSSL 1.1.1b FIPS 26 Feb 2019
linked to OpenSSL version: OpenSSL 1.1.1b FIPS 26 Feb 2019
compiled with libxml2 version: 2.9.8
linked to libxml2 version: 20908
compiled with libjson-c version: 0.13.1
linked to libjson-c version: 0.13.1
compiled with zlib version: 1.2.11
linked to zlib version: 1.2.11
threads support is enabledSteps to reproduce
- configure --with-pkcs11 --enable-native-pkcs11 --enable-dnstap --with-cmocka
- build
- export TZ=CET
- make unit
- kyua debug lib/dns/tests/dnstap_test:main
What is the current bug behavior?
[==========] Running 3 test(s).
[ RUN ] create_test
[ OK ] create_test
[ RUN ] send_test
[ OK ] send_test
[ RUN ] totext_test
[ FAILED ] totext_test
[ ERROR ] --- "03-Feb-2017 23:47:16.000 SQ 10.53.0.1:2112 -> 10.53.0.2:2112 UDP 40b www.isc.org/IN/A" != "03-Feb-2017 15:47:16.000 SQ 10.53.0.1:2112 -> 10.53.0.2:2112 UDP 40b www.isc.org/IN/A"
[ LINE ] --- ../../../../lib/dns-pkcs11/tests/dnstap_test.c:359: error: Failure!
Dump of all outstanding memory allocations:
ptr 0x7feac8f59010 size 24 file ../../../lib/dns-pkcs11/dnstap.c line 859
ptr 0x7feac8f60fd0 size 64 file ../../../lib/isc-pkcs11/buffer.c line 550
ptr 0x7feac8f6dfd0 size 64 file ../../../lib/isc-pkcs11/buffer.c line 550
ptr 0x7feac8f693d0 size 80 file ../../../lib/dns-pkcs11/message.c line 1014
ptr 0x7feac8f5b078 size 104 file ../../../lib/isc-pkcs11/mem.c line 1891
ptr 0x7feac8f5b0e0 size 104 file ../../../lib/isc-pkcs11/mem.c line 1891
ptr 0x7feac8f6db70 size 112 file ../../../lib/dns-pkcs11/message.c line 1107
ptr 0x7feac8f6db00 size 112 file ../../../lib/dns-pkcs11/message.c line 1534
ptr 0x7feac8f6aeb8 size 344 file ../../../lib/dns-pkcs11/message.c line 192
ptr 0x7feac8f68010 size 456 file ../../../lib/dns-pkcs11/message.c line 712
ptr 0x7feac8f5c410 size 512 file ../../../lib/isc-pkcs11/buffer.c line 554
ptr 0x7feac8f6a010 size 536 file ../../../lib/dns-pkcs11/message.c line 192
ptr 0x7feac8f6b010 size 664 file ../../../lib/dns-pkcs11/message.c line 192
ptr 0x55c8fd818bf0 size 1152 file ../../../lib/dns-pkcs11/dnstap.c line 960
ptr 0x55c8fd819080 size 2048 file ../../../lib/isc-pkcs11/buffer.c line 554
../../../lib/isc-pkcs11/mem.c:1270: REQUIRE(ctx->references == 1) failed, back trace
#0 0x7feac9ae83bb in ??
#1 0x7feac9ae8300 in ??
#2 0x7feac9afb402 in ??
#3 0x7feac9aff355 in ??
#4 0x55c8fd469276 in ??
#5 0x7feac925951e in ??
#6 0x7feac9259f79 in ??
#7 0x55c8fd467e7b in ??
#8 0x7feac90b2413 in ??
#9 0x55c8fd467ece in ??
Process with PID 21643 exited with signal 6 and dumped core; attempting to gather stack trace
Cannot find any core file
Files left in work directory after failure: .ccache
dnstap_test:main -> broken: Received signal 6What is the expected correct behavior?
(What you should see instead.)
[==========] Running 3 test(s).
[ RUN ] create_test
[ OK ] create_test
[ RUN ] send_test
[ OK ] send_test
[ RUN ] totext_test
[ OK ] totext_test
[==========] 3 test(s) run.
[ PASSED ] 3 test(s).
Relevant configuration files
(Paste any relevant configuration files - please use code blocks (```)
to format console output. If submitting the contents of your
configuration file in a non-confidential Issue, it is advisable to
obscure key secrets: this can be done automatically by using
named-checkconf -px.)
date
Thu Mar 14 16:04:23 CET 2019Relevant logs and/or screenshots
- gdb backtrace of first getenv("TZ")
#0 __GI_getenv (name=name@entry=0x7ffff74438b7 "TZ") at getenv.c:34
#1 0x00007ffff7375a4f in tzset_internal (always=<optimized out>) at tzset.c:378
#2 0x00007ffff7375e0a in __tz_convert (timer=timer@entry=0x7fffffffbbd8, use_localtime=use_localtime@entry=1,
tp=tp@entry=0x7fffffffbbf0) at tzset.c:584
#3 0x00007ffff7374351 in __localtime_r (t=t@entry=0x7fffffffbbd8, tp=tp@entry=0x7fffffffbbf0) at localtime.c:30
#4 0x00007ffff73b3784 in __GI___vsyslog_chk (pri=<optimized out>, flag=1, fmt=0x7ffff7155c2d "%s%s", ap=0x7fffffffbcd0)
at ../misc/syslog.c:195
#5 0x00007ffff73b3d83 in __syslog_chk (pri=pri@entry=3, flag=flag@entry=1, fmt=fmt@entry=0x7ffff7155c2d "%s%s")
at ../misc/syslog.c:129
#6 0x00007ffff7118aed in syslog (__fmt=0x7ffff7155c2d "%s%s", __pri=3) at /usr/include/bits/syslog.h:31
#7 softHSMLog (loglevel=loglevel@entry=3,
functionName=functionName@entry=0x7ffff7159765 <File::File(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, bool, bool, bool)::__func__> "File", fileName=fileName@entry=0x7ffff715a01e "File.cpp",
lineNo=lineNo@entry=94, format=format@entry=0x7ffff7159738 "Could not open the file (%s): %s") at log.cpp:102
#8 0x00007ffff714093f in File::File (this=0x7fffffffc1c0, inPath=..., forRead=<optimized out>, forWrite=<optimized out>,
create=<optimized out>, truncate=<optimized out>) at /usr/include/c++/8/bits/basic_string.h:2281
#9 0x00007ffff7141738 in Generation::commit (this=0x5555555a8eb0) at /usr/include/c++/8/bits/basic_string.h:927
#10 0x00007ffff71419c2 in Generation::Generation (this=0x5555555a8eb0, inPath=..., inIsToken=<optimized out>)
at Generation.cpp:258
#11 0x00007ffff7141a58 in Generation::create (
path="/var/lib/softhsm/tokens//fd04e9e9-bd75-2da1-0e70-82540070b451/generation", isToken=isToken@entry=true)
at /usr/include/c++/8/bits/basic_string.h:927
#12 0x00007ffff71459b5 in OSToken::OSToken (this=0x5555555a8dc0, inTokenPath=...)
at /usr/include/c++/8/bits/char_traits.h:285
#13 0x00007ffff7147043 in OSToken::accessToken (basePath=..., tokenDir=...) at /usr/include/c++/8/bits/char_traits.h:285
#14 0x00007ffff713d004 in ObjectStore::ObjectStore (this=0x5555555a8900, inStorePath=...)
at /usr/include/c++/8/bits/stl_iterator.h:796
#15 0x00007ffff70ee121 in SoftHSM::C_Initialize(void*) () at /usr/include/c++/8/bits/char_traits.h:285
#16 0x00007ffff70d3fc8 in C_Initialize (pInitArgs=0x7ffff7d7c000 <pk11_init_args>) at main.cpp:133
#17 0x00007ffff7d14069 in pk11_initialize (mctx=mctx@entry=0x55555555e9e0, engine=engine@entry=0x0)
at ../../../lib/isc-pkcs11/pk11.c:209
#18 0x00007ffff7f3fe92 in dst_lib_init2 (mctx=0x55555555e9e0, ectx=0x7ffff7186010, engine=engine@entry=0x0,
eflags=eflags@entry=4) at ../../../lib/dns-pkcs11/dst_api.c:199
#19 0x00007ffff7f4009d in dst_lib_init (mctx=<optimized out>, ectx=<optimized out>, eflags=eflags@entry=4)
at ../../../lib/dns-pkcs11/dst_api.c:149
#20 0x0000555555558f38 in dns_test_init (state=<optimized out>) at ../../../../lib/dns-pkcs11/tests/dnstest.c:145
#21 0x00007ffff74874e3 in cmocka_run_one_test_or_fixture (
function_name=function_name@entry=0x7ffff748a336 "cmocka_group_setup", test_func=test_func@entry=0x0,
setup_func=setup_func@entry=0x555555558e80 <dns_test_init>, teardown_func=teardown_func@entry=0x0,
state=state@entry=0x7fffffffc8b8, heap_check_point=heap_check_point@entry=0x7ffff71c7e50)
at /usr/src/debug/cmocka-1.1.3-1.fc29.x86_64/src/cmocka.c:2721
#22 0x00007ffff7487b68 in cmocka_run_group_fixture (function_name=0x7ffff748a336 "cmocka_group_setup", teardown_func=0x0,
heap_check_point=0x7ffff71c7e50, state=0x7fffffffc8b8, setup_func=0x555555558e80 <dns_test_init>)
at /usr/src/debug/cmocka-1.1.3-1.fc29.x86_64/src/cmocka.c:2926
#23 _cmocka_run_group_tests (group_name=0x55555555a138 "tests", tests=<optimized out>, num_tests=<optimized out>,
group_setup=0x555555558e80 <dns_test_init>, group_teardown=0x555555559230 <dns_test_final>)
at /usr/src/debug/cmocka-1.1.3-1.fc29.x86_64/src/cmocka.c:2926
#24 0x0000555555557e93 in main () at ../../../../lib/dns-pkcs11/tests/dnstap_test.c:381Possible fixes
(If you can, link to the line of code that might be responsible for the problem.) Move setenv(TZ) before dns library initialization. That with dns_test_init means it has to be before any test code, not part of it.