Ganache-cli: Error: LevelUpArrayAdapter named 'blockLogs' index out of range

[jtremback]

I get this error when running tests. It goes away for a little while after restarting testrpc.

I am on a MacBook with node 8.1.3, with testrpc 4.0.1

If you want to reproduce this, clone https://github.com/jtremback/guac and run npm run test a few times.

[cryptofuture]

Have the same issue.

LevelUpArrayAdapter named 'blockLogs' index out of range: index 11; length: 11

I happens after truffle test goes to the next test, on testrpc reverting to snapshot #1
I can run tests separately without any problem, but when I run all three one after etch other, all is bloody red.

[alex-miller-0]

Same issue here between tests. Individual tests are fine.

[jtremback]

I thought it was because of the snapshotting at first, but I tried it without and it still seemed to be happening. But maybe I was mistaken. Has anyone experienced this without snapshotting?

[mikeshultz]

Version:

EthereumJS TestRPC v4.0.1 (ganache-core: 1.0.1)

Confirmed on 4.0.0 and 3.9.2. Tried to go back further, but... npm. Perhaps an upgraded dependency?

Snippet from debug logs:

SHA3
DUP2
SWAP1
SSTORE
JUMPDEST
JUMPDEST
POP
POP
JUMP
JUMPDEST
STOP

  Transaction: 0x7d677dca77f851068c6cb85fbfdcfb3a0c4f2274218c4e8f54332a1ceb1e98c3
  Gas usage: 43544
  Block Number: 15
  Block Time: Sun Jul 16 2017 22:29:28 GMT-0600 (MDT)

eth_getTransactionReceipt
Error: LevelUpArrayAdapter named 'blockLogs' index out of range: index 15; length: 15
    at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97358:23
    at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97332:5
    at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97778:12
    at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97543:19
    at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:100234:7
    at _combinedTickCallback (internal/process/next_tick.js:95:7)
    at process._tickCallback (internal/process/next_tick.js:161:9)
eth_call
eth_getLogs
eth_blockNumber
eth_call
eth_call
eth_getLogs
eth_getFilterChanges
evm_revert
Reverting to snapshot #1
evm_snapshot
Saved snapshot #1
eth_blockNumber

[mikeshultz]

errr... scratch that. Once I removed /usr/local/lib/npm_modules and started from scratch, 3.9.2 did not show this error.

EDIT: Nope, got it again with 3.9.2... odd

[Ankarrr]

Im using TestRPC v4.0.1. I also see the error log when I run test.

But I restart TestRPC when I see the error log every time and then it will work fine...

[mikeshultz]

Restarting does not help with me. I am also seeing this error in the docker container, so it's not just my local system. It appears as though it's being thrown during an RPC InvalidResponse error.

Though the error does seem intermittent, since 1 out of every 50 seems to work in my case. The error seems to be thrown every time after a call to eth_getTransactionReceipt. I haven't seen any other calls cause it.

[travs]

I'm also getting this on 4.0.1 and 3.9.2.

Reproduce:

• Clone this branch
• unskip these two tests
• npm install
• run testrpc, then npm test

[patrickgorrell]

Started getting a weird issue today when I ran a clean install and not sure if it’s a known issue from the popup logs.

popup.js:80367 Error: LevelUpArrayAdapter named 'blocks' index out of range: index 4068832; length: 7
    at /Users/.nvm/versions/node/v8.1.3/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97358:23
    at /Users/.nvm/versions/node/v8.1.3/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97332:5
    at /Users/.nvm/versions/node/v8.1.3/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97778:12
    at /Users/.nvm/versions/node/v8.1.3/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97543:19
    at /Users/.nvm/versions/node/v8.1.3/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:100234:7
    at _combinedTickCallback (internal/process/next_tick.js:95:7)
    at process._tickCallback (internal/process/next_tick.js:161:9)

truffle / testrpc on initial load on Node 8.1.3, Testrpc, Mac OSX Chrome Latest.

[jdkanani]

Same issue.

[patrickgorrell]

I fixed it for now... Here is how I did it.

I was using Metamask w/ truffle. I was able to resolve the issue but first:

$ npm uninstall -g ethereumjs-testrpc
$ npm install -g ethereumjs-testrpc
$testrpc

Go to chrome -> Right click on metamask -> Manage Extension -> scroll to metamask -> click "Bakcground Image" blue link -> refresh the inspector that is opened (cmd+r on mac).

I was logged out of Metamask. I logged back in and the problem was resolved.

See: https://github.com/MetaMask/faq/blob/master/LOGS.md#background-logs-chrome

Background Logs in chrome -> Refresh the inspector

[ghanshaw]

I also get the same problem when I use testrpc and MetaMask. When I try to send transactions, the popup hangs and I see the error in the console. But sometimes, the popup hangs and I won't see any error in the console. Not sure how I should proceed--I can't even reliably get the same error message...

[mikeshultz]

Every time the error occurs, this is what I'm getting from some debug statements. For me, it always seems to happen during the RPC call eth_call, but not for every one of them. At some point when it occurs once, it happens with every subsequent call. Because of how intermittent this is, it feels very much like a race condition.

server.request.body: {"jsonrpc":"2.0","id":54,"method":"eth_getTransactionReceipt","params":["0x0eb8d1e056b1e84fb00b6edd0c70ccb6261f21bc9e440b82686326fed2a302ef"]}
LevelUpArrayAdapter.get(8)
LevelUpArrayAdapter.get(8)
LevelUpArrayAdapter.length == 9
LevelUpArrayAdapter.length == 9
{ id: 54,
  jsonrpc: '2.0',
  result: 
   { transactionHash: '0x0eb8d1e056b1e84fb00b6edd0c70ccb6261f21bc9e440b82686326fed2a302ef',
     transactionIndex: '0x00',
     blockHash: '0xcbffddd5f238c860133c3a15e219264bd1b4141f1446cb7d863f21e7a12e7c4d',
     blockNumber: '0x09',
     gasUsed: '0x030488',
     cumulativeGasUsed: '0x030488',
     contractAddress: null,
     logs: [] } }
server.request.body: {"jsonrpc":"2.0","id":55,"method":"eth_blockNumber","params":[]}
BlockchainDouble.getHeight(): 8
{ id: 55, jsonrpc: '2.0', result: '0x08' }
server.request.body: {"jsonrpc":"2.0","id":56,"method":"eth_call","params":[{"from":"0x54942de713d679efd97b8b3c5203e190b9b92f71","gas":"0x47e7c4","gasPrice":"0x174876e800","to":"0x64b9889865a89c40ff049fe5cec1f1568f46c5db","data":"0x32648e0900000000000000000000000049fb5e93463322cdde82f2ba1860a7df25d9f4b7"},"latest"]}
LevelUpArrayAdapter.get(9)
LevelUpArrayAdapter.get(9)
LevelUpArrayAdapter.length == 9
{ id: 56,
  jsonrpc: '2.0',
  result: undefined,
  error: 
   { message: 'Error: LevelUpArrayAdapter named \'blocks\' index out of range: index 9; length: 9\n    at /home/mike/dev/ganache-core/lib/database/leveluparrayadapter.js:52:23\n    at /home/mike/dev/ganache-core/lib/database/leveluparrayadapter.js:25:5\n    at /home/mike/dev/ganache-core/node_modules/level-sublevel/shell.js:102:12\n    at /home/mike/dev/ganache-core/node_modules/level-sublevel/nut.js:122:19\n    at /home/mike/dev/ganache-core/node_modules/cachedown/index.js:53:7\n    at _combinedTickCallback (internal/process/next_tick.js:131:7)\n    at process._tickDomainCallback (internal/process/next_tick.js:218:9)',
     code: -32000 } }

I'll continue to dig further but maybe someone more familiar with the codebase would recognize a bug faster than I.

EDIT: If I had to guess, this is probably a problem in web3-provider-engine.

[patrickgorrell]

@ghanshaw did you try my solution? I was having the exact same problem...

[egortsaryk9]

I had the same problem. @pvader 's steps helped me to get Metamask working, thanks

[jtremback]

Tried uninstalling and reinstalling, but it still happens.

[arpankotecha]

I'm having the same issue as well with TestRPC v4.0.1. It just started all of a sudden. Been running it without issues for a month. Not sure what might have triggered this. I've tried uninstall and reinstalling but that didn't help. I don't have metamask installed so that seems unrelated. Here's my trace.

 Error: Error: LevelUpArrayAdapter named 'blocks' index out of range: index 231; length: 231
at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97358:23
at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97332:5
at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97778:12
at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:97543:19
at /usr/local/lib/node_modules/ethereumjs-testrpc/build/cli.node.js:100234:7
at _combinedTickCallback (internal/process/next_tick.js:95:7)
at process._tickCallback (internal/process/next_tick.js:161:9)

[patrickgorrell]

@arpankotecha did you try my solution above? I fixed that same issue as stated above.

[patrickgorrell]

@jttemback try my steps above. It should work.

[arpankotecha]

Hi @pvader I tried the first half of the solution (kill testrpc, uninstall testrpc, install testrpc, start testrpc). The second part did not apply as I don't have metamask. Unfortunately the problem still persisted. I also upgraded both testrpc and truffle to the latest version. No luck.

[jtremback]

@pvader Also not using metamask, also reinstalled testrpc, still not working.

[arpankotecha]

Looks like a line in my truffle test is corrupting the db. I've gotten around it by supplying a path to the db on the command line:
mkdir logs; testrpc --db logs

When i encounter the error, I rm -r logs; mkdir logs and restart testrpc. Ofcourse this only works after I've commented out the offending line of code in my test:
assert.strictEqual(price, initiaPrice, "")

Not sure why that would corrupt the db. But my tests pass now and allows me to proceed with the project.

[mikeshultz]

@arpankotecha wow, nice find. For me, creating a new db directory allows my tests to go through just fine. Deleting and recreating that directory does not prevent all of my subsequent tests from failing with this error. So if I just create a new directory in /tmp every time I run my tests, they pass.

How odd.

EDIT: That appears to have only worked temporarily.

[dpilch]

I had this issue when I forgot to return promises in my test cases. Haven't run into the issue again after that.

[mikeshultz]

No matter how bad you screw up your tests, this is still throwing an internal testrpc error that appears to be caused during eth_call.

Right before the error on eth_call, this is what I'm seeing from internal calls:

eth_getBlockByNumber: latest(9)
eth_blockNumber: 8
eth_getBlockByNumber: latest(9)

The 9 is coming from block.header.number in GethApiDouble.eth_getBlockByNumber, not !blocks!length in the DB. It appears there's an evm_revert call before all this goes down, which does properly update !blocks!length but perhaps the next created block causes that length count and the actual block number to become out of sync?

Though in the DB on disk, it appears okay.

$ ls -lah /tmp/wat/\!blocks*
-rw-r--r-- 1 mike mike 1.3K Aug  8 13:22 /tmp/wat/!blocks!0
-rw-r--r-- 1 mike mike 2.4K Aug  8 13:22 /tmp/wat/!blocks!1
-rw-r--r-- 1 mike mike 1.6K Aug  8 13:22 /tmp/wat/!blocks!2
-rw-r--r-- 1 mike mike 7.8K Aug  8 13:22 /tmp/wat/!blocks!3
-rw-r--r-- 1 mike mike 7.8K Aug  8 13:22 /tmp/wat/!blocks!4
-rw-r--r-- 1 mike mike  13K Aug  8 13:22 /tmp/wat/!blocks!5
-rw-r--r-- 1 mike mike 1.6K Aug  8 13:22 /tmp/wat/!blocks!6
-rw-r--r-- 1 mike mike 1.6K Aug  8 13:22 /tmp/wat/!blocks!7
-rw-r--r-- 1 mike mike    1 Aug  8 13:22 /tmp/wat/!blocks!length
mike@patty:~/dev/ganache-core$ cat /tmp/wat/\!blocks\!length 
8
$ cat /tmp/wat/\!blocks\!7
{"header":{"parentHash":"0x14e0c45523711b8e50f5c1c02e65c6db572651609e3edc7202ca68486247ef29","uncleHash":"0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347","coinbase":"0x0000000000000000000000000000000000000000","stateRoot":"0x9bd60b4e8d0c2a59ef9f76a518baae81463e0bf911c644d62fe740c7e427f455","transactionsTrie":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","receiptTrie":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","bloom":"0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","difficulty":"0x","number":"0x07","gasLimit":"0x47e7c4","gasUsed":"0x425b","timestamp":"0x598a1319","extraData":"0x","mixHash":"0x0000000000000000000000000000000000000000000000000000000000000000","nonce":"0x"},"transactions":[{"nonce":"0x06","gasPrice":"0x174876e800","gasLimit":"0x47e7c4","to":"0x3abd0d49d2ed14b4b9141b15cdbdcdf03d9f3521","value":"0x","data":"0x16e85b2e","v":"0x1c","r":"0x","s":"0x","from":"0x04319405a70fbb5a3b30dd7917bb59796616f7ad","hash":"0x7d7002d7edbc3b1c5e5b51e624c25da912c8bcb8578b86b4e5bcae221630cc4b"}],"uncleHeaders":[]}

I tried updating BlockchainDouble.getHeight to use BlockchainDouble.latestBlock instead of just using the length stored in the DB, but no joy. Still not clear to me exactly where this error is coming from and the traceback is not really of any help.

I wonder if CacheDOWN is the one out of sync but I haven't yet dug into it. Or maybe I'm way off base, since node is not my strong point.

[prozacchiwawa]

I was getting this bug, but I think I figured out how to fix it. The printing of the transaction receipt after sendTransaction appeared to be happening after an evm_revert when a javascript contract test finished and another one started. My proposed fix is to add evm_revert, evm_snapshot and eth_getLogs (which is fired from printTransactionReceipt) to the set of sequenced operations on a blockchain instance. Anyone interested in testing this? https://github.com/prozacchiwawa/ganache-core/tree/20170812-truffle-test-sequence

[mikeshultz]

@prozacchiwawa Most of the "Forking" tests are failing with this:

 TypeError: this._findPath is not a function
  at ForkedStorageTrie.keyExists (lib/utils/forkedstoragetrie.js:30:8)
  at lib/utils/forkedblockchain.js:269:20
  at ForkedBlockchain.BlockchainDouble.getEffectiveBlockNumber (lib/blockchain_double.js:133:14)
  at ForkedBlockchain.getCode (lib/utils/forkedblockchain.js:266:8)
  at StateManager.getCode (lib/statemanager.js:208:19)
  at GethApiDouble.eth_getCode (lib/subproviders/geth_api_double.js:127:14)
  at GethApiDouble.handleRequest (lib/subproviders/geth_api_double.js:70:10)
  at GethDefaults.handleRequest (lib/subproviders/gethdefaults.js:17:12)
  at DelayedBlockFilter.handleRequest (lib/subproviders/delayedblockfilter.js:27:3)
  at ReactiveBlockTracker.handleRequest (lib/subproviders/reactiveblocktracker.js:25:12)
  at RequestFunnel.handleRequest (lib/subproviders/requestfunnel.js:35:12)

I was not able to run any of my contract tests against it, because it appears the test accounts were not created with funds(probably related to the above).

[prozacchiwawa]

I think the tests are broken in master in general (same failures from master clone, npm install && npm test). I'll rebranch from a release tag, to get a clearer picture. I hot patched this into my tree, and it seemed to solve my problem, but admittedly didn't need to generate accounts as I have a set of pregenerated ones I was using in my tests. Thanks for trying it out.

[mikeshultz]

@prozacchiwawa Yeah, sorry. It appears all of those errors are not related to your changes. I get those same errors from a clean master branch of ganache-core from a week or two ago. Let me see if I can get a working branch and then I'll test your changes.

[prozacchiwawa]

Remade my branch against release: https://github.com/prozacchiwawa/ganache-core/tree/20170812-truffle-test-sequence-release . All tests seem to be passing in this branch.

[mikeshultz]

That find path is easy enough to fix but I'm still not getting account balances when I start it. How are you building that, anyway?

I'll try your branch in a minute.

[prozacchiwawa]

I'm not an npm power user really, so there might be a more convenient way,
but

I cloned ganache-core and did npm link in there.
I cloned testrpc and did

npm install
npm link ganache-core
npm run build
npm link

Then did npm link testrpc in my main repo.

I'm running testrpc like this:

!/bin/sh

exec ./node_modules/.bin/testrpc \
--account=0x3a1076bf45ab87712ad64ccb3b10217737f7faacbf2872e88fdd9a537d8fe266,20000000000000000000
\
--account=0x9fd05d15f4e1a20307928e6371ffc2d075fc008afb891c3b0fcbebd04f58d9bc,20000000000000000000
\
--account=0xd212c54b88131ec213cd4f8bf4c2990bba5b4cd7469991a4d6537e3f7fb1a330,20000000000000000000
\
"${@}"

^-- the above are not real accounts :-)

On Sat, Aug 12, 2017 at 11:36 AM, Mike Shultz [e-mail]
wrote:

That find path is easy enough to fix
https://github.com/mikeshultz/ganache-core/commit/dbc537954db4eac37d351fb626458144e2720b00
but I'm still not getting account balances when I start it. How are you
building that, anyway?

I'll try your branch in a minute.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/ethereumjs/testrpc/issues/346#issuecomment-321998362,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAOEENXVrzQWkVvxMf7T9ebhi-aeqbGaks5sXfC3gaJpZM4OU5_O
.

[mikeshultz]

This has got to be the most frustrating codebase I've stuck my nose into but I'm getting nowhere. I can't get this to build because of some failing dependency, and I'm still having an account balance issue. In the state manager, accounts show a balance:

> server.provider.manager.state.accounts['0xabc...'].account.balance
<Buffer 00 00 00 00 00 00 00 05 6b c7 5e 2d 63 10 00 00>

But not through getBalance:

> server.provider.manager.state.blockchain.getBalance("0xabc...", 'latest',  function(err, bal) { console.log(bal); })
<Buffer >

It's a fresh source tree, so maybe this is a separate bug in master, or my system is a mess. I wasn't seeing this the other day when I was testing. I'll try again tomorrow with a fresh node install.

[edwmamedov]

This bug is real stopper, @tcoulter could you please fix it ASAP.
Thanks.

[tcoulter]

We're taking a look at this. Will add more info when we've locked it down.

[tcoulter]

This has been fixed in ganache-core (the code that powers the testrpc). Will go out with the next TestRPC release, which should be in the next couple days.

Thanks all for the reports!

[Meekohi]

I am still seeing this on EthereumJS TestRPC v4.1.3 (ganache-core: 1.1.3)

[jackcasey]

I just got the error on the new version too :

$ testrpc --version
EthereumJS TestRPC v4.1.3 (ganache-core: 1.1.3)

[tomericco]

Make sure that you wait for your promises.
If you are using async/await syntax, make sure every call to the contract is prefixed by await

[benjamincburns]

@Meekohi & @jackcasey if you are still seeing this issue after employing @tomericco's advice, please post here with repro steps and we may reopen the issue.

[mgraczyk]

@benjamincburns Easy repro:

Run this

$ ./node_modules/.bin/ganache-cli
Ganache CLI v6.1.0 (ganache-core: 2.1.0)

Then in another shell, run

curl localhost:8545 -X POST -d '{"method": "eth_getBalance", "params": ["", 1]}'

[mgraczyk]

If you'd like a repo to compare with geth, try:

Geth:

$ curl https://mainnet.infura.io:8545 -X POST -d '{"method": "eth_getBalance", "params": ["0x0000000000000000000000000000000000000000", "0x1111111111111111"], "id": 0}'
{"jsonrpc":"2.0","id":0,"result":"\u003cnil\u003e"}

ganache-cli

$ curl localhost:8545 -X POST -d '{"method": "eth_getBalance", "params": ["0x0000000000000000000000000000000000000000", "0x1111111111111111"], "id": 0}'
{"id":0,"error":{"message":"LevelUpArrayAdapter named 'blocks' index out of range: index 1; length: 1","code":-32000,"data":{"stack":"Error: LevelUpArrayAdapter named 'blocks' index out of range: index 1; length: 1\n    at <>/node_modules/ganache-cli/build/cli.node.js:2:778143\n    at <>/node_modules/ganache-cli/build/cli.node.js:2:777808\n
at <>/node_modules/ganache-cli/build/cli.node.js:2:774000\n    at <>/node_modules/ganache-cli/build/cli.node.js:2:776505\n    at <>/node_modules/ganache-cli/build/cli.node.js:2:748516\n    at process._tickCallback (internal/process/next_tick.js:112:11)","name":"Error"}}}

[PopTudor]

had the issue because I was calling the right method on the wrong contract...realised after 2 hours of not knowing what's going on