smammy has asked for the wisdom of the Perl Monks concerning the following question:

Learned Monks,

I am trying to use Devel::DProf on some code that uses Safe compartments. I've found that some subroutine names (in "&" lines) in the resulting tmon.out file are corrupted with nonprintable characters. Sometimes the corrupted names contain newlines, which is a problem for dprofpp. I'm using Perl 5.8.8 on FreeBSD 5.4 (compiled from a port). Here's a test program that triggers the problem:

#!/usr/bin/perl use strict; use warnings; use Safe; my $safe = new Safe; $safe->reval(q| sub fibonacci { my $index = shift; return 0 if $index == 0; return 1 if $index == 1; return fibonacci( $index - 1 ) + fibonacci( $index - 2 ); } |); print "F($ARGV[0]) is ", $safe->reval(qq|fibonacci($ARGV[0])|), "\n";

When run with "perl -d:DProf", the resulting tmon.out file contains the following odd subroutine lines:

& 2e main L<13><08>N & 30 main p<FF><06><08>ON__ & 31 main L<13><08>N & 32 main p<FF><06><08>ON__

(I've replaced the non-printable characters with their hex equivalents.) The second one looks like it's supposed to be "__ANON__", only the first four bytes have been overwritten. Some kind of memory corruption? Multiple runs result in roughly the same output -- the timing it different, but names and sequence of subroutines is the same.

When I run "dprofpp -T", it shows me that the odd subroutines are called by Safe::reval:

Safe::reval Safe::lexless_anon_sub main::L<13><08>N strict::unimport Opcode::_safe_call_sv main::p<FF><06><08>ON__ Safe::reval Safe::lexless_anon_sub main::L<13><08>N strict::unimport Opcode::_safe_call_sv main::p<FF><06><08>ON__ main::fibonacci main::fibonacci (... and so on)

This code, however, doesn't produce any corruption:

#!/usr/bin/perl use strict; use warnings; eval(q| sub fibonacci { my $index = shift; return 0 if $index == 0; return 1 if $index == 1; return fibonacci( $index - 1 ) + fibonacci( $index - 2 ); } |); print "F($ARGV[0]) is ", eval(qq|fibonacci($ARGV[0])|), "\n";

My real mod_perl codebase, which makes extensive use of Safe, yields such gems as:

& 471 main <10><98> id

What I've come up with so far is a cleaning script that escapes nonprintable bytes and inappropriate newlines:

while (<>) { print; last if /^PART2/ } while (<>) { s/([\x00-\x09\x0b-\x15\x7f-\xff])/"<".sprintf("%X",ord($1))."> +"/eg; /^[@&+\-\/*]/ or $prev =~ s/\n$/<10>/; print $prev; $prev = $_; } print $prev;

So dprofpp can handle the output, but I have no idea if I'm getting useful profile data. In my real codebase (a large mod_perl app, profiled with Apache::DProf under "httpd -X"), several consecutive requests will result in different garbage values, or no corruption:

Request 1:

WeBWorK::PG::Translator::translate Safe::reval main::<10><98> strict::unimport main::<88>'<AA><08>ON__ main::DOCUMENT

Request 2:

WeBWorK::PG::Translator::translate Safe::reval main::<08><83>G<0A>N strict::unimport main::<F8><CE><99><08>ON__ main::DOCUMENT

Request with no corruption:

WeBWorK::PG::Translator::translate Safe::reval main::BEGIN strict::unimport main::__ANON__ main::DOCUMENT

My question is: what gives? I'm hoping that others have seen this before and can suggest a solution, or at least tell me "Stop trying, Safe and DProf are not compatible". Or maybe it's not a problem -- the corruption seems to be localized, and the routines in question don't run for very long. (For example, main::<E4><F2><99><08>ON__ runs for 0.049s.)

Replies are listed 'Best First'.
Re: DProf + Safe = corrupted tmon.out
by BrowserUk (Patriarch) on Oct 20, 2006 at 06:08 UTC

    Have you tried dprofpp's -F switch?

    One thing that produces a garbled tmon.out file is code that uses the magic goto:

    sub bsub { return ...; } sub asub{ goto &bsub; }

    A bsub never returns to asub, no exit timestamp appears in the trace for that sub. -F will fake those timestamps and allow dprofpp to process the file. The fake timestamps will usually be the same as the exit timestamp for the gone to sub</c>, so the timings will all be fairly accurate.

    I've never used mod_perl or Safe, so this may be a completely bogus post and waste of your time and mine.


    Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error.
    Lingua non convalesco, consenesco et abolesco. -- Rule 1 has a caveat! -- Who broke the cabal?
    "Science is about questioning the status quo. Questioning authority".
    In the absence of evidence, opinion is indistinguishable from prejudice.
      This isn't a "garbled" file -- all the exit timestamps are present. -F doesn't help things.
Re: DProf + Safe = corrupted tmon.out
by Khen1950fx (Canon) on Oct 20, 2006 at 08:17 UTC
    I have a couple of suggestions for you. First, in your first script that triggers the problem, turn off warnings. According to the perldebug docs:

    "The debugger does not currently work in conjunction with the -W command-line switch because it itself is not free of warnings"

    In other words, the debugger can be buggy, so you have to play with it.

    Second, for me at least, I don't think that Safe and Devel::DProf are a good fit for use on mod_perl and Apache. Safe, for example, has safety issues. To quote the author:

    "Any string eval which is executed by code executing in a compartment, or by code called from code executing in a compartment, will be eval'd in the namespace of the compartment. This is potentially a serious problem."

    Also, Safe might also eat up all of your memory; it might also cause infinite looping; it might also open the door to snooping, viruses, etc.; it might also cause signals to interfere with your processes. That's not to say that Safe shouldn't be used here, but you might want to reconsider it.

    Apache::DProf, which implements Devel::DProf in Apache, works fine on perl code in Apache, but what about non-perl code? Apache recommends using gdb. So do I. See:

    Apache HTTPD Debugging Guide

      Sadly, turning off warnings doesn't help the situation.

      Regarding Safe, we're aware of these issues. The code we're dealing with is written by trusted authors -- the safe compartment is just a level of insurance against accidental flaws. We also use resource limits and an alarm handler to prevent inadvertent DDoS attacks.

      Regarding Devel::DProf, my goal is to profile my perl code -- I don't care about debugging or profiling Apache itself.