Sporadic transfer of random numbers to the S7

[fu-zhou]

The following issue is being reported by several users of the iobroker S7-Adapter.
ioBroker/ioBroker.s7#13

Over the last two days one of the developers looked into the issue and "suspects" node-snap7.
https://forum.iobroker.net/post/1094196

It is just an idea, but can @mathiask88 you give me some clues how to test if node-snap7 causes the transfer of randomly high or low numbers to the S7?

Actually V1.0.7 is installed.

[mathiask88]

Version 1.0.7 did not change the code of node-snap7. Just the build tools to prebuild the native cpp addon for the current node version. So I would say unlikely but never say never. A test case would be good..

[Bettman66]

This problem has existed since 2018, I didn't have it until I did a test in ioBroker because I didn't believe it.
Look here.

[Bettman66]

I wrote the current seconds into a DInt every second since the beginning of the day and after a while a negative value arrived in the PLC. The polling time was set to 200ms. I excluded the ioBroker adapter because I inserted a log before describing with node-snap7 in which the data was still correct.

adapter.log.info(data.native.dbId + ' - ' + data.native.address + ' - ' + buf.readInt32BE(0)); s7client.DBWrite(data.native.dbId, data.native.address, getByteSize(type, data.native.len), buf, err => next(err));

[mathiask88]

Could you post a minimal example without any other dependencies, that fails for you? Then I can run this locally and see if I can reproduce this behaviour. Otherwise it is hard to help.

[Bettman66]

Ich habe nur mit den Tools von ioBroker gearbeitet, das wird dich aber nicht weiter bringen.
In der PLC transferiere ich das Datendoppelwort DB2.DBD12 in den DB2.DBD16, damit ich im ioBroker reagieren kann.

[fu-zhou]

I tried it like this (without copying the double word in the S7):
Write a random integer number between -99 and 99 every second (poll delay 200 ms) to a real (DB22.DBD92). If the value is <-99 or >99 when reading back from the S7, then output a log entry with the value. A massively negative value has actually been logged:
2023-12-14 23:23:29.313 - info: javascript.0 (915) script.js.zz_Test_WIP.S7_Komm_Test: -7.030908697961254e+36
2023-12-14 23:23:28.457 - info: javascript.0 (915) script.js.zz_Test_WIP.S7_Komm_Test: -7.030908697961254e+36

Now, of course, the whole thing has run again in the ioBroker environment with a Javascript (Blockly). If anyone can give me a tip on how to run and log such a script on a Linux system without iobroker, I would be happy to try it. So: Linux is installed (in my case Ubuntu 22 Server), node-js, npm installed, node-snap7 is installed and configured and writes a double word with a number and this number is read back and logged if the number is outside the limits.

[mathiask88]

I'll do some testing this week. If I can't reproduce I will share the test code so you can try to in your environment.

[fu-zhou]

In my current constellation the random numbers occur like 6 times in 24 hours in average over the last couple of days

[Bettman66]

With this script I wrote random numbers into DB2.DBD12 at a rate of 100ms.
In the PLC I transferred the DB2.DBD12 to the DB2.DBD16 and read it back into the script.
I can't reproduce any error.

var sleep = require('system-sleep');
var snap7 = require('node-snap7');

var s7client = new snap7.S7Client();
s7client.ConnectTo('192.168.12.222', 0, 2, function(err) {
    if(err)
        return console.log(' >> Connection failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    let ende=true;

    do {
      sleep(100); 
      let buf;
      buf = Buffer.alloc(4);
      buf.writeInt32BE(parseInt(Math.floor(Math.random() * 198 - 99), 10), 0, 4);

      s7client.DBWrite(2, 12, 4, buf, function(err, res) {
        if(err)
            return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));

        console.log(buf)
      });

      s7client.DBRead(2, 16, 4, function(err, res) {
        if(err)
            return console.log(' >> DBRead failed. Code #' + err + ' - ' + s7client.ErrorText(err));

        console.log(res);
        if (readInt32BE(res) != readInt32BE(buf)) {
          console.log('falsch');
          ende=false;
        }
      });
    } while (ende);
});

[fu-zhou]

@Bettman66 is that a script you run independent from iobroker? Or do you run it in iobroker in Javascript just not in blockly?

[Bettman66]

I run the script independently of ioBroker.

[fu-zhou]

Ah okay, and what is the conclusion? Does anything in iobroker screw something up, after all?

[Bettman66]

I don't know what to say anymore.
In iobroker, the write buffer immediately before the write command corresponds to the value to be sent.
Without iobroker I can't reproduce the error.
Unfortunately, my knowledge of Nodejs is not sufficient to find the error.

[fu-zhou]

I do some more testing to narrow the behavior down further...

[fu-zhou]

@Bettman66 I took your Javascript from above and put it in iobroker as Javascript but a little modified as I couldn't get it to run (I installed system-sleep). I'm writing a Float in the S7 every 500ms but the comparison of written and read value didn't work in the iobroker environment (error was like "readInt32BE not defined" or so even when I tried to read Float).

var sleep = require('system-sleep');
var snap7 = require('node-snap7');

var s7client = new snap7.S7Client();
s7client.ConnectTo('1.1.1.1', 0, 2, function(err) {
    if(err)
        return console.log(' >> Connection failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    let ende=true;

    do {
      sleep(500); 
      let buf;
      buf = Buffer.alloc(4);
      buf.writeFloatBE(parseInt(Math.floor(Math.random() * 198 - 99), 10), 0, 4);
              
      s7client.DBWrite(23, 620, 4, buf, function(err, res) {
        if(err)
            return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));

        //console.log(buf)
      });

      s7client.DBRead(23, 620, 4, function(err, res) {
        if(err)
            return console.log(' >> DBRead failed. Code #' + err + ' - ' + s7client.ErrorText(err));
      });
    } while (ende);
});

So I'm reading the DB23.DBD620 now in blockly and check if the value is above 99 or below -99 and if so I write into the log file. Sure enough over the last two days I did not get any over- or under run bypassing the S7 Adapter (which the script does, I guess) while other values (written via blockly) do get the sporadic over- or under run. Does that help in any direction?

Another thing I'm wondering about: I don't see where a poll delay/ cycle time is being set in the script while in the S7 Adapter I configured a poll delay of 200ms. Can that have something to do with our problem?

Another interesting effect: Even if I stop the script in iobroker, it keeps running (writing data to DB23.DBD620) and stops only once I stop the Javascript instance. Any clue why that?

[fu-zhou]

I think I found the issue: When I use one/ the same "buf" only to write multiple values to multiple DB.DBDs, the sporadic transfer happens:

var snap7 = require('node-snap7');
let buf;
 
var s7client = new snap7.S7Client();
s7client.ConnectTo('1.1.1.1', 0, 2, function(err) {
    if(err)
        return console.log(' >> Connection failed. Code #' + err + ' - ' + s7client.ErrorText(err));
});
 
function anS7senden() {
    buf = Buffer.alloc(4);
    buf.writeFloatBE(getState('javascript.0.PV.Netzleistung').val);
 
    s7client.DBWrite(22, 336, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
    buf = Buffer.alloc(4);
    buf.writeFloatBE(getState('javascript.0.PV.Batterieleistung').val);
 
    s7client.DBWrite(22, 352, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
    buf = Buffer.alloc(4);
    buf.writeFloatBE(getState('javascript.0.Ansteuerung_Thyro.AW128_LIMIT').val);
 
    s7client.DBWrite(22, 340, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
    buf = Buffer.alloc(4);
    buf.writeFloatBE(getState('javascript.0.Ansteuerung_Thyro.AW128_LADE_SOLL').val);
 
    s7client.DBWrite(22, 348, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
}
 
setInterval(anS7senden, 200);

As soon as I use one buf per value to be written (buf1 - buf5), the transfer works perfectly without any sporadic random value:

var snap7 = require('node-snap7');
let buf1;
let buf2;
let buf3;
let buf4;
let buf5;
 
var s7client = new snap7.S7Client();
s7client.ConnectTo('1.1.1.1', 0, 2, function(err) {
    if(err)
        return console.log(' >> Connection failed. Code #' + err + ' - ' + s7client.ErrorText(err));
});
 
function anS7senden() {
    buf1 = Buffer.alloc(4);
    buf1.writeFloatBE(getState('javascript.0.PV.Netzleistung').val);
 
    s7client.DBWrite(22, 336, 4, buf1, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
    buf2 = Buffer.alloc(4);
    buf2.writeFloatBE(getState('javascript.0.PV.Batterieleistung').val);
 
    s7client.DBWrite(22, 352, 4, buf2, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
    buf3 = Buffer.alloc(4);
    buf3.writeFloatBE(getState('javascript.0.Ansteuerung_Thyro.AW128_LIMIT').val);
 
    s7client.DBWrite(22, 340, 4, buf3, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
    buf4 = Buffer.alloc(4);
    buf4.writeFloatBE(getState('javascript.0.Ansteuerung_Thyro.AW128_LADE_SOLL').val);
 
    s7client.DBWrite(22, 348, 4, buf4, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
 
    buf5 = Buffer.alloc(4);
    buf5.writeFloatBE(getState('javascript.0.S7_Komm_Test.Reserve').val);
 
    s7client.DBWrite(22, 92, 4, buf5, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
}
 
setInterval(anS7senden, 200);

The question for me now is: Is that behavior to be expected and is there a way to go with one "buf" only by making sure that only correct values will be stored in buf and transferred to the S7? How is the API supposed to be used?

[fu-zhou]

Clearing the buffer each cycle, not overwriting it seems to do the trick - maybe worthwhile to mention in the API? Anyways: node-snap7 does what it is expected to do. Sorry for the hassle and thanks for the great work!

[mathiask88]

@fu-zhou This is expected behaviour.. The issue with your code is that you treat the async functions as synchronous.. So what happens is as you call DBWrite with the reference to ´buf´, node puts the call in the event loop but the actual Write to the PLC is on the next tick while the other allocations happen in the same tick, where ´buf´ refers already to the fourth different object at the end. Remeber javascript is pass by reference for objects. so the first three buffers are not referenced anymore and can be garbage collected or overwritten. Snap7 still has the reference to these "dead" objects that can now be random memory blocks and writes these to the PLC...

Result

1 - Node - alloc 00000000
2 - Node - writeFloatBE 3f800000
3 - Node - DBWrite 3f800000
Snap7 - WriteArea (3f800000)
4 - Node - alloc 00000000
5 - Node - writeFloatBE 40000000
6 - Node - DBWrite 40000000
7 - Node - alloc 00000000
8 - Node - writeFloatBE 40400000
9 - Node - DBWrite 40400000
10 - Node - alloc 00000000
11 - Node - writeFloatBE 40800000
12 - Node - DBWrite 40800000
Snap7 - WriteArea (40000000)
Snap7 - WriteArea (6db82206)
Snap7 - WriteArea (40800000)

Your modified test code

var snap7 = require('node-snap7');
let buf;
 
var s7client = new snap7.S7Client();
s7client.ConnectTo('172.27.160.1', 0, 1, function(err) {
    if(err)
        return console.log(' >> Connection failed. Code #' + err + ' - ' + s7client.ErrorText(err));

    setInterval(anS7senden, 100);
});
 
function anS7senden() {
    buf = Buffer.alloc(4);
    console.log(`1 - Node - alloc ${buf.toString('hex')}`);
    buf.writeFloatBE(1);
    console.log(`2 - Node - writeFloatBE ${buf.toString('hex')}`);
 
    s7client.DBWrite(1, 0, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
    console.log(`3 - Node - DBWrite ${buf.toString('hex')}`);
 
    buf = Buffer.alloc(4);
    console.log(`4 - Node - alloc ${buf.toString('hex')}`);
    buf.writeFloatBE(2);
    console.log(`5 - Node - writeFloatBE ${buf.toString('hex')}`);
 
    s7client.DBWrite(1, 16, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
    console.log(`6 - Node - DBWrite ${buf.toString('hex')}`);
 
    buf = Buffer.alloc(4);
    console.log(`7 - Node - alloc ${buf.toString('hex')}`);
    buf.writeFloatBE(3);
    console.log(`8 - Node - writeFloatBE ${buf.toString('hex')}`);
 
    s7client.DBWrite(1, 32, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
    console.log(`9 - Node - DBWrite ${buf.toString('hex')}`);
 
    buf = Buffer.alloc(4);
    console.log(`10 - Node - alloc ${buf.toString('hex')}`);
    buf.writeFloatBE(4);
    console.log(`11 - Node - writeFloatBE ${buf.toString('hex')}`);
 
    s7client.DBWrite(1, 48, 4, buf, function(err, res) {
    if(err)
        return console.log(' >> DBWrite failed. Code #' + err + ' - ' + s7client.ErrorText(err));
    });
    console.log(`12 - Node - DBWrite ${buf.toString('hex')}`);
}

Modified node-snap7 to see the actual write

...
  case WRITEAREA:
      printf("Snap7 - WriteArea (%02x%02x%02x%02x)\n"
      , ((uint8_t*) pData)[0]
      , ((uint8_t*) pData)[1]
      , ((uint8_t*) pData)[2]
      , ((uint8_t*) pData)[3]);

      returnValue = s7client->snap7Client->WriteArea(int1, int2, int3, int4
        , int5, pData);
      break;
...

[fu-zhou]

@mathiask88 thanks for taking the effort to explain the situation. To be honest: I still have no clue what's going on, maybe a little ;-). However I hope @Bettman66 knows what you are referring to, the fix seemed pretty simple...

[jla]

@mathiask88 Maybe a reference to the buffer should be kept in snap7.S7Client.prototype.DBWrite until the callback is called to prevent it from being garbage collected. Or just a note on the docs that this could happen.

I ran into this problem today. I could only replicate it consistently on a very slow connection while sending write requests continuously. If I don't keep a reference to the buffer, sometimes it ends up writing garbage to the PLC.

let buf = Buffer.alloc(4);
buf.writeFloatBE(1234);
s7client.DBWrite(1, 0, 4, buf, function(err) {
    buf;  // Just to prevent been garbaged collected before is sent to the PLC
});

Thank you for this project!