NetBSD Problem Report #52701
From gson@gson.org Sun Nov 5 13:33:59 2017
Return-Path: <gson@gson.org>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
by mollari.NetBSD.org (Postfix) with ESMTPS id 8C4647A1CD
for <gnats-bugs@gnats.NetBSD.org>; Sun, 5 Nov 2017 13:33:59 +0000 (UTC)
Message-Id: <20171105133353.07298989E67@guava.gson.org>
Date: Sun, 5 Nov 2017 15:33:53 +0200 (EET)
From: gson@gson.org (Andreas Gustafsson)
Reply-To: gson@gson.org (Andreas Gustafsson)
To: gnats-bugs@NetBSD.org
Subject: rtadvd logs thousands of syslog messages
X-Send-Pr-Version: 3.95
>Number: 52701
>Category: bin
>Synopsis: rtadvd logs thousands of syslog messages
>Confidential: no
>Severity: serious
>Priority: medium
>Responsible: bin-bug-people
>State: open
>Class: sw-bug
>Submitter-Id: net
>Arrival-Date: Sun Nov 05 13:35:00 +0000 2017
>Closed-Date:
>Last-Modified: Thu Feb 08 08:38:53 +0000 2018
>Originator: Andreas Gustafsson
>Release: NetBSD-current, source date >= 2017.02.28.04.47.41
>Organization:
>Environment:
System: NetBSD
Architecture: i386
Machine: i386
>Description:
While reviewing console output logs from the test runs on the TNF
testbed in the course of investigating an unrelated bug, I noticed
that some of the logs included messages like the following:
Nov 2 18:40:30 syslogd[189]: last message repeated 78108 times
Nov 2 18:50:30 syslogd[189]: last message repeated 116025 times
Nov 2 19:00:30 syslogd[189]: last message repeated 112322 times
Nov 2 19:10:30 syslogd[189]: last message repeated 111487 times
Nov 2 19:20:31 syslogd[189]: last message repeated 119638 times
Nov 2 19:30:31 syslogd[189]: last message repeated 113491 times
Nov 2 19:40:31 syslogd[189]: last message repeated 112569 times
Nov 2 19:50:31 syslogd[189]: last message repeated 112543 times
Nov 2 20:00:33 syslogd[189]: last message repeated 133812 times
Nov 2 20:10:33 syslogd[189]: last message repeated 137892 times
Nov 2 20:20:33 syslogd[189]: last message repeated 144270 times
Nov 2 20:30:34 syslogd[189]: last message repeated 140495 times
Nov 2 20:40:34 syslogd[189]: last message repeated 135550 times
Nov 2 20:50:34 syslogd[189]: last message repeated 139106 times
Nov 2 21:00:34 syslogd[189]: last message repeated 139265 times
These particular ones are are from
http://releng.netbsd.org/b5reports/i386/build/2017.11.01.21.13.26/test.log
As far as I can tell from the log, the message being repeated is:
Nov 2 11:09:07 rtadvd[1478]: main: poll: Socket is not connected
The messages first appeared in February, in
http://releng.netbsd.org/b5reports/i386/build/2017.02.28.04.47.41/test.log
but since they do not appear in every test run, this does not identify
the exact commit that triggered the problem.
>How-To-Repeat:
>Fix:
>Release-Note:
>Audit-Trail:
From: "J. Hannken-Illjes" <hannken@eis.cs.tu-bs.de>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: bin/52701: rtadvd logs thousands of syslog messages
Date: Sun, 5 Nov 2017 15:48:07 +0100
--Apple-Mail=_D998CD31-DB37-4159-9C9D-F768E4B92A7D
Content-Transfer-Encoding: 7bit
Content-Type: text/plain;
charset=us-ascii
For some time I have this local change and it helped me a lot.
--
J. Hannken-Illjes - hannken@eis.cs.tu-bs.de - TU Braunschweig (Germany)
--Apple-Mail=_D998CD31-DB37-4159-9C9D-F768E4B92A7D
Content-Disposition: attachment;
filename=t_ra.diff
Content-Type: application/octet-stream;
x-unix-mode=0644;
name="t_ra.diff"
Content-Transfer-Encoding: 7bit
Index: t_ra.sh
===================================================================
RCS file: /cvsroot/src/tests/net/ndp/t_ra.sh,v
retrieving revision 1.29
diff -p -u -2 -r1.29 t_ra.sh
--- t_ra.sh 22 Jun 2017 09:56:48 -0000 1.29
+++ t_ra.sh 5 Nov 2017 14:46:30 -0000
@@ -288,4 +288,8 @@ ra_flush_prefix_entries_cleanup()
{
+ if [ -f ${PIDFILE} ]; then
+ kill -TERM `cat ${PIDFILE}`
+ wait_term ${PIDFILE}
+ fi
$DEBUG && dump
cleanup
@@ -345,4 +349,8 @@ ra_flush_defrouter_entries_cleanup()
{
+ if [ -f ${PIDFILE} ]; then
+ kill -TERM `cat ${PIDFILE}`
+ wait_term ${PIDFILE}
+ fi
$DEBUG && dump
cleanup
@@ -772,4 +780,8 @@ ra_defrouter_expiration_cleanup()
{
+ if [ -f ${PIDFILE} ]; then
+ kill -TERM `cat ${PIDFILE}`
+ wait_term ${PIDFILE}
+ fi
$DEBUG && dump
cleanup
@@ -837,4 +849,8 @@ ra_prefix_expiration_cleanup()
{
+ if [ -f ${PIDFILE} ]; then
+ kill -TERM `cat ${PIDFILE}`
+ wait_term ${PIDFILE}
+ fi
$DEBUG && dump
cleanup
--Apple-Mail=_D998CD31-DB37-4159-9C9D-F768E4B92A7D--
From: "Ryota Ozaki" <ozaki-r@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/52701 CVS commit: src/tests/net/ndp
Date: Mon, 6 Nov 2017 10:51:40 +0000
Module Name: src
Committed By: ozaki-r
Date: Mon Nov 6 10:51:40 UTC 2017
Modified Files:
src/tests/net/ndp: t_ra.sh
Log Message:
Kill rtadvd surely even if the tests fail in the middle
It may help PR bin/52701.
To generate a diff of this commit:
cvs rdiff -u -r1.29 -r1.30 src/tests/net/ndp/t_ra.sh
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
From: Ryota Ozaki <ozaki-r@netbsd.org>
To: "gnats-bugs@NetBSD.org" <gnats-bugs@netbsd.org>
Cc: gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
Andreas Gustafsson <gson@gson.org>
Subject: Re: bin/52701: rtadvd logs thousands of syslog messages
Date: Mon, 6 Nov 2017 19:58:55 +0900
On Sun, Nov 5, 2017 at 11:50 PM, J. Hannken-Illjes
<hannken@eis.cs.tu-bs.de> wrote:
> The following reply was made to PR bin/52701; it has been noted by GNATS.
>
> From: "J. Hannken-Illjes" <hannken@eis.cs.tu-bs.de>
> To: gnats-bugs@NetBSD.org
> Cc:
> Subject: Re: bin/52701: rtadvd logs thousands of syslog messages
> Date: Sun, 5 Nov 2017 15:48:07 +0100
>
> --Apple-Mail=_D998CD31-DB37-4159-9C9D-F768E4B92A7D
> Content-Transfer-Encoding: 7bit
> Content-Type: text/plain;
> charset=us-ascii
>
> For some time I have this local change and it helped me a lot.
Thanks. I added similar cleanup codes to the tests.
I think that the real fix is to suppress rtadvd on a rump kernel
from dumping logs to the host, but I have no idea how to do it.
ozaki-r
>
> --
> J. Hannken-Illjes - hannken@eis.cs.tu-bs.de - TU Braunschweig (Germany)
>
> --Apple-Mail=_D998CD31-DB37-4159-9C9D-F768E4B92A7D
> Content-Disposition: attachment;
> filename=t_ra.diff
> Content-Type: application/octet-stream;
> x-unix-mode=0644;
> name="t_ra.diff"
> Content-Transfer-Encoding: 7bit
>
> Index: t_ra.sh
> ===================================================================
> RCS file: /cvsroot/src/tests/net/ndp/t_ra.sh,v
> retrieving revision 1.29
> diff -p -u -2 -r1.29 t_ra.sh
> --- t_ra.sh 22 Jun 2017 09:56:48 -0000 1.29
> +++ t_ra.sh 5 Nov 2017 14:46:30 -0000
> @@ -288,4 +288,8 @@ ra_flush_prefix_entries_cleanup()
> {
>
> + if [ -f ${PIDFILE} ]; then
> + kill -TERM `cat ${PIDFILE}`
> + wait_term ${PIDFILE}
> + fi
> $DEBUG && dump
> cleanup
> @@ -345,4 +349,8 @@ ra_flush_defrouter_entries_cleanup()
> {
>
> + if [ -f ${PIDFILE} ]; then
> + kill -TERM `cat ${PIDFILE}`
> + wait_term ${PIDFILE}
> + fi
> $DEBUG && dump
> cleanup
> @@ -772,4 +780,8 @@ ra_defrouter_expiration_cleanup()
> {
>
> + if [ -f ${PIDFILE} ]; then
> + kill -TERM `cat ${PIDFILE}`
> + wait_term ${PIDFILE}
> + fi
> $DEBUG && dump
> cleanup
> @@ -837,4 +849,8 @@ ra_prefix_expiration_cleanup()
> {
>
> + if [ -f ${PIDFILE} ]; then
> + kill -TERM `cat ${PIDFILE}`
> + wait_term ${PIDFILE}
> + fi
> $DEBUG && dump
> cleanup
>
> --Apple-Mail=_D998CD31-DB37-4159-9C9D-F768E4B92A7D--
>
From: "Ryota Ozaki" <ozaki-r@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/52701 CVS commit: src/tests/net/ndp
Date: Tue, 7 Nov 2017 02:19:23 +0000
Module Name: src
Committed By: ozaki-r
Date: Tue Nov 7 02:19:23 UTC 2017
Modified Files:
src/tests/net/ndp: t_ra.sh
Log Message:
Let rtadvd not use syslog for logging
Thanks to christos@ now rtadvd can log via stderr instead of syslog
by -D option.
Address PR bin/52701
To generate a diff of this commit:
cvs rdiff -u -r1.30 -r1.31 src/tests/net/ndp/t_ra.sh
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
From: "Martin Husemann" <martin@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/52701 CVS commit: [netbsd-8] src
Date: Tue, 21 Nov 2017 10:54:19 +0000
Module Name: src
Committed By: martin
Date: Tue Nov 21 10:54:19 UTC 2017
Modified Files:
src/tests/net/ndp [netbsd-8]: t_ra.sh
src/usr.sbin/rtadvd [netbsd-8]: advcap.c config.c dump.c if.c rrenum.c
rtadvd.8 rtadvd.c timer.c
Added Files:
src/usr.sbin/rtadvd [netbsd-8]: logit.h
Log Message:
Pull up following revision(s) (requested by ozaki-r in ticket #358):
usr.sbin/rtadvd/rtadvd.c: revision 1.54-1.58
usr.sbin/rtadvd/config.c: revision 1.37
usr.sbin/rtadvd/if.c: revision 1.25
usr.sbin/rtadvd/dump.c: revision 1.15
usr.sbin/rtadvd/rrenum.c: revision 1.20
usr.sbin/rtadvd/logit.h: revision 1.1
usr.sbin/rtadvd/rtadvd.8: revision 1.26
tests/net/ndp/t_ra.sh: revision 1.30
usr.sbin/rtadvd/timer.c: revision 1.14
tests/net/ndp/t_ra.sh: revision 1.31
usr.sbin/rtadvd/advcap.c: revision 1.17
KNF, fix time printing formats.
Don't start another copy of rtadvd if one is running.
PR/52618: Shinichi Doyashiki: Don't exit if adding interface to multicast
group fails. This happens with empty vlan interfaces
- make syscalls checks against -1
- fix errors to print %s: instead of <%s>
XXX: if_vlan is the only pseudo interface in net/ that returns such an
error..
Kill rtadvd surely even if the tests fail in the middle
It may help PR bin/52701.
Change the meaning of the D flag to print errors to stderr instead of
syslog(3) and exit if poll(2) fails (intended to be used with unit-tests).
Mark expandm as preserving format strings.
Let rtadvd not use syslog for logging
Thanks to christos@ now rtadvd can log via stderr instead of syslog
by -D option.
Address PR bin/52701
To generate a diff of this commit:
cvs rdiff -u -r1.27.2.1 -r1.27.2.2 src/tests/net/ndp/t_ra.sh
cvs rdiff -u -r1.16 -r1.16.8.1 src/usr.sbin/rtadvd/advcap.c
cvs rdiff -u -r1.36 -r1.36.4.1 src/usr.sbin/rtadvd/config.c
cvs rdiff -u -r1.14 -r1.14.8.1 src/usr.sbin/rtadvd/dump.c
cvs rdiff -u -r1.24 -r1.24.8.1 src/usr.sbin/rtadvd/if.c
cvs rdiff -u -r0 -r1.1.2.2 src/usr.sbin/rtadvd/logit.h
cvs rdiff -u -r1.19 -r1.19.8.1 src/usr.sbin/rtadvd/rrenum.c
cvs rdiff -u -r1.25 -r1.25.6.1 src/usr.sbin/rtadvd/rtadvd.8
cvs rdiff -u -r1.53 -r1.53.4.1 src/usr.sbin/rtadvd/rtadvd.c
cvs rdiff -u -r1.13 -r1.13.8.1 src/usr.sbin/rtadvd/timer.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
State-Changed-From-To: open->feedback
State-Changed-By: ozaki-r@NetBSD.org
State-Changed-When: Wed, 22 Nov 2017 02:03:59 +0000
State-Changed-Why:
Fixed in -current and -8. Let me know if the issue still happens.
From: Andreas Gustafsson <gson@gson.org>
To: gnats-bugs@NetBSD.org
Cc: ozaki-r@NetBSD.org
Subject: Re: bin/52701 (rtadvd logs thousands of syslog messages)
Date: Sat, 20 Jan 2018 23:11:56 +0200
On Nov 22, 2017, ozaki-r@NetBSD.org wrote:
> Fixed in -current and -8. Let me know if the issue still happens.
I can confirm that the syslog messages no longer occur.
However, since the volume of messages suggests that rtadvd got into
some kind of busy-loop, and the fixes involved redirecting log
messages away from syslog and killing rtadvd at the end of the tests,
I wonder if the underlying issue of rtadvd getting into the loop in
the first place was addressed, or only hidden by redirecting the
messages and/or killing the process.
--
Andreas Gustafsson, gson@gson.org
State-Changed-From-To: feedback->open
State-Changed-By: gson@NetBSD.org
State-Changed-When: Thu, 08 Feb 2018 08:38:53 +0000
State-Changed-Why:
Feedback provided.
>Unformatted:
(Contact us)
$NetBSD: query-full-pr,v 1.43 2018/01/16 07:36:43 maya Exp $
$NetBSD: gnats_config.sh,v 1.9 2014/08/02 14:16:04 spz Exp $
Copyright © 1994-2017
The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.
Home