Page MenuHomePhabricator
Create Task
Maniphest T266070

wdqs updater failing on parse error
Closed, DeclinedPublic
Actions

Description

All wdqs servers appear to hit an error, causing the unit to fail. Eventually the service is restarted, at which point it eventually hits the error and fails again.

Oct 20 20:17:32 wdqs1008 systemd[1]: Started Query Service Updater.
Oct 20 20:17:32 wdqs1008 wdqs-updater[12116]: Updating via http://localhost:9999/bigdata/namespace/wdq/sparql
Oct 20 20:17:33 wdqs1008 wdqs-updater[12116]: #logback.classic pattern: %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg %mdc%n
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]: 20:27:13.519 [main] ERROR org.wikidata.query.rdf.tool.Update - Error during updater run.
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]: java.lang.RuntimeException: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null')
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:  at [Source: (org.apache.http.conn.EofSensorInputStream); line: 1, column: 2]
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.wikibase.WikibaseRepository.fetchRecentChanges(WikibaseRepository.java:356)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.wikibase.WikibaseRepository.fetchRecentChangesByTime(WikibaseRepository.java:327)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.change.RecentChangesPoller.doFetchRecentChanges(RecentChangesPoller.java:322)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.change.RecentChangesPoller.fetchRecentChanges(RecentChangesPoller.java:314)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.change.RecentChangesPoller.batch(RecentChangesPoller.java:338)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.change.RecentChangesPoller.nextBatch(RecentChangesPoller.java:167)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.change.RecentChangesPoller.nextBatch(RecentChangesPoller.java:38)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.Updater.nextBatch(Updater.java:371)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.Updater.run(Updater.java:163)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.Update.run(Update.java:174)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.Update.main(Update.java:98)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]: Caused by: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null')
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:  at [Source: (org.apache.http.conn.EofSensorInputStream); line: 1, column: 2]
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1804)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:693)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:591)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._handleUnexpectedValue(UTF8StreamJsonParser.java:2630)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._nextTokenNotInObject(UTF8StreamJsonParser.java:832)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:729)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:4141)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4000)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3070)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.wikibase.WikibaseRepository.getJson(WikibaseRepository.java:526)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         at org.wikidata.query.rdf.tool.wikibase.WikibaseRepository.fetchRecentChanges(WikibaseRepository.java:350)
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:         ... 10 common frames omitted
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]: Exception in thread "main" java.lang.RuntimeException: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null')
Oct 20 20:27:13 wdqs1008 wdqs-updater[12116]:  at [Source: (org.apache.http.conn.EofSensorInputStream); line: 1, column: 2]
Oct 20 20:27:13 wdqs1008 systemd[1]: wdqs-updater.service: Main process exited, code=exited, status=1/FAILURE
Oct 20 20:27:13 wdqs1008 systemd[1]: wdqs-updater.service: Unit entered failed state.
Oct 20 20:27:13 wdqs1008 systemd[1]: wdqs-updater.service: Failed with result 'exit-code'.

Related Objects

Event Timeline

RKemper created this task.Oct 20 2020, 8:35 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptOct 20 2020, 8:35 PM
RKemper updated the task description. (Show Details)Oct 20 2020, 8:41 PM
RKemper updated the task description. (Show Details)Oct 20 2020, 8:43 PM
dcausse added a subscriber: dcausse.Oct 21 2020, 8:53 AM

< at line 1 looks suspiciously as an HTML blob being returned while calling the recent change API, could it be that the host hit by this request was not fully functional at this time?

Looking at logstash I see a spike of errors on wikidata (from 18:00 to 21:00 sameday) related to Return value of Wikibase\Search\Elastic\Hooks::getWBCSConfig() must be an instance of Vikibase\Search\Elastic\WikibaseSearchConfig, instance of Vikibase\Search\Elastic\WikibaseSearchConfig returned. I think this relates to T245183.

dcausse added a project: Wikidata-Query-Service.Oct 21 2020, 9:08 AM
Restricted Application added a project: Wikidata. · View Herald TranscriptOct 21 2020, 9:08 AM
Aklapper removed a subscriber: Discovery-Search (Current work).Oct 24 2020, 1:16 PM
dcausse closed this task as Declined.Oct 26 2020, 4:40 PM

There's nothing to fix in the updater related to this ticket, the reason was a bad response from one mw machine.

Content licensed under Creative Commons Attribution-ShareAlike 4.0 (CC-BY-SA) unless otherwise noted; code licensed under GNU General Public License (GPL) or other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL