History stream errors for encrypted hypercores

Question

History stream errors for encrypted hypercores

Closed this issue 2 years ago · 6 comments

Nuhvi commented 2 years ago

This one is puzzling, to say the least. at the end of this issue, you can find an isolated test to replicate it.

NOTE: the same errors occur when using this PR of Hypercore.

none of the following issues occur if you comment line 9 to disable encryption.

What I am trying to achieve

Listen to a Hyperbee's feed, and log the changed key whenever the feed emits append event:

clone.on('append', async () => {
   // Check that the clone is setup correctly
    console.log({
      name,
      valid:
        cloneDB.feed.peers.length > 0 &&
        (encryptionKey ? !!cloneDB.feed.encryption : true),
    });

    const stream = cloneDB.createHistoryStream({
      reverse: true,
      limit: 1,
    });

    stream?.on('data', (data) => console.log('Data at: ' + name, data));
    stream?.on('error', (err) =>
      console.log('Error at: ' + name + ':\n', err),
    );
});

What happens

There are two cases:
1- Replicating an encrypted Hyperbee and creating a HistroyStream whenever the core emits append.
Two errors are thrown then it works fine :

{ name: 'ONE', valid: true }
{ name: 'ONE', valid: true }
Error at: ONE:
 TypeError: Cannot read properties of undefined (reading 'keys')
    at BlockEntry.getTreeNode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:253:37)
    at HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:50)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HistoryIterator.open (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/iterators/history.js:16:5)
Error at: ONE:
 Error: Groups are not supported
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:29:13)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:469:18)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:416:21)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:432:14)
    at Hypercore._decode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:789:23)
    at Hypercore._decryptAndDecode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:630:24)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HyperBee.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:354:21)
    at async Batch.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:525:9)
    at async HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:13)
{ name: 'ONE', valid: true }
Data at: ONE { type: 'put', seq: 2, key: 'foo', value: 'update number: 1' }
{ name: 'ONE', valid: true }
Data at: ONE { type: 'put', seq: 3, key: 'foo', value: 'update number: 2' }

2- It gets worse if I try to do the same for two Hyperbees from the same Hypercore (literally the same object or two sessions of the same core), all logs are errors, here is an example:

{ name: 'ONE', valid: true }
{ name: 'TWO', valid: true }
{ name: 'ONE', valid: true }
{ name: 'TWO', valid: true }
Error at: TWO:
 RangeError: Could not decode varint
    at Object.read [as decode] (/Users/ward/code/play/hyperbee-tests/node_modules/varint/decode.js:17:13)
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:24:24)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:232:18)
    at new Pointers (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:36:29)
    at inflate (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:67:10)
    at BlockEntry.getTreeNode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:249:20)
    at HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:50)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HistoryIterator.open (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/iterators/history.js:16:5)
Error at: ONE:
 Error: Groups are not supported
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:29:13)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:469:18)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:416:21)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:432:14)
    at Hypercore._decode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:789:23)
    at Hypercore._decryptAndDecode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:630:24)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HyperBee.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:354:21)
    at async Batch.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:525:9)
    at async HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:13)
Error at: ONE:
 RangeError: Could not decode varint
    at Object.read [as decode] (/Users/ward/code/play/hyperbee-tests/node_modules/varint/decode.js:17:13)
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:24:24)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:232:18)
    at new Pointers (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:36:29)
    at inflate (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:67:10)
    at BlockEntry.getTreeNode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:249:20)
    at HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:50)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HistoryIterator.open (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/iterators/history.js:16:5)
Error at: TWO:
 Error: Groups are not supported
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:29:13)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:469:18)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:416:21)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:432:14)
    at Hypercore._decode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:789:23)
    at Hypercore._decryptAndDecode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:630:24)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HyperBee.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:354:21)
    at async Batch.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:525:9)
    at async HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:13)
{ name: 'ONE', valid: true }
{ name: 'TWO', valid: true }
Error at: TWO:
 TypeError: Cannot read properties of undefined (reading 'keys')
    at BlockEntry.getTreeNode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:253:37)
    at HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:50)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HistoryIterator.open (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/iterators/history.js:16:5)
Error at: ONE:
 Error: Groups are not supported
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:29:13)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:469:18)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:416:21)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:432:14)
    at Hypercore._decode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:789:23)
    at Hypercore._decryptAndDecode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:630:24)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HyperBee.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:354:21)
    at async Batch.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:525:9)
    at async HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:13)
{ name: 'ONE', valid: true }
{ name: 'TWO', valid: true }
Error at: TWO:
 TypeError: Cannot read properties of undefined (reading 'keys')
    at BlockEntry.getTreeNode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:253:37)
    at HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:50)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HistoryIterator.open (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/iterators/history.js:16:5)
Error at: ONE:
 Error: Decoded message is not valid
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:446:39)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:416:21)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:432:14)
    at Hypercore._decode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:789:23)
    at Hypercore._decryptAndDecode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:630:24)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HyperBee.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:354:21)
    at async Batch.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:525:9)
    at async HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:13)
    at async HistoryIterator.open (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/iterators/history.js:16:5)
{ name: 'ONE', valid: true }
{ name: 'TWO', valid: true }
Error at: TWO:
 Error: Unknown wire type: 7
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:35:9)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:232:18)
    at new Pointers (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:36:29)
    at inflate (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:67:10)
    at BlockEntry.getTreeNode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:249:20)
    at HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:50)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HistoryIterator.open (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/iterators/history.js:16:5)
Error at: ONE:
 Error: Unknown wire type: 6
    at exports.skip (/Users/ward/code/play/hyperbee-tests/node_modules/protocol-buffers-encodings/index.js:35:9)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/lib/messages.js:469:18)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:416:21)
    at Object.decode (/Users/ward/code/play/hyperbee-tests/node_modules/compact-encoding/index.js:432:14)
    at Hypercore._decode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:789:23)
    at Hypercore._decryptAndDecode (/Users/ward/code/play/hyperbee-tests/node_modules/hypercore/index.js:630:24)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async HyperBee.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:354:21)
    at async Batch.getBlock (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:525:9)
    at async HyperBee.getRoot (/Users/ward/code/play/hyperbee-tests/node_modules/hyperbee/index.js:342:13)

I am happy to offer any more context if needed.

Here is the code to replicate this bug:

import Corestore from 'corestore';
import Hyperbee from 'hyperbee';
import RAM from 'random-access-memory';

let key;
let originStore;

let encryptionKey;
// Commenting next line will resolve all issues
encryptionKey = Buffer.alloc(32, 'hello world');

{
  const store = new Corestore(RAM);

  const origin = store.get({
    name: 'origin',
    encryptionKey,
  });
  await origin.ready();

  const originDB = new Hyperbee(origin, {
    keyEncoding: 'utf8',
    valueEncoding: 'utf8',
  });

  let count = 0;
  setInterval(() => originDB.put('foo', 'update number: ' + count++), 1000);

  key = origin.key;
  originStore = store;
}

{
  const store = new Corestore(RAM);

  const s = store.replicate(true);
  s.pipe(originStore.replicate(false)).pipe(s);

  await test('ONE');
  // Try commenting next line
  await test('TWO');

  async function test(name) {
    const clone = store.get({
      key: key,
      encryptionKey,
    });
    await clone.update();

    const cloneDB = new Hyperbee(clone, {
      keyEncoding: 'utf8',
      valueEncoding: 'utf8',
    });

    clone.on('append', async () => {
      // Check that the clone is setup correctly
      console.log({
        name,
        valid:
          cloneDB.feed.peers.length > 0 &&
          (encryptionKey ? !!cloneDB.feed.encryption : true),
      });

      const stream = cloneDB.createHistoryStream({
        reverse: true,
        limit: 1,
      });

      stream?.on('data', (data) => console.log('Data at: ' + name, data));
      stream?.on('error', (err) =>
        console.log('Error at: ' + name + ':\n', err),
      );
    });
  }
}

package.json

{
  "type": "module",
  "dependencies": {
    "corestore": "^6.0.1-alpha.17",
    "hyperbee": "^1.8.3",
    "random-access-memory": "^4.1.0"
  }
}

Answer 1 · 2022-05-24T08:31:01.000Z

Doesn't look like a Hyperbee bug, seems it's just getting encrypted blocks (due to some bug) which makes Hyperbee throw (as it should)

Answer 2 · 2022-05-24T08:34:36.000Z

That makes sense, but I made sure that I check the validity of Hypercores every time in on('append') and the encryption seems to be fine. Moreover, catching these errors at #53, resulted in the correct behavior, meaning, that it didn't stop the decrypted blocks and valid history to be fetched correctly.

If you know where should I look next I would be happy to follow that lead instead of #53

Answer 3 · 2022-05-24T11:06:49.000Z

Having multiple, inflight replicator requests for the same encrypted block results in a bug as the block is then decrypted multiple times: https://github.com/hypercore-protocol/hypercore-next/blob/b113b082e087f0ea796e7dc163862ddf3a5d61dc/test/encryption.js#L173-L186

Answer 4 · 2022-05-24T11:19:02.000Z

@kasperisager nice catch, can you capture that in a hypercore test?

Answer 5 · 2022-05-24T11:21:06.000Z

@mafintosh That is a Hypercore test 😄 Opened a draft PR as well: hypercore-protocol/hypercore-next#105

Answer 6 · 2022-05-24T14:27:10.000Z

The example code works on my end with the changes from the above PR ☝️