Re: Apache::Session not updating (writing)

[prev] [thread] [next] [Date index for 2005/05/19]

On 5/11/05, Perrin Harkins <perrin@xxxx.xxx> wrote:
> This is starting to sound like your problem is at a very fundamental
> level.  I'd suggest making sure RaiseError is on for your database
> connection, and putting some warn statements in the Apache::Session code
> to see that things are being called (i.e. DESTROY(), save(), etc.) or
> running it in the debugger.

Well, I took your advice....


I am attempting to use MasonX::Request::WithApacheSession with a MySQL
backend and it is not updating. In order to debug I have copied mason
code over to a normal perl program. I basically stripped out all
mason/html code. I have also placed debugging print statements all
over the Apache::Session (and related) code. I basically put these
statements in key places so I could debug under Mason. I am also using
these debug statements to compare behaviour between the command line
version of the program and the mason version. Below is the commandline
version of the program. It simply creates a session, sets some key
values and then loads the session again and prints out the data again.

#!/usr/bin/perl
use lib '/data/projects/cas3/trunk/lib';
use AMP;
use AMP::DBI;
use Apache::Session::MySQL;

my $dbh =3D AMP::DBI->connect();
my $session_id;

sub create
{
       my %session;
       print STDERR "CREATING TEST SESSION\n";
       tie %session, 'Apache::Session::MySQL', undef, {
               Handle     =3D> $dbh,
               LockHandle =3D> $dbh
       };

       $session_id =3D $session{'_session_id'};

       print STDERR "THE SESSION ID FOR THE TEST SESSION IS [$session_id]\n=
";

       print "Setting some of the session keys of session id
[$session{'_session_id'}]\n";

       $session{'car'} =3D {
               make =3D> 'BMW',
               year =3D> '2005',
               model =3D> 'M3',
               color =3D> 'Interlagos Blue'
       };

       print "Dumping contents of \%session [$session{_session_id}]\n";
       for my $key (keys %session) {
               print "[$key] =3D> [$session{$key}]\n";
       }

       #undef %session;
}

sub load
{
       my %load;
       tie %load, 'Apache::Session::MySQL', $session_id, {
               Handle     =3D> $dbh,
               LockHandle =3D> $dbh
       };

       print "DUMPING Session from %load\n";
       for my $key (sort keys %load) {
               print "[$key] =3D> [$load{$key}]\n";
       }
}

create();
load();

#----------------------------------END OF COMMANDLINE
VERSION----------------------------------------

When I run this and redirect STDIN and STDERR to a file, I get in the log f=
ile:

CREATING TEST SESSION
[Apache::Session::save] class [Apache::Session::MySQL] called by
[Apache::Session]
$self->{status} =3D [1]
[Apache::Session::save] class [Apache::Session::MySQL] : Made it past
1st return statement.
[Apache::Session::save] class [Apache::Session::MySQL] : In 'NEW' block.
[Apache::Session::Store::DBI::insert] class
[Apache::Session::Store::MySQL] Called
[Apache::Session::Store::DBI::insert] DUMPING $session
$VAR1 =3D bless( {
                'object_store' =3D> bless( {
                                           'table_name' =3D> 'sessions'
                                         }, 'Apache::Session::Store::MySQL'=
 ),
                'status' =3D> 1,
                'lock' =3D> 2,
                'args' =3D> {
                            'LockHandle' =3D> bless( {}, 'AMP::DBI::db' ),
                            'Handle' =3D> $VAR1->{'args'}{'LockHandle'}
                          },
                'serialize' =3D> sub { "DUMMY" },
                'data' =3D> {
                            '_session_id' =3D> 'c23fa2253c3ce36de1fbd097529=
db126'
                          },
                'unserialize' =3D> sub { "DUMMY" },
                'lock_manager' =3D> bless( {
                                           'lockid' =3D>
'Apache-Session-c23fa2253c3ce36de1fbd097529db126',
                                           'lock' =3D> 1,
                                           'dbh' =3D>
$VAR1->{'args'}{'LockHandle'},
                                           'mine' =3D> 0
                                         }, 'Apache::Session::Lock::MySQL' =
),
                'generate' =3D> sub { "DUMMY" },
                'serialized' =3D> '^E^F^C^@^@^@^A
 c23fa2253c3ce36de1fbd097529db126^@^@^@^K_session_id',
                'validate' =3D> sub { "DUMMY" }
              }, 'Apache::Session::MySQL' );
Apache::Session::TIEHASH called [Apache::Session::MySQL]
THE SESSION ID FOR THE TEST SESSION IS [c23fa2253c3ce36de1fbd097529db126]
[Apache::Session::DESTROY] class [Apache::Session::MySQL] called by [main]
[Apache::Session::save] class [Apache::Session::MySQL] called by
[Apache::Session]
$self->{status} =3D [10]
[Apache::Session::save] class [Apache::Session::MySQL] : Made it past
1st return statement.
[Apache::Session::save] class [Apache::Session::MySQL] : In 'MODIFIED' bloc=
k.
[Apache::Session::save] class [Apache::Session::MySQL] : In 'MODIFIED'
block right after call to serialize.
[Apache::Session::Store::DBI::update] class
[Apache::Session::Store::MySQL] called by [Apache::Session]
Trace begun at /usr/local/lib/perl5/site_perl/5.8.6/Apache/Session/Store/DB=
I.pm
line 67
Apache::Session::Store::DBI::update('Apache::Session::Store::MySQL=3DHASH(0=
x863f44c)',
'Apache::Session::MySQL=3DHASH(0x863df88)') called at
/usr/local/lib/perl5/site_perl/5.8.6/Apache/Session.pm line 542
Apache::Session::save('Apache::Session::MySQL=3DHASH(0x863df88)') called
at /usr/local/lib/perl5/site_perl/5.8.6/Apache/Session.pm line 485
Apache::Session::DESTROY('Apache::Session::MySQL=3DHASH(0x863df88)')
called at session.pl line 54
eval {...} at session.pl line 54
main::create at session.pl line 54
[Apache::Session::Store::DBI::update] session id
[c23fa2253c3ce36de1fbd097529db126].
[Apache::Session::Store::DBI::update] $self->{update_sth} was not defined.
[Apache::Session::Store::DBI::update] SQL [UPDATE sessions SET
a_session =3D ? WHERE id =3D ?]
[Apache::Session::Store::DBI::update] created new statement handle.
[Apache::Session::Store::DBI::update] DUMPING $session
$VAR1 =3D bless( {
                'object_store' =3D> bless( {
                                           'insert_sth' =3D> bless( {},
'AMP::DBI::st' ),
                                           'dbh' =3D> bless( {},
'AMP::DBI::db' ),
                                           'table_name' =3D> 'sessions',
                                           'update_sth' =3D> bless( {},
'AMP::DBI::st' )
                                         }, 'Apache::Session::Store::MySQL'=
 ),
                'status' =3D> 10,
                'lock' =3D> 2,
                'args' =3D> {
                            'LockHandle' =3D> $VAR1->{'object_store'}{'dbh'=
},
                            'Handle' =3D> $VAR1->{'object_store'}{'dbh'}
                          },
                'serialize' =3D> sub { "DUMMY" },
                'data' =3D> {
                            '_session_id' =3D>
'c23fa2253c3ce36de1fbd097529db126',
                            'car' =3D> {
                                       'color' =3D> 'Interlagos Blue',
                                       'make' =3D> 'BMW',
                                       'model' =3D> 'M3',
                                       'year' =3D> '2005'
                                     }
                          },
                'unserialize' =3D> sub { "DUMMY" },
                'lock_manager' =3D> bless( {
                                           'lockid' =3D>
'Apache-Session-c23fa2253c3ce36de1fbd097529db126',
                                           'lock' =3D> 1,
                                           'dbh' =3D>
$VAR1->{'object_store'}{'dbh'},
                                           'mine' =3D> 0
                                         }, 'Apache::Session::Lock::MySQL' =
),
                'generate' =3D> sub { "DUMMY" },
                'serialized' =3D> '^E^F^C^@^@^@^B
 c23fa2253c3ce36de1fbd097529db126^@^@^@^K_session_id^D^C^@^@^@^D
^OInterlagos Blue^@^@^@^Ecolor
^CBMW^@^@^@^Dmake
^BM3^@^@^@^Emodel
^D2005^@^@^@^Dyear^@^@^@^Ccar',
                'validate' =3D> sub { "DUMMY" }
              }, 'Apache::Session::MySQL' );
[Apache::Session::Store::DBI::update] Calling DBI's execute.
[Apache::Session::save] class [Apache::Session::MySQL] : In 'MODIFIED'
block right after call to update.
[Apache::Session::Store::MySQL::DESTROY] class
[Apache::Session::Store::MySQL] Called
[Apache::Session::Store::MySQL::DESTROY] DUMPING $self->{dbh}
$VAR1 =3D bless( {}, 'AMP::DBI::db' );
[Apache::Session::Store::DBI::materialize] Called
Apache::Session::TIEHASH called [Apache::Session::MySQL]
[Apache::Session::DESTROY] class [Apache::Session::MySQL] called by [main]
[Apache::Session::save] class [Apache::Session::MySQL] called by
[Apache::Session]
$self->{status} =3D [8]
[Apache::Session::Store::MySQL::DESTROY] class
[Apache::Session::Store::MySQL] Called
[Apache::Session::Store::MySQL::DESTROY] DUMPING $self->{dbh}
$VAR1 =3D bless( {}, 'AMP::DBI::db' );
Setting some of the session keys of session id
[c23fa2253c3ce36de1fbd097529db126]
Dumping contents of %session [c23fa2253c3ce36de1fbd097529db126]
[_session_id] =3D> [c23fa2253c3ce36de1fbd097529db126]
[car] =3D> [HASH(0x804d08c)]
DUMPING Session from %load
[_session_id] =3D> [c23fa2253c3ce36de1fbd097529db126]
[car] =3D> [HASH(0x8674a78)]

END OF LOG OUTPUT

As you can see, everything works fine. The thing that I was especially
concerned about was the call to Apache::Session::save and
Apache::Session::Store::DBI::update. This is happening in the command
line version but not the Mason version. The Mason version consist of
two html pages. There is one named set.html which sets the data values
and is supposed to save the values to the database. This does not
happen. There is also a dump.html which is supposed to dump the data
backout. Also note there is also a system-wide
MasonX::Request::WithApacheSession working around everything, so there
seems to be two calls to everything....

Here is the set.html

<%perl>
       my $session_id;
       my %copy;
       {
               my %session;
               print STDERR "CREATING TEST SESSION\n";
               tie %session, 'Apache::Session::MySQL', undef, {
                       Handle     =3D> $DBH,
                       LockHandle =3D> $DBH
               };

               $session_id =3D $session{'_session_id'};

               print STDERR "THE SESSION ID FOR THE TEST SESSION IS
[$session_id]\n";

               $session{'car'} =3D {
                       make =3D> 'BMW',
                       year =3D> '2005',
                       model =3D> 'M3',
                       color =3D> 'Interlagos Blue'
               };

               $session{'user'} =3D $USEROBJECT;

               for my $key (keys %session)
               {
                       $copy{$key} =3D $session{$key};
               }
       }
</%perl>

       <h3>Dumping contents of %session <% $session_id %></h3>
% for my $key (keys %copy) {
       <h3><% $key %> =3D <% $copy{$key} %></h3>
% }

<h3><a href=3D"dump.html?id=3D<% $session_id %>">dump.html</a></h3>

And here is the dump.html

[ cas3@www ] $ vi dump.html
<%args>
       $id
</%args>
<%perl>
       my %session;
       tie %session, 'Apache::Session::MySQL', $id, {
               Handle     =3D> $DBH,
               LockHandle =3D> $DBH
       };
</%perl>

       <h3>DUMPING Session from %session</h3>
% for my $key (sort keys %session) {
       <h3><% $key %> =3D <% $session{$key} %></h3>
% }

<h3><a href=3D"set.html">set.html</a></h3>

And finally here is the output from STDERR from the call to set.html

[Apache::Session::Store::DBI::materialize] Called
Apache::Session::TIEHASH called [Apache::Session::MySQL]
CREATING TEST SESSION
[Apache::Session::save] class [Apache::Session::MySQL] called by
[Apache::Session]
$self->{status} =3D [1]
[Apache::Session::save] class [Apache::Session::MySQL] : Made it past
1st return statement.
[Apache::Session::save] class [Apache::Session::MySQL] : In 'NEW' block.
[Apache::Session::Store::DBI::insert] class
[Apache::Session::Store::MySQL] Called
[Apache::Session::Store::DBI::insert] DUMPING $session
$VAR1 =3D bless( {
                'object_store' =3D> bless( {
                                           'table_name' =3D> 'sessions'
                                         }, 'Apache::Session::Store::MySQL'=
 ),
                'status' =3D> 1,
                'lock' =3D> 2,
                'args' =3D> {
                            'LockHandle' =3D> bless( {}, 'AMP::DBI::db' ),
                            'Handle' =3D> $VAR1->{'args'}{'LockHandle'}
                          },
                'serialize' =3D> sub { "DUMMY" },
                'data' =3D> {
                            '_session_id' =3D> '3396efdc19ce464e198284efcc9=
6688e'
                          },
                'unserialize' =3D> sub { "DUMMY" },
                'lock_manager' =3D> bless( {
                                           'lockid' =3D>
'Apache-Session-3396efdc19ce464e198284efcc96688e',
                                           'lock' =3D> 1,
                                           'dbh' =3D>
$VAR1->{'args'}{'LockHandle'},
                                           'mine' =3D> 0
                                         }, 'Apache::Session::Lock::MySQL' =
),
                'generate' =3D> sub { "DUMMY" },
                'serialized' =3D> '
 3396efdc19ce464e198284efcc96688e
                                _session_id',
                'validate' =3D> sub { "DUMMY" }
              }, 'Apache::Session::MySQL' );
Apache::Session::TIEHASH called [Apache::Session::MySQL]
THE SESSION ID FOR THE TEST SESSION IS [3396efdc19ce464e198284efcc96688e]
[Apache::Session::DESTROY] class [Apache::Session::MySQL] called by
[HTML::Mason::Commands]
[Apache::Session::save] class [Apache::Session::MySQL] called by
[Apache::Session]
$self->{status} =3D [10]
[Apache::Session::save] class [Apache::Session::MySQL] : Made it past
1st return statement.
[Apache::Session::save] class [Apache::Session::MySQL] : In 'MODIFIED' bloc=
k.
[Apache::Session::Store::MySQL::DESTROY] class
[Apache::Session::Store::MySQL] Called
[Apache::Session::Store::MySQL::DESTROY] DUMPING $self->{dbh}
$VAR1 =3D bless( {}, 'AMP::DBI::db' );
PuTTY[Apache::Session::DESTROY] class [Apache::Session::MySQL] called
by [MasonX::Request::WithApacheSession]
[Apache::Session::save] class [Apache::Session::MySQL] called by
[Apache::Session]
$self->{status} =3D [10]
[Apache::Session::save] class [Apache::Session::MySQL] : Made it past
1st return statement.
[Apache::Session::save] class [Apache::Session::MySQL] : In 'MODIFIED' bloc=
k.
[Apache::Session::Store::MySQL::DESTROY] class
[Apache::Session::Store::MySQL] Called
[Apache::Session::Store::MySQL::DESTROY] DUMPING $self->{dbh}
$VAR1 =3D bless( {}, 'Apache::DBI::db' );
[Wed May 18 22:25:56 2005] [error] [client 24.39.114.170] File does
not exist: /data/www/cas3/htdocs/css/main_bg.jpg
[Wed May 18 22:25:58 2005] [error] [client 24.39.114.170] File does
not exist: /data/www/cas3/htdocs/favicon.ico

So the thing that I can't figure out is why there is no call to
Apache::Session::Store::DBI::update in the Mason version. Here is an
excerpt of my debugging code filled version of Apache::Session:

sub save {
   my $self =3D shift;

   my $func =3D __PACKAGE__ . "::save";
   my $class =3D ref $self;
   my $caller =3D caller;
   print STDERR "[$func] class [$class] called by [$caller]\n";
   print STDERR "\$self->{status} =3D [$self->{status}]\n";

   return unless (
       $self->{status} & MODIFIED ||
       $self->{status} & NEW      ||
       $self->{status} & DELETED
   );

   print STDERR "[$func] class [$class] : Made it past 1st return
statement.\n";

   $self->acquire_write_lock;

   if ($self->{status} & DELETED) {
       print STDERR "[$func] class [$class] : In 'DELETED' block.\n";
       $self->{object_store}->remove($self);
       $self->{status} |=3D SYNCED;
       $self->{status} &=3D ($self->{status} ^ MODIFIED);
       $self->{status} &=3D ($self->{status} ^ DELETED);
       return;
   }
   if ($self->{status} & MODIFIED) {
       print STDERR "[$func] class [$class] : In 'MODIFIED' block.\n";
       &{$self->{serialize}}($self);
       print STDERR "[$func] class [$class] : In 'MODIFIED' block
right after call to serialize.\n";
       $self->{object_store}->update($self);
       print STDERR "[$func] class [$class] : In 'MODIFIED' block
right after call to update.\n";
       $self->{status} &=3D ($self->{status} ^ MODIFIED);
       $self->{status} |=3D SYNCED;
       return;
   }
   if ($self->{status} & NEW) {
       print STDERR "[$func] class [$class] : In 'NEW' block.\n";
       &{$self->{serialize}}($self);
       $self->{object_store}->insert($self);
       $self->{status} &=3D ($self->{status} ^ NEW);
       $self->{status} |=3D SYNCED;
       $self->{status} &=3D ($self->{status} ^ MODIFIED);
       return;
   }
}

I am completely stumped. Someone PLEASE HELP!

Thanks to anyone who actually goes through this code! =3D)

Rick