status: Log getMessage()/getWikiText() calls on good Statuses

Why:

- Calling getMessage()/getWikiText() with a good Status is a logic error
  that converts the Status being operated on into a fatal one.
- However, this error is never logged anywhere, which can make it
  difficult to diagnose such cases, as seen in
  I17166e988bf389a5b03d4a74f539f7bec7f5997f.

What:

- Add a warning-level log for the case when getMessage() or
  getWikiText() is invoked with a good Status.

Bug: T374436
Change-Id: I3efae5c4c336156924f1c9b4186fa9142aaed9ca

6 files changed, 90 insertions, 28 deletions

diff --git a/includes/ServiceWiring.php b/includes/ServiceWiring.php
index a425ca67e017..6b57ef482177 100644
--- a/includes/ServiceWiring.php
+++ b/includes/ServiceWiring.php
@@ -870,7 +870,8 @@ return [
 			$services->getTitleFormatter(),
 			$services->getHookContainer(),
 			$services->getUserIdentityUtils(),
-			$services->getLanguageFactory()
+			$services->getLanguageFactory(),
+			LoggerFactory::getInstance( 'status' )
 		);
 	},
 
diff --git a/includes/Status/StatusFormatter.php b/includes/Status/StatusFormatter.php
index 0e9b590989cc..fc522cf834e0 100644
--- a/includes/Status/StatusFormatter.php
+++ b/includes/Status/StatusFormatter.php
@@ -28,6 +28,8 @@ use MediaWiki\Parser\ParserOutput;
 use MediaWiki\StubObject\StubUserLang;
 use MessageCache;
 use MessageLocalizer;
+use Psr\Log\LoggerInterface;
+use RuntimeException;
 use StatusValue;
 use UnexpectedValueException;
 use Wikimedia\Message\MessageSpecifier;
@@ -43,10 +45,16 @@ class StatusFormatter {
 
 	private MessageLocalizer $messageLocalizer;
 	private MessageCache $messageCache;
+	private LoggerInterface $logger;
 
-	public function __construct( MessageLocalizer $messageLocalizer, MessageCache $messageCache ) {
+	public function __construct(
+		MessageLocalizer $messageLocalizer,
+		MessageCache $messageCache,
+		LoggerInterface $logger
+	) {
 		$this->messageLocalizer = $messageLocalizer;
 		$this->messageCache = $messageCache;
+		$this->logger = $logger;
 	}
 
 	/**
@@ -96,16 +104,18 @@ class StatusFormatter {
 		$rawErrors = $status->getErrors();
 		if ( count( $rawErrors ) === 0 ) {
 			if ( $status->isOK() ) {
-				$status->fatal(
-					'internalerror_info',
-					__METHOD__ . " called for a good result, this is incorrect\n"
-				);
+				$errMsg = __METHOD__ . " called for a good result, this is incorrect\n";
 			} else {
-				$status->fatal(
-					'internalerror_info',
-					__METHOD__ . ": Invalid result object: no error text but not OK\n"
-				);
+				$errMsg = __METHOD__ . ": Invalid result object: no error text but not OK\n";
 			}
+
+			$status->fatal(
+				'internalerror_info',
+				$errMsg
+			);
+
+			$this->logger->warning( $errMsg, [ 'exception' => new RuntimeException() ] );
+
 			$rawErrors = $status->getErrors(); // just added a fatal
 		}
 
@@ -171,16 +181,18 @@ class StatusFormatter {
 		$rawErrors = $status->getErrors();
 		if ( count( $rawErrors ) === 0 ) {
 			if ( $status->isOK() ) {
-				$status->fatal(
-					'internalerror_info',
-					__METHOD__ . " called for a good result, this is incorrect\n"
-				);
+				$errMsg = __METHOD__ . " called for a good result, this is incorrect\n";
 			} else {
-				$status->fatal(
-					'internalerror_info',
-					__METHOD__ . ": Invalid result object: no error text but not OK\n"
-				);
+				$errMsg = __METHOD__ . ": Invalid result object: no error text but not OK\n";
 			}
+
+			$status->fatal(
+				'internalerror_info',
+				$errMsg
+			);
+
+			$this->logger->warning( $errMsg, [ 'exception' => new RuntimeException() ] );
+
 			$rawErrors = $status->getErrors(); // just added a fatal
 		}
 		if ( count( $rawErrors ) === 1 ) {
diff --git a/includes/language/FormatterFactory.php b/includes/language/FormatterFactory.php
index c792debbebab..6a038713ca41 100644
--- a/includes/language/FormatterFactory.php
+++ b/includes/language/FormatterFactory.php
@@ -10,6 +10,7 @@ use MediaWiki\Title\TitleFormatter;
 use MediaWiki\User\UserIdentityUtils;
 use MessageCache;
 use MessageLocalizer;
+use Psr\Log\LoggerInterface;
 
 /**
  * Factory for formatters of common complex objects
@@ -23,23 +24,26 @@ class FormatterFactory {
 	private HookContainer $hookContainer;
 	private UserIdentityUtils $userIdentityUtils;
 	private LanguageFactory $languageFactory;
+	private LoggerInterface $logger;
 
 	public function __construct(
 		MessageCache $messageCache,
 		TitleFormatter $titleFormatter,
 		HookContainer $hookContainer,
 		UserIdentityUtils $userIdentityUtils,
-		LanguageFactory $languageFactory
+		LanguageFactory $languageFactory,
+		LoggerInterface $logger
 	) {
 		$this->messageCache = $messageCache;
 		$this->titleFormatter = $titleFormatter;
 		$this->hookContainer = $hookContainer;
 		$this->userIdentityUtils = $userIdentityUtils;
 		$this->languageFactory = $languageFactory;
+		$this->logger = $logger;
 	}
 
 	public function getStatusFormatter( MessageLocalizer $messageLocalizer ): StatusFormatter {
-		return new StatusFormatter( $messageLocalizer, $this->messageCache );
+		return new StatusFormatter( $messageLocalizer, $this->messageCache, $this->logger );
 	}
 
 	public function getBlockErrorFormatter( LocalizationContext $context ): BlockErrorFormatter {
diff --git a/tests/phpunit/includes/Status/StatusFormatterTest.php b/tests/phpunit/includes/Status/StatusFormatterTest.php
index 080c0caaea17..7ce0d07e1220 100644
--- a/tests/phpunit/includes/Status/StatusFormatterTest.php
+++ b/tests/phpunit/includes/Status/StatusFormatterTest.php
@@ -5,6 +5,7 @@ use MediaWiki\Language\RawMessage;
 use MediaWiki\Message\Message;
 use MediaWiki\Status\StatusFormatter;
 use MediaWiki\User\User;
+use Psr\Log\Test\TestLogger;
 use Wikimedia\Message\MessageValue;
 use Wikimedia\TestingAccessWrapper;
 
@@ -13,6 +14,19 @@ use Wikimedia\TestingAccessWrapper;
  */
 class StatusFormatterTest extends MediaWikiLangTestCase {
 
+	private ?TestLogger $logger;
+
+	protected function setUp(): void {
+		parent::setUp();
+
+		$this->logger = new TestLogger();
+	}
+
+	protected function tearDown(): void {
+		parent::tearDown();
+		$this->logger = null;
+	}
+
 	private function getFormatter( $lang = 'en' ) {
 		$localizer = new class() implements MessageLocalizer {
 			public $lang;
@@ -32,7 +46,7 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 
 		$localizer->lang = $lang;
 
-		return new StatusFormatter( $localizer, $cache );
+		return new StatusFormatter( $localizer, $cache, $this->logger );
 	}
 
 	/**
@@ -91,7 +105,12 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 	 * @dataProvider provideGetWikiTextAndHtml
 	 */
 	public function testGetHtml(
-		StatusValue $status, $wikitext, $wrappedWikitext, $html, $wrappedHtml
+		StatusValue $status,
+		$wikitext,
+		$wrappedWikitext,
+		$html,
+		$wrappedHtml,
+		?string $expectedWarning = null
 	) {
 		$formatter = $this->getFormatter();
 		$this->assertEquals( $html, $formatter->getHTML( $status ) );
@@ -107,6 +126,12 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 				]
 			)
 		);
+
+		if ( $expectedWarning !== null ) {
+			$this->assertTrue( $this->logger->hasWarningThatContains( $expectedWarning ) );
+		} else {
+			$this->assertFalse( $this->logger->hasWarningRecords() );
+		}
 	}
 
 	/**
@@ -125,6 +150,7 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 			"<p>Internal error: MediaWiki\Status\StatusFormatter::getWikiText called for a good result, this is incorrect\n</p>",
 			"<p>(wrap-short: (internalerror_info: MediaWiki\Status\StatusFormatter::getWikiText called for a good result, " .
 				"this is incorrect\n))\n</p>",
+			'MediaWiki\Status\StatusFormatter::getWikiText called for a good result, this is incorrect'
 		];
 
 		$status = new StatusValue();
@@ -137,6 +163,7 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 			"<p>Internal error: MediaWiki\Status\StatusFormatter::getWikiText: Invalid result object: no error text but not OK\n</p>",
 			"<p>(wrap-short: (internalerror_info: MediaWiki\Status\StatusFormatter::getWikiText: Invalid result object: " .
 				"no error text but not OK\n))\n</p>",
+			'MediaWiki\Status\StatusFormatter::getWikiText: Invalid result object: no error text but not OK'
 		];
 
 		$status = new StatusValue();
@@ -204,7 +231,11 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 	 * @dataProvider provideGetMessage
 	 */
 	public function testGetMessage(
-		StatusValue $status, $expectedParams, $expectedKey, $expectedWrapper
+		StatusValue $status,
+		$expectedParams,
+		$expectedKey,
+		$expectedWrapper,
+		?string $expectedWarning = null
 	) {
 		$formatter = $this->getFormatter();
 		$message = $formatter->getMessage( $status, [ 'lang' => 'qqx' ] );
@@ -233,6 +264,12 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 		$this->assertInstanceOf( Message::class, $message );
 		$this->assertEquals( 'wrapper', $message->getKey(), 'Message::getKey with wrappers' );
 		$this->assertCount( 1, $message->getParams(), 'Message::getParams with wrappers' );
+
+		if ( $expectedWarning !== null ) {
+			$this->assertTrue( $this->logger->hasWarningThatContains( $expectedWarning ) );
+		} else {
+			$this->assertFalse( $this->logger->hasWarningRecords() );
+		}
 	}
 
 	/**
@@ -248,7 +285,8 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 			new StatusValue(),
 			[ "MediaWiki\Status\StatusFormatter::getMessage called for a good result, this is incorrect&#10;" ],
 			'internalerror_info',
-			'wrapper-short'
+			'wrapper-short',
+			'MediaWiki\Status\StatusFormatter::getMessage called for a good result, this is incorrect'
 		];
 
 		$status = new StatusValue();
@@ -257,7 +295,8 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 			$status,
 			[ "MediaWiki\Status\StatusFormatter::getMessage: Invalid result object: no error text but not OK&#10;" ],
 			'internalerror_info',
-			'wrapper-short'
+			'wrapper-short',
+			'MediaWiki\Status\StatusFormatter::getMessage: Invalid result object: no error text but not OK'
 		];
 
 		$status = new StatusValue();
@@ -457,5 +496,4 @@ class StatusFormatterTest extends MediaWikiLangTestCase {
 			);
 		$this->assertTrue( true );
 	}
-
 }
diff --git a/tests/phpunit/unit/includes/Permissions/UserAuthorityTest.php b/tests/phpunit/unit/includes/Permissions/UserAuthorityTest.php
index 1152572f2179..9d0833bb8b9e 100644
--- a/tests/phpunit/unit/includes/Permissions/UserAuthorityTest.php
+++ b/tests/phpunit/unit/includes/Permissions/UserAuthorityTest.php
@@ -30,6 +30,7 @@ use MediaWiki\Status\StatusFormatter;
 use MediaWiki\Tests\Unit\FakeQqxMessageLocalizer;
 use MediaWiki\User\User;
 use MediaWikiUnitTestCase;
+use Psr\Log\NullLogger;
 
 /**
  * @covers \MediaWiki\Permissions\UserAuthority
@@ -383,7 +384,11 @@ class UserAuthorityTest extends MediaWikiUnitTestCase {
 		$this->assertStatusError( 'blockedtext-partial', $permissionStatus );
 		$this->assertNotNull( $permissionStatus->getBlock() );
 
-		$formatter = new StatusFormatter( new FakeQqxMessageLocalizer(), $this->createNoOpMock( \MessageCache::class ) );
+		$formatter = new StatusFormatter(
+			new FakeQqxMessageLocalizer(),
+			$this->createNoOpMock( \MessageCache::class ),
+			new NullLogger()
+		);
 		// Despite all the futzing around with services, StatusFormatter depends on this global through wfEscapeWikiText
 		global $wgEnableMagicLinks;
 		$old = $wgEnableMagicLinks;
diff --git a/tests/phpunit/unit/includes/language/FormatterFactoryTest.php b/tests/phpunit/unit/includes/language/FormatterFactoryTest.php
index c49a9b79c71e..49d1c43dd4bb 100644
--- a/tests/phpunit/unit/includes/language/FormatterFactoryTest.php
+++ b/tests/phpunit/unit/includes/language/FormatterFactoryTest.php
@@ -6,6 +6,7 @@ use MediaWiki\Language\FormatterFactory;
 use MediaWiki\Languages\LanguageFactory;
 use MediaWiki\Title\TitleFormatter;
 use MediaWiki\User\UserIdentityUtils;
+use Psr\Log\NullLogger;
 
 /**
  * @covers \MediaWiki\Language\FormatterFactory
@@ -18,7 +19,8 @@ class FormatterFactoryTest extends MediaWikiUnitTestCase {
 			$this->createNoOpMock( TitleFormatter::class ),
 			$this->createNoOpMock( HookContainer::class ),
 			$this->createNoOpMock( UserIdentityUtils::class ),
-			$this->createNoOpMock( LanguageFactory::class )
+			$this->createNoOpMock( LanguageFactory::class ),
+			new NullLogger()
 		);
 	}