`this.pending.get()` is undefined

[jerinphilip]

Browser console on running 4-worker translateLocally. console

[Exception... "Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIAppStartup.secondsSinceLastOSRestart]"  nsresult: "0x80004001 (NS_ERROR_NOT_IMPLEMENTED)"  location: "JS frame :: resource:///modules/BrowserGlue.jsm :: _collectStartupConditionsTelemetry :: line 1574"  data: no] [BrowserGlue.jsm:1574:9](resource:///modules/BrowserGlue.jsm)
[Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIPrefBranch.getStringPref]"  nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"  location: "JS frame :: resource://activity-stream/lib/ASRouter.jsm :: _remoteSettingsLoader :: line 289"  data: no] [ASRouter.jsm:289:28](resource://activity-stream/lib/ASRouter.jsm)
NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIPrefBranch.getCharPref] [PersonalityProvider.jsm:68](resource://activity-stream/lib/PersonalityProvider/PersonalityProvider.jsm)
Key event not available on some keyboard layouts: key=“r” modifiers=“accel,alt” id=“key_toggleReaderMode” [browser.xhtml](chrome://browser/content/browser.xhtml)
Key event not available on some keyboard layouts: key=“i” modifiers=“accel,alt,shift” id=“key_browserToolbox” [browser.xhtml](chrome://browser/content/browser.xhtml)
this.pending.get(...) is undefined [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”). 2 chrome:511:24
Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”). chrome:62:22
Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”). 2 chrome:511:24
Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”). chrome:62:22
this.pending.get(...) is undefined [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 2 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
1656968312559   Toolkit.Telemetry   WARN    TelemetryStorage::_scanArchive - have seen this id before: 62953a07-be9f-4ca7-833f-0edf2227916c, overwrite: false
undefined has no properties 9 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
this.pending.get(...) is undefined [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
this.pending.get(...) is undefined 7 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 12 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 3 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
this.pending.get(...) is undefined [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 14 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
this.pending.get(...) is undefined 3 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 3 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 12 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
this.pending.get(...) is undefined 3 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 3 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
undefined has no properties 22 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
this.pending.get(...) is undefined 4 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
debuggee 'resource://devtools/shared/loader/base-loader.js:291' would run 7 [builtin-modules.js:209:11](resource://devtools/shared/loader/builtin-modules.js)

[jelmervdl]

Are you able to reproduce this consistently? I haven't been able to reproduce it yet.

[jerinphilip]

The failures are not consistent. It has however showed up in multiple runs so far. I got through Native Messaging 1 worker once and then the process hung at Run 3 in 4 workers. The other time single worker process hung.

Here's a most recent run.

[jerinphilip]

Not sure if related, this time the errors are:

sendRemoveListener on closed conduit {c9cdf885-0431-4eed-8e18-967b1758c951}.274877907200 [ConduitsChild.jsm:112](resource://gre/modules/ConduitsChild.jsm)
ownerWin.whereToOpenLink is not a function [WebNavigation.jsm:275](resource://gre/modules/WebNavigation.jsm)
    onContentClick resource://gre/modules/WebNavigation.jsm:275
    notifyClickListeners resource:///actors/ClickHandlerParent.jsm:135
    receiveMessage resource:///actors/ClickHandlerParent.jsm:59
undefined has no properties 2 [TLTranslationHelper.js:36](moz-extension://47ef68c1-99de-4b9f-8dbb-2bc072f802ad/controller/translation/TLTranslationHelper.js)
JSON.parse: unexpected character at line 1 column 1 of the JSON data 2 [subprocess_common.jsm:497](resource://gre/modules/subprocess/subprocess_common.jsm)
    readJSON resource://gre/modules/subprocess/subprocess_common.jsm:497
File closed [NativeMessaging.jsm:213](resource://gre/modules/NativeMessaging.jsm)
    writePromise resource://gre/modules/NativeMessaging.jsm:213

[jelmervdl]

Interesting! The JSON parse failure might be a hint that translateLocally is producing broken output. I assume you're running a self-compiled version of the main branch?

Could you test this out by altering the path in the manifest file ~/.mozilla/native-messaging-hosts/translatelocally.json to refer to a little wrapper script, and let the wrapper script be something like:

#!/bin/bash
set -euo pipefail
NAME=natmsg-$(date +'%Y%m%d%H%M%S')
tee >(pigz -9c > $NAME.input.gz) | ./translateLocally "$@" | tee >(pigz -9c > $NAME.output.gz)

And then restart firefox (although reloading the benchmark page might be sufficient, you can see if it starts producing the natmsg files) and upload the natmsg files generated when this error starts occurring?

For clarification, this is how I changed my setup to log input & output:

That should allow me to replay your input with pigz -cd natmsg-*.input.gz | ./translateLocally -p

[jerinphilip]

{
    "error": "Unrecognised message command: Version AvailableCommands: Translate DownloadModel ListModels",
    "id": 1,
    "success": false
}

I'm installing via yay from git directly, just to be sure:

==> Sources are ready.
 -> translatelocally-git-r455.3727f33-1 already made -- skipping build
 -> Found git repo: github.com/XapaJIaMnu/translateLocally.git

r455.3727f33 looks like latest commit?

[jerinphilip]

Update: I have the input working. Output is truncated and unreadable by zcat. Firefox is hung.

natmsg-20220705153002.input.gz

[jelmervdl]

I can't reproduce it on my end yet. Your input seems valid, and the output I get when I run it through translateLocally is equally okay.

What I did:

pigz -cd natmsg-20220705153002.input.gz | ./translateLocally -p | pigz -c > output.gz
./validate_natmsg.py natmsg-20220705153002.input.gz output.gz

Which should tell you:

Sent 150 messages Left 0 messages without response

With validate_natmsg.py being:

#!/usr/bin/env python3
import sys
import json
import struct
import gzip

def readnativemessage(fh):
    while True:
        raw_length = fh.read(4)
        if len(raw_length) == 0:
            break

        length = struct.unpack("@I", raw_length)[0]

        raw_message = fh.read(length)
        assert len(raw_message) == length

        yield json.loads(raw_message)

request_ids = set()

with gzip.open(sys.argv[1]) as fh:
    for message in readnativemessage(fh):
        assert 'id' in message
        assert message['id'] not in request_ids
        request_ids.add(message['id'])

print(f"Sent {len(request_ids)} messages")

with gzip.open(sys.argv[2]) as fh:
    for message in readnativemessage(fh):
        assert 'id' in message
        assert message['id'] in request_ids
        request_ids.remove(message['id'])

print(f"Left {len(request_ids)} messages without response")

Yep, compiled with same commit on macOS. I'll try it on my Ubuntu installation as well, maybe its linux specific?

[jelmervdl]

I'm able to reproduce this on Linux now with the input file linked above.

[jelmervdl]

Okay whaaat is going on?

Screenshot of output + code that generates it. There is a static size_t serial that shows that both error messages are printed from the same call. Is writing to std::cout somehow duplicating the output? Is it messing up some internal buffer? Is the write incomplete or retrying? Why is the output different over separate runs (and it also differs when I change the number of lines of head -n…)

This all feels too much like magical low level C for me at the moment.

[jerinphilip]

1 worker and 4 worker appear to be good now.

[jerin@thinkpad ~]$ ps ax | grep translatelocally
 183843 ?        Sl     0:31 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183859 ?        Sl     0:32 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183871 ?        Sl     0:33 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183883 ?        Sl     0:32 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183895 ?        Sl     0:35 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183915 ?        Sl     0:36 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183930 ?        Sl     0:39 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183952 ?        Sl     0:39 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183967 ?        Sl     0:35 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 183983 ?        Sl     0:36 /usr/bin/translateLocally /home/jerin/.mozilla/native-messaging-hosts/translatelocally.json {c9cdf885-0431-4eed-8e18-967b1758c951}
 184010 pts/3    S+     0:00 grep translatelocally

[jerinphilip]

Closing, will reopen if this shows up.