Bug #34753 for Sys-Syslog: Sys-Syslog 0.19-0.24 slowdown

Mon Apr 07 19:05:29 2008 powerman [...] powerman.name - Ticket created

Subject:	Sys-Syslog 0.19-0.24 slowdown
Date:	Tue, 8 Apr 2008 02:04:12 +0300
To:	bug-Sys-Syslog [...] rt.cpan.org
From:	Alex Efros <powerman [...] powerman.name>

Hi! I'm using socklog (syslog-compatible log daemon) for logging in my projects, i.e. each project run own socklog daemon, and have own unix socket to send logs to that daemon. So, I HAVE to use setlogsock('unix'). Starting from version 0.19 there was 0.25 sec timeout added in connection_ok(): - my $ret = select $rin, undef, $rin, 0; + my $ret = select $rin, undef, $rin, 0.25; I've no idea about reason to do this (at least I don't find anything related to this in Changelog or documentation), but this have side effect in slowing down logging. For example, I've fast networking I/O code which doing thousands operations on non-blocking sockets every second, and I wish to log a lot of messages every second (may be thousands too, in debug mode). But after 0.25 sec timeout was added, I can log 4 messages per second maximum! This isn't acceptable, so for now I stick to 0.18. Can you explain reason why that timeout needed and make it possible to disable (or configure) it? -- WBR, Alex.

Mon Apr 07 20:06:14 2008 SAPER [...] cpan.org - Correspondence added

Subject:	Re: [rt.cpan.org #34753] Sys-Syslog 0.19-0.24 slowdown
Date:	Tue, 8 Apr 2008 02:05:14 +0200
To:	bug-Sys-Syslog [...] rt.cpan.org
From:	Sébastien Aperghis-Tramoni <saper [...] cpan.org>

Alex Efros wrote: Show quoted text

> Hi!

Hello, Show quoted text

> I'm using socklog (syslog-compatible log daemon) for logging in my > projects, i.e. each project run own socklog daemon, and have own unix > socket to send logs to that daemon. So, I HAVE to use setlogsock > ('unix').

I guess this means you've read the documentation and now what you're doing, which is good (most people are just cargo-culting without knowing). Show quoted text

> Starting from version 0.19 there was 0.25 sec timeout added in > connection_ok(): > - my $ret = select $rin, undef, $rin, 0; > + my $ret = select $rin, undef, $rin, 0.25; > > I've no idea about reason to do this (at least I don't find anything > related to this in Changelog or documentation), but this have side > effect > in slowing down logging. For example, I've fast networking I/O code > which > doing thousands operations on non-blocking sockets every second, and I > wish to log a lot of messages every second (may be thousands too, > in debug > mode). But after 0.25 sec timeout was added, I can log 4 messages per > second maximum! This isn't acceptable, so for now I stick to 0.18. > > Can you explain reason why that timeout needed and make it possible to > disable (or configure) it?

I have no memory of why this was changed. Thanks goodness we have revision control system. Sys-Syslog' SVN tells me that this line was changed in décember 2006: » http://svnweb.mongueurs.net/Sys-Syslog/revision/?rev=62 Finding the actual reason was a little more tough, because there wasn't any direct mail from these people to me, but I finally found it: » http://london.pm.org/pipermail/london.pm/Week-of- Mon-20061211/005961.html I agree adding it without checking the running operating system was probably a bad idea. What I can do is to permit one to set the timeout via a third argument to setlogsock(), roll back to the default value of zero on all systems except on OSX where it is then set to 0.25 sec. -- Sébastien Aperghis-Tramoni Close the world, txEn eht nepO.

Mon Apr 07 20:06:19 2008 The RT System itself - Status changed from 'new' to 'open'

Mon Apr 07 20:17:08 2008 SAPER [...] cpan.org - Taken

Mon Apr 07 20:17:28 2008 SAPER [...] cpan.org - Severity Unimportant added

Mon Apr 07 20:17:28 2008 SAPER [...] cpan.org - Broken in 0.19 added

Mon Apr 07 20:17:28 2008 SAPER [...] cpan.org - Broken in 0.20 added

Mon Apr 07 20:17:28 2008 SAPER [...] cpan.org - Broken in 0.21 added

Mon Apr 07 20:17:28 2008 SAPER [...] cpan.org - Broken in 0.22 added

Mon Apr 07 20:17:28 2008 SAPER [...] cpan.org - Broken in 0.23 added

Mon Apr 07 20:17:28 2008 SAPER [...] cpan.org - Broken in 0.24 added

Mon Apr 07 20:35:38 2008 powerman [...] powerman.name - Correspondence added

Subject:	Re: [rt.cpan.org #34753] Sys-Syslog 0.19-0.24 slowdown
Date:	Tue, 8 Apr 2008 03:34:21 +0300
To:	S??bastien Aperghis-Tramoni via RT <bug-Sys-Syslog [...] rt.cpan.org>
From:	Alex Efros <powerman [...] powerman.name>

Hi! On Mon, Apr 07, 2008 at 08:06:22PM -0400, S??bastien Aperghis-Tramoni via RT wrote: Show quoted text

> What I can do is to permit one to set the timeout via a third > argument to setlogsock(), roll back to the default value of zero on > all systems except on OSX where it is then set to 0.25 sec.

Sounds good for me. :) -- WBR, Alex.

Sat Apr 19 21:52:37 2008 SAPER [...] cpan.org - Correspondence added

Subject:	Re: [rt.cpan.org #34753] Sys-Syslog 0.19-0.24 slowdown
Date:	Sun, 20 Apr 2008 03:52:20 +0200
To:	bug-Sys-Syslog [...] rt.cpan.org
From:	Sébastien Aperghis-Tramoni <saper [...] cpan.org>

Alex Efros wrote: Show quoted text

> Sébastien Aperghis-Tramoni via RT wrote:

>> What I can do is to permit one to set the timeout via a third >> argument to setlogsock(), roll back to the default value of zero on >> all systems except on OSX where it is then set to 0.25 sec.

> > Sounds good for me. :)

This is committed in the SVN. You may also be interested in a change I made to setlogsock() which allows to set the remote host for network mechanism with the second argument: setlogsock("udp", $remotehost); -- Sébastien Aperghis-Tramoni Close the world, txEn eht nepO.

Sat Jun 07 21:09:44 2008 maddingue [...] free.fr - Correspondence added

Subject:	Re: [rt.cpan.org #34753] Sys-Syslog 0.19-0.24 slowdown
Date:	Sun, 8 Jun 2008 03:09:50 +0200
To:	bug-Sys-Syslog [...] rt.cpan.org
From:	Sébastien Aperghis-Tramoni <maddingue [...] free.fr>

This issue is fixed in version 0.25. Thanks for your report. -- Sébastien Aperghis-Tramoni Close the world, txEn eht nepO.

Sat Jun 07 21:19:35 2008 SAPER [...] cpan.org - Status changed from 'open' to 'resolved'

Sat Jun 07 21:19:36 2008 SAPER [...] cpan.org - Fixed in 0.25 added