Page MenuHomePhabricator

Error 1062 from Flow\Data\Storage\RevisionStorage::insert, {error} {sql1line} {db_server}
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error
normalized_message
Error 1062 from Flow\Data\Storage\RevisionStorage::insert, {error} {sql1line} {db_server}
exception.trace
from /srv/mediawiki/php-1.38.0-wmf.24/includes/libs/rdbms/database/Database.php(1636)
#0 /srv/mediawiki/php-1.38.0-wmf.24/includes/libs/rdbms/database/Database.php(1613): Wikimedia\Rdbms\Database->getQueryExceptionAndLog(string, integer, string, string)
#1 /srv/mediawiki/php-1.38.0-wmf.24/includes/libs/rdbms/database/Database.php(1207): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
#2 /srv/mediawiki/php-1.38.0-wmf.24/includes/libs/rdbms/database/Database.php(2401): Wikimedia\Rdbms\Database->query(string, string, integer)
#3 /srv/mediawiki/php-1.38.0-wmf.24/includes/libs/rdbms/database/Database.php(2381): Wikimedia\Rdbms\Database->doInsert(string, array, string)
#4 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Data/Storage/RevisionStorage.php(392): Wikimedia\Rdbms\Database->insert(string, array, string)
#5 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Data/ObjectManager.php(248): Flow\Data\Storage\RevisionStorage->insert(array)
#6 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Data/ObjectManager.php(173): Flow\Data\ObjectManager->insert(array, array)
#7 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Data/ObjectManager.php(146): Flow\Data\ObjectManager->multiPut(array, array)
#8 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Data/ManagerGroup.php(81): Flow\Data\ObjectManager->put(Flow\Model\PostRevision, array)
#9 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Block/TopicBlock.php(458): Flow\Data\ManagerGroup->put(Flow\Model\PostRevision, array)
#10 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/SubmissionHandler.php(164): Flow\Block\TopicBlock->commit()
#11 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/WorkflowLoader.php(66): Flow\SubmissionHandler->commit(Flow\Model\Workflow, array)
#12 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Api/ApiFlowBasePost.php(35): Flow\WorkflowLoader->commit(array)
#13 /srv/mediawiki/php-1.38.0-wmf.24/extensions/Flow/includes/Api/ApiFlow.php(108): Flow\Api\ApiFlowBasePost->execute()
#14 /srv/mediawiki/php-1.38.0-wmf.24/includes/api/ApiMain.php(1892): Flow\Api\ApiFlow->execute()
#15 /srv/mediawiki/php-1.38.0-wmf.24/includes/api/ApiMain.php(870): ApiMain->executeAction()
#16 /srv/mediawiki/php-1.38.0-wmf.24/includes/api/ApiMain.php(841): ApiMain->executeActionWithErrorHandling()
#17 /srv/mediawiki/php-1.38.0-wmf.24/api.php(90): ApiMain->execute()
#18 /srv/mediawiki/php-1.38.0-wmf.24/api.php(45): wfApiMain()
#19 /srv/mediawiki/w/api.php(3): require(string)
#20 {main}
Impact

Seen only on testwiki.

Notes

43 instances in the last week. Seems like a regression with wmf.24

Details

Request URL
https://test.wikipedia.org/w/api.php

Event Timeline

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

@kostajh should this be in the current sprint?

@kostajh should this be in the current sprint?

Yeah, probably, as there are enough of them to make it worthwhile to fix, I think.

From looking at a handful of these, I see:

Query: INSERT INTO `flow_revision` (rev_id,rev_user_id,rev_user_ip,rev_user_wiki,rev_parent_id,rev_change_type,rev_type,rev_type_id,rev_content,rev_flags,rev_mod_state,rev_mod_user_id,rev_mod_user_ip,rev_mod_user_wiki,rev_mod_timestamp,rev_mod_reason,rev_last_edit_id,rev_edit_user_id,rev_edit_user_ip,rev_edit_user_wiki,rev_content_length,rev_previous_content_length) VALUES ('� ݃#�a�',23124,NULL,'testwiki','�g�Qb�c_�a','restore-post','post','@��o@�Y5A-','DB://cluster27/82526','utf-8,gzip,html,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,external,exter,external','',NULL,NULL,NULL,NULL,'Pywikibot test',NULL,NULL,NULL,NULL,47,'0')

Note the "Pywikibot test" and "restore-topic" values.

So, there is definitely a bug in Flow that should handle whatever is being triggered by Pywikibot, but in the short term, perhaps the Pywikibot maintainers could see what is happening with the code path that is calling "restore-post" on testwiki?

kostajh triaged this task as Medium priority.Mar 14 2022, 8:23 PM

perhaps the Pywikibot maintainers could see what is happening with the code path that is calling "restore-post" on testwiki?

You can find the CI log here. Just search for flow_edit_tests or restore. The corresponding API error message is shown there.

perhaps the Pywikibot maintainers could see what is happening with the code path that is calling "restore-post" on testwiki?

You can find the CI log here. Just search for flow_edit_tests or restore. The corresponding API error message is shown there.

Sorry, just saw this and that link says the URI is expired. I'm looking at https://github.com/wikimedia/pywikibot/actions and am unfamiliar with logs on Github actions; if you could point me towards where to find the logs I'd appreciate it. Thanks!

Here an acutal issue:

2022-03-24T13:08:42.7951226Z =================================== FAILURES ===================================
2022-03-24T13:08:42.7951615Z ___________________ TestFlowLockTopic.test_lock_unlock_topic ___________________
2022-03-24T13:08:42.7951845Z 
2022-03-24T13:08:42.7952072Z self = <tests.flow_edit_tests.TestFlowLockTopic testMethod=test_lock_unlock_topic>
2022-03-24T13:08:42.7952331Z 
2022-03-24T13:08:42.7952463Z     def test_lock_unlock_topic(self):
2022-03-24T13:08:42.7952771Z         """Lock and unlock a test topic."""
2022-03-24T13:08:42.7953031Z         # Setup
2022-03-24T13:08:42.7953631Z         topic = Topic(self.site, 'Topic:Sn12rdih4iducjsd')
2022-03-24T13:08:42.7953943Z         if topic.is_locked:
2022-03-24T13:08:42.7954232Z >           topic.unlock(MODERATION_REASON)
2022-03-24T13:08:42.7954416Z 
2022-03-24T13:08:42.7954537Z tests/flow_edit_tests.py:174: 
2022-03-24T13:08:42.7954825Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
2022-03-24T13:08:42.7955123Z pywikibot/flow.py:263: in unlock
2022-03-24T13:08:42.7955434Z     self.site.lock_topic(self, False, reason)
2022-03-24T13:08:42.7956176Z pywikibot/site/_decorators.py:92: in callee
2022-03-24T13:08:42.7956475Z     return fn(self, *args, **kwargs)
2022-03-24T13:08:42.7956784Z pywikibot/site/_decorators.py:60: in callee
2022-03-24T13:08:42.7957086Z     return fn(self, *args, **kwargs)
2022-03-24T13:08:42.7957404Z pywikibot/site/_extensions.py:528: in lock_topic
2022-03-24T13:08:42.7957683Z     data = req.submit()
2022-03-24T13:08:42.7957959Z pywikibot/data/api.py:1822: in submit
2022-03-24T13:08:42.7958288Z     if self._internal_api_error(code, error, result):
2022-03-24T13:08:42.7958629Z pywikibot/data/api.py:1673: in _internal_api_error
2022-03-24T13:08:42.7958899Z     self.wait()
2022-03-24T13:08:42.7959171Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
2022-03-24T13:08:42.7959349Z 
2022-03-24T13:08:42.7960171Z self = pywikibot.data.api.Request<wikipedia:test->'/w/api.php?action=flow&page=Topic:Sn12rdih4iducjsd&submodule=lock-topic&cotreason=Pywikibot+test&cotmoderationState=unlock&maxlag=5&format=json&token=0338df8e93639a5bc1ba6907ba15c7c0623c6794+\\'>
2022-03-24T13:08:42.7960785Z delay = None
2022-03-24T13:08:42.7960930Z 
2022-03-24T13:08:42.7961049Z     def wait(self, delay=None):
2022-03-24T13:08:42.7961367Z         """Determine how long to wait after a failed request."""
2022-03-24T13:08:42.7961688Z         self.current_retries += 1
2022-03-24T13:08:42.7961997Z         if self.current_retries > self.max_retries:
2022-03-24T13:08:42.7962486Z >           raise TimeoutError('Maximum retries attempted without success.')
2022-03-24T13:08:42.7962937Z E           pywikibot.exceptions.TimeoutError: Maximum retries attempted without success.
2022-03-24T13:08:42.7963215Z 
2022-03-24T13:08:42.7963356Z pywikibot/data/api.py:1899: TimeoutError
2022-03-24T13:08:42.7963859Z ------------------------------ Captured log setup ------------------------------
2022-03-24T13:08:42.7964332Z VERBOSE  pywiki:logging.py:106 Found 1 wikipedia:test processes running, including this one.
2022-03-24T13:08:42.7964913Z ----------------------------- Captured stdout call -----------------------------
2022-03-24T13:08:42.7965236Z  36.544s 
2022-03-24T13:08:42.7965673Z ------------------------------ Captured log call -------------------------------
2022-03-24T13:08:42.7966556Z WARNING  pywiki:logging.py:106 API error internal_api_error_DBQueryError: [4fbb03d3-f508-4bf1-a78f-7d0c60376fca] Exception caught: A database query error has occurred. This may indicate a bug in the software.
2022-03-24T13:08:42.7967112Z VERBOSE  pywiki:logging.py:106            headers=
2022-03-24T13:08:42.7970991Z {'date': 'Thu, 24 Mar 2022 12:44:04 GMT', 'server': 'mw1381.eqiad.wmnet', 'x-content-type-options': 'nosniff', 'mediawiki-api-error': 'internal_api_error_DBQueryError', 'x-frame-options': 'DENY', 'content-disposition': 'inline; filename=api-result.json', 'cache-control': 'private, max-age=0, s-maxage=0', 'vary': 'Accept-Encoding', 'set-cookie': 'cpPosIndex=2%401648125844%239ac33e8c493d80136e6f7f7ad3634ae1; expires=Thu, 24-Mar-2022 12:44:14 GMT; Max-Age=10; path=/; secure; HttpOnly, UseDC=master; expires=Thu, 24-Mar-2022 12:44:14 GMT; Max-Age=10; path=/; secure; HttpOnly, UseCDNCache=false; expires=Thu, 24-Mar-2022 12:44:14 GMT; Max-Age=10; path=/; secure; HttpOnly', 'content-type': 'application/json; charset=utf-8', 'content-encoding': 'gzip', 'age': '0', 'x-cache': 'cp1077 miss, cp1081 pass', 'x-cache-status': 'pass', 'server-timing': 'cache;desc="pass", host;desc="cp1081"', 'strict-transport-security': 'max-age=106384710; includeSubDomains; preload', 'report-to': '{ "group": "wm_nel", "max_age": 86400, "endpoints": [{ "url": "https://intake-logging.wikimedia.org/v1/events?stream=w3c.reportingapi.network_error&schema_uri=/w3c/reportingapi/network_error/1.0.0" }] }', 'nel': '{ "report_to": "wm_nel", "max_age": 86400, "failure_fraction": 0.05, "success_fraction": 0.0}', 'permissions-policy': 'interest-cohort=()', 'x-client-ip': '23.102.121.162', 'accept-ranges': 'bytes', 'transfer-encoding': 'chunked'}
2022-03-24T13:08:42.7976640Z ERROR    pywiki:logging.py:106 Detected MediaWiki API exception internal_api_error_DBQueryError: [4fbb03d3-f508-4bf1-a78f-7d0c60376fca] Exception caught: A database query error has occurred. This may indicate a bug in the software.
2022-03-24T13:08:42.7977240Z [errorclass: Wikimedia\Rdbms\DBQueryError;
2022-03-24T13:08:42.7977867Z  *: Wikimedia\Rdbms\DBQueryError at /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1589)
2022-03-24T13:08:42.7978500Z from /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1589)
2022-03-24T13:08:42.7979266Z #0 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1573): Wikimedia\Rdbms\Database->getQueryException(string, integer, string, string)
2022-03-24T13:08:42.7980171Z #1 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1547): Wikimedia\Rdbms\Database->getQueryExceptionAndLog(string, integer, string, string)
2022-03-24T13:08:42.7981065Z #2 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1156): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
2022-03-24T13:08:42.7981888Z #3 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(2335): Wikimedia\Rdbms\Database->query(string, string, integer)
2022-03-24T13:08:42.7982658Z #4 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(2315): Wikimedia\Rdbms\Database->doInsert(string, array, string)
2022-03-24T13:08:42.7983480Z #5 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/Storage/RevisionStorage.php(392): Wikimedia\Rdbms\Database->insert(string, array, string)
2022-03-24T13:08:42.7984287Z #6 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ObjectManager.php(248): Flow\Data\Storage\RevisionStorage->insert(array)
2022-03-24T13:08:42.7985055Z #7 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ObjectManager.php(173): Flow\Data\ObjectManager->insert(array, array)
2022-03-24T13:08:42.7985812Z #8 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ObjectManager.php(146): Flow\Data\ObjectManager->multiPut(array, array)
2022-03-24T13:08:42.7986618Z #9 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ManagerGroup.php(81): Flow\Data\ObjectManager->put(Flow\Model\PostRevision, array)
2022-03-24T13:08:42.7987431Z #10 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Block/TopicBlock.php(458): Flow\Data\ManagerGroup->put(Flow\Model\PostRevision, array)
2022-03-24T13:08:42.7988194Z #11 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/SubmissionHandler.php(164): Flow\Block\TopicBlock->commit()
2022-03-24T13:08:42.7988961Z #12 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/WorkflowLoader.php(66): Flow\SubmissionHandler->commit(Flow\Model\Workflow, array)
2022-03-24T13:08:42.7989718Z #13 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Api/ApiFlowBasePost.php(35): Flow\WorkflowLoader->commit(array)
2022-03-24T13:08:42.7990415Z #14 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Api/ApiFlow.php(108): Flow\Api\ApiFlowBasePost->execute()
2022-03-24T13:08:42.7991050Z #15 /srv/mediawiki/php-1.39.0-wmf.3/includes/api/ApiMain.php(1897): Flow\Api\ApiFlow->execute()
2022-03-24T13:08:42.7991694Z #16 /srv/mediawiki/php-1.39.0-wmf.3/includes/api/ApiMain.php(871): ApiMain->executeAction()
2022-03-24T13:08:42.7992352Z #17 /srv/mediawiki/php-1.39.0-wmf.3/includes/api/ApiMain.php(842): ApiMain->executeActionWithErrorHandling()
2022-03-24T13:08:42.7992921Z #18 /srv/mediawiki/php-1.39.0-wmf.3/api.php(90): ApiMain->execute()
2022-03-24T13:08:42.7993375Z #19 /srv/mediawiki/php-1.39.0-wmf.3/api.php(45): wfApiMain()
2022-03-24T13:08:42.7993725Z #20 /srv/mediawiki/w/api.php(3): require(string)
2022-03-24T13:08:42.7994002Z #21 {main};
2022-03-24T13:08:42.7994244Z  servedby: mw1381]; retrying
2022-03-24T13:08:42.7994582Z VERBOSE  pywiki:logging.py:106 MediaWiki exception DBQueryError details:
2022-03-24T13:08:42.7994906Z           query=
2022-03-24T13:08:42.7995489Z ("{'action': ['flow'], 'page': [Topic('Topic:Sn12rdih4iducjsd')], 'token': "
2022-03-24T13:08:42.7996002Z  "['0338df8e93639a5bc1ba6907ba15c7c0623c6794+\\\\'], 'submodule': "
2022-03-24T13:08:42.7996494Z  "['lock-topic'], 'cotreason': ['Pywikibot test'], 'cotmoderationState': "
2022-03-24T13:08:42.7996957Z  "['unlock'], 'maxlag': ['5'], 'format': ['json']}")
2022-03-24T13:08:42.7997231Z           response=
2022-03-24T13:08:42.8005310Z {'error': {'code': 'internal_api_error_DBQueryError', 'info': '[4fbb03d3-f508-4bf1-a78f-7d0c60376fca] Exception caught: A database query error has occurred. This may indicate a bug in the software.', 'errorclass': 'Wikimedia\\Rdbms\\DBQueryError', 'help': 'Wikimedia\\Rdbms\\DBQueryError at /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1589)\nfrom /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1589)\n#0 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1573): Wikimedia\\Rdbms\\Database->getQueryException(string, integer, string, string)\n#1 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1547): Wikimedia\\Rdbms\\Database->getQueryExceptionAndLog(string, integer, string, string)\n#2 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(1156): Wikimedia\\Rdbms\\Database->reportQueryError(string, integer, string, string, boolean)\n#3 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(2335): Wikimedia\\Rdbms\\Database->query(string, string, integer)\n#4 /srv/mediawiki/php-1.39.0-wmf.3/includes/libs/rdbms/database/Database.php(2315): Wikimedia\\Rdbms\\Database->doInsert(string, array, string)\n#5 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/Storage/RevisionStorage.php(392): Wikimedia\\Rdbms\\Database->insert(string, array, string)\n#6 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ObjectManager.php(248): Flow\\Data\\Storage\\RevisionStorage->insert(array)\n#7 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ObjectManager.php(173): Flow\\Data\\ObjectManager->insert(array, array)\n#8 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ObjectManager.php(146): Flow\\Data\\ObjectManager->multiPut(array, array)\n#9 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Data/ManagerGroup.php(81): Flow\\Data\\ObjectManager->put(Flow\\Model\\PostRevision, array)\n#10 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Block/TopicBlock.php(458): Flow\\Data\\ManagerGroup->put(Flow\\Model\\PostRevision, array)\n#11 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/SubmissionHandler.php(164): Flow\\Block\\TopicBlock->commit()\n#12 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/WorkflowLoader.php(66): Flow\\SubmissionHandler->commit(Flow\\Model\\Workflow, array)\n#13 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Api/ApiFlowBasePost.php(35): Flow\\WorkflowLoader->commit(array)\n#14 /srv/mediawiki/php-1.39.0-wmf.3/extensions/Flow/includes/Api/ApiFlow.php(108): Flow\\Api\\ApiFlowBasePost->execute()\n#15 /srv/mediawiki/php-1.39.0-wmf.3/includes/api/ApiMain.php(1897): Flow\\Api\\ApiFlow->execute()\n#16 /srv/mediawiki/php-1.39.0-wmf.3/includes/api/ApiMain.php(871): ApiMain->executeAction()\n#17 /srv/mediawiki/php-1.39.0-wmf.3/includes/api/ApiMain.php(842): ApiMain->executeActionWithErrorHandling()\n#18 /srv/mediawiki/php-1.39.0-wmf.3/api.php(90): ApiMain->execute()\n#19 /srv/mediawiki/php-1.39.0-wmf.3/api.php(45): wfApiMain()\n#20 /srv/mediawiki/w/api.php(3): require(string)\n#21 {main}'}, 'servedby': 'mw1381'}
2022-03-24T13:08:42.8010580Z WARNING  pywiki:logging.py:106 Waiting 5.0 seconds before retrying.

There are serveral reries made with similar results.

Are the board/topic names in the Pywikibot test randomised, or is this just a case of a single Flow board being corrupted in some way and the bot repeatedly trying to access it?

Are the board/topic names in the Pywikibot test randomised, or is this just a case of a single Flow board being corrupted in some way and the bot repeatedly trying to access it?

The code is here https://github.com/wikimedia/pywikibot/blob/master/tests/flow_edit_tests.py . Looks like it's https://test.wikipedia.org/wiki/Talk:Pywikibot_test. But I am not sure if it is corrupted.

Is this getting more frequent? Last 7 days, there have been 288 such errors.

MShilova_WMF moved this task from Needs Discussion to Triaged on the Growth-Team board.
MShilova_WMF subscribed.

We acknowledge that it's a real error exposed by these tests, but we currently don't have the capacity to fix it.

thcipriani subscribed.

Not seeing these in the last 90 days. Optimistically resolving.