Camera view poor performance: fake framegrabber image appears as scattered lines instead of a single one

[nunoguedelha]

When visualization the fake framegrabber generated image, we see a swiping set of scattered lines instead of a single one.

[nunoguedelha]

At some point we suspected that the line scattering observed in the fake-framegrabber rendering was due to the simultaneous display of multiple frames, and thus related to the Historical requests (refer to this documentation section). This seems now to be a wrong lead, as we can see in the screenshot below that even a single frame includes multiple lines instead of a singe one for the fake framegrabber.

Originally posted by @nunoguedelha in #71 (comment)

[nunoguedelha]

Logging the received image data on a yarp port

We publish the image data received through the plugin RealtimeTelemetryPlugin on a Yarp port /yarpjs/cameraEcho:o of type bottle.

For this we added the support of socket.io and yarp.js features in the visualizer plugin installation page:

yarp-openmct/openmctStaticServer/index.html

Lines 12 to 13 in 3d6105d

	<script src="/socket.io-client/socket.io.js"></script>
	<script src="/yarp.js"></script>

yarp-openmct/openmctStaticServer/index.html

Lines 28 to 33 in 3d6105d

	let socket = io();
	let echoPort = [];
	yarp.onInit(function() {
	echoPort = yarp.PortHandler.openPort('/yarpjs/cameraEcho:o', 'bottle');
	});
	yarp.init(socket);

yarp-openmct/openmctStaticServer/index.html

Line 143 in 3d6105d

openmct.install(RealtimeTelemetryPlugin(telemServerHost,telemServerPort,echoPort));

yarp-openmct/openmctStaticServer/realtime-telemetry-plugin.js

Lines 5 to 16 in 3d6105d

	function RealtimeTelemetryPlugin(telemServerHost,telemServerPort,echoPort) {
	return function (openmct) {
	var socket = new WebSocket('ws://' + telemServerHost + ':' + telemServerPort + '/realtime/');
	var listener = {};
	socket.onmessage = function (event) {
	point = JSON.parse(event.data);
	echoPort.write(JSON.stringify(point.value));
	if (listener[point.id]) {
	listener[point.id](point);
	}
	};

We then use the stream video plugin example of yarp.js repository to display the streamed images. We can see in the stream the same scattered lines instead of a single one, as we see in the Open-MCT based visualizer.

We can conclude that the line scattered lines issue occurs in the data transmission between the telemetry server and the Open-MCT based visualizer client.

Sending a fixed frame

If we break the telemetry server we get a constant sample and thus a fixed frame on the visualizer, similar to the output illustrated on #71 (comment), i.e with scattered lines.

This confirms the observation from the previous experiment. We then implement some changes in order to have the server send the raw image data buffer, and the client to apply the conversion to the URI format and base 64 (yarp.getImageSrc(...)):

yarp-openmct/openmctStaticServer/realtime-telemetry-plugin.js

Lines 10 to 21 in 34cae51

	socket.onmessage = function (event) {
	let data = JSON.parse(event.data);
	let point = {
	timestamp: data.timestamp,
	value: yarp.getImageSrc(data.value.compressionType,data.value.buffer.data),
	id: data.id
	};
	// echoPort.write(point.value);
	if (listener[point.id]) {
	listener[point.id](point);
	}
	};

This way it's easier to compare the data sent and received.

I'm suspecting an issue with the way the data transmission is scheduled, which could cause a race condition leading to concurrent data access in the case of big chunks of data, typically image data.

Originally posted by @nunoguedelha in #71 (comment)

[nunoguedelha]

This way it's easier to compare the data sent and received.

• We log the data received on port /yarpjs/camLeftEye:i into a yarpview port
• After running the telemetry server and client visualizer, we disconnect the framegrabber ouput:

  yarp disconnect /icubSim/camLeftEye /yarpjs/camLeftEye:i
  

This way, we get a fixed frame on the visualizer, and also on the yarpview display as well:

We can see that the outputs are well aligned. We then break the telemetry server and the client visualizer in order to get in the debugger the sent and received buffers.

• point.value.buffer in the subscribers notification sender notifySubscribers.
  

  yarp-openmct/openmctStaticServer/realtime-telemetry-plugin.js

  Lines 5 to 11 in 3d6105d

  	function RealtimeTelemetryPlugin(telemServerHost,telemServerPort,echoPort) {
  	return function (openmct) {
  	var socket = new WebSocket('ws://' + telemServerHost + ':' + telemServerPort + '/realtime/');
  	var listener = {};
  	socket.onmessage = function (event) {
  	point = JSON.parse(event.data);

• data.value.buffer in the RealtimeTelemetryPlugin plugin.
  

  yarp-openmct/iCubTelemVizServer/realtime-server.js

  Lines 20 to 24 in 34cae51

  	function notifySubscribers(point) {
  	if (subscribed[point.id] && ws.readyState === ws.OPEN) {
  	ws.send(JSON.stringify(point));
  	}
  	}

The buffers are identical.

The problem is not in the transmission of the data between the server and client, but rather in the implementation of the yarp image type port reading.

---

From the yarp.js repository examples, we know that the implementation of image type port reading through websockets works pretty well. For that reason we'll try reading the port directly via yarp socket in the visualizer client (no history shall be supported).

---

Originally posted by @nunoguedelha in #71 (comment)

[nunoguedelha]

A debug version of the fix is implemented in https://github.com/ami-iit/yarp-openmct/tree/e5e0f28fbe8708954ac8240bfc43819b2955ff02.

---

This change broke the shutdown sequence. Fixing...

---

The proper closure of the iCubTelemVizServer server was blocked by the openmctStaticServer server hanging at closure itself.

Received SIGINT ...
{
  status: 'WRPLY',
  message: 'Process (PID 36504) OpenMCT Server stopping (signal SIGINT) ...'
}
iCub Telemetry Server closing: no further connection requests accepted.
Control Console Server closing: no further connection requests accepted.
[OPEN-MCT STATIC SERVER] stdout: Received SIGINT ...
Open-MCT Visualizer Server closing: no further incoming requests accepted. Refreshing the visualizer web page will fail.
Open-MCT Visualizer Server closed: all sockets closed.

The closure process resumes normally after we kill the nodejs process running the openmctStaticServer server.

iCub Telemetry Server closing: no further "subscribe"/"unsubscribe" requests accepted.
[INFO] |yarp.os.impl.PortCoreInputUnit| Removing input from /icubSim/inertial to /yarpjs/inertial:i
[INFO] |yarp.os.impl.PortCoreInputUnit| Removing input from /icubSim/left_leg/stateExt:o to /yarpjs/left_leg/stateExt:o
[INFO] |yarp.os.impl.PortCoreInputUnit| Removing input from /icubSim/camLeftEye to /yarpjs/camLeftEye:i
[INFO] |yarp.os.impl.PortCoreInputUnit| Removing input from /walking-coordinator/logger/data:o to /yarpjs/walking-coordinator-logger/data:i
iCub Telemetry Server closing: disconnected network ports.
Data transmission ended.
Closing all Telemetry Server and Control Console sockets!
[
  'iCub Telemetry Server closed: all sockets closed.',
  'Control Console Server closed: all sockets closed.'
]
Waiting for the debugger to disconnect...

Process finished with exit code 0

Originally posted by @nunoguedelha in #71 (comment)

[nunoguedelha]

Checks...

The previous analysis was verified by checking:

• there was no socket left open by the openmct server child task,
• the child process closure triggered in
  

  yarp-openmct/iCubTelemVizServer/terminationHandler.js

  Lines 40 to 43 in e5e0f28

  	const closeChildProcessPromise = new Promise(function (resolve, reject) {
  	let ret = this.openMctServerHandler.stop(signal, resolve, reject);
  	console.log(ret);
  	}.bind(this));

  
  is never resolved as the child process keeps running, and for that reason, the "then" block is never executed
  

  yarp-openmct/iCubTelemVizServer/terminationHandler.js

  Line 23 in e5e0f28

  this.runSubsetB.bind(this)).then(

Quick Fix

A quick fix ( cd07da9 ) consists in adding a process.exit() as a final SIGINT callback , as done for the iCubTelemVizServer task

yarp-openmct/iCubTelemVizServer/terminationHandler.js

Lines 123 to 124 in e5e0f28

	// (WORKAROUND) Add in last position a listener for forcing the process to exit
	process.once(signal,() => {process.exit();});

We shall later implement a proper fix which does a backup of the original termination callbacks and restores them at the end, as done for the iCubTelemVizServer task

yarp-openmct/iCubTelemVizServer/iCubTelemVizServer.js

Lines 197 to 203 in e5e0f28

	// Add our own termination signals listeners.
	// When the signal comes from the terminal, the generated event doesn't have a 'signal' parameter,
	// so it appears undefined in the callback body. We worked around this issue by explicitly setting
	// the 'signal' parameter case by case.
	terminationHandler.backupAndReplaceSignalListeners('SIGQUIT');
	terminationHandler.backupAndReplaceSignalListeners('SIGTERM');
	terminationHandler.backupAndReplaceSignalListeners('SIGINT');

yarp-openmct/iCubTelemVizServer/terminationHandler.js

Lines 25 to 30 in e5e0f28

	Promise.all([subsetCpromise, subsetApromise.closeServers]).then(
	function (values) {
	values.forEach((v) => console.log(v));
	this.restoreSignalListeners(signal);
	}.bind(this)
	).catch(console.error);

We could actually re-use the class TerminationHandler as a base, and derived classes for processing the different closures (iCubTelemVizServer, openmctStaticServer).

Note on the Never Ending Main Processes

openmctStaticServer process keeps running most probably for the same reason as iCubTelemVizServer. We suspect a never expiring timer to be the cause in the node.js internal engine.

  function processTimers(now) {
    debug('process timer lists %d', now);
    nextExpiry = Infinity;

    let list;
    let ranAtLeastOneList = false;
    while (list = timerListQueue.peek()) {
      if (list.expiry > now) {
        nextExpiry = list.expiry;
        return refCount > 0 ? nextExpiry : -nextExpiry;
      }
      if (ranAtLeastOneList)
        runNextTicks();
      else
        ranAtLeastOneList = true;
      listOnTimeout(list, now);
    }
    return 0;
  }