Server not releasing spawned ports

HOOPS Communicator
1

We have just upgraded directly from Communicator 2023U1 to 2024.3, and are now having severe problems with the server not releasing the spawned ports. The server has been running for a couple of years without problems. We have never sent any shutdown commands, so we need to add that, but still I thought the ports should be released if there are no traffic in at least 15 minutes.

2

Hello @ole.martin.helgesen,

As a quick test using our default Web Viewer, I was not able to reproduce the behavior where spawned ports are not disconnected after reaching the alloted timeout period. Using the callbacks timeout and timeoutWarning helped in this regard. I’ve confirmed this with the default 15 minutes as well as setting a shorter interval using setClientTimeout.

Have you noticed if the issue on your end is occuring for specific Stream Cache files? If so, it might be better if you can send us the test file in question via the Communicator Support Portal and we can do a deeper investigation.

Thanks,
Tino

3

Hi, we discovered we didn’t use the timeout-callback, so it was added on friday. But still spawns are hanging, if I query the spawns-endpoint:

“timestamp”: “2024-06-10T07:30:43.560Z”,
“spawns”: [
{
“id”: “c1f993f9-957f-42cc-8d75-95e875bb28b7”,
“state”: “ready”,
“port”: 11003,
“spawnTime”: “2024-06-09T20:01:26.729Z”,
“lastUpdateTime”: “2024-06-10T07:30:42.269Z”
},
{
“id”: “f0221284-d2b1-446c-ada6-e5712101cef5”,
“state”: “ready”,
“port”: 11002,
“spawnTime”: “2024-06-09T20:01:43.280Z”,
“lastUpdateTime”: “2024-06-10T07:30:43.426Z”
},

As you can see, the two first spawns are from the day before.
And note, we have adjusted the code to include port, which should be included as default!!
Without it the report is pointless!

Also I note on the status-query, that the last items never change from 0:
“usedSpawnPorts”: 18,
“availableSpawnPorts”: 14,
“launching”: 0,
“ready”: 18,
“suspect”: 0,
“disconnected”: 0,
“nice-killed”: 0,
“killed”: 0,
“zombie”: 0,
“dead”: 0

So our main question is, do we have to call shutdown in order for the server to detect it? We are now logging all initializations, so we can map it against the spawn-report and kill spawns manually. That is also an important API-endpoint which should be available, but seems to be easy to implement.
It seems we are not able to detect window close/destroy-events properly, so we are investigating this further.
I would like you to verify our server configuration, can I share it privatly?

4

Here is the status-report:
Note: I have never spotted anything else than 0 on the last 6 keys, which I find strange.

{
  "timestamp": "2024-06-10T07:45:49.852Z",
  "status": "ok",
  "config": {
    "spawnServerPort": 11182,
    "publicHostname": "viewer.bim2share.no",
    "ipVersion": "auto",
    "spawnServerAccessControlAllowOriginHeader": "*",
    "fileServerAccessControlAllowOriginHeader": "*",
    "sslCertificateFile": "xxx.crt",
    "sslPrivateKeyFile": "xxx.key",
    "sslCertificateAuthorityPath": "xxx.crt",
    "sslEnableFileServer": true,
    "sslEnableSpawnServer": true,
    "sslEnableScServer": true,
    "sslDisableRevocationTest": false,
    "spawnMaxSpawnCount": 32,
    "spawnWebsocketPortsBegin": 11000,
    "spawnLivelinessReportIntervalTime": 5,
    "spawnInitialUseDuration": 60,
    "csrEnabled": true,
    "ssrEnabled": true,
    "ssrGpuCount": null,
    "ssrUseEgl": false,
    "autoGcIntervalTime": 30,
    "disableConsoleEnterToShutdown": true,
    "communicatorDir": "C:\\Applications\\Hoops2024SP3",
    "streamCacheExeFile": null,
    "modelDirs": [
      "xxx\\HoopsModels"
    ],
    "workspaceDir": "C:\\ProgramData\\HoopsWork",
    "logDir": "C:\\ProgramData\\HoopsLog\\2024",
    "logSpawnFileCategoryMask": 7,
    "logSpawnStdoutCategoryMask": 0,
    "logSpawnUseDeltaTime": false,
    "logFileTimeFormat": "iso",
    "logConsoleTimeFormat": "local",
    "logStdoutAsLevel": "debug",
    "logStderrAsLevel": "debug",
    "logConsoleLevelCutoff": "info",
    "logFileLevelCutoff": "verbose",
    "logRestFilterRegex": {

    },
    "logRestHttpRequestsAsLevel": "verbose",
    "logFileHttpRequestsAsLevel": "debug",
    "fileServerPort": null,
    "fileServerStaticDirs": [
      "./quick_start",
      "./quick_start/converted_models/user/scs_models",
      "./quick_start/converted_models/standard/scs_models",
      "./web_viewer/src",
      "./web_viewer/examples"
    ],
    "fileServerProxyViewerConnections": true,
    "windowsServiceRespawnEnabled": false,
    "windowsServiceRespawnLogSuffix": "_respawner",
    "licenseFile": null,
    "license": "\u003Chidden\u003E",
    "serverDir": "C:\\Applications\\Hoops2024SP3\\server\\node",
    "communicatorAbsDir": "C:\\Applications\\Hoops2024SP3",
    "spawnExeAbsFile": "C:\\Applications\\Hoops2024SP3\\server\\bin\\win64\\ts3d_sc_server.exe",
    "logAbsDir": "C:\\ProgramData\\HoopsLog\\2024",
    "modelAbsDirs": [
      "xxx\\HoopsModels"
    ],
    "workspaceAbsDir": "C:\\ProgramData\\HoopsWork",
    "licenseAbsFile": null,
    "statusUriBase": "xxx:11182/api/spawns/",
    "fileServerStaticAbsDirs": [
      "C:\\Applications\\Hoops2024SP3\\quick_start",
      "C:\\Applications\\Hoops2024SP3\\quick_start\\converted_models\\user\\scs_models",
      "C:\\Applications\\Hoops2024SP3\\quick_start\\converted_models\\standard\\scs_models",
      "C:\\Applications\\Hoops2024SP3\\web_viewer\\src",
      "C:\\Applications\\Hoops2024SP3\\web_viewer\\examples"
    ],
    "sslPrivateKeyAbsFile": "xxx.key",
    "sslCertificateAbsFile": "xxx.crt",
    "sslPrivateKey": "\u003Chidden\u003E",
    "sslCertificate": "\u003Chidden\u003E"
  },
  "memory": {
    "rss": "63.859 MB",
    "heapTotal": "22.523 MB",
    "heapUsed": "15.031 MB",
    "external": "1.741 MB"
  },
  "usedSpawnPorts": 15,
  "availableSpawnPorts": 17,
  "launching": 0,
  "ready": 15,
  "suspect": 0,
  "disconnected": 0,
  "nice-killed": 0,
  "killed": 0,
  "zombie": 0,
  "dead": 0
}
5

From the server log file:
Sometimes it cleans up properly (as before)

0.001:info: settings.restFileserver: 
0.003:info: HTTP Ping client enabled
0.004:info: HttpPingClient::exec: entered
0.035:info: sendHttpPost: url='<viewerur>:11182/api/spawns/ebf88f51-b57b-4b4b-a510-7d3f52e167ab?liveliness=ready'
0.630:info: server has received initial data from the WS connection
5.058:info: sendHttpPost: url='<viewerur>:11182/api/spawns/ebf88f51-b57b-4b4b-a510-7d3f52e167ab?liveliness=ping'
10.073:info: sendHttpPost: url='<viewerur>:11182/api/spawns/ebf88f51-b57b-4b4b-a510-7d3f52e167ab?liveliness=ping'
15.089:info: sendHttpPost: url='<viewerur>:11182/api/spawns/ebf88f51-b57b-4b4b-a510-7d3f52e167ab?liveliness=ping'
17.733:info: server disconnect: disconnected after finish model
17.733:info: server disconnect: disconnect
17.752:info: sendHttpPost: url='<viewerur>:11182/api/spawns/ebf88f51-b57b-4b4b-a510-7d3f52e167ab?liveliness=disconnect'
17.753:info: HttpPingClient::exec: exiting

But some are not exiting! After it has disconnected, ping is not exiting. It even detects “Connection died” 3 times, but still keeps on pinging!?!

5.058:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
10.089:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
15.120:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
18.952:info: server disconnect: disconnected after finish model
18.952:info: server disconnect: disconnect
20.152:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
:
95.575:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
95.577:warn: Failed to send HTTP ping: response='Connection died, tried 5 times before giving up'
100.590:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
105.608:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
:
160.845:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
160.846:warn: Failed to send HTTP ping: response='Connection died, tried 5 times before giving up'
165.847:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
170.862:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
:
246.136:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
246.136:warn: Failed to send HTTP ping: response='Connection died, tried 5 times before giving up'
251.151:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
256.167:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
261.183:info: sendHttpPost: url='<viewerurl>2/api/spawns/aead842d-d1a5-4713-afa4-4e8debab3ecc?liveliness=ping'
6

Hello @ole.martin.helgesen,

Thanks for providing additional details.

Going back to your question:

…we would not expect that an explicit call to disconnect is required after the timeout period has been reached.

In your testing, it would appear that in some cases, the disconnection does occur and in others, it does not. Perhaps the unexpected behavior is model specific whereby the streaming process from the server to the client does not fully complete for some reason. On that matter, we’ve created a support ticket on your behalf. We kindly request that you please share the file where disconnection/timeout does not occur.

Thanks,
Tino