Double ACK causes Block transfer to send duplicate messages

[ErikssonM]

Description

This is a bug which has been observed in crowded network conditions when doing large block transfers. It happens with a node-coap client (using Agent) when the server ACKs a block N after the client already sent a retransmission. Both the original ACK and the ACK of the retransmission will cause the client to send block N+1.

sequenceDiagram
    participant C as Client
    participant S as Server
    
    C->>S: Block N
    
    C->>S: Block N [Retransmission]
    
    S-->>C: ACK Block N
    
    S-->>C: ACK Block N
    
    C->>S: Block N + 1
    
    C->>S: Block N + 1

Loading

Reproduction

Below is a reproduction of the bug. The server will not send the ACK of block 5 until it received the retransmission of block 5, then it sends both. Note that the same behavior can happen while the original ACK is in flight which is the case we originally observed.

client.js:

const coap = require('coap');
const { createSocket } = require('node:dgram');

const port = 5683;
const socket = createSocket({ type: 'udp4' });
const agent = new coap.Agent({
    socket
});
const req = agent.request({
    host: 'localhost',
    port,
    method: 'PUT',
    options: {
        'Block1': Buffer.of(0x2)
    }
});

req.on('response', (res) => {
    console.log('Handled response');
});
req.on('timeout', () => {
    console.log('timeout');
});
req.on('error', () => {
    console.log('error');
});

const buf = Buffer.alloc(1024, '__Repeated_Content__');

req.end(buf);

server.js:

const { createSocket } = require('node:dgram');
const { parse, generate } = require('coap-packet');

function generateBlockOption (blockState) {
    const num = blockState.num
    const more = blockState.more
    const size = blockState.size
    let buff = Buffer.alloc(4)
    const value = (num << 4) | (more << 3) | (size & 7)
    buff.writeInt32BE(value)
    if (num >= 4096) {
        buff = buff.slice(1, 4)
    } else if (num >= 16) {
        buff = buff.slice(2, 4)
    } else {
        buff = buff.slice(3, 4)
    }
    return buff
}


function parseBlockOption (buff) {
    const TwoPowTwenty = 1048575;
    if (buff.length === 1) {
        buff = Buffer.concat([Buffer.alloc(3), buff]);
    } else if (buff.length === 2) {
        buff = Buffer.concat([Buffer.alloc(2), buff]);
    } else if (buff.length === 3) {
        buff = Buffer.concat([Buffer.alloc(1), buff]);
    } else {
        throw new Error(`Invalid block option buffer length. Must be 1, 2 or 3. It is ${buff.length}`);
    }
    const value = buff.readInt32BE();
    const num = (value >> 4) & TwoPowTwenty;
    const more = (value & 8) === 8 ? 1 : 0;
    const size = value & 7;

    return {
        num,
        more,
        size
    };
}

const server = createSocket('udp4');
const port = 5683;

// On block 5, wait for the retransmission, then send the ack for the original message
// This simulates a retransmission being triggered while the ack is in flight
const triggerBugOnNum = 5;
let delayedAck = undefined;

server.on('message', (msg, rinfo) => {
    const packet = parse(msg);
    const blockState = parseBlockOption(packet.options[0].value);
    console.log(`Client sent block num ${blockState.num}`);

    const ack = generate({
        ack: true,
        messageId: packet.messageId,
        options: [
           { name: 'Block1', value: generateBlockOption(blockState) } 
        ],
        code: '2.05',
        token: packet.token
    });

    if (blockState.num === triggerBugOnNum && delayedAck === undefined) {
        // Save ack
        console.log('Saving ack');
        delayedAck = ack;
        return;
    } else if (blockState.num === triggerBugOnNum && delayedAck !== undefined) {
        // Send delayed ack before real ack
        console.log('Sending delayed ack');
        server.send(delayedAck, rinfo.port, rinfo.address);
        delayedAck = undefined;
    }
    server.send(ack, rinfo.port, rinfo.address);
});

server.on('listening', () => {
    const address = server.address();
    console.log(`Server listening ${address.address}:${address.port}`);
});

server.on('error', (err) => {
    console.error(`server error:\n${err.stack}`);
    server.close();
});

server.bind(port);

Output from server when running repro:

Server listening 0.0.0.0:5683
Client sent block num 0
Client sent block num 1
Client sent block num 2
Client sent block num 3
Client sent block num 4
Client sent block num 5
Saving ack
Client sent block num 5
Sending delayed ack
Client sent block num 6
Client sent block num 6
Client sent block num 7
Client sent block num 7
Client sent block num 8
Client sent block num 8
Client sent block num 9
Client sent block num 9
Client sent block num 10
Client sent block num 10
Client sent block num 11
Client sent block num 11
Client sent block num 12
Client sent block num 12
Client sent block num 13
Client sent block num 13
Client sent block num 14
Client sent block num 14
Client sent block num 15

Notice that every message beyond 5 is sent twice.

[Apollon77]

did you tried running your repro with "DEBUG=*" to get more internal details?

[ErikssonM]

From my own investigations, the second "chain" of blocks seems to be caused by this call to SegmentedTransmission.resendPreviousPacket.

https://github.com/coapjs/node-coap/blob/d012d1a4d4412ee0183d2695b63930f8ef13dd46/lib/agent.ts#L245C1-L247C22

The following diff fixes the issue for the application I'm working on:

diff --git a/lib/agent.ts b/lib/agent.ts
index 10ade18..5569690 100644
--- a/lib/agent.ts
+++ b/lib/agent.ts
@@ -234,6 +234,11 @@ class Agent extends EventEmitter {
                         req._packet.messageId = this._nextMessageId()
                         this._msgIdToReq.set(req._packet.messageId, req)
                         segmentedSender.receiveACK(block1)
+                    } else if (segmentedSender.isPreviousACK(block1)) {
+                        // The received ACK is a response to a previous messageId.
+                        // This can happen if a block transmission is retried
+                        // and the server ACKs both messages.
+                        return
                     } else {
                           segmentedSender.resendPreviousPacket()
diff --git a/lib/segmentation.ts b/lib/segmentation.ts
index 488d650..1f33e51 100644
--- a/lib/segmentation.ts
+++ b/lib/segmentation.ts
@@ -62,6 +62,10 @@ export class SegmentedTransmission {
         return retBlockState.num === this.blockState.num// && packet.code == "2.31"
     }
 
+    isPreviousACK (retBlockState: Block): boolean {
+        return retBlockState.num < this.blockState.num
+    }
+
     resendPreviousPacket (): void {
         if (this.resendCount < 5) {
             this.currentByte = this.lastByte

I'm not sure resendPreviousPacket should ever be called from this context, I can't think of a situation.

One could also argue that the server is misconfigured, and should not ACK blocks that have already been received. I couldn't find any info on what behavior is correct in the RFC.