Re: [SLUG] Apps hanging when writing to /dev/log
On Wednesday 11 February 2009 19:07:46 Jamie Wilkinson wrote: > Is the syslog daemon logging into /var/log/syslog that it's out of > connections? Interesting. I presume something like lsof will tell me this. > syslog can run out of file descriptors sometimes; if > it's syslog-ng it'll write "Number of allowed concurrent connections > exceeded". I know it's not syslog-ng. It's sysklogd, which is stock-standard in Ubuntu: http://www.infodrom.org/projects/sysklogd/ signature.asc Description: This is a digitally signed message part. -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
Is the syslog daemon logging into /var/log/syslog that it's out of connections? syslog can run out of file descriptors sometimes; if it's syslog-ng it'll write "Number of allowed concurrent connections exceeded". 2009/1/29 Jeremy Visser : > G'day, > > Since around the beginning of the month, I've been encountering a > problem with our server (glenstorm, Ubuntu 8.04), where apps that > attempt to write out logs to /dev/log will hang for 5 or so minutes. > > Most notably PAM gets affected, which makes ssh'ing in or using sudo a > _very_ lengthy process. Also BIND was unresponsive, I guess anything > that writes to the logs would have been. > > I only found out a workaround yesterday thanks to Mick Pollard (lunix), > who suggested I use strace. Apps like sudo would connect() to /dev/log > (which I presume is a UNIX socket), and use send() to write the actual > log. The apps were hanging on send(), not connect(). > > Eventually, I've found that this only occurs if syslogd is running. > While an app is hanging, a `killall syslogd` will instantly un-freeze > it. > > `fuser -u /dev/log` reveals that indeed, syslogd listens on /dev/log. > > Funny thing is, if I restart syslogd, and do things that write to the > log, it works fine. I can see the log entries coming through in syslog, > and it's all good. Just after a few hours, it conks out and starts > hanging. > > I am not sure if the actual syslogd process is locked up, or what. > > Oh, and none of my filesystems are full. That was one of the first > things I checked. :) > > Any idea why syslogd is behaving as such? > > Jeremy. > > -- > SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ > Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html > -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
maybe there's an open write lock on /dev/log that keeps the send() hanging?
On Wed, Feb 4, 2009 at 8:39 PM, Jeremy Visser wrote:
> On 02/02/2009, at 11:56 AM, Daniel Pittman wrote:
>
>> That should let you see which syscalls were delaying the process, and so
>> narrow it down to a specific set of options...
>>
>
> Did you read my post 30/01/09 7:14PM? It was basically a running commentary
> of it, as I was watching the strace, not just logging it to a file.
>
> The actual syslogd daemon did not appear to be locked up. It didn't even
> hang when I sent a normal HUP to it -- it quits cleanly.
>
> Just the socket communication between apps and /dev/log seems to be hanging
> (though killing syslogd stops the hanging).
>
> As for the actual apps that hang as a result of the dead communication,
> they hang on send(), when writing the log message.
>
> It's strange that they hang on send(). connect('/dev/log'), which is what
> I'd expect them to hang on, returns instantly.
>
> --
> SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/
> Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
>
--
SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/
Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
On 02/02/2009, at 11:56 AM, Daniel Pittman wrote:
That should let you see which syscalls were delaying the process,
and so
narrow it down to a specific set of options...
Did you read my post 30/01/09 7:14PM? It was basically a running
commentary of it, as I was watching the strace, not just logging it to
a file.
The actual syslogd daemon did not appear to be locked up. It didn't
even hang when I sent a normal HUP to it -- it quits cleanly.
Just the socket communication between apps and /dev/log seems to be
hanging (though killing syslogd stops the hanging).
As for the actual apps that hang as a result of the dead
communication, they hang on send(), when writing the log message.
It's strange that they hang on send(). connect('/dev/log'), which is
what I'd expect them to hang on, returns instantly.
PGP.sig
Description: This is a digitally signed message part
--
SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/
Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
Jeremy Visser writes: > Still got absolutely no idea. Should I attach a gzipped copy of my > syslog strace output (6.7K) to help get an idea? You might try generating the strace output with the '-tt' option, which causes strace to generate relative timestamps of the syscalls. That should let you see which syscalls were delaying the process, and so narrow it down to a specific set of options... Regards, Daniel -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
Still got absolutely no idea. Should I attach a gzipped copy of my syslog strace output (6.7K) to help get an idea? -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
Update:
Left syslogd running again for a few hours, and it again starting acting
up.
I attached strace to it, and it wasn't hanging. Every few seconds, it
was doing stuff like this:
poll([{fd=15, events=POLLIN}], 1, 1) = 0
gettimeofday({1233300158, 115424}, NULL) = 0
poll([{fd=1, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
send(1, "\6\235\1\0\0\1\0\0\0\0\0\0\0013\0010\003168\003192\7in"...,
42, MSG_NOSIGNAL) = 42
I'm not sure if that's normal or not. A while later, I got a bit of
this:
poll([{fd=1, events=POLLIN}], 1, 5000) = 0
socket(PF_INET6, SOCK_DGRAM, IPPROTO_IP) = 15
connect(15, {sa_family=AF_INET6, sin6_port=htons(53),
inet_pton(AF_INET6, ":::127.0.0.1", &sin6_addr), sin6_flowinfo=16777343,
sin6_scope_id=0}, 28) = 0
fcntl64(15, F_GETFL)= 0x2 (flags O_RDWR)
fcntl64(15, F_SETFL, O_RDWR|O_NONBLOCK) = 0
gettimeofday({1233301548, 576663}, NULL) = 0
poll([{fd=15, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
So that's connecting to IPv6 sockets. I wonder if it has anything to do
with IPv6. Thinking about what John said, it could be something to do
with not having reverse DNS on the IPv6 interface.
However, I just temporarily disabled the IPv6 interfaces and tunnel, and
it didn't seem to do anything.
Strangely, I thought "IPv4-compatible" addresses like
":::127.0.0.1", which syslogd is connecting to, was supposed to be
deprecated.
I do have a feeling it's something to do with reverse DNS, as it does
this occasionally:
write(1, "RESOLVE-ADDRESS 192.168.0.3\n", 28) = 28
read(1, "-15 Timeout reached\n", 1024) = 20
close(1)= 0
192.168.0.3 is the address of our VoIP box. Which reminds me, we'll have
to buy a new one if we want IPv6-enabled VoIP, as I doubt there will be
a new firmware released for a consumer box.
It looks at /etc/resolv.conf every now and then:
munmap(0xb7f76000, 4096)= 0
stat64("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=96, ...}) = 0
socket(PF_INET6, SOCK_DGRAM, IPPROTO_IP) = 1
connect(1, {sa_family=AF_INET6, sin6_port=htons(53),
inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28)
= 0
Don't know why it's so insistent on doing funny queries using IPv6. I
know I've been setting up IPv6 tunnels and things, but I haven't done
anything other than that. /etc/hosts doesn't have anything crazy like
localhost pointing to ::1 (as opposed to ip6-localhost).
When I run something that hangs, like `sudo -v`, I see no extra output
from the strace'ed syslogd. When I look at /var/log/syslog, there is
some occasional stuff getting written to the log. So some stuff is being
passed through to syslogd, some is not.
This is confusing.
--
Jeremy Visser http://jeremy.visser.name/
No Internet Censorship for Australia http://nocleanfeed.com/
signature.asc
Description: This is a digitally signed message part
--
SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/
Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
On Fri, Jan 30, 2009 at 2:57 PM, Martin Visser wrote: > Sure about that? I am sending syslog to it from our router ;-) Oh, yes, I remember that now. That's syslog, is it? Well, every single TCP connection that goes out of our house goes into glenstorm's syslog, in that case. If there ever was a way to trigger the race condition that Michael linked, that would be it. -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
Sure about that? I am sending syslog to it from our router ;-) Regards, Martin martinvisse...@gmail.com On Fri, Jan 30, 2009 at 2:52 PM, Jeremy Visser wrote: > On Fri, Jan 30, 2009 at 3:01 AM, Michael Chesterton > wrote: > > If you haven't already, you could attach strace to syslogd and see what > > it's up to, from memory it's strace -p > > Good idea. > > >From looking at the man page, it's `strace -p` without a space. > That would be very handy for stepping in when the problem occurs, > rather than having to stab in the dark, setting up a test environment, > hoping to trigger the bug. > > > also, (if you haven't already) you could try googling syslogd hanging > > > > http://lkml.org/lkml/2005/3/26/37 > > Interesting reading about the ctime() stuff. I'll definitely know if > that's the problem, from looking at strace's output. > -- > SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ > Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html > -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
On Fri, Jan 30, 2009 at 3:01 AM, Michael Chesterton wrote: > If you haven't already, you could attach strace to syslogd and see what > it's up to, from memory it's strace -p Good idea. >From looking at the man page, it's `strace -p` without a space. That would be very handy for stepping in when the problem occurs, rather than having to stab in the dark, setting up a test environment, hoping to trigger the bug. > also, (if you haven't already) you could try googling syslogd hanging > > http://lkml.org/lkml/2005/3/26/37 Interesting reading about the ctime() stuff. I'll definitely know if that's the problem, from looking at strace's output. -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
On Thu, Jan 29, 2009 at 11:24 PM, John Ferlito wrote: > Last time I saw something similar it was on our syslog host. ie many > servers were logging to it. The problem occurred where some of the > servers didn't have reverse DNS and syslogd was hanging trying to > perform reverse lookups. Interesting. Though I didn't mention it in my O.P., DNS was one of the things I suspected. glenstorm's IPv4 address is a local address, and neither of its IPv6 addresses have reverse DNS (Internode don't provide it), so it doesn't have reverse DNS. It's not a syslogd server, though -- all the logs are local AFAIK. Not sure what to do about checking any further, though. I don't understand reverse DNS very well. -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
On 29/01/2009, at 11:24 PM, John Ferlito wrote: On Thu, Jan 29, 2009 at 10:49:09PM +1100, Jeremy Visser wrote: `fuser -u /dev/log` reveals that indeed, syslogd listens on /dev/log. Funny thing is, if I restart syslogd, and do things that write to the log, it works fine. I can see the log entries coming through in syslog, and it's all good. Just after a few hours, it conks out and starts hanging. Last time I saw something similar it was on our syslog host. ie many servers were logging to it. The problem occurred where some of the servers didn't have reverse DNS and syslogd was hanging trying to perform reverse lookups. If you haven't already, you could attach strace to syslogd and see what it's up to, from memory it's strace -p also, (if you haven't already) you could try googling syslogd hanging http://lkml.org/lkml/2005/3/26/37 -- http://chesterton.id.au/blog/ http://barrang.com.au/ -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
Re: [SLUG] Apps hanging when writing to /dev/log
On Thu, Jan 29, 2009 at 10:49:09PM +1100, Jeremy Visser wrote: > `fuser -u /dev/log` reveals that indeed, syslogd listens on /dev/log. > > Funny thing is, if I restart syslogd, and do things that write to the > log, it works fine. I can see the log entries coming through in syslog, > and it's all good. Just after a few hours, it conks out and starts > hanging. Last time I saw something similar it was on our syslog host. ie many servers were logging to it. The problem occurred where some of the servers didn't have reverse DNS and syslogd was hanging trying to perform reverse lookups. Cheers, John > -- > SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ > Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html -- John Bloghttp://www.inodes.org/blog OLPC Friends http://olpcfriends.org -- SLUG - Sydney Linux User's Group Mailing List - http://slug.org.au/ Subscription info and FAQs: http://slug.org.au/faq/mailinglists.html
