genielabs / zwave-lib-dotnet

Z-Wave Home Automation library for .NET / Mono
Apache License 2.0
63 stars 37 forks source link

ParseSerialBuffer() cannot handle receipt of a fragmented ACK #47

Open PK-Moore opened 1 year ago

PK-Moore commented 1 year ago

I recently upgraded my HomeGenie from a Pi2 to a faster Pi4, while continuing to use an old Aeon stick as the controller. This has resulted in many more fragmented Zwave frames. SOF frames are handled ok, but if an ACK is fragmented, the code incorrectly handles it, as follows. A normal ACK frame is traced as 06-01-04-01-13-01-E8.

2022-12-25 07:59:21.2557 Trace [[[ BEGIN REQUEST ]]] 2022-12-25 07:59:21.2557 Trace WaitAck 2022-12-25 07:59:21.2557 Trace Sending Message (Node=39 2022-12-25 07:59:21.2557 Debug 01-0E-00-13-27-07-60-0D-00-02-25-01-00-05-3B-B7 2022-12-25 07:59:21.2630 Debug 06-01-04 // Start of ACK 2022-12-25 07:59:21.2630 Debug ZWaveMessage (RawData=01-04) 2022-12-25 07:59:21.2630 Debug ZWaveMessage (Direction=Inbound 2022-12-25 07:59:21.2630 Debug 15 2022-12-25 07:59:21.2630 Warn Bad message checksum 2022-12-25 07:59:21.2630 Debug 01-13-01-E8 // Remainder of ACK 2022-12-25 07:59:21.2630 Trace Expected message length is 21 2022-12-25 07:59:21.3637 Debug 01-04-01-13-01-E8 2022-12-25 07:59:21.3637 Trace Merged buffer to message: 01-13-01-E8-01-04-01-13-01-E8 2022-12-25 07:59:21.3637 Trace Expected message length is 21 2022-12-25 07:59:22.7655 Debug 01-04-01-13-01-E8 2022-12-25 07:59:22.7655 Trace Merged buffer to message: 01-13-01-E8-01-04-01-13-01-E8-01-04-01-13-01-E8

In fact the logic in ParseSerialBuffer() looks very strange.

PK-Moore commented 1 year ago

On further study the logic looks less strange and I think the fix is actually very simple. The response following the ACK byte needs to drop through to the logic that assembles fragmented messages and ultimately calls ProcessMessage() near the end of ParseSerialBuffer().

Line 1333

Line 1335

Can someone confirm this looks good? I don't want to break fundamental ZWave operation.

PK-Moore commented 1 year ago

The above fix is not sufficient. I have been testing the following re-write for the past week or so and it seems solid for all branches (except NAK which don't occur on my system, and in any event aren't handled by ProcessMessage. It's also much clearer as to how each message type is dealt with. What do you think? Maybe too many trace statements, but they've been helpful to track code coverage during my testing. Pat

    /// <summary>
    /// Parses the data buffer coming from the serial port.
    /// </summary>
    /// <param name="message">raw bytes data.</param>
    private void ParseSerialData(byte[] message)
    {
        if (serialBuffer != null)
        {
            byte[] merged = new byte[serialBuffer.Length + message.Length];
            Array.Copy(serialBuffer, 0, merged, 0, serialBuffer.Length);
            Array.Copy(message, 0, merged, serialBuffer.Length, message.Length);
            message = merged;
            serialBuffer = null;
            Utility.Logger.Trace("Parse: Merged buffer to message: {0}", BitConverter.ToString(message));
        }

        // Split serial data into correct length ZWave messages
        byte[] nextMessage = null;
        FrameHeader header = (FrameHeader)((int)message[0]);
        if (header == FrameHeader.SOF)
        {
            int msgLength = message.Length > 1 ? (int)message[1] + 2 : 2;
            int extraLength = message.Length - msgLength;
            if (extraLength != 0)  // ==0 is most common, so test it first
            {
                if (extraLength > 0)
                {
                    // To long, split into two
                    nextMessage = new byte[extraLength];
                    Array.Copy(message, msgLength, nextMessage, 0, extraLength);
                    byte[] tmpmsg = new byte[msgLength];
                    Array.Copy(message, 0, tmpmsg, 0, msgLength);
                    Utility.Logger.Trace("Parse: Split message into length {0} and {1}", msgLength, extraLength);
                    message = tmpmsg;
                }
                else
                {
                    // Too short, wait for more
                    serialBuffer = new byte[message.Length];
                    Array.Copy(message, 0, serialBuffer, 0, serialBuffer.Length);
                    Utility.Logger.Trace("Parse: Expected message length is {0}, currently received length is {1}", msgLength, message.Length);
                    message = null;
                }
            }
        }

        else if ((header == FrameHeader.ACK) || (header == FrameHeader.NAK))
        {
            if (message.Length > 1)
            {
                nextMessage = new byte[message.Length - 1];
                Array.Copy(message, 1, nextMessage, 0, nextMessage.Length);
            }
            Utility.Logger.Trace("Parse: ACK length: {0}", message.Length);
            message = null;  // Discard the ACK
        }

        else if (header == FrameHeader.CAN)
        {
            if (message.Length > 1)
            {
                nextMessage = new byte[message.Length - 1];
                Array.Copy(message, 1, nextMessage, 0, nextMessage.Length);
            }
            Utility.Logger.Trace("Parse: CAN length: {0}", message.Length);
            message = new byte[] { message[0] };  // Process the CAN
        }

        try
        {
            if (message != null)
            {
                // We have a correct length ZWave message
                ProcessMessage(new ZWaveMessage(message, MessageDirection.Inbound));
            }
        }
        catch (Exception e)
        {
            Utility.Logger.Error(e);
        }

        if (nextMessage != null)
        {
            // The next message may not be the correct length
            // TODO: Check out possible recursion loops
            ParseSerialData(nextMessage);
        }
    }