From 5e5370134377bbec66060d9adb5673973239981b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Pokorn=C3=BD?= Date: Fri, 6 Oct 2017 17:17:26 +0200 Subject: [PATCH 1/7] Med: qblog.h: better explanation + behaviour of QB_LOG_INIT_DATA MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Based on better understanding how link-time callsite collection works, put a better description for the macro. Also based on poor user experience in case that feature does not work well, say because the linker deliberately changes the previously settled visibility of the section boundary symbols (happened in ld from binutils-2.29, fix is forthcoming), tweak the assertion message a bit, together with an extension of the general intro to point that macro out. Also play fair, include the header, which this macro requires. - use case: /usr/sbin/pacemakerd --features - before: pacemakerd: utils.c:69: common: Assertion `0' failed - after: pacemakerd: utils.c:69: common: Assertion `"non-empty implicit callsite section" && QB_ATTR_SECTION_START != QB_ATTR_SECTION_STOP' failed. Restructuring of the assertion inspired by the suggestion of Ferenc Wágner (for the subsequent commit, actually). And regarding: > as a side effect, it can ensure the boundary-denoting symbols for > the target collection area are kept alive with some otherwise unkind > linkers this was actually empirically discovered in one particular combination with ld.bfd @ binutils 2.29, and extensively with 2.29.1 (placing here a forward reference for the following commits that elaborate on the libqb-target cross-combination matrix and the findings). Signed-off-by: Jan Pokorný --- include/qb/qblog.h | 45 ++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 40 insertions(+), 5 deletions(-) diff --git a/include/qb/qblog.h b/include/qb/qblog.h index 3cb4eef86..99ead1be7 100644 --- a/include/qb/qblog.h +++ b/include/qb/qblog.h @@ -42,6 +42,10 @@ extern "C" { #undef QB_HAVE_ATTRIBUTE_SECTION #endif /* S_SPLINT_S */ +#ifdef QB_HAVE_ATTRIBUTE_SECTION +#include /* possibly needed for QB_LOG_INIT_DATA */ +#endif + /** * @file qblog.h * The logging API provides four main parts (basics, filtering, threading & blackbox). @@ -64,6 +68,17 @@ extern "C" { * } * @endcode * + * @note + * In practice, such a minimalistic approach hardly caters real use cases. + * Following section discusses the customization. Moreover, it's quite + * vital to instrument the target user of this logging subsystem with + * @c QB_LOG_INIT_DATA() macro placed in the top file scope in an exactly + * one source file (preferably the main one) to be mixed into the resulting + * compilation unit. This is a self-defensive measure for when the + * linker-assisted collection of callsite data silently fails, which + * could otherwise go unnoticed, causing troubles down the road. + * + * * @par Configuring log targets. * A log target can be syslog, stderr, the blackbox, stdout, or a text file. * By default only syslog is enabled. @@ -268,11 +283,31 @@ typedef void (*qb_log_filter_fn)(struct qb_log_callsite * cs); extern struct qb_log_callsite QB_ATTR_SECTION_START[]; extern struct qb_log_callsite QB_ATTR_SECTION_STOP[]; -/* mere linker sanity check, possible future extension for internal purposes */ -#define QB_LOG_INIT_DATA(name) \ - void name(void); \ - void name(void) \ - { if (QB_ATTR_SECTION_START == QB_ATTR_SECTION_STOP) assert(0); } \ +/* optional on-demand self-check of 1/ toolchain sanity (prerequisite for + the logging subsystem to work properly) and 2/ non-void active use of + logging (satisfied with a justifying existence of a logging callsite as + defined with a @c qb_logt invocation) at the target (but see below), which + is supposedly assured by it's author(!) as of relying on this very macro + [technically, the symbols that happen to be resolved under the respective + identifiers do not necessarily originate in the same compilation unit as + when it's not the end executable (or by induction, a library positioned + earlier in the symbol lookup order) but a shared library, the former takes + a precedence unless that site comes short of exercising the logging, + making its callsite section empty and, in turn, without such boundary + symbols, hence making the resolution continue further in the lookup order + -- despite fuzzily targeted attestation, the check remains reasonable]; + only effective when link-time ("run-time amortizing") callsite collection + is; as a side effect, it can ensure the boundary-denoting symbols for the + target collection area are kept alive with some otherwise unkind linkers; + may be extended in future for more in-depth self-validation */ +#define QB_LOG_INIT_DATA(name) \ + void name(void); \ + void name(void) { \ + /* our own (target's) sanity, or possibly that of higher priority \ + symbol resolution site (unless target equals end executable) \ + or even the lower one if no such predecessor defines these */ \ + assert("implicit callsite section is populated" \ + && QB_ATTR_SECTION_START != QB_ATTR_SECTION_STOP); } \ void __attribute__ ((constructor)) name(void); #else #define QB_LOG_INIT_DATA(name) From 6c9948772cffbd03df43847e589da20b214fc7c1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Pokorn=C3=BD?= Date: Fri, 6 Oct 2017 17:17:26 +0200 Subject: [PATCH 2/7] build: configure: check section boundary symbols present in the test MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit There was an idea to make apparently run-time test set to that effect, but it would make cross-building harder. So arrange the test as if it would be meant for AC_TRY_RUN, but achieve the same as with the first assertion by the means of inspecting the linked result with, possibly target-specific, nm utility. While arranging the test for AC_TRY_RUN, based on feedback by Ferenc Wágner, unify and increase usability of the run-time error signalling through assertions. Signed-off-by: Jan Pokorný --- configure.ac | 35 ++++++++++++++++++++++++++--------- 1 file changed, 26 insertions(+), 9 deletions(-) diff --git a/configure.ac b/configure.ac index 7ec8f0eb9..5d3f897dc 100644 --- a/configure.ac +++ b/configure.ac @@ -77,6 +77,7 @@ AC_CHECK_PROGS([DOXYGEN], [doxygen]) AM_CONDITIONAL(HAVE_DOXYGEN, test -n "${DOXYGEN}") AC_CHECK_PROGS([SPLINT], [splint]) AM_CONDITIONAL(HAVE_SPLINT, test -n "${SPLINT}") +AC_CHECK_TOOLS([NM], [eu-nm nm], [:]) ## local helper functions @@ -620,15 +621,31 @@ AC_SUBST(HAVE_SLOW_TESTS) if test "x${GCC}" = xyes; then AC_MSG_CHECKING([whether GCC supports __attribute__((section()) + ld supports orphan sections]) if test "x${ac_cv_link_attribute_section}" = x ; then - AC_TRY_LINK([#include - extern void * __start___verbose, * __stop___verbose;], - [static int my_var __attribute__((section("__verbose"))) = 5; - if (__start___verbose == __stop___verbose) assert(0); - if (my_var == 5) return 0; - else return -1; - ], - [gcc_has_attribute_section=yes], - [gcc_has_attribute_section=no]) + dnl could be turned to AC_TRY_RUN (first assertion is equivalent to + dnl the further check in action-if-true), but that would prevent + dnl cross-building + AC_LINK_IFELSE( + [AC_LANG_PROGRAM( + [[#include + extern void * __start___verbose, * __stop___verbose;]], + [[static int my_var __attribute__((section("__verbose"))) = 5; + assert("non-empty data section" + && __start___verbose != __stop___verbose); + assert("no data section value loss" + && my_var == 5);]] + )], + [# alternatively something like (but requires number parsing): + # readelf -SW "conftest${ac_exeext}" \ + # | sed -n '/__verbose/s/^\s*//p' | tr -s ' ' | cut -d" " -f6 + verbose_start_addr=$(${NM} -g --portability -- "conftest${ac_exeext}" \ + | grep __start___verbose | cut -d" " -f 3) + verbose_stop_addr=$(${NM} -g --portability -- "conftest${ac_exeext}" \ + | grep __stop___verbose | cut -d" " -f 3) + test "${verbose_start_addr}" = "${verbose_stop_addr}" \ + && gcc_has_attribute_section=no \ + || gcc_has_attribute_section=yes], + [gcc_has_attribute_section=no] + ) else gcc_has_attribute_section=${ac_cv_link_attribute_section} fi From 454610697b9790da14c6115b0dd8b9fe3754dd0f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Pokorn=C3=BD?= Date: Fri, 6 Oct 2017 17:17:26 +0200 Subject: [PATCH 3/7] tests: new sort of tests dubbed "functional", cover linker vs. logging MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit These are for quick manual sanity checking, assuming the target audience -- maintainers -- are clear on the context of use and the purpose (perhaps with the help of static files for comparison and/or additional checking harness, usually available through "make check", but not to be confused with regular unit + broader tests). These test are meant to be compiled on demand only, not during the standard building routine, for which a trick leveraging GNUmakefile-Makefile precedence with GNU make was devised (GNU make/gmake already required by configure script for other reasons [some pattern-based matching not available with FreeBSD's default "make", IIRC], so this introduces no new build dependency). The respective new tests are meant to simulate logging variants in two different library consumption models: a. regular: linking against system-wide library b. developmental: consuming library from a local sub-checkout tree, using libtool conventions and hence attaching the library through libqb.la intermediate library descriptor of libtool and between up to three possibly affected logging system participants (discrete compilation units): 1. libqb itself will emit log messages in boundary conditions or for tracing purposes 2. client program that consumes libqb's logging API directly 3. ditto, but the client program furthermore links with a library (referred to as "interlib") that itself exercises the logging API (it's also linked with libqb) -- through induction, this should cover whole class of N interlib cases Especially the latter perspective makes for a test matrix to possibly (hopefully) demonstrate a fix allowing to cope with the changed behaviour of ld from binutils 2.29+ wrt. boundaries denoting symbols for a (custom) orphan section that are no longer externally visible. Such commit is in the pipeline... Developmental consumption model (a.) is now also tested automatically in Travis CI runs and as a part of %check within upstream-suggested libqb.spec for RPM packaging, whereas the regular one (b.) serves as a building block for new log_test_mock.sh runner of said test matrix -- it iterates through all the possible permutations of linker-imposed implicit visibility of mentioned symbols between various affected link participants all making use of logging (see 1. - 3. above) so as to demonstrate A/ the impact of the problem (see table below), and subsequently B/ that the fix is effective in all these situations (updated table will be provided as well) once it lands. This script also allows convoluting the test matrix further, notably with on-demand defusing the self-checks based on QB_LOG_INIT_DATA macro, which is of significance as demonstrated below (and will become even more important with upcoming patches in this series). * * * Current state for such matrix, in which participants 1. - 3. map like: 1. ~ libqb(Y) 2. ~ "direct" 3. ~ libX(Y) [a.k.a. interlib] and where "X(Y)" denotes "X linked with linker Y": X(a) .. ld.bfd < 2.29 X(b) .. ld.bfd = 2.29 (and only 2.29), goes like this: +=========+=========+=========+=========+=========+=========+=========+ #client(x)# libqb(a) usage # libqb(b) usage # # vvv #---------+---------+---------+---------+---------+---------+ # V # direct | libX(a) : libX(b) # direct | libX(a) : libX(b) # +=========+=========+=========+=========+=========+=========+=========+ # x = a # OK | OK : BAD[*2] # BAD[*1] | BAD[*D] : BAD[*3] # # x = b # BAD[*A] | BAD[*B] : BAD[*C] # BAD[*1] | BAD[*C] : BAD[*3] # +=========+=========+=========+=========+=========+=========+=========+ whereas if we swap 2.29 for 2.29.1, i.e., X(b) .. ld.bfd = 2.29.1, we can observe a somewhat simpler story (DEP ~ "depends"): +=========+=========+=========+=========+=========+=========+=========+ #client(x)# libqb(a) usage # libqb(b) usage # # vvv #---------+---------+---------+---------+---------+---------+ # V # direct | libX(a) : libX(b) # direct | libX(a) : libX(b) # +=========+=========+=========+=========+=========+=========+=========+ # x = a # OK | OK : DEP[*J] # BAD[*1] | BAD[*1] : BAD[*L] # # x = b # DEP[*I] | DEP[*I] : DEP[*K] # BAD[*1] | BAD[*1] : BAD[*L] # +=========+=========+=========+=========+=========+=========+=========+ * * * [*1] client logging not working [*2] interlib logging not working [*3] both client and interlib logging not working [*A] boils down to [*1], unless QB_LOG_INIT_DATA used on client side, which fails on 'implicit callsite section is populated' assertion [*B] boils down to [*1], unless QB_LOG_INIT_DATA used on interlib side, which fails on 'implicit callsite section is populated' assertion [*C] boils down to [*3], unless QB_LOG_INIT_DATA used on interlib side, which fails on 'implicit callsite section is populated' assertion [*D] boils down to [*3], unless QB_LOG_INIT_DATA used on interlib side, which makes it boil down just to [*1] (hypothesis: mere internal self-reference to the section's boundary symbols makes them overcome some kind of symbol garbage collection at the linkage stage, so they are exposed even they wouldn't be otherwise as demonstrated with the initial, plain case of [*3]) [*I] boils down to [*1], unless QB_LOG_INIT_DATA used on client side, which makes it, likely through self-reference keepalive (see below) work OK [*J] boils down to [*2], unless QB_LOG_INIT_DATA used on interlib side, which makes it, likely through self-reference keepalive (see below) work OK [*K] boils down to [*3], unless QB_LOG_INIT_DATA used on both client and interlib side, which makes it, likely through self-reference keepalive (see below) work OK (it's expected that this a mere composite of situations [*I] and [*J] with consequences as stated) [*L] boils down to [*3], unless QB_LOG_INIT_DATA used on interlib side (sufficient?), which makes it, likely through self-reference keepalive (see below) boil down just to [*1] * * * Note: as observed with [*D] case (libqb linked with ld.bfd < 2.29 whereas interlib and its client linked with ld.bfd = 2.29), the exact availability of a working logging doesn't depend solely on the linkers in question, but generally (further investigation out of scope) the conclusion is that when 2.29 ld.bfd is involved somewhere in the chain of logging-related discrete compilation units, also (self-)referencing of the section's boundary denoting symbols is a deciding factor whether particular logging source will be honored. This may be a result of some internal linkage garbage collection mechanisms involved. Anyway, it is supposed that the fix to broken-by-linkage logging can be proclaimed complete once all combinations pass barring QB_LOG_INIT_DATA usage (incurring the mentioned active referential use of the symbols), along with a spin using it everywhere for good measure. For another level of the analysis depth, one can further play with combinations of -n{sc,cl,il} options (explained upon -h switch) to log_test_mock.sh (taking an oracle, this is added mostly to justify the upcoming self-check test change because linker-script-based workaround for newer linkers will cause the section boundary symbols to be present regardless if that section is utilized, leading to a self-inflicted breakage due to these empty section symbols suddenly winning in the symbol resolution mechanism). Signed-off-by: Jan Pokorný --- .gitignore | 11 +- .travis.yml | 4 +- configure.ac | 7 +- libqb.spec.in | 3 +- tests/Makefile.am | 3 + tests/functional/GNUmakefile | 20 ++ tests/functional/Makefile.am | 23 ++ tests/functional/log.am | 49 +++ tests/functional/log_client.c | 88 +++++ tests/functional/log_external/Makefile.am | 23 ++ tests/functional/log_interlib.c | 70 ++++ tests/functional/log_interlib_client.c | 68 ++++ tests/functional/log_internal/Makefile.am | 23 ++ tests/functional/log_test_client.err | 2 + tests/functional/log_test_client.sh | 33 ++ tests/functional/log_test_interlib_client.err | 4 + tests/functional/log_test_interlib_client.sh | 36 ++ tests/functional/log_test_mock.sh | 310 ++++++++++++++++++ 18 files changed, 773 insertions(+), 4 deletions(-) create mode 100644 tests/functional/GNUmakefile create mode 100644 tests/functional/Makefile.am create mode 100644 tests/functional/log.am create mode 100644 tests/functional/log_client.c create mode 100644 tests/functional/log_external/Makefile.am create mode 100644 tests/functional/log_interlib.c create mode 100644 tests/functional/log_interlib_client.c create mode 100644 tests/functional/log_internal/Makefile.am create mode 100644 tests/functional/log_test_client.err create mode 100755 tests/functional/log_test_client.sh create mode 100644 tests/functional/log_test_interlib_client.err create mode 100755 tests/functional/log_test_interlib_client.sh create mode 100755 tests/functional/log_test_mock.sh diff --git a/.gitignore b/.gitignore index 8419b131e..9c30e733e 100644 --- a/.gitignore +++ b/.gitignore @@ -17,6 +17,9 @@ config.status configure .libs +# since we use subdir-objects as automake option +.dirstamp + # ignore "libtoolized" m4 files, but keep our (custom-prefixed) ones /m4/* !/m4/ax_*.m4 @@ -35,4 +38,10 @@ abi_dumps TAGS *~ test-driver -tests/*.trs + +/tests/**/*.real +/tests/**/*.trs +/tests/functional/**/log_client +/tests/functional/**/log_interlib_client +/tests/functional/_pkgs +/tests/functional/_results diff --git a/.travis.yml b/.travis.yml index d9faed9b6..5ee9a1052 100644 --- a/.travis.yml +++ b/.travis.yml @@ -15,7 +15,9 @@ addons: script: RPMBUILDOPTS_="--nodeps --define '_without_check 1'"; ./autogen.sh && ./configure - && make distcheck CPPFLAGS=-Dci_dump_shm_usage VERBOSE=1 + && make -C lib V=1 + && make -C tests/functional/log_internal V=1 check + && make V=1 CPPFLAGS=-Dci_dump_shm_usage distcheck && sed "s|RPMBUILDOPTS =|\\0 ${RPMBUILDOPTS_}|" Makefile | make -f- rpm after_failure: diff --git a/configure.ac b/configure.ac index 5d3f897dc..161f8a248 100644 --- a/configure.ac +++ b/configure.ac @@ -13,7 +13,7 @@ AC_CONFIG_SRCDIR([lib/ringbuffer.c]) AC_CONFIG_HEADERS([include/config.h include/qb/qbconfig.h]) AC_USE_SYSTEM_EXTENSIONS -AM_INIT_AUTOMAKE([-Wno-portability dist-xz]) +AM_INIT_AUTOMAKE([-Wno-portability dist-xz subdir-objects]) dnl automake >= 1.11 offers --enable-silent-rules for suppressing the output from dnl normal compilation. When a failure occurs, it will then display the full dnl command line @@ -730,6 +730,9 @@ AC_CONFIG_FILES([Makefile lib/libqb.pc tools/Makefile tests/Makefile + tests/functional/Makefile + tests/functional/log_external/Makefile + tests/functional/log_internal/Makefile tests/test.conf examples/Makefile docs/Makefile @@ -737,6 +740,8 @@ AC_CONFIG_FILES([Makefile docs/html.dox docs/man.dox]) +AC_CONFIG_LINKS([tests/functional/GNUmakefile:tests/functional/GNUmakefile]) + AC_OUTPUT AC_MSG_RESULT([]) diff --git a/libqb.spec.in b/libqb.spec.in index 3c73d40ca..5dda96705 100644 --- a/libqb.spec.in +++ b/libqb.spec.in @@ -31,7 +31,8 @@ make %{?_smp_mflags} %if 0%{?with_check} %check -VERBOSE=1 make check +make V=1 check \ + && make -C tests/functional/log_internal V=1 check %endif %install diff --git a/tests/Makefile.am b/tests/Makefile.am index fe5474116..df1af81a7 100644 --- a/tests/Makefile.am +++ b/tests/Makefile.am @@ -20,6 +20,9 @@ MAINTAINERCLEANFILES = Makefile.in EXTRA_DIST = CLEANFILES = + +SUBDIRS = functional + AM_CPPFLAGS = -I$(top_builddir)/include -I$(top_srcdir)/include noinst_PROGRAMS = bmc bmcpt bms rbreader rbwriter \ diff --git a/tests/functional/GNUmakefile b/tests/functional/GNUmakefile new file mode 100644 index 000000000..1b9de8100 --- /dev/null +++ b/tests/functional/GNUmakefile @@ -0,0 +1,20 @@ +all check: + # do not trigger automatically, it's for on-demand use + @echo "Use 'make $@' within particular subdirectories" +install: force + # definitely not desired to install anything from this subtree +distclean: + # following is a nasty hack to keep "make distclean" succeeding + # (problem mostly arises from shared object files and hence shared + # compiler-generated makefile includes which are swiped when + # processing one subdir and missing as hard error for the other) + @$(MAKE) -C log_external $@ + @mkdir .deps + @touch .deps/log_client.Po .deps/log_interlib.Plo .deps/log_interlib_client.Po + @$(MAKE) -C log_internal $@ + @$(MAKE) -f Makefile $@ SUBDIRS= +%: force + @$(MAKE) -f Makefile $@ +force: ; + +.PHONY: check distclean force install diff --git a/tests/functional/Makefile.am b/tests/functional/Makefile.am new file mode 100644 index 000000000..0d34ae8ce --- /dev/null +++ b/tests/functional/Makefile.am @@ -0,0 +1,23 @@ +# Copyright 2017 Red Hat, Inc. +# +# Authors: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +MAINTAINERCLEANFILES = Makefile.in +EXTRA_DIST = GNUmakefile log_test_client.err log_test_interlib_client.err \ + log_test_client.sh log_test_interlib_client.sh log_test_mock.sh +SUBDIRS = log_external log_internal diff --git a/tests/functional/log.am b/tests/functional/log.am new file mode 100644 index 000000000..e8e474066 --- /dev/null +++ b/tests/functional/log.am @@ -0,0 +1,49 @@ +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +MAINTAINERCLEANFILES = Makefile.in +CLEANFILES = log_test_client.err.real log_test_interlib_client.err.real + +AM_CPPFLAGS = -I$(top_builddir)/include -I$(top_srcdir)/include + +noinst_PROGRAMS = log_client log_interlib_client +# cannot use {check,noinst}_LTLIBRARIES because it leads to solely static lib +# (this won't get installed anyway, thanks to GNUmakefile rule) +lib_LTLIBRARIES = liblog_inter.la + +log_client_SOURCES = ../log_client.c +# log_client_LDFLAGS/log_client_LDADD to be delivered by the base Makefile.am + +liblog_inter_la_SOURCES = ../log_interlib.c +liblog_inter_la_LDFLAGS = -shared +# liblog_inter_la_LIBADD to be delivered by the base Makefile.am + +log_interlib_client_SOURCES = ../log_interlib_client.c +# this transitively shares link dependencies with liblog_inter.la itself +log_interlib_client_LDADD = $(builddir)/liblog_inter.la + +# actual 'make check' auxiliary definitions +TESTS = ../log_test_client.sh ../log_test_interlib_client.sh +TEST_EXTENSIONS = .sh +log_test.log: $(check_PROGRAMS) + +../log_test_client.log: log_client +../log_test_interlib_client.log: log_interlib_client + +# vim: ft=automake diff --git a/tests/functional/log_client.c b/tests/functional/log_client.c new file mode 100644 index 000000000..c60d6570f --- /dev/null +++ b/tests/functional/log_client.c @@ -0,0 +1,88 @@ +/* + * Copyright 2017 Red Hat, Inc. + * + * All rights reserved. + * + * Author: Jan Pokorny + * + * This file is part of libqb. + * + * libqb is free software: you can redistribute it and/or modify + * it under the terms of the GNU Lesser General Public License as published by + * the Free Software Foundation, either version 2.1 of the License, or + * (at your option) any later version. + * + * libqb is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public License + * along with libqb. If not, see . + */ +#include "os_base.h" +#include + +#ifndef NSELFCHECK +QB_LOG_INIT_DATA(linker_contra_log); +#endif + +static const char * +my_tags_stringify(uint32_t tags) +{ + if (qb_bit_is_set(tags, QB_LOG_TAG_LIBQB_MSG_BIT)) { + return "libqb"; + } else { + return "MAIN"; + } +} + +int32_t +main(int32_t argc, char *argv[]) +{ + int tmpfile_fd; + struct stat tmpfile_stat; + char *tmpfile_buf = strdup("linker-log-XXXXXX"); + + qb_log_init("linker-contra-log", LOG_USER, LOG_INFO); + qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE); + qb_log_filter_ctl(QB_LOG_STDERR, QB_LOG_FILTER_ADD, + QB_LOG_FILTER_FILE, "*", LOG_DEBUG); + qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE); + + qb_log_tags_stringify_fn_set(my_tags_stringify); + qb_log_format_set(QB_LOG_STDERR, "[%5g|%p] %f:%l:%b"); + +#if 0 + printf("--\n"); + qb_log_callsites_dump(); + printf("--\n"); +#endif + +#ifndef NLOG + /* Casual test of "user-space" logging. */ + qb_log(LOG_DEBUG, "hello"); +#endif + + /* And now of "library-space" logging, i.e., let libqb generated + an error message on its own behalf, first to see if it will be + logged at all, second if it will be distinguished properly. + The trigger here is as simple as trying to print non-existing + blackbox file. */ + tmpfile_fd = mkstemp(tmpfile_buf); + if (tmpfile_fd == -1) { + qb_perror(LOG_ERR, "creating temporary file"); + exit(EXIT_FAILURE); + } + unlink(tmpfile_buf); + close(tmpfile_fd); +#if 0 + if (stat(tmpfile_buf, &tmpfile_stat) == -1) { + qb_perror(LOG_ERR, "stat'ing nonexistent temporary file"); + exit(EXIT_FAILURE); + } +#endif + qb_log_blackbox_print_from_file(tmpfile_buf); + free(tmpfile_buf); + qb_log_fini(); +} diff --git a/tests/functional/log_external/Makefile.am b/tests/functional/log_external/Makefile.am new file mode 100644 index 000000000..36aa0af1c --- /dev/null +++ b/tests/functional/log_external/Makefile.am @@ -0,0 +1,23 @@ +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +include ../log.am + +log_client_LDFLAGS = -lqb +liblog_inter_la_LIBADD = -lqb diff --git a/tests/functional/log_interlib.c b/tests/functional/log_interlib.c new file mode 100644 index 000000000..228a339d8 --- /dev/null +++ b/tests/functional/log_interlib.c @@ -0,0 +1,70 @@ +/* + * Copyright 2017 Red Hat, Inc. + * + * All rights reserved. + * + * Author: Jan Pokorny + * + * This file is part of libqb. + * + * libqb is free software: you can redistribute it and/or modify + * it under the terms of the GNU Lesser General Public License as published by + * the Free Software Foundation, either version 2.1 of the License, or + * (at your option) any later version. + * + * libqb is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public License + * along with libqb. If not, see . + */ +#include "os_base.h" +#include + +#ifndef NSELFCHECK +QB_LOG_INIT_DATA(linker_contra_log_lib); +#endif + +void foo(void); + +void +foo(void) +{ + int tmpfile_fd; + struct stat tmpfile_stat; + char *tmpfile_buf = strdup("linker-log-XXXXXX"); + +#if 0 + printf("--\n"); + qb_log_callsites_dump(); + printf("--\n"); +#endif + +#ifndef NLIBLOG + /* Casual test of "user-space" logging. */ + qb_log(LOG_INFO, "aloha"); +#endif + + /* And now of "library-space" logging, i.e., let libqb generated + an error message on its own behalf, first to see if it will be + logged at all, second if it will be distinguished properly. + The trigger here is as simple as trying to print non-existing + blackbox file. */ + tmpfile_fd = mkstemp(tmpfile_buf); + if (tmpfile_fd == -1) { + qb_perror(LOG_ERR, "creating temporary file"); + exit(EXIT_FAILURE); + } + unlink(tmpfile_buf); + close(tmpfile_fd); +#if 0 + if (stat(tmpfile_buf, &tmpfile_stat) == -1) { + qb_perror(LOG_ERR, "stat'ing nonexistent temporary file"); + exit(EXIT_FAILURE); + } +#endif + qb_log_blackbox_print_from_file(tmpfile_buf); + free(tmpfile_buf); +} diff --git a/tests/functional/log_interlib_client.c b/tests/functional/log_interlib_client.c new file mode 100644 index 000000000..820df67ce --- /dev/null +++ b/tests/functional/log_interlib_client.c @@ -0,0 +1,68 @@ +/* + * Copyright 2017 Red Hat, Inc. + * + * All rights reserved. + * + * Author: Jan Pokorny + * + * This file is part of libqb. + * + * libqb is free software: you can redistribute it and/or modify + * it under the terms of the GNU Lesser General Public License as published by + * the Free Software Foundation, either version 2.1 of the License, or + * (at your option) any later version. + * + * libqb is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public License + * along with libqb. If not, see . + */ +#include "os_base.h" +#include + +#ifndef NSELFCHECK +QB_LOG_INIT_DATA(linker_contra_log_lib_user); +#endif + +void foo(void); + +static const char * +my_tags_stringify(uint32_t tags) +{ + if (qb_bit_is_set(tags, QB_LOG_TAG_LIBQB_MSG_BIT)) { + return "libqb"; + } else { + return "MAIN"; + } +} + +int +main(int argc, char *argv[]) +{ + qb_log_init("linker-contra-log", LOG_USER, LOG_INFO); + qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE); + qb_log_filter_ctl(QB_LOG_STDERR, QB_LOG_FILTER_ADD, + QB_LOG_FILTER_FILE, "*", LOG_DEBUG); + qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE); + + qb_log_tags_stringify_fn_set(my_tags_stringify); + qb_log_format_set(QB_LOG_STDERR, "[%5g|%p] %f:%l:%b"); + +#if 0 + printf("--\n"); + qb_log_callsites_dump(); + printf("--\n"); +#endif + +#ifndef NLOG + qb_log(LOG_INFO, "BEFORE"); +#endif + foo(); +#ifndef NLOG + qb_log(LOG_INFO, "AFTER"); +#endif + qb_log_fini(); +} diff --git a/tests/functional/log_internal/Makefile.am b/tests/functional/log_internal/Makefile.am new file mode 100644 index 000000000..697cee2a6 --- /dev/null +++ b/tests/functional/log_internal/Makefile.am @@ -0,0 +1,23 @@ +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +include ../log.am + +log_client_LDADD = $(top_builddir)/lib/libqb.la +liblog_inter_la_LIBADD = $(top_builddir)/lib/libqb.la diff --git a/tests/functional/log_test_client.err b/tests/functional/log_test_client.err new file mode 100644 index 000000000..19fca2c86 --- /dev/null +++ b/tests/functional/log_test_client.err @@ -0,0 +1,2 @@ +[MAIN |debug] ../log_client.c:64:hello +[libqb|error] log_blackbox.c:196:qb_log_blackbox_print_from_file: diff --git a/tests/functional/log_test_client.sh b/tests/functional/log_test_client.sh new file mode 100755 index 000000000..9098751f0 --- /dev/null +++ b/tests/functional/log_test_client.sh @@ -0,0 +1,33 @@ +#!/bin/sh +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +# error msg can differ per locale, errno code per system (Hurd begs to differ) +./log_client 2>&1 >/dev/null \ + | sed 's/\(qb_log_blackbox_print_from_file:\).*/\1/' \ + >log_test_client.err.real + +_pipeline='cat ../log_test_client.err' +case "${CPPFLAGS}" in + *-DNLOG*) + _pipeline="${_pipeline} | \ + grep -Ev '^\[MAIN |info] \.\./log_client\.c'";; +esac + +eval "${_pipeline}" | diff -u - log_test_client.err.real diff --git a/tests/functional/log_test_interlib_client.err b/tests/functional/log_test_interlib_client.err new file mode 100644 index 000000000..5b42b29e3 --- /dev/null +++ b/tests/functional/log_test_interlib_client.err @@ -0,0 +1,4 @@ +[MAIN |info] ../log_interlib_client.c:61:BEFORE +[MAIN |info] ../log_interlib.c:47:aloha +[libqb|error] log_blackbox.c:196:qb_log_blackbox_print_from_file: +[MAIN |info] ../log_interlib_client.c:65:AFTER diff --git a/tests/functional/log_test_interlib_client.sh b/tests/functional/log_test_interlib_client.sh new file mode 100755 index 000000000..d06ec989a --- /dev/null +++ b/tests/functional/log_test_interlib_client.sh @@ -0,0 +1,36 @@ +#!/bin/sh +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +# error msg can differ per locale, errno code per system (Hurd begs to differ) +./log_interlib_client 2>&1 >/dev/null \ + | sed 's/\(qb_log_blackbox_print_from_file:\).*/\1/' \ + >log_test_interlib_client.err.real + +_pipeline='cat ../log_test_interlib_client.err' +case "${CPPFLAGS}" in + *-DNLOG*) + _pipeline="${_pipeline} | \ + grep -Ev '^\[MAIN \|info] \.\./log_interlib_client\.c'";; + *-DNLIBLOG*) + _pipeline="${_pipeline} | \ + grep -Ev '^\[MAIN \|info\] \.\./log_interlib\.c'";; +esac + +eval "${_pipeline}" | diff -u - log_test_interlib_client.err.real diff --git a/tests/functional/log_test_mock.sh b/tests/functional/log_test_mock.sh new file mode 100755 index 000000000..145b9f4dd --- /dev/null +++ b/tests/functional/log_test_mock.sh @@ -0,0 +1,310 @@ +#!/bin/sh +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +# Given the source RPM for libqb, this will run through the basic test matrix +# so as to figure out the outcomes for particular linker (pre-2.29 and 2.29+ +# differing in visibility of orphan section delimiting boundary symbols and +# hence possibly causing harm to the logging facility of libqb) being used +# for particular part of the composite logging system (libqb itself, +# it's direct client / (client library + it's own client that uses logging) +# as well). While this is tailored to Fedora, it should be possible to +# run this testsuite wherever following is present: +# +# - rpm (for parsing archive name embedded in libqb.src.rpm [note that +# rpm2cpio is part of rpm package as well] because the extracted dir +# follows the same naming, which we need to know) +# - mock (https://github.com/rpm-software-management/mock/) +# + dependencies + fedora-27-${arch} configuration for mock +# (or whatever other configuration if some variables below are +# changed appropriately) +# - koji (https://pagure.io/koji/) + dependencies (but binutils packages +# can be precached when downloaded from https://koji.fedoraproject.org/ +# manually) +# - internet connection (but see the above statement for koji, and +# possibly the full package set within the build'n'test underlying +# container can be precached without further details on "how") +# - commons (coreutils, findutils, sed, ...) +# +# The testsuite will not mangle with your host system as mock spawns +# it's somewhat private container for be worked with under the hood. +# +# Note that in order not to get mad when entering the root password anytime +# mock is invoked, you can add the user initiating the test run to the +# 'mock' group. Be aware of the associated security risks, though: +# https://github.com/rpm-software-management/mock/wiki#setup + +set -eu + +# change following as suitable + +arch=x86_64 +mock_args="-r fedora-27-${arch}" +pkg_binutils_228=binutils-2.28-14.fc27 +#pkg_binutils_228=binutils-2.27-23.fc27 # alternatively test with 2.27 ... +pkg_binutils_229=binutils-2.29-6.fc27 +#pkg_binutils_229=binutils-2.29.1-2.fc28 # alternatively test with 2.29.1 + +# +# prettified reporters +# + +do_progress () { printf "\x1b[7m%s\x1b[0m\n" "$*"; } +do_info () { printf "\x1b[36mINFO: %s\x1b[0m\n" "$*"; } +do_warn () { printf "\x1b[31mWARNING: %s\x1b[0m\n" "$*"; } +do_die () { printf "\x1b[31mFATAL: %s\x1b[0m\n" "$*"; exit 1; } + +# +# actual building blocks +# + +# $1, ... $N: packages (and possibly related subpackages) to be downloaded +do_download () { + while test $# -gt 0; do + if test -d "_pkgs/$1" 2>/dev/null; then + do_info "$1 already downloaded" + shift; continue + fi + mkdir -p "_pkgs/$1" + ( cd "_pkgs/$1" && koji download-build --arch="${arch}" "$1" ) + shift + done +} + +# $1, ... $N: descriptors of packages to be installed +do_install () { + while test $# -gt 0; do + if test -d "_pkgs/$1" 2>/dev/null; then + do_install_inner "_pkgs/$1"/*.rpm + else + do_warn "$1 is not downloaded, hence skipped" + fi + shift + done +} + +# $1, ... $N: concrete packages to be installed +do_install_inner () { + _remove_cmd="mock ${mock_args} -- shell \"rpm --nodeps --erase" + _install_cmd="mock ${mock_args}" + while test $# -gt 0; do + case "$1" in + *.src.rpm|*-debuginfo*|*-debugsource*) ;; + *) + _pkg_name="$(basename "$1" | sed 's|\(-[0-9].*\)||')" + _remove_cmd="${_remove_cmd} \'${_pkg_name}\'" + _install_cmd="${_install_cmd} --install \"$1\"";; + esac + shift + done + eval "${_remove_cmd}\"" || : # extra quotation mark intentional + eval "${_install_cmd}" +} + +# $1: full path of srpm to be rebuilt +# $2: %{dist} macro for rpmbuild (distinguishing the builds) +do_buildsrpm () { + _pkg_descriptor="$(basename "$1" | sed 's|\.src\.rpm$||')" + # need to prune due to possible duplicates caused by differing %{dist} + rm -f -- "_pkgs/${_pkg_descriptor}"/* + mock ${mock_args} -Nn --define "dist $2" --define '_without_check 1' \ + --resultdir "_pkgs/${_pkg_descriptor}" --rebuild "$1" +} + +# $1: full path srpm to be rebuilt +# $2: extra (presumably) variable assignments for the make goal invocation +do_compile_interlib () { + mock ${mock_args} --shell \ + "find \"builddir/build/BUILD/$1/tests/functional\" \ + \( -name log_internal -o -name '*.c' \) -prune \ + -o -name '*liblog_inter*' \ + -exec rm -- {} \;" + mock ${mock_args} --shell "( cd \"builddir/build/BUILD/$1\"; ./configure )" + mock ${mock_args} --shell \ + "make -C \"builddir/build/BUILD/$1/tests/functional/log_external\" \ + liblog_inter.la $2" +} + +# $1: full path srpm to be rebuilt +# $2: which type of client to work with (client/interclient) +# $3: base (on-host) directory for test results +# $4: output file to capture particular test result +# $5: extra (presumably) variable assignments for the make goal invocation +do_compile_and_test_client () { + _result=$4 + case "$2" in + interclient) + _logfile=log_test_interlib_client + mock ${mock_args} --shell \ + "find \"builddir/build/BUILD/$1/tests/functional\" \ + \( -name log_internal -o -name '*.err' -o -name '*.c' \) -prune \ + -o \( -name '*log_interlib_client*' -o -name \"${_logfile}.log\" \) \ + -exec rm -- {} \;" + ;; + client|*) + _logfile=log_test_client + mock ${mock_args} --shell \ + "find \"builddir/build/BUILD/$1/tests/functional\" \ + \( -name log_internal -o -name '*.err' -o -name '*.c' \) -prune \ + -o \( -name '*log_client*' -o -name \"${_logfile}.log\" \) \ + -exec rm -- {} \;" + ;; + esac + mock ${mock_args} --shell "( cd \"builddir/build/BUILD/$1\"; ./configure )" + mock ${mock_args} --shell \ + "make -C \"builddir/build/BUILD/$1/tests/functional/log_external\" \ + check-TESTS \"TESTS=../${_logfile}.sh\" $5" \ + && _result="${_result}_good" \ + || _result="${_result}_bad" + mock ${mock_args} --copyout \ + "builddir/build/BUILD/$1/tests/functional/log_external/test-suite.log" \ + "$3/${_result}" +} + +do_shell () { + mock ${mock_args} --shell +} + +# $1, ... $N: "argv" +do_proceed () { + + _makevars= + _resultsdir_tag= + _selfcheck=1 + _clientlogging=1 + _interliblogging=1 + while :; do + case "$1" in + shell) shift; do_shell "$@"; return;; + -nsc) _resultsdir_tag="${_resultsdir_tag}$1"; shift; _selfcheck=0;; + -ncl) _resultsdir_tag="${_resultsdir_tag}$1"; shift; _clientlogging=0;; + -nil) _resultsdir_tag="${_resultsdir_tag}$1"; shift; _interliblogging=0;; + -*) do_die "Uknown option: $1";; + *) break;; + esac + done + + if test -n "${_resultsdir_tag}"; then + _makevars="CPPFLAGS=\"$(test "${_selfcheck}" -eq 1 || printf %s ' -DNSELFCHECK') \ + $(test "${_clientlogging}" -eq 1 || printf %s ' -DNLOG') \ + $(test "${_interliblogging}" -eq 1 || printf %s ' -DNLIBLOG')\"" + _makevars=$(echo ${_makevars}) + fi + + test -s "$1" || do_die "Not an input file: $1" + _libqb_descriptor_path="$1" + _libqb_descriptor="$(basename "${_libqb_descriptor_path}" \ + | sed 's|\.src\.rpm$||')" + _libqb_descriptor_archive="$(rpm -q --qf '[%{FILENAMES}\n]' \ + -p "${_libqb_descriptor_path}" \ + | sed -n '/\.tar/{s|\.tar\.[^.]*$||;p;q}')" + + _resultsdir="_results/$(date '+%y%m%d_%H%M%S')_${_libqb_descriptor}${_resultsdir_tag}" + mkdir -p "${_resultsdir}" + rm -f -- "${_resultsdir}/*" + + _dist= + _outfile= + _outfile_client= + _outfile_qb= + + do_download "${pkg_binutils_228}" "${pkg_binutils_229}" + + for _pkg_binutils_libqb in "${pkg_binutils_228}" "${pkg_binutils_229}"; do + + case "${_pkg_binutils_libqb}" in + ${pkg_binutils_228}) _outfile_qb="qb+"; _dist=.binutils228;; + ${pkg_binutils_229}) _outfile_qb="qb-"; _dist=.binutils229;; + *) _outfile_qb="?";; + esac + + do_progress "installing ${_pkg_binutils_libqb} so as to build" \ + "libqb [${_outfile_qb}]" + do_install "${_pkg_binutils_libqb}" + + do_progress "building ${_libqb_descriptor_path} with" \ + "${_pkg_binutils_libqb} [${_outfile_qb}]" + do_buildsrpm "${_libqb_descriptor_path}" "${_dist}" + + do_progress "installing ${_libqb_descriptor}-based packages" \ + "built with ${_pkg_binutils_libqb} [${_outfile_qb}]" + do_install "${_libqb_descriptor}" + # from now on, we can work fully offline, also to speed + # the whole thing up (and not to bother the mirrors) + mock_args="${mock_args} --offline" + + for _pkg_binutils_interlib in none "${pkg_binutils_228}" "${pkg_binutils_229}"; do + + case "${_pkg_binutils_interlib}" in + none) _outfile="${_outfile_qb}";; + ${pkg_binutils_228}) _outfile="${_outfile_qb}_il+";; + ${pkg_binutils_229}) _outfile="${_outfile_qb}_il-";; + *) _outfile="${_outfile_qb}_?";; + esac + + case "${_pkg_binutils_interlib}" in + none) ;; + *) + do_progress "installing ${_pkg_binutils_interlib}" \ + "so as to build interlib [${_outfile}]" + do_install "${_pkg_binutils_interlib}" + + do_progress "building interlib with ${_libqb_descriptor_archive}" \ + "+ ${_pkg_binutils_interlib} [${_outfile}]" \ + "{${_makevars}}" + do_compile_interlib "${_libqb_descriptor_archive}" "${_makevars}" + ;; + esac + + for _pkg_binutils_client in "${pkg_binutils_228}" "${pkg_binutils_229}"; do + + _client=client + test "${_pkg_binutils_interlib}" = none || _client=interclient + + case "${_pkg_binutils_client}" in + ${pkg_binutils_228}) _outfile_client="${_outfile}_c+";; + ${pkg_binutils_229}) _outfile_client="${_outfile}_c-";; + *) _outfile_client="${_outfile}_?";; + esac + + do_progress "installing ${_pkg_binutils_client}" \ + "so as to build ${_client} [${_outfile_client}]" + do_install "${_pkg_binutils_client}" + do_progress "building ${_client} with ${_libqb_descriptor_archive}" \ + "+ ${_pkg_binutils_client} [${_outfile_client}]" \ + "{${_makevars}}" + do_compile_and_test_client "${_libqb_descriptor_archive}" \ + "${_client}" "${_resultsdir}" \ + "${_outfile_client}" "${_makevars}" + done + done + done +} + +{ test $# -eq 0 || test "$1" = -h || test "$1" = --help; } \ + && printf '%s\n %s\n %s\n %s\n %s\n %s\n %s\n %s\n' \ + "usage: $0 {[-n{sc,cl,il}]* | shell}" \ + "- use '-nsc' to suppress optional self-check (\"see whole story\")" \ + "- use '-ncl' to suppress client-side logging" \ + "- use '-nil' to suppress interlib-side logging" \ + "- 'make -C ../.. srpm' (or so) can generate the requested input" \ + " (in that case, apparently, refer to '../../libqb-X.src.rpm')" \ + "- _pkgs dir caches (intermediate or not) packages to work with" \ + "- results stored in '_results/_[_]'" \ + || do_proceed "$@" From 32555d8af9373af9483befaaf88b35de49e7ee94 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Pokorn=C3=BD?= Date: Tue, 31 Oct 2017 16:43:20 +0100 Subject: [PATCH 4/7] tests: add a script to generate callsite-heavy logging client... MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ...so as to evaluate use of resources. In particular, the intention here is to uncover the observable differences between the same logging code built with callsite section (default when available) and purposefully (overriding that default by force) without it. To allow for the latter being applied conveniently, new macro, QB_KILL_ATTRIBUTE_SECTION, can be defined in the compile-time of the client code that wishes to opt-out from the callsite section feature. * * * Following is a discussion on these differences, sticking with the logging client code generated with the script defaults, i.e., as it would be run with these switches: --callsite-count=3640 --branching-factor=3 --callsites-per-fnc=10 --round-count=1000 and then built twice (as detailed in tests/functional/log_external/Makefile.am): * log_callsite_bench_sectionfull - with callsite section * log_callsite_bench_sectionless - without callsite section, imposed with -DQB_KILL_ATTRIBUTE_SECTION in CPPFLAGS --> Static size of the executable: $ size -B log_callsite_bench_section* | tr '\t' ' ' | tr -s ' ' \ | cut --complement -d' ' -f6 | column -t > text data bss dec filename > 82761 146180 4 228945 log_callsite_bench_sectionfull > 190000 588 4 190592 log_callsite_bench_sectionless We can see that sectionfull is few kB bigger in the object sections of interest, though the text-data ratio changes considerably, with code section being cut in half in comparison to sectionless, which can actually help the code locality (and hence utilization of CPU caches) in the former case. --> Dynamic memory/heap operations: $ valgrind --log-fd=1 ./log_callsite_bench_section{full,less} 2>/dev/null total heap usage: - log_callsite_bench_sectionfull: > 88 allocs, 87 frees, 3,427 bytes allocated[*] - log_callsite_bench_sectionless: > 11,894 allocs, 11,893 frees, 486,035 bytes allocated[*] [*] "32 bytes in 1 blocks still reachable" looks rather as a spurious warning on the valgrind's side (matter of dynamic linking library) Apparently, sectionless keeps stirring the heap constantly, with all the possible downsides associated with that, like hitting the page faults leading to less timely execution. --> Run-time efficiency: $ time ./log_callsite_bench_section{full,less} 2>/dev/null mean attempts out of 3 consecutive runs: - log_callsite_bench_sectionfull: > real 0m1.298s > user 0m0.965s > sys 0m0.331s - log_callsite_bench_sectionless: > real 0m1.436s > user 0m1.067s > sys 0m0.365s As expected, we can observe sectionfull is slightly faster/more efficient. * * * Based on the above, we can conclude that leveraging the callsite section for logging as facilitated by the toolchain intrinsics is beneficial, especially for performance-critical applications (corosync being the showcase here). Therefore it's desired to struggle for retaining this nifty trick despite some troubles emerged with recent binutils releases (starting with 2.29) and the changed behaviour we relied on so far in respective ld.bfd linkers (as mentioned in preceding commits). That motive is immediately followed -- well, judging the impact fairly, actually outclassed -- with the intention to preserve binary compatibility (incl. continuous library support for callsite section offloading spread in the existing client space widely for quite some years already) to the utmost extent possible. Signed-off-by: Jan Pokorný --- .gitignore | 2 + configure.ac | 2 + include/qb/qblog.h | 4 +- tests/functional/Makefile.am | 3 +- tests/functional/log.am | 11 +- tests/functional/log_callsite_bench_gen.py | 173 +++++++++++++++++++++ tests/functional/log_external/Makefile.am | 13 ++ 7 files changed, 204 insertions(+), 4 deletions(-) create mode 100755 tests/functional/log_callsite_bench_gen.py diff --git a/.gitignore b/.gitignore index 9c30e733e..d36173734 100644 --- a/.gitignore +++ b/.gitignore @@ -41,6 +41,8 @@ test-driver /tests/**/*.real /tests/**/*.trs +/tests/functional/log_callsite_bench.c +/tests/functional/**/log_callsite_bench_section*.c /tests/functional/**/log_client /tests/functional/**/log_interlib_client /tests/functional/_pkgs diff --git a/configure.ac b/configure.ac index 161f8a248..210955505 100644 --- a/configure.ac +++ b/configure.ac @@ -78,6 +78,8 @@ AM_CONDITIONAL(HAVE_DOXYGEN, test -n "${DOXYGEN}") AC_CHECK_PROGS([SPLINT], [splint]) AM_CONDITIONAL(HAVE_SPLINT, test -n "${SPLINT}") AC_CHECK_TOOLS([NM], [eu-nm nm], [:]) +AM_PATH_PYTHON([2.6],, [:]) +AM_CONDITIONAL([HAVE_PYTHON], [test "$PYTHON" != :]) ## local helper functions diff --git a/include/qb/qblog.h b/include/qb/qblog.h index 99ead1be7..d09b21c95 100644 --- a/include/qb/qblog.h +++ b/include/qb/qblog.h @@ -38,9 +38,9 @@ extern "C" { #include #include -#ifdef S_SPLINT_S +#if defined(QB_KILL_ATTRIBUTE_SECTION) || defined(S_SPLINT_S) #undef QB_HAVE_ATTRIBUTE_SECTION -#endif /* S_SPLINT_S */ +#endif /* defined(QB_KILL_ATTRIBUTE_SECTION) || defined(S_SPLINT_S) */ #ifdef QB_HAVE_ATTRIBUTE_SECTION #include /* possibly needed for QB_LOG_INIT_DATA */ diff --git a/tests/functional/Makefile.am b/tests/functional/Makefile.am index 0d34ae8ce..33dde4805 100644 --- a/tests/functional/Makefile.am +++ b/tests/functional/Makefile.am @@ -19,5 +19,6 @@ MAINTAINERCLEANFILES = Makefile.in EXTRA_DIST = GNUmakefile log_test_client.err log_test_interlib_client.err \ - log_test_client.sh log_test_interlib_client.sh log_test_mock.sh + log_test_client.sh log_test_interlib_client.sh log_test_mock.sh \ + log_callsite_bench_gen.py SUBDIRS = log_external log_internal diff --git a/tests/functional/log.am b/tests/functional/log.am index e8e474066..8976b6ca4 100644 --- a/tests/functional/log.am +++ b/tests/functional/log.am @@ -18,7 +18,8 @@ # along with libqb. If not, see . MAINTAINERCLEANFILES = Makefile.in -CLEANFILES = log_test_client.err.real log_test_interlib_client.err.real +CLEANFILES = log_test_client.err.real log_test_interlib_client.err.real \ + ../log_callsite_bench.c AM_CPPFLAGS = -I$(top_builddir)/include -I$(top_srcdir)/include @@ -46,4 +47,12 @@ log_test.log: $(check_PROGRAMS) ../log_test_client.log: log_client ../log_test_interlib_client.log: log_interlib_client +../log_callsite_bench.c: ../log_callsite_bench_gen.py +if HAVE_PYTHON + $(AM_V_GEN)$(PYTHON) $< >$@ +else + @echo 'configure script did not detect python prerequisite' + false +endif + # vim: ft=automake diff --git a/tests/functional/log_callsite_bench_gen.py b/tests/functional/log_callsite_bench_gen.py new file mode 100755 index 000000000..d80011e20 --- /dev/null +++ b/tests/functional/log_callsite_bench_gen.py @@ -0,0 +1,173 @@ +#!/usr/bin/python +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +# expected to work with both Python 2.6+/3+ +from __future__ import print_function + +"""Generate callsite-heavy logging client so as to evaluate use of resources""" + +from getopt import GetoptError, getopt +from math import ceil, floor, log10 +#from pprint import pprint +#from random import shuffle +from sys import argv, exit + +def die(*args, **kwargs): + print(*args, **kwargs) + exit(1) + +def list_to_c_source(worklist, fnc_prefix, width=0): + ret = [] + + while worklist: + item = worklist.pop() + if type(item) is list: + head, children = item + if type(children) is list: + for i, ci in enumerate(children): + ret += list_to_c_source([ci], fnc_prefix, width) + if type(ci) is list: + children[i] = ci[0] + if type(children[i]) is list: + children[i] = children[i][0] + else: + head = item + children = [] + if type(head) is not list: + head = [head] + ret += ["static void {0}_{1:0{2}}(int doit) {{" + .format(fnc_prefix, head[0], width), + "\tif (!doit) return;"] + ret += ["\tqb_log(LOG_ERR, \"{0:0{1}}\");".format(i, width) + for i in head] + ret += ["\t{0}_{1:0{2}}(doit);".format(fnc_prefix, i, width) + for i in reversed(children)] + ret += ["}"] + return ret + +def main(opts, args): + FNC_PREFIX = "fnc" + + try: + CALLSITE_COUNT = int(opts["CALLSITE_COUNT"]) + if not 0 < CALLSITE_COUNT < 10 ** 6: raise ValueError + except ValueError: + die("callsites count can only be a number x, 0 < x < 1e6") + try: + BRANCHING_FACTOR = int(opts["BRANCHING_FACTOR"]) + if not 0 < BRANCHING_FACTOR < 10 ** 3: raise ValueError + except ValueError: + die("branching factor can only be a number x, 0 < x < 1000") + try: + CALLSITES_PER_FNC = int(opts["CALLSITES_PER_FNC"]) + if not 0 < CALLSITES_PER_FNC < 10 ** 3: raise ValueError + except ValueError: + die("callsites-per-fnc count can only be a number x, 0 < x < 1000") + try: + ROUND_COUNT = int(opts["ROUND_COUNT"]) + if not 0 < ROUND_COUNT < 10 ** 6: raise ValueError + except ValueError: + die("round count can only be a number x, 0 < x < 1e6") + + worklist, worklist_len = list(range(0, CALLSITE_COUNT)), CALLSITE_COUNT + #shuffle(worklist) + + #pprint(worklist) + first = worklist[0] + while worklist_len > 1: + item = worklist.pop(); worklist_len -= 1 + reminder = worklist_len % CALLSITES_PER_FNC + parent = (worklist_len - reminder if reminder + else (worklist_len // CALLSITES_PER_FNC - 1) + // BRANCHING_FACTOR * CALLSITES_PER_FNC) + #print("parent {0} (len={1})".format(parent, worklist_len)) + if type(worklist[parent]) is not list: + worklist[parent] = [worklist[parent], []] + if not(reminder): + worklist[parent][1].append(item) # reverses the order! + #worklist[parent][1][:0] = [item] + else: + if type(worklist[parent][0]) is not list: + worklist[parent][0] = [worklist[parent][0]] + #worklist[parent][0].append(item) # reverses the order + worklist[parent][0][1:1] = [item] # parent itself the 1st element + #pprint(worklist) + + width = int(floor(log10(CALLSITE_COUNT))) + 1 + print('\n'.join([ + "/* compile with -lqb OR with -DQB_KILL_ATTRIBUTE_SECTION -lqb */", + "#include ", + ] + list_to_c_source(worklist, FNC_PREFIX, width) + [ + "int main(int argc, char *argv[]) {", + "\tqb_log_init(\"log_gen_test\", LOG_DAEMON, LOG_INFO);", + "\tqb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);", + "\tqb_log_filter_ctl(QB_LOG_STDERR, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FILE, \"*\", LOG_ERR);", + "\tqb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE);", + "\tfor (int i = 0; i < {0}; i++) {{".format(ROUND_COUNT), + "\t\t{0}_{1:0{2}}(argc);".format(FNC_PREFIX, first, width), + "\t}", + "\tqb_log_fini();", + "\treturn !argc;", + "}" + ] + )) + + +if __name__ == '__main__': + # Full trees for CALLSITES_PER_FNC == 1 (can be trivially extrapolated): + # BF = 2 (binary trees) + # --> C = 7 (3 steps), 15 (4 steps), ..., 127 (6 steps), ... + # (see https://en.wikipedia.org/wiki/Binary_tree#Properties_of_binary_trees) + # BF = 3 (ternary trees) + # --> C = 13 (3 steps), 40 (4 steps), ..., 1093 (6 steps), ... + # (see https://en.wikipedia.org/wiki/Ternary_tree#Properties_of_ternary_trees) + # ... + BRANCHING_FACTOR = 3 + CALLSITES_PER_FNC = 10 + CALLSITE_COUNT = 3640 + ROUND_COUNT = 1000 + try: + opts, args = getopt(argv[1:], + "hc:b:f:r:", + ("help", "callsite-count=", "branching-factor=", + "callsites-per-fnc=", "round-count=")) + for o, a in opts: + if o in ("-h", "--help"): + raise GetoptError("__justhelp__") + elif o in ("-c", "--callsite-count"): CALLSITE_COUNT = a + elif o in ("-b", "--branching-factor"): BRANCHING_FACTOR = a + elif o in ("-f", "--callsites-per-fnc"): CALLSITES_PER_FNC = a + elif o in ("-r", "--round-count"): ROUND_COUNT = a + except GetoptError as err: + if err.msg != "__justhelp__": + print(str(err)) + print("Usage:\n{0} -h|--help\n" + "{0} [-c X|--callsite-count={CALLSITE_COUNT}]" + " [-b Y|--branching-factor={BRANCHING_FACTOR}]\n" + "{1:{2}} [-f Z|--callsites-per-fnc={CALLSITES_PER_FNC}]" + " [-r R|--round-count={ROUND_COUNT}]" + .format(argv[0], '', len(argv[0]), **locals())) + exit(0 if err.msg == "__justhelp__" else 2) + + opts = dict(CALLSITE_COUNT=CALLSITE_COUNT, + BRANCHING_FACTOR=BRANCHING_FACTOR, + CALLSITES_PER_FNC=CALLSITES_PER_FNC, + ROUND_COUNT=ROUND_COUNT) + main(opts, args) diff --git a/tests/functional/log_external/Makefile.am b/tests/functional/log_external/Makefile.am index 36aa0af1c..018c83694 100644 --- a/tests/functional/log_external/Makefile.am +++ b/tests/functional/log_external/Makefile.am @@ -21,3 +21,16 @@ include ../log.am log_client_LDFLAGS = -lqb liblog_inter_la_LIBADD = -lqb + +# extras for log_external: comparable, generated callsite-heavy logging clients + +if HAVE_PYTHON +noinst_PROGRAMS += log_callsite_bench_sectionfull log_callsite_bench_sectionless +endif + +log_callsite_bench_sectionfull_SOURCES = ../log_callsite_bench.c +log_callsite_bench_sectionfull_LDFLAGS = -lqb + +log_callsite_bench_sectionless_SOURCES = ../log_callsite_bench.c +log_callsite_bench_sectionless_LDFLAGS = -lqb +log_callsite_bench_sectionless_CPPFLAGS = -DQB_KILL_ATTRIBUTE_SECTION From cdb026998fa1e62cb606be048ce0a5143e6f3483 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Pokorn=C3=BD?= Date: Fri, 6 Oct 2017 17:17:26 +0200 Subject: [PATCH 5/7] Med: add extra run-time (client, libqb) checks that logging will work MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Now that the previous commit provides a foundation for what exactly can go wrong with ld.bfd = 2.29+ linker, let's start reconciling that with some reasonable assurance that logging is not silently severed, because realizing the logs are missing is otherwise bound to happen when the logs are suddently pretty crucial analytical resource :-) We'll proceed in two steps as detailed. * * * As a first step, the table below concludes how the test matrix overview introduced with a message for the preceding commit (also introducing log_test_mock.sh runner which got reused here) looks as of this refreshed sanity check, once QB_LOG_INIT_DATA macro at hand gets applied (meaning "for non-libqb logging participants" so as not complicate the matrix further). That macro is nothing triggered directly, it will just plant a constructor-like function (to be invoked automatically early in the execution) that will run through the checks (one original and couple of new ones as of this changeset). Note that for libqb users, this implies a new link dependency on libdl, because they may opt-in for refreshed QB_LOG_INIT_DATA sanity check that calls out to dlopen/dlsym/dladdr directly in case of "attribute section" being available for the particular platform, and hence immediately needs those symbols resolved in link time. Hence, add this conditional link dependency to libqb.pc pkg-config file under Libs variable -- we actually restore the occurrence of "-ldl" there as it used to be present until commit 56754d0. While doing so, also move immediate link dependencies of libqb (if any, currently not but that may be a regression arising from the cleanup related to the mentioned commit) represented with the LIBS autoconf variable under Libs.private variable in libqb.pc, where it belongs per pkg-config documentation. The promised table follows, but first as a recap, "X(Y)" denotes "X linked with linker Y": X(a) .. ld.bfd < 2.29 X(b) .. ld.bfd = 2.29 (and only 2.29) goes like this (values in denote non-trivial change [not mere rewording] introduced as of this commit, in comparison to the table stated in the preceding commit): +=========+=========+=========+=========+=========+=========+=========+ #client(x)# libqb(a) usage # libqb(b) usage # # vvv #---------+---------+---------+---------+---------+---------+ # V # direct | libX(a) : libX(b) # direct | libX(a) : libX(b) # +=========+=========+=========+=========+=========+=========+=========+ # x = a # OK | OK : BAD[*2] #|:# # x = b # BAD[*A] | BAD[*B] : BAD[*C] #|:# +=========+=========+=========+=========+=========+=========+=========+ Woefully, nothing changes if we swap binutils 2.29 for 2.29.1, i.e., X(b) .. ld.bfd = 2.29.1, compared to previous state, i.e., the second table from the previous commit is still applicable for that situation. The added sanity checks are useful nonetheless, consider for example, that attribute-section-less libqb is what gets run-time linked to an attribute-section-full target. The most precise check we could use -- a custom logger function applied in a self-test scheme -- is not available at the point the macro-defined function gets invoked, simply because qb_log_init hasn't been invoked by the time that constructor gets triggered. However, what we can do is to add a non-trapping libqb-residing reverse-testing of the client space that (and once it) voluntarily initiates qb_log_init (delivering abruption all of a sudden at some unanticipated, as opposed to a well-timed like with constructors, execution point, seems pretty bad idea + libqb as a library is a mere helper, not an undertaker :) -- this check then only announces, via syslog (the only pre-enabled logging target), the target's logging may be severed. * * * Hence, as a promised second step, after incorporating the syslog change (and extending log_test_mock.sh so as to capture syslog stream within the container), not much changes with the table above, i.e., X(b) .. ld.bfd = 2.29: [*A] in addition, unless QB_LOG_INIT_DATA used on client side, syslog carries this notice: "(libqb) log module hasn't observed target chain supplied callsite section, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly, or target chain built purposefully without these sections)" logged by libqb proper [*C] in addition, unless QB_LOG_INIT_DATA used on interlib side, syslog carries this notice: "(libqb) log module hasn't observed target chain supplied callsite section, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly, or target chain built purposefully without these sections)" logged by libqb proper [*E] in addition, unless QB_LOG_INIT_DATA used on client side, syslog carries this warning: "(libqb) log module has observed target chain supplied section unpopulated, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly)" logged by libqb proper [*F] in addition, unless QB_LOG_INIT_DATA used on interlib side, syslog carries this warning: "(libqb) log module has observed target chain supplied section unpopulated, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly)" logged by libqb proper [*G] in addition, unless QB_LOG_INIT_DATA used on interlib side, syslog carries this warning: "(libqb) log module has observed target chain supplied section unpopulated, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly)" logged by libqb proper but desirably changes with "X(b) .. ld.bfd = 2.29.1" one (DEP ~ "depends"): +=========+=========+=========+=========+=========+=========+=========+ #client(x)# libqb(a) usage # libqb(b) usage # # vvv #---------+---------+---------+---------+---------+---------+ # V # direct | libX(a) : libX(b) # direct | libX(a) : libX(b) # +=========+=========+=========+=========+=========+=========+=========+ # x = a # OK | OK : DEP[*J] #|:# # x = b #| DEP[*I] :#|:# +=========+=========+=========+=========+=========+=========+=========+ * * * [*1] client logging not working [*2] interlib logging not working [*3] both client and interlib logging not working [*A] boils down to [*1], unless QB_LOG_INIT_DATA used on client side, which then fails on "implicit callsite section is populated, otherwise target's build is at fault, preventing reliable logging" assertion [*B] boils down to [*1], unless QB_LOG_INIT_DATA used on interlib side, which then fails on "implicit callsite section is populated, otherwise target's build is at fault, preventing reliable logging" assertion [*C] boils down to [*3], unless QB_LOG_INIT_DATA used on interlib side, which then fails on "implicit callsite section is populated, otherwise target's build is at fault, preventing reliable logging" assertion [*E] boils down to [*1], unless QB_LOG_INIT_DATA used on client side, which then fails on "implicit callsite section is self-observable, otherwise target's and/or libqb's build is at fault, preventing reliable logging" assertion [*F] boils down to [*3], unless QB_LOG_INIT_DATA used on interlib side, which then fails on "libqb's callsite section is populated, otherwise libqb's build is at fault, preventing reliable logging" assertion [*G] boils down to [*3], unless QB_LOG_INIT_DATA used on interlib side, which then fails on "implicit callsite section is self-observable, otherwise target's and/or libqb's build is at fault, preventing reliable logging" assertion [*I] boils down to [*1], unless QB_LOG_INIT_DATA used on client side, which makes it, likely through self-reference keepalive (see below), work OK [*J] boils down to [*2], unless QB_LOG_INIT_DATA used on interlib side, which makes it, likely through self-reference keepalive (see below), work OK [*K] boils down to [*3] in addition, syslog carries this notice: "(libqb) log module hasn't observed target chain supplied callsite section, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly, or target chain built purposefully without these sections)" logged by libqb proper [*L] boils down to [*3], unless QB_LOG_INIT_DATA used on interlib side (sufficient?), which makes it, likely through self-reference keepalive (see below), boil down just to [*1]; in addition, syslog carries this notice: "(libqb) log module hasn't observed target chain supplied callsite section, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly, or target chain built purposefully without these sections)" logged by libqb proper [*M] boils down to [*1]; in addition, syslog carries this notice: "(libqb) log module hasn't observed target chain supplied callsite section, target's and/or libqb's build is at fault, preventing reliable logging (unless qb_log_init invoked in no-custom-logging context unexpectedly, or target chain built purposefully without these sections)" logged by libqb proper [*N] boils down to [*M], unless QB_LOG_INIT_DATA used on client side, which makes it, likely through self-reference keepalive (see below), work OK [*O] boils down to [*K], unless QB_LOG_INIT_DATA used on both client and interlib side, which makes it, likely through self-reference keepalive (see below), work OK (it's expected that this a mere composite of situations [*I] and [*J] with consequences as stated) * * * Note: the only problematic (i.e. not captured automatically by the QB_LOG_INIT_DATA macro presumably utilized at every non-libqb logging system participant in the form of a discrete compilation unit) combination with 2.29 is the one intersecting at "BAD[*2]" pertaining "everything but interlib compiled with ld.bfd < 2.29". It would, of course, be solvable as well, but presumably not in an easy way, and that use case should not be as frequent. Takeway: whenever your target (library or client program) actively utilizes logging (meaning it emits at least a single log message, otherwise there's an imminent danger of possibly even run-terminating false positive in the self-check mechanism!), YOU ARE strongly ENCOURAGED TO USE QB_LOG_INIT_DATA macro function at (exactly) one of the source code files (presumably the main one) per respective target's compilation unit. It will alleviate the hassles possibly caused by downgrading libqb to the linker-vs-libqb incompatibly compiled one or in similar circumstances arising merely from the linker behaviour change, which the current build system/code shake is all about. Signed-off-by: Jan Pokorný --- configure.ac | 1 + include/qb/qblog.h | 108 ++++++++++++++++------ lib/libqb.pc.in | 3 +- lib/log.c | 51 ++++++++++ tests/functional/Makefile.am | 3 +- tests/functional/log.am | 2 +- tests/functional/log_external/Makefile.am | 8 +- tests/functional/log_test_mock.sh | 13 ++- tests/functional/syslog-stdout.py | 51 ++++++++++ 9 files changed, 205 insertions(+), 35 deletions(-) create mode 100755 tests/functional/syslog-stdout.py diff --git a/configure.ac b/configure.ac index 210955505..8df2c29b4 100644 --- a/configure.ac +++ b/configure.ac @@ -657,6 +657,7 @@ if test "x${GCC}" = xyes; then AC_DEFINE([QB_HAVE_ATTRIBUTE_SECTION], 1, [Enabling code using __attribute__((section))]) PACKAGE_FEATURES="$PACKAGE_FEATURES attribute-section" + AC_SUBST([client_dlopen_LIBS],[$dlopen_LIBS]) fi fi diff --git a/include/qb/qblog.h b/include/qb/qblog.h index d09b21c95..7be1390fd 100644 --- a/include/qb/qblog.h +++ b/include/qb/qblog.h @@ -1,9 +1,10 @@ /* - * Copyright (C) 2010 Red Hat, Inc. + * Copyright 2017 Red Hat, Inc. * * All rights reserved. * * Author: Angus Salkeld + * Jan Pokorny * * libqb is free software: you can redistribute it and/or modify * it under the terms of the GNU Lesser General Public License as published by @@ -44,6 +45,7 @@ extern "C" { #ifdef QB_HAVE_ATTRIBUTE_SECTION #include /* possibly needed for QB_LOG_INIT_DATA */ +#include /* dynamic linking: dlopen, dlsym, dladdr, ... */ #endif /** @@ -70,14 +72,14 @@ extern "C" { * * @note * In practice, such a minimalistic approach hardly caters real use cases. - * Following section discusses the customization. Moreover, it's quite - * vital to instrument the target user of this logging subsystem with - * @c QB_LOG_INIT_DATA() macro placed in the top file scope in an exactly - * one source file (preferably the main one) to be mixed into the resulting - * compilation unit. This is a self-defensive measure for when the - * linker-assisted collection of callsite data silently fails, which - * could otherwise go unnoticed, causing troubles down the road. - * + * Following section discusses the customization. Moreover when employing + * the log module is bound to its active use (some log messages are assuredly + * emitted within the target compilation unit), it's quite vital to instrument + * the target side with @c QB_LOG_INIT_DATA() macro placed in the top file + * scope in exactly one source file (preferably the main one) to be mixed into + * the resulting compilation unit. This is a self-defensive measure for when + * the linker-assisted collection of callsite data silently fails, which could + * otherwise go unnoticed, causing troubles down the road. * * @par Configuring log targets. * A log target can be syslog, stderr, the blackbox, stdout, or a text file. @@ -283,35 +285,85 @@ typedef void (*qb_log_filter_fn)(struct qb_log_callsite * cs); extern struct qb_log_callsite QB_ATTR_SECTION_START[]; extern struct qb_log_callsite QB_ATTR_SECTION_STOP[]; -/* optional on-demand self-check of 1/ toolchain sanity (prerequisite for - the logging subsystem to work properly) and 2/ non-void active use of - logging (satisfied with a justifying existence of a logging callsite as - defined with a @c qb_logt invocation) at the target (but see below), which - is supposedly assured by it's author(!) as of relying on this very macro - [technically, the symbols that happen to be resolved under the respective - identifiers do not necessarily originate in the same compilation unit as - when it's not the end executable (or by induction, a library positioned - earlier in the symbol lookup order) but a shared library, the former takes - a precedence unless that site comes short of exercising the logging, - making its callsite section empty and, in turn, without such boundary - symbols, hence making the resolution continue further in the lookup order - -- despite fuzzily targeted attestation, the check remains reasonable]; - only effective when link-time ("run-time amortizing") callsite collection - is; as a side effect, it can ensure the boundary-denoting symbols for the - target collection area are kept alive with some otherwise unkind linkers; - may be extended in future for more in-depth self-validation */ +/* Related to the next macro that is -- unlike this one -- a public API */ +#ifndef _GNU_SOURCE +#define QB_NONAPI_LOG_INIT_DATA_EXTRA_ \ + _Pragma(QB_PP_STRINGIFY(GCC warning QB_PP_STRINGIFY( \ + without "_GNU_SOURCE" defined (directly or not) \ + QB_LOG_INIT_DATA cannot check sanity of libqb proper))) +#else +#define QB_NONAPI_LOG_INIT_DATA_EXTRA_ \ + { Dl_info work_dli; \ + /* libqb sanity (locating libqb by it's relatively unique \ + -- and currently only such per-linkage global one -- \ + non-functional symbol, due to possible confusion otherwise) */ \ + if (dladdr(dlsym(RTLD_DEFAULT, "facilitynames"), &work_dli) \ + && (work_handle = dlopen(work_dli.dli_fname, \ + RTLD_LOCAL|RTLD_LAZY)) != NULL) { \ + work_s1 = (struct qb_log_callsite *) \ + dlsym(work_handle, QB_ATTR_SECTION_START_STR); \ + work_s2 = (struct qb_log_callsite *) \ + dlsym(work_handle, QB_ATTR_SECTION_STOP_STR); \ + assert("libqb's callsite section is observable, otherwise \ +libqb's build is at fault, preventing reliable logging" \ + && work_s1 != NULL && work_s2 != NULL); \ + assert("libqb's callsite section is populated, otherwise \ +libqb's build is at fault, preventing reliable logging" \ + && work_s1 != work_s2); \ + dlclose(work_handle); } } +#endif /* _GNU_SOURCE */ + +/** + * Optional on-demand self-check of 1/ toolchain sanity (prerequisite for + * the logging subsystem to work properly) and 2/ non-void active use of + * logging (satisfied with a justifying existence of a logging callsite as + * defined with a @c qb_logt invocation) at the target (but see below), which + * is supposedly assured by it's author(!) as of relying on this very macro + * [technically, the symbols that happen to be resolved under the respective + * identifiers do not necessarily originate in the same compilation unit as + * when it's not the end executable (or by induction, a library positioned + * earlier in the symbol lookup order) but a shared library, the former takes + * a precedence unless that site comes short of exercising the logging, + * making its callsite section empty and, in turn, without such boundary + * symbols, hence making the resolution continue further in the lookup order + * -- despite fuzzily targeted attestation, the check remains reasonable]; + * only effective when link-time ("run-time amortizing") callsite collection + * is; as a side effect, it can ensure the boundary-denoting symbols for the + * target collection area are kept alive with some otherwise unkind linkers. + * + * Applying this macro in the target program/library is strongly recommended + * whenever the logging as framed by this header file is in use. + * Moreover, it's important to state that using this check while not ensuring + * @c _GNU_SOURCE macro definition is present at compile-time means only half + * of the available sanity checking will be performed, possibly resulting + * in libqb's own internally logged messages being lost without warning. + */ #define QB_LOG_INIT_DATA(name) \ void name(void); \ void name(void) { \ + void *work_handle; struct qb_log_callsite *work_s1, *work_s2; \ /* our own (target's) sanity, or possibly that of higher priority \ symbol resolution site (unless target equals end executable) \ or even the lower one if no such predecessor defines these */ \ - assert("implicit callsite section is populated" \ + if ((work_handle = dlopen(NULL, RTLD_LOCAL|RTLD_LAZY)) != NULL) { \ + work_s1 = (struct qb_log_callsite *) \ + dlsym(work_handle, QB_ATTR_SECTION_START_STR); \ + work_s2 = (struct qb_log_callsite *) \ + dlsym(work_handle, QB_ATTR_SECTION_STOP_STR); \ + assert("implicit callsite section is observable, otherwise \ +target's and/or libqb's build is at fault, preventing reliable logging" \ + && work_s1 != NULL && work_s2 != NULL); \ + dlclose(work_handle); /* perhaps overly eager thing to do */ } \ + /* better targeted attestations when available */ \ + QB_NONAPI_LOG_INIT_DATA_EXTRA_; \ + /* finally, original, straightforward check */ \ + assert("implicit callsite section is populated, otherwise \ +target's build is at fault, preventing reliable logging" \ && QB_ATTR_SECTION_START != QB_ATTR_SECTION_STOP); } \ void __attribute__ ((constructor)) name(void); #else #define QB_LOG_INIT_DATA(name) -#endif +#endif /* QB_HAVE_ATTRIBUTE_SECTION */ /** * Internal function: use qb_log() or qb_logt() diff --git a/lib/libqb.pc.in b/lib/libqb.pc.in index 8a8d0ba8f..37d27b74e 100644 --- a/lib/libqb.pc.in +++ b/lib/libqb.pc.in @@ -7,5 +7,6 @@ Name: libqb Version: @PACKAGE_VERSION@ Description: libqb Requires: -Libs: -L${libdir} -lqb @LIBS@ +Libs: -L${libdir} -lqb @client_dlopen_LIBS@ +Libs.private: @LIBS@ Cflags: -I${includedir} diff --git a/lib/log.c b/lib/log.c index bfd218fac..e9cff8873 100644 --- a/lib/log.c +++ b/lib/log.c @@ -853,6 +853,18 @@ qb_log_init(const char *name, int32_t facility, uint8_t priority) { int32_t l; enum qb_log_target_slot i; +#ifdef QB_HAVE_ATTRIBUTE_SECTION + void *work_handle; struct qb_log_callsite *work_s1, *work_s2; + Dl_info work_dli; +#endif /* QB_HAVE_ATTRIBUTE_SECTION */ + /* cannot reuse single qb_log invocation in various contexts + through the variables (when section attribute in use), + hence this indirection */ + enum { + preinit_err_none, + preinit_err_target_sec, + preinit_err_target_empty, + } preinit_err = preinit_err_none; l = pthread_rwlock_init(&_listlock, NULL); assert(l == 0); @@ -871,6 +883,26 @@ qb_log_init(const char *name, int32_t facility, uint8_t priority) qb_log_dcs_init(); #ifdef QB_HAVE_ATTRIBUTE_SECTION + /* sanity check that target chain supplied QB_ATTR_SECTION_ST{ART,OP} + symbols and hence the local references to them are not referencing + the proper libqb's ones (locating libqb-self by it's relatively + unique -- and currently only such per-linkage global one -- + non-functional symbol, due to possible confusion otherwise) */ + if (dladdr(dlsym(RTLD_DEFAULT, "facilitynames"), &work_dli) + && (work_handle = dlopen(work_dli.dli_fname, + RTLD_LOCAL|RTLD_LAZY)) != NULL) { + work_s1 = (struct qb_log_callsite *) + dlsym(work_handle, QB_ATTR_SECTION_START_STR); + work_s2 = (struct qb_log_callsite *) + dlsym(work_handle, QB_ATTR_SECTION_STOP_STR); + if (work_s1 == QB_ATTR_SECTION_START + || work_s2 == QB_ATTR_SECTION_STOP) { + preinit_err = preinit_err_target_sec; + } else if (work_s1 == work_s2) { + preinit_err = preinit_err_target_empty; + } + dlclose(work_handle); /* perhaps overly eager thing to do */ + } qb_log_callsites_register(QB_ATTR_SECTION_START, QB_ATTR_SECTION_STOP); dl_iterate_phdr(_log_so_walk_callback, NULL); _log_so_walk_dlnames(); @@ -884,6 +916,25 @@ qb_log_init(const char *name, int32_t facility, uint8_t priority) _log_target_state_set(&conf[QB_LOG_SYSLOG], QB_LOG_STATE_ENABLED); (void)qb_log_filter_ctl(QB_LOG_SYSLOG, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FILE, "*", priority); + + if (preinit_err == preinit_err_target_sec) + qb_util_log(LOG_NOTICE, "(libqb) log module hasn't observed" + " target chain supplied callsite" + " section, target's and/or libqb's" + " build is at fault, preventing" + " reliable logging (unless qb_log_init" + " invoked in no-custom-logging context" + " unexpectedly, or target chain built" + " purposefully without these sections)"); + else if (preinit_err == preinit_err_target_empty) { + qb_util_log(LOG_WARNING, "(libqb) log module has observed" + " target chain supplied section" + " unpopulated, target's and/or libqb's" + " build is at fault, preventing" + " reliable logging (unless qb_log_init" + " invoked in no-custom-logging context" + " unexpectedly)"); + } } void diff --git a/tests/functional/Makefile.am b/tests/functional/Makefile.am index 33dde4805..4d9071f84 100644 --- a/tests/functional/Makefile.am +++ b/tests/functional/Makefile.am @@ -19,6 +19,7 @@ MAINTAINERCLEANFILES = Makefile.in EXTRA_DIST = GNUmakefile log_test_client.err log_test_interlib_client.err \ - log_test_client.sh log_test_interlib_client.sh log_test_mock.sh \ + log_test_client.sh log_test_interlib_client.sh \ + log_test_mock.sh syslog-stdout.py \ log_callsite_bench_gen.py SUBDIRS = log_external log_internal diff --git a/tests/functional/log.am b/tests/functional/log.am index 8976b6ca4..f2c6fbcc9 100644 --- a/tests/functional/log.am +++ b/tests/functional/log.am @@ -21,7 +21,7 @@ MAINTAINERCLEANFILES = Makefile.in CLEANFILES = log_test_client.err.real log_test_interlib_client.err.real \ ../log_callsite_bench.c -AM_CPPFLAGS = -I$(top_builddir)/include -I$(top_srcdir)/include +AM_CPPFLAGS = -D_GNU_SOURCE -I$(top_builddir)/include -I$(top_srcdir)/include noinst_PROGRAMS = log_client log_interlib_client # cannot use {check,noinst}_LTLIBRARIES because it leads to solely static lib diff --git a/tests/functional/log_external/Makefile.am b/tests/functional/log_external/Makefile.am index 018c83694..b1b568a6d 100644 --- a/tests/functional/log_external/Makefile.am +++ b/tests/functional/log_external/Makefile.am @@ -19,8 +19,12 @@ include ../log.am -log_client_LDFLAGS = -lqb -liblog_inter_la_LIBADD = -lqb +# while linking with system-wide version of libqb, we are still pursuing +# local in-tree header file, hence we need to link with dynamic linking +# library (which is a prerequisite for using QB_LOG_INIT_DATA defined +# in qblog.h) explicitly +log_client_LDFLAGS = -lqb @client_dlopen_LIBS@ +liblog_inter_la_LIBADD = -lqb @client_dlopen_LIBS@ # extras for log_external: comparable, generated callsite-heavy logging clients diff --git a/tests/functional/log_test_mock.sh b/tests/functional/log_test_mock.sh index 145b9f4dd..cdfce1fe2 100755 --- a/tests/functional/log_test_mock.sh +++ b/tests/functional/log_test_mock.sh @@ -166,10 +166,19 @@ do_compile_and_test_client () { -exec rm -- {} \;" ;; esac + mock ${mock_args} --copyin "syslog-stdout.py" "builddir" mock ${mock_args} --shell "( cd \"builddir/build/BUILD/$1\"; ./configure )" mock ${mock_args} --shell \ - "make -C \"builddir/build/BUILD/$1/tests/functional/log_external\" \ - check-TESTS \"TESTS=../${_logfile}.sh\" $5" \ + "python3 builddir/syslog-stdout.py \ + >\"builddir/build/BUILD/$1/tests/functional/log_external/.syslog\" & \ + { sleep 2; make -C \"builddir/build/BUILD/$1/tests/functional/log_external\" \ + check-TESTS \"TESTS=../${_logfile}.sh\" $5; } \ + && ! test -s \"builddir/build/BUILD/$1/tests/functional/log_external/.syslog\"; \ + ret_ec=\$?; \ + ( cd \"builddir/build/BUILD/$1/tests/functional/log_external\"; \ + cat .syslog >> test-suite.log; \ + echo SYSLOG-begin; cat .syslog; echo SYSLOG-end ); \ + ret () { return \$1; }; ret \${ret_ec}" \ && _result="${_result}_good" \ || _result="${_result}_bad" mock ${mock_args} --copyout \ diff --git a/tests/functional/syslog-stdout.py b/tests/functional/syslog-stdout.py new file mode 100755 index 000000000..64baf4c13 --- /dev/null +++ b/tests/functional/syslog-stdout.py @@ -0,0 +1,51 @@ +#!/usr/bin/python3 +# Copyright 2017 Red Hat, Inc. +# +# Author: Jan Pokorny +# +# This file is part of libqb. +# +# libqb is free software: you can redistribute it and/or modify +# it under the terms of the GNU Lesser General Public License as published by +# the Free Software Foundation, either version 2.1 of the License, or +# (at your option) any later version. +# +# libqb is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public License +# along with libqb. If not, see . + +"""Simple /dev/log to stdout forwarding""" + +import socket +from atexit import register +from os import remove +from sys import argv + +# no locking, but anyway +try: + remove("/dev/log") +except FileNotFoundError: + pass +sock = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) +sock.bind("/dev/log") + +def shutdown(): + sock.close() + remove("/dev/log") + +def main(*argv): + register(shutdown) + while True: + try: + b = sock.recv(4096) + # flushing is crucial here + print(">>> " + str(b, 'ascii').split(' ', 3)[-1], flush=True) + except IOError: + pass + +if __name__ == '__main__': + main(*argv) From 20246f544f74866885f4d9491f74152bd95e7786 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Pokorn=C3=BD?= Date: Fri, 6 Oct 2017 17:17:26 +0200 Subject: [PATCH 6/7] High: bare fix for libqb logging not working with ld.bfd/binutils 2.29+ MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit (or rather [read on]: "bare" fix, now that we established means to analyse the impact of the linker-dependent misbehaviour and to detect some of its symptoms in preceding two commits, respectively) Initially with the help of the internal test suite and the failing log test, it was eventually discovered[1] that these binutils commits going to the recent 2.29 release affected the treatment of _start_SECNAME and __stop_SECNAME symbols denoting the boundary start/stop addresses of a SECNAME orphan section -- specifically in libqb context a custom section (SECNAME=__verbose) used for link-time ("run-time amortizing") callsite collection when there's a support in the toolchain[*]: https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=cbd0eecf261c2447781f8c89b0d955ee66fae7e9 https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=b27685f2016c510d03ac9a64f7b04ce8efcf95c4 https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=7dba9362c172f1073487536eb137feb2da30b0ff The first one explicitly states: > Also __start_SECNAME and __stop_SECNAME symbols are marked as hidden > by ELF linker so that __start_SECNAME and __stop_SECNAME symbols for > section SECNAME in different modules are unique. The problem is that libqb silently depends on the previous status quo ld.bfd linker behaviour of keeping those symbols externally visible, which was apparently not granted as it has deliberately changed per above. And then for 2.29.1 release of binutils once again, as someone actually noticed something went overboard with the 2.29 changes: http://lists.gnu.org/archive/html/bug-binutils/2017-08/msg00195.html (overview of the original bug discussion, rather than directly https://sourceware.org/bugzilla/show_bug.cgi?id=21964, which is a result of a conflct resolution when restoring bugzilla backup) https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=487b6440dad57440939fab7afdd84a218b612796 At least that change doesn't invalidate all the effort being put into the original version of the changeset, only the configure script check had to be refined so as not to miss the "orphan section magic not working properly out of the box, without band aid" observation (see the inline comment) -- the workaround arrangement needs to be applied in that case as well. * * * So regarding the solution itself, the core of the fix was sketched at the original Fedora targeted bug against binutils[2]. In short, we are using a custom linker script that (re)describes the mentioned custom orphan output section, or better yet, assuredly pushes that section, and more importantly, it's own boundary denoting symbols, through into the resulting executable when it's being linked (as in compile-time step). This solution alone, while working for the non-libqb (more on that below) logging participants, is not good enough, as it requires all libqb targets to start using new incantation (namely "-Wl,foo.t" switch) in the final link step during compilation, which might be solvable with a tweak in libqb's pkg-config file under assumption that practice of using "pkg-config --libs libqb" is rigidly followed. Which is likely a false expectation, and furthermore only for the regular consumption model, as it doesn't cover the least bit the developmental one (refer to previous-but-one "tests" commit message), e.g. applied for internal examples + tests (but no local sub-checkout tree usage can be excluded). So further extensions were devised to cover both consumption models: - a. regular: courtesy of binutils maintainer[3], we follow an idea to make libqb.so (i.e. what the targets link against) rather a linker script on its own, which first include the version-specified (e.g. libqb.so.0) file into the link, then lists, in situ, the content of the linker script per above, hence -lqb linking has the same effect as having both "-lqb -Wl,foo.t" explicitly in the link command prior to this trick - b. developmental: to eliminate any kind of race condition arising from the attempt to post-modify libqb.la libtool archive file generated internally by libtool, we sort of abuse "inherited_linker_flags" variable within this file format, as it forms an accumulative value across the whole transitive dependencies chain (if not impaired per the note below), fitting exactly our purpose of injecting "-Wl,foo.t" switch equivalent for those libtool-linking by L{D,IB}ADD'ing libqb.la; it's then enough to craft a custom libtool archive file declaring that value, and hook it into such dependency chain through libqb_la_LIBADD, and with a little bit of further fiddling, it works as desired (note that double occurrence of "-Wl,foo.t" equivalent present at some stages of sorting this trick turned out to be, surprisingly, counter-productive, which should now demistify the very existence of effectively empty qblog_script_noop.ld file); NOTE: some forms of libtool distribution (debian + derivatives ones in particular) undermine natural transitive dependency propagation with a deliberate cut off (https://bugs.debian.org/702737), so we need to ensure the "impairment" is not happening by force (corosync precedent: https://github.com/corosync/corosync/commit/0f1dc5c1) ^ something like this needs to be applied for any such "private consumer" (although it hopefully goes without saying this way of consuming libqb outside of it's own playground is hardly the Right Thing) if portability is important, nonetheless! * * * On the address of linker script workaround, there are linkers out there that do not support the trick, for instance: - ld.gold from binutils (but it has hardly ever been working with orphan sections, anyway: https://sourceware.org/bugzilla/show_bug.cgi?id=22291) - ancient versions of ld.bfd, e.g. 10+ years old one used as a native system linker even in the most recent releases of FreeBSD, unless GCC toolchain is used instead If these are hit when (because) the compiler has already demonstrated it supports "section" attribute, the build system configuration is forcibly stopped, simply to stay conceptually compatible with the prior state in which the affinity to leverage that feature hasn't been called off under any circumstances. One is, however, able to achieve exactly this behaviour with --enable-nosection-fallback switch, but if some other participants in the logging, possibly linked with a more friendly linker, do utilize this orphan section, logging may silently break (another reason to require an explicit sign-off). Another note, the particular self-check change slightly touched in the previous commit but otherwise predating this whole effort by far needs to be modified now once again, this time because linker-script-based workaround for newer linkers as stated causes the section boundary symbols to be present regardless if that section is utilized, leading to a self-inflicted breakage due to these empty section symbols suddenly winning in the symbol resolution mechanism (previously the empty section would be dropped incl. the boundary symbols), causing problems down the line. It also makes this very check self-contained in the same compilation unit that trigggers it, whereas previously it used to be the said "arbitrary" winner and things kept silently working just because failure condition -- empty section -- would be implicitly isolated. Last but not least, libqb itself needs to be linked with the mentioned "-Wl,foo.t" equivalent for its own outgoing log messages to be honoured under all circumstances, which is already achieved with the arrangement for b. above, and by experiments, further redefinition of those boundary denoting symbols as weak was necessary so as to make them truly global within libqb.so proper (at least with binutils 2.29). * * * To provide a high-level prioritized overview of what drove the approach: - PRESERVATION OF BINARY COMPATIBILITY (ABI), which is achieved except for a single "ABI nongracefulness" I am aware of but that's more a consequence of slightly incorrect assumptions in the logic of QB_LOG_INIT_DATA macro function predating this whole affair by a long shot and which the patchset finally rectifies: if in the run-time dynamic link, following is combined: (. libqb, arbitrary variant: pre-/post-fix, binutils < / >= 2.29) . an "intermediate" library (something that the end executable links with) triggering QB_LOG_INIT_DATA macro and being built with pre-fix libqb (and perhaps only with binutils < 2.29) . end executable using no libqb's logging at all, but being built with post-fix libqb (and arbitrary binutils < / >= 2.29) then, unlike when executable is built with pre-fix libqb, the special callsite data containing section in the ELF structure of the executable is created + its boundary denoting symbols defined within, despite the section being empty (did not happen with pre-fix libqb), and because the symbols defined within the target program have priority over that of shared libraries in the symbol resolution fallback scheme, the assertion of QB_LOG_INIT_DATA of the mentioned intermediate library will actually be evaluating the inequality of boundaries for the section of the executable(!) rather than it's own (or whatever higher prio symbols are hit, presumably only present if the section at that level is non-empty, basically a generalization of the story so far); the problem then manifests as unability to run said executable as it will fail because of the intermediate library inflicted assertion (sadly with very unhelpful "Assertion `0' failed" message); fortunately, there's enough flexibility so as how to fix this, either should be fine: . have everything in the executable's library dependency closure that links against libqb assurably (compile-time) linked with one variant of libqb only (either all pre-fix or post-fix, mind the apparent limitation of binutils' versions with the former) . have the end executable (that does not use logging at all as discussed precondition) linked using substitution like this: s/-lqb/-l:libqb.so.0/ (you may need to adapt the number later) and you may also need to add this CPPFLAG for the executable: -DQB_KILL_ATTRIBUTE_SECTION - as high level of isolation of the client space from the linker (respectively toolchain) subtleties as possible (no new compilation flags and such required, plus there's no way to hook any dynamic computational ad-hoc decision when the compilation is about to happen, anyway), and in turn, versatility is preserved as much as possible * * * Finally, let's have a look how the already well-known test matrix overview changes as of this commit, but first as a recap, "X(Y)" denotes "X linked with linker Y": X(a) .. ld.bfd < 2.29 X(b) .. ld.bfd = 2.29 (+ 2.29.1 and hopefully on) and here you are (values in denote non-trivial change [not mere rewording] introduced as of this commit, in comparison to the table stated in the preceding commit): +=========+=========+=========+=========+=========+=========+=========+ #client(x)# libqb(a) usage # libqb(b) usage # # vvv #---------+---------+---------+---------+---------+---------+ # V # direct | libX(a) : libX(b) # direct | libX(a) : libX(b) # +=========+=========+=========+=========+=========+=========+=========+ # x = a # OK | OK : # | : # # x = b # | : # | : # +=========+=========+=========+=========+=========+=========+=========+ Everything is green \o/ * * * Note: as of this fix, it is assumed that the non-green counterpart of this table in the message for the preceding commit (loosely though[!], as the occurrence of empty callsite section can no longer be attributed to something bad going on as of this fix that enforces its presence unconditionally, whereas it would be suppressed when unused before with kind linkers, hence some other conditions can be witnessed especially when QB_LOG_INIT_DATA misused in no-logging context) doubles as an indicator how will mixing the logging participants wrt. linker+libqb version work out, when "X(Y)" becomes read as "X linked with linker Y under additional restriction on libqb version when compile-time link is performed of the particular part": X(a) .. ld.bfd < 2.29 OR [arbitrary ld.bfd AND libqb after this fix) X(b) .. ld.bfd = 2.29 (and likely on) AND libqb up to, but excluding this fix * * * Let's also state some imperfections and loops kept open: Deficiencies: * whenever anything is compiled against our install-time-modified libqb.so so as to force the visibility of the discussed symbols (or when compiling [with] libqb internally): > /usr/bin/ld: warning: ../lib/qblog_script.ld contains output sections; did you forget -T? - not solvable as long as we use the linker script, and there's hardly any other way not requiring the libqb consumers to adapt in any aspect * as already mentioned, lacking compatibility with ld.gold linker and won't foreseeably be (cf. https://bugzilla.redhat.com/1500898#c7) - please stick with ld.bfd (i.e. default ld linker), which you had to do in the past anyway (at least for compiling libqb itself) Open questions: * should we enable attribute((__section__)) for powerpc and other minor platforms if the feature is proved to be working there as well? and if/when that's going to happen, we need to figure out the transition plan to be spread throughout an extended period to keep the transition smooth -- notably when now-with-callsite-section clients will get run-time linked with callsite-section-not-a-default libqb (say upon it's downgrade), and for that, the libqb's support alone should be enabled year(s) ahead of the actual client space... * * * [*] basically GCC's section("SECNAME") __attribute__ annotation of the global variables + linker described behaviour previously mistakenly taken for granted References: [1] http://oss.clusterlabs.org/pipermail/developers/2017-July/000503.html [2] https://bugzilla.redhat.com/show_bug.cgi?id=1477354#c2 + comment 8 [3] https://bugzilla.redhat.com/show_bug.cgi?id=1477354#c9 Signed-off-by: Jan Pokorný --- .gitignore | 4 + check | 2 + configure.ac | 156 ++++++++++++++++++--- include/qb/qblog.h | 32 ++++- lib/Makefile.am | 79 ++++++++++- lib/libqb.pc.in | 11 ++ lib/log.c | 7 + lib/qblog_script.la.in | 15 ++ lib/qblog_script.ld.in | 30 ++++ lib/qblog_script_noop.ld | 1 + tests/functional/log_callsite_bench_gen.py | 2 +- tests/functional/log_external/Makefile.am | 2 +- 12 files changed, 312 insertions(+), 29 deletions(-) create mode 100644 lib/qblog_script.la.in create mode 100644 lib/qblog_script.ld.in create mode 100644 lib/qblog_script_noop.ld diff --git a/.gitignore b/.gitignore index d36173734..48d733624 100644 --- a/.gitignore +++ b/.gitignore @@ -15,6 +15,7 @@ aclocal.m4 autom4te.cache/ config.status configure +conftest.* .libs # since we use subdir-objects as automake option @@ -28,6 +29,9 @@ configure /.tarball-version /tag-* +/lib/qblog_script.ld +# already captured with wildcard: /lib/qblog_script.la + libtool .version libqb.spec diff --git a/check b/check index 6a2f29d40..79062c570 100755 --- a/check +++ b/check @@ -90,6 +90,8 @@ check_nosection() { echo "checking nosection" echo "=======================" # no __attribute__((section)) + # NOTE: alternatively CPPFLAGS=-DQB_KILL_ATTRIBUTE_SECTION, but + # that won't shortcut many initial/configure decisions check "ac_cv_link_attribute_section=no" } diff --git a/configure.ac b/configure.ac index 8df2c29b4..540712b7e 100644 --- a/configure.ac +++ b/configure.ac @@ -78,6 +78,7 @@ AM_CONDITIONAL(HAVE_DOXYGEN, test -n "${DOXYGEN}") AC_CHECK_PROGS([SPLINT], [splint]) AM_CONDITIONAL(HAVE_SPLINT, test -n "${SPLINT}") AC_CHECK_TOOLS([NM], [eu-nm nm], [:]) +AC_CHECK_TOOLS([READELF], [eu-readelf readelf], [:]) AM_PATH_PYTHON([2.6],, [:]) AM_CONDITIONAL([HAVE_PYTHON], [test "$PYTHON" != :]) @@ -504,6 +505,14 @@ AC_ARG_ENABLE([debug], AC_ARG_ENABLE([coverage], [AS_HELP_STRING([--enable-coverage],[coverage analysis of the codebase])]) +AC_ARG_ENABLE([interlib-deps], + [AS_HELP_STRING([--disable-interlib-deps], + [disable inter-library dependencies (might break builds)])]) + +AC_ARG_ENABLE([nosection-fallback], + [AS_HELP_STRING([--enable-nosection-fallback], + [allow (logging compat-breaking?) fallback when orphan section dead-ended])]) + AC_ARG_ENABLE([slow-tests], [AS_HELP_STRING([--enable-slow-tests],[build and run slow tests])]) @@ -612,6 +621,19 @@ else COVERAGE_LDFLAGS="" fi +# --- inter-library dependencies --- +# because of debian/ubuntu swimming against the stream +# https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=702737, +# override the libtool variable by force because the current +# arrangement relies on transitive dependency propagation +AC_MSG_NOTICE([Enabling inter-library dependencies: $enable_interlib_deps]) +if test "x${enable_interlib_deps}" = xno; then + link_all_deplibs=no +else + link_all_deplibs=yes +fi + +# --- slow tests --- if test "x${enable_slow_tests}" = xyes ; then AC_DEFINE([HAVE_SLOW_TESTS], 1,[have slow tests]) AC_MSG_NOTICE([Enabling Slow tests]) @@ -621,20 +643,60 @@ AC_SUBST(HAVE_SLOW_TESTS) # --- callsite sections --- if test "x${GCC}" = xyes; then + AX_SAVE_FLAGS AC_MSG_CHECKING([whether GCC supports __attribute__((section()) + ld supports orphan sections]) if test "x${ac_cv_link_attribute_section}" = x ; then + LDFLAGS="${LDFLAGS_save} -shared -fPIC" # we are compiling shared lib + AC_LINK_IFELSE( + [AC_LANG_SOURCE( + [[#include + extern int __start___verbose[], __stop___verbose[]; + int test(void) { + static int my_var __attribute__((section("__verbose"))) = 3; + assert("L:non-empty data section" + && __start___verbose != __stop___verbose); + assert("L:no data section value loss" + && my_var == 3 /* for 2.29.1+ */); + return *((int *) __start___verbose); }]] + )], + [gcc_has_attribute_section=yes; cp "conftest${ac_exeext}" "conftest.so"], + [gcc_has_attribute_section=no] + ) + AX_RESTORE_FLAGS + else + gcc_has_attribute_section=${ac_cv_link_attribute_section} + fi + AC_MSG_RESULT($gcc_has_attribute_section) + + # in the failing case (e.g. with ld from binutils 2.29), it's likely the + # following will fail readily in linkage (hidden symbol `__stop___verbose' + # in conftest is referenced by DSO), but keep the sensible test + # (in-executable symbol is expected to be propagated into the library, + # and to draw the full circle back to the executable through standard + # return value passing (respectively no-exec probing to spot the issue); + # -rpath passed because LD_LIBRARY_PATH exporting is unwieldy here); + # moreover, "my_var" == 3 assertion above (respectively checking if the + # boundary symbol visibility differs from DEFAULT in readelf output) is + # necessary so that binutils 2.29.1+ will not slip other parts of the + # overall is-workaround-needed harness, as it restored some (but not + # all) of the original behaviour, but the workaround is still provably + # needed + if test "x${gcc_has_attribute_section}" = xyes; then + AC_MSG_CHECKING([whether linker emits global boundary symbols for orphan sections]) + LIBS="${LIBS} -L. -l:conftest${shrext_cmds} -Wl,-rpath=$(pwd)" dnl could be turned to AC_TRY_RUN (first assertion is equivalent to dnl the further check in action-if-true), but that would prevent dnl cross-building AC_LINK_IFELSE( [AC_LANG_PROGRAM( [[#include - extern void * __start___verbose, * __stop___verbose;]], + extern int __start___verbose[], __stop___verbose[]; + int test(void);]], [[static int my_var __attribute__((section("__verbose"))) = 5; - assert("non-empty data section" + assert("E:non-empty data section" && __start___verbose != __stop___verbose); - assert("no data section value loss" - && my_var == 5);]] + assert("E:no data section value loss" + && my_var == test() /*5?*/);]] )], [# alternatively something like (but requires number parsing): # readelf -SW "conftest${ac_exeext}" \ @@ -644,22 +706,78 @@ if test "x${GCC}" = xyes; then verbose_stop_addr=$(${NM} -g --portability -- "conftest${ac_exeext}" \ | grep __stop___verbose | cut -d" " -f 3) test "${verbose_start_addr}" = "${verbose_stop_addr}" \ - && gcc_has_attribute_section=no \ - || gcc_has_attribute_section=yes], - [gcc_has_attribute_section=no] + && gcc_has_attribute_section_visible=no \ + || { verbose_start_type=$(${READELF} -s backup \ + | sed -n '/__start___verbose/{s/^\s*//p;q}' \ + | tr -s ' ' \ + | cut -d" " -f6) + test "${verbose_start_type}" = DEFAULT \ + && gcc_has_attribute_section_visible=yes \ + || gcc_has_attribute_section_visible=no; }], + [gcc_has_attribute_section_visible=no] ) - else - gcc_has_attribute_section=${ac_cv_link_attribute_section} - fi + AX_RESTORE_FLAGS + AC_MSG_RESULT($gcc_has_attribute_section_visible) + rm -f "conftest${shrext_cmds}" + + if test "x${gcc_has_attribute_section_visible}" = xno; then + # check if the linker script based workaround is + # feasible at all, otherwise fallback to using no + # section attribute while making some noise about it + # as combining with-without accustomed logging + # participants is currently uncharted waters + AC_MSG_CHECKING([whether linker workaround for orphan sections usable]) + >conftest.ld cat <<-EOF + SECTIONS { + __verbose : { + __start___verbose = .; + *(__verbose); + __stop___verbose = .; + } + } + EOF + LDFLAGS="${LDFLAGS} -Wl,conftest.ld" + AC_LINK_IFELSE( + [AC_LANG_PROGRAM( + [[#include + extern int __start___verbose[], __stop___verbose[]; + int test(void);]], + [[static int my_var __attribute__((section("__verbose"))) = 5; + assert("E:non-empty data section" + && __start___verbose != __stop___verbose); + assert("E:no data section value loss" + && my_var == 5);]] + )], + [], + [gcc_has_attribute_section=no] + ) + AX_RESTORE_FLAGS + AC_MSG_RESULT([$gcc_has_attribute_section]) + rm -f "conftest.ld" + fi - AC_MSG_RESULT($gcc_has_attribute_section) - if test $gcc_has_attribute_section = yes; then - AC_DEFINE([QB_HAVE_ATTRIBUTE_SECTION], 1, - [Enabling code using __attribute__((section))]) - PACKAGE_FEATURES="$PACKAGE_FEATURES attribute-section" - AC_SUBST([client_dlopen_LIBS],[$dlopen_LIBS]) + if test "x${gcc_has_attribute_section}" = xyes; then + AC_DEFINE([QB_HAVE_ATTRIBUTE_SECTION], 1, + [Enabling code using __attribute__((section))]) + AC_SUBST([client_dlopen_LIBS],[$dlopen_LIBS]) + if test "x${gcc_has_attribute_section_visible}" = xyes; then + PACKAGE_FEATURES="$PACKAGE_FEATURES attribute-section" + else + AC_DEFINE([QB_NEED_ATTRIBUTE_SECTION_WORKAROUND], 1, + [Enabling code using __attribute__((section))]) + PACKAGE_FEATURES="$PACKAGE_FEATURES attribute-section-workaround" + fi + elif test "x${enable_nosection_fallback}" = xyes; then + AC_MSG_NOTICE([Falling back to not using orphan section]) + else + AC_MSG_ERROR([Would use section attribute, cannot; see --enable-nosection-fallback]) + fi fi fi +AM_CONDITIONAL(HAVE_GCC_ATTRIBUTE_SECTION, [test "x${gcc_has_attribute_section}" = xyes]) +AM_CONDITIONAL(NEED_GCC_ATTRIBUTE_SECTION_WORKAROUND, + [test "x${gcc_has_attribute_section}" = xyes \ + && test "x${gcc_has_attribute_section_visible}" != xyes]) # --- ansi --- if test "x${enable_ansi}" = xyes && \ @@ -741,9 +859,11 @@ AC_CONFIG_FILES([Makefile docs/Makefile docs/common.dox docs/html.dox - docs/man.dox]) + docs/man.dox + lib/qblog_script.la:lib/qblog_script.la.in]) -AC_CONFIG_LINKS([tests/functional/GNUmakefile:tests/functional/GNUmakefile]) +AC_CONFIG_LINKS([lib/qblog_script_noop.ld:lib/qblog_script_noop.ld + tests/functional/GNUmakefile:tests/functional/GNUmakefile]) AC_OUTPUT diff --git a/include/qb/qblog.h b/include/qb/qblog.h index 7be1390fd..0af7d62ed 100644 --- a/include/qb/qblog.h +++ b/include/qb/qblog.h @@ -79,7 +79,10 @@ extern "C" { * scope in exactly one source file (preferably the main one) to be mixed into * the resulting compilation unit. This is a self-defensive measure for when * the linker-assisted collection of callsite data silently fails, which could - * otherwise go unnoticed, causing troubles down the road. + * otherwise go unnoticed, causing troubles down the road, but alas it cannot + * discern misuse of @c QB_LOG_INIT_DATA() macro in no-logging context from + * broken callsite section handling assumptions owing to overboard fancy + * linker -- situation that the self-check aims to detect in the first place. * * @par Configuring log targets. * A log target can be syslog, stderr, the blackbox, stdout, or a text file. @@ -287,12 +290,13 @@ extern struct qb_log_callsite QB_ATTR_SECTION_STOP[]; /* Related to the next macro that is -- unlike this one -- a public API */ #ifndef _GNU_SOURCE -#define QB_NONAPI_LOG_INIT_DATA_EXTRA_ \ +#define QB_NONAPI_LOG_INIT_DATA_EXTRA_(name) \ _Pragma(QB_PP_STRINGIFY(GCC warning QB_PP_STRINGIFY( \ without "_GNU_SOURCE" defined (directly or not) \ - QB_LOG_INIT_DATA cannot check sanity of libqb proper))) + QB_LOG_INIT_DATA cannot check sanity of libqb proper \ + nor of the target site originating this check alone))) #else -#define QB_NONAPI_LOG_INIT_DATA_EXTRA_ \ +#define QB_NONAPI_LOG_INIT_DATA_EXTRA_(name) \ { Dl_info work_dli; \ /* libqb sanity (locating libqb by it's relatively unique \ -- and currently only such per-linkage global one -- \ @@ -310,6 +314,23 @@ libqb's build is at fault, preventing reliable logging" \ assert("libqb's callsite section is populated, otherwise \ libqb's build is at fault, preventing reliable logging" \ && work_s1 != work_s2); \ + dlclose(work_handle); } \ + /* sanity of the target site originating this check alone */ \ + if (dladdr(dlsym(RTLD_DEFAULT, QB_PP_STRINGIFY(name)), &work_dli) \ + && (work_handle = dlopen(work_dli.dli_fname, \ + RTLD_LOCAL|RTLD_LAZY)) != NULL) { \ + work_s1 = (struct qb_log_callsite *) \ + dlsym(work_handle, QB_ATTR_SECTION_START_STR); \ + work_s2 = (struct qb_log_callsite *) \ + dlsym(work_handle, QB_ATTR_SECTION_STOP_STR); \ + assert("target's own callsite section observable, otherwise \ +target's own linkage at fault and logging would not work reliably \ +(unless QB_LOG_INIT_DATA macro used unexpectedly in no-logging context)"\ + && work_s1 != NULL && work_s2 != NULL); \ + assert("target's own callsite section non-empty, otherwise \ +target's own linkage at fault and logging would not work reliably \ +(unless QB_LOG_INIT_DATA macro used unexpectedly in no-logging context)"\ + && work_s1 != work_s2); \ dlclose(work_handle); } } #endif /* _GNU_SOURCE */ @@ -354,8 +375,7 @@ libqb's build is at fault, preventing reliable logging" \ target's and/or libqb's build is at fault, preventing reliable logging" \ && work_s1 != NULL && work_s2 != NULL); \ dlclose(work_handle); /* perhaps overly eager thing to do */ } \ - /* better targeted attestations when available */ \ - QB_NONAPI_LOG_INIT_DATA_EXTRA_; \ + QB_NONAPI_LOG_INIT_DATA_EXTRA_(name); \ /* finally, original, straightforward check */ \ assert("implicit callsite section is populated, otherwise \ target's build is at fault, preventing reliable logging" \ diff --git a/lib/Makefile.am b/lib/Makefile.am index 0bebeb5e7..1572cff5f 100644 --- a/lib/Makefile.am +++ b/lib/Makefile.am @@ -19,6 +19,7 @@ # along with libqb. If not, see . +CLEANFILES = qblog_script.ld MAINTAINERCLEANFILES = Makefile.in noinst_HEADERS = ipc_int.h util_int.h ringbuffer_int.h loop_int.h \ @@ -39,9 +40,48 @@ source_to_lint = util.c hdb.c ringbuffer.c ringbuffer_helper.c \ log_syslog.c log_dcs.c log_format.c \ map.c skiplist.c hashtable.c trie.c +# Following two files related to linkage using classic ld from binutils 2.29+ +# with which we cannot afford to lose public access to section boundary symbols +# (as the mentioned version started to scope them privately by default, see +# the comment within the first of the files, ultimately leading to broken +# logging functionality of libqb) deserve a bit of explanation: +# * qblog_script.ld +# - linker script that instructs the output section that those symbols should +# be visible, i.e. supports the same behaviour regardless of ld version +# - serves two purposes: +# . local: libqb itself and its "private" (cf. examples) users need those +# symbols visible, which is achieved with a help of the other file +# . system-wide: whenever the non-private library users link against libqb +# (it's development files), this linker script with +# prepended INPUT command so as to refer to the actual +# libqb library (it's numbered alias that is eventually +# resolved to proper shared library) is masked as libqb.so, +# this arrangement achieves the libqb's user will have +# the discussed symbols visible alike +# * qblog_script.la +# - as mentioned earlier, this indirectly hooks into libtool machinery, with +# the only true intention of injecting "-Wl," +# into "inherited_linker_flags" libtool archive variable, from where it's +# subsequently spread into the build process of all the internal library +# users, assuming they have their dep arranged as "user_LIBADD=libqb.la" +# (this also alleviates the burden on getting things right if, e.g., any +# libqb user consumes it directly like this from its own sub-checkout tree) +# - it indirectly, once libtool prechew the original link command +# originally referring to this file, it turns such reference into the +# "real" library reference (here combining libdir and old_library +# variables within the file), also ensures libqb itself will visibly +# expose the discussed symbols, because such references point again to +# the (not enriched) linker script file that will get interpreted just +# like that during the last build step of the library +EXTRA_libqb_la_DEPENDENCIES = qblog_script.ld qblog_script.la +EXTRA_DIST = qblog_script.ld.in qblog_script.la.in qblog_script_noop.ld + libqb_la_SOURCES = $(source_to_lint) unix.c libqb_la_CFLAGS = $(PTHREAD_CFLAGS) libqb_la_LIBADD = $(LTLIBOBJS) $(dlopen_LIBS) $(PTHREAD_LIBS) $(socket_LIBS) +if NEED_GCC_ATTRIBUTE_SECTION_WORKAROUND +libqb_la_LIBADD += qblog_script.la +endif AM_LDFLAGS = $(LDFLAGS_COPY:-Bsymbolic-functions=) @@ -60,9 +100,42 @@ else endif endif - -pkgconfigdir = $(libdir)/pkgconfig -pkgconfig_DATA = libqb.pc +qblog_script.ld: %.ld: %.ld.in + $(AM_V_GEN)$(CPP) -xc -I$(top_srcdir)/include -D_GNU_SOURCE -C -P $< \ + | sed -n "/$$(sed -n '/^[^#]/{s/[*\/]/\\&/g;p;q;}' $<)/,$$ p" \ + > $@ + +# sadly, there's a distinction between "exec" and "data" install, and it's hard +# to decouple install-exec-hook below (.pc file is platform-dependent, anyway) +pkgconfigexecdir = $(libdir)/pkgconfig +pkgconfigexec_DATA = libqb.pc + +# find the libqb.so symlink's target, if so, try to find out, iteratively, +# its gradually shorter forms that likewise symlinks the same target as the +# original libqb.so path, point to that file from the linker script using +# qblog_script.ld as a template, storing result in place of original libqb.so +# (e.g., libqb.so := "INPUT(libqb.so.0) " [...] "SECTIONS { " [...] "}") +# NOTE: readlink nor realpath are POSIX; not chained links ready +# NOTE: conservative check, i.e., not per NEED_GCC_ATTRIBUTE_SECTION_WORKAROUND +if HAVE_GCC_ATTRIBUTE_SECTION +install-exec-hook: qblog_script.ld + target=$$(ls -l "$(DESTDIR)$(libdir)/libqb.so" || :); \ + target=$${target#* -> }; t1_bn=$$(basename "$${target}" || :); \ + while test -n "$${t1_bn}"; do t2_bn=$${t1_bn%.*[0-9]*}; \ + test "$${t2_bn}" != libqb.so || break; \ + test -L "$${t2_bn}" || { t1_bn=$${t2_bn}; continue; }; \ + t2_target=$$(ls -l "$${t2_bn}" || break); t2_target=$${t2_target#* -> }; \ + test "$${t2_target}" = "$${target}" || break; \ + t1_bn=$${t2_bn}; done; test -n "$${t1_bn}" || \ + { echo "only applicable to SO symlink scheme"; exit 1; }; \ + echo "$${t1_bn}" > "$(DESTDIR)$(libdir)/libqb.so-t" + so_ver=$$(cat "$(DESTDIR)$(libdir)/libqb.so-t"); \ + echo "INPUT($${so_ver})" > "$(DESTDIR)$(libdir)/libqb.so-t"; \ + cat $< >> "$(DESTDIR)$(libdir)/libqb.so-t"; \ + sed -i -- "s/libqb.so./$${so_ver}/" \ + "$(DESTDIR)$(libdir)/libqb.so-t" "$(DESTDIR)$(pkgconfigexecdir)/libqb.pc" + mv -f "$(DESTDIR)$(libdir)/libqb.so-t" "$(DESTDIR)$(libdir)/libqb.so" +endif if HAVE_SPLINT check_SCRIPTS = run_splint.sh diff --git a/lib/libqb.pc.in b/lib/libqb.pc.in index 37d27b74e..d9839bf41 100644 --- a/lib/libqb.pc.in +++ b/lib/libqb.pc.in @@ -8,5 +8,16 @@ Version: @PACKAGE_VERSION@ Description: libqb Requires: Libs: -L${libdir} -lqb @client_dlopen_LIBS@ +# NOTE: If -lqb not usable for linking (e.g. linker not compatible with +# linker scripts ad-hoc modifying output sections), try recent +# ld.bfd/binutils linker first when available, otherwise you can +# try "-l:libqb.so." link switch that bypasses said linker +# script -- but beware, logging may be less efficient and may lack +# possible future optimizations and extra features. Consequently, +# logging issues (typically bound to QB_LOG_INIT_DATA macro) can be +# mitigated with QB_KILL_ATTRIBUTE_SECTION macro defined for a build. +# NOTE: when concerned about a warning coming from the build process like +# warning: [...]libqb.so contains output sections; did you forget -T? +# and the build finishes OK, take it merely as a harmless side-effect Libs.private: @LIBS@ Cflags: -I${includedir} diff --git a/lib/log.c b/lib/log.c index e9cff8873..769087171 100644 --- a/lib/log.c +++ b/lib/log.c @@ -40,6 +40,13 @@ #include "util_int.h" #include +#if defined(QB_NEED_ATTRIBUTE_SECTION_WORKAROUND) && !defined(S_SPLINT_S) +/* following only needed to force these symbols be global + with ld 2.29: https://bugzilla.redhat.com/1477354 */ +struct qb_log_callsite __attribute__((weak)) QB_ATTR_SECTION_START[] = { 0 }; +struct qb_log_callsite __attribute__((weak)) QB_ATTR_SECTION_STOP[] = { 0 }; +#endif + static struct qb_log_target conf[QB_LOG_TARGET_MAX]; static uint32_t conf_active_max = 0; static int32_t in_logger = QB_FALSE; diff --git a/lib/qblog_script.la.in b/lib/qblog_script.la.in new file mode 100644 index 000000000..f262df8cf --- /dev/null +++ b/lib/qblog_script.la.in @@ -0,0 +1,15 @@ +# Generated by libtool +# NOTE: above line is just to pass func_ltwrapper_script_p sanity check of +# libtool script, as we are basically sort of abusing it so as to inject +# our custom linker script to "private" (cf. examples) users of libqb.la + +# shall rather carry a location of old_library (possibly libdir or something +# else, but installed=no needed to suppress 'library moved' warning then) as +# it's together (with libtool implied prefix otherwise) used for linking libqb +libdir=@abs_builddir@ + +# avoids issues with library_names (spurious rpath emitting, relink-on-install) +old_library=qblog_script_noop.ld + +# subject of our injection into libqb.la impacting build time for private users +inherited_linker_flags=-Wl,@abs_builddir@/qblog_script.ld diff --git a/lib/qblog_script.ld.in b/lib/qblog_script.ld.in new file mode 100644 index 000000000..a188ac233 --- /dev/null +++ b/lib/qblog_script.ld.in @@ -0,0 +1,30 @@ +#include +/* GNU ld script + This atypical arrangement enforces global visibility of boundary symbols + (QB_ATTR_SECTION_START, QB_ATTR_SECTION_STOP) for the custom section + QB_ATTR_SECTION used for compile-time offloading of the logging call sites + tracking. While libqb relies on these being global, default linker from + binutils change the visibility as of version 2.29, making the logging + unusable without artificial stimulus: https://bugzilla.redhat.com/1477354 + + NOTE: If -lqb not usable for linking (e.g. linker not compatible with + linker scripts ad-hoc modifying output sections), try recent + ld.bfd/binutils linker first when available, otherwise you can + try "-l:libqb.so." link switch that bypasses said linker + script -- but beware, logging may be less efficient and may lack + possible future optimizations and extra features. Consequently, + logging issues (typically bound to QB_LOG_INIT_DATA macro) can be + mitigated with QB_KILL_ATTRIBUTE_SECTION macro defined for a build. + NOTE: When concerned about a warning coming from the build process like + warning: [...]libqb.so contains output sections; did you forget -T? + while it finishes OK, consider it merely a harmless side-effect. + */ +SECTIONS { +#ifdef QB_HAVE_ATTRIBUTE_SECTION + QB_ATTR_SECTION : { + QB_ATTR_SECTION_START = .; + *(QB_ATTR_SECTION); + QB_ATTR_SECTION_STOP = .; + } +#endif +} diff --git a/lib/qblog_script_noop.ld b/lib/qblog_script_noop.ld new file mode 100644 index 000000000..f037fcace --- /dev/null +++ b/lib/qblog_script_noop.ld @@ -0,0 +1 @@ +/* this is an empty linker script having a role of a NO-OP link object */ diff --git a/tests/functional/log_callsite_bench_gen.py b/tests/functional/log_callsite_bench_gen.py index d80011e20..4cb7e2968 100755 --- a/tests/functional/log_callsite_bench_gen.py +++ b/tests/functional/log_callsite_bench_gen.py @@ -112,7 +112,7 @@ def main(opts, args): width = int(floor(log10(CALLSITE_COUNT))) + 1 print('\n'.join([ - "/* compile with -lqb OR with -DQB_KILL_ATTRIBUTE_SECTION -lqb */", + "/* compile with -lqb OR with -DQB_KILL_ATTRIBUTE_SECTION -l:libqb.so.0 */", "#include ", ] + list_to_c_source(worklist, FNC_PREFIX, width) + [ "int main(int argc, char *argv[]) {", diff --git a/tests/functional/log_external/Makefile.am b/tests/functional/log_external/Makefile.am index b1b568a6d..ac0a2ea8e 100644 --- a/tests/functional/log_external/Makefile.am +++ b/tests/functional/log_external/Makefile.am @@ -36,5 +36,5 @@ log_callsite_bench_sectionfull_SOURCES = ../log_callsite_bench.c log_callsite_bench_sectionfull_LDFLAGS = -lqb log_callsite_bench_sectionless_SOURCES = ../log_callsite_bench.c -log_callsite_bench_sectionless_LDFLAGS = -lqb +log_callsite_bench_sectionless_LDFLAGS = -l:libqb.so.0 log_callsite_bench_sectionless_CPPFLAGS = -DQB_KILL_ATTRIBUTE_SECTION From c011b12fcaf093f0463901154c475905f51d783a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Pokorn=C3=BD?= Date: Fri, 6 Oct 2017 17:17:26 +0200 Subject: [PATCH 7/7] Low: fix internal object symbol's leak & expose run-time lib version MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The object in question has never been published through the header file, hence it's presumably safe to make it static as it's meant to be. On the other hand, QB_LOG_INIT_DATA macro from qblog.h has already started to depend on that symbol so as to locate the library handle for libqb itself correctly. This is trivially fixed by finally exposing library versioning info in run-time ("online") as a structure with members corresponding to compile-time ("offline") counterparts from qbconfig.h header file, which are admittedly of very limited use as opposed to the newly introduced dynamic info, plus lower-cased equivalent of QB_VER_STR. Better than to roll out a futile data object serving as an artificial anchor for the above purpose, and this was due for a while, afterall. In turn, also bump "current" and "age" of fields of the libtool's "-version-info" versioning system. Signed-off-by: Jan Pokorný --- include/qb/qbconfig.h.in | 7 ++++++- include/qb/qblog.h | 8 +++++--- include/qb/qbutil.h | 11 +++++++++++ lib/Makefile.am | 2 +- lib/log.c | 10 ++++++---- lib/log_format.c | 2 +- lib/util.c | 10 ++++++++++ tests/functional/log_client.c | 5 +++++ tests/functional/log_test_client.err | 2 +- 9 files changed, 46 insertions(+), 11 deletions(-) diff --git a/include/qb/qbconfig.h.in b/include/qb/qbconfig.h.in index c1852e12e..9094dc7d9 100644 --- a/include/qb/qbconfig.h.in +++ b/include/qb/qbconfig.h.in @@ -30,7 +30,12 @@ /* Enabling code using __attribute__((section)) */ #undef QB_HAVE_ATTRIBUTE_SECTION -/* versioning info: MAJOR, MINOR, MICRO, and REST components */ +/* versioning info: MAJOR, MINOR, MICRO, and REST components; + note that static compile-time info is not that useful as consulting + the respectively named members of qb_version struct constant under + @c qb_ver identifier (or @c qb_ver_str equivalent of the local + upper-cased value) directly from libqb in run-time (see qbutil.h), + but that was only introduced after v1.0.2 */ #undef QB_VER_MAJOR #undef QB_VER_MINOR #undef QB_VER_MICRO diff --git a/include/qb/qblog.h b/include/qb/qblog.h index 0af7d62ed..1cb63194d 100644 --- a/include/qb/qblog.h +++ b/include/qb/qblog.h @@ -299,9 +299,11 @@ extern struct qb_log_callsite QB_ATTR_SECTION_STOP[]; #define QB_NONAPI_LOG_INIT_DATA_EXTRA_(name) \ { Dl_info work_dli; \ /* libqb sanity (locating libqb by it's relatively unique \ - -- and currently only such per-linkage global one -- \ - non-functional symbol, due to possible confusion otherwise) */ \ - if (dladdr(dlsym(RTLD_DEFAULT, "facilitynames"), &work_dli) \ + non-functional symbols -- the two are mutually exclusive, the \ + ordinarily latter was introduced by accident, the former is \ + intentional -- due to possible confusion otherwise) */ \ + if ((dladdr(dlsym(RTLD_DEFAULT, "qb_ver_str"), &work_dli) \ + || dladdr(dlsym(RTLD_DEFAULT, "facilitynames"), &work_dli)) \ && (work_handle = dlopen(work_dli.dli_fname, \ RTLD_LOCAL|RTLD_LAZY)) != NULL) { \ work_s1 = (struct qb_log_callsite *) \ diff --git a/include/qb/qbutil.h b/include/qb/qbutil.h index bfce349fc..b02ce8db7 100644 --- a/include/qb/qbutil.h +++ b/include/qb/qbutil.h @@ -289,6 +289,17 @@ uint64_t qb_util_stopwatch_time_split_get(qb_util_stopwatch_t *sw, uint32_t receint, uint32_t older); +/** Structured library versioning info */ +extern const struct qb_version { + uint8_t major; /**< Major component */ + uint8_t minor; /**< Minor component */ + uint8_t micro; /**< Micro component */ + const char *rest; /**< Rest (pertaining the mid-release-point) */ +} qb_ver; + +/** Complete library versioning info as a string */ +extern const char *const qb_ver_str; + /* *INDENT-OFF* */ #ifdef __cplusplus } diff --git a/lib/Makefile.am b/lib/Makefile.am index 1572cff5f..6ca6b1518 100644 --- a/lib/Makefile.am +++ b/lib/Makefile.am @@ -30,7 +30,7 @@ AM_CPPFLAGS = -I$(top_builddir)/include -I$(top_srcdir)/include lib_LTLIBRARIES = libqb.la -libqb_la_LDFLAGS = -version-info 18:2:18 +libqb_la_LDFLAGS = -version-info 19:0:19 source_to_lint = util.c hdb.c ringbuffer.c ringbuffer_helper.c \ array.c loop.c loop_poll.c loop_job.c \ diff --git a/lib/log.c b/lib/log.c index 769087171..7cff29854 100644 --- a/lib/log.c +++ b/lib/log.c @@ -892,10 +892,12 @@ qb_log_init(const char *name, int32_t facility, uint8_t priority) #ifdef QB_HAVE_ATTRIBUTE_SECTION /* sanity check that target chain supplied QB_ATTR_SECTION_ST{ART,OP} symbols and hence the local references to them are not referencing - the proper libqb's ones (locating libqb-self by it's relatively - unique -- and currently only such per-linkage global one -- - non-functional symbol, due to possible confusion otherwise) */ - if (dladdr(dlsym(RTLD_DEFAULT, "facilitynames"), &work_dli) + the proper libqb's ones (locating libqb by it's relatively unique + non-functional symbols -- the two are mutually exclusive, the + ordinarily latter was introduced by accident, the former is + intentional -- due to possible confusion otherwise) */ + if ((dladdr(dlsym(RTLD_DEFAULT, "qb_ver_str"), &work_dli) + || dladdr(dlsym(RTLD_DEFAULT, "facilitynames"), &work_dli)) && (work_handle = dlopen(work_dli.dli_fname, RTLD_LOCAL|RTLD_LAZY)) != NULL) { work_s1 = (struct qb_log_callsite *) diff --git a/lib/log_format.c b/lib/log_format.c index 712f44756..e7e1f40bf 100644 --- a/lib/log_format.c +++ b/lib/log_format.c @@ -49,7 +49,7 @@ static struct syslog_names prioritynames[] = { {NULL, -1} }; -struct syslog_names facilitynames[] = { +static struct syslog_names facilitynames[] = { {"auth", LOG_AUTH}, #if defined(LOG_AUTHPRIV) {"authpriv", LOG_AUTHPRIV}, diff --git a/lib/util.c b/lib/util.c index 6181a2594..a510bd1c9 100644 --- a/lib/util.c +++ b/lib/util.c @@ -23,6 +23,7 @@ #include "util_int.h" #include #include +#include #include #include @@ -372,3 +373,12 @@ qb_util_stopwatch_time_split_get(qb_util_stopwatch_t *sw, } return (time_start - time_end) / QB_TIME_NS_IN_USEC; } + +const struct qb_version qb_ver = { + .major = QB_VER_MAJOR, + .minor = QB_VER_MINOR, + .micro = QB_VER_MICRO, + .rest = QB_VER_REST, +}; + +const char *const qb_ver_str = QB_VER_STR; diff --git a/tests/functional/log_client.c b/tests/functional/log_client.c index c60d6570f..d5d80890f 100644 --- a/tests/functional/log_client.c +++ b/tests/functional/log_client.c @@ -53,6 +53,11 @@ main(int32_t argc, char *argv[]) qb_log_tags_stringify_fn_set(my_tags_stringify); qb_log_format_set(QB_LOG_STDERR, "[%5g|%p] %f:%l:%b"); +#if 0 + printf("\n==%s consists of: %d, %d, %d, %s==\n\n", qb_ver_str, + qb_ver.major, qb_ver.minor, qb_ver.micro, qb_ver.rest); +#endif + #if 0 printf("--\n"); qb_log_callsites_dump(); diff --git a/tests/functional/log_test_client.err b/tests/functional/log_test_client.err index 19fca2c86..98df44ca7 100644 --- a/tests/functional/log_test_client.err +++ b/tests/functional/log_test_client.err @@ -1,2 +1,2 @@ -[MAIN |debug] ../log_client.c:64:hello +[MAIN |debug] ../log_client.c:69:hello [libqb|error] log_blackbox.c:196:qb_log_blackbox_print_from_file: