What we found is that Perl is not thread-safe. Let me repeat that: PERL IS NOT THREAD-SAFE! I say this with emphasis because after several long nights hunting down segfaults in the system, turning on debugging, adding evals to trap errors, banging my head, I came across this in the log:

Bizarre ARRAY copy in caller() at Common::Logger::log_stuff ...
[download]

I strongly encourage you to investigate the possibility of dead threads fouling your app. Then look at alternatives to a threaded model. We moved to a multi-tiered Apache platform. We have an Apache "front-end" that talks to an Apache "back-end" (which in turn can talk to itself; we have layers of parallel and serially parallel processing).

When we mentioned to merlyn, TheDamien, and Nick Clark that we were looking at the threaded approach when we were at OSCON 2005, they all pretty much wished us luck. I do the same for you now.

What we found is that Perl is not thread-safe. Let me repeat that: PERL IS NOT THREAD-SAFE!

That sentance makes no sense at all.

Bizarre ARRAY copy in caller() at Common::Logger::log_stuff ...

Common::Logger is our internal logging package. log_stuff is the logging function. It calls CORE::caller(). This blew up.

Hmm. Did you report this 'bug'?

It's quite possible to generate the 'Bizarre ARRAY copy' bug in perfectly ordinary, non-threaded bad code. What's more, perl will often not give you much in the way of clues as to what you are doing wrong when it happens.

I don't know what version of Perl you were using, but it seems quite unlikely that using caller with threads is a problem. Set the loop counters in the following code to any values you like; or increase the depth of sub calls as far as you like, and it will run for as long as you let it without producing a "bizarre array copy error". Or any other error.

#! perl -slw
use strict;
use threads;

sub t1{
    printf "%3d:t1: %s\n", threads->tid, join '|', grep defined, calle
+r(1);
    return
}

sub t2 {
    t1();
    printf "%3d:t2: %s\n", threads->tid, ''; '|',  grep defined, calle
+r(1);
    return
}

sub t3 {
    for( 1 .. 100 ) {
        t2();
        printf "%3d:t3: %s\n", threads->tid, join '|',  grep defined, 
+caller(1);
    }
    return;
}

my @threads = map{ threads->create( \&t3 ) } 1 .. 100;
sleep 3;
$_->join for @threads;
[download]

It seems much more likely that your Common::Logger class was not written to be called from multiple threads. Indeed, the most likely scenario is that you were passing objects between threads. That's a documented no no.

Most modern cars are pretty safe, but if you attempt to climb trees in them, it's likely to be unsuccessful; but saying cars are useless because your tree climbing attempt went ary, is unlikely to garner much support, even from the tree-hugging, cars-are-evil crowd.

---

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.

The threads themselves seem to work fine until mod_perl is switched on. The application is live in it's non mod_perl version at the moment. But yes, it took us a long time to get to the stage where we got something other than bizarre errors in the log. And with mod_perl, they just get ever stranger.

We actually started as non-threading, using a simple Perl powered web server (HTTP::Server based I think it was) plus LWP::Paralllel on the front-end to connect to it with different parameters, which it then went off and processed. But it all became too slow and unwieldy as the number of searches increased and the Perl webserver forked more and more. Returning to an LWP::Parallel process connecting to a more stable backend (like a light web server) is tempting, if only for scalability reasons.

But darnit, when you've come this far, sometimes you just want things to work. :)

It happens immediately. And the access_log shows the item immediately, it just doesn't appear to have run anything.

One thing I forgot to mention, was that under Apache2, there is an occassional message in the error_log about load.pm not being able to find index.pl (the script the .phtml URL's get pushed through) at line 256.

Could not find file for 'Apache::ROOTwww_2ethesite_2eco_2euk::index_2epl' at /usr/local/share/perl/5.8.7/load.pm line 256.