Maxcul ist komplett unbrauchbar (geloest mit 0.5.2)

skraw.iobroker

Und schon ists passiert:

! maxcul.0 2018-03-03 00:00:03.037 debug serial port buffer have been drained maxcul.0 2018-03-03 00:00:03.037 debug serial port buffer have been drained maxcul.0 2018-03-03 00:00:03.036 debug serial port buffer have been drained maxcul.0 2018-03-03 00:00:03.001 debug Send Packet to CUL: 0b0100401234561b7c2e0026, awaiting drain event maxcul.0 2018-03-03 00:00:03.000 debug Send Packet to CUL: 0b0100401234561b7bbd0026, awaiting drain event maxcul.0 2018-03-03 00:00:03.000 debug serial port buffer have been drained maxcul.0 2018-03-03 00:00:03.000 debug Send Packet to CUL: 0b0100401234561b7e310022, awaiting drain event maxcul.0 2018-03-03 00:00:02.999 debug Send Packet to CUL: 0b0100401234561b7d410022, awaiting drain event maxcul.0 2018-03-03 00:00:02.999 debug got OK-ACK Packet from 16fbae maxcul.0 2018-03-03 00:00:02.999 debug RSSI for Message: -72 maxcul.0 2018-03-03 00:00:02.999 debug decoding Message Z0E01020216FBAE123456000138002204 maxcul.0 2018-03-03 00:00:02.998 debug incoming raw data from CUL: Z0E01020216FBAE123456000138002204 maxcul.0 2018-03-03 00:00:01.877 debug sendTemperature(maxcul.0.OEQ2604915, 19, 0) maxcul.0 2018-03-03 00:00:01.871 debug sendTemperature(maxcul.0.OEQ2604801, 19, 0) maxcul.0 2018-03-03 00:00:01.868 debug sendTemperature(maxcul.0.OEQ2605429, 17, 0) maxcul.0 2018-03-03 00:00:01.865 debug serial port buffer have been drained maxcul.0 2018-03-03 00:00:01.853 debug Send Packet to CUL: 0b01004012345616fbae0022, awaiting drain event maxcul.0 2018-03-03 00:00:01.851 debug sendTemperature(maxcul.0.OEQ2605190, 17, 0) maxcul.0 2018-03-03 00:00:01.851 debug sendTemperature(maxcul.0.NKF0003377, 17, 0) maxcul.0 2018-03-03 00:00:00.876 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.desiredTemperature {"val":19,"ack":false,"ts":1520031600873,"q":0,"from":"system.adapter.javascript.0","lc":1520031600873} maxcul.0 2018-03-03 00:00:00.868 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.desiredTemperature {"val":19,"ack":false,"ts":1520031600864,"q":0,"from":"system.adapter.javascript.0","lc":1520031600864} maxcul.0 2018-03-03 00:00:00.865 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605429.desiredTemperature {"val":17,"ack":false,"ts":1520031600864,"q":0,"from":"system.adapter.javascript.0","lc":1520028000856} maxcul.0 2018-03-03 00:00:00.845 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605190.desiredTemperature {"val":17,"ack":false,"ts":1520031600831,"q":0,"from":"system.adapter.javascript.0","lc":1520031600831} maxcul.0 2018-03-03 00:00:00.844 debug redis pmessage io.maxcul.0.* io.maxcul.0.NKF0003377.desiredTemperature {"val":17,"ack":false,"ts":1520031600820,"q":0,"from":"system.adapter.javascript.0","lc":1520028000802} javascript.0 2018-03-03 00:00:00.830 info script.js.Skript-Heizung-Esszimmer: setForeignState(id=maxcul.0.OEQ2605190.desiredTemperature, state=17) javascript.0 2018-03-03 00:00:00.827 info script.js.Skript-Heizung-Wohnzimmer: setForeignState(id=maxcul.0.NKF0003377.desiredTemperature, state=17) maxcul.0 2018-03-02 23:59:58.914 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031598899,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:59:53.899 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031593896,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:59:48.897 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031588894,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:59:43.898 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031583894,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:59:38.881 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031578877,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:59:33.877 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031573873,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:48.844 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031528835,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:43.840 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031523831,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:38.831 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031518829,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:33.831 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031513827,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:28.829 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031508825,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:23.829 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031503823,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:18.827 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031498821,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:13.811 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031493804,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:08.809 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031488802,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:03.808 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031483799,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:58:01.280 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.rssi {"val":-66.5,"ack":true,"ts":1520031481275,"q":0,"from":"system.adapter.maxcul.0","lc":1520031481275} maxcul.0 2018-03-02 23:58:01.274 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.batteryLow {"val":false,"ack":true,"ts":1520031481267,"q":0,"from":"system.adapter.maxcul.0","lc":1519979406969} maxcul.0 2018-03-02 23:58:01.269 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.rfError {"val":false,"ack":true,"ts":1520031481260,"q":0,"from":"system.adapter.maxcul.0","lc":1519979406964} maxcul.0 2018-03-02 23:58:01.263 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.measuredTemperature {"val":20.1,"ack":true,"ts":1520031481253,"q":0,"from":"system.adapter.maxcul.0","lc":1520031481253} maxcul.0 2018-03-02 23:58:01.256 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.valvePosition {"val":22,"ack":true,"ts":1520031481247,"q":0,"from":"system.adapter.maxcul.0","lc":1520031481247} maxcul.0 2018-03-02 23:58:01.248 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.desiredTemperature {"val":20,"ack":true,"ts":1520031481241,"q":0,"from":"system.adapter.maxcul.0","lc":1520030166413} maxcul.0 2018-03-02 23:58:01.240 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604915.mode {"val":null,"ack":true,"ts":1520031481232,"q":0,"from":"system.adapter.maxcul.0","lc":1520031481232} maxcul.0 2018-03-02 23:58:01.236 debug ThermostatStateReceived: {"src":"1b7c2e","desiredTemperature":20,"valvePosition":22,"measuredTemperature":20.1,"dstSetting":1,"lanGateway":1,"panel":1,"rfError":0,"batteryLow":0,"untilString":"","rssi maxcul.0 2018-03-02 23:58:01.235 debug got data from heatingelement 1b7c2e with payload 39162800C9 maxcul.0 2018-03-02 23:58:01.235 debug RSSI for Message: -66.5 maxcul.0 2018-03-02 23:58:01.234 debug decoding Message Z0F0004601B7C2E0000000039162800C90F maxcul.0 2018-03-02 23:58:01.234 debug incoming raw data from CUL: Z0F0004601B7C2E0000000039162800C90F maxcul.0 2018-03-02 23:57:58.804 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031478797,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:57:53.799 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031473796,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:57:48.795 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031468792,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:57:43.793 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031463790,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:57:38.795 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031458787,"q":0,"from":"system.adapter.maxcul.0","lc":1520031458787} maxcul.0 2018-03-02 23:57:33.792 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":895,"ack":true,"ts":1520031453785,"q":0,"from":"system.adapter.maxcul.0","lc":1520031453785} maxcul.0 2018-03-02 23:57:30.114 debug redis pmessage io.maxcul.0.* io.maxcul.0.MEQ1480497.rssi {"val":-75.5,"ack":true,"ts":1520031450110,"q":0,"from":"system.adapter.maxcul.0","lc":1520031450110} maxcul.0 2018-03-02 23:57:30.106 debug redis pmessage io.maxcul.0.* io.maxcul.0.MEQ1480497.batteryLow {"val":false,"ack":true,"ts":1520031450104,"q":0,"from":"system.adapter.maxcul.0","lc":1518824069530} maxcul.0 2018-03-02 23:57:30.103 debug redis pmessage io.maxcul.0.* io.maxcul.0.MEQ1480497.rfError {"val":false,"ack":true,"ts":1520031450100,"q":0,"from":"system.adapter.maxcul.0","lc":1519997246688} maxcul.0 2018-03-02 23:57:30.099 debug redis pmessage io.maxcul.0.* io.maxcul.0.MEQ1480497.isOpen {"val":false,"ack":true,"ts":1520031450095,"q":0,"from":"system.adapter.maxcul.0","lc":1520002444590} maxcul.0 2018-03-02 23:57:30.098 debug ShutterContactStateReceived: {"src":"133721","isOpen":0,"rfError":0,"batteryLow":0,"rssi":-75.5} maxcul.0 2018-03-02 23:57:30.098 debug got data from shutter contact 133721 10000 maxcul.0 2018-03-02 23:57:30.097 debug RSSI for Message: -75.5 maxcul.0 2018-03-02 23:57:30.097 debug decoding Message Z0B5106301337211234560010FD maxcul.0 2018-03-02 23:57:30.097 debug incoming raw data from CUL: Z0B5106301337211234560010FD maxcul.0 2018-03-02 23:57:30.097 debug ignored auto-ack packet maxcul.0 2018-03-02 23:57:30.097 debug RSSI for Message: -74 maxcul.0 2018-03-02 23:57:30.097 debug decoding Message Z0B510002123456133721000000 maxcul.0 2018-03-02 23:57:30.096 debug incoming raw data from CUL: Z0B510002123456133721000000 maxcul.0 2018-03-02 23:57:28.786 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031448783,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:57:23.780 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031443778,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:57:18.783 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031438776,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:57:13.779 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031433773,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:57:08.778 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031428770,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:57:03.761 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031423753,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:56:58.757 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031418750,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:56:53.753 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031413748,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} maxcul.0 2018-03-02 23:56:48.753 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":900,"ack":true,"ts":1520031408747,"q":0,"from":"system.adapter.maxcul.0","lc":1520031208598} !
So schauts aus, hilft uns das was?

Koennte es sein dass man beim Senden eines Paketes auch auf seine "Fertigstellung" (sprich kompletten Versand) warten sollte?

skraw.iobroker

Hier ist das Problem:

Zeile 150 communication-layer.js:

        CommunicationServiceLayer.prototype.serialWrite = function(data) {
            var command;
            if (this._serialDeviceInstance.isOpen()) {
                command = 'Zs' + data + '\n';
                return this._serialDeviceInstance.writeAsync(command).then((function(_this) {
                    return function() {
                        env.logger.debug('Send Packet to CUL: ' + data + ', awaiting drain event');
                        return _this._serialDeviceInstance.drainAsync().then(function() {
                            return env.logger.debug('serial port buffer have been drained');
                        });
                    };
                })(this));
            } else {
                env.logger.debug('Can not send packet because serial port is not open');
                return Promise.reject('Error: serial port is not open');
            }
        };

Diese Funktion braucht ein Locking. Am besten innerhalb des ersten if.

Damit serialisiert man das Handling des Devices und alles wird funktionieren …

Gibts in dieser Umgebung ein Lock/Unlock? Falls nein einfach "von Hand".

Eine statische Variable hochzaehlen und danach ueberpruefen ob sie 1 ist (0 init). Falls nicht 1 Sekunde warten und nochmal pruefen.

Unlock per Variable--.

Oder sowas ginge auch:

https://github.com/kirill-konshin/mutex-promise

apollon77

naja, das macht man in nodejs etwas anders/einfacher :-)

Ich schaue mal wann ich Zeit finde

apollon77

Versuch mal Github version. die sollte jetzt Schreibbefehle queuen und nacheinander senden … schaue mal und sag mal

skraw.iobroker

Da haett ich schonmal was:

maxcul.0 2018-03-04 13:27:08.191 info Packet X could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 13:27:08.175 debug Queued send for X

maxcul.0 2018-03-04 13:27:04.220 debug Za drained

maxcul.0 2018-03-04 13:27:04.216 debug Za written

maxcul.0 2018-03-04 13:27:04.212 debug Zr drained

maxcul.0 2018-03-04 13:27:04.205 debug Zr written

maxcul.0 2018-03-04 13:27:04.199 debug X20 drained

maxcul.0 2018-03-04 13:27:04.194 debug X20 written

maxcul.0 2018-03-04 13:27:04.189 debug enable MAX! Mode of the CUL868

maxcul.0 2018-03-04 13:27:03.189 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":453,"ack":true,"ts":1520166423183,"q":0,"from":"system.adapter.maxcul.0","lc":1520166423183}

maxcul.0 2018-03-04 13:27:03.189 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.limitOverflow {"val":false,"ack":true,"ts":1520166423180,"q":0,"from":"system.adapter.maxcul.0","lc":1520074213155}

maxcul.0 2018-03-04 13:27:03.172 info Packet X could not be sent! TypeError: Cannot read property 'shift' of undefined

maxcul.0 2018-03-04 13:27:03.165 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-04 13:27:00.222 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.connection {"val":true,"ack":true,"ts":1520166420208,"q":0,"from":"system.adapter.maxcul.0","lc":1520166420208}

maxcul.0 2018-03-04 13:27:00.222 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.version {"val":"V 1.67 nanoCUL868","ack":true,"ts":1520166420206,"q":0,"from":"system.adapter.maxcul.0","lc":1519041256179}

maxcul.0 2018-03-04 13:27:00.221 info CUL FW Version: V 1.67 nanoCUL868

maxcul.0 2018-03-04 13:27:00.220 debug incoming raw data from CUL: V 1.67 nanoCUL868

maxcul.0 2018-03-04 13:27:00.185 debug Requested CUL Version…

maxcul.0 2018-03-04 13:27:00.181 debug check CUL Firmware version

Das sollten wir wirklich dringend loesen, denn der derzeit verteilte maxcul 0.3.0 hat auch das Problem mit dem Overrun beim Senden und es gibt bestimmte Situationen wo man das Setup nicht retten kann. Ich bin grade in einer. Der Treiber (in diesem Fall 0.3.0) versucht 5 Geraete gleichzeitig mit irgendwelchen Kommandos zu versorgen und kackt ab sobald er sie schickt.

apollon77

~~@skraw.iobroker:~~

Da haett ich schonmal was: `

Ich schaue mal. Also ist irgendwas im Code nicht korrekt …

~~@skraw.iobroker:~~

Das sollten wir wirklich dringend loesen … `

Ich bin doch schon dran, oder ?! Jetzt mach mal ganz langsam bitte.

ich versuche die Probleme gerade "blind" zu fixen …

Ingo

skraw.iobroker

Ich bin nicht sicher ob der kurze Ausschnitt aus dem Log richtig darstellt dass dieser Code gar nicht sendet, weil alle gequeueten Sends nicht gesendet werden (koennen) … ?!?

apollon77

War auch mein verdacht. ES kommt später nachdem die Kids im Bett sind ein weiterer Versuch. Stay tuned

apollon77

So nächster versuch bitte von Github

skraw.iobroker

Schaut fuer mich nicht so gut aus :

maxcul.0 2018-03-04 21:51:32.915 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:32.910 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-04 21:51:29.148 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.146 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-04 21:51:29.145 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.128 debug Send Packet to CUL: Zs0b0100401234561b7bbd0065, awaiting drain event

maxcul.0 2018-03-04 21:51:29.126 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.110 debug Send Packet to CUL: Zs0b0100401234561b7e310067, awaiting drain event

maxcul.0 2018-03-04 21:51:29.108 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.087 debug Send Packet to CUL: Zs0b0100401234561b7e34006a, awaiting drain event

maxcul.0 2018-03-04 21:51:29.085 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.067 debug Send Packet to CUL: Zs0b0100401234561b7edc0069, awaiting drain event

maxcul.0 2018-03-04 21:51:29.066 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.041 debug Send Packet to CUL: Zs0b0100401234561b7d410071, awaiting drain event

maxcul.0 2018-03-04 21:51:29.039 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.037 debug Send Packet to CUL: Zs0b01004012345616fbae006d, awaiting drain event

maxcul.0 2018-03-04 21:51:29.036 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:29.035 debug Send Packet to CUL: Zs0b01004012345616fb8f0071, awaiting drain event

maxcul.0 2018-03-04 21:51:29.034 info Packet X could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 21:51:29.034 info Packet 0b0100401234561b7bbd0065 could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 21:51:29.033 info Packet 0b0100401234561b7e310067 could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 21:51:29.032 info Packet 0b0100401234561b7e34006a could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 21:51:29.032 info Packet 0b0100401234561b7edc0069 could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 21:51:29.031 info Packet 0b0100401234561b7d410071 could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 21:51:29.030 info Packet 0b01004012345616fbae006d could not be sent! TypeError: Cannot read property 'catch' of undefined

maxcul.0 2018-03-04 21:51:29.029 debug Queued send for X

maxcul.0 2018-03-04 21:51:29.028 debug Queued send for Zs0b0100401234561b7bbd0065

maxcul.0 2018-03-04 21:51:29.028 debug Queued send for Zs0b0100401234561b7e310067

maxcul.0 2018-03-04 21:51:29.027 debug Queued send for Zs0b0100401234561b7e34006a

maxcul.0 2018-03-04 21:51:29.026 debug Queued send for Zs0b0100401234561b7edc0069

maxcul.0 2018-03-04 21:51:29.025 debug Queued send for Zs0b0100401234561b7d410071

maxcul.0 2018-03-04 21:51:29.025 debug Queued send for Zs0b01004012345616fbae006d

maxcul.0 2018-03-04 21:51:29.024 debug got OK-ACK Packet from 16e328

maxcul.0 2018-03-04 21:51:29.023 debug RSSI for Message: -44

maxcul.0 2018-03-04 21:51:29.023 debug decoding Message Z0E01020216E32812345600013964313C

maxcul.0 2018-03-04 21:51:29.022 debug incoming raw data from CUL: Z0E01020216E32812345600013964313C

maxcul.0 2018-03-04 21:51:27.916 debug serial port buffer have been drained

maxcul.0 2018-03-04 21:51:27.915 debug Send Packet to CUL: Zs0b01004012345616e3280071, awaiting drain event

maxcul.0 2018-03-04 21:51:27.915 info Poll device1 : 1, 18.5

maxcul.0 2018-03-04 21:51:27.915 info Poll device1 : 1, 19.5

maxcul.0 2018-03-04 21:51:27.914 info Poll device1 : 1, 21

maxcul.0 2018-03-04 21:51:27.914 info Poll device1 : 1, 20.5

maxcul.0 2018-03-04 21:51:27.913 info Poll device1 : 1, 24.5

maxcul.0 2018-03-04 21:51:27.913 info Poll device1 : 1, 22.5

maxcul.0 2018-03-04 21:51:27.912 info Poll device1 : 1, 24.5

apollon77

Hi,

ich hab ggf ne Lösung. noch nicht 100% perfekt, aber versuche bitte mal Github und schick mir log. Danke

skraw.iobroker

Hier ist das Logfile. Es gibt ein Problem. Man sieht dem Logfile nicht mehr an, dass der nanoCUL effektiv tot ist.

Ich sehe es an der schnell blinkenden LED. Das Ding ist tot seit der schnellen Uebertragung der Kommandos

nach den Send Packet bei "2018-03-05 00:22:04.". Ich empfehle dringend diese Sends so zu gestalten, dass nur ein Send pro 5 Sekunden stattfindet.

maxcul.0 2018-03-05 00:23:58.715 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:53.710 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:53.710 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:48.710 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:48.703 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:43.707 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:43.703 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:38.699 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:38.697 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:33.693 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:33.691 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:28.710 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:28.709 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:23.664 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:23.660 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:18.658 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:18.654 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:13.654 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:13.653 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:08.648 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:08.647 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:23:03.645 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:23:03.644 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:58.643 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:58.642 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:53.638 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:53.637 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:48.646 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:48.628 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:43.631 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:43.630 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:38.630 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:38.629 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:33.628 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:33.626 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:28.621 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:28.620 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:23.617 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:23.616 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:18.608 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:18.608 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:13.602 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:13.602 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:08.596 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:08.595 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:04.748 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:04.746 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:22:04.745 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:04.728 debug Send Packet to CUL: Zs0b0100401234561b7bbd0065, awaiting drain event

maxcul.0 2018-03-05 00:22:04.726 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:04.710 debug Send Packet to CUL: Zs0b0100401234561b7e310063, awaiting drain event

maxcul.0 2018-03-05 00:22:04.708 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:04.690 debug Send Packet to CUL: Zs0b0100401234561b7e34006a, awaiting drain event

maxcul.0 2018-03-05 00:22:04.689 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:04.672 debug Send Packet to CUL: Zs0b0100401234561b7d410063, awaiting drain event

maxcul.0 2018-03-05 00:22:04.670 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:04.656 debug Send Packet to CUL: Zs0b01004012345616fbae0063, awaiting drain event

maxcul.0 2018-03-05 00:22:04.656 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:04.655 debug Send Packet to CUL: Zs0b01004012345616fb8f0071, awaiting drain event

maxcul.0 2018-03-05 00:22:04.655 debug Queued send for X

maxcul.0 2018-03-05 00:22:04.655 debug Queued send for Zs0b0100401234561b7bbd0065

maxcul.0 2018-03-05 00:22:04.655 debug Queued send for Zs0b0100401234561b7e310063

maxcul.0 2018-03-05 00:22:04.654 debug Queued send for Zs0b0100401234561b7e34006a

maxcul.0 2018-03-05 00:22:04.654 debug Queued send for Zs0b0100401234561b7d410063

maxcul.0 2018-03-05 00:22:04.654 debug Queued send for Zs0b01004012345616fbae0063

maxcul.0 2018-03-05 00:22:04.653 debug got OK-ACK Packet from 16e328

maxcul.0 2018-03-05 00:22:04.653 debug RSSI for Message: -45.5

maxcul.0 2018-03-05 00:22:04.647 debug decoding Message Z0E01020216E328123456000139643139

maxcul.0 2018-03-05 00:22:04.647 debug incoming raw data from CUL: Z0E01020216E328123456000139643139

maxcul.0 2018-03-05 00:22:03.555 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:22:03.553 debug Send Packet to CUL: Zs0b01004012345616e3280071, awaiting drain event

maxcul.0 2018-03-05 00:22:03.552 info Poll device1 : 1, 18.5

maxcul.0 2018-03-05 00:22:03.551 info Poll device1 : 1, 17.5

maxcul.0 2018-03-05 00:22:03.550 info Poll device1 : 1, 21

maxcul.0 2018-03-05 00:22:03.550 info Poll device1 : 1, 17.5

maxcul.0 2018-03-05 00:22:03.549 info Poll device1 : 1, 17.5

maxcul.0 2018-03-05 00:22:03.548 info Poll device1 : 1, 24.5

maxcul.0 2018-03-05 00:21:58.611 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":503,"ack":true,"ts":1520205718601,"q":0,"from":"system.adapter.maxcul.0","lc":1520205718601}

maxcul.0 2018-03-05 00:21:58.590 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:58.583 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:53.594 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":498,"ack":true,"ts":1520205713586,"q":0,"from":"system.adapter.maxcul.0","lc":1520205713586}

maxcul.0 2018-03-05 00:21:53.582 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:53.581 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:48.618 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":493,"ack":true,"ts":1520205708601,"q":0,"from":"system.adapter.maxcul.0","lc":1520205708601}

maxcul.0 2018-03-05 00:21:48.584 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:48.582 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:43.584 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":488,"ack":true,"ts":1520205703578,"q":0,"from":"system.adapter.maxcul.0","lc":1520205703578}

maxcul.0 2018-03-05 00:21:43.573 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:43.572 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:38.566 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":483,"ack":true,"ts":1520205698560,"q":0,"from":"system.adapter.maxcul.0","lc":1520205698560}

maxcul.0 2018-03-05 00:21:38.562 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:38.561 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:33.567 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":478,"ack":true,"ts":1520205693561,"q":0,"from":"system.adapter.maxcul.0","lc":1520205693561}

maxcul.0 2018-03-05 00:21:33.554 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:33.553 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:31.714 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605599.rssi {"val":-65.5,"ack":true,"ts":1520205691709,"q":0,"from":"system.adapter.maxcul.0","lc":1520205691709}

maxcul.0 2018-03-05 00:21:31.706 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605599.batteryLow {"val":false,"ack":true,"ts":1520205691703,"q":0,"from":"system.adapter.maxcul.0","lc":1519668132799}

maxcul.0 2018-03-05 00:21:31.700 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605599.rfError {"val":false,"ack":true,"ts":1520205691695,"q":0,"from":"system.adapter.maxcul.0","lc":1519668132793}

maxcul.0 2018-03-05 00:21:31.690 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605599.measuredTemperature {"val":21,"ack":true,"ts":1520205691683,"q":0,"from":"system.adapter.maxcul.0","lc":1520205691683}

maxcul.0 2018-03-05 00:21:31.684 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605599.valvePosition {"val":23,"ack":true,"ts":1520205691672,"q":0,"from":"system.adapter.maxcul.0","lc":1520205691672}

maxcul.0 2018-03-05 00:21:31.667 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605599.desiredTemperature {"val":20,"ack":true,"ts":1520205691658,"q":0,"from":"system.adapter.maxcul.0","lc":1519684773078}

maxcul.0 2018-03-05 00:21:31.655 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2605599.mode {"val":null,"ack":true,"ts":1520205691634,"q":0,"from":"system.adapter.maxcul.0","lc":1520205691634}

maxcul.0 2018-03-05 00:21:31.644 debug ThermostatStateReceived: {"src":"1b7edc","desiredTemperature":20,"valvePosition":23,"measuredTemperature":21,"dstSetting":1,"lanGateway":1,"panel":1,"rfError":0,"batteryLow":0,"untilString":"","rssi":

maxcul.0 2018-03-05 00:21:31.642 debug got data from heatingelement 1b7edc with payload 39172800D2

maxcul.0 2018-03-05 00:21:31.641 debug RSSI for Message: -65.5

maxcul.0 2018-03-05 00:21:31.637 debug decoding Message Z0F0004601B7EDC0000000039172800D211

maxcul.0 2018-03-05 00:21:31.636 debug incoming raw data from CUL: Z0F0004601B7EDC0000000039172800D211

maxcul.0 2018-03-05 00:21:28.563 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":473,"ack":true,"ts":1520205688556,"q":0,"from":"system.adapter.maxcul.0","lc":1520205688556}

maxcul.0 2018-03-05 00:21:28.553 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:28.552 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:23.555 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":468,"ack":true,"ts":1520205683552,"q":0,"from":"system.adapter.maxcul.0","lc":1520205683552}

maxcul.0 2018-03-05 00:21:23.547 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:23.546 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:18.556 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":463,"ack":true,"ts":1520205678550,"q":0,"from":"system.adapter.maxcul.0","lc":1520205678550}

maxcul.0 2018-03-05 00:21:18.546 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:18.542 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:13.552 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":458,"ack":true,"ts":1520205673547,"q":0,"from":"system.adapter.maxcul.0","lc":1520205673547}

maxcul.0 2018-03-05 00:21:13.538 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:13.535 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:09.569 debug Za drained

maxcul.0 2018-03-05 00:21:09.566 debug Za written

maxcul.0 2018-03-05 00:21:09.563 debug Zr drained

maxcul.0 2018-03-05 00:21:09.558 debug Zr written

maxcul.0 2018-03-05 00:21:09.554 debug X20 drained

maxcul.0 2018-03-05 00:21:09.549 debug X20 written

maxcul.0 2018-03-05 00:21:09.545 debug enable MAX! Mode of the CUL868

maxcul.0 2018-03-05 00:21:08.552 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":453,"ack":true,"ts":1520205668543,"q":0,"from":"system.adapter.maxcul.0","lc":1520205668543}

maxcul.0 2018-03-05 00:21:08.552 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.limitOverflow {"val":false,"ack":true,"ts":1520205668539,"q":0,"from":"system.adapter.maxcul.0","lc":1520196435104}

maxcul.0 2018-03-05 00:21:08.538 debug serial port buffer have been drained

maxcul.0 2018-03-05 00:21:08.530 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 00:21:05.585 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.connection {"val":true,"ack":true,"ts":1520205665573,"q":0,"from":"system.adapter.maxcul.0","lc":1520205665573}

maxcul.0 2018-03-05 00:21:05.585 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.version {"val":"V 1.67 nanoCUL868","ack":true,"ts":1520205665568,"q":0,"from":"system.adapter.maxcul.0","lc":1519041256179}

maxcul.0 2018-03-05 00:21:05.579 info CUL FW Version: V 1.67 nanoCUL868

maxcul.0 2018-03-05 00:21:05.579 debug incoming raw data from CUL: V 1.67 nanoCUL868

maxcul.0 2018-03-05 00:21:05.541 debug Requested CUL Version…

maxcul.0 2018-03-05 00:21:05.536 debug check CUL Firmware version

maxcul.0 2018-03-05 00:21:03.543 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.connection {"val":false,"ack":true,"ts":1520205663531,"q":0,"from":"system.adapter.maxcul.0","lc":1520197165821}

maxcul.0 2018-03-05 00:21:03.543 info serialPort /dev/ttyUSB0 is open!

maxcul.0 2018-03-05 00:21:03.516 info using serial device /dev/ttyUSB0@38400

maxcul.0 2018-03-05 00:21:02.954 info starting. Version 0.5.1 in /opt/iobroker/node_modules/iobroker.maxcul, node: v6.12.0

apollon77

~~@skraw.iobroker:~~

Hier ist das Logfile. Es gibt ein Problem. Man sieht dem Logfile nicht mehr an, dass der nanoCUL effektiv tot ist.

Ich sehe es an der schnell blinkenden LED. Das Ding ist tot seit der schnellen Uebertragung der Kommandos

nach den Send Packet bei "2018-03-05 00:22:04.". Ich empfehle dringend diese Sends so zu gestalten, dass nur ein Send pro 5 Sekunden stattfindet. `

5s beisst sich aber mit dem aktuellen "retry nach 3 Sekunden wenn kein Ack angekommen ist" … Mist ... ich würde erstmal 200ms oder so einbauen als Delay und dann tasten wir uns ran.

Oder kommen die 5s von irgendwo her?

skraw.iobroker

Ich wuerde die Sache so versuchen zu schreiben, dass nach dem Send Zeit fuer eine Antwort vom Geraet drin ist. So dass man im Endeffekt endet bei

Send

Receive ACK

Send

Receive ACK

usw

skraw.iobroker

Ich hab die betreffende Routine jetzt so veraendert:

CommunicationServiceLayer.prototype.writeQueue = function() {

if (!this._queuedWrites.length) return Promise.resolve(true);

var command = this._queuedWrites.shift();

this._queueSendInProgress = true;

return this._serialDeviceInstance.writeAsync(command).then(() => {

env.logger.debug('Send Packet to CUL: ' + command.trim() + ', awaiting drain event');

return this._serialDeviceInstance.drainAsync()

}).then(() => {

env.logger.debug('serial port buffer have been drained');

this._queueSendInProgress = false;

Promise.delay(4000).then(() => {

env.logger.debug('delayed 4s');

return this.writeQueue();

});

};

Ich kann diese Sprache nicht wirklich, ich versuch mir nur zu denken was die Codeteile bedeuten koennten…(daher dieses Promise Statement)

Das fuehrt zu folgendem Logfile und keinem Absturz:

maxcul.0 2018-03-05 01:13:22.238 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:13:22.230 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:13:21.219 debug delayed 4s

maxcul.0 2018-03-05 01:13:17.228 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":105,"ack":true,"ts":1520208797225,"q":0,"from":"system.adapter.maxcul.0","lc":1520208797225}

maxcul.0 2018-03-05 01:13:17.219 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:13:17.212 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:13:16.216 debug delayed 4s

maxcul.0 2018-03-05 01:13:12.226 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":100,"ack":true,"ts":1520208792223,"q":0,"from":"system.adapter.maxcul.0","lc":1520208792223}

maxcul.0 2018-03-05 01:13:12.211 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:13:12.209 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:13:11.215 debug delayed 4s

maxcul.0 2018-03-05 01:13:07.224 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":95,"ack":true,"ts":1520208787221,"q":0,"from":"system.adapter.maxcul.0","lc":1520208787221}

maxcul.0 2018-03-05 01:13:07.209 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:13:07.208 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:13:06.213 debug delayed 4s

maxcul.0 2018-03-05 01:13:03.398 debug delayed 4s

maxcul.0 2018-03-05 01:13:02.257 debug delayed 4s

maxcul.0 2018-03-05 01:13:02.225 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":90,"ack":true,"ts":1520208782219,"q":0,"from":"system.adapter.maxcul.0","lc":1520208782219}

maxcul.0 2018-03-05 01:13:02.209 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:13:02.207 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:59.422 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":88,"ack":true,"ts":1520208779397,"q":0,"from":"system.adapter.maxcul.0","lc":1520208779397}

maxcul.0 2018-03-05 01:12:59.398 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:59.390 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:59.385 debug delayed 4s

maxcul.0 2018-03-05 01:12:58.275 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":86,"ack":true,"ts":1520208778270,"q":0,"from":"system.adapter.maxcul.0","lc":1520208778270}

maxcul.0 2018-03-05 01:12:58.257 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:58.253 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:58.251 debug delayed 4s

maxcul.0 2018-03-05 01:12:57.199 debug Queued send for X

maxcul.0 2018-03-05 01:12:55.390 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":84,"ack":true,"ts":1520208775383,"q":0,"from":"system.adapter.maxcul.0","lc":1520208775383}

maxcul.0 2018-03-05 01:12:55.380 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:55.375 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:55.368 debug delayed 4s

maxcul.0 2018-03-05 01:12:54.269 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":82,"ack":true,"ts":1520208774259,"q":0,"from":"system.adapter.maxcul.0","lc":1520208774259}

maxcul.0 2018-03-05 01:12:54.252 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:54.246 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:54.242 debug delayed 4s

maxcul.0 2018-03-05 01:12:52.193 debug Queued send for X

maxcul.0 2018-03-05 01:12:51.373 debug LOVF: credits=503

maxcul.0 2018-03-05 01:12:51.370 debug incoming raw data from CUL: LOVF

maxcul.0 2018-03-05 01:12:51.365 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:51.349 debug Send Packet to CUL: Zs0b0100401234561b7bbd0065, awaiting drain event

maxcul.0 2018-03-05 01:12:51.345 debug delayed 4s

maxcul.0 2018-03-05 01:12:50.243 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.limitOverflow {"val":true,"ack":true,"ts":1520208770234,"q":0,"from":"system.adapter.maxcul.0","lc":1520208770234}

maxcul.0 2018-03-05 01:12:50.243 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:50.242 debug LOVF: credits=503

maxcul.0 2018-03-05 01:12:50.241 debug incoming raw data from CUL: LOVF

maxcul.0 2018-03-05 01:12:50.220 debug Send Packet to CUL: Zs0b0100401234561b7e34006a, awaiting drain event

maxcul.0 2018-03-05 01:12:50.217 debug delayed 4s

maxcul.0 2018-03-05 01:12:48.426 debug got OK-ACK Packet from 1b7d41

maxcul.0 2018-03-05 01:12:48.422 debug RSSI for Message: -45.5

maxcul.0 2018-03-05 01:12:48.418 debug decoding Message Z0E0102021B7D41123456000139642339

maxcul.0 2018-03-05 01:12:48.414 debug incoming raw data from CUL: Z0E0102021B7D41123456000139642339

maxcul.0 2018-03-05 01:12:47.340 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:47.316 debug Send Packet to CUL: Zs0b0100401234561b7d410063, awaiting drain event

maxcul.0 2018-03-05 01:12:47.313 debug delayed 4s

maxcul.0 2018-03-05 01:12:47.299 debug got OK-ACK Packet from 16fbae

maxcul.0 2018-03-05 01:12:47.298 debug RSSI for Message: -72

maxcul.0 2018-03-05 01:12:47.298 debug decoding Message Z0E01020216FBAE123456000139002304

maxcul.0 2018-03-05 01:12:47.297 debug incoming raw data from CUL: Z0E01020216FBAE123456000139002304

maxcul.0 2018-03-05 01:12:47.190 debug Queued send for X

maxcul.0 2018-03-05 01:12:46.215 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:46.202 debug Send Packet to CUL: Zs0b01004012345616fbae0063, awaiting drain event

maxcul.0 2018-03-05 01:12:46.198 debug delayed 4s

maxcul.0 2018-03-05 01:12:44.399 debug got OK-ACK Packet from 16fb8f

maxcul.0 2018-03-05 01:12:44.398 debug RSSI for Message: -46.5

maxcul.0 2018-03-05 01:12:44.393 debug decoding Message Z0E01020216FB8F123456000139643137

maxcul.0 2018-03-05 01:12:44.392 debug incoming raw data from CUL: Z0E01020216FB8F123456000139643137

maxcul.0 2018-03-05 01:12:43.314 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:43.313 debug Send Packet to CUL: Zs0b01004012345616fb8f0071, awaiting drain event

maxcul.0 2018-03-05 01:12:43.312 debug Queued send for X

maxcul.0 2018-03-05 01:12:43.312 debug Queued send for Zs0b0100401234561b7bbd0065

maxcul.0 2018-03-05 01:12:43.311 debug Queued send for Zs0b0100401234561b7e34006a

maxcul.0 2018-03-05 01:12:43.310 debug Queued send for Zs0b0100401234561b7d410063

maxcul.0 2018-03-05 01:12:43.309 debug Queued send for Zs0b01004012345616fbae0063

maxcul.0 2018-03-05 01:12:43.309 debug got OK-ACK Packet from 16e328

maxcul.0 2018-03-05 01:12:43.308 debug RSSI for Message: -44

maxcul.0 2018-03-05 01:12:43.307 debug decoding Message Z0E01020216E32812345600013964313C

maxcul.0 2018-03-05 01:12:43.307 debug incoming raw data from CUL: Z0E01020216E32812345600013964313C

maxcul.0 2018-03-05 01:12:42.204 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:42.202 debug Send Packet to CUL: Zs0b01004012345616e3280071, awaiting drain event

maxcul.0 2018-03-05 01:12:42.201 info Poll device1 : 1, 18.5

maxcul.0 2018-03-05 01:12:42.200 info Poll device1 : 1, 21

maxcul.0 2018-03-05 01:12:42.199 info Poll device1 : 1, 17.5

maxcul.0 2018-03-05 01:12:42.198 info Poll device1 : 1, 17.5

maxcul.0 2018-03-05 01:12:42.197 info Poll device1 : 1, 24.5

maxcul.0 2018-03-05 01:12:42.196 info Poll device1 : 1, 24.5

maxcul.0 2018-03-05 01:12:41.181 debug delayed 4s

maxcul.0 2018-03-05 01:12:37.187 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":503,"ack":true,"ts":1520208757179,"q":0,"from":"system.adapter.maxcul.0","lc":1520208757179}

maxcul.0 2018-03-05 01:12:37.172 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:37.168 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:36.174 debug delayed 4s

maxcul.0 2018-03-05 01:12:32.181 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":498,"ack":true,"ts":1520208752172,"q":0,"from":"system.adapter.maxcul.0","lc":1520208752172}

maxcul.0 2018-03-05 01:12:32.168 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:32.166 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:31.181 debug delayed 4s

maxcul.0 2018-03-05 01:12:27.187 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":493,"ack":true,"ts":1520208747176,"q":0,"from":"system.adapter.maxcul.0","lc":1520208747176}

maxcul.0 2018-03-05 01:12:27.172 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:27.169 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:26.174 debug delayed 4s

maxcul.0 2018-03-05 01:12:22.176 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":488,"ack":true,"ts":1520208742168,"q":0,"from":"system.adapter.maxcul.0","lc":1520208742168}

maxcul.0 2018-03-05 01:12:22.165 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:22.163 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:21.168 debug delayed 4s

maxcul.0 2018-03-05 01:12:17.174 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":483,"ack":true,"ts":1520208737165,"q":0,"from":"system.adapter.maxcul.0","lc":1520208737165}

maxcul.0 2018-03-05 01:12:17.163 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:17.161 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:16.172 debug delayed 4s

maxcul.0 2018-03-05 01:12:12.174 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":478,"ack":true,"ts":1520208732166,"q":0,"from":"system.adapter.maxcul.0","lc":1520208732166}

maxcul.0 2018-03-05 01:12:12.164 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:12.159 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:11.163 debug delayed 4s

maxcul.0 2018-03-05 01:12:07.181 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":473,"ack":true,"ts":1520208727176,"q":0,"from":"system.adapter.maxcul.0","lc":1520208727176}

maxcul.0 2018-03-05 01:12:07.158 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:07.157 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:06.161 debug delayed 4s

maxcul.0 2018-03-05 01:12:02.177 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":468,"ack":true,"ts":1520208722173,"q":0,"from":"system.adapter.maxcul.0","lc":1520208722173}

maxcul.0 2018-03-05 01:12:02.156 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:12:02.155 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:12:01.167 debug delayed 4s

maxcul.0 2018-03-05 01:11:57.178 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":463,"ack":true,"ts":1520208717172,"q":0,"from":"system.adapter.maxcul.0","lc":1520208717172}

maxcul.0 2018-03-05 01:11:57.157 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:11:57.153 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:11:56.157 debug delayed 4s

maxcul.0 2018-03-05 01:11:52.161 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":458,"ack":true,"ts":1520208712154,"q":0,"from":"system.adapter.maxcul.0","lc":1520208712154}

maxcul.0 2018-03-05 01:11:52.150 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:11:52.147 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:11:51.153 debug delayed 4s

maxcul.0 2018-03-05 01:11:48.183 debug Za drained

maxcul.0 2018-03-05 01:11:48.180 debug Za written

maxcul.0 2018-03-05 01:11:48.177 debug Zr drained

maxcul.0 2018-03-05 01:11:48.173 debug Zr written

maxcul.0 2018-03-05 01:11:48.168 debug X20 drained

maxcul.0 2018-03-05 01:11:48.164 debug X20 written

maxcul.0 2018-03-05 01:11:48.161 debug enable MAX! Mode of the CUL868

maxcul.0 2018-03-05 01:11:47.169 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.quota {"val":453,"ack":true,"ts":1520208707158,"q":0,"from":"system.adapter.maxcul.0","lc":1520208707158}

maxcul.0 2018-03-05 01:11:47.168 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.limitOverflow {"val":false,"ack":true,"ts":1520208707155,"q":0,"from":"system.adapter.maxcul.0","lc":1520196435104}

maxcul.0 2018-03-05 01:11:47.148 debug serial port buffer have been drained

maxcul.0 2018-03-05 01:11:47.145 debug Send Packet to CUL: X, awaiting drain event

maxcul.0 2018-03-05 01:11:44.193 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.connection {"val":true,"ack":true,"ts":1520208704180,"q":0,"from":"system.adapter.maxcul.0","lc":1520208704180}

maxcul.0 2018-03-05 01:11:44.192 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.version {"val":"V 1.67 nanoCUL868","ack":true,"ts":1520208704179,"q":0,"from":"system.adapter.maxcul.0","lc":1519041256179}

maxcul.0 2018-03-05 01:11:44.187 info CUL FW Version: V 1.67 nanoCUL868

maxcul.0 2018-03-05 01:11:44.186 debug incoming raw data from CUL: V 1.67 nanoCUL868

maxcul.0 2018-03-05 01:11:44.158 debug Requested CUL Version...

maxcul.0 2018-03-05 01:11:44.153 debug check CUL Firmware version

maxcul.0 2018-03-05 01:11:42.160 debug redis pmessage io.maxcul.0.* io.maxcul.0.info.connection {"val":false,"ack":true,"ts":1520208702148,"q":0,"from":"system.adapter.maxcul.0","lc":1520208644510}

maxcul.0 2018-03-05 01:11:42.160 info serialPort /dev/ttyUSB0 is open!

maxcul.0 2018-03-05 01:11:42.135 info using serial device /dev/ttyUSB0@38400

maxcul.0 2018-03-05 01:11:41.568 info starting. Version 0.5.1 in /opt/iobroker/node_modules/iobroker.maxcul, node: v6.12.0

Wie man sieht kommt nach dem Send Packet jeweils das ACK.

delay(2000) funktioniert nicht, hab ich probiert. delay(4000) geht scheinbar...

skraw.iobroker

Ich habe da noch ein neues Problem mit maxcul.

Es geht um das mode Feld eines Thermostat Objekts. Man kann dieses Setzen und es wird zum Thermostat uebertragen. Aber danach wird das Feld scheinbar geloescht oder undefiniert hinterlassen. Es kommt mir so vor, als ob danach bei der naechsten Einstellungs-Sendung des Thermostats dieses immer auf "Auto" sprich "0" gesetzt wird. Aber genau das will man eigentlich nicht. Die ioBroker Einstellungen funktionieren nur korrekt wenn das Thermostat auf "Manual" (1) steht.

Ich glaube mich zu erinnern dass das im 0.3.0 anders war…

apollon77

~~@skraw.iobroker:~~

Wie man sieht kommt nach dem Send Packet jeweils das ACK.

delay(2000) funktioniert nicht, hab ich probiert. delay(4000) geht scheinbar… `

Was genau geht bei einem kleineren Delay nicht? Crasht er immer noch? 4s kann halt wenn viel los ist zu eeecht langen Reaktionszeiten führen … und ich kapiere nicht warum das so ist wie es ist.

wenn er crasht weil zu schnell gesendet wird dann sollte eigentlich ein weit kleinerer Delay reichen. Und es ist ja ok wenn schneller gesendetwird die Ack sollten dann immer noch entsprechend reinkommen und verarbeitet werden ...

apollon77

~~@skraw.iobroker:~~

Ich habe da noch ein neues Problem mit maxcul.

Es geht um das mode Feld eines Thermostat Objekts. Man kann dieses Setzen und es wird zum Thermostat uebertragen. Aber danach wird das Feld scheinbar geloescht oder undefiniert hinterlassen. Es kommt mir so vor, als ob danach bei der naechsten Einstellungs-Sendung des Thermostats dieses immer auf "Auto" sprich "0" gesetzt wird. Aber genau das will man eigentlich nicht. Die ioBroker Einstellungen funktionieren nur korrekt wenn das Thermostat auf "Manual" (1) steht.

Ich glaube mich zu erinnern dass das im 0.3.0 anders war… `

Ich habe sonst nichts an der "Logik" geändert

skraw.iobroker

Erst mal zu einem Vorgang der die Sache mit dem mode beweist:

maxcul.0 2018-03-05 10:02:34.372 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.rssi {"val":-69.5,"ack":true,"ts":1520240554367,"q":0,"from":"system.adapter.maxcul.0","lc":1520240554367}

maxcul.0 2018-03-05 10:02:34.366 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.batteryLow {"val":false,"ack":true,"ts":1520240554361,"q":0,"from":"system.adapter.maxcul.0","lc":1519978554323}

maxcul.0 2018-03-05 10:02:34.360 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.rfError {"val":false,"ack":true,"ts":1520240554356,"q":0,"from":"system.adapter.maxcul.0","lc":1519978554318}

maxcul.0 2018-03-05 10:02:34.355 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.measuredTemperature {"val":18.6,"ack":true,"ts":1520240554349,"q":0,"from":"system.adapter.maxcul.0","lc":1520240309909}

maxcul.0 2018-03-05 10:02:34.348 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.valvePosition {"val":8,"ack":true,"ts":1520240554342,"q":0,"from":"system.adapter.maxcul.0","lc":1520240554342}

maxcul.0 2018-03-05 10:02:34.341 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.desiredTemperature {"val":18,"ack":true,"ts":1520240554336,"q":0,"from":"system.adapter.maxcul.0","lc":1520236920388}

maxcul.0 2018-03-05 10:02:34.335 debug redis pmessage io.maxcul.0.* io.maxcul.0.OEQ2604801.mode {"val":null,"ack":true,"ts":1520240554328,"q":0,"from":"system.adapter.maxcul.0","lc":1520240554328}

maxcul.0 2018-03-05 10:02:34.335 debug ThermostatStateReceived: {"src":"1b7bbd","desiredTemperature":18,"valvePosition":8,"measuredTemperature":18.6,"dstSetting":1,"lanGateway":1,"panel":1,"rfError":0,"batteryLow":0,"untilString":"","rssi"

Man sieht hier dass der Received keinerlei "mode" enthaelt. Aber das erste was als Message generiert wird ist ein mode mit "null".

Hier noch mal die komplette Zeile aus dem logfile:

2018-03-05 10:02:34.327 - debug: maxcul.0 ThermostatStateReceived: {"src":"1b7bbd","desiredTemperature":18,"valvePosition":8,"measuredTemperature":18.6,"dstSetting":1,"lanGateway":1,"panel":1,"rfError":0,"batteryLow":0,"untilString":"","rssi":-69.5}

skraw.iobroker

bzgl. delay:

was crasht ist der nanoCUL. Der Adapter denkt weiterhin er koennte mit dem nanoCUL reden, aber der blinkt sich zu Tode und schickt keine Pakete mehr ueber Funk. Receive geht, aber kein Send.

Dieser Status laesst sich nicht mehr korrigieren wenn er eingetreten ist, da hilft nur noch ausstecken des nanoCUL.

Nachtrag:

ich hab mir das jetzt nochmal ganz genau angeschaut. Das Problem koennte auch am Aufruf des Codes liegen der die Queue ausleert, denn wenn das Flag gleich wieder auf false gesetzt wird kann ein folgender Aufruf vor Ablauf des Delays nochmal zu einem Send fuehren, daher:

CommunicationServiceLayer.prototype.writeQueue = function() {

if (!this._queuedWrites.length) return Promise.resolve(true);

var command = this._queuedWrites.shift();

this._queueSendInProgress = true;

return this._serialDeviceInstance.writeAsync(command).then(() => {

env.logger.debug('Send Packet to CUL: ' + command.trim() + ', awaiting drain event');

return this._serialDeviceInstance.drainAsync()

}).then(() => {

env.logger.debug('serial port buffer have been drained');

Promise.delay(2000).then(() => {

env.logger.debug('delayed 2s');

this._queueSendInProgress = false;

return this.writeQueue();

});

};

Jetzt mit "this._queueSendInProgress = false;" ganz am Schluss…

Wenn man genau darueber nachdenkt sollte man das false auch gar nicht am Ende setzen, sondern ganz oben eine Abfrage auf length==0 und dann auf false und exit. Wenn diese Routine "zweimal" parallel laeuft gibts sicher ein Problem...

Das Problem mit dem Locking ist jetzt halt hier konzentriert anstatt bei jedem SendPacket Aufruf wie frueher.

Community Forum

NEWS

Maxcul ist komplett unbrauchbar (geloest mit 0.5.2)

Support us

857

32.4k

81.5k

1.3m