Page MenuHomePhabricator

[20h] Investigate the significant number of skipped Item IDs for newly created Wikidata items
Closed, ResolvedPublic

Description

T44362 reports a huge number of skipped item IDs when new Wikidata items are created.

We should understand what leads to the issue that prevent creation of new Items, and in turn to "skipping" the ID.
In particular, it would be important to find out if any of the recent code changes has increased the "conflict" rate - @Lucas_Werkmeister_WMDE suggests that recent change of the ratelimit for bots might be one of the factors relevant here (T258354).

WMDE has recently look into the related problem in T232620.

There is a number of hypotheses of issues that could be leading to creation problems, reported as:
T264448: Entity ID should not be assigned for label/description conflict
T264449: Entity ID should not be assigned for invalid entity data
T264450: Entity ID should not be assigned if rate limit is hit
T264451: Entity ID should not be assigned if disallowed by AbuseFilter

Investigation does not have to limit to investigation those four possible causes.
Investigation will be timeboxed to 20 hrs.

Event Timeline

Task inspection notes:

  • Idea from @Pablo-WMDE: add some logging to the entity ID generating code (with stack traces or similar), run our browser test suite (or API edge-to-edge tests, or similar), and see if anything unexpected causes entity IDs to be generated. Try to build a comprehensive overview of what causes entity IDs to be generated.
  • We seem to be in agreement that the “proper” solution to the problem of skipped item IDs would be to only assign an item ID very late, just before saving the item; however, this solution would likely take a lot of effort, since we’d have to adjust a lot of code to remove the assumption that item IDs are always available. (I dimly remember some related problems when editing Forms and Senses, whose IDs below the lexeme ID are also assigned in some different way…)
  • This doesn’t really belong to the investigation, but assuming that the main cause of skipped item IDs is T264450: Entity ID should not be assigned if rate limit is hit (due to T258354: remove noratelimit from bot group for Wikidata), I am thinking that one solution might be to introduce a separate rate limit for new item IDs (with the same limit as for page creation, probably), and to check that rate limit right before assigning an ID. This would also, in a way, “protect” us from the other issues – if you send a million new items with label/description conflicts per minute, then now you run into the “new item ID” rate limit before we even check for conflicts. (Could also reuse the same create rate limit, not sure.)
    • Can we confirm if the rate limit (or some other error) is the main cause, by checking which errors are returned most frequently by the API? Maybe we have a dashboard of API errors or something similar.

Following my report in T44362#6638174, I looked into this a little more. From Wikidata's mediawiki database, I queried page creation times for the items created during the reported time period (14 Nov, 1:42 to 21 Nov, 1:42) and quickly plotted Q-ID vs. item creation timestamp.

On the upper panel of the attached figure, you can see that there are two phases where the curve increases rapidly; a finer evaluation yields steep increases from 2020-11-14, 11:54 through 2020-11-16, 20:23, and another shorter period from 2020-11-18, 20:24 through 2020-11-18, 23:53. I also plotted the item creation rate (in 10 min bins) on the lower panel.

new_items_nov2020.png (1×800 px, 89 KB)

We can also compare the Grafana charts on the Wikidata edits dashboard. Particularly during the first and longer period, there have been phases where not a single user has been editing at the rate limit (90/min).

My findings are:

  • Skipped Q-IDs are not temporarily equally distributed over the one week period. It is reasonable to assume that someone triggers this with some sort of requests, and these requests are not coming in all the time.
  • The item creation rate (lower panel) looks perfectly sane, including during times when the curve on the upper panel increases quickly. This means that most of the Q-IDs are skipped during the steeper sections of the upper panel graph.
  • The two steep phases in the upper panel together comprise around 215.000 seconds. Considering we have lost ~450.000 Q-IDs mostly during that time period, it is reasonable to assume that Q-IDs are skipped/wasted at a rate of roughly 2/sec during these phases. This is above the rate limit (1.5/sec), but since no edits at all seem to go through, I think that the rate limit is likely not the cause for this problem.
ItamarWMDE renamed this task from Investigate the significant number of skipped Item IDs for newly created Wikidata items to [20h] Investigate the significant number of skipped Item IDs for newly created Wikidata items.Nov 26 2020, 1:48 PM

Copying from the parent task:

So I looked at a small gap here:

So the skips don't even appear to be during a time of mass creations?
I think the best way to investigate this would probably to be to add some fairly verbose logging around the entity creation flows in it's own log channel?
Perhaps:

  • When Special:NewItem starts the process of creating a new item?
  • When wbeditentity start the process of creating a new item?
  • When an ID is claimed in the IdGenerator

This should then allow us to progress toward seeing exactly which requests end up generating an ID that end up not completing / saving an entity.

(I probably should have written this on T268625)

Yeah, I think I’ll try to add some logging mainly around the IdGenerator.

(But I’m still leaning towards the “rate limit” solution from T268625#6645259. Even if the rate limit isn’t the current cause of the problem, adding a rate limit for entity ID generation seems like an elegant solution for me – because that’s what we want at the end of the day, isn’t it? We don’t want to let anyone “burn through” a large number of entity IDs, regardless of what exact issue is causing IDs to be skipped, and a rate limit in front of the IdGenerator ought to achieve that.)

Even if the rate limit isn’t the current cause of the problem, adding a rate limit for entity ID generation seems like an elegant solution for me – because that’s what we want at the end of the day, isn’t it? We don’t want to let anyone “burn through” a large number of entity IDs, regardless of what exact issue is causing IDs to be skipped.

Yes!

Change 643760 had a related patch set uploaded (by Lucas Werkmeister (WMDE); owner: Lucas Werkmeister (WMDE)):
[mediawiki/extensions/Wikibase@master] WIP: Introduce LoggingIdGenerator

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

Change 643874 had a related patch set uploaded (by Lucas Werkmeister (WMDE); owner: Lucas Werkmeister (WMDE)):
[operations/mediawiki-config@master] Add log channel Wikibase.IdGenerator

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

Change 643882 had a related patch set uploaded (by Lucas Werkmeister (WMDE); owner: Lucas Werkmeister (WMDE)):
[mediawiki/extensions/Wikibase@master] Log more messages in LoggingIdGenerator

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

Change 643760 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Introduce LoggingIdGenerator

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

Change 643882 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Log more messages in LoggingIdGenerator

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

Change 644564 had a related patch set uploaded (by Lucas Werkmeister (WMDE); owner: Lucas Werkmeister (WMDE)):
[operations/mediawiki-config@master] Enable Wikibase Repo ID generator logging on Test Wikidata

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

Since wmf.20 is still blocked (T263186), I don’t think we can backport the logging changes today. And that means it probably doesn’t make much sense to backport them at all – at this point, I figure we might as well wait for wmf.21 to roll out Tuesday and Wednesday. (That also means we can first test the logging on Test Wikidata before wmf.21 reaches real Wikidata.)

Change 643874 merged by jenkins-bot:
[operations/mediawiki-config@master] Add log channel Wikibase.IdGenerator

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

Mentioned in SAL (#wikimedia-operations) [2020-12-14T12:43:55Z] <lucaswerkmeister-wmde@deploy1001> Synchronized wmf-config/InitialiseSettings.php: Config: [[gerrit:643874|Add log channel Wikibase.IdGenerator (T268625)]] (duration: 00m 54s)

Mentioned in SAL (#wikimedia-operations) [2020-12-14T12:45:06Z] <lucaswerkmeister-wmde@deploy1001> Synchronized wmf-config/InitialiseSettings-labs.php: Config: [[gerrit:643874|Add log channel Wikibase.IdGenerator (T268625)]] (Beta-only sync to avoid drift) (duration: 00m 55s)

Change 644564 merged by jenkins-bot:
[operations/mediawiki-config@master] Enable Wikibase Repo ID generator logging on Test Wikidata

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

Mentioned in SAL (#wikimedia-operations) [2020-12-14T12:53:16Z] <lucaswerkmeister-wmde@deploy1001> Synchronized wmf-config/InitialiseSettings.php: Config: [[gerrit:644564|Enable Wikibase Repo ID generator logging on Test Wikidata (T268625)]] (1/2) (duration: 00m 54s)

Mentioned in SAL (#wikimedia-operations) [2020-12-14T12:54:23Z] <lucaswerkmeister-wmde@deploy1001> Synchronized wmf-config/Wikibase.php: Config: [[gerrit:644564|Enable Wikibase Repo ID generator logging on Test Wikidata (T268625)]] (2/2) (duration: 00m 54s)

Change 649321 had a related patch set uploaded (by Lucas Werkmeister (WMDE); owner: Lucas Werkmeister (WMDE)):
[operations/mediawiki-config@master] Enable Wikibase Repo ID generator logging on Wikidata

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

Change 649321 merged by jenkins-bot:
[operations/mediawiki-config@master] Enable Wikibase Repo ID generator logging on Wikidata

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

Mentioned in SAL (#wikimedia-operations) [2020-12-14T13:45:44Z] <lucaswerkmeister-wmde@deploy1001> Synchronized wmf-config/InitialiseSettings.php: Config: [[gerrit:649321|Enable Wikibase Repo ID generator logging on Wikidata (T268625)]] (duration: 00m 55s)

Alright, the logging is now enabled on real Wikidata too. When the next burst of skipped IDs comes, we should be able to see in the logs where it comes from.

Can we have a look at the logs and see where we currently stand?

Number of log events over the past 24 hours (from the Logstash dashboard linked in T268625#6688794):

Screenshot_2021-01-11 Wikibase IdGenerator (T268625) - Kibana.png (176×1 px, 12 KB)

Overall, 6030 log events during that period (4255 from api_appserver and 1775 from appserver), which would be 4 generated IDs per minute. Scrolling through the log messages, the generated IDs look contiguous to me –
Screenshot from 2021-01-11 17-29-05.png (419×409 px, 62 KB)

– so I assume that the skipped IDs are actually generated in PHP (and then not used), not being skipped at some lower SQL level.

I also picked out one random skipped item ID from Special:NewPages (searching Logstash for id:104777500) and found that its request data instructed Wikidata to create an item with Portuguese label/sitelink “Categoria:…”, but English label/sitelink “ategory:…” – this might be due to a Wikibase Client bug or a human error, but in either case I assume item creation ultimately failed because the missing “C” at the beginning of the enwiki sitelink caused a “no such page” error.

That’s just one random skipped item, though. I think it would be most useful to look at these log events during one of the “steep phases” that @MisterSynergy identified. @MisterSynergy: could you maybe repeat your analysis and tell us some timestamps to investigate further? :)

@Lucas_Werkmeister_WMDE: We have not seen excessive phases of QID skipping since the week ending December 5. We skip around 10k–50k QIDs per week since then which seems pretty "normal".

However, some regions in the QID space are still only sparsely populated. In the week ending last Saturday January 9, 2021, 1:42 AM UTC, for instance, we managed to put only 55 items between Q104646000 and Q104647000. In other words: that range is only 5.5% populated. I think it would be worth to check what was going on there.

Alright, thanks! Both of those IDs were generated at some time between 20:30 and 21:30 (both UTC, I think) on January 3rd; overall, that time range saw 3058 IDs being generated, which I downloaded. Of those 3058 log events, 2954 hit /w/api.php (the rest presumably used Special:NewItem), all of them with action=wbeditentity. And out of those 2954, 2692 (91%) used the exact same request data (along with new=item and a handful other parameters):

data (prettified – originally all in one line with no whitespace)
{
  "labels": [
    {
      "language": "English",
      "value": "Maggie Rogers"
    }
  ],
  "aliases": [
    {
      "language": "English",
      "value": "Mary Margaret Salisbury"
    }
  ],
  "claims": [
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P31",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "5",
            "id": "Q5"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P21",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "6581072",
            "id": "Q6581072"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P27",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "30",
            "id": "Q30"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P1559",
        "datatype": "monolingualtext",
        "datavalue": {
          "value": {
            "text": "Maggie Rogers",
            "language": "english"
          },
          "type": "monolingualtext"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P735",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "4963612",
            "id": "Q4963612"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P734",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "16471355",
            "id": "Q16471355"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P569",
        "datatype": "time",
        "datavalue": {
          "value": {
            "time": "+1933-08-04T00:00:00Z",
            "timezone": 0,
            "before": 0,
            "after": 0,
            "precision": 11,
            "calendarmodel": "http://www.wikidata.org/entity/Q1985727"
          },
          "type": "time"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P19",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "5083",
            "id": "Q5083"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P570",
        "datatype": "time",
        "datavalue": {
          "value": {
            "time": "+2018-11-29T00:00:00Z",
            "timezone": 0,
            "before": 0,
            "after": 0,
            "precision": 11,
            "calendarmodel": "http://www.wikidata.org/entity/Q1985727"
          },
          "type": "time"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P20",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "661595",
            "id": "Q661595"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P1317",
        "datatype": "time",
        "datavalue": {
          "value": {
            "time": "+1970-00-00T00:00:00Z",
            "timezone": 0,
            "before": 0,
            "after": 0,
            "precision": 9,
            "calendarmodel": "http://www.wikidata.org/entity/Q1985727"
          },
          "type": "time"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P1412",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "1860",
            "id": "Q1860"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P106",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "2487799",
            "id": "Q2487799"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P101",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "7175",
            "id": "Q7175"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P108",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "30290949",
            "id": "Q30290949"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P463",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "7053817",
            "id": "Q7053817"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P69",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "284777",
            "id": "Q284777"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P512",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "13420675",
            "id": "Q13420675"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P551",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "6106",
            "id": "Q6106"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P485",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "13371",
            "id": "Q13371"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P973",
        "datatype": "url",
        "datavalue": {
          "value": "https://id.lib.harvard.edu/ead/far00047/catalog",
          "type": "string"
        }
      },
      "type": "statement",
      "rank": "normal"
    }
  ]
}

Some bot was apparently very eager to ensure that Maggie Rogers, alias Mary Margaret Salisbury, member of the North American Mycological Association, got her item. (There’s no such item at the moment, but I don’t know whether the first request was successful and the 2691 others failed due to the duplicate label+description, and the item was subsequently deleted, or whether all 2692 requests failed for some reason.) I don’t know which bot that was – the current user is not part of the log events, and the requests don’t include assertuser in the request data – but that certainly looks suspect.

The next-most-common request data is for one Edwin M. Post, Jr., with 174 identical requests attempting to create an item for him.

Very odd.

Ah, one more thing. The Mary Margaret Salisbury requests don’t have an edit summary, but the Edwin M. Post, Jr. ones do:

New item using [[:toollabs:wikidata-todo/relator|Relator]]

Re. "Maggie Rogers": the request does not create an item since the input is not formatted correctly. If I throw this exact input to the API using pywikibot's editentity function [1], I get this error message: "WARNING: API error not-recognized-language: The supplied language code was not recognized." No idea whether this wastes a QID.

The second item "Edwin M. Post" interestingly mentions "wikidata-todo". This is one of the Magnus tools which sometimes creates plenty of empty items without the user realizing it. We had a couple of incidents in the past months where something of the order of 1000 completely empty items had to be deleted that had been accidentally created by the some tool; IIRC, it was a very old QuickStatements version that is still online. Relator [2] is something else, but it apparently uses parts of the same code in the background.

[1] https://public.paws.wmcloud.org/User:MisterSynergy/tmp/SkippedQIDs_testing.ipynb
[2] https://wikidata-todo.toolforge.org/relator/#/

More: only 77 items have been created in the past 30 days using Relator (per recentchanges table), 67 of them by User:Animalparty [1]. This user also created some items related to "Edwin M. Post" recently [2][3][4]. The other Relator users are User:Ayack (5 creations on Dec 21/22 and Jan 05), User:Miraclepine (1 creation on Dec 23), User:Andrew_Gray (1 creation on Jan 10), and User:Ldhank (3 creations on Jan 13). I think the tool is to be blamed here, but maybe you might want to interview them to understand their workflow and ask for suspicious tool behavior that they might have experienced.

[1] https://www.wikidata.org/w/index.php?target=Animalparty&namespace=all&tagfilter=&newOnly=1&start=&end=&limit=100&title=Special%3AContributions
[2] https://www.wikidata.org/wiki/Q104636500
[3] https://www.wikidata.org/wiki/Q104647694
[4] https://www.wikidata.org/wiki/Q104650032

Even if the rate limit isn’t the current cause of the problem, adding a rate limit for entity ID generation seems like an elegant solution for me – because that’s what we want at the end of the day, isn’t it? We don’t want to let anyone “burn through” a large number of entity IDs, regardless of what exact issue is causing IDs to be skipped.

Yes!

Created a dedicated task: T272032: Add rate limit for creating Item IDs

Alright, thanks! Both of those IDs were generated at some time between 20:30 and 21:30 (both UTC, I think) on January 3rd; overall, that time range saw 3058 IDs being generated, which I downloaded. Of those 3058 log events, 2954 hit /w/api.php (the rest presumably used Special:NewItem), all of them with action=wbeditentity. And out of those 2954, 2692 (91%) used the exact same request data (along with new=item and a handful other parameters):

data (prettified – originally all in one line with no whitespace)
{
  "labels": [
    {
      "language": "English",
      "value": "Maggie Rogers"
    }
  ],
  "aliases": [
    {
      "language": "English",
      "value": "Mary Margaret Salisbury"
    }
  ],
  "claims": [
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P31",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "5",
            "id": "Q5"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P21",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "6581072",
            "id": "Q6581072"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P27",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "30",
            "id": "Q30"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P1559",
        "datatype": "monolingualtext",
        "datavalue": {
          "value": {
            "text": "Maggie Rogers",
            "language": "english"
          },
          "type": "monolingualtext"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P735",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "4963612",
            "id": "Q4963612"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P734",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "16471355",
            "id": "Q16471355"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P569",
        "datatype": "time",
        "datavalue": {
          "value": {
            "time": "+1933-08-04T00:00:00Z",
            "timezone": 0,
            "before": 0,
            "after": 0,
            "precision": 11,
            "calendarmodel": "http://www.wikidata.org/entity/Q1985727"
          },
          "type": "time"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P19",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "5083",
            "id": "Q5083"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P570",
        "datatype": "time",
        "datavalue": {
          "value": {
            "time": "+2018-11-29T00:00:00Z",
            "timezone": 0,
            "before": 0,
            "after": 0,
            "precision": 11,
            "calendarmodel": "http://www.wikidata.org/entity/Q1985727"
          },
          "type": "time"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P20",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "661595",
            "id": "Q661595"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P1317",
        "datatype": "time",
        "datavalue": {
          "value": {
            "time": "+1970-00-00T00:00:00Z",
            "timezone": 0,
            "before": 0,
            "after": 0,
            "precision": 9,
            "calendarmodel": "http://www.wikidata.org/entity/Q1985727"
          },
          "type": "time"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P1412",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "1860",
            "id": "Q1860"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P106",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "2487799",
            "id": "Q2487799"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P101",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "7175",
            "id": "Q7175"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P108",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "30290949",
            "id": "Q30290949"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P463",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "7053817",
            "id": "Q7053817"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P69",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "284777",
            "id": "Q284777"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P512",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "13420675",
            "id": "Q13420675"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P551",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "6106",
            "id": "Q6106"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P485",
        "datavalue": {
          "value": {
            "entity-type": "item",
            "numeric-id": "13371",
            "id": "Q13371"
          },
          "type": "wikibase-entityid"
        }
      },
      "type": "statement",
      "rank": "normal"
    },
    {
      "mainsnak": {
        "snaktype": "value",
        "property": "P973",
        "datatype": "url",
        "datavalue": {
          "value": "https://id.lib.harvard.edu/ead/far00047/catalog",
          "type": "string"
        }
      },
      "type": "statement",
      "rank": "normal"
    }
  ]
}

Some bot was apparently very eager to ensure that Maggie Rogers, alias Mary Margaret Salisbury, member of the North American Mycological Association, got her item. (There’s no such item at the moment, but I don’t know whether the first request was successful and the 2691 others failed due to the duplicate label+description, and the item was subsequently deleted, or whether all 2692 requests failed for some reason.) I don’t know which bot that was – the current user is not part of the log events, and the requests don’t include assertuser in the request data – but that certainly looks suspect.

The next-most-common request data is for one Edwin M. Post, Jr., with 174 identical requests attempting to create an item for him.

Very odd.

Do you record the user who make the request? it is important when issues happen.