System Error when running Ganache 2.0.1 on win32 ('pop' of undefined)

[officialfrancismendoza]

• Was testing dapp. After relevant commands (truffle migrate --reset and npm run dev), my dapp initially did not display. I initially refreshed several times until the content finally displayed. It appears as if there were delays in communication between the backend + UI because I got duplicates, and perhaps this delay caused mismatches of fields of some sort.

I received RPC errors where nonces were mismatched. I restarted Ganache several times and, by working through Metamask, used the same RPC link and sample account private key. Transactions were unable to pass because of a nonce mismatch (ie: upon restart, nonce 2 mismatch with nonce 184)

PLATFORM: win32
GANACHE VERSION: 2.0.1

EXCEPTION:

TypeError: Cannot read property 'pop' of undefined
    at CheckpointTrie.Trie._updateNode (C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:360:23)
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:107:16
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:461:14
    at processNode (C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:471:23)
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:516:13
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:180:7
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\util.js:75:7
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\node_modules\async\lib\async.js:52:16
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\node_modules\async\lib\async.js:269:32
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\node_modules\async\lib\async.js:44:16
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\util.js:71:7
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:157:9
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\lib\database\levelupobjectadapter.js:41:16
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\level-sublevel\shell.js:101:15
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\level-sublevel\nut.js:121:19
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\encoding-down\index.js:51:21
    at C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\cachedown\index.js:58:21
    at ReadFileContext.callback (C:\Program Files\WindowsApps\Ganache_2.0.1.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\lib\database\filedown.js:26:14)
    at FSReqWrap.readFileAfterOpen [as oncomplete] (fs.js:420:13)

APPLICATION LOG:

T+702867124ms: eth_sendTransaction
T+702867225ms:   Transaction: 0xd2796e2c1a72a57c7d452beb031b4bccd3e5dc92a47a83ef26b306a8c753ce11
T+702867225ms:   Contract created: 0x9fd1d717675ca9c78e0cb1e410b5cd91864d8667
T+702867225ms:   Gas usage: 544676
T+702867225ms:   Block Number: 187
T+702867225ms:   Block Time: Fri Jun 07 2019 15:42:04 GMT-0700 (US Mountain Standard Time)
T+702867225ms: eth_getBlockByNumber
T+702867225ms: eth_getTransactionReceipt
T+702867227ms: eth_getCode
T+702867228ms: eth_getTransactionByHash
T+702867229ms: eth_getBlockByNumber
T+702867233ms: eth_getBalance
T+702867241ms: eth_getBlockByNumber
T+702867246ms: eth_getBlockByNumber
T+702867251ms: eth_sendTransaction
T+702867319ms:   Transaction: 0x04b265c9add73a700905498e5dafc9ac07fb33e0856e624f60fbe2a3c4072b14
T+702867319ms:   Gas usage: 27008
T+702867319ms:   Block Number: 188
T+702867319ms:   Block Time: Fri Jun 07 2019 15:42:04 GMT-0700 (US Mountain Standard Time)
T+702867321ms: eth_getBlockByNumber
T+702867321ms: eth_getTransactionReceipt
T+702873682ms: net_version
T+702873683ms: net_version
T+702873756ms: eth_getLogs
T+702873761ms: eth_call
T+702875635ms: eth_blockNumber
T+702875641ms: eth_getBlockByNumber
T+702875761ms: eth_call
T+702877603ms: net_version
T+702877609ms: net_version
T+702877680ms: eth_getLogs
T+702877685ms: eth_call
T+702878772ms: eth_call
T+702878773ms: eth_call
T+702895652ms: eth_blockNumber
T+702901290ms: net_version
T+702901291ms: net_version
T+702902114ms: eth_getLogs
T+702905186ms: net_version
T+702905191ms: net_version
T+702906072ms: net_version
T+702906075ms: net_version
T+702907078ms: eth_getLogs
T+702915670ms: eth_blockNumber
T+702935684ms: eth_blockNumber
T+702955703ms: eth_blockNumber
T+702975720ms: eth_blockNumber
T+702995740ms: eth_blockNumber
T+702999093ms: net_version
T+702999094ms: net_version
T+703000068ms: net_version
T+703000073ms: net_version
T+703001083ms: eth_getLogs
T+703015756ms: eth_blockNumber
T+703016891ms: net_version
T+703016898ms: eth_accounts
T+703016918ms: eth_getBlockByNumber
T+703016922ms: eth_accounts
T+703016941ms: eth_getBlockByNumber
T+703016945ms: eth_getBlockByNumber
T+703016949ms: eth_getBlockByNumber
T+703016957ms: eth_estimateGas
T+703017087ms: eth_unsubscribe
T+703017087ms: eth_unsubscribe
T+703017104ms: eth_unsubscribe
T+703017104ms: eth_unsubscribe
T+703017110ms: eth_unsubscribe

[wbt]

I also just noticed a similar error, with the same stack trace including line and column numbers, also on win32, though on Ganache version 2.0.0-beta.2.

Just prior to that, I'd been reading data from the blockchain in a dapp, getting errors like:

MetaMask - RPC Error: Error: [ethjs-query] while formatting outputs from RPC '{"value":{"message":"Key not found in database","code":-32603}}'
at chrome-extension://nkbihfbeogaeaoehlefnkodbefgpgknn/background.js:1:1209395

Ganache had previously been displayed on an external monitor that was not present, so the UI was lost. I tried doing a truffle migrate --reset but believe the bug occurred prior to that, because the migration failed with the following outcome, some line breaks omitted:

Starting migrations...
======================
> Network name:    'development'
> Network id:      5777
> Block gas limit: 0x6691b7
1_initial_migration.js
======================
   Replacing 'Migrations'
   ----------------------
Could not connect to your Ethereum client with the following parameters:
    - host       > 127.0.0.1
    - port       > 7545
    - network_id > 5777
Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle-config.js)

I was able to see this bug by again connecting to an external monitor with the appropriate dimensions and position. The application log generated for a bug report included calls to the following:

• eth_getBlockByNumber
• eth_blockNumber
• eth_getBalance
• eth_blockNumber
• net_version
• eth_call
• eth_getLogs
• eth_accounts
• eth_estimateGas
• eth_unsubscribe

but no recent write transactions.

[wbt]

I just got this error when opening Ganache (v2.1.2) and clicking Quickstart, with nothing else running to interact with the blockchain. After clicking Relaunch, and clicking on the one existing workspace, the same thing happened, again with nothing else interacting with the blockchain. Here is what was autopopulated when I clicked Raise GitHub Issue:

PLATFORM: win32
GANACHE VERSION: 2.1.2

EXCEPTION:

TypeError: Cannot read property 'pop' of undefined
    at CheckpointTrie.Trie._updateNode (C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:360:23)
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:107:16
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:461:14
    at processNode (C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:471:23)
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:457:5
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:180:7
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\util.js:75:7
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\node_modules\async\lib\async.js:52:16
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\node_modules\async\lib\async.js:269:32
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\node_modules\async\lib\async.js:44:16
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\util.js:71:7
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\merkle-patricia-tree\baseTrie.js:157:9
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\lib\database\levelupobjectadapter.js:41:16
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\level-sublevel\shell.js:101:15
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\level-sublevel\nut.js:121:19
    at C:\Program Files\WindowsApps\Ganache_2.1.2.0_x64__zh355ej5cj694\app\resources\app.asar\node_modules\ganache-core\node_modules\encoding-down\index.js:51:21

APPLICATION LOG:

T+0ms: �[33mYou can improve web3's peformance when running Node.js versions older than 10.5.0 by installing the (deprecated) scrypt package in your project�[0m
T+690ms: Starting server (version 2.1.2) with initial configuration: {"gasLimit":6721975,"gasPrice":20000000000,"hardfork":"petersburg","hostname":"127.0.0.1","port":7545,"network_id":5777,"default_balance_ether":100,"total_accounts":10,"unlocked_accounts":[],"locked":false,"vmErrorsOnRPCResponse":true,"verbose":false,"db_path":"C:\\Users\\username\\AppData\\Roaming\\Ganache\\workspaces\\Quickstart\\chaindata"}
T+2044ms: Ganache started successfully!
T+2044ms: Waiting for requests...

I also found a bunch of duplicates, all reporting the same issue on the same line:

On win32:
https://github.com/trufflesuite/ganache/issues/1344 & https://github.com/trufflesuite/ganache/issues/1506
On linux:
https://github.com/trufflesuite/ganache/issues/1453
On darwin:
https://github.com/trufflesuite/ganache/issues/1292,
trufflesuite/ganache#1337,
https://github.com/trufflesuite/ganache/issues/1348,
https://github.com/trufflesuite/ganache/issues/1372,
https://github.com/trufflesuite/ganache/issues/1388,
https://github.com/trufflesuite/ganache/issues/1448,
https://github.com/trufflesuite/ganache/issues/1449,
https://github.com/trufflesuite/ganache/issues/1471,
https://github.com/trufflesuite/ganache/issues/1474, &
trufflesuite/ganache#1589

[wbt]

See also: ethereumjs/merkle-patricia-tree#12 ("important" "bug" known since May 2016).

[davidmurdoch]

Thanks for digging into this @wbt. We've suspected this to be a race condition, but haven't ever pinpointed the issue.

If you are able to consistently reproduce the issue with that workspace, do you mind zipping up the workplace contents and sending it to me? On Windows the app workspace data should be located at C:\Users\{YOUR USER NAME}\AppData\Local\Packages\Ganache{IDENTIFIER}\LocalCache\Roaming\Ganache\workspaces\

You should be able to upload it so https://send.firefox.com/ if you don't mind sharing the contents of the worksapce chain publically. If not, let me know and we'll find another way. Thanks!

[wbt]

Unfortunately, even I don't have consistent reproduction steps and restarting the app a sufficient number of times (often a low number) and creating a new workspace usually provides a workaround (even if it is a slow one). However, all the dupes I found in a very quick search (there are probably lots more) makes this look like a relatively common issue, and the lack of responses to these system issues that shouldn't be happening make the project look unmaintained. Therefore it might still be a good one to fix.

I think a strategy for starting to fix this would be for someone with more time and skill at reading through "callback hell" than I to audit the merkle-patricia-tree code, perhaps starting with the two traces started in the other issue, and making sure there are appropriate undefined checks in place before variables are used or passed on. That code could probably benefit from a good audit/code review and finding/fixing an issue there might have higher impact on production applications than trying the same in Ganache.

---

Also of note, the folder name in C:\Users\{YOUR USER NAME}\AppData\Local\Packages\Ganache{IDENTIFIER}\LocalCache\Roaming\Ganache\workspaces\ is set for the original default workspace name, with no clear correspondence to the user-set workspace name and thus no good way to figure out which folder corresponds to a particular named workspace, unless:

• the user left the default name
• the user kept a separate record of the correspondence between the default and given workspace names
• there is only one workspace other than Quickstart

[davidmurdoch]

I figured out a way of reproducing the issue (in the case where it errors on start up). It came down to a race condition in how we write and read the trie files.

The gist of it is that if you fs.readFile on a file that is being written to with fs.writeFile then sometimes the readFile will return "" (or an empty Buffer). The value would then propagate into the trie, causing the trie to have an invalid node, and then it would eventually crash as you are seeing here.

The issue you described on start up is caused by a bug in ethereumjs-vm's constructor performing asynchronous IO with no way of signaling to the caller that its IO is complete. The fix I'm proposing for ganache-core works around this issue. I've opened an issue at etehreumjs-vm you can check out if you are curious.

[davidmurdoch]

Fixed in https://github.com/trufflesuite/ganache/releases/tag/v2.3.0! Please let me know if you are still experiencing problems!