fid 249 has no src saved for B.pm (NYTP_FIDf_HAS_SRC not set but src available!)

[Martin]

Hi,

I run Devel::NYTProf all the time and have no problems with it until
this morning. Now I get quite a lot of the above warning (around 8). 1
is my own module and the others are things like:

fid 23 has no src saved for /home/martin/perl5/perlbrew/perls/
perl-5.14.0/lib/5.14.0/Getopt/Std.pm (NYTP_FIDf_HAS_SRC not set but
src available!)
fid 193 has no src saved for /home/martin/perl5/perlbrew/perls/
perl-5.14.0/lib/5.14.0/Benchmark.pm (NYTP_FIDf_HAS_SRC not set but src
available!)

I cannot see what is common between them and I'm at a loss to think
what I may have done to cause this. Even though the message is issued
for B.pm the source is visible in the nytprofhtml output.

$ perl -MDevel::NYTProf -le 'print $Devel::NYTProf::VERSION;'
4.06

perl is 5.14.0 installed via perlbrew. I do have PERL_UNICODE=SAL but
I've had that some time and unsetting it made no difference. I
couldn't find anyone else with this issue on google.

Martin

[Tim Bunce]

On Tue, Jun 28, 2011 at 12:46:51AM -0700, Martin wrote:
> Hi,
>
> I run Devel::NYTProf all the time and have no problems with it until
> this morning. Now I get quite a lot of the above warning (around 8). 1
> is my own module and the others are things like:
>
> fid 23 has no src saved for /home/martin/perl5/perlbrew/perls/
> perl-5.14.0/lib/5.14.0/Getopt/Std.pm (NYTP_FIDf_HAS_SRC not set but
> src available!)
> fid 193 has no src saved for /home/martin/perl5/perlbrew/perls/
> perl-5.14.0/lib/5.14.0/Benchmark.pm (NYTP_FIDf_HAS_SRC not set but src
> available!)

It's certainly odd.

> I cannot see what is common between them and I'm at a loss to think
> what I may have done to cause this.

Yes, the obvious question is "what changed?"

> Even though the message is issued
> for B.pm the source is visible in the nytprofhtml output.

nytprofhtml will fallback to reading the source directly from the file
path if it's not embedded into the profile.

> perl is 5.14.0 installed via perlbrew. I do have PERL_UNICODE=SAL but
> I've had that some time and unsetting it made no difference. I
> couldn't find anyone else with this issue on google.

I've not seen it before. The implication is that source code wasn't
available when the file was first 'noticed' by the profiler (so
NYTP_FIDf_HAS_SRC didn't get set), but was available when the profile
as written out at the end of the run.

Looking at svn blame etc I see that that check was included in the
initial implementation of saving the source code.

If you can't retrace your steps to find the cause, which I hope you can,
then you could send me a trace file. Level 4 should suffice.
(I can't promise I'll even look at it though as I'm rather snowed under
with a different kind of project: http://yfrog.com/z/h0paexycj )

Tim.

[Martin]

On Wednesday, 29 June 2011 10:41:58 UTC+1, Tim.Bunce wrote:

On Tue, Jun 28, 2011 at 12:46:51AM -0700, Martin wrote:
> Hi,
>
> I run Devel::NYTProf all the time and have no problems with it until
> this morning. Now I get quite a lot of the above warning (around 8). 1
> is my own module and the others are things like:
>
> fid 23 has no src saved for /home/martin/perl5/perlbrew/perls/
> perl-5.14.0/lib/5.14.0/Getopt/Std.pm (NYTP_FIDf_HAS_SRC not set but
> src available!)
> fid 193 has no src saved for /home/martin/perl5/perlbrew/perls/
> perl-5.14.0/lib/5.14.0/Benchmark.pm (NYTP_FIDf_HAS_SRC not set but src
> available!)

It's certainly odd.

> I cannot see what is common between them and I'm at a loss to think
> what I may have done to cause this.

Yes, the obvious question is "what changed?"

That could be a difficult one to pinpoint as a lot is changing right now here. I will however try.

> Even though the message is issued
> for B.pm the source is visible in the nytprofhtml output.

nytprofhtml will fallback to reading the source directly from the file
path if it's not embedded into the profile.

ah, ok, I wondered why it was warning but appearing to work.

> perl is 5.14.0 installed via perlbrew. I do have PERL_UNICODE=SAL but
> I've had that some time and unsetting it made no difference. I
> couldn't find anyone else with this issue on google.

I've not seen it before. The implication is that source code wasn't
available when the file was first 'noticed' by the profiler (so
NYTP_FIDf_HAS_SRC didn't get set), but was available when the profile
as written out at the end of the run.

I cannot see how the source code would not be available at profile time but it is later.
Also, all modules mentioned are in my home directory - either under the Perl installed via perlbrew or our own modules in my account.

Looking at svn blame etc I see that that check was included in the
initial implementation of saving the source code.

If you can't retrace your steps to find the cause, which I hope you can,
then you could send me a trace file. Level 4 should suffice.
(I can't promise I'll even look at it though as I'm rather snowed under
with a different kind of project: http://yfrog.com/z/h0paexycj )

I see you look very busy so I'll poke around a bit more myself.
Just thought someone might have seen the issue before.

Thanks

Tim.

BTW, watch what you are doing with those kuboto diggers. We hired one for a a few weeks years ago and my wife managed to get it stuck between 2 brick wall posts when it sank unexpectedly. I had visions of having to hire a crane or knock the newly laid walls down. It took hours of gentle maneuvering to get it out.

[Martin]

Just in case it provides a clue:

I ran an strace on this code with an exit 0 placed after the last "use" statement. Then I picked a module which was reported with a warning like:

fid 23 has no src saved for /home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt/Std.pm (NYTP_FIDf_HAS_SRC not set but src available!)

The only mentions of Std in the trace are:
# these right at start after failing to find Std.pm or Std.pmc anywhere else
stat64("/home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt/Std.pm", {st_mode=S_IFREG|0444, st_size=8370, ...}) = 0
open("/home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt/Std.pm", O_RDONLY|O_LARGEFILE) = 5
# a lot of these:
clock_gettime(CLOCK_MONOTONIC, {11311843, 972136001}) = 0
# and seemingly in the middle of nowhere:
lstat64("/home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt/Std.pmc", 0xbff870bc) = -1 ENOENT (No such file or directory)
# but not corresponding lstat for Std.pm

$ ls -la /home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt
total 100
drwxr-xr-x  2 martin root  4096 2011-05-17 10:58 .
drwxr-xr-x 60 martin root  4096 2011-05-17 10:58 ..
-r--r--r--  1 martin root 79188 2011-05-17 10:58 Long.pm
-r--r--r--  1 martin root  8370 2011-05-17 10:58 Std.pm

Martin

[Martin]

Missed a bit (possibly vital) out. I can see a successful read on Std.pm:

On Wednesday, 29 June 2011 15:58:05 UTC+1, Martin wrote:

Just in case it provides a clue:

I ran an strace on this code with an exit 0 placed after the last "use" statement. Then I picked a module which was reported with a warning like:

fid 23 has no src saved for /home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt/Std.pm (NYTP_FIDf_HAS_SRC not set but src available!)

The only mentions of Std in the trace are:
# these right at start after failing to find Std.pm or Std.pmc anywhere else
stat64("/home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt/Std.pm", {st_mode=S_IFREG|0444, st_size=8370, ...}) = 0
open("/home/martin/perl5/perlbrew/perls/perl-5.14.0/lib/5.14.0/Getopt/Std.pm", O_RDONLY|O_LARGEFILE) = 5
# a lot of these:
clock_gettime(CLOCK_MONOTONIC, {11311843, 972136001}) = 0
# and seemingly in the middle of nowhere:

 read(5, "package Getopt::Std;\nrequire 5.0"..., 8192) = 8192

[Martin]

Solved (to a degree). This causes it:

use open qw( :encoding(UTF-8) :std );

When commented out the warnings go away. That line was added recently to this code but I thought it had lexical scope and I am surprised it had an effect on Devel::NYTProf.

Martin

[Tim Bunce]

Ah, very interesting. Can you create a small test case?

> BTW, watch what you are doing with those kuboto diggers. We hired one for a a few weeks years ago and my
> wife managed to get it stuck between 2 brick wall posts when it sank unexpectedly. I had visions of
> having to hire a crane or knock the newly laid walls down. It took hours of gentle maneuvering to get it
> out.

Ouch. I'm not crazy enough to attempt that much work myself. A team of
builders is doing all the hands-on work, and far faster and more
skillfully than I could.

Tim.

[Martin]

This is perl, v5.10.1 (*) built for i686-linux

$ cat devel_nytprof.t
#use v5.14;
use strict;

use open qw( :encoding(UTF-8) :std );

use Getopt::Std;

$ perl -d:NYTProf devel_nytprof.t
fid 21 has no src saved for /home/martin/perl5/perlbrew/perls/
perl-5.10.1/lib/5.10.1/Getopt/Std.pm (NYTP_FIDf_HAS_SRC not set but
src available!)

PERL_UNICODE was not set.

$ cat devel_nytprof.t
#use v5.14;
use strict;
#use open qw( :encoding(UTF-8) :std );
use Getopt::Std;

$ perl -d:NYTProf devel_nytprof.t
works ok.

I'm actually using 5.14 but I stepped back to 5.10.1 for the above
runs. I have the same issue in 5.14.

BTW, when compiling for 5.10.1 I got these:

cc -c -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/
include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -O2 -DVERSION=
\"4.06\" -DXS_VERSION=\"4.06\" -fPIC "-I/home/martin/perl5/perlbrew/
perls/perl-5.10.1/lib/5.10.1/i686-linux/CORE" -DHAS_CLOCK_GETTIME -
DHAS_ZLIB -W -Wall -Wpointer-arith -Wbad-function-cast -Wno-comment -
Wno-sign-compare -Wno-cast-qual -Wmissing-noreturn -Wno-unused-
parameter NYTProf.c
NYTProf.xs:1519:20: warning: extra tokens at end of #ifdef directive
NYTProf.xs:815: warning: ‘lookup_file_entry’ defined but not used
NYTProf.xs:3649: warning: ‘eval_outer_fid’ defined but not used
Running Mkbootstrap for Devel::NYTProf ()

Martin

[Martin]

This is perl, v5.10.1 (*) built for i686-linux

$ cat devel_nytprof.t
#use v5.14;
use strict;

use open qw( :encoding(UTF-8) :std );

[Martin]

Sorry for double post, the google groups interface said there was an
error posting so I reposted.

I thought since the fid warning does not happen for all modules them
perhaps some modules had 8 bit data in them that is not utf-8 but that
does not seem to be the case:

$ cat devel_nytprof.t
#use v5.14;
use strict;
use open qw( :encoding(UTF-8) :std );
use Getopt::Std;

open my $f, "/home/martin/perl5/perlbrew/perls/perl-5.10.1/lib/5.10.1/
Getopt/Std.pm" or die "$!";
while(<$f>) {};