Help troubleshoot a consistently repeatable mod_perl2 / $SIG{__DIE__} bug

Question

This is mod_perl2 on Apache 2.2, ActiveState Perl 5.10 for win32.

I override $SIG{__DIE__} and turn on DBI's RaiseError flag, which AFAICT from the docs, should call my override when a database call fails. It seems to almost always, except in one case, and I can't understand why.

My script has an our $page variable, and being mod_perl2, I can get at this from the override like so:

use Carp::Trace;
my $full_trace = Carp::Trace::trace;
$full_trace =~ m/^(ModPerl::ROOT::ModPerl::Registry::.*::)handler .*$/m;
my $page;
if (defined $1)
{
    eval '$page = $' . $1 . 'page';
    if (defined $page)
    {
        $json = 1 if defined $$page{json_response};
        if (defined $$page{dbh})
        {
            my $errno = $$page{dbh}->state;
            if ($errno ~~ $$page{error_handling}{allowed})
            {
                # allowed to let it go--no report, expected possible user error at some level that couldn't be caught sooner (usually db level)
                my $errmsg = $$page{error_handling}{translation_map}{$errno};
                if (defined $errmsg)
                                    {
                                               ...

This works fine. Now, within that $page, I have an array ref of 'allowed' error values that I want to do something different with when they come back from the DB. When the DB throws one of these errors, I want to translate it into a user-friendly message, $r->print that in JSON, and stop execution (behaviour A). For some reason, it instead returns control to the script (behaviour B).

Here's the main part of my script:

{
    $$page{error_handling}{allowed} = ['22007'];
    $$page{json_response}{result} = $page->one_liner("select 'aa'::timestamp");
    $$page{json_response}{test} = $$page{error_handling}{state};
}
    $page->make_json; # just JSONifies $$page{json_response} and prints it

If I comment out the first line, I get a normal error (handling something unexpected) (behaviour C), which is what I expect, because I haven't added the error that's occurring to the list of allowed errors. What's really strange is, if I cut that first line and paste it into my $SIG{__DIE__} override, it works: the JSON response is overridden, printed, and execution stops before {test} is assigned (behaviour A). Stranger still, I can set {allowed} to any set of numbers, and so long as it contains '22007' in particular, I get behaviour B. If it doesn't, I get behaviour C. Even more strange, I can actually fill my override with anything (warnings, calls to CORE::die, etc.--as long as it compiles) and I get behaviour B still--even though the override no longer contains any of the code that would make it possible! Also I don't get any of the expected results of the calls to warn and CORE::die, just silence in the logs, so I can't even attempt to manually trace the path of execution through my override.

I have restarted Apache2.2 in between every script save. I have even moved the override to the same script file as the script itself, out of the module where it normally is, and commented out the entire module file where the override normally is, and restarted.

If I take out that first line, or take '22007' out of it, I can warn and die and otherwise manually debug all I like, and everything works as expected. What is it about '22007' that it never outputs anything different despite server resets? There are no references to '22007' anywhere else in the entire project, except the translation map, and I can delete it from that file entirely and restart and the result is no different. It's behaving as if it has cached my override from earlier in the day and will never ever forget. It's not a browser cache issue either, because I can add random query strings and the results are no different.

This is the strangest and most frustrating mod_perl2 experience I've ever had, and I've run out of ideas. Does anybody have any hints? The only thing I can think of is that it's a caching problem, yet I've restarted the service countless times.

Since it was the end of the day I thought I would try fully restarting the server computer, and it still didn't change anything. I even, before restarting the server, changed the only line where {state} is assigned to this:

$$page{error_handling}{state} = 'my face'; # $errno;

And yet, the output afterwards had {test} as '22007', which is what it should be only if I had left = $errno intact.

Even if it was, say, the reverse proxy it goes through doing the caching, this situation doesn't make sense to me, since the request can be different. After a full server restart, how can it still be assigning a value that is no longer in the code, i.e., how can it be using my old $SIG{__DIE__} override after a full restart, when it no longer exists in any file?

Update: I also tried changing the allowed errors to '42601' and changing the db call to 'select', which produces that error code, but did not add it to the translation map. It still gives me behaviour B, setting {state} to '42601', so it's not specific to '22007'. Any error code that is put into {allowed}, if that error actually occurs, it's running the old version of the override. Cause an error that's not in {allowed} and it runs the current version. But how does it know whether the current error is in {allowed}, or that that even means anything, before getting to the override? (Because the override is the only place where {allowed} is grepped for the current error.)

Answer 1

This is my temporary workaround, but I would like to solve the mystery and not have to add the extra line everywhere I have a DB call with allowed errors.

package MyModule::ErrorLogging;
sub InsanityWorkaround # duplicates part of $SIG{__DIE__} override for allowed errors
{
    my ($page) = @_;
    my $r = $$page{r};
    my $errno = $$page{error_handling}{state};
    if ($errno ~~ $$page{error_handling}{allowed})
    {
        # allowed to let it go--no report, expected possible user error at some level that couldn't be caught sooner (usually db level)
        my $errmsg = $$page{error_handling}{translation_map}{$errno};
        if (defined $errmsg)
        {
            use JSON::XS qw(encode_json);
            $$page{json_response} =
            {
                error => $errmsg,
            };
            my $response = encode_json($$page{json_response});
            $r->content_type("application/json");
            $r->print($response);
            exit(0);
        }
        else
        {
            return 0; # get back to script where {state} can be checked and output can be customized even further
        }
    }
    return;
}

Then my script becomes:

{
    $$page{error_handling}{allowed} = ['22007']; # don't be bothered by invalid timestamp error
    $$page{json_response}{result} = $page->one_liner("select 'aa'::timestamp");
    MyModule::ErrorLogging::InsanityWorkaround($page);
}

This is giving behaviour A.