Hi all,
I am trying to debug a problem in a long-running process. We have a
perl-based web service (OTRS) that runs via FastCGI, and after a few hours
of heavy use, it becomes slower and slower (like requests that used to take
1s now take > 3s). And we don't know why, but as far as possible we have
ruled out external factors (system load, database response times, IO
response times etc.). Restarting Apache, and thus the FastCGI processes,
resets the response time again. So I want to figure out what's slowing it
down.
So I've added a small piece of code that switches on the profiler for
certain requests, using
require Devel::NYTProf;
DB::enable_profile($filename);
# do the request here, and then
DB::finish_profile();
Now that works, in the sense that the nytprof.*.out files are written to
disc, but the HTML files generated by nytprofhtml are mostly empty, for
example http://moritz.faui2k3.org/tmp/nytprof-b0rked/ . You can see that
this is for 10 requests (combined with nytprofmerge) for a total of 30.8s,
but the exclusive time of all the subroutines adds up to less than half a
second, so most of the time spent in the profile is missing, and I don't
learn anything interesting from the profile.
Another weird thing is that in the generated HTML, the subroutine links
don't seem to lead to any useful locations, neither to the declaration nor
to the calling location of that routine.
nytprofmerge warned:
Reading nytprof.slow2_01.3818.1377251760.out
unknown eval_fid 3 in nytprof.slow2_01.3818.1377251760.out fid 2
unknown folded eval_fid 3 in nytprof.slow2_01.3818.1377251760.out fid 2 at
/usr/bin/nytprofmerge line 263
main::__ANON__('NEW_FID', 2, 3, 1, 36, 0, 0, '(eval 70)') called at
/usr/lib/perl5/Devel/NYTProf/Data.pm line 89
Devel::NYTProf::Data::new('Devel::NYTProf::Data',
'HASH(0x140ed40)') called at /usr/bin/nytprofmerge line 327
Use of uninitialized value $folded_fid in concatenation (.) or string at
/usr/bin/nytprofmerge line 266.
Use of uninitialized value $folded_fid in concatenation (.) or string at
/usr/bin/nytprofmerge line 269.
Reading nytprof.slow2_01.3818.1377251760.out
Use of uninitialized value in subroutine entry at /usr/bin/nytprofmerge
line 172.
but this was only for one of the files (the others didn"t warn), and if I
do the same with a single-process Apache in debug mode, and a single
request, I don't get any warnings, and the profile is just as empty as the
one I linked to above.
Any idea what's going on here, and how I could gather more useful
information?
Some system details: Debian Linux "wheezy" 64bit, with perl 5.14.2 and
Devel::NYTProf 5.05, apache 2.2.22.
Best regards,
Moritz
--
--
You've received this message because you are subscribed to
the Devel::NYTProf Development User group.
Group hosted at: http://groups.google.com/group/develnytprof-dev
Project hosted at: http://perl-devel-nytprof.googlecode.com
CPAN distribution: http://search.cpan.org/dist/Devel-NYTProf
To post, email: [email protected]
To unsubscribe, email: [email protected]
---
You received this message because you are subscribed to the Google Groups
"Devel::NYTProf Dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
For more options, visit https://groups.google.com/groups/opt_out.
