Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Circular reference in category causes "Segmentation fault" due to "Maximum function nesting level of '256' reached..." #1713

Closed
kghbln opened this issue Jul 9, 2016 · 35 comments
Closed

Circular reference in category causes "Segmentation fault" due to "Maximum function nesting level of '256' reached..." #1713

kghbln opened this issue Jul 9, 2016 · 35 comments
Labels
bug Occurrence of an unintended or unanticipated behaviour that causes a vulnerability or fatal error

Comments

@kghbln
Copy link
Member

kghbln commented Jul 9, 2016 •
edited

Setup and configuration

  • PHP 5.6.11-1ubuntu3.4 (apache2handler)
  • MySQL 5.6.30-0ubuntu0.15.10.1
  • MediaWiki 1.25.6 (01b4001) 21:49, 20 May 2016
  • Semantic MediaWiki 2.4.0 (61b7da6) 06:23, 9 July 2016

Issue

When running "rebuildData.php" with

php rebuildData.php -v --with-maintenance-log --report-runtime --ignore-exceptions --exception-log=/var/log/mediawiki/20160709_swm_exception.log --skip-properties

on smw.o heaps of segmentation faults are issued without further information.

(42/40615)      Finished processing ID 53 (Property:Has_component)
Segmentation fault
(22/40615)      Finished processing ID 76* (Property:Display_units)
Segmentation fault
(10/40623)      Finished processing ID 87 (Property:Located_in)
Segmentation fault
(54/40623)      Finished processing ID 146 (Category:Effective_pages)
Segmentation fault
(1230/40640)    Finished processing ID 2045 (Talks_and_publications)
Segmentation fault
(496/40752)     Finished processing ID 2592* (User:Hosiryuhosi)
Segmentation fault
(42/40790)      Finished processing ID 2662* (User:Cavila)
Segmentation fault
(427/40791)     Finished processing ID 3166* (Category:SMWCon/en) - 3172
Segmentation fault
(75/40823)      Finished processing ID 3250* (Page_Schemas_(de))
Segmentation fault
(86/40828)      Finished processing ID 3341* (Extension:Semantic_Signup)
Segmentation fault
(613/40836)     Finished processing ID 4047 (User:Hosiryuhosi)
Segmentation fault
(43/40870)      Finished processing ID 4106 (File:Semantic-Glossary-Example-HTML.png)
Segmentation fault
(194/40871)     Finished processing ID 4310 (SaveMLAK_(ru))
Segmentation fault
(329/40884)     Finished processing ID 4671* (Category:Listwidget_examples)
Segmentation fault
(390/40901)     Finished processing ID 5100* (Semantic_Expressiveness_(de)) - 5109
Segmentation fault
(5/40913)       Finished processing ID 5113* (Help_talk:Process_format)
Segmentation fault
(11/40913)      Finished processing ID 5126* (Thread:User_talk:Benedikt_Kaempgen/Semantic_Web_Browser/reply_(4))
Segmentation fault
(3/40914)       Finished processing ID 5131* (Thread:Help_talk:Selecting_pages/Case_insensitive_query_possible?)
Segmentation fault
(3/40914)       Finished processing ID 5136* (Thread:Semantic-mediawiki.org:Community_portal/Problem_with_export_of_latitude/longitude_coordinates_via_CSV/reply)
Segmentation fault
(3/40915)       Finished processing ID 5141* (Template:Valuerank.example)
Segmentation fault
(229/40915)     Finished processing ID 5401* (Thread:Semantic-mediawiki.org:Community_portal/SMWSQLStore2_/_3_after_upgrade_to_SMW_1.8/reply_(6))
Segmentation fault
(385/40923)     Finished processing ID 5849 (Éigse)
Segmentation fault
(1889/40935)    Finished processing ID 8057* (Help:$smwgEnableUpdateJobs_(ru))
Segmentation fault
(12/40971)      Finished processing ID 8073* (SMWCon_Spring_2013/ArchE/Presentation)
Segmentation fault
(14/40971)      Finished processing ID 8089 (Smw-format-json-export.png#6#Meta_data)
Segmentation fault
(2163/40971)    Finished processing ID 14079 (Thread:Talk:Semantic_MediaWiki_1.8.0/1.8.0.2/reply)
Segmentation fault
(3024/40992)    Finished processing ID 19784 (Help:$smwgDefaultStore_(ru))
Segmentation fault
(22/41007)      Finished processing ID 19884 (File:Arche-SMWConSpring2013.pdf)
Segmentation fault
@kghbln kghbln added the bug Occurrence of an unintended or unanticipated behaviour that causes a vulnerability or fatal error label Jul 9, 2016
@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

Whoo ... "Segmentation fault", no idea.

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016 •
edited

Whoo ... "Segmentation fault", no idea.

The report is a bit sparse, any information from the PHP log or Apache log since "Segmentation fault" only happens on the PHP stack.

@kghbln
Copy link
Member Author

kghbln commented Jul 9, 2016

That makes two of us. Let's see if others come up with it, too. My feeling is that the wiki is somehow borked because of the previous time of "neglectance".

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

Luckily you were able to run with "--ignore-exceptions --exception-log"

@kghbln
Copy link
Member Author

kghbln commented Jul 9, 2016

"--ignore-exceptions --exception-log"

This did not help I am afraid. The script stopped every time and a log was not created either.

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

What happens when you run one of the mentioned pages individually?

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

This did not help I am afraid.

That's right because its not an exception but a fault which happens on the "deep" PHP side without MW or SMW application involved.

@kghbln
Copy link
Member Author

kghbln commented Jul 9, 2016

What happens when you run one of the mentioned pages individually?

No change, just "Segmentation Fault". :(

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

No change, just "Segmentation Fault". :(

Anything in the php_error.log or Apache error.log?

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

http://stackoverflow.com/questions/13079513/how-do-i-diagnose-this-php-segmentation-fault

@kghbln
Copy link
Member Author

kghbln commented Jul 9, 2016

error.log:

[Sat Jul 09 15:21:09.460444 2016] [core:notice] [pid 25713] AH00052: child pid 16873 exit signal Segmentation fault (11)
[Sat Jul 09 15:28:14.972920 2016] [core:notice] [pid 25713] AH00052: child pid 16975 exit signal Segmentation fault (11)
[Sat Jul 09 15:31:40.290084 2016] [core:notice] [pid 25713] AH00052: child pid 16976 exit signal Segmentation fault (11)
[Sat Jul 09 15:36:10.726100 2016] [core:notice] [pid 25713] AH00052: child pid 16986 exit signal Segmentation fault (11)
[Sat Jul 09 15:37:23.829289 2016] [core:notice] [pid 25713] AH00052: child pid 16977 exit signal Segmentation fault (11)
[Sat Jul 09 15:39:36.996538 2016] [core:notice] [pid 25713] AH00052: child pid 17004 exit signal Segmentation fault (11)
[Sat Jul 09 15:43:53.317076 2016] [core:notice] [pid 25713] AH00052: child pid 17038 exit signal Segmentation fault (11)
[Sat Jul 09 15:51:18.091185 2016] [core:notice] [pid 25713] AH00052: child pid 17122 exit signal Segmentation fault (11)
[Sat Jul 09 15:51:20.093465 2016] [core:notice] [pid 25713] AH00052: child pid 17104 exit signal Segmentation fault (11)
[Sat Jul 09 15:51:27.106045 2016] [core:notice] [pid 25713] AH00052: child pid 17140 exit signal Segmentation fault (11)
[Sat Jul 09 15:51:59.186453 2016] [core:notice] [pid 25713] AH00052: child pid 17143 exit signal Segmentation fault (11)
[Sat Jul 09 15:52:07.193938 2016] [core:notice] [pid 25713] AH00052: child pid 17145 exit signal Segmentation fault (11)
[Sat Jul 09 16:08:20.570808 2016] [core:notice] [pid 25713] AH00052: child pid 17204 exit signal Segmentation fault (11)
[Sat Jul 09 16:46:22.571302 2016] [core:notice] [pid 25713] AH00052: child pid 17369 exit signal Segmentation fault (11)
[Sat Jul 09 16:47:35.650131 2016] [core:notice] [pid 25713] AH00052: child pid 17279 exit signal Segmentation fault (11)
[Sat Jul 09 16:49:52.836883 2016] [core:notice] [pid 25713] AH00052: child pid 17389 exit signal Segmentation fault (11)
[Sat Jul 09 16:54:07.267538 2016] [core:notice] [pid 25713] AH00052: child pid 17249 exit signal Segmentation fault (11)
[Sat Jul 09 17:02:22.055013 2016] [core:notice] [pid 25713] AH00052: child pid 17479 exit signal Segmentation fault (11)
[Sat Jul 09 17:18:52.588913 2016] [core:notice] [pid 25713] AH00052: child pid 17575 exit signal Segmentation fault (11)
[Sat Jul 09 17:25:00.147862 2016] [core:notice] [pid 25713] AH00052: child pid 17622 exit signal Segmentation fault (11)
[Sat Jul 09 17:26:13.252886 2016] [core:notice] [pid 25713] AH00052: child pid 17606 exit signal Segmentation fault (11)
[Sat Jul 09 17:28:26.419610 2016] [core:notice] [pid 25713] AH00052: child pid 17646 exit signal Segmentation fault (11)
[Sat Jul 09 17:32:39.637285 2016] [core:notice] [pid 25713] AH00052: child pid 17632 exit signal Segmentation fault (11)
[Sat Jul 09 17:40:53.443893 2016] [core:notice] [pid 25713] AH00052: child pid 17720 exit signal Segmentation fault (11)
[Sat Jul 09 17:57:06.618023 2016] [core:notice] [pid 25713] AH00052: child pid 17796 exit signal Segmentation fault (11)
[Sat Jul 09 18:03:30.203231 2016] [core:notice] [pid 25713] AH00052: child pid 17823 exit signal Segmentation fault (11)
[Sat Jul 09 18:09:11.767904 2016] [core:notice] [pid 25713] AH00052: child pid 17824 exit signal Segmentation fault (11)
[Sat Jul 09 18:09:15.789466 2016] [core:notice] [pid 25713] AH00052: child pid 17722 exit signal Segmentation fault (11)
[Sat Jul 09 18:09:19.792899 2016] [core:notice] [pid 25713] AH00052: child pid 18636 exit signal Segmentation fault (11)
[Sat Jul 09 18:09:22.796356 2016] [core:notice] [pid 25713] AH00052: child pid 18638 exit signal Segmentation fault (11)
[Sat Jul 09 18:29:20.523845 2016] [core:notice] [pid 25713] AH00052: child pid 17883 exit signal Segmentation fault (11)

So not really helpful.

@kghbln
Copy link
Member Author

kghbln commented Jul 9, 2016

We are getting to it with php -d xdebug.auto_trace=ON -d xdebug.trace_output_dir=/var/www/html/02310/ rebuildData.php -v:

(52/41076)      Finished processing ID 53 (Property:Has_component)
PHP Fatal error:  Maximum function nesting level of '256' reached, aborting! in /.../w/vendor/onoi/cache/src/FixedInMemoryLruCache.php on line 71
PHP Stack trace:
PHP   1. {main}() /.../w/extensions/SemanticMediaWiki/maintenance/rebuildData.php:0
PHP   2. require_once() /.../w/extensions/SemanticMediaWiki/maintenance/rebuildData.php:197
PHP   3. SMW\Maintenance\RebuildData->execute() /.../w/maintenance/doMaintenance.php:103
PHP   4. SMW\Maintenance\DataRebuilder->rebuild() /.../w/extensions/SemanticMediaWiki/maintenance/rebuildData.php:149
PHP   5. SMW\Maintenance\DataRebuilder->doRebuildAll() /.../w/extensions/SemanticMediaWiki/src/Maintenance/DataRebuilder.php:167
PHP   6. SMW\Maintenance\DataRebuilder->doExecuteFor() /.../w/extensions/SemanticMediaWiki/src/Maintenance/DataRebuilder.php:266
PHP   7. SMW\SQLStore\ByIdDataRebuildDispatcher->dispatchRebuildFor() /.../w/extensions/SemanticMediaWiki/src/Maintenance/DataRebuilder.php:307
PHP   8. SMW\MediaWiki\Jobs\UpdateJob->run() /.../w/extensions/SemanticMediaWiki/src/SQLStore/ByIdDataRebuildDispatcher.php:191
PHP   9. SMW\MediaWiki\Jobs\UpdateJob->doUpdate() /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Jobs/UpdateJob.php:56
PHP  10. SMW\MediaWiki\Jobs\UpdateJob->doPrepareForUpdate() /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Jobs/UpdateJob.php:87
PHP  11. SMW\MediaWiki\Jobs\UpdateJob->needToParsePageContentBeforeUpdate() /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Jobs/UpdateJob.php:118
PHP  12. SMW\ContentParser->parse() /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Jobs/UpdateJob.php:135
PHP  13. SMW\ContentParser->fetchFromParser() /.../w/extensions/SemanticMediaWiki/includes/ContentParser.php:147
PHP  14. Parser->parse() /.../w/extensions/SemanticMediaWiki/includes/ContentParser.php:202
PHP  15. Parser->internalParse() /.../w/includes/parser/Parser.php:435
PHP  16. Parser->replaceVariables() /.../w/includes/parser/Parser.php:1232
PHP  17. PPFrame_DOM->expand() /.../w/includes/parser/Parser.php:3334
PHP  18. Parser->braceSubstitution() /.../w/includes/parser/Preprocessor_DOM.php:1169
PHP  19. PPTemplateFrame_DOM->cachedExpand() /.../w/includes/parser/Parser.php:3656
PHP  20. PPFrame_DOM->expand() /.../w/includes/parser/Preprocessor_DOM.php:1614
PHP  21. Parser->braceSubstitution() /.../w/includes/parser/Preprocessor_DOM.php:1169
PHP  22. PPFrame_DOM->expand() /.../w/includes/parser/Parser.php:3659
PHP  23. Parser->braceSubstitution() /.../w/includes/parser/Preprocessor_DOM.php:1169
PHP  24. Parser->callParserFunction() /.../w/includes/parser/Parser.php:3517
PHP  25. PPFrame_DOM->expand() /.../w/includes/parser/Parser.php:3774
PHP  26. Parser->braceSubstitution() /.../w/includes/parser/Preprocessor_DOM.php:1169
PHP  27. PPFrame_DOM->expand() /.../w/includes/parser/Parser.php:3659
PHP  28. Parser->braceSubstitution() /.../w/includes/parser/Preprocessor_DOM.php:1169
PHP  29. Parser->callParserFunction() /.../w/includes/parser/Parser.php:3517
PHP  30. call_user_func_array:{/.../w/includes/parser/Parser.php:3783}() /.../w/includes/parser/Parser.php:3783
PHP  31. ExtParserFunctions::switchObj() /.../w/includes/parser/Parser.php:3783
PHP  32. ExtParserFunctions::decodeTrimExpand() /.../w/extensions/ParserFunctions/ParserFunctions_body.php:204
PHP  33. PPFrame_DOM->expand() /.../w/extensions/ParserFunctions/ParserFunctions_body.php:849
PHP  34. Parser->argSubstitution() /.../w/includes/parser/Preprocessor_DOM.php:1188
PHP  35. PPTemplateFrame_DOM->getArgument() /.../w/includes/parser/Parser.php:4151
PHP  36. PPTemplateFrame_DOM->getNamedArgument() /.../w/includes/parser/Preprocessor_DOM.php:1685
PHP  37. PPFrame_DOM->expand() /.../w/includes/parser/Preprocessor_DOM.php:1677
PHP  38. Parser->braceSubstitution() /.../w/includes/parser/Preprocessor_DOM.php:1169
PHP  39. Parser->callParserFunction() /.../w/includes/parser/Parser.php:3517
PHP  40. call_user_func_array:{/.../w/includes/parser/Parser.php:3783}() /.../w/includes/parser/Parser.php:3783
PHP  41. SMW\ParserFunctionFactory->SMW\{closure}() /.../w/includes/parser/Parser.php:3783
PHP  42. SMW\AskParserFunction->parse() /.../w/extensions/SemanticMediaWiki/src/ParserFunctionFactory.php:277
PHP  43. SMW\AskParserFunction->doFetchResultsForRawParameters() /.../w/extensions/SemanticMediaWiki/includes/parserhooks/AskParserFunction.php:115
PHP  44. SMWQueryProcessor::getResultFromQuery() /.../w/extensions/SemanticMediaWiki/includes/parserhooks/AskParserFunction.php:194
PHP  45. SMWSQLStore3->getQueryResult() /.../w/extensions/SemanticMediaWiki/includes/query/SMW_QueryProcessor.php:455
PHP  46. Hooks::run() /.../w/extensions/SemanticMediaWiki/includes/storage/SQLStore/SMW_SQLStore3.php:396
PHP  47. call_user_func_array:{/.../w/includes/Hooks.php:207}() /.../w/includes/Hooks.php:207
PHP  48. SMW\MediaWiki\Hooks\HookRegistry->SMW\MediaWiki\Hooks\{closure}() /.../w/includes/Hooks.php:207
PHP  49. SMW\SQLStore\QueryDependency\QueryDependencyLinksStore->doUpdateDependenciesBy() /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Hooks/HookRegistry.php:537
PHP  50. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->getDependencyList() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryDependencyLinksStore.php:241
PHP  51. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->doResolveDependenciesFromDescription() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:156
PHP  52. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->doResolveDependenciesFromDescription() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:205
PHP  53. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->doResolveDependenciesFromDescription() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:205
PHP  54. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->doMatchSubcategory() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:191
PHP  55. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->doMatchSubcategory() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:234
...
PHP 253. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->doMatchSubcategory() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:234
PHP 254. SMW\PropertyHierarchyLookup->findSubcategoryListFor() /.../w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:229
PHP 255. SMW\PropertyHierarchyLookup->findMatchesFor() /.../w/extensions/SemanticMediaWiki/src/PropertyHierarchyLookup.php:120
PHP 256. Onoi\Cache\FixedInMemoryLruCache->fetch() /.../w/extensions/SemanticMediaWiki/src/PropertyHierarchyLookup.php:153

The lines I omitted are identical.

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

We are getting to it with

Nice, it will take me a while to figure what's going here.

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016 •
edited

The lines I omitted are identical.

Could paste the whole report into a gist and linked it here.

@kghbln
Copy link
Member Author

kghbln commented Jul 9, 2016

Could paste the whole report into a gist and linked it here.

https://gist.github.com/kghbln/c54a276e1110b79f0fb1a433e77804d4

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

QueryResultDependencyListResolver->doMatchSubcategory() /var/www/html/02310/w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:191
PHP 55. SMW\SQLStore\QueryDependency\QueryResultDependencyListResolver->doMatchSubcategory() /var/www/html/02310/w/extensions/SemanticMediaWiki/src/SQLStore/QueryDependency/QueryResultDependencyListResolver.php:234

Somehow a category (or a redirect thereof) is pointing to itself which cause the doMatchSubcategory to run in circles and eventually strikes with a "Maximum function nesting level of '256' reached, aborting! in Unknown on line 0".

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016 •
edited

@kghbln Could you try applying the following patch.

@@ -224,19 +224,27 @@ class QueryResultDependencyListResolver {
        }
    }

    private function doMatchSubcategory( &$subjects, DIWikiPage $category ) {

-       $subcategories = $this->propertyHierarchyLookup->findSubcategoryListFor( $category );
+       $hash = $category->getHash();
+       $subcategories = array();
+
+       // #1713
+       // Safeguard against a possible category (or redirect thereof) to point
+       // to itself
+       if ( !isset( $subjects[$hash] ) ) {
+           $subcategories = $this->propertyHierarchyLookup->findSubcategoryListFor( $category );
+       }

        foreach ( $subcategories as $subcategory ) {

+           $subjects[$subcategory->getHash()] = $subcategory;
+
            if ( $this->propertyHierarchyLookup->hasSubcategoryFor( $subcategory ) ) {
                $this->doMatchSubcategory( $subjects, $subcategory );
            }
-
-           $subjects[] = $subcategory;
        }
    }

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

Somehow a category (or a redirect thereof) is pointing to itself which cause the doMatchSubcategory to run in circles

A simple use case the provide some context.

  • Create page TestSubCategory and add [[Category:SomeCategory]]
  • Create page Category:SomeCategory and point to itself by adding [[Category:SomeCategory]]

@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

Similar happens when you do:

  • Create page TestSubProperty and add [[TestSubProp::Foo]]
  • Create page Property:TestSubProp with [[Subproperty of::TestSubProp]]

@mwjames mwjames changed the title Segmentation fault Circular reference in category causes "Segmentation fault" due to "Maximum function nesting level of '256' reached..." Jul 9, 2016
@mwjames mwjames mentioned this issue Jul 9, 2016
Merged
mwjames added a commit that referenced this issue Jul 9, 2016
@mwjames
Merge pull request #1714 from SemanticMediaWiki/circular
5a6c67c 
Guard against circular reference in category/property hierarchy, refs #1713
@mwjames
Copy link
Contributor

mwjames commented Jul 9, 2016

@kghbln You could try pulling from master and confirm that #1714 solves the issue.

@mwjames mwjames mentioned this issue Jul 11, 2016
Closed
16 tasks
@kghbln
Copy link
Member Author

kghbln commented Jul 11, 2016 •
edited

The script is running now without segmentation faults. However it appears to be substaniallly slower and starting with ID 84 I am getting a loop:

(82/41146)      Finished processing ID 83* (Property:Area)
(82/41146)      Finished processing ID 83 (Property:Master_page)
(83/41146)      Finished processing ID 84* (Property:Population)
(83/41146)      Finished processing ID 84 (Property:From_version)
(84/41146)      Finished processing ID 84* (Demo:Berlin)
(84/41146)      Finished processing ID 84 (Property:To_version)
(85/41146)      Finished processing ID 84* (Demo:Berlin)
(85/41146)      Finished processing ID 84 (Property:To_version)
(86/41146)      Finished processing ID 84* (Demo:Berlin)
(86/41146)      Finished processing ID 84 (Property:To_version)
(87/41146)      Finished processing ID 84* (Demo:Berlin)
(87/41146)      Finished processing ID 84 (Property:To_version)
...

now at 500+ loops for ID 84. Hmm ....

Edit: I just stopped at loop 600+ and restarted the script with -s 85. So far no further loop.

@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016

now at 500+ loops for ID 84. Hmm ....

Need to investigate!

@kghbln
Copy link
Member Author

kghbln commented Jul 11, 2016 •
edited

I now see a pattern with the next loop I ran into:

(376/41146)     Finished processing ID 478* (User_talk:Najevi)
(377/41146)     Finished processing ID 479* (SMW_1.4.3)
(378/41146)     Finished processing ID 480* (Inline_query)
(379/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(379/41146)     Finished processing ID 480 (Demo:Berlin)
(380/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(380/41146)     Finished processing ID 480 (Demo:Berlin)
(381/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(381/41146)     Finished processing ID 480 (Demo:Berlin)
(382/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(382/41146)     Finished processing ID 480 (Demo:Berlin)
(383/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(383/41146)     Finished processing ID 480 (Demo:Berlin)
(384/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(384/41146)     Finished processing ID 480 (Demo:Berlin)
(385/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(385/41146)     Finished processing ID 480 (Demo:Berlin)
(386/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(386/41146)     Finished processing ID 480 (Demo:Berlin)
(387/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(387/41146)     Finished processing ID 480 (Demo:Berlin)
(388/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(388/41146)     Finished processing ID 480 (Demo:Berlin)
(389/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(389/41146)     Finished processing ID 480 (Demo:Berlin)
(390/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(390/41146)     Finished processing ID 480 (Demo:Berlin)
(391/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(391/41146)     Finished processing ID 480 (Demo:Berlin)
(392/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(392/41146)     Finished processing ID 480 (Demo:Berlin)
(393/41146)     Finished processing ID 480* (Semantic_MediaWiki_1.4.3)
(393/41146)     Finished processing ID 480 (Demo:Berlin)
...

So it is probably something on the Demo:Berlin page

@kghbln
Copy link
Member Author

kghbln commented Jul 11, 2016 •
edited

Same for Demo:London:

(6/41154)       Finished processing ID 591 (New_style_for_semantic-mediawiki.org)
(7/41154)       Finished processing ID 592* (United_Kingdom)
(8/41154)       Finished processing ID 592* (Demo:London)
(8/41154)       Finished processing ID 592 (Template:News_list)
(9/41154)       Finished processing ID 592* (Demo:London)
(9/41154)       Finished processing ID 592 (Template:News_list)
(10/41154)      Finished processing ID 592* (Demo:London)
(10/41154)      Finished processing ID 592 (Template:News_list)
(11/41154)      Finished processing ID 592* (Demo:London)
(11/41154)      Finished processing ID 592 (Template:News_list)
(12/41154)      Finished processing ID 592* (Demo:London)
(12/41154)      Finished processing ID 592 (Template:News_list)
(13/41154)      Finished processing ID 592* (Demo:London)
(13/41154)      Finished processing ID 592 (Template:News_list)
(14/41154)      Finished processing ID 592* (Demo:London)
(14/41154)      Finished processing ID 592 (Template:News_list)
...

When trying to edit the page I get:

Exception encountered, of type "InvalidArgumentException"
[d2f46bcf] /w/index.php?title=Demo:London&action=submit InvalidArgumentException from line 217 of /.../w/vendor/onoi/blob-store/src/BlobStore.php: Expected the id to be a string
Backtrace:
#0 /.../w/vendor/onoi/blob-store/src/BlobStore.php(195): Onoi\BlobStore\BlobStore->getKey(integer)
#1 /.../w/extensions/SemanticMediaWiki/src/CachedPropertyValuesPrefetcher.php(58): Onoi\BlobStore\BlobStore->delete(string)
#2 /.../w/extensions/SemanticMediaWiki/src/EventListenerRegistry.php(79): SMW\CachedPropertyValuesPrefetcher->resetCacheFor(SMW\DIWikiPage)
#3 [internal function]: SMW\EventListenerRegistry->SMW\{closure}(Onoi\EventDispatcher\DispatchContext)
#4 /.../w/vendor/onoi/event-dispatcher/src/Listener/GenericCallbackEventListener.php(62): call_user_func_array(Closure, array)
#5 /.../w/vendor/onoi/event-dispatcher/src/Dispatcher/GenericEventDispatcher.php(122): Onoi\EventDispatcher\Listener\GenericCallbackEventListener->execute(Onoi\EventDispatcher\DispatchContext)
#6 /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Hooks/NewRevisionFromEditComplete.php(124): Onoi\EventDispatcher\Dispatcher\GenericEventDispatcher->dispatch(string, Onoi\EventDispatcher\DispatchContext)
#7 /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Hooks/NewRevisionFromEditComplete.php(75): SMW\MediaWiki\Hooks\NewRevisionFromEditComplete->doProcess()
#8 /.../w/extensions/SemanticMediaWiki/src/MediaWiki/Hooks/HookRegistry.php(222): SMW\MediaWiki\Hooks\NewRevisionFromEditComplete->process()
#9 [internal function]: SMW\MediaWiki\Hooks\HookRegistry->SMW\MediaWiki\Hooks\{closure}(WikiPage, Revision, boolean, User)
#10 /.../w/includes/Hooks.php(207): call_user_func_array(Closure, array)
#11 /.../w/includes/page/WikiPage.php(1830): Hooks::run(string, array)
#12 [internal function]: WikiPage->doEditContent(WikitextContent, string, integer, boolean, NULL, string)
#13 /.../w/includes/page/Article.php(2016): call_user_func_array(array, array)
#14 /.../w/includes/EditPage.php(1921): Article->__call(string, array)
#15 /.../w/includes/EditPage.php(1921): Article->doEditContent(WikitextContent, string, integer, boolean, NULL, string)
#16 /.../w/includes/EditPage.php(1305): EditPage->internalAttemptSave(array, boolean)
#17 /.../w/includes/EditPage.php(539): EditPage->attemptSave(array)
#18 /.../w/includes/actions/EditAction.php(56): EditPage->edit()
#19 /.../w/includes/actions/SubmitAction.php(40): EditAction->show()
#20 /.../w/includes/MediaWiki.php(463): SubmitAction->show()
#21 /.../w/includes/MediaWiki.php(269): MediaWiki->performAction(Article, Title)
#22 /.../w/includes/MediaWiki.php(634): MediaWiki->performRequest()
#23 /.../w/includes/MediaWiki.php(482): MediaWiki->main()
#24 /.../w/index.php(41): MediaWiki->run()
#25 {main}

@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016

Same for Demo:London When trying to edit the page I get:

Different cause, and I have an Idea why ... so just hold the horses.

@kghbln
Copy link
Member Author

kghbln commented Jul 11, 2016

Different cause, and I have an Idea why ... so just hold the horses.

Will do. Keeping fingers crossed.

@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016 •
edited

Different cause, and I have an Idea why ... so just hold the horses.

Can you update CachedPropertyValuesPrefetcher::VERSION to 0.3 [0] (manually will do a change later);

[0] https://github.com/SemanticMediaWiki/SemanticMediaWiki/blob/master/src/CachedPropertyValuesPrefetcher.php#L31

@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016

Different cause

Just for the curious, I changed onoi/blob-store@053b1ed and this comes into effect with 1.2.1. Demo:London has a NDL ID with an linked list to cache the uniqueness attribute and the old cache key causes a Expected the id to be a string in case 1.2.0 was used.

@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016

@kghbln When you look at the smw_object_ids table and search in field smw_title with either Demo:Berlin or Demo:London what is the output?

@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016 •
edited

However it appears to be substaniallly slower

I tried to verify that observation by comparing master against changes before #1714 on a local sample but I could not establish this fact.

Sampling:

@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016

Currently I'm unsure where those loops coming from (maybe some rogue redirects):

(8/41154)       Finished processing ID 592 (Template:News_list)
(9/41154)       Finished processing ID 592* (Demo:London)
(9/41154)       Finished processing ID 592 (Template:News_list)
(10/41154)      Finished processing ID 592* (Demo:London)
(10/41154)      Finished processing ID 592 (Template:News_list)

See my comments in #1713 (comment).

@mwjames mwjames mentioned this issue Jul 11, 2016
Closed
@mwjames
Copy link
Contributor

mwjames commented Jul 11, 2016

@kghbln I think we should close this one and open a new investigation into the loops since the original "Segmentation fault" has been solved.

Addressed "InvalidArgumentException from line 217 of /.../w/vendor/onoi/blob-store/src/BlobStore.php: Expected the id to be a string" in #1724.

@kghbln
Copy link
Member Author

kghbln commented Jul 12, 2016

I think we should close this one and open a new investigation into the loops since the original "Segmentation fault" has been solved.

Indeed since the segmentation faults triggered are no longer detectable.

@kghbln kghbln closed this as completed Jul 12, 2016
@kghbln
Copy link
Member Author

kghbln commented Jul 12, 2016

However it appears to be substaniallly slower

I tried to verify that observation by comparing master against changes before #1714 on a local sample but I could not establish this fact.

I suspect this is due to the fact that xdebug is still kicking in somehow.

@mwjames
Copy link
Contributor

mwjames commented Jul 12, 2016

I suspect this is due to the fact that xdebug is still kicking in somehow.

Yes (I remembered to tell you to disabled it after it is no longer required but without it we wouldn't have found the cause.)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Occurrence of an unintended or unanticipated behaviour that causes a vulnerability or fatal error
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@kghbln @mwjames