Page MenuHomePhabricator

Reports of 400 and 500 errors with Parsoid
Closed, ResolvedPublic0 Story Points

Description

See the original report: https://en.wikipedia.org/w/index.php?title=Wikipedia:VisualEditor/Feedback&diff=680469738&oldid=680467172

Errors were produced when both text and references were added.

Event Timeline

Whatamidoing-WMF updated the task description. (Show Details)
Whatamidoing-WMF raised the priority of this task from to Normal.
Whatamidoing-WMF added a subscriber: Whatamidoing-WMF.
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptSep 11 2015, 4:29 PM
Elitre added a subscriber: Elitre.Sep 11 2015, 5:23 PM

So, Josve05a reported on #mediawiki-visualeditor that https://war.wikipedia.org/w/index.php?title=Mansellia_annulata&veaction=edit is one of the failing pages. @Krenair and I confirmed it. I grepped parsoid logs and as you can see, the serialization requests never even got to Parsoid. So, the 400 is being returned further up in the request pipeline. This doesn't seem Parsoid-related.

subbu@earth:~$ for wtp in `ssh ssastry@bast1001.wikimedia.org cat /etc/dsh/group/parsoid` ; do echo $wtp ; ssh ssastry@$wtp grep warwiki /var/log/parsoid/parsoid.log | grep serializ ; done
wtp1001.eqiad.wmnet
{"name":"parsoid","hostname":"wtp1001","pid":9437,"level":30,"logType":"info","wiki":"warwiki","title":"Whitfieldia_elongata","oldId":null,"reqId":"9d16f697-58ad-11e5-ab88-e2dd9c7b3958","msg":"started serializing","longMsg":"started serializing","time":"2015-09-11T17:50:39.426Z","v":0}
{"name":"parsoid","hostname":"wtp1001","pid":9437,"level":30,"logType":"info","wiki":"warwiki","title":"Whitfieldia_elongata","oldId":6198805,"reqId":"9d16f697-58ad-11e5-ab88-e2dd9c7b3958","msg":"completed serializing in 219 ms","longMsg":"completed serializing in 219 ms","time":"2015-09-11T17:50:39.525Z","v":0}
wtp1002.eqiad.wmnet
wtp1003.eqiad.wmnet
wtp1004.eqiad.wmnet
wtp1005.eqiad.wmnet
wtp1006.eqiad.wmnet
wtp1007.eqiad.wmnet
wtp1008.eqiad.wmnet
wtp1009.eqiad.wmnet
{"name":"parsoid","hostname":"wtp1009","pid":22819,"level":30,"logType":"info","wiki":"warwiki","title":"Gumaramit:Krenair_(WMF)/Sandbox","oldId":null,"reqId":"6b2baded-58ae-11e5-9f3c-a1707e2935e0","msg":"started serializing","longMsg":"started serializing","time":"2015-09-11T17:56:25.039Z","v":0}
{"name":"parsoid","hostname":"wtp1009","pid":22819,"level":30,"logType":"info","wiki":"warwiki","title":"Gumaramit:Krenair_(WMF)/Sandbox","oldId":6198807,"reqId":"6b2baded-58ae-11e5-9f3c-a1707e2935e0","msg":"completed serializing in 52 ms","longMsg":"completed serializing in 52 ms","time":"2015-09-11T17:56:25.087Z","v":0}
wtp1010.eqiad.wmnet
wtp1011.eqiad.wmnet
wtp1012.eqiad.wmnet
wtp1013.eqiad.wmnet
wtp1014.eqiad.wmnet
wtp1015.eqiad.wmnet
{"name":"parsoid","hostname":"wtp1015","pid":6321,"level":30,"logType":"info","wiki":"warwiki","title":"Gumaramit:Krenair_(WMF)/Sandbox","oldId":null,"reqId":"62fd1b0c-58ae-11e5-89e6-81926e3d9e44","msg":"started serializing","longMsg":"started serializing","time":"2015-09-11T17:56:11.470Z","v":0}
{"name":"parsoid","hostname":"wtp1015","pid":6321,"level":30,"logType":"info","wiki":"warwiki","title":"Gumaramit:Krenair_(WMF)/Sandbox","oldId":null,"reqId":"62fd1b0c-58ae-11e5-89e6-81926e3d9e44","msg":"completed serializing in 168 ms","longMsg":"completed serializing in 168 ms","time":"2015-09-11T17:56:11.474Z","v":0}
wtp1016.eqiad.wmnet
wtp1017.eqiad.wmnet
wtp1018.eqiad.wmnet
wtp1019.eqiad.wmnet
wtp1020.eqiad.wmnet
wtp1021.eqiad.wmnet
wtp1022.eqiad.wmnet
wtp1023.eqiad.wmnet
{"name":"parsoid","hostname":"wtp1023","pid":31228,"level":30,"logType":"info","wiki":"warwiki","title":"Syahan nga Pakli","oldId":null,"reqId":null,"msg":"started serializing","longMsg":"started serializing","time":"2015-09-11T18:24:21.809Z","v":0}
{"name":"parsoid","hostname":"wtp1023","pid":31228,"level":30,"logType":"info","wiki":"warwiki","title":"Syahan nga Pakli","oldId":null,"reqId":null,"msg":"completed serializing in 90 ms","longMsg":"completed serializing in 90 ms","time":"2015-09-11T18:24:21.811Z","v":0}
{"name":"parsoid","hostname":"wtp1023","pid":31228,"level":30,"logType":"info","wiki":"warwiki","title":"Syahan nga Pakli","oldId":null,"reqId":null,"msg":"started serializing","longMsg":"started serializing","time":"2015-09-11T18:26:01.007Z","v":0}
{"name":"parsoid","hostname":"wtp1023","pid":31228,"level":30,"logType":"info","wiki":"warwiki","title":"Syahan nga Pakli","oldId":null,"reqId":null,"msg":"completed serializing in 8 ms","longMsg":"completed serializing in 8 ms","time":"2015-09-11T18:26:01.008Z","v":0}
wtp1024.eqiad.wmnet
Jdforrester-WMF set Security to None.
Jdforrester-WMF added a subscriber: Jdforrester-WMF.

Issue in RESTBase then?

It turns out that this is triggered by really old HTML revisions (rendered and stored in early March) not having a mw:TimeUuid meta tag in the head. A newly added sanity check now detects this issue, and refuses to guess in order to avoid corruptions. It only affects stored renders that haven't been touched since, or where re-renders have not changed the content at all.

A temporary work-around is to edit the page once using the wikitext editor.

In the meantime, we will make sure to re-render all HTML revisions stored before early March.

GWicke added a comment.EditedSep 11 2015, 11:14 PM

I have started a script to replace all renders from before April 1st, which is when the change to insert the mw:TimeUuid meta tag was deployed.

GWicke added a comment.EditedSep 13 2015, 8:10 PM

To speed things up a little bit, I have now increased the parallelism of re-renders by performing them asynchronously to old revision deletions:

This is running in a screen on restbase1002. Current token range being worked on is -8454960161286145256 out of a total of about -9254960161286145256 to 9254960161286145256, meaning that even at this pace it'll take a while to complete.

Progress update: The script is at -3951775668321071380, so a few more days to go.

Thanks a lot for your work and for the update! It's much appreciated when we can give an ETA :)

We are now getting close to 60%. Based on progress so far, the refresh of all old renders should finish less than 48 hours from now.

Ainali added a subscriber: Ainali.Sep 16 2015, 2:12 PM
ssastry moved this task from Backlog to Non-Parsoid Tasks on the Parsoid board.Sep 16 2015, 10:48 PM
GWicke closed this task as Resolved.Sep 18 2015, 8:01 PM
GWicke claimed this task.

The refresh script finished on Wednesday, so this issue should now be resolved. Thanks for your patience!

NQ added a subscriber: NQ.EditedSep 24 2015, 1:19 AM

From the en.wiki help desk: https://en.wikipedia.org/w/index.php?title=Wikipedia:Help_desk&diff=682483785&oldid=682482046

For the past several days, whenever I have tried to make anything more than a simple change using the "Edit" tool (rather than "Edit Source"), I have been unable to save my work due to a "parsoidserver-http: HTTP 400" error.

The refresh script finished on Wednesday, so this issue should now be resolved. Thanks for your patience!

In T112286#1669264, @NQ wrote:
From the en.wiki help desk: https://en.wikipedia.org/w/index.php?title=Wikipedia:Help_desk&diff=682483785&oldid=682482046

For the past several days, whenever I have tried to make anything more than a simple change using the "Edit" tool (rather than "Edit Source"), I have been unable to save my work due to a "parsoidserver-http: HTTP 400" error.

Could we get some specific information? For which page that occurred? Which revision? And, if possible, provide the time you attempted the edit.

Looking at the list of thrown 4xx errors for transforms I'm thinking this is partially caused by T113117: RESTBase wrongly refusing to serve revision text if username is hidden, so will put it as a blocker.

Another interesting and possibly-related task is T113163: Cannot save existing pages using IE11, but it claims that error can be witnessed only in IE11, but not in other browsers.

mobrovac reopened this task as Open.Sep 24 2015, 10:33 AM

Reopening as the battle with 4xx errors is still on-going.

TTO added a subscriber: TTO.Sep 25 2015, 12:21 PM
mobrovac changed the task status from Open to Stalled.Sep 25 2015, 1:34 PM

Both blocking tickets have been resolved. Setting the status of this one to stalled, so that we can monitor if there are other unforeseen issues.

No new reports for 20 days now. Are we out of the woods for this one? If so, I'd like to remove RB's double logging of 4xx Parsoid errors.

I've recently seen reports of failures without a code, and reports of 500 errors from non-WMF wikis, but I think those are not relevant here.

ori added a subscriber: ori.Nov 7 2015, 5:35 AM
  1. Go to https://en.wikipedia.org/wiki/Jonathan_Mendelsohn.
  2. Click on the redlink labeled 'Nicola' in the final paragraph.
  3. Click on 'Create'.

I reliably get an HTTP 400 error this way.

The request is an HTTP POST to https://en.wikipedia.org/api/rest_v1/transform/wikitext/to/html/Nicola_Mendelsohn/0 with form data:

titleNicola_Mendelsohn
oldid0
wikitext
stashtrue

The response is:

{"type":"https://restbase.org/errors/invalid_request","method":"post","detail":"Missing request parameter: wikitext","uri":"/en.wikipedia.org/v1/transform/wikitext/to/html/Nicola_Mendelsohn/0"}

@ori, it looks like VE has started to use the new stash API when switching from wikitext to visual editing. That API mode did not exist at the time of the original report, so this is definitely unrelated.

I think it would be nicer to relax our input validation to accept the empty string as an input there, as it would save clients from implementing a special case for blank pages. I have created T118070 to track this.

GWicke closed this task as Resolved.Nov 7 2015, 7:59 AM

There have been no reports for the original issue since September. The Flow post issue sounds like new content & likely a Parsoid issue. I think it's safe to say that this issue is resolved.