UZB1 Stick: Lizenz schaltet AES Security frei?

Begonnen von buspirat, 18 November 2016, 13:37:11

Vorheriges Thema - Nächstes Thema

buspirat

Kommunikationsfehler ist gerade aufgetreten:

So sieht der relevante Teil von $hash aus:

$VAR1 = {
        'secInProgress' => 1,
        'secStack' => [],
        'SendStack' => [
                        'sentset:13290a9880947ec5aad6a5ed80253c',
                        'set:13290a98808affa067a0c17d9e253d',
                        'set:13290a98809f6f2cff397deaf5253e',
                        'set:13290a98809a5afccb9609fc5a253f'
                        ],

        'isWakeUp' => 1,
};


Für jede NONCE-Anforderung kommt ein set:xxxxxxx im SendStack hinzu.
Ich tippe darauf, daß das "sentset" die Abarbeitung blockiert, da es auf ein ACK wartet?

Vorschlag, den ich auch gleich probieren werde:
ZWAVE_secEnd() bekommt ein "clear_sendstack" Flag.

ZWAVE_secUnlock() ruft das mit clear_sendstack=true auf und dann leeren wir neben dem "secStack" auch den kompletten "sendStack".

Weniger invasiv wäre alle "sentset" Anfrage aus dem "sendStack" zu entfernen,
aber ein komplettes Cleanup kann auch nicht schaden, um die Kommunikation wieder in geordnete Bahnen zu lenken.

buspirat

Hmm, eigentlich ist da bereits Code in Zwave_processSendStack(), der genau die "sentset" Nachricht aufräumen soll. Allerdings bei $ackType = "next".

Der Timer für $ackType = "next" wird jedoch an einer Codestelle nur gesetzt, wenn es kein WakeUp Device ist. Es handelt sich hier jedoch um ein Wakeup-Device.


buspirat

Anbei nochmal ein Log, der das Problem zeigt, daß fhem nicht mehr sendet.
Im process_SendStack habe ich das "pSS:" Debug-Logging vorher einkommentiert + einen Dump des Hashes eingebaut, sobald der Expire-Timer triggert.


2016.11.26 01:09:39 1: pSS: ZWave_SENSOR_NOTIFICATION_41, next set:13290a98809b37e545fa27dec9256d
2016.11.26 01:09:39 5: ZWDongle_Write 0013290a98809b37e545fa27dec9256d (ee557686)
2016.11.26 01:09:39 5: SW: 01110013290a98809b37e545fa27dec9256d48
2016.11.26 01:09:39 5: ACK received, WaitForAck=>2 for 01110013290a98809b37e545fa27dec9256d48
2016.11.26 01:09:39 4: ZWDongle_Read ZWDongle_0: rcvd 011301 (answer ZW_SEND_DATA), sending ACK
2016.11.26 01:09:39 5: SW: 06
2016.11.26 01:09:39 5: ZWDongle_0 dispatch 011301
2016.11.26 01:09:39 4: ZWDongle_Read ZWDongle_0: rcvd 000400291a9881f658fbdeaf196ed32d10d446af66dc6b8dfebe98f1fd6be6 (request APPLICATION_COMMAND_HANDLER), sending ACK
2016.11.26 01:09:39 5: SW: 06
2016.11.26 01:09:39 5: ZWDongle_0 dispatch 000400291a9881f658fbdeaf196ed32d10d446af66dc6b8dfebe98f1fd6be6
2016.11.26 01:09:39 4: CMD:APPLICATION_COMMAND_HANDLER ID:29 ARG:1a9881f658fbdeaf196ed32d10d446af66dc6b8dfebe98f1fd6be6 CB:00
2016.11.26 01:09:39 1: ZWave_SENSOR_NOTIFICATION_41: secDecrypt: Authentification code not verified, command 23c5f47c36b0 will be dropped!

2016.11.26 01:09:41 4: no response from device, removing 01110013290a98809b37e545fa27dec9256d48 from dongle sendstack

2016.11.26 01:09:42 4: ZWDongle_Read ZWDongle_0: rcvd 00040029029840 (request APPLICATION_COMMAND_HANDLER), sending ACK
2016.11.26 01:09:42 5: SW: 06
2016.11.26 01:09:42 5: ZWDongle_0 dispatch 00040029029840
2016.11.26 01:09:42 4: CMD:APPLICATION_COMMAND_HANDLER ID:29 ARG:029840 CB:00
2016.11.26 01:09:43 4: ZWDongle_Read ZWDongle_0: rcvd 0004001c055b03c40002 (request APPLICATION_COMMAND_HANDLER), sending ACK

2016.11.26 01:09:49 3: ZWave_SENSOR_NOTIFICATION_41: secStart older than 6 seconds detected, secUnlock will call Zwave_secEnd
2016.11.26 01:09:49 1: HASH DUMP in secUnlock before calling secEnd(): $VAR1 = {
          'lastMsgSent' => '1480118979.84631',
          'secStack' => [],
          'ZWaveSubDevice' => 'no',
          'ZWDongle_0_TIME' => '2016-11-26 01:09:45',
          'homeId' => 'ee557686',
          'secInProgress' => 1,
          'nodeIdHex' => '29',
          'ZWDongle_0_MSGCNT' => 1620,
          'secTime' => '1480118982.15724',
          'NR' => 80,
          'LASTInputDev' => 'ZWDongle_0',
          'READINGS' => {
                          'state' => {
                                       'VAL' => 'wakeupInterval 86400 1',
                                       'TIME' => '2016-11-25 23:32:02'
                                     },
                          'modelConfig' => {
                                             'TIME' => '2016-11-25 23:32:04',
                                             'VAL' => 'philio/pst02.xml'
                                           },
                          'timeToAck' => {
                                           'TIME' => '2016-11-26 01:09:39',
                                           'VAL' => '0.070'
                                         },
                          'transmit' => {
                                          'TIME' => '2016-11-26 01:09:45',
                                          'VAL' => 'NO_ACK'
                                        },
                          'luminance' => {
                                           'TIME' => '2016-11-26 01:09:35',
                                           'VAL' => '37 %'
                                         },
                          'alarm' => {
                                       'VAL' => 'AccessControl: Window/Door is closed',
                                       'TIME' => '2016-11-26 01:09:35'
                                     },
                          'temperature' => {
                                             'TIME' => '2016-11-26 01:09:35',
                                             'VAL' => '23.5 C'
                                           },
                          'model' => {
                                       'VAL' => 'Philio Technology Corporation PST02-A 4 in 1 Multi-Sensor',
                                       'TIME' => '2016-11-25 23:32:04'
                                     },
                          'battery' => {
                                         'VAL' => '90 %',
                                         'TIME' => '2016-11-26 01:09:35'
                                       },
                          'SECURITY' => {
                                          'TIME' => '2016-11-25 23:31:44',
                                          'VAL' => 'ENABLED'
                                        },
                          'UNPARSED' => {
                                          'TIME' => '2016-11-25 23:31:44',
                                          'VAL' => 'SECURITY 03980500'
                                        },
                          'send_nonce' => {
                                            'VAL' => 'dcfb932e3219dca7',
                                            'TIME' => '2016-11-26 01:09:42'
                                          },
                          'modelId' => {
                                         'TIME' => '2016-11-25 23:32:04',
                                         'VAL' => '013c-0002-000c'
                                       }
                        },
          'DEF' => 'ee557686 41',
          'isWakeUp' => 1,
          'ZWDongle_0_RAWMSG' => '00136d010214',
          'STATE' => 'wakeupInterval 86400 1',
          'secTimer' => {
                          'hash' => $VAR1
                        },
          'MSGCNT' => 1620,
          '.vclasses' => {},
          'SendStack' => [
                           'sentset:13290a98809b37e545fa27dec9256d',
                           'set:13290a9880dcfb932e3219dca7256e'
                         ],
          'NAME' => 'ZWave_SENSOR_NOTIFICATION_41',
          'TYPE' => 'ZWave'
        };


Was tatsächlich hilft ist in ZWAVE_secUnlock() den SendStack komplett zu löschen,
die Kommunikation erholt sich dann sofort. Das ist allerdings der Vorschlaghammer...

A.Harrenberg

Hi,
Zitat von: buspirat am 26 November 2016, 01:49:05
Anbei nochmal ein Log, der das Problem zeigt, daß fhem nicht mehr sendet.
Im process_SendStack habe ich das "pSS:" Debug-Logging vorher einkommentiert + einen Dump des Hashes eingebaut, sobald der Expire-Timer triggert.
Du bist ja ganz schön aktiv ,-)

Ich denke das der Auslöser für das Verhalten einen Schritt vor dem Log liegt... Ich versuche das mal aufzudröseln und zu kommentieren:


2016.11.26 01:09:39 1: pSS: ZWave_SENSOR_NOTIFICATION_41, next set:13290a98809b37e545fa27dec9256d
2016.11.26 01:09:39 5: ZWDongle_Write 0013290a98809b37e545fa27dec9256d (ee557686)
2016.11.26 01:09:39 5: SW: 01110013290a98809b37e545fa27dec9256d48

Hier wird eine NONCE gesendet <b37e545fa27dec92> (d.h. sie fängt mit <b3> an, das erste Byte wird im verschlüsselten Packet noch mal wieder mit zurückgeschickt, das kommt gleich...)


2016.11.26 01:09:39 4: ZWDongle_Read ZWDongle_0: rcvd 000400291a9881f658fbdeaf196ed32d10d446af66dc6b8dfebe98f1fd6be6 (request APPLICATION_COMMAND_HANDLER), sending ACK
2016.11.26 01:09:39 5: SW: 06
2016.11.26 01:09:39 5: ZWDongle_0 dispatch 000400291a9881f658fbdeaf196ed32d10d446af66dc6b8dfebe98f1fd6be6
2016.11.26 01:09:39 4: CMD:APPLICATION_COMMAND_HANDLER ID:29 ARG:1a9881f658fbdeaf196ed32d10d446af66dc6b8dfebe98f1fd6be6 CB:00
2016.11.26 01:09:39 1: ZWave_SENSOR_NOTIFICATION_41: secDecrypt: Authentification code not verified, command 23c5f47c36b0 will be dropped!

Jetzt kommt die verschlüsselte Nachricht an, hier wird aber auf eine andere NONCE referenziert, daher stimmt die Authentifizierung nicht...
1a9881f658fbdeaf196ed32d10d446af66 dc 6b8dfebe98f1fd6be6
                                                                 ^^ Kennung der genutzen NONCE ist <dc>

Der Befehl wird weggeworfen, und an dieser Stelle mache ich eventuell schon einen Fehler, hier müsste(n) die "sent NONCE" schon mal aufgeräumt werden, das muss ich mal prüfen ob die das mache oder übersehen habe. Gedachtes Vorgehen ist ja:
- Geräte will was senden und fragt nach einer NONCE
- NONCE wird generiert, gesendet und gespeichert
- Gerät schickt verschlüsselte Nachricht und wird mit der gespeicherten NONCE entschlüsselt bzw. authentifiziert
- gespeicherte NONCE wird entfernt und die nächste Kommunikation kann beginnen

Ist hierfür aber denke ich nicht relevant, Problem liegt wohl eher im Handling vom Stack...


2016.11.26 01:09:41 4: no response from device, removing 01110013290a98809b37e545fa27dec9256d48 from dongle sendstack

Keine Antwort auf das Senden der <b3> NONCE...


2016.11.26 01:09:42 4: ZWDongle_Read ZWDongle_0: rcvd 00040029029840 (request APPLICATION_COMMAND_HANDLER), sending ACK

Hier wird noch mal nach einer neuen NONCE gefragt, im Log ist aber kein Senden der Nonce enthalten.


2016.11.26 01:09:49 3: ZWave_SENSOR_NOTIFICATION_41: secStart older than 6 seconds detected, secUnlock will call Zwave_secEnd

Timer expired und der schöne Data::Dump ;-)

Hier gibt es jetzt zwei, bzw. sogar drei Auffälligkeiten für mich, die das ganze aber etwas erklären, aber natürlich neue Fragen aufwerfen.

                          'UNPARSED' => {
                                          'TIME' => '2016-11-25 23:31:44',
                                          'VAL' => 'SECURITY 03980500'
                                        },
                          'send_nonce' => {
                                            'VAL' => 'dcfb932e3219dca7',
                                            'TIME' => '2016-11-26 01:09:42'
                                          },
          'SendStack' => [
                           'sentset:13290a98809b37e545fa27dec9256d',
                           'set:13290a9880dcfb932e3219dca7256e'
                         ],

Auffälligkeiten:

  • Es gibt einen UNPARSED Eintrag für 03980500, das ist die Bestätigung des Gerätes das S0 Security mit "Scheme 0" genutzt wird. Mir ist völlig unklar wie das in UNPARSED landen kann, das wird während der Inklusion genutzt und der Empfang der Nachricht wird mMn auch für den Ablauf der Inklusion genutzt. Muss ich mir auch noch mal anschauen, ist hier aber nur Nebenschauplatz.
  • Bei der send_nonce geht jetzt wirklich was durcheinander... Hier ist die <dc> Nonce als "gültige" versendete NONCE eingetragen, allerdings passt der Zeitstempel zu dem zweiten Request um 01:09:42 der aber nie wirklich gesendet wurde.
  • Auf dem Stack kann man das ganze auch noch mal sehen: Die Antwort auf die <b3> NONCE kommt nicht, deswegen "verhungert" der SentStack -> eigentlich müsste hier der Stack aufgeräumt werden da ja erkannt wurde das keine Antwort kam. Als nächster liegt die <dc> NONCE auf dem Stack, die aber nciht gesendet wird weil der Stack hängt. Hier ist für mich jetzt aber das größte Fragezeichen! Wenn die <dc> NONCE ja nun noch gar nicht gesendet wurden, wie kann das Geräte dann auf eine <dc> NONCE verweisen? Es könnte natürlich Zufall sein das genau vorher eine NONCE mit <dc> verschickt wurde.

Um das weiter zu analysieren wäre es gut wenn Du etwas mehr von dem Log posten könntest damit ich mir die "Vorgeschichte" noch mal anschauen kann. (Für weitere Tests würde ich Dich bitten unter global das Attribut mseclog=1 zu setzen, dann werden auch millisekunden angezeigt).

Ich schau mir die Generierung der NONCE noch mal an, und würde das dann dort zum Testen mal so ändern das das erste Byte der NONCE fortlaufend nummeriert wird, dann kann man recht einfach erkennen wann welche NONCE erzeugt bzw. genutzt wird.

Dann muss ich mir noch mal die ganzen Stacks (sec-Stack, WU-Stack. send-Stack, Dongle send-Stack) anschauen um zu verstehen wieso die <b3> Nachricht nicht weggeräumt wird und wie das so die Interaktion läuft. Dabei kriege ich aber regelmäßig einen Knoten im Hirn  ::)
Du hast ja da anscheinend schon eine Sonderbehandlung für die WU-Geräte gefunden die das erklären könnte.

Zitat von: buspirat am 26 November 2016, 01:49:05
Was tatsächlich hilft ist in ZWAVE_secUnlock() den SendStack komplett zu löschen,
die Kommunikation erholt sich dann sofort. Das ist allerdings der Vorschlaghammer...
Ja, Vorschlaghammer hilft immer, aber das setzt ja nur am Symptom und nicht an der Ursache an, wobei das natürlich auch für mein secUnlock() gilt! Ich dachte aber auch das mit den letzten Änderungen das secUnlock() nicht mehr nötig sein sollte...

Gruß,
Andreas.
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

buspirat

Vielen Dank für die Analyse! Während ich relativ gut programmieren kann, kenne ich leider die Details des Z-Wave Funkstandards noch nicht. Deine Analyse ist sehr hilfreich!

Habe gestern vor dem Test die Logdatei geleert und fhem neu gestartet.
Die vollständige Logdatei ist per E-Mail raus, unkomprimiert sind es 3,4MB.

Das Attribut mseclog=1 ist jetzt gesetzt. Sag Bescheid, falls ich den Fehler nochmal provozieren soll.

Die Komplexität mit SECURITY ist auch, daß es an ein paar Stellen den SendStack umgeht, z.B. um die NONCE zeitnah und nicht erst nach einem Wakeup-Event zu verschicken ;D Dann gibt es noch zig Timer die irgendwo werklen usw.

A.Harrenberg

Hi,
Zitat von: buspirat am 26 November 2016, 11:22:23
Die Komplexität mit SECURITY ist auch, daß es an ein paar Stellen den SendStack umgeht, z.B. um die NONCE zeitnah und nicht erst nach einem Wakeup-Event zu verschicken ;D Dann gibt es noch zig Timer die irgendwo werklen usw.
ja, ein WU-Gerät verschickt auch ohne WU-Notification seine Werte und wenn das unter Security geschieht dann schläft das Gerät für fhem, und dann darf die NONCE nicht auf dem WU-Stack liegenbleiben.

Die Interaktionen zwischen den ganzen Stacks und den Timern ist mittlerweile wirklich recht hoch, ich sage ja, jedesmal wenn ich damit anfange kriege ich einen Knoten im Hirn.

Jetzt schaue ich aber mal in Dein Logfile rein, mal sehen was dabei rauskommt.

Gruß,
Andreas.
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

A.Harrenberg

Hallo,

so, habe jetzt mal einen Teil des Logs durchgeschaut, ist schon ein ziemlicher Stresstest für die Kommunikation was da abgeht...

Zu Anfang kommt die Kommunikation mal aus dem Tritt, fängt sich dann aber nach dem secUnlock() wieder. Prinzipiell passiert das folgende: (irgendwann habe ich mal das NONCE request weggelassen)

NONCE request
<02> NONCE verschickt
<02> NONCE angekommen
SENSOR MULTILEVEL

NONCE request
<ae> NONCE verschickt
<ae> NONCE angekommen
SENSOR MULTILEVEL

NONCE request
<00> NONCE verschickt
<00> NONCE angekommen

*** jetzt kommen "Störungen" durch den KFOB

SCENE 2
SCENE 2
SCENE 2
SCENE 2
SCENE 2
SCENE 2

<00> NONCE wurde verschickt und Empfang wurde bestätigt, es kommt jedoch kein verchlüsseltes Packet an

2016.11.26 01:02:23 3: ZWave_SENSOR_NOTIFICATION_41: secStart older than 6 seconds detected, secUnlock will call Zwave_secEnd

*****
secUnlock
*****

NONCE request
<d0> NONCE verschickt
<d0> NONCE angekommen
SENSOR MULTILEVEL

NONCE request
<f4> NONCE verschickt
<f4> NONCE angekommen
SENSOR MULTILEVEL


Später kommt das ganze dann auch mal kurz aus dem Tritt, fängt sich wieder um dann aber für eine sehr lange Zeit asynchron zu laufen:

<cd> NONCE verschickt
<cd> NONCE angekommen
SENSOR MULTILEVEL

<1b> NONCE verschickt
*****
KEINE Bestätigung, aber neue Anforderung einer NONCE! Wahrscheinlich Übertragungsproblem des ACK in Richtung Sensor!
*****
<1b> NONCE angekommen ??

<db> NONCE verschickt
*****
verschlüsseltes Packet mit <1b> NONCE angekommen -> dropped da <db> NONCE aktuell ist!
*****

<db> NONCE angekommen
*****
verschlüsseltes Packet noch mal mit <1b> NONCE angekommen -> dropped da <db> NONCE aktuell war, aber entfernt wurde!
*****

<f0> NONCE verschickt
<f0> NONCE angekommen
BATTERY

<23> NONCE verschickt
<23> NONCE angekommen
ALARM

<83> NONCE verschickt
*****
(noch) KEINE Bestätigung
*****
BATTERY mit <83> NONCE

NONCE request
*****
<83> NONCE wird als angekommen markiert, ACK gehört aber wohl eher zum Empfangsbestätigung "NONCE request"
*****
<39> NONCE verschickt
<39> NONCE angekommen
<b2> NONCE verschickt
*****
verschlüsseltes Packet mit <83> NONCE angekommen -> dropped da <b2> NONCE aktuell ist!
Gar kein Paket mit <39> NONCE angekommen...
*****

<b2> NONCE angekommen
<4e> NONCE verschickt
*****
verschlüsseltes Packet mit <b2> NONCE angekommen -> dropped da <4e> NONCE aktuell ist!
*****

<4e> NONCE angekommen
<e7> NONCE verschickt
*****
verschlüsseltes Packet mit <4e> NONCE angekommen -> dropped da <e7> NONCE aktuell ist!
*****

<e7> NONCE angekommen
<3c> NONCE verschickt
*****
verschlüsseltes Packet mit <e7> NONCE angekommen -> dropped da <3c> NONCE aktuell ist!
*****

Das System kommt dabei in eine recht stabile asynchrone Kommunikation. Anscheinend sendet der Sensor eine neue Anforderung für eine NONCE nachdem wahrscheinlich das ACK nicht beim Sensor angekommen ist. Dadurch wird die aktuelle, bereits verschickte NONCE "weggeworfen" und eine neue erzeugt. Der Sensor nimmt aber die bereits verschickte NONCE um die Nachricht zu verschlüsseln. Die wird aber weggeworfen das die NONCE mittlerweile nicht mehr gültig ist. Die neue NONCE wird angefordert, die alte weggeworfen, der Sensor nutz die aber wieder zur Verschlüsseung und so weiter...

Es gibt hier meiner Meinung nach drei Probleme.

1.) Das versenden eine neuen NONCE während bereits eine verschickt wurde kann den ganzen Zirkus starten und sollte blockiert werden, das sollte auch recht einfach zu realisieren sein da es ja secStart()/secEnd() gibt die secInProgress setzen. Sollte es hier zu einem "Hänger" kommen sollte secUnlock() das nach 6 sekunden auflösen, es sollte aber keine asynchronen NONCE Kommunikationen mehr geben.

2.) Die Stacks sind ja "fire-and-forget", d.h. aus Applikationsicht ist der Befehl für micht versendet sobald ich den in den Stack geschoben habe. Ob der Stack klemmt kriege ich nicht direkt mit, was die Sache nicht einfacher macht. Ich habe aber auch keine Idee wie das Problem gelöst werden kann ohne das gesamte System unnötig mit Warten zu blockieren. Ich denke das wir damit leben müssen

3.) Der Sendstack klemmt irgendwie merkwürdig bzw. das System scheint für einige Zeit einzufrieren und nicht mehr zu loggen oder so. In der ersten Analyse ist mir aufgefallen das die NONCES im Stack bzw. in den Readings nicht zueinanderpassen.
Es gibt dort einen Ablauf mit:


<86> NONCE angekommen

<6b> NONCE verschickt
*****
verschlüsseltes Packet mit <86> NONCE angekommen -> dropped da <6b> NONCE aktuell ist!
*****
<6b> NONCE angekommen

<9b> NONCE verschickt
*****
verschlüsseltes Packet mit <6b> NONCE angekommen -> dropped da <9b> NONCE aktuell ist!
*****

*****
no response from device
<9b> NONCE message removing from sendstack
*****
*****
NO_ACK for sending <9b> NONCE

dann kommt das secUnlock() und in dem Dump findet sich:

'send_nonce' => {
                                            'VAL' => 'dcfb932e3219dca7',
                                            'TIME' => '2016-11-26 01:09:42'

und

          'SendStack' => [
                           'sentset:13290a98809b37e545fa27dec9256d',
                           'set:13290a9880dcfb932e3219dca7256e'
                         ],

Das passt nicht zu dem Log... die Nachricht mit der <9b> NONCE sollte ja berits vom Stack entfernt worden sein und es taucht ein Paket mit einer <dc> NONCE im Stack auf, die im Log bis dahin nicht aufgetaucht ist und auch danach nicht mehr kommt...

Im weiteren Verlauf sammeln sich die weiteren Nachrichten hinter der sentset <9b> NONCE message und der Stack ist blockiert...

Für 1.) schaue ich mal nach einem Fix, für 2.) gibt es wohl keine Lösung, aber bei 3.) bin ich völlig überfragt was dort passiert. Ich habe das Gefühl das hier die ACK Nachrichten nicht korrekt zugeordnet werden da anscheinend einige nicht übertragen wurden, das erklärt aber nicht warum die Nachricht die angeblich entfernt wurde noch auf dem Stack liegt und der Stack danach blockiert ist.

Gruß,
Andreas.
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

A.Harrenberg

Hi buspirat,

kannst Du mal versuchen die Function ZWave_secNonceRequestReceived () durch diese Variante zu ersetzen und das ganze noch mal zu provozieren?
Hier wird dann einfach der NONCE-Request ignoriert solange noch eine Kommunikation aktiv ist.

sub
ZWave_secNonceRequestReceived ($)
{
  my ($hash) = @_;
  if (!ZWave_secIsEnabled($hash) || !$hash->{secInProgress}) {
    Log3 $hash->{NAME}, 1, "$hash->{NAME}: dropped NONCE request due to "
                          ."actual communication still active";
    return;
  }
  ZWave_secStart($hash);
  ZWave_secAddToSendStack($hash, '98'.ZWave_secCreateNonce($hash));
}


Gruß,
Andreas.
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

A.Harrenberg

Hi,

grummel, die negierung war natürlich falsch...

sub
ZWave_secNonceRequestReceived ($)
{
  my ($hash) = @_;
  if (!ZWave_secIsEnabled($hash) || $hash->{secInProgress}) {
    Log3 $hash->{NAME}, 1, "$hash->{NAME}: dropped NONCE request due to "
                          ."actual communication still active";
    return;
  }
  ZWave_secStart($hash);
  ZWave_secAddToSendStack($hash, '98'.ZWave_secCreateNonce($hash));
}


Gruß,
Andreas.
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

buspirat

Hi Andreas,

die Code-Änderung in ZWave_secNonceRequestReceived() kann ich gerne ausprobieren.
Bis jetzt hat sich der SendStack nicht mehr erholt und ist mehrere Bildschirmseiten lang.
Die WUN will vermutlich auch vorher eine NONCE... ich starte jetzt fhem neu.

Zitat von: A.Harrenberg am 26 November 2016, 22:10:08
dann kommt das secUnlock() und in dem Dump findet sich:

'send_nonce' => {
                                            'VAL' => 'dcfb932e3219dca7',
                                            'TIME' => '2016-11-26 01:09:42'

und

          'SendStack' => [
                           'sentset:13290a98809b37e545fa27dec9256d',
                           'set:13290a9880dcfb932e3219dca7256e'
                         ],

Das passt nicht zu dem Log... die Nachricht mit der <9b> NONCE sollte ja berits vom Stack entfernt worden sein und es taucht ein Paket mit einer <dc> NONCE im Stack auf, die im Log bis dahin nicht aufgetaucht ist und auch danach nicht mehr kommt...

mir war auch aufgefallen, daß die Nachricht "13290a98809b37e545fa27dec9256d" eigentlich weg sein müsste und danach wieder im Dump zu finden war. Hier gibt es für mich nur drei Erklärungsmöglichkeiten:

1. die Nachricht lag doppelt auf dem Stack
2. sie wurde nicht aus dem SendStack-Array entfernt.
  Wenn man sich ZWDongle_shiftSendStack() ansieht kann das eigentlich nicht sein,
  erst recht nicht nachdem die Logmeldung aufgetaucht ist.

  Evtl. ein extrem unwahrscheinlicher perl-Bug, würde ich jedoch erstmal ausschließen.

3. Es wurde auf einer Kopie vom SendStack / $hash Objekt gearbeitet.
   Das entspricht dann in etwa 1.

Ich tippe darauf, daß über irgendeinen verschlungenen Code-Pfad die gleiche Nachricht doppelt auf den Stack gelegt wurde. Anders kann ich mir das nicht erklären.

Bevor ich Deine Code-Änderung mit der NONCE reinmachen würde,
hatte ich noch folgende Idee:

- in 00_ZWDongle.pm in der Funktion ZWDongle_shiftSendStack($$$$;$)

  vor

  shift @{$ss};

  ein

  if ($txt != "device ack reveived")     # PseudoCode. $txt hat Tippfehler im Code
     Log Data::Dumper($ss)

- wie von Dir angedacht die NONCE-Generierung zu einem linearen Zähler umbauen.
  Wie war das, nur das erste Byte wird im Klartext geloggt?

  Dann müsste man irgendwie an den großen Stelle der Zahl hochzählen.
  Weiß nicht ob sich das lohnt, wenn nur ein Byte geloggt wird,
  dann sind die 255 möglichen Funktelegramme sehr schnell aufgebraucht
  bis der Fehler auftritt. Es sei denn, man zählt dann wieder von vorne.
  Müsste eigentlich möglich sein.


Fazit: Das bestehende Verhalten erstmal nicht verändern, sondern nur um zusätzliches Logging erweitern. Ich will den Bug fangen :)

Vermutlich werde ich erst in zwei Tagen wieder daran arbeiten können.

A.Harrenberg

Hi,
Zitat von: buspirat am 27 November 2016, 10:26:33
die Code-Änderung in ZWave_secNonceRequestReceived() kann ich gerne ausprobieren.
Bis jetzt hat sich der SendStack nicht mehr erholt und ist mehrere Bildschirmseiten lang.
Die WUN will vermutlich auch vorher eine NONCE... ich starte jetzt fhem neu.
wenn Dir Deine Batterien lieb sind solltest Du das nicht sooo lange laufen lassen, das Ding sendet ja quasi ununterbrochen...

Die WUN braucht keine NONCE, die ist unverschlüsselt, aber die regelmäßigen Werte wie BATTERY brauchen eine, die ALARM Meldung natürlich auch. Solche Meldungen kommen auch VOR der WUN...

Zitat von: buspirat am 27 November 2016, 10:26:33
mir war auch aufgefallen, daß die Nachricht "13290a98809b37e545fa27dec9256d" eigentlich weg sein müsste und danach wieder im Dump zu finden war. Hier gibt es für mich nur drei Erklärungsmöglichkeiten:

1. die Nachricht lag doppelt auf dem Stack
glaube ich eher nicht, dann hätte sie zwei mal als "ZWDonge_write" bzw. "SW:" auftauchen müssen. Sie ist ja als versendet gekennzeichnet.

Zitat von: buspirat am 27 November 2016, 10:26:33
2. sie wurde nicht aus dem SendStack-Array entfernt.
  Wenn man sich ZWDongle_shiftSendStack() ansieht kann das eigentlich nicht sein,
  erst recht nicht nachdem die Logmeldung aufgetaucht ist.

  Evtl. ein extrem unwahrscheinlicher perl-Bug, würde ich jedoch erstmal ausschließen.
Was soll ich sagen, ich verstehe es ja auch nicht....

Zitat von: buspirat am 27 November 2016, 10:26:33
3. Es wurde auf einer Kopie vom SendStack / $hash Objekt gearbeitet.
   Das entspricht dann in etwa 1.
Wüsste nicht wie das passieren sollte...

Zitat von: buspirat am 27 November 2016, 10:26:33
Ich tippe darauf, daß über irgendeinen verschlungenen Code-Pfad die gleiche Nachricht doppelt auf den Stack gelegt wurde. Anders kann ich mir das nicht erklären.
Glaube ich eher nicht. Ich hätte eher die diversen Timer in Hintergrund im Verdacht das da einer genau zu einer unpassenden Zeit zugeschlagen hat der Ablauf dann doch nicht so war wie geplant. Dazu müsste ich da aber mal sehr genau reinschauen oder Rudi kann hier behilflich sein.

Zitat von: buspirat am 27 November 2016, 10:26:33
Bevor ich Deine Code-Änderung mit der NONCE reinmachen würde,
hatte ich noch folgende Idee:

- in 00_ZWDongle.pm in der Funktion ZWDongle_shiftSendStack($$$$;$)

  vor

  shift @{$ss};

  ein

  if ($txt != "device ack reveived")     # PseudoCode. $txt hat Tippfehler im Code
     Log Data::Dumper($ss)
dagegen spricht ja nichts

Zitat von: buspirat am 27 November 2016, 10:26:33
- wie von Dir angedacht die NONCE-Generierung zu einem linearen Zähler umbauen.
  Wie war das, nur das erste Byte wird im Klartext geloggt?

  Dann müsste man irgendwie an den großen Stelle der Zahl hochzählen.
  Weiß nicht ob sich das lohnt, wenn nur ein Byte geloggt wird,
  dann sind die 255 möglichen Funktelegramme sehr schnell aufgebraucht
  bis der Fehler auftritt. Es sei denn, man zählt dann wieder von vorne.
  Müsste eigentlich möglich sein.
Die NONCE sind wie gesagt mehr oder weniger "öffentlich", ob die nun im Klartext geloggt werden oder nicht ist ziemlich egal.
Das erste Byte der gesendeten NONCE wird in der verschlüsselten Antwort noch mal wieder mit zurückgesendet damit man die "richtige" NONCE zum Entschlüsseln wiederfinden kann. Das ist aber eigentlich nur interessant wenn man das ganze an zentraler Stelle für mehrere Geräte macht. Für ein einzelnes Gerät darf es immer nur eine aktive Kommunikation geben und selbst für den Dongle gibt es da Einschränkungen.
Daher ist das erste Byte der gesendeten NONCE hier interessant. Und den Zähler kann man ja ohne weiteres "rollen" lassen, wenn der nach 255 Packeten wieder bei 0 anfängt macht das ja nichts.

Zitat von: buspirat am 27 November 2016, 10:26:33
Fazit: Das bestehende Verhalten erstmal nicht verändern, sondern nur um zusätzliches Logging erweitern. Ich will den Bug fangen :)
Ok, aber es wäre schön wenn Du dennoch mal probieren könntest ob die Änderungen denn auch im jetzigen Zustand helfen würde.

Gruß,
Andreas.
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

buspirat

Hi Andreas,

Zitat von: A.Harrenberg am 27 November 2016, 10:47:04
Hi,wenn Dir Deine Batterien lieb sind solltest Du das nicht sooo lange laufen lassen, das Ding sendet ja quasi ununterbrochen...
ich wollte herausfinden, ob er z.B. nach 24h sich von alleine erholt. War leider nicht so, der klemmt komplett.

Zitat von: A.Harrenberg am 27 November 2016, 10:47:04
Was soll ich sagen, ich verstehe es ja auch nicht....
Wüsste nicht wie das passieren sollte...
Glaube ich eher nicht. Ich hätte eher die diversen Timer in Hintergrund im Verdacht das da einer genau zu einer unpassenden Zeit zugeschlagen hat der Ablauf dann doch nicht so war wie geplant. Dazu müsste ich da aber mal sehr genau reinschauen oder Rudi kann hier behilflich sein.
sieht mir irgendwie nach einem indirekten Ablauf aus. Ich habe ZWDongle_shiftSendStack() wie angedacht umgebaut und der SendStack ist eigentlich komplett leer und dann kommt der Fehler.

Wilde Theorie: Das Paket wird vom SendStack entfernt und kurz darauf wird das "sentXXXX" dennoch auf den Stack gelegt, obwohl die Bearbeitung des Anfrage eigentlich nicht geklappt hat.
Aus dem Bauch heraus würde ich tippen, daß das Einfügen von "sentXXX" die Fehlersituation nicht erkennt oder richtig überprüft.

Die Generierung der NONCE sieht jetzt so aus:

my $global_nonce_counter=0;
sub
ZWave_secGetNonce()
{
  my $nonce=sprintf "%02x", $global_nonce_counter;
  for (my $i = 0; $i <7; $i++) {
    $nonce .= sprintf "%02x",int(rand(256));
  }

  $global_nonce_counter++;
  if ($global_nonce_counter == 255) {
    $global_nonce_counter=0;
  }
  Log 1, "DEBUG: Computed NONCE: $nonce";

  return $nonce;
}


ZWDongle_shiftSendStack() hat auch Debug-Code bekommen:

    my $debug_dump_hash=0;
    if ($txt && $txt ne "device ack reveived" && $txt ne "ACK received") {
      $debug_dump_hash=1;
    }

    if ($debug_dump_hash)
    {
       Log 1, "DEBUG: Dumping hash in ZWDongle_shiftSendStack: ".Dumper($hash);
    }

    shift @{$ss};
    if ($debug_dump_hash)
    {
       Log 1, "DEBUG: SendStack after shift (txt: $txt): ".Dumper($ss);
    }

    Log3 $hash, $loglevel, "$txt, removing $cmd from dongle sendstack"
        if($txt && $cmd);


Der vorherige Data::Dumper() Aufruf im secUnlock ist weiterhin vorhanden.

Zitat von: A.Harrenberg am 27 November 2016, 10:47:04
Die NONCE sind wie gesagt mehr oder weniger "öffentlich", ob die nun im Klartext geloggt werden oder nicht ist ziemlich egal.
das Logging aus Sicherheitsgründen hatte ich bei meiner Aussage gar nicht im Sinn, sonder nur wieviele Bytes im Klartext bei der Antwort zurückgeschickt werden. Du hast meine Frage perfekt beantwortet. Danke :)
NONCE is eigentlich bei fast allen Kryptoprotokollen im Klartext.

Zitat von: A.Harrenberg am 27 November 2016, 10:47:04
Ok, aber es wäre schön wenn Du dennoch mal probieren könntest ob die Änderungen denn auch im jetzigen Zustand helfen würde.
werde ich morgen oder übermorgen auf jeden Fall machen. Dauert manchmal bis ich den Fehler erwische.

Neue Logdatei ist an Dich per E-Mail raus. Hoffentlich hilft die lineare NONCE beim Debuggen.

Viele Grüße
Thomas

A.Harrenberg

Hi,

habe mir das neue Log mal angesehen, aber leider nicht mehr daraus gelernt...

Zu Anfang des Logs gibt es einen Fall wo das secUnlock() aufgerufen wird, das ist aber richtig (und gut) so. Es wurde eine NONCE verschickt, dann kamen etliche Nachrichten von der Fernbedienung und der Sensor hat nichts geschickt.

Ich habe dann mal das Log von "hinten" anscheschaut, das waren aber ein paar tausend Zeilen die ich dazu durchgeackert habe um den interessanten Teil zu finden... ,-(
Ich habe den Ablauf hier mal vereinfacht dargestellt, wenn nur eine hexzahl genannt ist wurde die entsprechende NONCE verschickt (SW:...), hexzahl + "ok" bedeutet das fhem ein ACK vom Device bekommen hat und das vom Stack genommen hat (device ack reveived, removing ... from dongle sendstack). Ansonsten habe ich die Klassen der angekommenen Nachrichten reingeschrieben.

Das hier ist der Anfang des Problems. Auf das Versenden der "af" NONCE gab es zwar ein ACK, es wird aber eine neue NONCE angefordert. Hier ist es wahrscheinlich zu einem Übertragungsproblem gekommen und es ist auf einer Seite ein ACK nicht angekommen...
Es kommen dann trotz ACK auf die versendete NONCE noch weitere NONCE-Request bis zum Versenden der NONCE "b2". Es kommt dann jedoch ein Paket mit der ursprunglichen "af" NONCE das natürlich als ungültig weggeworfen wird.

BATTERY
ac
ac ok
ALARM
ad
ad ok
SENSOR_MULTILEVEL
ae
ae ok
BATTERY
af
af ok
*****
noch kein verschlüsseltes Paket erhalten, neue Anfrge nach NONCE
*****
b0
b0 ok
*****
noch kein verschlüsseltes Paket erhalten, neue Anfrge nach NONCE
*****
b1
b1 ok
*****
noch kein verschlüsseltes Paket erhalten, neue Anfrge nach NONCE
*****
b2
*****
Paket mit NONCE af angekommen -> b2 ist aktiv! NONCE b0, b1, b2 "zwischenzeitlich erzeugt"
*****


Danach beginnt dann das bekannte asynchrone Spiel, "b2" NONCE wird bestätigt, "b3" NONCE wird erzeugt/verschickt, Paket kommt mit b2 NONCE an wird weggeworfen und so weiter...
Es kommen auch noch ein paar CAN dazu, die haben aber mMn. keinen Einfluß auf den Ablauf. An einer Stelle sind die NONCES sogar synchron, aber es werden wieder zwei NONCE hintereinander angefordert und das es ist gleich wieder asynchron..

CENTRAL_SCENE
b2 ok
b3
Dongle ACK für b3
NONCE request (b4)
*****
Paket mit NONCE b2 angekommen -> b3 ist aktiv!
*****
NONCE request (b5)
b3 ok
b4
*****
Paket mit NONCE b3 angekommen -> b4 ist aktiv
*****
CENTRAL_SCENE
NONCE request (b6)
b4 ok
b5
*****
Paket mit NONCE b4 angekommen -> b5 ist aktiv
*****
NOCE request (b7)
b5 ok
b6
*****
Paket mit NONCE b5 angekommen -> b6 ist aktiv
*****
*****
Paket mit NONCE b5 (noch mal) angekommen -> b6 ist aktiv, aber keine NONCE mehr vorhanden...
*****
b6 ok
b7
b7 ok
b8
CAN received (for b8?)
NONCE request (b9)
no ACK for b8
b8 erneut versendet (wg. CAN)
b8 ok
b9
*****
Paket mit NONCE b6 angekommen -> b9 ist aktiv
*****
CAN received (for b9?)
NONCE request (ba)
no ACK for b9
b9 erneut versendet (wg. CAN)
Dongle ACK b9
CENTRAL_SCENE
b9 ok
ba
*****
Paket mit NONCE b9 angekommen -> ba ist aktiv
*****
NONCE request (bb)
ba ok
bb
*****
Paket mit NONCE ba angekommen -> bb ist aktiv
*****
NONCE request (bc)
bb
bc
*****
Paket mit NONCE bb angekommen -> bc ist aktiv
*****
CENTRAL_SCENE
NONCE request (bd)
bc ok
bd
*****
Paket mit NONCE bc angekommen -> bd ist aktiv
*****
bd ok
be
Dongle ACK
NONCE request (bf)
CENTRAL_SCENE
be ok
bf
Dongle ACK
NONCE request (c0)
CENTRAL_SCENE
*****
Paket mit NONCE bd angekommen -> c0 ist aktiv
*****
NONCE request (c1)
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
bf ok
c0
Dongle ACK
*****
Paket mit NONCE bf angekommen -> c0 ist aktiv
*****
c0 ok
c1
Dongle ACK
NONCE request (c2)
*****
Paket mit NONCE c0 angekommen -> c2 ist aktiv
*****
NONCE request (c3)
CENTRAL_SCENE
c1 ok
c2
*****
Paket mit NONCE c1 angekommen -> c2 ist aktiv
*****
NONCE request (c4)
CENTRAL_SCENE
c2 ok
c3
*****
Paket mit NONCE c2 angekommen -> c3 ist aktiv
*****
NONCE request (c5)
c3 ok
c4
*****
Paket mit NONCE c3 angekommen -> c4 ist aktiv
*****
NONCE request (c6)
c4 ok
c5
*****
Paket mit NONCE c4 angekommen -> c5 ist aktiv
*****
NONCE request (c7)
c5 ok
c6
c6 ok
c7
NONCE request (c8)
c7 ok
c8
*****
Paket mit NONCE c5 angekommen -> c8 ist aktiv
*****
CENTRAL_SCENE
NONCE request (c9)
c8 ok
c9
*****
Paket mit NONCE c8 angekommen -> c9 ist aktiv
*****
c9 ok
ca
*****
Paket mit NONCE c9 angekommen -> ca ist aktiv
*****
ca ok
cb
*****
Paket mit NONCE ca angekommen -> cb ist aktiv
*****
cb ok
*****
Paket mit NONCE ca NOCHMAL angekommen -> cb ist aktiv, keine NONCE vorhanden
*****
cc
CENTRAL_SCENE
CAN received (for cc?)
CENTRAL_SCENE
no ACK for cc
cc erneut versendet (wg. CAN)
CENTRAL_SCENE
cc ok
*****
Paket mit passender NONCE cc angekommen, Ablauf sollte jetzt wieder stimmen...
*****
cd
NONCE request (ce)
CENTRAL_SCENE
cd ok
ce
*****
Paket mit NONCE cd angekommen -> ce ist aktiv, Ablauf wieder gestört...
*****
*****
Paket mit NONCE cd noch mal angekommen -> ce ist aktiv
*****
NONCE request (cf)
ce ok
cf


Im letzten Teil kommt es dann zu einem no response was ein ZWDongle_shiftSendStack auslöst, hier liegt die zuletzt verschickte "d1" NONCE noch auf dem Stack (und sollte mMn. auch entfernt werden)
Dann kommen wieder jede Menge Signale von der Fernbedienung und ein no ACK für die d1 NONCE.
Dann kommt ein neuer NONCE request (d2), die Nonce wird aber letztendlich nicht gesendet da der Stack klemmt.
Nach Ablauf des Timers wird SecUnlock aufgerufen, d1-NONCE und d2-NONCE liegen auf dem Stack,
Nächster NONCE-request (d3), selbes Spiel, danach liegen d1,d2,d3-NONCE auf dem Stack.


*****
Paket mit NONCE ce angekommen -> cf ist aktiv
*****
CENTRAL_SCENE
NONCE request (d0)
cf ok
d0
*****
Paket mit NONCE cf angekommen -> d0 ist aktiv
*****
NONCE request (d1)
CENTRAL_SCENE
d0 ok
d1
*****
Paket mit NONCE d0 angekommen -> d1 ist aktiv
*****
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
(was hat an dieser Stelle ZWDongle_shiftSendStack ausgelöst, no response?)
d1 NONCE liegt auf SendStack
2016.12.01 22:24:54 1: DEBUG: Dumping hash in ZWDongle_shiftSendStack: $VAR1 = {
*****
'SendStack' => [
'011100132c0a9880d123839fb30c495f25d273'
],
*****
2016.12.01 22:24:54 1: DEBUG: SendStack after shift (txt: no response from device): $VAR1 = [];
2016.12.01 22:24:54 4: no response from device, removing 011100132c0a9880d123839fb30c495f25d273 from dongle sendstack
no response
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
no ACK for CB:d2 -> 2016.12.01 22:24:52 5: SW: 011100132c0a9880d123839fb30c495f25d273
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
CENTRAL_SCENE
NONCE request (d2)
*****
secUnlock, d2 NONCE wurde nicht geschrieben
2016.12.01 22:25:34 1: HASH DUMP in secUnlock before calling secEnd(): $VAR1 = {
*****
*****
'sentset:132c0a9880d123839fb30c495f25d2',
'set:132c0a9880d24c2ec20d99ed8625d3'
*****
NONCE request (d3)
2016.12.01 22:25:42 3: ZWave_SENSOR_NOTIFICATION_44: secStart older than 6 seconds detected, secUnlock will call Zwave_secEnd
*****
secUnlock, d2 NONCE wurde nicht geschrieben
2016.12.01 22:25:42 1: HASH DUMP in secUnlock before calling secEnd(): $VAR1 = {
*****
*****
'sentset:132c0a9880d123839fb30c495f25d2',
'set:132c0a9880d24c2ec20d99ed8625d3',
'set:132c0a9880d3147bc03a3d8e3125d4'
*****


Es scheint das bei dem ZWDongle_shiftSendStack Aufruf was schief läuft und der Befehl nicht vom Stack entfernt wird. Ich war eigentlich der Meinung das im Hintergrund auch ein Timer werkelt der dort aufräumt, evtl. kommt auch Timer aus dem Tritt...

Mein resumeé ist momentan folgendes:
- die gesendeten NONCE in einer Liste aufbewaren
- nur neue NONCE erzeugen die sich in der ersten Stelle unterscheiden um eindeutig zu bleiben
- benutzte NONCE aus der Liste entfernen
- über time alte, unbenutze NONCE aus der Liste entfernen

Den Fehler im Ablauf mit dem Stack müssen wir irgendwie anders finden.

Gruß,
Andreas
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

A.Harrenberg

#43
Hi Thomas,

könntest Du bitte mal die angehängte 10_ZWave.pm ausprobieren?

Darin habe ich prinzipiell das gesagte aus dem vorherigen Post umgesetzt:
Zitat
- die gesendeten NONCE in einer Liste aufbewaren
- nur neue NONCE erzeugen die sich in der ersten Stelle unterscheiden um eindeutig zu bleiben
- benutzte NONCE aus der Liste entfernen
- über time alte, unbenutze NONCE aus der Liste entfernen
Allerdings habe ich keinen Timer eingebaut sondern prüfe das einfach vor jedem zurückholen einer Nonce. D.h. wenn sie alt ist wird sie vorher weggeworfen. Die Spezifikation sieht hier Timer zwischen 3 und 20 Sekunden vor, ich habe mich an die Empfehlung 10 sekunden gehalten.

Das sollte die Kommunikation deutlich robuster machen und stellt auch keine Verschlechterung der Sicherheit dar. Dieses asynchrone Pong-Ping sollte damit kein Problem mehr darstellen. Wenn am Ende ein paar NONCE "übrigbleiben" werden die einfach bei nächsten Befehl wieder entfernt.

Wenn das bei Dir wirkt würde ich das gerne schon mal offiziell bei Rudi abgeben, das Problem mit dem SendStack haben wir dann zwar immer noch nicht gefunden. Hierzu müssten wir uns wohl mal auf die Behandlung des Stacks konzentrieren. Ich kann mir höchtens vorstellen das eine normale Aktion aus dem Ablauf und der no_ACK Timer sich irgendwie in die Quere kommen und dann was undefiniertes dabei rauskommt.

Gruß,
Andreas

EDIT: Anhang gelöscht da fehlerhaft... ,-( Update kommt gleich...
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY

A.Harrenberg

Hi,

so, jetzt mit neuem Anhang...

Da ich noch recht viele unfertige Änderungen bei mir drin habe kann ich meine Datei nicht einfach weitergeben und muss die "richtigen" Änderungen da rausfiltern. Dabei ist mir eben ein kleiner Fehler unterlaufen der in einigen hundert Zeilen Fehlermeldungen beim Start von FHEM endete... ,-(

Sollte jetzt aber funktionieren, habe es noch mal quergetestet.

Gruß,
Andreas.
FB 7360, Homematic und ZWave
Support for ZWave-SECURITY