You are here: Foswiki>Tasks Web>Item10987 (19 Aug 2011, SvenDowideit)Edit Attach

Item10987: MongoDBPlugin borks FoswikI::Form $session->{forms} "cache" because constructor is never called properly

pencil
Priority: Urgent
Current State: Closed
Released In: n/a
Target Release: n/a
Applies To: Extension
Component: MongoDBPlugin
Branches:
Reported By: PaulHarvey
Waiting For:
Last Change By: SvenDowideit
Symptom: sometimes, the edit screen fails to render a form.

This is because Foswiki::Form->renderForEdit() doesn't bother re-parsing the topic text for field definitions if it's already in the $session->{forms} cache.

These commented-out lines are the culprit (but commenting out these lines causes other issues):

diff --git a/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm b/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm
index d80975e..6c7c98c 100644
--- a/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm
+++ b/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm
@@ -218,13 +218,13 @@ sub loadTopic {
     bless( $_[1], 'Foswiki::Plugins::MongoDBPlugin::Meta' );
     $_[1]->reload();    #get the latest version
     $_[1]->{_latestIsLoaded} = 1;
-    if ( $_[1]->topic =~ /Form$/ ) {
-        use Foswiki::Form;
-        bless( $_[1], 'Foswiki::Form' );
-
-        $session->{forms}->{ $_[1]->web . '.' . $_[1]->topic } = $_[1];
-        print STDERR "------ init Form obj\n" if MONITOR;
-    }
+#    if ( $_[1]->topic =~ /Form$/ ) {
+#        use Foswiki::Form;
+#        bless( $_[1], 'Foswiki::Form' );
+#
+#        $session->{forms}->{ $_[1]->web . '.' . $_[1]->topic } = $_[1];
+#        print STDERR "------ init Form obj\n" if MONITOR;
+#    }
 
     $session->search->metacache->addMeta( $_[1]->web, $_[1]->topic, $_[1] );
     

MongoDBPlugin is just blessing Foswiki::Form objects directly, and the Foswiki::Form->new() constructor is never called.

So we end up with unparsed Foswiki::Form objects in the $session->{forms} cache.

Need to figure out if random occurrences where supposedly $formObj things are actually Foswiki::Meta (eg. calls to ->getAvailableForms fail) are linked to this problem.

Here's the patch I implemented as a temporary work-around:

diff --git a/lib/Foswiki/Form.pm b/lib/Foswiki/Form.pm
index 261e201..c270e0a 100644
--- a/lib/Foswiki/Form.pm
+++ b/lib/Foswiki/Form.pm
@@ -75,7 +75,7 @@ sub new {
     my ( $class, $session, $web, $form, $def ) = @_;
 
     my $this = $session->{forms}->{"$web.$form"};
-    unless ($this) {
+    unless ($this and $this->{_parsed}) {
 
         # A form name has to be a valid topic name after normalisation
         my ( $vweb, $vtopic ) = $session->normalizeWebTopicName( $web, $form );
@@ -106,6 +106,7 @@ sub new {
 
         $this = $class->SUPER::new( $session, $vweb, $vtopic );
         $session->{forms}->{"$web.$form"} = $this;
+        $this->{_parsed} = 1;
 
         unless ( $def || $this->haveAccess('VIEW') ) {
             throw Foswiki::AccessControlException( 'VIEW', $session->{user},
@@ -396,6 +397,8 @@ sub renderForEdit {
     my ( $text, $repeatTitledText, $repeatUntitledText, $afterText ) =
       split( /%REPEAT%/, $tmpl );
 
+    #require Data::Dumper;
+    #Foswiki::Func::writeDebug("fieldDef: " . Data::Dumper->Dump([$this]));
     foreach my $fieldDef ( @{ $this->{fields} } ) {
 
         my $value;

-- PaulHarvey - 19 Jul 2011

This is still busted:

Can't locate object method "getFields" via package "Foswiki::Plugins::MongoDBPlugin::Meta" at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Plugins/JQGridPlugin/GRID.pm line 221.
 at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Plugins/JQGridPlugin/GRID.pm line 221
   Foswiki::Plugins::JQGridPlugin::GRID::handleGrid('Foswiki::Plugins::JQGridPlugin::GRID=HASH(0x41c0938)', 'Foswiki::Attrs=HASH(0x39862d8)', 'Taxa', 'TaxonProfile/Builder', 'Foswiki::Plugins::MongoDBPlugin::Meta=HASH(0x3985758)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Plugins/JQGridPlugin.pm line 60
   Foswiki::Plugins::JQGridPlugin::handleGrid('Foswiki=HASH(0x1b76778)', 'Foswiki::Attrs=HASH(0x39862d8)', 'Taxa', 'TaxonProfile/Builder', 'Foswiki::Plugins::MongoDBPlugin::Meta=HASH(0x3985758)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Func.pm line 568
   Foswiki::Func::__ANON__('Foswiki=HASH(0x1b76778)', 'Foswiki::Attrs=HASH(0x39862d8)', 'Foswiki::Plugins::MongoDBPlugin::Meta=HASH(0x3985758)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki.pm line 3064
   Foswiki::_expandMacroOnTopicRendering('Foswiki=HASH(0x1b76778)', 'GRID', '
   query="form.name"
   fields="Topic,Modified,By,PlumeMoths...', 'Foswiki::Plugins::MongoDBPlugin::Meta=HASH(0x3985758)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki.pm line 2940
   Foswiki::_processMacros('Foswiki=HASH(0x1b76778)', '---++ All Taxa

[[%BASEWEB%.TaxonCreator][ %ICON{"newtopic"}%...', 'CODE(0x1adb188)', 'Foswiki::Plugins::MongoDBPlugin::Meta=HASH(0x3985758)', 16) called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki.pm line 2737
   Foswiki::innerExpandMacros('Foswiki=HASH(0x1b76778)', 'SCALAR(0x37ce280)', 'Foswiki::Plugins::MongoDBPlugin::Meta=HASH(0x3985758)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Macros/INCLUDE.pm line 296
   Foswiki::__ANON__() called at /usr/share/perl5/Error.pm line 416
   eval {...} called at /usr/share/perl5/Error.pm line 408
   Error::subs::try('CODE(0x3f2c880)', 'HASH(0x3f2d420)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Macros/INCLUDE.pm line 343
   Foswiki::INCLUDE('Foswiki=HASH(0x1b76778)', 'Foswiki::Attrs=HASH(0x3985380)', 'Foswiki::Meta=HASH(0x36a8610)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki.pm line 3064
   Foswiki::_expandMacroOnTopicRendering('Foswiki=HASH(0x1b76778)', 'INCLUDE', '"TaxonProfile/Builder.Taxa" NAMESPACE="PlumeMoths" DEFAULTPRO...', 'Foswiki::Meta=HASH(0x36a8610)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki.pm line 2940
   Foswiki::_processMacros('Foswiki=HASH(0x1b76778)', '%INCLUDE{"%BUILDERWEB%.%TOPIC%" NAMESPACE="PlumeMoths" DEFAUL...', 'CODE(0x1adb188)', 'Foswiki::Meta=HASH(0x36a8610)', 16) called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki.pm line 2737
   Foswiki::innerExpandMacros('Foswiki=HASH(0x1b76778)', 'SCALAR(0x36b4518)', 'Foswiki::Meta=HASH(0x36a8610)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki.pm line 3246
   Foswiki::expandMacros('Foswiki=HASH(0x1b76778)', '%INCLUDE{"%BUILDERWEB%.%TOPIC%" NAMESPACE="PlumeMoths" DEFAUL...', 'Foswiki::Meta=HASH(0x36a8610)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Meta.pm line 3108
   Foswiki::Meta::expandMacros('Foswiki::Meta=HASH(0x36a8610)', '%INCLUDE{"%BUILDERWEB%.%TOPIC%" NAMESPACE="PlumeMoths" DEFAUL...') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/UI/View.pm line 406
   Foswiki::UI::View::_prepare('%INCLUDE{"%BUILDERWEB%.%TOPIC%" NAMESPACE="PlumeMoths" DEFAUL...', 'Foswiki::Meta=HASH(0x36a8610)', 0) called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/UI/View.pm line 386
   Foswiki::UI::View::view('Foswiki=HASH(0x1b76778)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/UI.pm line 316
   Foswiki::UI::__ANON__() called at /usr/share/perl5/Error.pm line 416
   eval {...} called at /usr/share/perl5/Error.pm line 408
   Error::subs::try('CODE(0x1458fb8)', 'HASH(0x1b8cc10)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/UI.pm line 435
   Foswiki::UI::_execute('Foswiki::Request=HASH(0x14827d0)', 'CODE(0x1b56918)', 'command_line', 1, 'view', 1) called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/UI.pm line 274
   Foswiki::UI::handleRequest('Foswiki::Request=HASH(0x14827d0)') called at /usr/local/src/wiki.trin.org.au/core/lib/Foswiki/Engine/CLI.pm line 53
   Foswiki::Engine::CLI::run('Foswiki::Engine::CLI=HASH(0x15087f0)') called at ./view line 29.
   (in cleanup)    (in cleanup) not an object during global destruction.
 at ./view line 0
   eval {...} called at ./view line 0

The fundamental problem is that the MongoDB store listener is "re-blessing" an object which is NOT a Foswiki::Meta (in fact, it is a Foswiki::Form which ISA Foswiki::Meta), as a Foswiki::Plugins::MongoDBPlugin::Meta.

THIS IS BAD

-- PaulHarvey - 04 Aug 2011

Happens trying to view PlumeMoths.Taxa

-- PaulHarvey - 04 Aug 2011

The problem is that Foswiki::Form->_parseFormDefinition() does this:
sub _parseFormDefinition {
     print STDERR 'Foswiki::Form: ' . ref($this) . "\n";
     my $text    = $this->text();
     print STDERR 'Now it\'s a Foswiki::Plugins::MongoDBPlugin::Meta!!! :' . ref($this) . "\n";

-- PaulHarvey - 04 Aug 2011

Here's a hack that seems to work:

diff --git a/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm b/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm
index 3dbfb95..c71abbf 100644
--- a/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm
+++ b/lib/Foswiki/Plugins/MongoDBPlugin/Listener.pm
@@ -202,7 +202,8 @@ sub loadTopic {
         #return;
         #query the versions collection - via  MongoDBPlugin::Meta 
         #rebless into a mighter version of Meta
-        bless( $_[1], 'Foswiki::Plugins::MongoDBPlugin::Meta' );
+        #bless( $_[1], 'Foswiki::Plugins::MongoDBPlugin::Meta' );
+        _mongofyClass(\$_[1]);
         $_[1]->reload($_[2]);    #get the requested version
         return ( $_[1]->getLoadedRev(), 1 );
     }
@@ -220,7 +221,8 @@ sub loadTopic {
     }
 
     #rebless into a mighter version of Meta
-    bless( $_[1], 'Foswiki::Plugins::MongoDBPlugin::Meta' );
+    #bless( $_[1], 'Foswiki::Plugins::MongoDBPlugin::Meta' );
+    _mongofyClass(\$_[1]);
     $_[1]->reload();    #get the latest version
     $_[1]->{_latestIsLoaded} = 1;
     if ( $_[1]->topic =~ /Form$/ ) {
@@ -244,6 +246,38 @@ sub loadTopic {
 
 }
 
+sub _mongofyClass {
+    my ($pObj) = @_;
+    my $class = ref(${$pObj});
+
+    ASSERT($class) if DEBUG;
+    if (not $class->isa('Foswiki::Plugins::MongoDBPlugin::Meta')) {
+        my $isaref = eval '\@' . $class . '::ISA';
+        my $foundit;
+        my $i = 0;
+        ASSERT(ref($isaref) eq 'ARRAY') if DEBUG;
+        my $nsuperclasses = scalar(@{$isaref});
+
+        #require Data::Dumper;
+        #print STDERR 'Before, ' . $class . ' ISA: ' . Data::Dumper->Dump([$isaref]);
+        ASSERT($class->isa('Foswiki::Meta')) if DEBUG;
+        while ( not $foundit and $i < $nsuperclasses ) {
+            if ($isaref->[$i] eq 'Foswiki::Meta') {
+                $isaref->[$i] = 'Foswiki::Plugins::MongoDBPlugin::Meta';
+                $foundit = 1;
+            }
+            $i += 1;
+        }
+        if (not $foundit) {
+            bless( ${$pObj}, 'Foswiki::Plugins::MongoDBPlugin::Meta' );
+        }
+        #print STDERR 'After, the ' . ref(${$pObj}) . ' obj ISA: ' . Data::Dumper->Dump([$isaref]);
+        ASSERT(${$pObj}->isa('Foswiki::Plugins::MongoDBPlugin::Meta'), "It's a " . $class . ', ' . ($foundit ||0)) if DEBUG;
+    }
+
+    return;
+}
+
 sub getRevisionHistory {
     my $this = shift;
     my $meta = shift;

-- PaulHarvey - 04 Aug 2011

mmm, ok, 2 big questoins:

  1. where did you get the idea to do it this way, and
  2. what exactly are you intending this code to do?

I think i grok what the code does, but I want to make sure that is the same as what you intend it to do :/ cos its not quite what i expected would work :/

I also only just now noticed the most important info Happens trying to view PlumeMoths.Taxa

excellent, I'll test that asap.

-- SvenDowideit - 07 Aug 2011

argh! course, viewing that topic is ok on my setup - I don't have the same plugins as you frown, sad smile

-- SvenDowideit - 07 Aug 2011

even adding topic recurse plugin, it does not crash for me frown, sad smile

I then grabbed the list of enabled plugins from the trin server, and made it into

and even that does not crash on my system.

SO _ what the heck?

I do get
[Sun Aug 07 09:15:33 2011] [error] [client 127.0.1.1] [Sun Aug  7 09:15:33 2011] view: Argument "\\x{25}\\x{44}..." isn't numeric in numeric lt (<) at /home/sven/src/foswiki/core/lib/Foswiki/Plugins/TopicRecursePlugin/Node.pm line 136.
[Sun Aug 07 09:15:35 2011] [error] [client 127.0.1.1] [Sun Aug  7 09:15:35 2011] view: \t(in cleanup) not an object during global destruction.
[Sun Aug 07 09:15:35 2011] [error] [client 127.0.1.1] [Sun Aug  7 09:15:35 2011] view:  at /home/sven/src/foswiki/core/bin/view line 0
[Sun Aug 07 09:15:35 2011] [error] [client 127.0.1.1] [Sun Aug  7 09:15:35 2011] view: \teval {...} called at /home/sven/src/foswiki/core/bin/view line 0
in my log file tho

-- SvenDowideit - 07 Aug 2011

running as guest

-- SvenDowideit - 07 Aug 2011

educational reading:

-- PaulHarvey - 07 Aug 2011

The diff had a mistake checking $class->isa instead of ${$pObj}->isa, updated it

-- PaulHarvey - 11 Aug 2011

Paul, what happens when you run the FormDefTests?

I'm getting

1 failure:
FormDefTests::test_searchForOptions

Expected:'SplodgeOne,SplodgeTwo'
 But got:''
 at /home/sven/src/foswiki/core/lib/Unit/TestCase.pm line 271
   Unit::TestCase::assert_str_equals('FormDefTests=HASH(0x232a340)', 'SplodgeOne,SplodgeTwo', '') called at /home/sven/src/foswiki/core/test/unit/FormDefTests.pm line 214

when I've got mongoDB on..

-- SvenDowideit - 12 Aug 2011

On perl 5.12 I get a different error in FormDefTests::test_Item972_selectPlusValues:
   
*** Use of uninitialized value in concatenation (.) or string at /usr/local/src/github.com/foswiki/core/lib/Assert.pm line 95.
 at /usr/local/src/github.com/foswiki/core/test/unit/FoswikiTestCase.pm line 40
   FoswikiTestCase::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /usr/local/src/github.com/foswiki/core/lib/Foswiki.pm line 149
   Foswiki::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /usr/local/src/github.com/foswiki/core/lib/Assert.pm line 95
   Assert::TAINT(undef) called at /usr/local/src/github.com/foswiki/core/lib/Foswiki/Form/Select.pm line 59
   Foswiki::Form::Select::getOptions('Foswiki::Form::Select=HASH(0x269d510)') called at /usr/local/src/github.com/foswiki/core/test/unit/FormDefTests.pm line 286
   FormDefTests::test_Item972_selectPlusValues('FormDefTests=HASH(0x182fde0)') called at /usr/local/src/github.com/foswiki/core/lib/Unit/TestRunner.pm line 383
   Unit::TestRunner::__ANON__() called at /usr/local/src/github.com/foswiki/core/lib/CPAN/lib/Error.pm line 379
   eval {...} called at /usr/local/src/github.com/foswiki/core/lib/CPAN/lib/Error.pm line 371
   Error::subs::try('CODE(0x23c88e0)', 'HASH(0x23c5e78)') called at /usr/local/src/github.com/foswiki/core/lib/Unit/TestRunner.pm line 402
   Unit::TestRunner::runOne('FormDefTests=HASH(0x182fde0)', 'FormDefTests', undef) called at /usr/local/src/github.com/foswiki/core/lib/Unit/TestRunner.pm line 137
   Unit::TestRunner::start('Unit::TestRunner=HASH(0x14feb20)', 'FormDefTests.pm') called

-- PaulHarvey - 13 Aug 2011

Okay, I fixed the errors I was getting, and can confirm the same problem.

It seems there's something wrong with ^ anchor, at least

-- PaulHarvey - 13 Aug 2011

na, its escaping the pipe wrong - I opened a different task for it tho (i have some fixes i'm working on, will dcommit soon)

-- SvenDowideit - 13 Aug 2011

k, created a test that fails, here's the error with MongoDB enabled:
Running FormDefTests
   FormDefTests::test_Item10987_formObjClass
*** Can't locate object method "createField" via package "Foswiki::Plugins::MongoDBPlugin::Meta" at /usr/local/src/github.com/foswiki/core/lib/Foswiki/Form.pm line 262.
 at /usr/local/src/github.com/foswiki/core/test/unit/FoswikiTestCase.pm line 40
   FoswikiTestCase::__ANON__('Can\'t locate object method "createField" via package "Foswik...') called at /usr/local/src/github.com/foswiki/core/lib/Foswiki/Form.pm line 262
   Foswiki::Form::_parseFormDefinition('Foswiki::Plugins::MongoDBPlugin::Meta=HASH(0x2be3a60)') called at /usr/local/src/github.com/foswiki/core/lib/Foswiki/Form.pm line 121
   Foswiki::Form::new('Foswiki::Form', 'Foswiki=HASH(0x2bf8e80)', 'System', 'UserForm') called at /usr/local/src/github.com/foswiki/core/test/unit/FormDefTests.pm line 344
   FormDefTests::test_Item10987_formObjClass('FormDefTests=HASH(0x1968030)') called at /usr/local/src/github.com/foswiki/core/lib/Unit/TestRunner.pm line 383
   Unit::TestRunner::__ANON__() called at /usr/local/src/github.com/foswiki/core/lib/CPAN/lib/Error.pm line 379
   eval {...} called at /usr/local/src/github.com/foswiki/core/lib/CPAN/lib/Error.pm line 371
   Error::subs::try('CODE(0x2a51950)', 'HASH(0x2bc1bc8)') called at /usr/local/src/github.com/foswiki/core/lib/Unit/TestRunner.pm line 402
   Unit::TestRunner::runOne('FormDefTests=HASH(0x1968030)', 'FormDefTests', 'test_Item10987_formObjClass') called at /usr/local/src/github.com/foswiki/core/lib/Unit/TestRunner.pm line 137
   Unit::TestRunner::start('Unit::TestRunner=HASH(0x1626db0)', 'FormDefTests::test_Item10987_formObjClass') called

-- PaulHarvey - 17 Aug 2011

did the fix I made to resolve the unit test fix it?

the core problem is that i thought Foswiki::Form objects were a promotion of an existing Meta obj, whereas your use clearly shows me i was being very forgetful.

-- SvenDowideit - 17 Aug 2011

Yep, works good. And my "fix" caused huge performance problems... bigger than I expected. Anyway, your fix seems to be doing the job

-- PaulHarvey - 18 Aug 2011
 
Topic revision: r23 - 19 Aug 2011, SvenDowideit
The copyright of the content on this website is held by the contributing authors, except where stated elsewhere. See Copyright Statement. Creative Commons License    Legal Imprint    Privacy Policy