slow syslogd makes system unusable

[Debian Bug Importer]

Automatically imported from Debian bug report #334295 http://bugs.debian.org/334295

[Debian Bug Importer (debzilla)]

Automatically imported from Debian bug report #334295 http://bugs.debian.org/334295

[Debian Bug Importer (debzilla)]

Message-Id: <email address hidden>
Date: Sun, 16 Oct 2005 13:50:21 +0200
From: Kai Henningsen <email address hidden>
To: Debian Bug Tracking System <email address hidden>
Subject: slow syslogd makes system unusable

Package: sysklogd
Version: 1.4.1-16
Severity: critical

I've seen this cause a boot take hours. The system looks like it's
mostly idle, but everything which uses syslog is excruciatingly slow.

It is possible that this is the same which is mentioned in bug 273269,
as both systems I've seen this on run with -r and -l, but the
explanation looks suspicious, as I believe the last time I saw it DNS
was actually working. In that case, -l wasn't working, but reverse
resolution was - every host was logged with the full reverse name
instead of the short name. In another case, the slowdown kept openvpn
from starting, and thus all actual log messages were from localhost.

/etc/init.d/sysklogd restart solved the problem in both situations.

-- System Information:
Debian Release: 3.1
  APT prefers testing
  APT policy: (995, 'testing'), (550, 'experimental'), (550, 'unstable')
Architecture: i386 (i686)
Kernel: Linux 2.6.13.2+kai.20050930
Locale: LANG=de_DE, LC_CTYPE=de_DE (charmap=ISO-8859-1)

Versions of packages sysklogd depends on:
ii klogd [linux-kernel-log-dae 1.4.1-16 Kernel Logging Daemon
ii libc6 2.3.2.ds1-22 GNU C Library: Shared libraries an

-- no debconf information

[Steve Langasek (vorlon)]

On Sun, Oct 16, 2005 at 01:50:21PM +0200, Kai Henningsen wrote:
> I've seen this cause a boot take hours. The system looks like it's
> mostly idle, but everything which uses syslog is excruciatingly slow.

> It is possible that this is the same which is mentioned in bug 273269,
> as both systems I've seen this on run with -r and -l, but the
> explanation looks suspicious, as I believe the last time I saw it DNS
> was actually working. In that case, -l wasn't working, but reverse
> resolution was - every host was logged with the full reverse name
> instead of the short name. In another case, the slowdown kept openvpn
> from starting, and thus all actual log messages were from localhost.

I'm pretty sure that 'critical' is not the right severity for this bug,
since you are the first to report it. Either hardly anyone is using -r -l,
and we should consider such a configuration contraindicated; or most people
using -r -l are not experiencing such symptoms, and we should wonder what is
special about your setup that's different from theirs. This problem could
also be worked around by running two instances of syslogd -- one for local
logging that's started as normal, and one for remote logging that is started
later and is configured not to use /dev/log.

> /etc/init.d/sysklogd restart solved the problem in both situations.

This is the most curious part of this bug report. If this is related to bug
#273269, why should restarting the daemon have any effect?

Thanks,
--
Steve Langasek Give me a lever long enough and a Free OS
Debian Developer to set it on, and I can move the world.
<email address hidden> http://www.debian.org/

[Debian Bug Importer (debzilla)]

Message-ID: <email address hidden>
Date: Sun, 16 Oct 2005 22:50:30 -0700
From: Steve Langasek <email address hidden>
To: Kai Henningsen <email address hidden>,
 <email address hidden>
Subject: Re: Bug#334295: slow syslogd makes system unusable

--jq0ap7NbKX2Kqbes
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

On Sun, Oct 16, 2005 at 01:50:21PM +0200, Kai Henningsen wrote:
> I've seen this cause a boot take hours. The system looks like it's
> mostly idle, but everything which uses syslog is excruciatingly slow.

> It is possible that this is the same which is mentioned in bug 273269,
> as both systems I've seen this on run with -r and -l, but the
> explanation looks suspicious, as I believe the last time I saw it DNS
> was actually working. In that case, -l wasn't working, but reverse
> resolution was - every host was logged with the full reverse name
> instead of the short name. In another case, the slowdown kept openvpn
> from starting, and thus all actual log messages were from localhost.

I'm pretty sure that 'critical' is not the right severity for this bug,
since you are the first to report it. Either hardly anyone is using -r -l,
and we should consider such a configuration contraindicated; or most people
using -r -l are not experiencing such symptoms, and we should wonder what is
special about your setup that's different from theirs. This problem could
also be worked around by running two instances of syslogd -- one for local
logging that's started as normal, and one for remote logging that is started
later and is configured not to use /dev/log.

> /etc/init.d/sysklogd restart solved the problem in both situations.

This is the most curious part of this bug report. If this is related to bug
#273269, why should restarting the daemon have any effect?

Thanks,
--=20
Steve Langasek Give me a lever long enough and a Free OS
Debian Developer to set it on, and I can move the world.
<email address hidden> http://www.debian.org/

--jq0ap7NbKX2Kqbes
Content-Type: application/pgp-signature; name="signature.asc"
Content-Description: Digital signature
Content-Disposition: inline

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.1 (GNU/Linux)

iD8DBQFDUzumKN6ufymYLloRAi9VAJ4yxP2JupielwLuyHPi4j52BKpdvQCfT8Ob
oImH2siahW8ob4JdNaOPq74=
=8+9n
-----END PGP SIGNATURE-----

--jq0ap7NbKX2Kqbes--

[Matt Zimmerman (mdz)]

Severity-inflated, no reason to track in bugzilla

[Joey Hess (joeyh)]

# Automatically generated email from bts, devscripts version 2.9.10
tags 334295 moreinfo

[Debian Bug Importer (debzilla)]

Message-Id: <email address hidden>
Date: Mon, 9 Jan 2006 23:50:32 -0500
From: Joey Hess <email address hidden>
To: <email address hidden>
Subject: tagging 334295

# Automatically generated email from bts, devscripts version 2.9.10
tags 334295 moreinfo

[Noah Meyerhans (noahm)]

On Sun, Oct 16, 2005 at 10:50:30PM -0700, Steve Langasek wrote:
> > I've seen this cause a boot take hours. The system looks like it's
> > mostly idle, but everything which uses syslog is excruciatingly slow.
>
> > It is possible that this is the same which is mentioned in bug 273269,
> > as both systems I've seen this on run with -r and -l, but the
> > explanation looks suspicious, as I believe the last time I saw it DNS
> > was actually working. In that case, -l wasn't working, but reverse
> > resolution was - every host was logged with the full reverse name
> > instead of the short name. In another case, the slowdown kept openvpn
> > from starting, and thus all actual log messages were from localhost.
>
> I'm pretty sure that 'critical' is not the right severity for this bug,
> since you are the first to report it. Either hardly anyone is using -r -l,
> and we should consider such a configuration contraindicated; or most people
> using -r -l are not experiencing such symptoms, and we should wonder what is
> special about your setup that's different from theirs. This problem could
> also be worked around by running two instances of syslogd -- one for local
> logging that's started as normal, and one for remote logging that is started
> later and is configured not to use /dev/log.
>
> > /etc/init.d/sysklogd restart solved the problem in both situations.
>
> This is the most curious part of this bug report. If this is related to bug
> #273269, why should restarting the daemon have any effect?

I wonder if this bug is somehow related to 301511, also submitted
against sysklogd 1.4.1-16. It sounds as though that bug report relates
to some harsher symptoms, so I doubt it's the same thing.

Can this bug be reproduced using 1.4.1-17.1 from unstable? How
consistantly reproducible is it? Can it be reproduced on systems that
are not using both -r and -l options to syslogd? I have never seen it
on the few production systems I support that use -r, but none of them
use -l. On test machines I've built, I've used -r and -l with no ill
effects.

Given my inability to reproduce this bug, coupled with the lack of
anybody else complaining of similar problems in the several months since
the most recent activity, I'm going to decrease the severity of this bug
to 'normal'.

noah

[Noah Meyerhans (noahm)]

severity 334295 normal

[Martin Schulze (joey-infodrom)]

tags 279120 help
tags 279120 moreinfo
severity 279120 normal
tags 315605 upstream
tags 315605 pending
forwarded 315605 <email address hidden>
close 22673
close 37193
close 42001
tags 59662 help
tags 59662 moreinfo
tags 59662 upstream
tags 315605 pending
fixed 91804 1.4.1-1
close 95480
fixed 100043 1.4.1-12
tags 107501 upstream
tags 107501 pending
tags 149659 unreproducible
close 149659
tags 166433 upstream
tags 166433 pending
tags 166763 upstream
tags 166763 pending
tags 203710 upstream
tags 203710 pending
severity 206947 wishlist
fixed 222245 1.4.1-19
tags 238507 upstream
tags 238507 pending
close 282058
tags 284877 upstream
tags 284877 pending
reopen 178000
tags 178000 upstream
tags 178000 pending
tags 308580 help
tags 308580 moreinfo
severity 365265 wishlist
merge 415136 178000
tags 415136 upstream
tags 419496 help
tags 118856 help
tags 419496 moreinfo
tags 118856 upstream
tags 334295 help
tags 334295 unreproducible
tags 118856 pending
tags 426271 upstream
tags 426271 pending
tags 192841 upstream
tags 192841 pending
unmerge 178050 198419
fixed 198419 1.4.1-19
fixed 226036 1.4.1-19
fixed 241657 1.4.1-19
tags 201231 upstream
tags 201231 pending
tags 291442 upstream
tags 291442 pending
tags 108653 upstream
tags 108653 pending
close 127620
tags 136190 upstream
tags 136190 pending
tags 144499 upstream
tags 144499 pending
tags 196521 upstream
tags 196521 pending
tags 44523 wontfix
tags 70429 wontfix
tags 70429 upstream
tags 89677 wontfix
tags 94285 upstream
close 166018
close 244028
tags 353744 upstream
tags 174038 upstream
tags 147471 upstream
tags 385292 upstream
retitle 158090 Every process can make use of syslog
submitter 27284 !
submitter 38529 !
submitter 51054 !
submitter 62812 !
submitter 64053 !
submitter 68670 !
submitter 71582 !
submitter 95380 !
submitter 273594 !
submitter 68862 !
submitter 98822 !
submitter 23515 !
submitter 31027 !
submitter 36592 !
submitter 37772 !
submitter 59614 !
submitter 59617 !
submitter 65372 !
submitter 66878 !
submitter 44910 !
submitter 31303 !
submitter 34042 !
submitter 61085 !
submitter 78574 !
submitter 117142 !
submitter 140879 !
submitter 26451 !
thanks

Note to Bug#37193: There's a DNS resolver timeout but after timeout syslogd
will complete init and run fine. When there's not nameserver available yet,
start syslogd a little bit later.

--
Every use of Linux is a proper use of Linux. -- Jon 'maddog' Hall

Please always Cc to me when replying to me on the lists.

[Craig Matsuura (cmatsuura)]

I have seen syslogd slows a system while remote logging heavy loads of data. My system is serving files via thttpd, while also logging. I can telnet to the computer most of the time. Sometimes it blocks after I enter a username and password. I think the key has been the heavy load of logging to this computer, I have 20 other devices logging remotely to this central computer.

The computer logging all data is call syslog with the following parameters (This computers networking is slow while logging):

/sbin/syslogd -rh

The remote devices are setup this way:

/sbin/syslogd -rh -p /tmp/log

I hope this helps.

Craig

--

Craig Matsuura - Principal Engineer
Control4
11734 South Election Road - Suite 200
Salt Lake City, UT 84020-6432
PH: 801-523-3161
FX: 801-523-3199