Wikimedia\Timestamp\TimestampException: Wikimedia\Timestamp\ConvertibleTimestamp::getTimestamp: The timestamp cannot be represented in the specified format
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Assigned To

Authored By

	jnuche
	Mar 21 2022, 1:00 PM

Description

Error

mwversion: 1.39.0-wmf.1
reqId: 305b4430-bdb3-41f4-824d-e0611c097cc2
Find reqId in Logstash

normalized_message

[{reqId}] {exception_url}   Wikimedia\Timestamp\TimestampException: Wikimedia\Timestamp\ConvertibleTimestamp::getTimestamp: The timestamp cannot be represented in the specified format

exception.trace

from /srv/mediawiki/php-1.39.0-wmf.1/vendor/wikimedia/timestamp/src/ConvertibleTimestamp.php(330)
#0 /srv/mediawiki/php-1.39.0-wmf.1/includes/libs/rdbms/database/Database.php(4618): Wikimedia\Timestamp\ConvertibleTimestamp->getTimestamp(integer)
#1 /srv/mediawiki/php-1.39.0-wmf.1/extensions/Echo/includes/UnreadWikis.php(123): Wikimedia\Rdbms\Database->timestamp(string)
#2 /srv/mediawiki/php-1.39.0-wmf.1/extensions/Echo/includes/NotifUser.php(495): EchoUnreadWikis->updateCount(string, integer, boolean, integer, MWTimestamp)
#3 /srv/mediawiki/php-1.39.0-wmf.1/extensions/Echo/includes/jobs/NotificationDeleteJob.php(55): MWEchoNotifUser->resetNotificationCount()
#4 /srv/mediawiki/php-1.39.0-wmf.1/extensions/EventBus/includes/JobExecutor.php(79): EchoNotificationDeleteJob->run()
#5 /srv/mediawiki/rpc/RunSingleJob.php(76): MediaWiki\Extension\EventBus\JobExecutor->execute(array)
#6 {main}

Impact

Notes

Spotted by @dom_walden on beta cluster via T304295:

https://beta-logs.wmcloud.org/app/dashboards#/doc/5f0c9be0-0b6f-11ec-9cde-3f4490e09a26/logstash-deploy-2022.03.21?id=ZCQzrH8B89ekSwroeTBB

See a few errors happen in quick succession here: https://beta-logs.wmcloud.org/app/dashboards#/view/default?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:'2022-03-21T11:18:48.000Z',to:'2022-03-21T11:18:49.000Z'))&_a=(description:'',filters:!(('$state':(store:appState),meta:(alias:!n,disabled:!f,index:'5f0c9be0-0b6f-11ec-9cde-3f4490e09a26',key:level,negate:!f,params:(query:ERROR),type:phrase),query:(match_phrase:(level:ERROR)))),fullScreenMode:!f,options:(hidePanelTitles:!f,useMargins:!t),query:(language:kuery,query:''),timeRestore:!t,title:Default,viewMode:view)

Details

Request URL: https://jobrunner.discovery.wmnet/rpc/RunSingleJob.php

Subject	Repo	Branch	Lines +/-
Revert "Call IDatabase::timestamp before inserting rows"	mediawiki/extensions/Echo	wmf/1.39.0-wmf.2	+6 -12
Revert "Call IDatabase::timestamp before inserting rows"	mediawiki/extensions/Echo	wmf/1.39.0-wmf.1	+6 -12
Revert "Call IDatabase::timestamp before inserting rows"	mediawiki/extensions/Echo	master	+6 -12

Customize query in gerrit

Related Objects
Search...

		Status	Subtype	Assigned	Task
		Resolved	Release	thcipriani	T300203 🧪🚂 Trainsperiment Week: 1.39.0-wmf.1, 1.39.0-wmf.2, 1.39.0-wmf.3, 1.39.0-wmf.4 deployment blockers
		Resolved	PRODUCTION ERROR	hashar	T304307 Wikimedia\Timestamp\TimestampException: Wikimedia\Timestamp\ConvertibleTimestamp::getTimestamp: The timestamp cannot be represented in the specified format

Event Timeline

jnuche triaged this task as Unbreak Now! priority.Mar 21 2022, 1:00 PM

jnuche created this task.

Restricted Application added a project: Growth-Team. · View Herald TranscriptMar 21 2022, 1:00 PM

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

jnuche added a parent task: T300203: 🧪🚂 Trainsperiment Week: 1.39.0-wmf.1, 1.39.0-wmf.2, 1.39.0-wmf.3, 1.39.0-wmf.4 deployment blockers.Mar 21 2022, 1:01 PM

On T281451#7792422 which is about a different normalized message, there is a second exception:

Error 1062 from EchoNotificationMapper::insert, Duplicate entry '17604325-1515299' for key 'PRIMARY' (db1157) INSERT INTO echo_notification (notification_event,notification_user,notification_timestamp,notification_read_timestamp,notification_bundle_hash) VALUES (1515299,17604325,'20220321124005',NULL,'') db1157

Which be related to the timestamp issue.

A recent change made to Echo is 4eb8fa23e45f36c440197fa722319ab061f4e118 Call IDatabase::timestamp before inserting rows for T244898.

hashar mentioned this in T244898: Notifications ('Echo') should work with postgres.Mar 21 2022, 1:16 PM

Lucas_Werkmeister_WMDE mentioned this in T304295: Wikimedia\Timestamp\ConvertibleTimestamp::getTimestamp: The timestamp cannot be represented in the specified format.Mar 21 2022, 1:24 PM

Change 772349 had a related patch set uploaded (by Hashar; author: Hashar):

[mediawiki/extensions/Echo@master] Revert "Call IDatabase::timestamp before inserting rows"

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

gerritbot added a project: Patch-For-Review.Mar 21 2022, 1:28 PM

hashar merged a task: T304295: Wikimedia\Timestamp\ConvertibleTimestamp::getTimestamp: The timestamp cannot be represented in the specified format.Mar 21 2022, 1:28 PM

hashar updated the task description. (Show Details)

hashar added subscribers: dom_walden, Lucas_Werkmeister_WMDE.

Could the NULL value for notification_read_timestamp be the issue?

$dbw->timestamp() might need to be $dbw->timestampOrNull()

Change 772350 had a related patch set uploaded (by Hashar; author: Hashar):

[mediawiki/extensions/Echo@wmf/1.39.0-wmf.1] Revert "Call IDatabase::timestamp before inserting rows"

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

Change 772351 had a related patch set uploaded (by Hashar; author: Hashar):

[mediawiki/extensions/Echo@wmf/1.39.0-wmf.2] Revert "Call IDatabase::timestamp before inserting rows"

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

Change 772349 merged by jenkins-bot:

[mediawiki/extensions/Echo@master] Revert "Call IDatabase::timestamp before inserting rows"

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

Change 772350 merged by jenkins-bot:

[mediawiki/extensions/Echo@wmf/1.39.0-wmf.1] Revert "Call IDatabase::timestamp before inserting rows"

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

Change 772351 merged by jenkins-bot:

[mediawiki/extensions/Echo@wmf/1.39.0-wmf.2] Revert "Call IDatabase::timestamp before inserting rows"

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

Mentioned in SAL (#wikimedia-operations) [2022-03-21T14:28:38Z] <hashar@deploy1002> Synchronized php-1.39.0-wmf.1/extensions/Echo: Revert "Call IDatabase::timestamp before inserting rows" - T304307 (duration: 00m 52s)

ReleaseTaggerBot added a project: MW-1.39-notes (1.39.0-wmf.3; 2022-03-22).Mar 21 2022, 3:00 PM

Looks like that fixed it. I have left a message on the original task T244898 to notify the revert.

hashar mentioned this in T281451: Wikimedia\Rdbms\DBTransactionError: Transaction round stage must be 'cursory' (not 'within-rollback-callbacks').Mar 21 2022, 3:04 PM

hashar mentioned this in T300203: 🧪🚂 Trainsperiment Week: 1.39.0-wmf.1, 1.39.0-wmf.2, 1.39.0-wmf.3, 1.39.0-wmf.4 deployment blockers.

Maintenance_bot removed a project: Patch-For-Review.Mar 21 2022, 3:10 PM

In T304307#7792580, @RhinosF1 wrote:

Could the NULL value for notification_read_timestamp be the issue?

$dbw->timestamp() might need to be $dbw->timestampOrNull()

It was timestampOrNull already ($dbw->timestampOrNull( $row['notification_read_timestamp'] )) to handle null.
But the error is not for this line, it is for the other class changed in that patch set. It sems it has to do with EchoUnreadWikis::DEFAULT_TS and the IDatabase::timestamp

Krinkle moved this task from Untriaged to Mar 2022 on the Wikimedia-production-error board.Mar 22 2022, 1:44 PM

Wikimedia\Timestamp\TimestampException: Wikimedia\Timestamp\ConvertibleTimestamp::getTimestamp: The timestamp cannot be represented in the specified formatClosed, ResolvedPublicPRODUCTION ERRORActions