Page MenuHomePhabricator

Frequent duplicate key errors by page assessments
Closed, ResolvedPublic1 Estimated Story PointsPRODUCTION ERROR

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.

Related Objects

StatusSubtypeAssignedTask
OpenNone
ResolvedPRODUCTION ERRORkaldari

Event Timeline

jcrespo raised the priority of this task from Medium to Needs Triage.
jcrespo created this task.

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 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

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.

mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:11 PM