2015-08-25 Maria Guseva * csu/libc-start.c: Include hp-timing.h (LIBC_START_MAIN): Add timing and print for DL_DEBUG_CTORDTOR_TIME. * elf/Makefile (test-srcs): Add tst-ctordtor_time. (tests-special): Add tst-ctordtor_time. (tst-ctordtor_time.out): Add rule for new test. * elf/dl-fini.c: Include hp-timing.h (_dl_fini): Add timing and print for DL_DEBUG_CTORDTOR_TIME. * elf/dl-init.c: Include hp-timing.h (call_init): Add timing and print for DL_DEBUG_CTORDTOR_TIME. * elf/rtld.c (debopts): Changed len of struct fields name and helptext, add element for DL_DEBUG_CTORDTOR_TIME (process_dl_debug): Fix print for new DL_DEBUG_CTORDTOR_TIME element * elf/tst-ctordtor_time.c: New test for LD_DEBUG=ctordtor_time * elf/tst-ctordtor_time.sh: New test for LD_DEBUG=ctordtor_time * sysdeps/generic/ldsodefs.h (DL_DEBUG_CTORDTOR_TIME): New define. csu/libc-start.c | 24 +++++++++++++++++++ elf/Makefile | 9 +++++-- elf/dl-fini.c | 55 +++++++++++++++++++++++++++++++++++++++++++ elf/dl-init.c | 48 +++++++++++++++++++++++++++++++++++++ elf/rtld.c | 12 +++++++--- elf/tst-ctordtor_time.c | 41 ++++++++++++++++++++++++++++++++ elf/tst-ctordtor_time.sh | 56 ++++++++++++++++++++++++++++++++++++++++++++ sysdeps/generic/ldsodefs.h | 1 + 9 files changed, 259 insertions(+), 5 deletions(-) create mode 100644 elf/tst-ctordtor_time.c create mode 100644 elf/tst-ctordtor_time.sh diff --git a/csu/libc-start.c b/csu/libc-start.c index 0afa7c0..53ec0f5 100644 --- a/csu/libc-start.c +++ b/csu/libc-start.c @@ -21,6 +21,7 @@ #include #include #include +#include "hp-timing.h" extern void __libc_init_first (int argc, char **argv, char **envp); #ifndef SHARED @@ -242,8 +243,31 @@ LIBC_START_MAIN (int (*main) (int, char **, char ** MAIN_AUXVEC_DECL), GLRO(dl_debug_printf) ("\ninitialize program: %s\n\n", argv[0]); #endif if (init) + { +#if defined SHARED && HP_TIMING_AVAIL + hp_timing_t init_time; + hp_timing_t start_time = 0; + hp_timing_t end_time; + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + HP_TIMING_NOW (start_time); +#endif + (*init) (argc, argv, __environ MAIN_AUXVEC_PARAM); +#if defined SHARED && HP_TIMING_AVAIL + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + { + HP_TIMING_NOW (end_time); + HP_TIMING_DIFF (init_time, start_time, end_time); + char buf[200]; + HP_TIMING_PRINT (buf, sizeof (buf), init_time); + GLRO (dl_debug_printf) ("%s => %s: spent %s in init (== 0x%0*lx)\n", + argv[0], argv[0], buf, (int) sizeof (void *) * 2, + (unsigned long int) init); + } +#endif + + } #ifdef SHARED /* Auditing checkpoint: we have a new object. */ if (__glibc_unlikely (GLRO(dl_naudit) > 0)) diff --git a/elf/Makefile b/elf/Makefile index 4ceeaf8..61a313b 100644 --- a/elf/Makefile +++ b/elf/Makefile @@ -154,7 +154,7 @@ ifeq ($(build-hardcoded-path-in-tests),yes) tests += tst-dlopen-aout LDFLAGS-tst-dlopen-aout = $(no-pie-ldflag) endif -test-srcs = tst-pathopt +test-srcs = tst-pathopt tst-ctordtor_time selinux-enabled := $(shell cat /selinux/enforce 2> /dev/null) ifneq ($(selinux-enabled),1) tests-execstack-yes = tst-execstack tst-execstack-needed tst-execstack-prog @@ -285,7 +285,7 @@ tests-special += $(objpfx)order-cmp.out $(objpfx)tst-array1-cmp.out \ $(objpfx)tst-array5-static-cmp.out $(objpfx)order2-cmp.out \ $(objpfx)tst-initorder-cmp.out \ $(objpfx)tst-initorder2-cmp.out $(objpfx)tst-unused-dep.out \ - $(objpfx)tst-unused-dep-cmp.out + $(objpfx)tst-unused-dep-cmp.out $(objpfx)tst-ctordtor_time.out endif check-abi: $(objpfx)check-abi-ld.out @@ -1205,3 +1205,8 @@ $(objpfx)tst-unused-dep.out: $(objpfx)testobj1.so $(objpfx)tst-unused-dep-cmp.out: $(objpfx)tst-unused-dep.out cmp $< /dev/null > $@; \ $(evaluate-test) + +$(objpfx)tst-ctordtor_time.out: tst-ctordtor_time.sh $(objpfx)tst-ctordtor_time + $(SHELL) $< $(common-objpfx) '$(test-program-prefix-before-env)' \ + '$(run-program-env)' '$(test-program-prefix-after-env)'; \ + $(evaluate-test) diff --git a/elf/dl-fini.c b/elf/dl-fini.c index 6cfe651..4254b98 100644 --- a/elf/dl-fini.c +++ b/elf/dl-fini.c @@ -20,6 +20,7 @@ #include #include #include +#include "hp-timing.h" /* Type of the constructor functions. */ @@ -142,6 +143,11 @@ _dl_fini (void) determining the order of the modules once again from the beginning. */ struct link_map **maps = NULL; size_t maps_size = 0; +#if HP_TIMING_AVAIL + hp_timing_t fini_time; + hp_timing_t start_time = 0; + hp_timing_t end_time; +#endif /* We run the destructors of the main namespaces last. As for the other namespaces, we pick run the destructors in them in reverse @@ -249,12 +255,61 @@ _dl_fini (void) unsigned int i = (l->l_info[DT_FINI_ARRAYSZ]->d_un.d_val / sizeof (ElfW(Addr))); while (i-- > 0) + { +#if HP_TIMING_AVAIL + if (__glibc_unlikely + (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + HP_TIMING_NOW (start_time); +#endif ((fini_t) array[i]) (); +#if HP_TIMING_AVAIL + if (__glibc_unlikely + (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + { + HP_TIMING_NOW (end_time); + HP_TIMING_DIFF (fini_time, start_time, + end_time); + char buf[200]; + HP_TIMING_PRINT (buf, sizeof (buf), fini_time); + _dl_debug_printf + ("%s => %s: spent %s in .fini_array[%u] (== 0x%0*lx)\n", + DSO_FILENAME (maps[0]->l_name), + DSO_FILENAME (l->l_name), buf, i, + (int) sizeof (void *) * 2, + (unsigned long int) ((fini_t) array[i] - + l->l_addr)); + } +#endif + } } /* Next try the old-style destructor. */ if (l->l_info[DT_FINI] != NULL) + { +#if HP_TIMING_AVAIL + if (__glibc_unlikely + (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + HP_TIMING_NOW (start_time); +#endif DL_CALL_DT_FINI(l, l->l_addr + l->l_info[DT_FINI]->d_un.d_ptr); +#if HP_TIMING_AVAIL + if (__glibc_unlikely + (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + { + HP_TIMING_NOW (end_time); + HP_TIMING_DIFF (fini_time, start_time, end_time); + char buf[200]; + HP_TIMING_PRINT (buf, sizeof (buf), fini_time); + _dl_debug_printf + ("%s => %s: spent %s in .fini (== 0x%0*lx)\n", + DSO_FILENAME (maps[0]->l_name), + DSO_FILENAME (l->l_name), buf, + (int) sizeof (void *) * 2, + (unsigned long int) (l->l_info[DT_FINI]->d_un. + d_ptr)); + } +#endif + } } #ifdef SHARED diff --git a/elf/dl-init.c b/elf/dl-init.c index 2f85731..1c6a899 100644 --- a/elf/dl-init.c +++ b/elf/dl-init.c @@ -18,6 +18,7 @@ #include #include +#include "hp-timing.h" /* Type of the initializer. */ @@ -27,6 +28,11 @@ typedef void (*init_t) (int, char **, char **); static void call_init (struct link_map *l, int argc, char **argv, char **env) { +#if HP_TIMING_AVAIL + hp_timing_t init_time; + hp_timing_t start_time = 0; + hp_timing_t end_time; +#endif if (l->l_init_called) /* This object is all done. */ return; @@ -55,7 +61,27 @@ call_init (struct link_map *l, int argc, char **argv, char **env) - the others in the DT_INIT_ARRAY. */ if (l->l_info[DT_INIT] != NULL) + { +#if HP_TIMING_AVAIL + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + HP_TIMING_NOW (start_time); +#endif DL_CALL_DT_INIT(l, l->l_addr + l->l_info[DT_INIT]->d_un.d_ptr, argc, argv, env); +#if HP_TIMING_AVAIL + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + { + HP_TIMING_NOW (end_time); + HP_TIMING_DIFF (init_time, start_time, end_time); + char buf[200]; + HP_TIMING_PRINT (buf, sizeof (buf), init_time); + _dl_debug_printf ("%s => %s: spent %s in .init (== 0x%0*lx)\n", + argv[0], DSO_FILENAME (l->l_name), buf, + (int) sizeof (void *) * 2, + (unsigned long int) (l->l_info[DT_INIT]->d_un. + d_ptr)); + } +#endif + } /* Next see whether there is an array with initialization functions. */ ElfW(Dyn) *init_array = l->l_info[DT_INIT_ARRAY]; @@ -69,7 +95,29 @@ call_init (struct link_map *l, int argc, char **argv, char **env) addrs = (ElfW(Addr) *) (init_array->d_un.d_ptr + l->l_addr); for (j = 0; j < jm; ++j) + { +#if HP_TIMING_AVAIL + if (__glibc_unlikely + (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + HP_TIMING_NOW (start_time); +#endif ((init_t) addrs[j]) (argc, argv, env); +#if HP_TIMING_AVAIL + if (__glibc_unlikely + (GLRO (dl_debug_mask) & DL_DEBUG_CTORDTOR_TIME)) + { + HP_TIMING_NOW (end_time); + HP_TIMING_DIFF (init_time, start_time, end_time); + char buf[200]; + HP_TIMING_PRINT (buf, sizeof (buf), init_time); + _dl_debug_printf + ("%s => %s: spent %s in .init_array[%u] (== 0x%0*lx)\n", + argv[0], DSO_FILENAME (l->l_name), buf, j, + (int) sizeof (void *) * 2, + (unsigned long int) (addrs[j] - l->l_addr)); + } +#endif + } } } diff --git a/elf/rtld.c b/elf/rtld.c index 69873c2..2b8ac5e 100644 --- a/elf/rtld.c +++ b/elf/rtld.c @@ -2213,8 +2213,8 @@ process_dl_debug (const char *dl_debug) static const struct { unsigned char len; - const char name[10]; - const char helptext[41]; + const char name[16]; + const char helptext[44]; unsigned short int mask; } debopts[] = { @@ -2241,6 +2241,12 @@ process_dl_debug (const char *dl_debug) DL_DEBUG_STATISTICS }, { LEN_AND_STR ("unused"), "determined unused DSOs", DL_DEBUG_UNUSED }, + // The "ctordtor_time" works only when HP_TIMING is available +#if HP_TIMING_AVAIL + { LEN_AND_STR ("ctordtor_time"), + "display constructors/destructors statistics", + DL_DEBUG_CTORDTOR_TIME }, +#endif { LEN_AND_STR ("help"), "display this help message and exit", DL_DEBUG_HELP }, }; @@ -2300,7 +2306,7 @@ Valid options for the LD_DEBUG environment variable are:\n\n"); for (cnt = 0; cnt < ndebopts; ++cnt) _dl_printf (" %.*s%s%s\n", debopts[cnt].len, debopts[cnt].name, - " " + debopts[cnt].len - 3, + " " + debopts[cnt].len - 3, debopts[cnt].helptext); _dl_printf ("\n\ diff --git a/elf/tst-ctordtor_time.c b/elf/tst-ctordtor_time.c new file mode 100644 index 0000000..de4a085 --- /dev/null +++ b/elf/tst-ctordtor_time.c @@ -0,0 +1,41 @@ +/* Test for LD_DEBUG=ctordtor_time option. + + Copyright (C) 2004-2014 Free Software Foundation, Inc. + This file is part of the GNU C Library. + Contributed by Ulrich Drepper , 2004. + + The GNU C Library 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. + + The GNU C Library 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 the GNU C Library; if not, see + . */ +#include +#include + +__attribute__ ((constructor)) + static void main_ctor_func (void) +{ + printf ("\nfunction main_ctor_func invoked\n"); + fflush (0); +} + +__attribute__ ((destructor)) + static void main_dtor_func (void) +{ + printf ("\nfunction main_dtor_func invoked\n"); + fflush (0); +} + +int +main (void) +{ + return 0; +} diff --git a/elf/tst-ctordtor_time.sh b/elf/tst-ctordtor_time.sh new file mode 100644 index 0000000..322b69b --- /dev/null +++ b/elf/tst-ctordtor_time.sh @@ -0,0 +1,56 @@ +#! /bin/sh +# Test for LD_DEBUG=ctordtor_time option. +# +# Copyright (C) 2015 Free Software Foundation, Inc. +# This file is part of the GNU C Library. + +# The GNU C Library 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. + +# The GNU C Library 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 the GNU C Library; if not, see +# . + +set -o pipefail +common_objpfx=$1 +test_program_prefix_before_env=$2 +run_program_env=$3 +test_program_prefix_after_env=$4 + +TEST="tst-ctordtor_time" +CTOR_OUTPUT="function main_ctor_func invoked" +DTOR_OUTPUT="function main_dtor_func invoked" + +${test_program_prefix_before_env} ${run_program_env} LD_DEBUG=help ${test_program_prefix_after_env} ${common_objpfx}elf/$TEST >${common_objpfx}elf/$TEST.out 2>&1 +grep "ctordtor_time" ${common_objpfx}elf/$TEST.out -wq +if test $? -ne 0; then + echo "***LD_DEBUG=ctordtor_time is not supported on this platform" + exit 0 +fi + +${test_program_prefix_before_env} ${run_program_env} LD_DEBUG=ctordtor_time ${test_program_prefix_after_env} ${common_objpfx}elf/$TEST >>${common_objpfx}elf/$TEST.out 2>&1; status=$? +if test $status -ne 0; then + echo "***Failed to run ${common_objpfx}elf/$TEST" + exit $status +fi + +sed -n -e "/$CTOR_OUTPUT/,+1p" ${common_objpfx}elf/$TEST.out | sed -n '2p' | grep "[0-9]\+:\s${common_objpfx}elf/$TEST => ${common_objpfx}elf/$TEST: spent [0-9]\+ cycles in init (== 0x[0-9a-fA-F]\+)$" -q; status=$? +if test $status -ne 0; then + echo "***LD_DEBUG=ctordtor_time log for constructor is not found in output" + exit $status +fi + +sed -n -e "/$DTOR_OUTPUT/,+1p" ${common_objpfx}elf/$TEST.out | sed -n '2p' | grep "[0-9]\+:\s${common_objpfx}elf/$TEST => ${common_objpfx}elf/$TEST: spent [0-9]\+ cycles in .fini_array\[[0-9]\+\] (== 0x[0-9a-fA-F]\+)$" -q; status=$? +if test $status -ne 0; then + echo "***LD_DEBUG=ctordtor_time log for destructor is not found in output" + exit $status +fi + +exit 0 diff --git a/sysdeps/generic/ldsodefs.h b/sysdeps/generic/ldsodefs.h index 7a0fe8d..bb46504 100644 --- a/sysdeps/generic/ldsodefs.h +++ b/sysdeps/generic/ldsodefs.h @@ -462,6 +462,7 @@ struct rtld_global_ro /* These two are used only internally. */ #define DL_DEBUG_HELP (1 << 10) #define DL_DEBUG_PRELINK (1 << 11) +#define DL_DEBUG_CTORDTOR_TIME (1 << 12) /* OS version. */ EXTERN unsigned int _dl_osversion; -- 1.7.9.5