There are instances of this error before Sep 19th in kibana, but since Sep 24, these greatly increased which is odd given that our previous deploy was Sep 19th.
But, anyway, there are a lot of these errors in kibana since Sep 24th ... so, should at least be easy to track down.

All the failures seem to be for zhwiki requests by presumably the iOS app based on the user agent string there (not pasting that email id here). They all say 'Main_Page' as the title which indicates a post request. And, they all seem to have stopped today after the mobileapps deploy at 3:00-3:06 pm CT. But, let us wait and see if they reappear. But, not sure we have enough information to debug this yet. But, independent of what in mobileapps caused this, this does look like something broken in Parsoid.

Scratch that. The errors have come back. But, they are all zhwiki and the iOS app user agent string and Main_Page.

Ongoing,
https://logstash.wikimedia.org/app/kibana#/doc/logstash-*/logstash-2019.11.12/parsoid/?id=AW5g-s-eKWrIH1QRkbYw

Yup, still happening at a rate of approx 100 errors/hour.

The RESTBase logs are a little more useful here in that they surface page names,

res.headers.content-location	https://zh.wikipedia.org/api/rest_v1/page/html/%E4%B8%AD%E5%8D%8E%E4%BA%BA%E6%B0%91%E5%85%B1%E5%92%8C%E5%9B%BD%E9%93%81%E8%B7%AF%E9%9A%A7%E9%81%93%E5%88%97%E8%A1%A8/56865865

https://logstash.wikimedia.org/app/kibana#/doc/logstash-*/logstash-2019.11.14/restbase?id=AW5nh5_rh3Uj6x1z8F-0&_g=h@44136fa

Given that,

curl --header "Accept-Language: zh-cn" https://zh.wikipedia.org/api/rest_v1/page/html/%E4%B8%AD%E5%8D%8E%E4%BA%BA%E6%B0%91%E5%85%B1%E5%92%8C%E5%9B%BD%E9%93%81%E8%B7%AF%E9%9A%A7%E9%81%93%E5%88%97%E8%A1%A8/56865865

crashes pretty consistently.

Ok, I can somewhat reproduce this locally now.

The problem stems from the conflux of,
https://github.com/wikimedia/parsoid/commit/554dfcf35dd30d1cb91bb619bb22acde5c2fa47d
and,
https://github.com/wikimedia/parsoid/commit/7df5d973a0b83a4682d6b66274c55ddcb0a18894

When 554dfcf landed, checking data-parsoid (the call to WTUtils.usesURLLinkSyntax(node)) merely left behind a .dataobject on a node that would be dropped when serialized. After 7df5d97, it leaks a data-object-id attribute. In other words, using DOMDataUtils in what are supposed to be pure transformation on the output is fraught.

This might have been caught sooner if the post-processing pass done while parsing was pushed to after cleanup, where the redlinks pass happens,
https://github.com/wikimedia/parsoid/blob/master/lib/wt2html/DOMPostProcessor.js#L307-L312

Indeed, doing so causes some parserTests to fail.

However, the thing that still remains the mystery is that the leak happens while doing a transform. So, that implies transforming already transformed content? Is it possible that RESTBase is doubling up somehow?

Change 550899 had a related patch set uploaded (by Arlolra; owner: Arlolra):
[mediawiki/services/parsoid@master] [WIP] Stop using DOMDataUtils in LC pass

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

I am not quite certain I understand your question, but the only scenario I can think of where RESTBase is definitely sending already transformed content is when editors switch from VE to WT and then back:

1. the editor starts editing with VE; RB stashes the content
2. the editor switches to WT-editing; the content gets transformed to WT and that gets stashed
3. the editor switches back to VE, edits some more and saves; RB picks up the transforms from (1) and sends them to Parsoid

Would that explain this? Even if it does, I'm having a hard time explaining the number of occurrences of this error: 100 editors per hour constantly switching between VE and WT sounds unlikely to me.

I am not quite certain I understand your question

Sorry, let me try to clarify but we can speak on IRC.

We're only talking about language conversion here, so the /transform/pagebundle/to/pagebundle/ endpoint.

The question is if content that has already been converted to one variant is then asked to be converted to another.

@mobrovac From today's Parsing-Team--ARCHIVED discussion, we're thinking of adding some logs for the http-equiv meta tag to see if the HTML we're receiving is already populated with Accept-Language.

Change 551623 had a related patch set uploaded (by Arlolra; owner: Arlolra):
[mediawiki/services/parsoid@master] Log a warning if HTML has already been variant converted

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

Change 551623 merged by jenkins-bot:
[mediawiki/services/parsoid@master] Log an error if HTML has already been variant converted

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

Mentioned in SAL (#wikimedia-operations) [2019-11-18T21:56:52Z] <arlolra> Upgraded Parsoid to 2245b8f (T237886, T237103, T236864, T237569, T236930, T237463, T236867, T234266)

After deploying the patch in T234266#5673264 there're a ton of logs showing that RESTBase is sending HTML that had already been variant converted to the pb2pb endpoint. That seems like a bug.

For example,
https://logstash.wikimedia.org/app/kibana#/doc/logstash-*/logstash-2019.11.18/parsoid?id=AW6AhhUhKWrIH1QRqeCO&_g=h@1251ff0

Hm, well, to be exact the logs are not as useful per se for two reasons:

Ok, that does seem awfully silly of me. I guess I misconstrued what Scott was saying. Should have verified, sorry.

Change 551863 had a related patch set uploaded (by Arlolra; owner: Arlolra):
[mediawiki/services/parsoid@master] Revert "Log an error if HTML has already been variant converted"

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

Change 551863 merged by jenkins-bot:
[mediawiki/services/parsoid@master] Revert "Log an error if HTML has already been variant converted"

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

So, if I'm understanding correctly, RESTBase is always going to add the header on (say) zhwiki, but the usual sequence is:

wt2html, w/ Accept-Language: zh (ie, no conversion is done by Parsoid)
html2html, w/ Accept-Language: zh-hans (ie conversion)

So @Arlolra was initially assuming the Accept-Language indicated language conversion, but you actually needed to look at the contents of the header to determine whether Parsoid was actually going to trigger the language conversion code?

I imagine the code that was reverted could be made to work by checking for a /\-/ in the language?

I've established that it's definitely RESTBase's fault: for some reason, when the revision is provided, it asks for the conversion twice, but the second time it provides the content returned to it by Parsoid for the first conversion request. I'm still investigating why and how that happens. To be continued.

Ok found the bug. The problem was that the filter routine that executed the actual conversion was loaded twice. PR #1219 fixes this.

Change 550899 merged by jenkins-bot:
[mediawiki/services/parsoid@master] Stop using DOMDataUtils in LC pass

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

Mentioned in SAL (#wikimedia-operations) [2019-11-26T07:29:34Z] <mobrovac@deploy1001> Started deploy [restbase/deploy@378f504]: Do not use duplicate filter definitions T234266

Mentioned in SAL (#wikimedia-operations) [2019-11-26T07:43:58Z] <mobrovac@deploy1001> Finished deploy [restbase/deploy@378f504]: Do not use duplicate filter definitions T234266 (duration: 14m 24s)