From debbugs-submit-bounces@debbugs.gnu.org Mon Jun 15 16:11:19 2015 Received: (at 20816) by debbugs.gnu.org; 15 Jun 2015 20:11:19 +0000 Received: from localhost ([127.0.0.1]:55006 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.80) (envelope-from ) id 1Z4aix-00067V-7i for submit@debbugs.gnu.org; Mon, 15 Jun 2015 16:11:19 -0400 Received: from eggs.gnu.org ([208.118.235.92]:56846) by debbugs.gnu.org with esmtp (Exim 4.80) (envelope-from ) id 1Z4air-00067D-5o for 20816@debbugs.gnu.org; Mon, 15 Jun 2015 16:11:13 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1Z4aie-0006VN-8P for 20816@debbugs.gnu.org; Mon, 15 Jun 2015 16:11:03 -0400 X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on eggs.gnu.org X-Spam-Level: X-Spam-Status: No, score=0.3 required=5.0 tests=BAYES_50,RP_MATCHES_RCVD autolearn=disabled version=3.3.2 Received: from fencepost.gnu.org ([2001:4830:134:3::e]:60302) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Z4aid-0005je-LU; Mon, 15 Jun 2015 16:10:55 -0400 Received: from reverse-83.fdn.fr ([80.67.176.83]:47761 helo=pluto) by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_128_CBC_SHA1:128) (Exim 4.82) (envelope-from ) id 1Z4aaq-0004pX-SQ; Mon, 15 Jun 2015 16:02:53 -0400 From: ludo@gnu.org (Ludovic =?utf-8?Q?Court=C3=A8s?=) To: Mark H Weaver Subject: Re: bug#20816: Excessive negative cache time for DNS lookups References: <87si9titcm.fsf@netris.org> X-URL: http://www.fdn.fr/~lcourtes/ X-Revolutionary-Date: 27 Prairial an 223 de la =?utf-8?Q?R=C3=A9volution?= X-PGP-Key-ID: 0x3D9AEBB5 X-PGP-Key: http://www.fdn.fr/~lcourtes/ludovic.asc X-PGP-Fingerprint: 3CE4 6455 8A84 FDC6 9DB4 0CFB 090B 1199 3D9A EBB5 X-OS: x86_64-unknown-linux-gnu Date: Mon, 15 Jun 2015 22:02:50 +0200 Message-ID: <874mm891ud.fsf@inria.fr> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/24.5 (gnu/linux) MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" X-detected-operating-system: by eggs.gnu.org: Error: Malformed IPv6 address (bad octet value). X-Received-From: 2001:4830:134:3::e X-Spam-Score: -5.5 (-----) X-Debbugs-Envelope-To: 20816 Cc: 20816@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.15 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -5.5 (-----) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Mark H Weaver skribis: > On my GuixSD system, DNS lookup failures (due to lack of network) are > cached for at least 4 minutes, and possibly much longer (I've not had > the patience to wait until it expires). > > Even after restarting nscd, the negative cache entry persists for about > another 20 seconds. To reproduce it, I ran =E2=80=98guix system vm=E2=80=99 on this: --8<---------------cut here---------------start------------->8--- (use-modules (gnu) (guix)) (use-package-modules base) (operating-system (host-name "komputilo") (timezone "Europe/Berlin") (locale "en_US.UTF-8") (bootloader (grub-configuration (device "/dev/sdX"))) (file-systems (cons (file-system (device "root") (title 'label) (mount-point "/") (type "ext4")) %base-file-systems)) (packages (cons* (canonical-package glibc) %base-packages)) (services (map (lambda (mservice) (mlet %store-monad ((service mservice)) (if (memq 'nscd (service-provision service)) (nscd-service (nscd-configuration (debug-level 10))) mservice))) %base-services))) --8<---------------cut here---------------end--------------->8--- Then I had one console running =E2=80=9Ctail -f /var/log/nscd.log=E2=80=9D,= and another one where I would run =E2=80=9Cping www.gnu.org.=E2=80=9D Initially looking up www.gnu.org fails (because the network is down), and nscd.log indeed shows: --8<---------------cut here---------------start------------->8--- Mon Jun 15 21:04:20 2015 - 276: handle_request: request received (Version = =3D 2) from PID 296 Mon Jun 15 21:04:20 2015 - 276: GETAI (www.gnu.org) Mon Jun 15 21:04:20 2015 - 276: Haven't found "www.gnu.org" in hosts cache! Mon Jun 15 21:04:20 2015 - 276: add new entry "www.gnu.org" of type GETAI f= or hosts to cache (first) --8<---------------cut here---------------end--------------->8--- For subsequent requests, it shows fewer details, meaning that the cached failure is used: --8<---------------cut here---------------start------------->8--- Mon Jun 15 21:04:25 2015 - 276: handle_request: request received (Version = =3D 2) from PID 297 Mon Jun 15 21:04:25 2015 - 276: GETFDHST Mon Jun 15 21:04:25 2015 - 276: provide access to FD 6, for hosts --8<---------------cut here---------------end--------------->8--- Twenty seconds after the original failure, we see: --8<---------------cut here---------------start------------->8--- Mon Jun 15 21:04:40 2015 - 276: pruning hosts cache; time 1434395080 Mon Jun 15 21:04:40 2015 - 276: considering GETAI entry "www.gnu.org", time= out 1434395080 --8<---------------cut here---------------end--------------->8--- So cache expiry seems to be working as expected. Now, if we enable networking with =E2=80=9Cdhclient -v eth0=E2=80=9D and se= e what happens, we get again a series of lookup failures, even after the www.gnu.org entry has been removed from cache; apparently new failures get cached. Eventually, after a bunch of cache prunes (so a few times 20 seconds), lookup succeeds. The situation is different if you use =E2=80=98getent hosts=E2=80=99 instea= d of =E2=80=98ping=E2=80=99=E2=80=93 note that the latter uses getaddrinfo whereas the former uses gethostbyname{,v6}, which is cached differently. Here we get a successful lookup within 20 seconds after networking has been put up. So my guess is that the GETAI cache is racy or something. I=E2=80=99ve run nscd with Helgrind, which reports a few things (see attach= ed file), but I suspect most of it are false positives. Ludo=E2=80=99. --=-=-= Content-Type: text/plain Content-Disposition: attachment; filename=vg.log Content-Description: Helgrind log ==336== Helgrind, a thread error detector ==336== Copyright (C) 2007-2013, and GNU GPL'd, by OpenWorks LLP et al. ==336== Using Valgrind-3.10.1 and LibVEX; rerun with -h for copyright info ==336== Command: nscd -f /gnu/store/8mhn4b3r0pg18lycwnnn9ms5jwr9wvfm-nscd.conf ==336== Parent PID: 291 ==336== ==337== Warning: invalid file descriptor 1024 in syscall close() ==337== Warning: invalid file descriptor 1025 in syscall close() ==337== Warning: invalid file descriptor 1026 in syscall close() ==337== Warning: invalid file descriptor 1027 in syscall close() ==337== Use --log-fd= to select an alternative log fd. ==337== Warning: invalid file descriptor 1028 in syscall close() ==337== Warning: invalid file descriptor 1029 in syscall close() ==336== ==336== For counts of detected and suppressed errors, rerun with: -v ==336== Use --history-level=approx or =none to gain increased speed, at ==336== the cost of reduced accuracy of conflicting-access information ==336== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0) ==337== ---Thread-Announcement------------------------------------------ ==337== ==337== Thread #1 is the program's root thread ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Thread #1: pthread_cond_{signal,broadcast}: dubious: associated lock is not held by any thread ==337== at 0x4C2A963: pthread_cond_signal_WRK (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4C2E18C: pthread_cond_signal@* (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x10E89A: fd_ready (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10F81E: main_loop_epoll (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x111E57: start_threads (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10D79D: main (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== ==337== ---Thread-Announcement------------------------------------------ ==337== ==337== Thread #7 was created ==337== at 0x5352E9E: clone (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libc-2.21.so) ==337== by 0x4E3E1D7: create_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x4E3FBB4: pthread_create@@GLIBC_2.2.5 (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x4C2C55B: pthread_create_WRK (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4C2D49B: pthread_create@* (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x111DD7: start_threads (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10D79D: main (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Thread #7: pthread_cond_{signal,broadcast}: dubious: associated lock is not held by any thread ==337== at 0x4C2A963: pthread_cond_signal_WRK (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4C2E18C: pthread_cond_signal@* (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x118A9C: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11AD6D: addhstaiX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11BB43: addhstai (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF76: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== ---Thread-Announcement------------------------------------------ ==337== ==337== Thread #4 was created ==337== at 0x5352E9E: clone (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libc-2.21.so) ==337== by 0x4E3E1D7: create_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x4E3FBB4: pthread_create@@GLIBC_2.2.5 (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x4C2C55B: pthread_create_WRK (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4C2D49B: pthread_create@* (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x111DD7: start_threads (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10D79D: main (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== ==337== ---Thread-Announcement------------------------------------------ ==337== ==337== Thread #5 was created ==337== at 0x5352E9E: clone (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libc-2.21.so) ==337== by 0x4E3E1D7: create_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x4E3FBB4: pthread_create@@GLIBC_2.2.5 (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x4C2C55B: pthread_create_WRK (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4C2D49B: pthread_create@* (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x111DD7: start_threads (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10D79D: main (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Possible data race during read of size 1 at 0x329990 by thread #4 ==337== Locks held: none ==337== at 0x115CDA: getservbyname_r (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116198: lookup (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C36: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous write of size 1 by thread #5 ==337== Locks held: none ==337== at 0x115E6E: getservbyname_r (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116198: lookup (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C36: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x329990 is 0 bytes inside data symbol "startp_initialized.11280" ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Possible data race during read of size 8 at 0x329980 by thread #4 ==337== Locks held: none ==337== at 0x115CF0: getservbyname_r (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116198: lookup (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C36: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous write of size 8 by thread #5 ==337== Locks held: none ==337== at 0x115E4E: getservbyname_r (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116198: lookup (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C36: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x329980 is 0 bytes inside data symbol "start_fct.11282" ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Possible data race during read of size 8 at 0x329988 by thread #4 ==337== Locks held: none ==337== at 0x115CF7: getservbyname_r (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116198: lookup (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C36: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous write of size 8 by thread #5 ==337== Locks held: none ==337== at 0x115E67: getservbyname_r (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116198: lookup (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C36: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x329988 is 0 bytes inside data symbol "startp.11281" ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Lock at 0x3295F0 was first observed ==337== at 0x4C2D7E9: pthread_mutex_init (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x110927: nscd_init (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10D798: main (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== Address 0x3295f0 is 1392 bytes inside data symbol "dbs" ==337== ==337== Possible data race during write of size 4 at 0x8449030 by thread #4 ==337== Locks held: 1, at address 0x3295F0 ==337== at 0x11A64A: mempool_alloc (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11692F: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous read of size 4 by thread #5 ==337== Locks held: none ==337== at 0x4E46C1D: ??? (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x1169BE: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x8449030 is not stack'd, malloc'd or on a free list ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Thread #5: pthread_cond_{signal,broadcast}: dubious: associated lock is not held by any thread ==337== at 0x4C2A963: pthread_cond_signal_WRK (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4C2E18C: pthread_cond_signal@* (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x118A9C: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116868: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Lock at 0x3295F0 was first observed ==337== at 0x4C2D7E9: pthread_mutex_init (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x110927: nscd_init (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10D798: main (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== Address 0x3295f0 is 1392 bytes inside data symbol "dbs" ==337== ==337== Possible data race during write of size 4 at 0x8449030 by thread #4 ==337== Locks held: 1, at address 0x3295F0 ==337== at 0x11A64A: mempool_alloc (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x118967: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11661C: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous read of size 4 by thread #5 ==337== Locks held: none ==337== at 0x118999: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116868: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x8449030 is not stack'd, malloc'd or on a free list ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Possible data race during write of size 8 at 0x8449050 by thread #4 ==337== Locks held: none ==337== at 0x118A0B: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11661C: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous read of size 8 by thread #5 ==337== Locks held: none ==337== at 0x4E46C1D: ??? (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== by 0x118AC1: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116868: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x8449050 is not stack'd, malloc'd or on a free list ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Possible data race during read of size 4 at 0x8449038 by thread #4 ==337== Locks held: none ==337== at 0x118A17: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11661C: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous write of size 4 by thread #5 ==337== Locks held: none ==337== at 0x118A23: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116868: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x8449038 is not stack'd, malloc'd or on a free list ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Possible data race during write of size 4 at 0x8449038 by thread #4 ==337== Locks held: none ==337== at 0x118A23: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11661C: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== This conflicts with a previous write of size 4 by thread #5 ==337== Locks held: none ==337== at 0x118A23: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116868: cache_addserv (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116C70: addservbyX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x116D33: addservbyname (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF40: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== Address 0x8449038 is not stack'd, malloc'd or on a free list ==337== ==337== ---------------------------------------------------------------- ==337== ==337== Thread #4: pthread_cond_{signal,broadcast}: dubious: associated lock is not held by any thread ==337== at 0x4C2A963: pthread_cond_signal_WRK (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4C2E18C: pthread_cond_signal@* (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x118A9C: cache_add (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11AD6D: addhstaiX (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x11BB43: addhstai (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x10FF76: nscd_run_worker (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/sbin/nscd) ==337== by 0x4C2C6E1: mythread_wrapper (in /gnu/store/apnmjac0aa0q6y78ynvasmlkljdfjcxv-valgrind-3.10.1/lib/valgrind/vgpreload_helgrind-amd64-linux.so) ==337== by 0x4E3F463: start_thread (in /gnu/store/hy2hi0zj5hrqkmkhpdxf04c9bcnlnsf9-glibc-2.21/lib/libpthread-2.21.so) ==337== ==337== ==337== For counts of detected and suppressed errors, rerun with: -v ==337== Use --history-level=approx or =none to gain increased speed, at ==337== the cost of reduced accuracy of conflicting-access information ==337== ERROR SUMMARY: 124 errors from 12 contexts (suppressed: 14313 from 349) --=-=-=--