cannot receive websocket messges

[SilverfishVR]

The webSocket.onmessage event never fires so you never get a response from a websocket server.

Tested to be broken on:

• 2024.06.01
• 2024.05.-rc2
• PR937-62bfab9

Tested to be working on:

• 2023.11.1

Test procedure:

• open entity script server log and console.
• Put this on an entity as server script. https://silverfish-freestuff.s3.amazonaws.com/TestStuff/testWS.js

You should get 2 responses on reload, Request served by 7811941c69e658 and Hello World. To send custom message, put this in the console:Entities.callEntityServerMethod("[ENTITY ID]", "sendMSG", ["message"]); You should get an echo back.

[ksuprynowicz]

Thanks for noticing this! Since it's a serious issue, we should probably fix it before announcing the release. I will look into it today.

[ksuprynowicz]

I just tested it with script running client-side, and it works correctly there. One thing I noticed is that wen script ran and then there was no communication for a logn time, it seemed to time out and not reply anymore. I need to test server side next.

[ksuprynowicz]

I just tested it server-side, and I'm getting the message too:

[
    {
        "entityID": "{c38b48fe-2973-4957-bc8c-ec327f4417df}",
        "fileName": "about:Entities 1",
        "lineNumber": 23,
        "message": "Sending WS message:  glob",
        "severity": 1,
        "type": 1
    }
]

[ksuprynowicz]

Is both your server and client running 2024.06.01?

[ksuprynowicz]

On another server I seem to be running into a similar issue as described. It seems that the websocket is immediately closed after script starts:

[
    {
        "entityID": "{51f039ae-c54d-4e51-bfbe-989a7ad6fb41}",
        "fileName": "about:Entities 2",
        "lineNumber": 32,
        "message": "Closing WebSocket",
        "severity": 1,
        "type": 1
    }
]
[
    {
        "entityID": "{51f039ae-c54d-4e51-bfbe-989a7ad6fb41}",
        "fileName": "about:Entities 2",
        "lineNumber": 14,
        "message": "Sending dummy WS message:  ah",
        "severity": 1,
        "type": 1
    }
]
[
    {
        "entityID": "{51f039ae-c54d-4e51-bfbe-989a7ad6fb41}",
        "fileName": "about:Entities 2",
        "lineNumber": 17,
        "message": "Sending WS message:  Hello World",
        "severity": 1,
        "type": 1
    }
]

[ksuprynowicz]

It turns out I was using wrong entity ID on second server. Everything seems to work correctly now.

[SilverfishVR]

I just tested it server-side, and I'm getting the message too:

[
    {
        "entityID": "{c38b48fe-2973-4957-bc8c-ec327f4417df}",
        "fileName": "about:Entities 1",
        "lineNumber": 23,
        "message": "Sending WS message:  glob",
        "severity": 1,
        "type": 1
    }
]

yes, that is sending the message, but there is no reply "WS Message received: glob" right?

[SilverfishVR]

"Closing WebSocket" is indeed from unloading/reloading the script.

• "Is both your server and client running 2024.06.01?" Yes, all tests are with matching server/client versions.

[ksuprynowicz]

Can you share script log when you reload script and almost immediately trigger sendMSG?

[SilverfishVR]

this is what I get on 2023.11.1:

[06/11 22:39:56] [DEBUG] [overte.scriptengine.script] [9972] [entity-script-server] [about:Entities 1] Sending dummy WS message:  ah
[06/11 22:39:56] [DEBUG] [overte.scriptengine.script] [9972] [entity-script-server] [about:Entities 1] WS Message received:  Request served by 7811941c69e658
[06/11 22:39:56] [DEBUG] [overte.scriptengine.script] [9972] [entity-script-server] [about:Entities 1] Sending WS message:  Hello World

[06/11 22:39:56] [DEBUG] [overte.scriptengine.script] [9972] [entity-script-server] [about:Entities 1] WS Message received:  Hello World
[06/11 22:40:08] [DEBUG] [overte.scriptengine.script] [9972] [entity-script-server] [about:Entities 1] Sending WS message:  test message

[06/11 22:40:08] [DEBUG] [overte.scriptengine.script] [9972] [entity-script-server] [about:Entities 1] WS Message received:  test message

On 2024.06.1 I get the same as you did, "Closing WebSocket" "Sending dummy WS message: ah" "Sending WS message: Hello World"

but nothing from the webSocket.onMessage callback function.

I do wonder if it could be related to the extra debugging that is happening now #992 because the ones that have it also never receive WS messages, could be coincidental though.

[ksuprynowicz]

So "Sending WS message: " is not printed either?

[SilverfishVR]

no 2024.06.1 reloading and sending message:

====================== Subscribed to the Entity Script Server's log ======================
[
    {
        "entityID": "{712a160d-3379-4eeb-8df5-3a06df90e65b}",
        "fileName": "about:Entities 1",
        "lineNumber": 32,
        "message": "Closing WebSocket",
        "severity": 1,
        "type": 1
    }
]
[
    {
        "entityID": "{712a160d-3379-4eeb-8df5-3a06df90e65b}",
        "fileName": "about:Entities 1",
        "lineNumber": 14,
        "message": "Sending dummy WS message:  ah",
        "severity": 1,
        "type": 1
    }
]
[
    {
        "entityID": "{712a160d-3379-4eeb-8df5-3a06df90e65b}",
        "fileName": "about:Entities 1",
        "lineNumber": 17,
        "message": "Sending WS message:  Hello World",
        "severity": 1,
        "type": 1
    }
]
[
    {
        "entityID": "{712a160d-3379-4eeb-8df5-3a06df90e65b}",
        "fileName": "about:Entities 1",
        "lineNumber": 23,
        "message": "Sending WS message:  test message",
        "severity": 1,
        "type": 1
    }
]

[ksuprynowicz]

Is the server running on Windows or Linux?

[ksuprynowicz]

I got workaround for it, but it will currently impossible to figure out entity ID for this message:

[
    {
        "entityID": "{f9668220-9f6d-4457-9df0-ac46bb537b79}",
        "fileName": "about:Entities 1",
        "lineNumber": 23,
        "message": "Sending WS message:  glob",
        "severity": 1,
        "type": 1
    }
]
[
    {
        "entityID": "{00000000-0000-0000-0000-000000000000}",
        "fileName": "about:Entities 1",
        "lineNumber": 28,
        "message": "WS Message received:  glob",
        "severity": 1,
        "type": 1
    }
]

[ksuprynowicz]

Getting proper entity ID would probably mean massive rework of script engine sadly