Skip Menu |

Preferred bug tracker

Please visit the preferred bug tracker to report your issue.

This queue is for tickets about the devel-nytprof CPAN distribution.

Report information
The Basics
Id: 39396
Status: resolved
Priority: 0/
Queue: devel-nytprof
People
Owner: Nobody in particular
Requestors: thomas.equeter [...] ovh.net
Tim.Bunce [...] pobox.com
Cc:
AdminCc:
Bug Information
Severity: (no value)
Broken in: (no value)
Fixed in: (no value)

History Show all quoted text
  Tue Sep 16 12:58:23 2008 Tim.Bunce [...] pobox.com - Ticket #39332: Ticket created
CC: Tim.Bunce [...] pobox.com, bug-devel-nytprof [...] rt.cpan.org, develnytprof-dev [...] googlegroups.com
Subject: Re: Weird errors using NYTProf
Date: Tue, 16 Sep 2008 16:11:05 +0100
To: Thomas Equeter <thomas.equeter [...] ovh.net>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
On Tue, Sep 16, 2008 at 01:18:33PM +0200, Thomas Equeter wrote: Show quoted text
> Hello, > > I'm trying to profile one of our Perl applications using NYTProf 2.03, > and running into weird "can't happen" errors. > > But first, the setting: this is a relatively simple perl script (< 1K > LoC) but it leverages a number of modules from our internal > behemoth-sized library at OVH, so I can't really run it anywhere else > than our dev and production servers. > > The details of our dev server are as follows: Linux 2.4.32 on i386, gcc > 4.1.2, perl 5.8.8 (Debian-based). Needless to say that I can't alter any > of that. However, I've also tried using a $HOME-installed perl 5.10.0, > without any change in the symptoms.
Please post the perl -V output for both as it may be useful. I've not been able to reproduce it with perl 5.8.6 or 5.10.0. Show quoted text
> Among the heap of weird errors that pop up whenever I add -d:NYTProf to > the command-line, I've located an easily reproducible one at least: > > $ perl -MSocket6=AI_PASSIVE -e 'print AI_PASSIVE, "\n"' > 1 > $ perl -MSocket6=AI_PASSIVE -d:NYTProf -e 'print AI_PASSIVE, "\n"' > Unable to determine line number in -e. > ... > Your vendor has not defined Socket macro AI_PASSIVE, used at -e line 1
Please try running with NYTPROF=subs=0:blocks=0:leave=0:use_db_sub=1 and various combinations of value to isolate any that make a difference. Also, could you hack a copy of Socket6? Modify the constant() function (static double constant(char *name, int arg)) to print a copy of the name argument, delimited by quotes, so we can see what it's getting. Show quoted text
> Also, the NYTProf test10 case fails (tests 46, 144, 242, 340): > > # got: 'test10.x line 3: got 0.0000000 expected ~2 for time' > # expected: ''
Odd. Can you try all the above with the current trunk code?: http://code.google.com/p/perl-devel-nytprof/source/checkout Show quoted text
> Of course, none of this happens on my workstation, so I guess that it is > somehow related to our dev server. Would you happen to have an idea of > where the problem might lie and/or how to work around it?
Not yet. Tim.
  Wed Sep 17 05:05:29 2008 thomas.equeter [...] ovh.net - Ticket #39350: Ticket created
CC: bug-devel-nytprof [...] rt.cpan.org, develnytprof-dev [...] googlegroups.com
Subject: Re: Weird errors using NYTProf
Date: Wed, 17 Sep 2008 11:02:53 +0200
To: Tim Bunce <Tim.Bunce [...] pobox.com>
From: Thomas Equeter <thomas.equeter [...] ovh.net>
On Tue, Sep 16, 2008 at 04:11:05PM +0100, Tim Bunce wrote: Show quoted text
> Please post the perl -V output for both as it may be useful.
Attached. Show quoted text
> Please try running with NYTPROF=subs=0:blocks=0:leave=0:use_db_sub=1 > and various combinations of value to isolate any that make a difference.
No effect (tried all 16 combinations). Show quoted text
> Also, could you hack a copy of Socket6? Modify the constant() function > (static double constant(char *name, int arg)) to print a copy of the > name argument, delimited by quotes, so we can see what it's getting.
I did and seen that it was behaving as expected. Firing up gdb, I also noticed that it was also returning the correct value (1). Back to the perl side, I added some debug in Socket6.pm's AUTOLOAD sub, around the call to constant(): $ perl -MSocket6=AI_PASSIVE -e 'print AI_PASSIVE, "\n"' Before: $!=Bad file descriptor Socket6::constant( AI_PASSIVE, 0 ) After: $val=1, $!= 1 $ perl -MSocket6=AI_PASSIVE -d:NYTProf -e 'print AI_PASSIVE, "\n"' Before: $!=Invalid argument Socket6::constant( AI_PASSIVE, 0 ) After: $val=1, $!=Invalid argument Your vendor has not defined Socket macro AI_PASSIVE, used at -e line 1 Apparently, NYTProf is affecting the value of $! pretty much everywhere. As Socket6 checks $! to determine if the call was successful, it reports an error and discards $val in the -d:NYTProf case. I noticed the same problem in other parts of my script: POE signals errors using $! as well, so my code was choking on these "Invalid arguments" while the calls were actually delivered (as noticed through logging). There are no extra system calls reported by strace between the two prints above, and no EINVAL reported at all. Without a syscall to start tracking from, my knowledge of XS doesn't allow me to investigate further. Show quoted text
> Can you try all the above with the current trunk code?: > http://code.google.com/p/perl-devel-nytprof/source/checkout
Same behaviour. -Thomas Equeter.

Message body is not shown because sender requested not to inline it.

Message body is not shown because sender requested not to inline it.

  Thu Sep 18 05:31:14 2008 Tim.Bunce [...] pobox.com - Ticket #39380: Ticket created
CC: Tim Bunce <Tim.Bunce [...] pobox.com>, bug-devel-nytprof [...] rt.cpan.org, develnytprof-dev [...] googlegroups.com
Subject: Re: Weird errors using NYTProf
Date: Thu, 18 Sep 2008 10:29:28 +0100
To: Thomas Equeter <thomas.equeter [...] ovh.net>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
On Wed, Sep 17, 2008 at 11:02:53AM +0200, Thomas Equeter wrote: Show quoted text
> Apparently, NYTProf is affecting the value of $! pretty much everywhere.
Ah, interesting. Show quoted text
> As Socket6 checks $! to determine if the call was successful, it reports > an error and discards $val in the -d:NYTProf case. > > I noticed the same problem in other parts of my script: POE signals > errors using $! as well, so my code was choking on these "Invalid > arguments" while the calls were actually delivered (as noticed through > logging).
Are you using compression? ("strings nytprof.out | head" will show a line starting with "# Compressed ..." if you are.) Show quoted text
> There are no extra system calls reported by strace between the two > prints above, and no EINVAL reported at all. Without a syscall to start > tracking from, my knowledge of XS doesn't allow me to investigate > further.
Sadly I've still not been able to reproduce this. Show quoted text
> > Can you try all the above with the current trunk code?: > > http://code.google.com/p/perl-devel-nytprof/source/checkout
> Same behaviour.
Please try a "make test" after an "svn update". I've added a new test (t/50.errno.t) that tries to test this. If the test passes please hack it till it doesn't! (But only use core perl modules.) Tim.
  Thu Sep 18 05:35:24 2008 TIMB [...] cpan.org - Ticket #39350: Merged into ticket #39396
  Thu Sep 18 05:35:24 2008 TIMB [...] cpan.org - Ticket #39332: Merged into ticket #39396
  Thu Sep 18 05:36:48 2008 TIMB [...] cpan.org - Ticket #39380: Merged into ticket #39396
  Thu Sep 18 05:36:48 2008 TIMB [...] cpan.org - Ticket #39332: Merged into ticket #39396
  Thu Sep 18 05:37:19 2008 TIMB [...] cpan.org - Ticket #39332: Status changed from 'new' to 'open'
  Thu Sep 18 11:35:36 2008 thomas.equeter [...] ovh.net - Ticket created
CC: bug-devel-nytprof [...] rt.cpan.org, develnytprof-dev [...] googlegroups.com
Subject: Re: Weird errors using NYTProf
Date: Thu, 18 Sep 2008 17:34:49 +0200
To: Tim Bunce <Tim.Bunce [...] pobox.com>
From: Thomas Equeter <thomas.equeter [...] ovh.net>
On Thu, Sep 18, 2008 at 10:29:28AM +0100, Tim Bunce wrote: Show quoted text
> Are you using compression? ("strings nytprof.out | head" will > show a line starting with "# Compressed ..." if you are.)
No such line on the dev server nor on my workstation (where NYTProf works). Show quoted text
> Please try a "make test" after an "svn update". I've added a new > test (t/50.errno.t) that tries to test this.
It hits the nail right on the head: both $! tests fail (lines 19 and 33). This said, in the meantime I've managed to get an other server for my purposes. As it runs NYTProf flawlessly, I've been able to locate and refactorise the chunk of code which was hogging the CPU. Therefore, running NYTProf on the dev server is not an emergency anymore. It would still be useful to profile other code without using a different server however, but I'd perfectly understand that you don't want to keep chasing this weird bug that affects so few users. Otherwise, I'm available for more debugging :-) In any case, thanks a lot for the prompt support and the great software! -Thomas.
  Thu Sep 18 12:10:42 2008 Tim.Bunce [...] pobox.com - Correspondence added
Subject: Re: [rt.cpan.org #39396] Re: Weird errors using NYTProf
Date: Thu, 18 Sep 2008 18:10:18 +0200
To: Thomas Equeter via RT <bug-devel-nytprof [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
On Thu, Sep 18, 2008 at 11:35:41AM -0400, Thomas Equeter via RT wrote: Show quoted text
> > On Thu, Sep 18, 2008 at 10:29:28AM +0100, Tim Bunce wrote:
> > Are you using compression? ("strings nytprof.out | head" will > > show a line starting with "# Compressed ..." if you are.)
> > No such line on the dev server nor on my workstation (where NYTProf > works). >
> > Please try a "make test" after an "svn update". I've added a new > > test (t/50.errno.t) that tries to test this.
> > It hits the nail right on the head: both $! tests fail (lines 19 and > 33).
Great. Show quoted text
> This said, in the meantime I've managed to get an other server for my > purposes. As it runs NYTProf flawlessly, I've been able to locate and > refactorise the chunk of code which was hogging the CPU. Therefore, > running NYTProf on the dev server is not an emergency anymore. > > It would still be useful to profile other code without using a different > server however, but I'd perfectly understand that you don't want to keep > chasing this weird bug that affects so few users. Otherwise, I'm > available for more debugging :-)
Thanks! Please sprinkle if (errno) warn("errno %d",errno); through the DB_stmt() code, plus a errno=0 at the top, to try to pin point where it's changed. Show quoted text
> In any case, thanks a lot for the prompt support and the great software!
You're welcome. Tim.
  Thu Sep 18 12:10:47 2008 The RT System itself - Status changed from 'new' to 'open'
  Fri Sep 19 11:55:31 2008 thomas.equeter [...] ovh.net - Correspondence added
Subject: Re: [rt.cpan.org #39396] Re: Weird errors using NYTProf
Date: Fri, 19 Sep 2008 17:32:20 +0200
To: Tim Bunce via RT <bug-devel-nytprof [...] rt.cpan.org>
From: Thomas Equeter <thomas.equeter [...] ovh.net>
On Thu, Sep 18, 2008 at 12:10:47PM -0400, Tim Bunce via RT wrote: Show quoted text
> Thanks! Please sprinkle > if (errno) warn("errno %d",errno); > through the DB_stmt() code, plus a errno=0 at the top, to try to pin > point where it's changed.
Hah, finally found it! CLOCK_MONOTONIC is defined in the headers but not supported by Linux 2.4, or so it seems. Forcing the macro CLOCK_GETTIME to compile as "clock_gettime(CLOCK_REALTIME, ts)" works around the problem (all the tests pass, in particular 10 and 50). Now that I think about it, it's funny that test10 was screaming the answer since day 1 :-) -Thomas.
  Thu Oct 02 11:08:35 2008 TIMB [...] cpan.org - Ticket #39332: Merged into ticket #39396
  Thu Oct 02 11:08:35 2008 TIMB [...] cpan.org - Merged into ticket #39396
  Fri Oct 03 10:03:52 2008 TIMB [...] cpan.org - Correspondence added
Fixed now (r485) thanks to some sleuthing work by Slaven Rezic.
  Fri Oct 03 10:03:55 2008 TIMB [...] cpan.org - Status changed from 'open' to 'resolved'