Beefy Boxes and Bandwidth Generously Provided by pair Networks
The stupid question is the question not asked
 
PerlMonks  

Threaded MPM Sharing Variables (this time with complete test code)

by busymeister (Initiate)
on Aug 02, 2011 at 05:57 UTC ( [id://917979]=perlquestion: print w/replies, xml ) Need Help??

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

Hello,

I posted a couple of weeks ago and since I did not get any answers, I am trying again but this time with complete test code that anyone can run on their own machine.

You will need an Apache running in Ubuntu 11.04 with mod_perl 2.0. Then add this code:

package U2D::TestSharing; use strict; use Apache2::Const -compile => qw(OK); use threads; use threads::shared; use APR::OS (); use Time::Format qw(%time); use Apache2::RequestRec; our @fruits :shared = (); sub handler { my $r = shift; $r->content_type('application/json'); { logTestMessage('Waiting for lock.'); lock(@fruits); logTestMessage('Acquired lock.'); if(scalar(@fruits) == 0) { logTestMessage('Initializing fruits.'); push(@fruits,'apple'); push(@fruits,'banana'); push(@fruits,'peach'); } logTestMessage('Releasing lock.'); } my $message = "I like to eat ".join(', ',@fruits)."."; print $message; logTestMessage($message); return Apache2::Const::OK; } sub logTestMessage { my $message = shift; my $tid = APR::OS::current_thread_id(); if(open(FILE,'>>/testSharing.log')) { print FILE $time{'dd-mm-yyyy hh:mm:ss:mmm'}.' '.$$.'-'.$tid.': + '.$message."\n"; close(FILE); } else { print $!."\n"; } } 1;

Add the following lines to apache2.conf (or uncomment the specified lines):

<IfModule mpm_worker_module> StartServers 1 MinSpareThreads 5 ThreadsPerChild 20 MaxRequestsPerChild 0 ServerLimit 1 PerlInterpMax 1 </IfModule>

To the site configuration also add:

<Location /testSharing> SetHandler perl-script PerlResponseHandler U2D::TestSharing </Location>

Then write a little JavaScript that loops 100 times and calls http://localhost/testSharing and check the log file. Here I am posting the beginning of the log on my machine:

02-08-2011 07:42:27:552 2669-3063479152: Waiting for lock. 02-08-2011 07:42:27:565 2669-3063479152: Acquired lock. 02-08-2011 07:42:27:566 2669-3063479152: Initializing fruits. 02-08-2011 07:42:27:566 2669-3063479152: Releasing lock. 02-08-2011 07:42:27:566 2669-3063479152: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:578 2669-3063479152: Waiting for lock. 02-08-2011 07:42:27:578 2669-3063479152: Acquired lock. 02-08-2011 07:42:27:578 2669-3063479152: Releasing lock. 02-08-2011 07:42:27:578 2669-3063479152: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:578 2669-3021515632: Waiting for lock. 02-08-2011 07:42:27:579 2669-3021515632: Acquired lock. 02-08-2011 07:42:27:579 2669-3021515632: Releasing lock. 02-08-2011 07:42:27:579 2669-3021515632: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:574 2669-3046693744: Waiting for lock. 02-08-2011 07:42:27:582 2669-3046693744: Acquired lock. 02-08-2011 07:42:27:582 2669-3046693744: Initializing fruits. 02-08-2011 07:42:27:582 2669-3046693744: Releasing lock. 02-08-2011 07:42:27:582 2669-3046693744: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:583 2669-3063479152: Waiting for lock. 02-08-2011 07:42:27:583 2669-3063479152: Acquired lock. 02-08-2011 07:42:27:583 2669-3063479152: Releasing lock. 02-08-2011 07:42:27:583 2669-3063479152: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:588 2669-3063479152: Waiting for lock. 02-08-2011 07:42:27:588 2669-3063479152: Acquired lock. 02-08-2011 07:42:27:588 2669-3063479152: Releasing lock. 02-08-2011 07:42:27:588 2669-3063479152: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:581 2669-3055086448: Waiting for lock. 02-08-2011 07:42:27:589 2669-3055086448: Acquired lock. 02-08-2011 07:42:27:589 2669-3055086448: Initializing fruits. 02-08-2011 07:42:27:589 2669-3055086448: Releasing lock. 02-08-2011 07:42:27:589 2669-3055086448: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:582 2669-3038301040: Waiting for lock. 02-08-2011 07:42:27:589 2669-3038301040: Acquired lock. 02-08-2011 07:42:27:589 2669-3038301040: Initializing fruits. 02-08-2011 07:42:27:589 2669-3038301040: Releasing lock. 02-08-2011 07:42:27:590 2669-3038301040: I like to eat apple, banana, +peach. 02-08-2011 07:42:27:588 2669-3013122928: Waiting for lock. 02-08-2011 07:42:27:594 2669-3013122928: Acquired lock. 02-08-2011 07:42:27:594 2669-3013122928: Initializing fruits. 02-08-2011 07:42:27:594 2669-3013122928: Releasing lock. 02-08-2011 07:42:27:594 2669-3013122928: I like to eat apple, banana, +peach.

The fruits array is initialized multiple times. This is not expected at all since the fruits array is shared and we are always running in the same process. Can anyone tell me why this code does not work?

Thank you for your help in advance. I hope someone can shed some light on this problem that I am having for weeks now.

Sincerely,

Pawel

SSSSSSSSOOOOOLLLLLLLVVVVVVEEEEEEEDDDDDDD:

The problem is that the shared variable needs to be loaded BEFORE the threads are created. This is done by creating a startup.pl file and adding PerlRequire startup.pl to the VirtualHost config. The entire startup.pl file looks like this:

use strict; use warnings FATAL => 'all'; require threads; "threads"->import(); use U2D::TestSharing (); 1;

Once I did this and added the sleep(1); to the handler as I discussed below then everything worked like a charm. The fruits array was created only once and shared by the other threads. All threads locked and waited just as I would expect. If you don't believe me, tail -f testSharing.log and watch the beauty unfold before your own eyes!

LOAD YOUR SHARED VARIABLES IN THE STARTUP.PL FILE BEFORE USING THEM IN THE HANDLERS!!!

Replies are listed 'Best First'.
Re: Threaded MPM Sharing Variables (this time with complete test code)
by Neighbour (Friar) on Aug 02, 2011 at 08:52 UTC

    Could you perhaps include said javascript?
    It seems to almost-work under my ubuntu 10.04.3 if I just access http://mymachine/testSharing, I'm getting this:

    Permission denied Permission denied Permission denied Permission denied I like to eat apple, banana, peach.Permission denied

Re: Threaded MPM Sharing Variables (this time with complete test code)
by Neighbour (Friar) on Aug 02, 2011 at 11:16 UTC
    After updating the site configuration to
    <Location /testSharing> Options -MultiViews SetHandler perl-script PerlResponseHandler U2D::TestSharing </Location>
    because apparently MultiViews doesn't work well with the code for updating the logfile.
    I'm getting the following output when holding down F5 a few seconds in my browser: That looks reasonably like the result you wanted, so I wonder what's happening on your end that makes things different.
    Oh, and I changed your logTestMessage a bit, since / is not a writable location for apache (hence the 'permission denied's I was getting).
    sub logTestMessage { my $message = shift; my $tid = APR::OS::current_thread_id(); if(open(FILE,'>>','/var/www/testSharing.log')) { print FILE $time{'dd-mm-yyyy hh:mm:ss:mmm'}.' '.$$.'-'.$tid.': + '.$message."\n"; close(FILE); } else { print "Error opening file: ".$!."\n"; } }
      After a few more attempts at leaning on F5, I am indeed getting multiple "Initializing"-lines in the logfile.
      Then this occurred to me:
      root@myserver:/usr/local/lib/site_perl/U2D# ps aux | grep apa root 9546 0.0 0.3 148856 9920 ? Ss 13:16 0:00 /usr/ +sbin/apache2 -k start www-data 9549 0.0 0.3 173424 9880 ? S 13:16 0:00 /usr/ +sbin/apache2 -k start www-data 9550 0.0 0.3 173424 9860 ? S 13:16 0:00 /usr/ +sbin/apache2 -k start www-data 9551 0.0 0.3 173424 9860 ? S 13:16 0:00 /usr/ +sbin/apache2 -k start www-data 9552 0.0 0.3 173424 9860 ? S 13:16 0:00 /usr/ +sbin/apache2 -k start www-data 9553 0.0 0.3 173424 9860 ? S 13:16 0:00 /usr/ +sbin/apache2 -k start www-data 9618 0.0 0.3 173424 9860 ? S 13:19 0:00 /usr/ +sbin/apache2 -k start root 9723 0.0 0.0 7624 920 pts/0 S+ 13:20 0:00 grep +apa root@myserver:/usr/local/lib/site_perl/U2D# grep Initializing /var/www +/testSharing.log 02-08-2011 13:19:38:736 9549-172922688: Initializing fruits. 02-08-2011 13:19:39:361 9550-172922688: Initializing fruits. 02-08-2011 13:19:39:426 9551-172922688: Initializing fruits. 02-08-2011 13:19:39:457 9552-172922688: Initializing fruits. 02-08-2011 13:19:39:480 9553-172922688: Initializing fruits. 02-08-2011 13:19:39:499 9618-172922688: Initializing fruits.
      Which leads me to think that for each running instance of apache2, the variable will have to be initialized at least once. Or is that too shortsighted?

        Hello Neighbour,

        Here is the javascript code:

        function init() { var options = { type: "POST", url: "testSharing", }; for(var i = 0; i < 100; i++) $.ajax(options); } $(document).ready(init);

        You need to download jQuery so that this code works but you can also create equivalent code that does not use jQuery and that does the same thing. At least you have the idea of what I am doing.

        As far as permissions go:

        sudo chown www-data:www-data /testSharing.log sudo chmod 660 /testSharing.log

        will do the trick.

        In your case, you are running multiple processes, as you can see in your log output (the four digit number before the hyphen after the milliseconds field). In order to force Apache to run as a single process with multiple threads, you need to change the config in apache2.conf by adding/changing:

        <IfModule mpm_worker_module> StartServers 1 MinSpareThreads 5 ThreadsPerChild 20 MaxRequestsPerChild 0 ServerLimit 1 PerlInterpMax 1 </IfModule>

        Also, install the worker mpm by running:

        sudo apt-get install apache2-mpm-worker

        Then, you will only have a single process and multiple threads, as you will clearly see when you run the javascript above and check the log file.

        I hope someone can help me with this problem. Still not clear why multiple instances are initialized.

        Sincerely,

        Pawel

Log In?
Username:
Password:

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: perlquestion [id://917979]
Approved by davido
help
Chatterbox?
and the web crawler heard nothing...

How do I use this?Last hourOther CB clients
Other Users?
Others studying the Monastery: (5)
As of 2024-04-19 00:53 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    No recent polls found