Page MenuHomePhabricator

Frequent duplicate key errors by page assessments
Closed, ResolvedPublic1 Story Points

Description

Happening since 2016-11-13:

https://logstash.wikimedia.org/goto/1accd04515820244e3afc443d7fdeed0

{
  "_index": "logstash-2016.12.01",
  "_type": "mediawiki",
  "_id": "AVi5awFtNPFiRo8stLUd",
  "_score": null,
  "_source": {
    "message": "PageAssessmentsBody::insertRecord\t10.64.32.27\t1062\tDuplicate entry '42117544-47' for key 'PRIMARY' (10.64.32.27)\tINSERT  INTO `page_assessments` (pa_page_id,pa_project_id,pa_class,pa_importance,pa_page_revision) VALUES ('42117544','47','C','Unknown','751323561')",
    "@version": 1,
    "@timestamp": "2016-12-01T08:05:46.000Z",
    "type": "mediawiki",
    "host": "mw1165",
    "level": "ERROR",
    "tags": [
      "syslog",
      "es",
      "es"
    ],
    "channel": "DBQuery",
    "normalized_message": "{fname}\t{db_server}\t{errno}\t{error}\t{sql1line}",
    "url": "/rpc/RunJobs.php?wiki=enwiki&type=refreshLinks&maxtime=30&maxmem=300M",
    "ip": "127.0.0.1",
    "http_method": "POST",
    "server": "127.0.0.1",
    "referrer": null,
    "wiki": "enwiki",
    "mwversion": "1.29.0-wmf.3",
    "reqId": "d111c21a32b3ab1725b3c415",
    "db_server": "10.64.32.27",
    "db_name": "enwiki",
    "db_user": "wikiuser",
    "method": "Database::reportQueryError",
    "errno": 1062,
    "error": "Duplicate entry '42117544-47' for key 'PRIMARY' (10.64.32.27)",
    "sql1line": "INSERT  INTO `page_assessments` (pa_page_id,pa_project_id,pa_class,pa_importance,pa_page_revision) VALUES ('42117544','47','C','Unknown','751323561')",
    "fname": "PageAssessmentsBody::insertRecord"
  },
  "fields": {
    "@timestamp": [
      1480579546000
    ]
  },
  "sort": [
    1480579546000
  ]
}

A well-created code should check for those in advance. If records can be deleted concurrently, run SELECT FOR UPDATE within a transaction to make sure it is consistent. If those are not real errors, we could use INSERT IGNORE or replace, but checking within or outside a transaction would be preferred.

This is causing log spam and makes more difficult debug problems.

Event Timeline

jcrespo removed kaldari as the assignee of this task.Dec 1 2016, 8:26 AM
jcrespo raised the priority of this task from Normal to Needs Triage.
jcrespo created this task.
jcrespo updated the task description. (Show Details)Dec 1 2016, 8:29 AM

It does have code to check for this. There must be a bug.

Change 327399 had a related patch set uploaded (by Kaldari):
Adding IGNORE in case 2 records for the same project are added at once

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

The existing code was only checking for the case where an assessment record was being added that matched the same article/project combination of an existing assessment, but it was not checking for the case of 2 records for the same article/project being added during the exact same parse. In theory this should never happen (since it doesn't make sense for a project to have 2 different assessments of the same article), but it is technically possible. Wrote a patch that discards the redundant assessment (using INSERT IGNORE).

kaldari claimed this task.Dec 15 2016, 12:19 AM
kaldari triaged this task as High priority.
kaldari edited projects, added Community-Tech-Sprint; removed Community-Tech.
kaldari set the point value for this task to 1.
kaldari moved this task from Ready to Needs Review/Feedback on the Community-Tech-Sprint board.

Change 327399 merged by jenkins-bot:
Adding IGNORE in case 2 records for the same project are added at once

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

kaldari closed this task as Resolved.Dec 15 2016, 10:26 PM

54 errors of this kind in 1 hour. While I think this is low priority and not a big issue, it would go against the idea that "Adding IGNORE" is actually working in production.

{
  "_index": "logstash-2018.09.05",
  "_type": "mediawiki",
  "_id": "AWWpdH8BN6mdcdu0n-RZ",
  "_version": 1,
  "_score": null,
  "_source": {
    "server": "tr.wikipedia.org",
    "db_server": "10.64.0.110",
    "wiki": "trwiki",
    "channel": "DBQuery",
    "type": "mediawiki",
    "error": "Duplicate entry 'Olimpiyatlar' for key 'pap_project_title' (10.64.0.110)",
    "http_method": "POST",
    "@version": 1,
    "host": "mw1258",
    "shard": "s2",
    "sql1line": "INSERT  INTO `page_assessments_projects` (pap_project_title,pap_project_id) VALUES ('Olimpiyatlar',NULL)",
    "fname": "MediaWiki\\Extension\\PageAssessments\\PageAssessmentsDAO::insertProject",
    "errno": 1062,
    "unique_id": "W4@7hApAMF0AADxxa70AAABG",
    "method": "Wikimedia\\Rdbms\\Database::makeQueryException",
    "level": "ERROR",
    "ip": "10.64.48.101",
    "mwversion": "1.32.0-wmf.19",
    "message": "MediaWiki\\Extension\\PageAssessments\\PageAssessmentsDAO::insertProject\t10.64.0.110\t1062\tDuplicate entry 'Olimpiyatlar' for key 'pap_project_title' (10.64.0.110)\tINSERT  INTO `page_assessments_projects` (pap_project_title,pap_project_id) VALUES ('Olimpiyatlar',NULL)",
    "normalized_message": "{fname}\t{db_server}\t{errno}\t{error}\t{sql1line}",
    "url": "/w/index.php?title=%C5%9Eablon_tart%C4%B1%C5%9Fma:Olimpiyatlarda_karma_tak%C4%B1mlar&action=submit",
    "tags": [
      "syslog",
      "es",
      "es"
    ],
    "reqId": "W4@7hApAMF0AADxxa70AAABG",
    "referrer": "https://tr.wikipedia.org/w/index.php?title=%C5%9Eablon_tart%C4%B1%C5%9Fma:Olimpiyatlarda_karma_tak%C4%B1mlar&action=edit&redlink=1",
    "@timestamp": "2018-09-05T11:18:28.000Z",
    "db_name": "trwiki",
    "db_user": "wikiuser"
  },
  "fields": {
    "@timestamp": [
      1536146308000
    ]
  },
  "sort": [
    1536146308000
  ]
}

Not reopening unless someone confirms this is the same issue or to report it as a separate one.