Florian created this task.
Florian added projects: MediaWiki-General-or-Unknown, Wikibase-DataModel, Wikibase-DataModel-_javascript_, Wikibase-DataModel-Serialization.
Herald added a subscriber: Aklapper.
Herald added a project: Wikidata.

TASK DESCRIPTION

I discovered this, when I worked in switching my wiki from the default, file-based logging, to Monolog loggers (my wiki uses Wikibase). So, I thought I "simply" configure $wgMWLoggerDefaultSpi in my LocalSettings.php, and let the logs be redirected to redis (which then is read by logstash and visualized in kibana, at least that's my plan). This resulted in the following configuration (based on the example on-wiki):

$wgMWLoggerDefaultSpi = array(
    'class' => '\\MediaWiki\\Logger\\MonologSpi',
    'args' => array( array(
        'loggers' => array(
            '@default' => array(
                'processors' => array( 'wiki', 'psr', 'pid', 'uid', 'web' ),
                'handlers'   => array( 'default', 'redis' ),
            ),
            'wfDebug' => array(
                'handlers'   => array( 'default' ),
                'processors' => array( 'psr' ),
            ),
            'profileoutput' => array(
                'handlers'   => array( 'profiler' ),
                'processors' => array( 'psr' ),
            ),
        ),

        'processors' => array(
            'wiki' => array(
                'class' => '\\MediaWiki\\Logger\\Monolog\\WikiProcessor',
            ),
            'psr' => array(
                'class' => '\\Monolog\\Processor\\PsrLogMessageProcessor',
            ),
            'pid' => array(
                'class' => '\\Monolog\\Processor\\ProcessIdProcessor',
            ),
            'uid' => array(
                'class' => '\\Monolog\\Processor\\UidProcessor',
            ),
            'web' => array(
                'class' => '\\Monolog\\Processor\\WebProcessor',
            ),
        ),

        'handlers' => array(
            'default' => array(
                'class' => '\\MediaWiki\\Logger\\Monolog\\LegacyHandler',
                'args' => array( '/data/www/mediawiki-log/monolog-'.date('Ymd').'.log' ),
                'formatter' => 'line',
            ),
            'redis' => array(
                'class' => '\\Monolog\\Handler\\RedisHandler',
                'args' => array(
                    function() {
                        $redis = new Redis();
                        $redis->connect( '127.0.0.1', 6379 );
                        return $redis;
                    },
                    'logstash'
                ),
                'formatter' => 'logstash',
            ),
            'profiler' => array(
                'class' => '\\MediaWiki\\Logger\\Monolog\\LegacyHandler',
                'args' => array( '/data/www/mediawiki-log/profiler-'.date('Ymd').'.log' ),
                'formatter' => 'profiler',
            ),
        ),

        'formatters' => array(
            'line' => array(
                'class' => '\\Monolog\\Formatter\\LineFormatter',
            ),
            'logstash' => array(
                'class' => '\\Monolog\\Formatter\\LogstashFormatter',
                'args'  => array( 'mediawiki', php_uname( 'n' ), null, '', 1 ),
            ),
            'profiler' => array(
                'class' => '\\Monolog\\Formatter\\LineFormatter',
                'args' => array( "%datetime% %message%\n\n", null, true, true ),
            ),
        ),
    ) ),
);

After setting the $wgMWLoggerDefaultSpi config variable, I recognized, that no data is sent to logstash, and even not to redis (which I checked after that).

After some time, I checked, if my configuration is applied by putting the following code directly after the assignment of the $wgMWLoggerDefaultSpi variable:

$logger = LoggerFactory::getInstance( 'test' );
var_dump( get_class( $logger ) );
exit;

And I got the output, that the LegacyLogger is returned by the LoggerFactory, which shouldn't happen if the configuration above is applied. So, after checking, that I used the correct global variable (twice) I checked, when getInstance() of LoggerFactory is called the first time by adding a debug_print_backtrace() call to the method, and I got the following output:

#0 MediaWiki\Logger\LoggerFactory::getProvider() called at [/data/mediawiki/main/includes/debug/logger/LoggerFactory.php:97] 
#1 MediaWiki\Logger\LoggerFactory::getInstance(objectcache) called at [/data/mediawiki/main/includes/objectcache/ObjectCache.php:175] 
#2 ObjectCache::newFromParams(Array) called at [/data/mediawiki/main/includes/ServiceWiring.php:336] 
#3 Closure$
#34(Object of class MediaWiki\MediaWikiServices could not be converted to string) 
#4 call_user_func_array(Object of class Closure$
#34;2111707029$8f1050010a79dba3428a504eb49b3b82$ could not be converted to string, Array) called at [/data/mediawiki/main/includes/services/ServiceContainer.php:361] 
#5 MediaWiki\Services\ServiceContainer->createService(LocalServerObjectCache) called at [/data/mediawiki/main/includes/services/ServiceContainer.php:344] 
#6 MediaWiki\Services\ServiceContainer->getService(LocalServerObjectCache) called at [/data/mediawiki/main/includes/MediaWikiServices.php:648] 
#7 MediaWiki\MediaWikiServices->getLocalServerObjectCache() called at [/data/mediawiki/main/includes/registration/ExtensionRegistry.php:90] 
#8 ExtensionRegistry->__construct() called at [/data/mediawiki/main/includes/registration/ExtensionRegistry.php:80] 
#9 ExtensionRegistry::getInstance() called at [/data/mediawiki/main/includes/GlobalFunctions.php:116] 
#10 wfLoadExtension(WikibaseDataModel, /data/mediawiki/main/vendor/wikibase/data-model/mediawiki-extension.json) called at [/data/mediawiki/main/vendor/wikibase/data-model/WikibaseDataModel.php:13] 
#11 include(/data/mediawiki/main/vendor/wikibase/data-model/WikibaseDataModel.php) called at [/data/mediawiki/main/vendor/composer/autoload_real.php:70] 
#12 composerRequire207f40de2cbb0083fd2081ddb0bacdd9(dc2c047038b9f5c71759f55f00aba99b, /data/mediawiki/main/vendor/wikibase/data-model/WikibaseDataModel.php) called at [/data/mediawiki/main/vendor/composer/autoload_real.php:60] 
#13 ComposerAutoloaderInit207f40de2cbb0083fd2081ddb0bacdd9::getLoader() called at [/data/mediawiki/main/vendor/autoload.php:7] 
#14 include(/data/mediawiki/main/vendor/autoload.php) called at [/data/mediawiki/main/includes/WebStart.php:86] 
#15 include(/data/mediawiki/main/includes/WebStart.php) called at [/data/mediawiki/main/index.php:40]

So, the Wikibase modules, which (in my setup) are loaded into the MediaWiki vendor directory (by merging all extension composer.json files into the main mediawiki core one, so I've to use composer update only once), uses wfLoadExtension to load itself. This, on its own, shouldn't be a problem. However, the MediaWiki composer autoloader is loaded before the LocalSettings.php is included in WebStart.php. That means, that any code, which is called in the composer autoloader files, is executed with the default configuration of MediaWiki. All objects, which uses singletons (e.g. LoggerFactory) then caches the objects and later calls get objects which are initialized with the MediaWiki default configuration.

I'm not sure, if this is a bug in mediawiki/core, in the Wikibase data-model modules (it's not just this one mentioned in the stack trace, it's just the first one) or if my setup isn't supported in this way (especially merging all extension composer.jsons into the mediawiki/core one:

"extra": {
        "merge-plugin": {
                "include": [
                        "extensions/*/composer.json"
                ]
        }
}

TASK DETAIL
https://phabricator.wikimedia.org/T151135

EMAIL PREFERENCES
https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: Florian
Cc: Aklapper, Florian, D3r1ck01, Izno, Wikidata-bugs, aude, JeroenDeDauw, Mbch331
_______________________________________________
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

Reply via email to