Failing to import anything

[AndrewIsh]

We are using translation-server to allow us to convert materials supplied in CSL JSON to RIS. When I initially set up a translation-server instance a few months ago it was working perfectly. However, now it does not appear to be, and I'm at something of a loss as to why, I'm hoping someone here can give some pointers as to where to look. I've brought the repo and it's submodules up to date, but am still seeing the same problem.

I have been trying to figure out what's going on using Postman and watching the translation-server console. Here's an example of a request and what I'm seeing in the console:

Request (curl):

curl -X POST \
  <my_server>/import \
  -H 'cache-control: no-cache' \
  -H 'content-type: application/json' \
  -d '[{"ISBN": "0-241-23221-X","id": "1-140","title": "This is a manual item","type": "book"}]'

Console output:

zotero(5)(+0218734): POST /import HTTP/1.1
cache-control: no-cache
Postman-Token: 3fa3436f-35cc-4a50-879f-bc6a8339c833
Content-Type: application/json
User-Agent: PostmanRuntime/6.1.6
Accept: */*
Host: <my_server>:8080
accept-encoding: gzip, deflate
content-length: 89
Connection: keep-alive

zotero(4)(+0000007): Translate: Binding sandbox to http://www.example.com/

zotero(4)(+0000005): Translate: Parsing code for Bibliontology RDF (14763d25-8ba0-45df-8f52-b8d1108e7ac9, 2017-06-03 10:21:42)

zotero(3)(+0000004): Translate: Initializing RDF data store

zotero(2)(+0000001): Translate: Detect using Bibliontology RDF failed: 
thrown exception => DOMParser error: loading data into data store failed
url => undefined
downloadAssociatedFiles => undefined
automaticSnapshots => undefined

zotero(4)(+0000002): Translate: Parsing code for MODS (0e2235e7-babf-413c-9acf-f27cce5f059c, 2015-02-11 01:24:19)

zotero(2)(+0000004): Translate: Detect using MODS failed: 
thrown exception => DOMParser error: loading data into data store failed
url => undefined
downloadAssociatedFiles => undefined
automaticSnapshots => undefined

zotero(4)(+0000002): Translate: Parsing code for CSL JSON (bc03b4fe-436d-4a1f-ba59-de4d2d7a63f7, 2017-07-05 19:32:38)

zotero(3)(+0000001): Translate: All translator detect calls and RPC calls complete:

zotero(3)(+0000000):    CSL JSON: 100

zotero(5)(+0000000): Translate: Running handler 0 for translators

zotero(5)(+0000002): Translate: Running handler 1 for translators

zotero(4)(+0000001): Translate: Parsing code for CSL JSON (bc03b4fe-436d-4a1f-ba59-de4d2d7a63f7, 2017-07-05 19:32:38)

zotero(3)(+0000002): Translate: Beginning translation with CSL JSON

zotero(3)(+0000001): Translate: Saving item

zotero(3)(+0000000): [JavaScript Error: "XML Parsing Error: syntax error
Location: moz-nullprincipal:{b6910630-9329-4f68-bba4-77b9ae291264}
Line Number 1, Column 1:" {file: "moz-nullprincipal:{b6910630-9329-4f68-bba4-77b9ae291264}" line: 1 column: 1 source: "[{"ISBN":"0-241-23221-X","id":"1-140","title":"This is a manual item","type":"book"}]"}] at undefined:1

zotero(3)(+0000001): [JavaScript Error: "XML Parsing Error: syntax error
Location: moz-nullprincipal:{19a43cd8-7e1c-4d8b-8f75-b21a0a0572f0}
Line Number 1, Column 1:" {file: "moz-nullprincipal:{19a43cd8-7e1c-4d8b-8f75-b21a0a0572f0}" line: 1 column: 1 source: "[{"ISBN":"0-241-23221-X","id":"1-140","title":"This is a manual item","type":"book"}]"}] at undefined:1

I'm confused as to why this is running into an XML parsing error, but really don't know where to start looking.

I've also tried the BibTeX example from the docs, but am seeing a similar error:

Request (and response):

curl -X POST -d 'TY  - JOUR
> TI  - Die Grundlage der allgemeinen Relativitätstheorie
> AU  - Einstein, Albert
> PY  - 1916
> SP  - 769
> EP  - 822
> JO  - Annalen der Physik
> VL  - 49
> ER  -' <my_server>:8080/import

No translators available

Console output:

zotero(5)(+0081828): POST /import HTTP/1.1
User-Agent: curl/7.38.0
Host: <my_server>:8080
Accept: */*
Content-Length: 161
Content-Type: application/x-www-form-urlencoded

zotero(4)(+0000012): Translate: Binding sandbox to http://www.example.com/

zotero(4)(+0000005): Translate: Parsing code for Bibliontology RDF (14763d25-8ba0-45df-8f52-b8d1108e7ac9, 2017-06-03 10:21:42)

zotero(3)(+0000003): Translate: Initializing RDF data store

zotero(2)(+0000002): Translate: Detect using Bibliontology RDF failed: 
thrown exception => DOMParser error: loading data into data store failed
url => undefined
downloadAssociatedFiles => undefined
automaticSnapshots => undefined

zotero(4)(+0000001): Translate: Parsing code for MODS (0e2235e7-babf-413c-9acf-f27cce5f059c, 2015-02-11 01:24:19)

zotero(2)(+0000005): Translate: Detect using MODS failed: 
thrown exception => DOMParser error: loading data into data store failed
url => undefined
downloadAssociatedFiles => undefined
automaticSnapshots => undefined

zotero(4)(+0000002): Translate: Parsing code for CSL JSON (bc03b4fe-436d-4a1f-ba59-de4d2d7a63f7, 2017-07-05 19:32:38)

zotero(4)(+0000003): Translate: Parsing code for RIS (32d59d2d-b65a-4da4-b0a3-bdd3cfb979e7, 2017-10-28 09:11:30)

zotero(4)(+0000013): Translate: Parsing code for Endnote XML (eb7059a4-35ec-4961-a915-3cf58eb9784b, 2017-07-05 19:32:38)

zotero(3)(+0000003): [JavaScript Error: "XML Parsing Error: not well-formed
Location: moz-nullprincipal:{a7e676b6-6fc3-4dea-b5af-d68779604cb7}
Line Number 1, Column 1:" {file: "moz-nullprincipal:{a7e676b6-6fc3-4dea-b5af-d68779604cb7}" line: 1 column: 1 source: "{"":"TY  - JOUR\nTI  - Die Grundlage der allgemeinen Relativitätstheorie\nAU  - Einstein, Albert\nPY  - 1916\nSP  - 769\nEP  - 822\nJO  - Annalen der Physik\nVL  - 49\nER  -"}"}] at undefined:1

zotero(3)(+0000001): [JavaScript Error: "XML Parsing Error: not well-formed
Location: moz-nullprincipal:{416003ee-6975-472e-957a-0fc7e69c0ef6}
Line Number 1, Column 1:" {file: "moz-nullprincipal:{416003ee-6975-472e-957a-0fc7e69c0ef6}" line: 1 column: 1 source: "{"":"TY  - JOUR\nTI  - Die Grundlage der allgemeinen Relativitätstheorie\nAU  - Einstein, Albert\nPY  - 1916\nSP  - 769\nEP  - 822\nJO  - Annalen der Physik\nVL  - 49\nER  -"}"}] at undefined:1

zotero(2)(+0000002): Translate: Detect using Endnote XML failed: 
thrown exception => DOMParser error: loading data into data store failed
url => undefined
downloadAssociatedFiles => undefined
automaticSnapshots => undefined

zotero(4)(+0000002): Translate: Parsing code for MARC (a6ee60df-1ddc-4aae-bb25-45e0537be973, 2017-09-17 09:32:19)

zotero(4)(+0000004): Translate: Parsing code for RDF (5e3ad958-ac79-463d-812b-a86a9235c28f, 2017-10-20 21:15:21)

zotero(2)(+0000004): Translate: Detect using RDF failed: 
string => Error: XML known invalid
stack => Error: XML known invalid
    Zotero.Translate.IO.String.prototype.init@chrome://translation-server/content/translation/translate.js:2796:10
    Zotero.Translate.Import.prototype._loadTranslatorPrepareIO<@chrome://translation-server/content/translation/translate.js:2308:2
    tryCatcher@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/util.js:16:16
    module.exports/Promise.method/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/method.js:15:21
From previous event:
    captureStackTrace@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/debuggability.js:826:23
    CapturedTrace@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/debuggability.js:718:5
    longStackTracesCaptureStackTrace@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/debuggability.js:397:19
    module.exports/Promise.prototype._then@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/promise.js:232:9
    module.exports/Promise.prototype.then@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/promise.js:125:12
    Zotero.Translate.Base.prototype._detect@chrome://translation-server/content/translation/translate.js:1703:3
    Zotero.Translate.Base.prototype.complete@chrome://translation-server/content/translation/translate.js:1529:5
    Zotero.Translate.Import.prototype.complete@chrome://translation-server/content/translation/translate.js:2249:2
    Zotero.Translate.Base.prototype.decrementAsyncProcesses@chrome://translation-server/content/translation/translate.js:1071:4
    Zotero.Translate.Base.prototype._detectTranslatorLoaded@chrome://translation-server/content/translation/translate.js:1728:3
    Zotero.Translate.Base.prototype._detect/<@chrome://translation-server/content/translation/translate.js:1705:11
    tryCatcher@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/util.js:16:16
    module.exports/Promise.prototype._settlePromiseFromHandler@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/promise.js:512:13
    module.exports/Promise.prototype._settlePromise@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/promise.js:569:13
    module.exports/Promise.prototype._settlePromise0@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/promise.js:614:5
    module.exports/Promise.prototype._settlePromises@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/promise.js:693:13
    Async.prototype._drainQueue@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/async.js:133:13
    Async.prototype._drainQueues@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/async.js:143:5
    Async/this.drainQueues@resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/async.js:17:9
    @app/init.js:149:14
url => undefined
downloadAssociatedFiles => undefined
automaticSnapshots => undefined

zotero(4)(+0000002): Translate: Parsing code for Refer/BibIX (881f60f2-0802-411a-9228-ce5f47b64c7d, 2017-06-03 11:41:00)

zotero(4)(+0000003): Translate: Parsing code for MEDLINE/nbib (9ec64cfd-bea7-472a-9557-493c0c26b0fb, 2015-10-16 18:47:13)

zotero(4)(+0000003): Translate: Parsing code for OVID Tagged (59e7e93e-4ef0-4777-8388-d6eddb3261bf, 2017-06-03 11:41:00)

zotero(4)(+0000005): Translate: Parsing code for Bookmarks (4e7119e0-02be-4848-86ef-79a64185aad8, 2017-06-03 11:41:00)

zotero(4)(+0000003): Translate: Parsing code for RefWorks Tagged (1a3506da-a303-4b0a-a1cd-f216e6138d86, 2016-06-21 08:45:20)

zotero(4)(+0000005): Translate: Parsing code for PubMed XML (fcf41bed-0cbc-3704-85c7-8062a0068a7a, 2015-10-17 05:38:38)

zotero(4)(+0000004): Translate: Parsing code for Web of Science Tagged (594ebe3c-90a0-4830-83bc-9502825a6810, 2015-06-02 21:33:13)

zotero(4)(+0000004): Translate: Parsing code for XML ContextObject (24d9f058-3eb3-4d70-b78f-1ba1aef2128d, 2015-05-20 00:05:55)

zotero(4)(+0000003): Translate: Parsing code for MARCXML (edd87d07-9194-42f8-b2ad-997c4c7deefd, 2016-12-04 14:12:35)

zotero(4)(+0000005): Translate: Parsing code for BibTeX (9cb70025-a888-4a29-a210-93ec52da40d4, 2017-07-05 19:32:38)

zotero(3)(+0000006): Translate: Scanning 175 characters for BibTeX

zotero(3)(+0000001): Translate: All translator detect calls and RPC calls complete:

zotero(3)(+0000000):    No suitable translators found

zotero(5)(+0000000): Translate: Running handler 0 for translators

zotero(5)(+0000001): HTTP/1.0 501 Method Not Implemented
Content-Type: text/plain

No translators available

zotero(5)(+0000000): Translate: Running handler 1 for translators

zotero(3)(+0000001): [JavaScript Error: "XML Parsing Error: not well-formed
Location: moz-nullprincipal:{081a3644-4aa8-4700-8f2f-84cfb87ed279}
Line Number 1, Column 1:" {file: "moz-nullprincipal:{081a3644-4aa8-4700-8f2f-84cfb87ed279}" line: 1 column: 1 source: "{"":"TY  - JOUR\nTI  - Die Grundlage der allgemeinen Relativitätstheorie\nAU  - Einstein, Albert\nPY  - 1916\nSP  - 769\nEP  - 822\nJO  - Annalen der Physik\nVL  - 49\nER  -"}"}] at undefined:1

I am sure this is going to be something obvious, but I'm failing to see what it is. Can anyone shed any light please?

[dstillman]

Is this with the Docker Hub version or the current master? If the latter, how are you building it?

[AndrewIsh]

Thanks for your reply.

Ah, this may be part of the problem. I deployed this a while ago so my memory is a bit hazy, but I'm pretty sure I deployed using the Docker Hub version. Whereas, I forgot that when bringing everything up to date, so I've just pulled the repos and not rebuilt or anything (go easy on me, I'm not a regular Docker user). OK, so I think my first step should be to update properly (using the Docker Hub version presumably) and then see if I'm still experiencing the problem. Thanks!

[dstillman]

The Docker Hub version is theoretically the current stable version. But we do plan to upload the current master to Docker Hub soon, so if you do build from that and run into trouble, let us know.

[AndrewIsh]

OK. Well I've ditched my Docker Hub version and cloned master just to make sure I'm up to date. I'm having some weirdness trying to get it working. Sorry, this is unrelated to the original problem, but I'm hoping it'll either lead to a resolution or a clearer understanding of the problem.

I've followed the instructions on https://github.com/zotero/translation-server#development as I wanted a custom port number and it seemed the only way to get that was to modify config.js then rebuilt. I did this but am not seeing the custom port number being used:

zotero@connect-1:~/translation-server$ docker run --rm -p 8080:8080 translation-server                                                          
From https://github.com/zotero/translators
 * branch            master     -> FETCH_HEAD
Already up-to-date.
JavaScript warning: resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/util.js, line 201: unreachable code after return statement
JavaScript warning: resource://gre/modules/commonjs/toolkit/loader.js -> resource://zotero/bluebird/util.js, line 201: unreachable code after return statement
zotero(3)(+0000000): HTTP GET resource://zotero/schema/dateFormats.json

zotero(3)(+0000007): HTTP GET resource://zotero/schema/dateFormats.json succeeded with 200

Loading translators from /opt/translation-server/app/translators
zotero(3)(+0000234): HTTP server listening on *:1969

This is the relevant line in config.js:

ref("translation-server.httpServer.port", "8080");

After making this change, I ran ./build.sh and it seemed to complete almost immediately, which was a bit odd.

Any ideas what I might have done wrong? Many thanks :)

[dstillman]

Don't change the config file. The port visible to the rest of your machine is just the first port passed to the -p flag.

[AndrewIsh]

@dstillman Aha, useful to know, thanks. Any idea why that's being ignored then in the example above?

[dstillman]

The debug output will still show 1969, because that's what it's bound to inside the container.

[AndrewIsh]

Ahaaaa Thanks! I'll have a play and see if I can get it up and running.

[AndrewIsh]

Right. After getting it up, everything seems to be working now on latest master. Many thanks @dstillman for your help, very much appreciated :) I'll close this issue.