Page MenuHomePhabricator

PHP Notice: unserialize(): Error at offset 65519 of 65535 bytes (in LiquidThreads)
Open, Needs TriagePublicPRODUCTION ERROR

Description

Error

MediaWiki version: 1.36.0-wmf.2

message
PHP Notice: unserialize(): Error at offset 65519 of 65535 bytes

Impact

Noticed a few of these today, while monitoring logs for breakage from this week's train. Not enough to be a train blocker at this volume, however, on the principle that every non-blocker error log message adds friction for the train, I'm reporting this in the hope someone will prevent this from happening again.

Notes

Details

Request ID
52a4ae81-9e29-41ac-86f5-367e40c5333c
Request URL
https://strategy.wikimedia.org/w/index.php?title=Thread:Talk:China_Task_Force/What_makes_Wikimedia_different_from_Hudong_%26_Baidu_Baike&lqt_method=thread_history
Stack Trace
exception.trace
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.36.0-wmf.2/extensions/LiquidThreads/classes/ThreadRevision.php(70): unserialize(string)
#2 /srv/mediawiki/php-1.36.0-wmf.2/extensions/LiquidThreads/classes/ThreadHistoryPager.php(109): ThreadRevision::loadFromRow(stdClass)
#3 /srv/mediawiki/php-1.36.0-wmf.2/extensions/LiquidThreads/classes/ThreadHistoryPager.php(97): ThreadHistoryPager->getActionDescription(string)
#4 /srv/mediawiki/php-1.36.0-wmf.2/includes/pager/TablePager.php(203): ThreadHistoryPager->formatValue(string, string)
#5 /srv/mediawiki/php-1.36.0-wmf.2/includes/pager/IndexPager.php(611): TablePager->formatRow(stdClass)
#6 /srv/mediawiki/php-1.36.0-wmf.2/includes/pager/TablePager.php(81): IndexPager->getBody()
#7 /srv/mediawiki/php-1.36.0-wmf.2/extensions/LiquidThreads/pages/ThreadHistoryListingView.php(22): TablePager->getBody()
#8 /srv/mediawiki/php-1.36.0-wmf.2/extensions/LiquidThreads/classes/Dispatch.php(104): ThreadHistoryListingView->show()
#9 /srv/mediawiki/php-1.36.0-wmf.2/extensions/LiquidThreads/classes/Dispatch.php(225): LqtDispatch::threadPermalinkMain(OutputPage, Article, Title, User, WebRequest)
#10 /srv/mediawiki/php-1.36.0-wmf.2/includes/HookContainer/HookContainer.php(320): LqtDispatch::tryPage(OutputPage, Article, Title, User, WebRequest, MediaWiki)
#11 /srv/mediawiki/php-1.36.0-wmf.2/includes/HookContainer/HookContainer.php(131): MediaWiki\HookContainer\HookContainer->callLegacyHook(string, array, array, array)
#12 /srv/mediawiki/php-1.36.0-wmf.2/includes/HookContainer/HookRunner.php(2557): MediaWiki\HookContainer\HookContainer->run(string, array)
#13 /srv/mediawiki/php-1.36.0-wmf.2/includes/MediaWiki.php(499): MediaWiki\HookContainer\HookRunner->onMediaWikiPerformAction(OutputPage, Article, Title, User, WebRequest, MediaWiki)
#14 /srv/mediawiki/php-1.36.0-wmf.2/includes/MediaWiki.php(313): MediaWiki->performAction(Article, Title)
#15 /srv/mediawiki/php-1.36.0-wmf.2/includes/MediaWiki.php(940): MediaWiki->performRequest()
#16 /srv/mediawiki/php-1.36.0-wmf.2/includes/MediaWiki.php(543): MediaWiki->main()
#17 /srv/mediawiki/php-1.36.0-wmf.2/index.php(53): MediaWiki->run()
#18 /srv/mediawiki/php-1.36.0-wmf.2/index.php(46): wfIndexMain()
#19 /srv/mediawiki/w/index.php(3): require(string)
#20 {main}
Related Changes in Gerrit:

Event Timeline

Krinkle moved this task from Untriaged to Jul 2020 on the Wikimedia-production-error board.
Krinkle subscribed.

No known owner per mw:Maintainers..

This seems to be caused by the value being truncated:

> $title = Title::makeTitle( NS_LQT_THREAD, 'Talk:China_Task_Force/What makes Wikimedia different from Hudong & Baidu Baike' );
> $p = WikiPage::factory($title);
> $th = Threads::withRoot( $p );
> var_dump($th->id());
string(2) "64"
 select length(th_content) from thread_history where th_thread=64 order by th_timestamp desc\g
+--------------------+
| length(th_content) |
+--------------------+
|               4609 |
|               3835 |
|              65535 |
|               3055 |
|               2298 |
|              65535 |
|              65535 |
|                709 |
+--------------------+

several entries have a length of 65535, which is the maximum length for a blob (as I realized too late, this was clear by looking at the error message). Then the column was expanded to LONGBLOB in 2009, but any entry that was already truncated upon insertion remains truncated.

Depending on the resources, there are three solutions to this issue:

Quick & easy solution

Just ignore the error. It can only happen on (some) pages older than 2009. It's certainly not high priority.

Quick but hacky solution

Suppress errors from the unserialize() call, do something in case of errors. The status quo is that $rev->mThreadObj is set to false and everything moves on silently, à la typical PHP ancient style, with horrible bugs waiting to happen (possibly).

Sane solution

Serialization should be avoided (T161647), as serializing classes like this to the database is bad practice (which can quickly become horrible practice if the classes are not plain value objects). As such, a new storage format might be introduced (e.g. JSON encoding of plain arrays), a maintenance script to update old entries could be written, and this script could also do something in case of truncated blobs. All of this would require a decent amount of work.

@Daimona What is the impact on end-user experience currently? The object that we are unable to unserialize, what object is it? Is there missing content now? Or is this an optimisation or cache that has a fallback?

If the content is missing, I'm guessing it's mostly irreversible, although we may able to re-encode a few rows by hand if we can find something in the truncated blob that's left to salvage and make sense of.

@Daimona What is the impact on end-user experience currently?

It is not entirely clear from the reproduction URL. For sure, there's no fatal error of any sort. There might be missing information, but I don't have enough knowledge of LiquidThreads or that specific page to determine this easily.

The object that we are unable to unserialize, what object is it?

It's a Thread object encapsulating some information about the thread history. I haven't analyzed the long blob from the prod DB, but there seems to be a lot of data in there. It seems like every Thread object stores additional thread objects, in a way that I think might easily run OOM, although this was for blobs stored in 2009. A blob taken from strategywiki with the following query:

select th_content from thread_history where th_id=309\g

seems to have 87 (!) Thread objects serialized inside of it. While these seem to be plain value objects, it seems like there was some fast (factorial/exponential) growth in the amount of Threads that can be stored (the page history has 8 threads), but again, I don't have more detailed information. The PHP serialization format also makes it particularly hard to read.

If the content is missing, I'm guessing it's mostly irreversible, although we may able to re-encode a few rows by hand if we can find something in the truncated blob that's left to salvage and make sense of.

Correct. I had to do something similar for AbuseFilter, see https://phabricator.wikimedia.org/diffusion/EABF/browse/master/maintenance/UpdateVarDumps.php$370

Still seeing these intermittently in 1.40.0-wmf.12.

Short spike after 1.43.0-wmf.13 deployment around Jul 11, 2024 @ 08:30:00.000, again on strategywiki only just like dup T360110.

sbassett added subscribers: Tgr, Bawolff.
Krinkle renamed this task from PHP Notice: unserialize(): Error at offset 65519 of 65535 bytes to PHP Notice: unserialize(): Error at offset 65519 of 65535 bytes (in LiquidThreads).Jul 25 2024, 3:30 PM

Still seen. The latest spike is from multiple different replies on this page failing to unserialize:

https://strategy.wikimedia.org/w/index.php?lqt_method=thread_history&title=Thread:Talk:Strategic_Plan/Movement_Priorities/diversity

Still seeing spikes of this error as of 1.43.0-wmf.23:

image.png (447×1 px, 83 KB)

https://logstash.wikimedia.org/goto/497b6eca591edceac36a99b29c6e6572

Snapshot was taken ~5 hours after deployment of 1.43.0-wmf.23 to group0. There seems to be a significant increase in the volume for 1.43.0-wmf.23 compared to previous versions.

For anyone running into this again in the future, it looks like there's some movement in the direction of sunsetting this extension: T370722 T350164

I've added a filter to the MediaWiki New Errors dashboard to try to reduce the noise. The filter is pretty safe: specific to LQT and strategywiki, so it shouldn't risk hiding similar issues happening elsewhere.

Error
normalized_message
[{reqId}] {exception_url}   PHP Notice: unserialize(): Error at offset 65531 of 65535 bytes
FrameLocationCall
from/srv/mediawiki/php-1.45.0-wmf.7/extensions/LiquidThreads/includes/ThreadRevision.php(77)
#0[internal function]MediaWiki\Exception\MWExceptionHandler::handleError(int, string, string, int)
#1/srv/mediawiki/php-1.45.0-wmf.7/extensions/LiquidThreads/includes/ThreadRevision.php(77)unserialize(string)
#2/srv/mediawiki/php-1.45.0-wmf.7/extensions/LiquidThreads/includes/ThreadHistoryPager.php(102)ThreadRevision::loadFromRow(stdClass)
#3/srv/mediawiki/php-1.45.0-wmf.7/extensions/LiquidThreads/includes/ThreadHistoryPager.php(92)ThreadHistoryPager->getActionDescription(string)
#4/srv/mediawiki/php-1.45.0-wmf.7/includes/pager/TablePager.php(189)ThreadHistoryPager->formatValue(string, string)
#5/srv/mediawiki/php-1.45.0-wmf.7/includes/pager/IndexPager.php(564)MediaWiki\Pager\TablePager->formatRow(stdClass)
#6/srv/mediawiki/php-1.45.0-wmf.7/includes/pager/IndexPager.php(601)MediaWiki\Pager\IndexPager->getRow(stdClass)
#7/srv/mediawiki/php-1.45.0-wmf.7/includes/pager/TablePager.php(100)MediaWiki\Pager\IndexPager->getBody()
#8/srv/mediawiki/php-1.45.0-wmf.7/extensions/LiquidThreads/includes/Pages/ThreadHistoryListingView.php(24)MediaWiki\Pager\TablePager->getFullOutput()
#9/srv/mediawiki/php-1.45.0-wmf.7/extensions/LiquidThreads/includes/LqtDispatch.php(114)ThreadHistoryListingView->show()
#10/srv/mediawiki/php-1.45.0-wmf.7/extensions/LiquidThreads/includes/LqtDispatch.php(234)LqtDispatch::threadPermalinkMain(MediaWiki\Output\OutputPage, MediaWiki\Page\Article, MediaWiki\Title\Title, MediaWiki\User\User, MediaWiki\Request\WebRequest)
#11/srv/mediawiki/php-1.45.0-wmf.7/includes/HookContainer/HookContainer.php(155)LqtDispatch::tryPage(MediaWiki\Output\OutputPage, MediaWiki\Page\Article, MediaWiki\Title\Title, MediaWiki\User\User, MediaWiki\Request\WebRequest, MediaWiki\Actions\ActionEntryPoint)
#12/srv/mediawiki/php-1.45.0-wmf.7/includes/HookContainer/HookRunner.php(2611)MediaWiki\HookContainer\HookContainer->run(string, array)
#13/srv/mediawiki/php-1.45.0-wmf.7/includes/actions/ActionEntryPoint.php(692)MediaWiki\HookContainer\HookRunner->onMediaWikiPerformAction(MediaWiki\Output\OutputPage, MediaWiki\Page\Article, MediaWiki\Title\Title, MediaWiki\User\User, MediaWiki\Request\WebRequest, MediaWiki\Actions\ActionEntryPoint)
#14/srv/mediawiki/php-1.45.0-wmf.7/includes/actions/ActionEntryPoint.php(505)MediaWiki\Actions\ActionEntryPoint->performAction(MediaWiki\Page\Article, MediaWiki\Title\Title)
#15/srv/mediawiki/php-1.45.0-wmf.7/includes/actions/ActionEntryPoint.php(143)MediaWiki\Actions\ActionEntryPoint->performRequest()
#16/srv/mediawiki/php-1.45.0-wmf.7/includes/MediaWikiEntryPoint.php(198)MediaWiki\Actions\ActionEntryPoint->execute()
#17/srv/mediawiki/php-1.45.0-wmf.7/index.php(58)MediaWiki\MediaWikiEntryPoint->run()
#18/srv/mediawiki/w/index.php(3)require(string)
#19{main}

Change #1163833 had a related patch set uploaded (by Ahmon Dancy; author: Ahmon Dancy):

[operations/puppet@production] logspam.pl: Consolidate ThreadRevision unserialize() errors

https://gerrit.wikimedia.org/r/1163833

Change #1163833 merged by JHathaway:

[operations/puppet@production] logspam.pl: Consolidate ThreadRevision unserialize() errors

https://gerrit.wikimedia.org/r/1163833